0

My main program logs to its own log file and the sub-process should have its own log file. I replaced the logger object inside the multiprocessing process, but the logging data from the sub-process is additionally redirected to the main log file.

How can I prevent this?

The structure looks like this:

import logging
import sys
import os
from pathlib import Path
import multiprocessing
import time

import requests


class ProcessFilter(logging.Filter):
    """Only accept log records from a specific pid."""

    def __init__(self, pid):
        self._pid = pid

    def filter(self, record):
        return record.process == self._pid


def create_logger(file):
    log = logging.getLogger(__name__)
    log.setLevel(logging.DEBUG)
    log.addFilter(ProcessFilter(pid=os.getpid()))
    file_handler = logging.FileHandler(file)
    stream_handler = logging.StreamHandler(sys.stdout)
    formatter = logging.Formatter('[%(asctime)s] %(levelname)s [%(filename)s.%(funcName)s:%(lineno)d] %(message)s',
                                  datefmt='%a, %d %b %Y %H:%M:%S')
    file_handler.setFormatter(formatter)
    stream_handler.setFormatter(formatter)
    log.addHandler(file_handler)
    log.addHandler(stream_handler)
    return log


def subprocess_init():
    global log
    sub_log_file = str(Path.home()) + '/logfile_sub.log'
    log = create_logger(sub_log_file)
    do_subprocess_stuff()


def do_subprocess_stuff():
    count = 0
    while True:
        create_log("subprocess", count)
        time.sleep(5)
        count += 1


def main_tasks():
    num = 10
    while num > 0:
        create_log("main", num)
        time.sleep(5)
        num -= 1


def create_log(text, num):
    log.debug(text + " log %s", num)


if __name__ == '__main__':
    file = str(Path.home()) + '/logfile.log'
    log = create_logger(file)
    sub_process = multiprocessing.Process(target=subprocess_init, args=())
    sub_process.daemon = True
    sub_process.start()
    main_tasks()
Ximi
  • 81
  • 10

1 Answers1

1

I am simply translating this answer to fit multiprocessing.

import logging

class ProcessFilter(logging.Filter):
    """Only accept log records from a specific pid."""

    def __init__(self, pid):
        self._pid = pid

    def filter(self, record):
        return record.process == self._pid
import logging
import os

def create_logger(file):
    log = logging.getLogger('')  # why use this logger and not __name__ ?
    log.setLevel(logging.DEBUG)
    log.addFilter(ProcessFilter(pid=os.getpid()))  # logger wide filter
    file_handler = logging.FileHandler(file)
    stream_handler = logging.StreamHandler(sys.stdout)
    formatter = logging.Formatter('[%(asctime)s] %(levelname)s [%(filename)s.%(funcName)s:%(lineno)d] %(message)s',
                                  datefmt='%a, %d %b %Y %H:%M:%S')
    file_handler.setFormatter(formatter)
    stream_handler.setFormatter(formatter)
    log.addHandler(file_handler)
    log.addHandler(stream_handler)
    return log

NB. you can also put the filter on a specific handler

ljmc
  • 4,830
  • 2
  • 7
  • 26
  • Thanks, with these changes the output of the subprocesses from my python program has disappeared from the main log, except for the debug log of imported stuff, it's still in both log files. Sub-process log messages from my python file are missing from the sub-process log file. Unfortunately it doesn't work as expected yet. – Ximi Aug 13 '22 at 11:10
  • Does anything else need to be adjusted according to the example above? – Ximi Aug 13 '22 at 11:33
  • @Ximi I don't know what you are logging, from where and how, as such I can only provide you with the above. If you need to set something for all loggers, you should configure the root logger, and maybe down to each logger namespace. It might be worth looking into configuring you logger with a [dictionary](https://docs.python.org/3/library/logging.config.html#logging-config-dictschema) if there is many loggers affected. – ljmc Aug 13 '22 at 12:17
  • I updated the code with your solution, this version shows the current problem. The `logfile_sub` keeps empty. (- The other debug log problem mentioned from other sources is for example with `requests.post`. The debug messages from the post request are in both log files. ) – Ximi Aug 13 '22 at 13:16
  • the "logging.getLogger('')" needs a specific name for each logger like 'mainprocess' and 'subprocess', than this solution will work in my example – Ximi Aug 14 '22 at 09:37
  • @Ximi yes, this could work, make sure the loggers share the same namespace, for instance with `f"{__name__}.{os.getpid()}"`. To me that’s a code smell, but if you make it work, it works. – ljmc Aug 14 '22 at 09:46
  • If you have any additional suggestions for improvement, I'd love to hear them. – Ximi Aug 14 '22 at 10:31
  • @Ximi, I would recommend using a full dictionary config to specify handlers and filters for each logger (including external like `request.x`) or at least each logger namespace, and after that using a filter like above to do the redirection you want, as pid or threat id should be part of the log line, not so much the logger name. – ljmc Aug 14 '22 at 12:18
  • @Ximi You should also check to this https://docs.python.org/3/library/multiprocessing.html#logging – ljmc Aug 14 '22 at 13:04