Logging using multiple process to one file in python

Question

I am trying to setup logging between multiple processes using the QueueHandler. I am seeing the same log in the log file printed multiple times. Using this as a template (https://docs.python.org/3/howto/logging-cookbook.html#logging-to-a-single-file-from-multiple-processes)

EDIT

multi processing file:

import logging
from logging.handlers   import RotatingFileHandler, QueueHandler
from multiprocessing import Process
from queue import Empty

class MultiProcessQueueLoggingListner(Process):
    def __init__(self, name, queue):
        super().__init__()
        self.name = name
        self.queue = queue
        self.logger = logging.getLogger(name)
        self.file_handler = RotatingFileHandler(name, maxBytes=536870912, backupCount=2)
        self.formatter = logging.Formatter('%(asctime)s %(processName)-10s %(name)s %(levelname)-8s %(message)s')
        self.file_handler.setFormatter(self.formatter)
        self.logger.addHandler(self.file_handler)

    def run(self):
        while True:
            try:
                record = self.queue.get()
                if record is None:
                    break
                self.logger.handle(record)
            except Exception:
                import sys, traceback
                print('Whoops! Problem:', file=sys.stderr)
                traceback.print_exc(file=sys.stderr)


class MulitProcessQueueLogger(object):
def __init__(self, name, queue):
    self.name = name
    self.queue = queue
    self.queue_handler = QueueHandler(queue)
    self.logger = logging.getLogger(name)
    self.logger.addHandler(self.queue_handler)
    self.logger.setLevel(logging.DEBUG)

test file:

import multi_process_logging
import multiprocessing
from time import sleep


def worker(po):
    name = multiprocessing.current_process().name
    po = multi_process_logging.MulitProcessQueueLogger('test.log', q)
    print("In worker")
    for i in range(10):
        po.logger.info(f"Logging from {name} line {i}")
    po.queue.put(None)

def main():
    q = multiprocessing.Queue()
    lp = multi_process_logging.MultiProcessQueueLoggingListner('test.log', q)
    lp.start()
    p = multiprocessing.Process(target=worker, args=(q,))
    p.start()
    p.join()
    lp.join()



if __name__ == '__main__':
    main()

The issue I see is that the test.log file contains multiple lines for the same entry. The program stops now and doesn't run indefinite but still seeing multiple lines

    cat test.log | grep 'line 0'
2018-09-26 16:32:40,117 Process-2  test.log INFO     Logging from Process-2 line 0
2018-09-26 16:32:40,117 Process-2  test.log INFO     Logging from Process-2 line 0
2018-09-26 16:32:40,117 Process-2  test.log INFO     Logging from Process-2 line 0
2018-09-26 16:32:40,117 Process-2  test.log INFO     Logging from Process-2 line 0
2018-09-26 16:32:50,318 Process-2  test.log INFO     Logging from Process-2 line 0
2018-09-26 16:32:50,318 Process-2  test.log INFO     Logging from Process-2 line 0
2018-09-26 16:32:50,318 Process-2  test.log INFO     Logging from Process-2 line 0
2018-09-26 16:32:50,318 Process-2  test.log INFO     Logging from Process-2 line 0

I removed test.log before the run to rule out the append onto an existing log file, but still seeing multiple logs.

Thanks

Vinay Sajip · Accepted Answer · 2018-09-26 19:54:45Z

1

Your problem is caused by the fact that you're checking for a None to break out of the loop, but that will never come because a QueueHandler always writes a LogRecord to a queue, never None. If you want to write None to the queue, you need to write it directly rather than by doing po.logger.info(None). For example, store the queue as an attribute named queue of your MulitProcessQueueLogger instance and then do po.queue.put(None) in worker().

answered Sep 26, 2018 at 19:54

Vinay Sajip

100k15 gold badges184 silver badges196 bronze badges

Sign up to request clarification or add additional context in comments.

5 Comments

Greg Brown Over a year ago

I added the changes you mentioned and now I am seeing it halt, but still seeing multiple line for the same entry. Am i messing something up with the handlers?

Darkonaut Over a year ago

@Greg Brown It's because you also have to initialize the loggers in the new process not in the parent. Your logger inherits the QueueHandler so he re-enqueues the log record when he handels it.

Greg Brown Over a year ago

@Darkonaut I moved the logger into the process instead of the main process, and I am still seeing the duplicate log entries. Am I missing something?

Darkonaut Over a year ago

@Greg Brown __init__ runs in the parent, you have to relocate the configuration of the logger into run. Make an _init_logging method and call it from run.

Greg Brown Over a year ago

@Darkonaut, made the changes and it is working now Thanks.

mike rodent · Accepted Answer · 2021-04-13 12:29:25Z

0

I realise this is not a "nuts and bolts" answer, but if the intention is in fact primarily to achieve multi-process, same-log-file logging, one can do worse than finding an effective off-the-shelf solution: concurrent-log-handler seems like a mature project, and seems to work beautifully as far as I can tell. I just had to change one line in my logging.conf file to achieve the goal.

No doubt one could examine the source code there to check out the "nuts and bolts" they've used if interested.

answered Apr 13, 2021 at 12:29

mike rodent

16.1k15 gold badges120 silver badges202 bronze badges

Collectives™ on Stack Overflow

Logging using multiple process to one file in python

2 Answers 2

5 Comments

Comments

Your Answer

Hot Network Questions

Collectives™ on Stack Overflow

2 Answers 2

5 Comments

Comments

Your Answer

Sign up or log in

Post as a guest

Related