160

My current format string is:

formatter = logging.Formatter('%(asctime)s : %(message)s')

and I want to add a new field called app_name which will have a different value in each script that contains this formatter.

import logging
formatter = logging.Formatter('%(asctime)s %(app_name)s : %(message)s')
syslog.setFormatter(formatter)
logger.addHandler(syslog)

But I'm not sure how to pass that app_name value to the logger to interpolate into the format string. I can obviously get it to appear in the log message by passing it each time but this is messy.

I've tried:

logging.info('Log message', app_name='myapp')
logging.info('Log message', {'app_name', 'myapp'})
logging.info('Log message', 'myapp')

but none work.

2
  • 2
    Do you really want to pass this in to every log call? If so, look at the docs where it says "This functionality can be used to inject your own values into a LogRecord…" But this seems like a prime case for using logger = logging.getLogger('myapp') and having it baked into the logger.info call.
    – abarnert
    Jul 9, 2013 at 21:39
  • the python logging can already do that afaik. if you use a different logger object in each app, you can make each one use a different name by instantiating your loggers like so: logger = logging.getLogger(myAppName). note that __name__ is the python module name, so if each app is its own python module, that would work as well. Mar 13, 2020 at 7:03

9 Answers 9

203

You could use a LoggerAdapter so you don't have to pass the extra info with every logging call:

import logging
extra = {'app_name':'Super App'}

logger = logging.getLogger(__name__)
syslog = logging.StreamHandler()
formatter = logging.Formatter('%(asctime)s %(app_name)s : %(message)s')
syslog.setFormatter(formatter)
logger.setLevel(logging.INFO)
logger.addHandler(syslog)

logger = logging.LoggerAdapter(logger, extra)
logger.info('The sky is so blue')

logs (something like)

2013-07-09 17:39:33,596 Super App : The sky is so blue

Filters can also be used to add contextual information.

import logging

class AppFilter(logging.Filter):
    def filter(self, record):
        record.app_name = 'Super App'
        return True

logger = logging.getLogger(__name__)
logger.addFilter(AppFilter())
syslog = logging.StreamHandler()
formatter = logging.Formatter('%(asctime)s %(app_name)s : %(message)s')
syslog.setFormatter(formatter)
logger.setLevel(logging.INFO)
logger.addHandler(syslog)

logger.info('The sky is so blue')

produces a similar log record.

4
  • 5
    How can we specify that in a config.ini file? I wish to add the current host name socket.gethostname(). Aug 27, 2016 at 8:41
  • I have this sample not working for me. import uuid uniqueId = str(uuid.uuid4()) extra = {"u_id" : uniqueId} RotatingHandler = RotatingFileHandler(LOG_FILENAME,encoding='utf-8',maxBytes=maxSize, backupCount=batchSize) logger.basicConfig(handlers=[RotatingHandler],level=logLevel.upper(),format='%(levelname)s %(u_id)s %(funcName)s %(asctime)s %(message)s ',datefmt='%m/%d/%Y %I:%M:%S %p') logger = logger.LoggerAdapter(logger=logger, extra=extra)
    – Hayat
    Oct 22, 2018 at 10:40
  • Is it possible to add a field "level" which is equal to "levelname"? See: How can I rename “levelname” to “level” in Python log messages? Oct 22, 2018 at 12:35
  • 2
    Can I just pass a string of Extra Info. Something like this: "Error occurred for employee ID 1029382" Without creating any dictionary. Mar 14, 2019 at 10:25
86

Python3

As of Python3.2 you can now use LogRecordFactory

import logging

logging.basicConfig(format="%(custom_attribute)s - %(message)s")

old_factory = logging.getLogRecordFactory()

def record_factory(*args, **kwargs):
    record = old_factory(*args, **kwargs)
    record.custom_attribute = "my-attr"
    return record

logging.setLogRecordFactory(record_factory)
>>> logging.info("hello")
my-attr - hello

Of course, record_factory can be customized to be any callable and the value of custom_attribute could be updated if you keep a reference to the factory callable.

Why is that better than using Adapters / Filters?

  • You do not need to pass your logger around the application
  • It actually works with 3rd party libraries that use their own logger (by just calling logger = logging.getLogger(..)) would now have the same log format. (this is not the case with Filters / Adapters where you need to be using the same logger object)
  • You can stack/chain multiple factories
12
  • Is any alternative for python 2.7?
    – karolch
    Dec 18, 2019 at 10:06
  • Not with the same benefits, with 2.7 you'd have to go with Adapters or Filters.
    – Ahmad
    Jan 6, 2020 at 14:01
  • 11
    This is nowaday's python3 best answer
    – Stéphane
    May 9, 2020 at 13:21
  • 1
    According to docs.python.org/3/howto/logging-cookbook.html: This pattern allows different libraries to chain factories together, and as long as they don’t overwrite each other’s attributes or unintentionally overwrite the attributes provided as standard, there should be no surprises. However, it should be borne in mind that each link in the chain adds run-time overhead to all logging operations, and the technique should only be used when the use of a Filter does not provide the desired result.
    – steve0hh
    Jun 19, 2020 at 16:58
  • 1
    @steve0hh one of the key desired results is the ability to log contextual information across different libraries/modules, which could only be achieved using this way. In most circumstances, libraries should not be touching the logger configuration, it's the responsibility of the parent application.
    – Ahmad
    Jun 20, 2020 at 18:59
68

You need to pass the dict as a parameter to extra to do it that way.

logging.info('Log message', extra={'app_name': 'myapp'})

Proof:

>>> import logging
>>> logging.basicConfig(format="%(foo)s - %(message)s")
>>> logging.warning('test', extra={'foo': 'bar'})
bar - test 

Also, as a note, if you try to log a message without passing the dict, then it will fail.

>>> logging.warning('test')
Traceback (most recent call last):
  File "/usr/lib/python2.7/logging/__init__.py", line 846, in emit
    msg = self.format(record)
  File "/usr/lib/python2.7/logging/__init__.py", line 723, in format
    return fmt.format(record)
  File "/usr/lib/python2.7/logging/__init__.py", line 467, in format
    s = self._fmt % record.__dict__
KeyError: 'foo'
Logged from file <stdin>, line 1
5
  • Will this also work for logging.info()? It failed when I tried last. :/
    – praxmon
    Dec 3, 2015 at 6:09
  • 4
    I like @mr2ert answer. You can give a default value to the extra field by extending the logging.Formatter class: class CustomFormatter(logging.Formatter): def format(self, record): if not hasattr(record, 'foo'): record.foo = 'default_foo' return super(CustomFormatter, self.format(record) h = loggin.StreamHandler() h.setFormatter(CustomFormatter('%(foo)s %(message)s') logger = logging.getLogger('bar') logger.addHandler(h) logger.error('hey!', extra={'foo': 'FOO'}) logger.error('hey!')
    – loutre
    Mar 4, 2016 at 11:21
  • This method is faster but you need to add the extra lines on each log message which is easy to forget and prone to errors. Replacing the super() calls is messier than the answer from unutbu.
    – pevogam
    Apr 21, 2016 at 14:12
  • @Prakhar Mohan Srivastava Yes It'll work fine for logging.info() as well. What error message are you getting ? Mar 14, 2019 at 10:23
  • Can I just pass a string of Extra Info. Something like this: "Error occurred for employee ID 1029382" Without creating any dictionary and passing the keys Mar 14, 2019 at 10:26
17

Another way is to create a custom LoggerAdapter. This is particularly useful when you can't change the format OR if your format is shared with code that does not send the unique key (in your case app_name):

class LoggerAdapter(logging.LoggerAdapter):
    def __init__(self, logger, prefix):
        super(LoggerAdapter, self).__init__(logger, {})
        self.prefix = prefix

    def process(self, msg, kwargs):
        return '[%s] %s' % (self.prefix, msg), kwargs

And in your code, you would create and initialize your logger as usual:

    logger = logging.getLogger(__name__)
    # Add any custom handlers, formatters for this logger
    myHandler = logging.StreamHandler()
    myFormatter = logging.Formatter('%(asctime)s %(message)s')
    myHandler.setFormatter(myFormatter)
    logger.addHandler(myHandler)
    logger.setLevel(logging.INFO)

Finally, you would create the wrapper adapter to add a prefix as needed:

    logger = LoggerAdapter(logger, 'myapp')
    logger.info('The world bores you when you are cool.')

The output will look something like this:

2013-07-09 17:39:33,596 [myapp] The world bores you when you are cool.
7

I found this SO question after implementing it myself. Hope it helps someone. In the code below, I'm inducing an extra key called claim_id in the logger format. It will log the claim_id whenever there is a claim_id key present in the environment. In my use case, I needed to log this information for an AWS Lambda function.

import logging
import os

LOG_FORMAT = '%(asctime)s %(name)s %(levelname)s %(funcName)s %(lineno)s ClaimID: %(claim_id)s: %(message)s'


class AppLogger(logging.Logger):

    # Override all levels similarly - only info overriden here

    def info(self, msg, *args, **kwargs):
        return super(AppLogger, self).info(msg, extra={"claim_id": os.getenv("claim_id", "")})


def get_logger(name):
    """ This function sets log level and log format and then returns the instance of logger"""
    logging.setLoggerClass(AppLogger)
    logging.basicConfig(level=logging.INFO, format=LOG_FORMAT)
    logger = logging.getLogger(name)
    logger.setLevel(logging.INFO)
    return logger


LOGGER = get_logger(__name__)

LOGGER.info("Hey")
os.environ["claim_id"] = "12334"
LOGGER.info("Hey")

Gist: https://gist.github.com/ygivenx/306f2e4e1506f302504fb67abef50652

5

The accepted answer did not log the format in logfile, whereas the format was reflected in sys output. Alternatively I used a simpler approach and worked as;

logging.basicConfig(filename="mylogfile.test",
                    filemode="w+",
                    format='%(asctime)s: ' +app_name+': %(message)s ',
                    level=logging.DEBUG)

1
  • simple and easy! May 21, 2023 at 11:29
3

If you need a default extra mapping, and you want to customize it for ad-hoc log messages, this works in Python 2.7+ by creating a LoggerAdapter that merges a default extra dictionary with any extra from a given message.

import logging
import os
import sys

logging.basicConfig(
    level=logging.DEBUG,
    format='%(asctime)s %(levelname)-8s Py%(python)-4s pid:%(pid)-5s %(message)s',
)
_logger = logging.getLogger("my-logger")
_logger.setLevel(logging.DEBUG)


class DefaultExtrasAdapter(logging.LoggerAdapter):
    def __init__(self, logger, extra):
        super(DefaultExtrasAdapter, self).__init__(logger, extra)

    def process(self, msg, kwargs):
        # Speed gain if no extras are present
        if "extra" in kwargs:
            copy = dict(self.extra).copy()
            copy.update(kwargs["extra"])
            kwargs["extra"] = copy
        else:
            kwargs["extra"] = self.extra
        return msg, kwargs


LOG = DefaultExtrasAdapter(_logger, {"python": sys.version_info[0], "pid": os.getpid()})

if __name__ == "__main__":
    LOG.info("<-- With defaults")
    LOG.info("<-- With my version", extra={"python": 3.10})
    LOG.info("<-- With my pid", extra={"pid": 0})
    LOG.info("<-- With both", extra={"python": 2.7, "pid": -1})

Results:

2021-08-05 18:58:27,308 INFO     Py2    pid:8435  <-- With defaults
2021-08-05 18:58:27,309 INFO     Py3.1  pid:8435  <-- With my version
2021-08-05 18:58:27,309 INFO     Py2    pid:0     <-- With my pid
2021-08-05 18:58:27,309 INFO     Py2.7  pid:-1    <-- With both
0

Using mr2ert's answer, I came up with this comfortable solution (Though I guess it's not recommended) - Override the built-in logging methods to accept the custom argument and create the extra dictionary inside the methods:

import logging

class CustomLogger(logging.Logger):

   def debug(self, msg, foo, *args, **kwargs):
       extra = {'foo': foo}

       if self.isEnabledFor(logging.DEBUG):
            self._log(logging.DEBUG, msg, args, extra=extra, **kwargs)

   *repeat for info, warning, etc*

logger = CustomLogger('CustomLogger', logging.DEBUG)
formatter = logging.Formatter('%(asctime)s [%(foo)s] %(message)s') 
handler = logging.StreamHandler()
handler.setFormatter(formatter) 
logger.addHandler(handler)

logger.debug('test', 'bar')

Output:

2019-03-02 20:06:51,998 [bar] test

This is the built in function for reference:

def debug(self, msg, *args, **kwargs):
    """
    Log 'msg % args' with severity 'DEBUG'.

    To pass exception information, use the keyword argument exc_info with
    a true value, e.g.

    logger.debug("Houston, we have a %s", "thorny problem", exc_info=1)
    """
    if self.isEnabledFor(DEBUG):
        self._log(DEBUG, msg, args, **kwargs)
0

import logging;

class LogFilter(logging.Filter):

def __init__(self, code):
    self.code = code

def filter(self, record):
    record.app_code = self.code
    return True

logging.basicConfig(format='[%(asctime)s:%(levelname)s]::[%(module)s -> %(name)s] - APP_CODE:%(app_code)s - MSG:%(message)s');

class Logger:

def __init__(self, className):
    self.logger = logging.getLogger(className)
    self.logger.setLevel(logging.ERROR)

@staticmethod
def getLogger(className):
    return Logger(className)

def logMessage(self, level, code, msg):
    self.logger.addFilter(LogFilter(code))

    if level == 'WARN':        
        self.logger.warning(msg)
    elif level == 'ERROR':
        self.logger.error(msg)
    else:
        self.logger.info(msg)

class Test: logger = Logger.getLogger('Test')

if __name__=='__main__':
    logger.logMessage('ERROR','123','This is an error')
1
  • 1
    This implementation will be very inefficient.
    – blakev
    May 29, 2020 at 20:56

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Not the answer you're looking for? Browse other questions tagged or ask your own question.