Logging module does not print in IPython

Question

The following code does print 'I want this to print' in 'ipython qtconsole', however it does not print in plain IPython.

import logging
import logging.handlers

log = logging.getLogger()
f = logging.Formatter("%(asctime)s - %(module)s.   %(funcName)s - %(levelname)s - %(message)s")
fh = logging.handlers.TimedRotatingFileHandler('log.txt', 'W6')
fh.setFormatter(f)
log.addHandler(fh)
log.setLevel(logging.INFO)
log.info('I want this to print')

In 'IPython qtconsole' however i get different problems, that i tried to explain here (which did not go so well, no need to read!).

Can you please tell me why?

EDIT: I use Python 2.7

EDIT2: Maybe i really just need to add logging.StreamHandler.

Weyermann

what version of python? – Device

You are setting a file handler, so the output is going to the file log.txt. I don't know why you think that the console should output on stdout... – Ioved

This works for me: I get lines like "2014-06-17 11:39:29,422 - <ipython-input-9-ced85295bf91>. <module> - INFO - I want this to print" in log.txt. – Ultrasonic

@Ioved Because i set log.setLevel(logging.INFO). I was thinking, that this configures the console printing behaviour. Also in qtconsole it does print. – Weyermann

@Evert Which console are you using? – Weyermann

Answer 1

It seems like qtconsole adds an handler to the root logger:

In [1]: import logging
   ...: root = logging.getLogger()
   ...: root.handlers
   ...: 
Out[1]: [<logging.StreamHandler at 0x7fd8e00e1f98>]

While using the normal python interpreter or just ipython:

In [1]: import logging

In [2]: root = logging.getLogger()

In [3]: root.handlers
Out[3]: []

If you want both to behave the same you should either add a StreamHandler to the root logger for normal ipython, or remove the StreamHandler from the qtconsole interpreter.

If you want the former just add:

root = logging.getLogger()
root.addHandler(logging.StreamHandler())

If you want the latter, before adding your own handler, do:

for handler in root.handlers[:]:
    root.removeHandler(handler)

---

Note that IPython already provides some machinery for logging to a file. See the documentation. If you want to use the code only inside ipython using its magics might be simpler.

Ioved

If you use the latter solution, it won't work properly if root has more than one handler because of removing-while-iterating problems. Use instead: ``` while len(root.handlers): root.removeHandler(root.handlers[0]) ``` – Earwax

@RonanPaixão Read the code carefully. I believe you missed 3 characters that make a difference and prevent the behaviour you describe. – Ioved

Answer 2

what worked for me

import logger BEFORE any other library/code, in separate cell. this is actually the main requirement. If I load logging and other libraries in one cell, no matter what hierarchy in that cell is, logging does not work

import logging
reload(logging)
logger = logging.getLogger(__name__)

only after loading libraries I set logging config to avoid printing pyspark load debug

logging.basicConfig(format='%(asctime)s %(levelname)s:%(message)s', 
                    level=logging.INFO, 
                    datefmt='%I:%M:%S')

Cardholder

I'm running Spyder3 from a Python 2.7 conda environment and this solved it for me. Thanks! – Artemisa

Note for those on python 3: You need to from importlib import reload as it is no longer a builtin. – Vicenary

Answer 3

If you use Bakuriu's latter solution, it won't work properly if root has more than one handler because of removing-while-iterating problems.

Use instead:

while len(root.handlers):
    root.removeHandler(root.handlers[0])

Showpiece

Bakuriu's answer does not have the problem you describe, thanks to the use of [:] (the 3 characters mentioned in his reply to your comment). However, your solution also works. – Grefe