Add a custom field to the Python log format string

- Posted by: Barbra Lashbrook - December 14, 2020 Back to CIRA Wiki Home



Topic Catagories:

This is from a project that makes use of Python multiprocessing and, as the first comment says, is done to provide a process name field. There are other ways to do this, but this one seemed the best for this application.

# coding: utf-8

# Setup fancy logging to see which process the message is from
# Do this before any other logging.getLogger() calls (?)

# Stock logging modules
import os
import logging

class ProcFilter(logging.Filter):
    procName = 'parent'
    def filter(self, record):
        record.proc_name = self.procName
        return True

# Then use proc_name in your formatting preferences
myformatter = logging.Formatter(
  '%(asctime)s %(levelname)-8s%(proc_name)-9s%(name)s: %(message)s'
)

myhandler = logging.StreamHandler()
myhandler.setFormatter(myformatter)
myhandler.addFilter(ProcFilter())

# The handler will propagate to all loggers when set on the root logger
root_logger = logging.getLogger()
root_logger.setLevel(os.environ.get('LOGLEVEL', 'DEBUG').upper())
root_logger.addHandler(myhandler)

log = logging.getLogger(__name__)

# Stock modules continued
import sys
import multiprocessing
from multiprocessing import Process, JoinableQueue

# Local modules

This can then be used to set proc_name differently for every child when using multiprocessing by passing ProcFilter and a child identifier to the child processes as they are created:

def proc_main(q, ProcFilter, procnum):

    # Customize logging for this child process
    ProcFilter.procName = 'child {:d}'.format(procnum)

    log.info('proc_main started')

Then in the log you get:

2020-12-11 20:55:55,547 INFO    parent   __main__: Starting procs
2020-12-11 20:55:55,554 INFO    child 0  __main__: proc_main started
2020-12-11 20:55:55,557 INFO    child 1  __main__: proc_main started
2020-12-11 20:55:55,559 INFO    child 2  __main__: proc_main started