Custom extra data in python log with multiple modules

Question

I'm trying to implement a logger in python that involves many modules. The core functionality involves a gRPC microservice which takes a payload, generates an id and does some optimization.

When multiple requests come in at once, the log can get jumbled up. What I would like to do is tag the logger lines with a the run_id so that the run_id prints in the log for each function call made in the parent and all imported modules.

I tried this:

logger = logging.getLogger("myservice")
log_file = "logs/solver.log"
formatter = logging.Formatter("%(asctime)s - %(levelname)s - %(log_id)s - %(name)s - %(message)s", datefmt="%y/%m/%d %H:%M:%S")  #: log_id is custom data
log_data = {'log_id': None}

concise_log = logging.FileHandler(log_file)                 #: file handler for concise log
concise_log.setLevel(logging.INFO)
concise_log.setFormatter(formatter)

#: Add the logging hanlders to the logger
logger.addHandler(concise_log)
logger.addHandler(detailed_log)

logger.info(f"log_file: {log_file}", extra=log_data)
logger.info("LOG START", extra=log_data)
logger.debug("Debug level messages are being recorded.", extra=log_data)

I used a dummy value for log_data initially because the logger will error out otherwise.

Later on I set the log_id and log various things like so:

    log_id = str(uuid.uuid4())
    log_data = {'log_id': log_id}      #: extra data for logger

    #: load the server config:
    logger.info("loading server config...", extra=log_data)

This works fine, but if I make calls to my logger in any imported function, it will error out because those functions don't have log_data.

What I would like to be able to do is set the log_id in a more global way so that the logger always has the right log_id in the imported modules, which will change from request to request.

Is there another pattern that I should be using to accomplish this?

blues · Accepted Answer · 2020-04-03 14:53:17Z

2

This is best done with a LoggerAdapter. The official documentation has an excellent example that is very close to what you are trying to do. The code will approximately look like this:

class LogIdAdapter(logging.LoggerAdapter):
    def process(self, msg, kwargs):
        return '[%s] %s' % (self.extra['log_id'], msg), kwargs

tmp_logger = logging.getLogger("myservice")
# ... set up handlers etc here. do not include log_id in formatter, it will be added later
logger = LogIdAdapter(tmp_logger, {'log_id': str(uuid.uuid4())})

logger.info("some text") # this log will have log_id prepended

answered Apr 3, 2020 at 14:53

blues

5,2743 gold badges26 silver badges46 bronze badges

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

3 Comments

Sledge Over a year ago

Does the child module inherit the id from the log adapter as well, or would I need to somehow pass the id to the child as well?

blues Over a year ago

The adapter is a wrapper around the logger. So it doesn't touch the logger object itself. Does that answer your question?

Sledge Over a year ago

I see what you're saying about the logger adapter as a wrapper. I think the real answer to my question is that i still need to pass additional data into my imported function if I want calls to the logger in those functions to be aware of my id.

Collectives™ on Stack Overflow

Custom extra data in python log with multiple modules

1 Answer 1

3 Comments

Your Answer

Hot Network Questions

Collectives™ on Stack Overflow

1 Answer 1

3 Comments

Your Answer

Sign up or log in

Post as a guest

Related