How to define a logger in python once for the whole program?

Question

I want to set up my logger once in my Python project and use that throughout the project.

main.py:

import logging
import test    

hostname = {"hostname": socket.gethostname()}
logger = logging.getLogger()
syslog = logging.StreamHandler()
formatter = logging.Formatter("{\"label\":\"%(name)s\", \"level\":\"%(levelname)s\", \"hostname\":\"%(hostname)s\", \"logEntry\": %(message)s, \"timestamp\", \"%(asctime)s\"}")
syslog.setFormatter(formatter)
logger.setLevel(logging.DEBUG)
logger.addHandler(syslog)
logger = logging.LoggerAdapter(logger, hostname)

def entry_point():
    logger.debug("entry_point")
    test.test_function()

entry_point()

test.py:

import logging

logger = logging.getLogger()
logger.setLevel(logging.DEBUG)

def test_function():
    logger.debug("test_function")

This should give me:

entry_point
test_function

... both formatted with the format provider.

However I actually get an error KeyError: 'hostname' because it would seem the second logger does not know about the hostname format provider. I've also tried initialising both loggers with __name__ but then I get No handlers could be found for logger "test".

Is there a way I can define my logging configuration once and re-use it throughout my application?

You can do `import main` then `main.logger.debug()`. Better yet, wrap your configuration in a function or a class. — Code-Apprentice, Jun 15 '18 at 14:19
@Code-Apprentice: if `main.py` is the main script, then it'll first be imported as the `'__main__'` module. A separate `import main` line would *again* load and run the file, now as the `'main'` module, and you then have two separate `LogAdapter` objects, and two handlers added separately to the root logger. — Martijn Pieters, Jun 15 '18 at 16:56
@MartijnPieters Good to know. I'll have to spend some more time learning about `logging` and its mechanics. — Code-Apprentice, Jun 15 '18 at 17:37
@Code-Apprentice: this is generic issue with the script being 'imported' as `__main__` so other imports of the script-as-a-module can create issues. — Martijn Pieters, Jun 15 '18 at 18:02

Martijn Pieters · Accepted Answer · 2018-06-18T13:53:11.170

A LoggingAdapter is a separate object, it does not replace the result of logging.getLogger() calls. You'll need to store it somewhere that it can be shared between different modules. You could use a separate module that everything else in your project imports from, for example.

I'll detail below how to handle this, but there is also an alternative that doesn't involve adapters at all, and instead uses a filter which is attached to the handler you created, letting you avoid having to deal with adapters altogether. See further down.

I'd separate out configuration and log object handling too; have the main module call the 'setup' function to configure the handlers and log levels, and set up the adapter in the module for others to import:

log.py:

import logging
import socket
def setup_logging():
    """Adds a configured stream handler to the root logger"""
    syslog = logging.StreamHandler()
    formatter = logging.Formatter(
        '{"label":"%(name)s", "level":"%(levelname)s",'
        ' "hostname":"%(hostname)s", "logEntry": %(message)s,'
        ' "timestamp", "%(asctime)s"}')
    syslog.setFormatter(formatter)

    logger = logging.getLogger()
    logger.addHandler(syslog)
    logger.setLevel(logging.DEBUG)


def host_log_adapter(logger):
    hostname = {"hostname": socket.gethostname()}
    return logging.LoggerAdapter(logger, hostname)


logger = host_log_adapter(logging.getLogger())

Then in main do:

import log
import test

log.setup_logging()

def entry_point():
    log.logger.debug("entry_point")
    test.test_function()

entry_point()

and in test:

from log import logger

def test_function():
    logger.debug("test_function")

Alternatively, rather than use an adapter, you could add information to log records by (ab)using a filter:

class HostnameInjectingFilter(logging.Filter):
    def __init__(self):
        self.hostname = socket.gethostname()}
    def filter(self, record):
        record.hostname = self.hostname
        return True

This adds the extra field directly on the record object and always returns True. Then just add this filter to the handler that needs to have the hostname available:

syslog = logging.StreamHandler()
formatter = logging.Formatter(
    '{"label":"%(name)s", "level":"%(levelname)s",'
    ' "hostname":"%(hostname)s", "logEntry": %(message)s,'
    ' "timestamp", "%(asctime)s"}')
syslog.setFormatter(formatter)
syslog.setFilter(HostnameInjectingFilter())

This removes the need to use an adapter entirely, so you can remove the host_log_adapter() function entirely and just use logging.getLogger() everywhere.

Strangely when I run this code on my Rapsberry PI I get two log outs. One at the correct log level without any formatting, another at ERROR level with the correct formatting. Do I need to set it up like this... https://gist.github.com/timss/8f03ae681256f21e25f8b0a16327c26c — Remotec, Jun 18 '18 at 10:46
@Remotec: I can't reproduce that. With the code in my answer, there are two entries logged, both at DEBUG level. Nothing in this configuration would cause the log level to change. The other configuration is more complex, in that it directs logging to two different streams (stdout and stderr) and puts a maximum severity level on one of those (normally filtering is done only for a minimum severity level). This lets you put your most critical messages to stderr (WARNING, ERROR and CRITICAL) with the rest going to stdout (INFO and DEBUG). That code doesn't alter message severity either. — Martijn Pieters, Jun 18 '18 at 11:16
@Martjin: yes it's really quite strange. This code works fine on my Windows machine and also on the Raspberry PI. It is eventually run as an AWS Lambda function through their Greengrass technology. Then I always get two log entries one at the correct level and another at error level Interestingly the error entry always reports this module: __init__.py:880 — Remotec, Jun 18 '18 at 12:00
@Remotec: Presumably that's because [AWS Lambda also sets up logging](https://docs.aws.amazon.com/lambda/latest/dg/python-logging.html). — Martijn Pieters, Jun 18 '18 at 12:02
@Remotec: You want to take a look at [Using python Logging with AWS Lambda](//stackoverflow.com/q/37703609) if you want to re-configure the handlers that AWS lambda puts in place. — Martijn Pieters, Jun 18 '18 at 12:05
I think this is in the right direction. I've create a new question here: https://stackoverflow.com/questions/50909824/getting-logs-twice-in-aws-lambda-function. Unfortunately the code to get the host name although working won't be used now as when the Lambda runs it does so in a sandbox environment which means no host name is reported. I've marked the question as correct though. — Remotec, Jun 18 '18 at 12:45
@Remotec: right, I've answered there. Note that I also updated this answer to add a better alternative that avoids using an adapter altogether. — Martijn Pieters, Jun 18 '18 at 13:55

How to define a logger in python once for the whole program?

1 Answers1

Linked