1

I'm trying to log messages into sys.stdout and a file using my own function to set the same format. When I log into the file or outside the function everything works as expected. When I send the message to my function I get duplicates:

def log(lvl, msg):
    logging.basicConfig(level=logging.DEBUG,
                        format='%(asctime)s %(levelname)-8s %(message)s',
                        datefmt='%Y-%m-%d %H:%M:%S',
                        filename='/tmp/test.log',
                        filemode='a')

    console = logging.StreamHandler(sys.stdout)
    console.setLevel(logging.INFO)
    formatter = logging.Formatter('%(levelname)-8s %(message)s')
    console.setFormatter(formatter)
    logging.getLogger('').addHandler(console)
    logging.log(lvl, "%s: %s" % (options.build_node, msg))

if __name__ == "__main__":

    print "Executing outside of the function"
    logging.basicConfig(level=logging.DEBUG,
                        format='%(asctime)s %(levelname)-8s %(message)s',
                        datefmt='%Y-%m-%d %H:%M:%S',
                        filename='/tmp/test.log',
                        filemode='a')
    console = logging.StreamHandler(sys.stdout)
    console.setLevel(logging.INFO)
    formatter = logging.Formatter('%(levelname)-8s %(message)s')
    console.setFormatter(formatter)
    logging.getLogger('').addHandler(console)
    logging.log(logging.INFO, "some message")
    logging.log(logging.ERROR, "some error message")
    logging.log(logging.WARN, "Warning message")
    logging.log(logging.INFO, "another info message")     

    print "\nNow calling the log function"
    log(logging.INFO, "some message")
    log(logging.ERROR, "some error message")
    log(logging.WARN, "Warning message")
    log(logging.INFO, "another info message")

And the output I get is:

Executing outside of the function
INFO     some message
ERROR    some error message
WARNING  Warning message
INFO     another info message

Now calling the log function
INFO     None: some message
INFO     None: some message
ERROR    None: some error message
ERROR    None: some error message
ERROR    None: some error message
WARNING  None: Warning message
WARNING  None: Warning message
WARNING  None: Warning message
WARNING  None: Warning message
INFO     None: another info message
INFO     None: another info message
INFO     None: another info message
INFO     None: another info message
INFO     None: another info message

and the log file content is as expected:

2016-05-10 09:38:15 INFO     some message
2016-05-10 09:38:15 ERROR    some error message
2016-05-10 09:38:15 WARNING  Warning message
2016-05-10 09:38:15 INFO     another info message
2016-05-10 09:38:15 INFO     None: some message
2016-05-10 09:38:15 ERROR    None: some error message
2016-05-10 09:38:15 WARNING  None: Warning message
2016-05-10 09:38:15 INFO     None: another info message

I can't find out what is wrong with my log(lvl, msg) function. Something causes it to propagate the message to the stdout with a duplication with each call. What am I missing?

Thanks in advance

2 Answers 2

5

logging.getLogger('').addHandler(console) is adding an handler each time you call the function log, that's why you have duplicated messages.

3

You're only supposed to set configuration once, not every time you log. Each call to log adds an extra console handler to the root logger so the number of messages keeps increasing.

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.