Encountering duplicate log output when using the Python logging module is a surprisingly common frustration for developers. This issue, where the same log message appears multiple times in the console or file, can obscure critical information and make debugging a nightmare. It often stems from a misunderstanding of how Python’s logging hierarchy and handlers operate. Far from being a bug in the module itself, duplicate logging is typically a symptom of incorrect configuration within an application. Understanding the underlying mechanisms, such as logger propagation and handler management, is crucial to resolving this elusive problem. This guide will delve into the root causes of duplicate log messages and provide practical, actionable solutions to ensure your logs are clean, concise, and useful.

Understanding Python’s Logging Hierarchy and Propagation

The Python logging module is designed with a hierarchical structure, similar to a file system, where loggers are organized in a parent-child relationship. For instance, a logger named 'my_app.sub_module' is a child of 'my_app', which in turn is a child of the root logger. Log messages flow upwards through this hierarchy by default, a process known as “propagation.” When a message is logged by a child logger, it’s passed to its parent, and then to its parent’s parent, and so on, until it reaches the root logger. Each logger in this chain can have its own set of handlers.

This propagation mechanism is the primary reason for duplicate log output. If you attach a handler to a specific logger (e.g., 'my_app.sub_module') and also attach the same or a similar handler to its parent ('my_app') or the root logger, a message issued by 'my_app.sub_module' will be processed by its own handler, and then propagate upwards to 'my_app' where it’s processed by that handler, and potentially again by the root logger’s handler. Each handler processes the message and sends it to its destination, resulting in the message appearing multiple times.

A key aspect of this system is the root logger. If you don’t explicitly create and configure a named logger, your messages will default to the root logger. The logging.basicConfig() function, often used for simple logging setups, configures the root logger. If you then create custom loggers and add handlers to them, but also leave the root logger configured with its own handler, messages might propagate to the root logger and be handled again, leading to duplicate output. This behavior is by design and provides flexibility, but it requires careful management of handlers across the logger hierarchy.

According to the official Python logging documentation, “Loggers have a concept of ‘effective level’. If a logger’s level is not explicitly set, its effective level is its parent’s effective level.” This concept extends to handlers, where messages propagate unless explicitly stopped.

Common Causes and Effective Solutions for Duplicate Logs

Understanding why duplicate log output occurs is the first step; fixing it requires addressing specific configuration patterns. One of the most frequent culprits is adding handlers to a logger multiple times. This often happens in scripts that are reloaded, or when a logging setup function is called more than once. Another common scenario involves the interaction between custom loggers and the default root logger.

1. Adding Handlers Multiple Times

If you execute code that adds a handler to a logger every time it runs (e.g., within a function called repeatedly, or in a script that’s reloaded in an interactive session), you’ll end up with duplicate handlers attached to the same logger. Each handler will then process every message, leading to multiple identical outputs. This is particularly prevalent in development environments like Jupyter notebooks or when running tests repeatedly.

To prevent this, always check if a handler already exists on a logger before adding it. Here’s a common pattern:

import logging logger = logging.getLogger(__name__) logger.setLevel(logging.INFO) if not logger.handlers: Add a stream handler if none exist handler = logging.StreamHandler() formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s') handler.setFormatter(formatter) logger.addHandler(handler) logger.info("This message should only appear once.") 

2. Logger Propagation

As discussed, messages propagate up the logger hierarchy. If a child logger sends a message, and both the child and its parent (or ancestors, including the root logger) have handlers configured, the message will be processed by each handler. The simplest solution is to disable propagation for specific loggers where you’ve already handled the message at the child level.

import logging Get a custom logger app_logger = logging.getLogger('my_app') app_logger.setLevel(logging.INFO) Add a handler to the custom logger app_handler = logging.StreamHandler() app_formatter = logging.Formatter('%(name)s: %(message)s') app_handler.setFormatter(app_formatter) app_logger.addHandler(app_handler) IMPORTANT: Disable propagation to the root logger app_logger.propagate = False Get a child logger child_logger = logging.getLogger('my_app.sub_module') child_logger.setLevel(logging.INFO) Child logger does not need its own handler if parent handles it child_logger.info("This message should only be handled by 'my_app's handler.") 

Setting logger.propagate = False ensures that messages from that logger are not passed to its parent loggers, effectively stopping the duplicate output from higher-level handlers.

3. Misuse of logging.basicConfig()

logging.basicConfig() is a convenient function for a quick, basic logging setup. However, it’s designed to be called only once. If you call it multiple times, it will not reconfigure the root logger unless you pass force=True (Python 3.8+) or explicitly remove existing handlers. The problem often arises when basicConfig() sets up a handler on the root logger, and then you set up custom loggers with their own handlers, allowing propagation to the already configured root logger.

Consider this problematic pattern:

In module A import logging logging.basicConfig(level=logging.INFO) Configures root logger logging.info("Message from module A") In module B (or later in module A) import logging my_logger = logging.getLogger("my_module") my_logger.setLevel(logging.INFO) my_logger.addHandler(logging.StreamHandler()) Adds another handler my_logger.info("Message from my_module") This might appear twice 

To fix this, either rely solely on basicConfig() for simple scripts, or for more complex applications, configure all loggers and handlers explicitly without using basicConfig() after the initial setup. For library code, it’s best practice not to configure logging at all, but rather to let the application using the library handle the logging configuration. For more on this, check out this Real Python guide on logging.

Best Practices for Robust Logging Configurations

To avoid the pitfalls of duplicate log output and establish a maintainable logging system, adhering to certain best practices is essential. A well-structured logging setup not only prevents redundant messages but also simplifies debugging and monitoring of your applications. Centralized configuration and careful handler management are paramount.

1. Centralize Logging Configuration: Define Question & Answer :
   I am using python logger. The following is my code:

   import os import time import datetime import logging class Logger : def myLogger(self): logger = logging.getLogger('ProvisioningPython') logger.setLevel(logging.DEBUG) now = datetime.datetime.now() handler=logging.FileHandler('/root/credentials/Logs/ProvisioningPython'+ now.strftime("%Y-%m-%d") +'.log') formatter = logging.Formatter('%(asctime)s %(levelname)s %(message)s') handler.setFormatter(formatter) logger.addHandler(handler) return logger 
   

   The problem I have is that I get multiple entries in the log file for each logger.info call. How can I solve this?

   Function logging.getLogger() returns the same instance for a given name.

   The problem is that every time you call myLogger(), it’s adding another handler to the instance, which causes the duplicate logs.

   Perhaps something like this?

   import os import time import datetime import logging loggers = {} def myLogger(name): global loggers if loggers.get(name): return loggers.get(name) else: logger = logging.getLogger(name) logger.setLevel(logging.DEBUG) now = datetime.datetime.now() handler = logging.FileHandler( '/root/credentials/Logs/ProvisioningPython' + now.strftime("%Y-%m-%d") + '.log') formatter = logging.Formatter('%(asctime)s %(levelname)s %(message)s') handler.setFormatter(formatter) logger.addHandler(handler) loggers[name] = logger return logger