The Pythons logging framework is powerful, but gives you plenty of ways to shoot yourself in the foot. To make matters worse, logging mistakes are subtle and slip through code review easily.

The post Python Logging Traps by Simon Weber originally appeared on www.simonmweber.com

In his time at Venmo, Simon had seen logging mistakes cause everything from unneeded debugging to application crashes. Here are the most common culprits.

Manual Interpolation

Bad:

logger.info('My data: %s' % some_data)
# or, equivalently
logger.info('My data: {}'.format(some_data))

Good:

logger.info('My data: %s', some_data)

This pushes the interpolation off to the logging framework:

• Interpolation overhead is skipped if info level is not enabled.
• Encoding problems will not raise an exception (they’ll be logged instead).
• Tools like Sentry will be able to aggregate log messages intelligently.

Pylint will detect this antipattern as W1201 and W1202.

logger.error(…e) in exception handlers

Bad:

try:
    ...
except FooException as e:
    logger.error('Uh oh! Error: %s', e)

Good:

try:
    ...
except FooException:
    logger.exception('Uh oh!')

Formatting an exception throws away the traceback, which you usually want for debugging. logger.exception is a helper that calls logger.error but also logs the traceback.

Implicitly encoding unicode data

Bad:

checkmark = '√'.decode('utf-8')
logger.info('My data: %s', checkmark)

Good:

checkmark = '√'.decode('utf-8')
logger.info('My data: %r', checkmark)

Using %s with a unicode string will cause it to be encoded, which will cause an EncodingError unless your default encoding is UTF-8. Using %r will format the unicode in \u-escaped repr format instead.