Python 3: Using a multiprocessing queue for logging

Question

I've recently been given the challenge of working multiprocessing into our software. I want a main process to spawn subprocesses, and I need some way of sending logging information back to the main process. This is mainly because a module we use writes warning and error messages to a logging object, and we want these messages to appear in the gui, which runs in the main process.

The obvious approach was to write a small class with a write() method that puts() onto a queue, and then use this class in a logging stream handler. The main process would then get() from this queue to send the text to the gui. But this didn't seem to work, and I don't know why

I wrote some sample code to demonstrate the problem. It uses a logging object to write a queue in a subprocess, and then the main process tries to read from the queue, but fails. Can someone help me figure out what is wrong with this?

import time, multiprocessing, queue, logging

class FileLikeQueue:
    """A file-like object that writes to a queue"""
    def __init__(self, q):
        self.q = q
    def write(self, t):
        self.q.put(t)
    def flush(self):
        pass


def func(q):
    """This function just writes the time every second for five 
    seconds and then returns. The time is sent to the queue and 
    to a logging object"""

    stream = FileLikeQueue(q)

    log = logging.getLogger()
    infohandler = logging.StreamHandler(stream)
    infohandler.setLevel(logging.INFO)
    infoformatter = logging.Formatter("%(message)s")
    infohandler.setFormatter(infoformatter)
    log.addHandler(infohandler)

    t1 = time.time()
    while time.time() - t1 < 5: #run for five seconds
        log.info('Logging: ' + str(time.time()))
        q.put('Put: %s' % str(time.time()))
        time.sleep(1)



def main():
    q = multiprocessing.Queue()
    p = multiprocessing.Process(target=func, args=(q,))
    p.start()

    #read the queue until it is empty
    while True:
        try:
            t = q.get()
        except queue.Empty:
            break
        print(t)


if __name__ == '__main__':
    main()

I expect the output to be:

Logging: 1333629221.01
Put: 1333629221.01
Logging: 1333629222.02
Put: 1333629222.02
Logging: 1333629223.02
Put: 1333629223.02
Logging: 1333629224.02
Put: 1333629224.02
Logging: 1333629225.02
Put: 1333629225.02

But what I get is:

Put: 1333629221.01
Put: 1333629222.02
Put: 1333629223.02
Put: 1333629224.02
Put: 1333629225.02

So the put() operation in func() works, but the logging doesn't. Why?

Thank you.

Answer 1

Your problem is with the configuration of the logging module:

You need to call log.setLevel(logging.INFO). The default log level is WARNING, so your logs have no effect.

You did call setLevel on the handler object, but the logged messages never reach the handler because they are filtered by the logger. There is no need to call setLevel on the handler itself, because it processes all messages by default.