Python logging repeated output

Question

I've been studying python logging since a few days and I'm testing it today at work. I'm testing the following code:

import inspect
import logging

def customLogger(FileHandlerlogLevel, ConsoleHandlerLogLevel, file_path_and_name):
    '''
    - logLevel input values:  DEBUG, INFO, WARNING, ERROR, CRITICAL
    '''

    # Gets the name of the class / method from where this method is called
    loggerName = inspect.stack()[1][3]

    logger = logging.getLogger(loggerName)

    logger.setLevel(logging.DEBUG)

    fileHandler = logging.FileHandler(file_path_and_name, mode="w")
    fileHandler.setLevel(FileHandlerlogLevel)

    formatter = logging.Formatter('%(name)s - %(lineno)d - %(asctime)s - %(levelname)s - %(message)s',
                                  datefmt="%m/%d/%Y %I:%M:%S %p")
    fileHandler.setFormatter(formatter)

    logger.addHandler(fileHandler)    

    stream_handler = logging.StreamHandler()
    stream_handler.setLevel(ConsoleHandlerLogLevel)
    stream_handler.setFormatter(formatter)
    logger.addHandler(stream_handler)


    return logger

test_logger = customLogger(logging.DEBUG,  logging.DEBUG,  "test_loggerv01.log")
test_logger.info("test 01")

So basically I have two handlers for a given logger. When I run the script the first time, this is what the console (Spyder) shows:

In [1]: runfile('C:/Users/aardem/Python_AA/AB/Corproates_Prj/custom_logger_andrea_v02.py', wdir='C:/Users/aardem/Python_AA/AB/Corproates_Prj')
<module> - 36 - 07/19/2018 06:32:22 PM - INFO - test 01

So far so good. Then, I change the info message to "test 02" (last line of my code), save and re-run the script. Now, the console shows the following:

In [2]: runfile('C:/Users/aardem/Python_AA/AB/Corproates_Prj/custom_logger_andrea_v02.py', wdir='C:/Users/aardem/Python_AA/AB/Corproates_Prj')
<module> - 36 - 07/19/2018 06:32:34 PM - INFO - test 02
<module> - 36 - 07/19/2018 06:32:34 PM - INFO - test 02

Again, if I change the last line of my script to:

test_logger.info("test 03")

then save and re-run the script, this is the new console output:

In [3]: runfile('C:/Users/aardem/Python_AA/AB/Corproates_Prj/custom_logger_andrea_v02.py', wdir='C:/Users/aardem/Python_AA/AB/Corproates_Prj')
<module> - 37 - 07/19/2018 06:38:20 PM - INFO - test 03
<module> - 37 - 07/19/2018 06:38:20 PM - INFO - test 03
<module> - 37 - 07/19/2018 06:38:20 PM - INFO - test 03

Can somebody help me with this unexpected problem? The same problem happens with the data saved inside the file "test_loggerv01.log". Thank you

user2357112 · Accepted Answer · 2018-07-19 22:45:48Z

3

Every time you run that file with runfile in the same IPython session, you're adding more and more handlers to the same logger. The old handlers don't go away.

All those duplicate handlers will handle that logger's log records, resulting in duplicate log handling.

answered Jul 19, 2018 at 22:45

user2357112

286k32 gold badges490 silver badges570 bronze badges

Sign up to request clarification or add additional context in comments.

3 Comments

Angelo Over a year ago

Thank you for the prompt answer. Would you have a suggestion please on how to avoid duplicate handlers?

user2357112 Over a year ago

Don't run this file over and over in the same IPython session, or if you really, really want to do that for some reason, save a reference to the handler you add so you can remove it later.

Angelo Over a year ago

Thank you. I also realized the following solution helps to fix my problem: stackoverflow.com/questions/28351287/…

martiangoblin · Accepted Answer · 2024-11-24 17:11:23Z

0

Here's my solution, based on the answer here by wim.

Create this file: .ipython/profile_default/startup/reload_logging.py

(Location of this directory may vary, use ipython locate profile to verify yours).

from IPython.core.magic import register_line_magic

@register_line_magic
def reload_logging(line):
    import logging
    from importlib import reload
    reload(logging)
    print("Logging module reloaded")

Then in ipython, you can simply run the line magic command %reload_logging to prevent duplicate messages.

answered Nov 24, 2024 at 17:11

martiangoblin

1097 bronze badges

Collectives™ on Stack Overflow

Python logging repeated output

2 Answers 2

3 Comments

Comments

Your Answer

Linked

Hot Network Questions

Collectives™ on Stack Overflow

2 Answers 2

3 Comments

Comments

Your Answer

Sign up or log in

Post as a guest

Linked

Related