Why overriding of sys.stdout does not work for output coming from multiprocessing.Process?

Question

I am redirecting stdout to a logger, and now I spawned a process using multiprocessing.Process. However even though the processes stdout is redirected to the parent stdout, it ignores the sys.stdout override. Here is an example:

import multiprocessing
import sys
import logging

def worker():
    print('Hello from the multiprocessing')
    sys.stdout.flush()

class LoggerWriter:
    def __init__(self, logger, level):
        self.logger = logger
        self.level = level

    def write(self, message):
        if message != '\n':
            self.logger.log(self.level, "LOGGER: "+message)

    def flush(self):
        pass


if __name__ == '__main__':
    logging.basicConfig(level=logging.INFO, format='%(message)s')
    sys.stdout = LoggerWriter(logging.getLogger(), logging.INFO)
    p = multiprocessing.Process(target=worker)
    print("Hello from main")
    p.start()
    p.join()

I expected it to print

LOGGER: Hello from main
LOGGER: Hello from the multiprocessing

but Instead I get

LOGGER: Hello from main
Hello from the multiprocessing

It completely ignores the sys.stdout ... Why is that? Can the first case be achieved?

Note: This is on Windows 7 - seems like it might play a role.

You need to override `sys.stdout` in each of your processes. Check [this answer](https://stackoverflow.com/a/44489010) as an example on capturing STDOUT/STDERR in a multiprocessing setting. — zwer, Oct 20 '18 at 22:59
Because you construct a *new* process, so that means it has its own stdin, stdout, etc. — Willem Van Onsem, Oct 20 '18 at 22:59
Actually, the above works on my python3.7 (although with an extra trailing empty logging line). Is this a windows vs linux thing? — Andras Deak -- Слава Україні, Oct 20 '18 at 23:00
@AndrasDeak - It's a fork vs actual new process thing. It may happen on fork-enabled systems (not all multiprocessing can be achieved through forking) but it will always be the case on Windows as it doesn't even support fork. — zwer, Oct 20 '18 at 23:03
@zwer It looks good, but in my case I actually am interested in real time printing - basically the production case is that this main process is starting bunch of subprocesses (including for example FTP server), and all of that should be logged in different places (console, one huge log file, etc...), but respecting time order in real time... It seems it would work easily on linux with this forking... — Sil, Oct 20 '18 at 23:52

score 1 · Accepted Answer · answered Oct 20 '18 at 23:05

You're on Windows, so you're using the spawn method for starting multiprocessing workers. This method starts a fresh Python interpreter from scratch and imports your script as a module before starting work.

Because your workers are started from scratch instead of forked, they don't automatically inherit setup performed by the main process, including setup like your stdout wrapper, and they don't redo that setup because it's inside the if __name__ == '__main__' guard. They just have the regular sys.stdout.

You'll have to arrange for the workers to set up their own stdout wrappers, perhaps by placing the wrapper setup outside the if __name__ == '__main__' guard.

Thank you, I think I've achieved what I needed, basically each of the workers do set up their logging, plus I needed to have the logging to same resource, so just created also one threading.Thread that gets log messages from child as they come in through Queue (which is a bit ironic since originally I wanted avoid Threads due to GIL limitations etc, but this way their functionality is at least limited to handle this logging issue, so I guess it's alright). — Sil, Oct 21 '18 at 09:02

Sil · Answer 2 · 2018-10-22T21:32:26.380

Based the comments and @user2357112's answer, I've eventually ended up using threading.Thread for handling logs from child process (exchanged through Queue), while still using Process for actual work. Here it is in case someone will need something similar.

Basically after adding:

class LoggedProcess(multiprocessing.Process):

    class LoggerWriter:
        def __init__(self, queue):
            self.queue = queue

        def write(self, message):
            for line in message.rstrip().splitlines():
                self.queue.put(line.rstrip())

        def flush(self):
            pass

    @staticmethod
    def logged_worker(logger_queue, worker, *args, **kwargs):
        import sys
        sys.stdout = sys.stderr = LoggedProcess.LoggerWriter(logger_queue)
        logging.basicConfig(format="%(message)s", level=logging.INFO)
        try:
            worker(*args, **kwargs)
        except:
            pass
        logger_queue.put(None)

    @staticmethod
    def process_logger(process, logger_queue, name):
        while True:
            try:
                if not process.is_alive():
                    raise EOFError()
                msg = logger_queue.get(timeout=1)
                if msg is None:
                    raise EOFError()
                logging.getLogger().log(logging.INFO, f"[PROCESS {process.pid} {name}] {msg}")
            except queue.Empty:
                pass # timeout
            except Exception:
                break # queue closed

    def __init__(self, target, log_name='', args=(), kwargs={}):
        self.logger_queue = multiprocessing.Queue()
        self.log_name = log_name
        super().__init__(target=self.logged_worker, args=(self.logger_queue, target, *args), kwargs=kwargs)


    def start(self):
        super().start()
        logger_t = threading.Thread(target=self.process_logger, args=(self, self.logger_queue, self.log_name))
        logger_t.setDaemon(True)
        logger_t.start()

    def terminate(self):
        super().terminate()
        super().join()
        self.logger_queue.put(None)

we can just replace p = multiprocessing.Process(target=worker) with p = LoggedProcess(target=worker). Now child process logs are mixed into the parent process logger, in this case resulting into

LOGGER: Hello from main
[PROCESS 5000 ] Hello from the multiprocessing

I've added some additional process info around, but original intent could be still satisfied, plus now it can be for example all put into same single log file by the parent process, or whatever is needed.

Why overriding of sys.stdout does not work for output coming from multiprocessing.Process?

2 Answers2