[FIXED] Does logger have a state in ipython?

Issue

I'm running a program that creates a logger and write info message to log once. When I run this program as python example.py I get the logging message once as expected:

minimal.py
----------

import handout
doc = handout.Handout('output')
doc.add_text('Print this text')

λ python minimal.py
Print this text

When I run same program several times using IPython runfile(), the logging messages accumulate. If I run it twice, on the nex run I fill get three messages instead of one:

> runfile('D:/github/handout/minimal.py', wdir='D:/github/handout')
Print this text
Print this text
Print this text

I wonder what may cause this logger behavour in IPython? Any clues appreciated.

Solution

I noticed that code in question had addHandler() hidden in __init__.py. IPython alone was actually killing the handlers on shutdown, while Spyder IDE was keeping them alive, discussion here

A more quick search path for this issue could have been:

• look addHandler calls in your codebase (I was looking in IPython and Spyder repos)

• prevent new handler creation if there are already some:

  import logging
  import sys
  
  logger = logging.getLogger('handout')
  logger.setLevel(logging.INFO)
  logger.propagate = False 
  if not logger.handlers:
      handler = logging.StreamHandler(sys.stdout)
      handler.setFormatter(logging.Formatter('%(message)s'))
      logger.addHandler(handler)
  

• remember logger is a singleton that lives on and can be accessed by its hame anywhere in the program

Workflow of logger vs handler is in the docs here.

Answered By - Evgeny