How to move ContextFilter class for logging to separate module?

Question

I have ContextFilter Class in my python script which I am using to have a counter variable in log formatter. It works as expected and prints value of incremented variable in log.

But when I try to move this Class to a custom module that I have created it always prints the initial value of variable and not the incremented value. Obviously I am missing something.

Contents of module log_format.py:

import logging
import datetime as dt

# As I need date in 2022-02-22 16:42:44.289193 format
class Formatter(logging.Formatter):
    converter=dt.datetime.fromtimestamp
    def formatTime(self, record, datefmt=None):
        ct = self.converter(record.created)
        if datefmt:
            s = ct.strftime(datefmt)
        else:
            t = ct.strftime("%Y-%m-%d %H:%M:%S")
            s = "%s,%03d" % (t, record.msecs)
        return s


#class ContextFilter(logging.Filter): # RUN 2
#    def __init__(self, i):           # RUN 2
#        self.i = i                   # RUN 2
#                                     # RUN 2
#    def filter(self, record):        # RUN 2
#        record.log_count = self.i    # RUN 2
#        return True                  # RUN 2

Contents of python script log_format_test.py

import os
import sys
import logging

py_lib = os.environ.get('app_dir') + "/lib"
sys.path.append(py_lib)

import log_format as lf

class ContextFilter(logging.Filter): # RUN 1
    def filter(self, record):        # RUN 1
        record.log_count = i         # RUN 1
        return True                  # RUN 1


logger = logging.getLogger(__name__)
l_level = 'INFO' #'DEBUG' #'INFO'
l_level = eval("logging." + l_level.upper())
logger.setLevel(l_level)

int_var = os.getpid()
i = 0
str_var = os.path.basename(__file__)

handler = logging.StreamHandler()
handler.setLevel(l_level)
lf_format = f'ZZZZZZZZ|%(asctime)s|{int_var}|%(log_count)s|{str_var}|%(message)s'
formatter = lf.Formatter(fmt=lf_format, datefmt='%Y-%m-%d %H:%M:%S.%f') # 2022-02-22 16:42:44.289193

logger.addFilter(ContextFilter()) # RUN 1
#logger.addFilter(lf.ContextFilter(i)) # RUN 2

handler.setFormatter(formatter)
logger.addHandler(handler)

i += 1; logger.info("I am INFO 0")
i += 1; logger.info("I am INFO 1")
i += 1; logger.debug("I am DEBUG 0")

When I run script log_format_test.py it does print log as expect with 4th field incremented for each log entry (RUN 1):

ZZZZZZZZ|2022-02-24 11:41:19.578733|20527|1|log_format_test.py|I am INFO 0
ZZZZZZZZ|2022-02-24 11:41:19.578868|20527|2|log_format_test.py|I am INFO 1

But when I try to move class ContextFilter out of log_format_test.py in to log_format.py by uncommenting # RUN 2 lines and commenting # RUN 1 lines, the log shows only initial value in 4th field which is 0 (RUN 2):

ZZZZZZZZ|2022-02-24 11:55:24.679430|29115|0|log_format_test.py|I am INFO 0
ZZZZZZZZ|2022-02-24 11:55:24.679552|29115|0|log_format_test.py|I am INFO 1

Question: How can I move move class ContextFilter out of log_format_test.py in to log_format.py (or a new module of it's own)? What am I missing here?

score 0 · Accepted Answer · answered Mar 08 '22 at 21:09

I was able to figure out how I could do this.

Contents of module log_format.py

import logging
import datetime as dt


class Formatter(logging.Formatter):
    converter=dt.datetime.fromtimestamp
    def formatTime(self, record, datefmt=None):
        ct = self.converter(record.created)
        if datefmt:
            s = ct.strftime(datefmt)
        else:
            t = ct.strftime("%Y-%m-%d %H:%M:%S")
            s = "%s,%03d" % (t, record.msecs)
        return s


class ContextFilter(logging.Filter): # RUN 2
    def __init__(self, i):           # RUN 2
        self.i = i                   # RUN 2
                                     # RUN 2
    def filter(self, record):        # RUN 2
        self.i += 1                  # NEW LINE
        record.log_count = self.i    # RUN 2
        return True                  # RUN 2

Contents of python script log_format_test.py

import os
import sys
import logging

py_lib = os.environ.get('app_dir') + "/lib"
sys.path.append(py_lib)

import log_format as lf


logger = logging.getLogger(__name__)
l_level = 'INFO' #'DEBUG' #'INFO'
l_level = eval("logging." + l_level.upper())
logger.setLevel(l_level)

int_var = os.getpid()
i = 0
str_var = os.path.basename(__file__)

handler = logging.StreamHandler()
handler.setLevel(l_level)
lf_format = f'ZZZZZZZZ|%(asctime)s|{int_var}|%(log_count)s|{str_var}|%(message)s'
formatter = lf.Formatter(fmt=lf_format, datefmt='%Y-%m-%d %H:%M:%S.%f') # 2022-02-22 16:42:44.289193

obj_filter = lf.ContextFilter(i)               # NEW LINE
logger.addFilter(lf.ContextFilter(obj_filter)) # CHANGED LINE

handler.setFormatter(formatter)
logger.addHandler(handler)

logger.info("I am INFO 1")
logger.info("I am INFO 2")
logger.debug("I am DEBUG 3")

This results in printing the log as expected and I don't even have to manually increment i every time.

ZZZZZZZZ|2022-02-24 11:41:19.578733|20527|1|log_format_test.py|I am INFO 1
ZZZZZZZZ|2022-02-24 11:41:19.578868|20527|2|log_format_test.py|I am INFO 2

How to move ContextFilter class for logging to separate module?

1 Answers1