Avoid common logging mistakes¶

The question. Log messages are missing, duplicated, or expensive to produce — and you can't work out why. Something in the configuration is fighting you. You want the short list of traps and the fix for each.

The answer: use %s formatting (not f-strings), configure once at the entry point (never in libraries), log exceptions with logger.exception, and watch out for the logger-vs-handler level gotcha. The full catalogue follows.

In [ ]:

# The canonical logger setup plus the four most common traps in one cell.
import logging

# (1) Module-level named logger — always __name__ in real code. One per module.
log = logging.getLogger('demo-module')
log.setLevel(logging.DEBUG)

# We add a handler just so this cell shows output; in real code the app does this once.
if not log.handlers:
    h = logging.StreamHandler()
    h.setFormatter(logging.Formatter('%(name)s - %(levelname)s: %(message)s'))
    log.addHandler(h)
    log.propagate = False         # don't duplicate via root

expensive_value = sum(range(1000))

# (2) %s formatting, not f-strings — the args aren't formatted unless the record
#     will actually be emitted. f-strings format eagerly and cost you even when
#     the level is filtered out.
log.debug('computed value: %s', expensive_value)   # lazy
# log.debug(f'computed value: {expensive_value}')  # eager — avoid

# (3) Log exceptions with .exception() — it captures the traceback. Plain .error()
#     gives you the message without the stack, which is almost always the wrong call
#     when there's a live exception.
try:
    1 / 0
except ZeroDivisionError:
    log.exception('division failed')    # == log.error(msg, exc_info=True)

# (4) Guard handler setup so repeated configuration doesn't create duplicates.
#     `if not log.handlers:` above does this for the cell; dictConfig with
#     `disable_existing_loggers: False` does it at the app level.
log.info('message appears exactly once')

# The canonical logger setup plus the four most common traps in one cell. import logging # (1) Module-level named logger — always __name__ in real code. One per module. log = logging.getLogger('demo-module') log.setLevel(logging.DEBUG) # We add a handler just so this cell shows output; in real code the app does this once. if not log.handlers: h = logging.StreamHandler() h.setFormatter(logging.Formatter('%(name)s - %(levelname)s: %(message)s')) log.addHandler(h) log.propagate = False # don't duplicate via root expensive_value = sum(range(1000)) # (2) %s formatting, not f-strings — the args aren't formatted unless the record # will actually be emitted. f-strings format eagerly and cost you even when # the level is filtered out. log.debug('computed value: %s', expensive_value) # lazy # log.debug(f'computed value: {expensive_value}') # eager — avoid # (3) Log exceptions with .exception() — it captures the traceback. Plain .error() # gives you the message without the stack, which is almost always the wrong call # when there's a live exception. try: 1 / 0 except ZeroDivisionError: log.exception('division failed') # == log.error(msg, exc_info=True) # (4) Guard handler setup so repeated configuration doesn't create duplicates. # `if not log.handlers:` above does this for the cell; dictConfig with # `disable_existing_loggers: False` does it at the app level. log.info('message appears exactly once')

Why each trap bites¶

f-strings vs %-args. log.debug(f'{expensive()}') runs expensive() every time, even when the logger's level is WARNING and the message will never be emitted. log.debug('%s', expensive()) also runs expensive() — but log.debug('user %s logged in', user_id) does not format the string unless the record is actually kept. The difference matters mostly for format calls with real expense (a repr() of a big structure, a DB roundtrip for a label). Default to %s.

Libraries don't configure. A library that calls logging.basicConfig() fights with the application for control. The convention is: library creates a logger with getLogger(__name__) and optionally attaches a NullHandler to suppress the 'no handlers' warning. The app decides what to do with those records.

logger.exception vs logger.error. exception is error + exc_info=True. Inside an except block you almost always want the traceback — that's the diagnostic you'll come back to at 3 a.m.

Logger level AND handler level. Both gates must open for a record to emerge. A handler at DEBUG on a logger whose level is still WARNING (the default, inherited from root) won't show DEBUG messages. Set the logger's level explicitly.

Don't use the root logger directly. logging.info(...) writes via the root logger and doesn't tell you which module produced it. Named loggers (via __name__) make the source obvious in every line.

Duplicate handlers. Calling a setup_logging() helper twice adds two handlers; every message now appears twice. Guard with if not logger.handlers:, or configure once via dictConfig at startup.

Don't log secrets. Log files end up in backups, monitoring systems, bug reports, emails. Passwords, API keys, full request bodies — assume they'll be seen by someone who shouldn't have them.

Checklist¶

Do	Do not
log.info('user %s done', user_id)	log.info(f'user {user_id} done')
Configure once at the app entry point	Configure inside a library
log.exception('blew up') inside except	log.error('blew up') — no traceback
logging.getLogger(__name__)	logging.info(...) directly
Set both the logger level and the handler level	Set only one and wonder why DEBUGs vanish
Guard handler setup with if not log.handlers:	Add handlers unconditionally
Redact or omit sensitive fields	Log passwords, tokens, PII

Each of these is a pattern. For the rare case where the default doesn't fit — an app that really does log every call via the root logger on purpose, say — it's fine. The traps bite when the shortcut is applied reflexively.

Related reading¶

• Configure logging for a project — the dictConfig shape that solves the 'configure once' and 'no duplicates' traps together.
• Create custom log handlers — when you need a destination the built-ins don't cover.
• Understanding log levels — what DEBUG/INFO/WARNING/ERROR should actually mean.
• Why logging, not print — when to reach for the log and when not to.