The python logging module no longer seems to work properly inside a notebook

[tudorprodan]

This pull request fixes this issue: jupyter/notebook#1397

For the sake of completeness, I'll repeat the issue here (edited according to the discussion on jupyter/notebook#1397).

When running the example from the python logging documentation page in a jupyter notebook, the messages go to the notebook console as opposed to the notebook's webpage output via the capture mechanism. Just create an empty notebook, run the example below, you'll see what I mean.

import logging
logging.basicConfig(format='%(levelname)s:%(message)s', level=logging.DEBUG)
logging.debug('This message should appear in the notebook')
logging.info('So should this')
logging.warning('And this, too')

What should happen: The messages appear in the notebook.
What actually happens: The messages don't appear in the notebook.

The issue is caused by:

• When jupyter runs a notebook, it spawns a subprocess for the notebook.
• The subprocess spawns an ZMQ IOLoop thread.
• The IOLoop thread creates a tornado IO loop.
• The tornad IO loop checks to see if there's any logger configured, and if not calls logging.basicConfig().
• logging.basicConfig() will then set up the root logger (logging.root) to use a default StreamHandler.
• StreamHandler when not given a stream defaults to sys.stderr.
• at that point sys.stderr is not the ipykernel captured output yet, it will be set later.

Just to be clear, this is the IOLoop on the side of the subprocess, not on the side of the jupyter server.

The tornado code that calls basicConfig is:
https://github.com/tornadoweb/tornado/blob/stable/tornado/ioloop.py#L360

   def _setup_logging(self):
       if not any([logging.getLogger().handlers,
                   logging.getLogger('tornado').handlers,
                   logging.getLogger('tornado.application').handlers]):
            logging.basicConfig()

I've added the IOPubThread._setup_tornado_logger() method which will just add a default StreamHandler to the tornado logger. This will stop tornado from calling basicConfig, so the actual user can configure the root logger.

With this patch, the code at the beginning of this comment works as expected in a notebook.

[tudorprodan]

I've just pushed another commit which moves the tornado logging init from IOPubThread._setup_tornado_logger IPKernelApp.init_tornado_logger according to @takluyver's comment. The logging is an app decision so it should be in the app class.

[takluyver]

Thanks, I think this looks good. Typically, init_* methods are all called by the initialize() method, but I've never heard that explicitly stated as a rule, so I think it's OK to call one from another init_foo method. @minrk ?

[takluyver]

Can you make this docstring follow the format:

• Single line summary
• Blank line
• Paragraph with more information (optional)

[tudorprodan]

OK, done

[tudorprodan]

@takluyver you're right, I've renamed the method:

-    def init_tornado_logger(self):
+    def configure_tornado_logger(self):

[minrk]

@takluyver yeah, that's fine. I think we have one or two other instances of init_foo calling init_bar. There's no rules about it, just a convention that it should be called as part of initialization at some point. If there's a more descriptive name, no problem with using whatever seems clearest.

[takluyver]

OK then, I think this looks fine. Thanks @tudorprodan

[minrk]

Welcome to the project, @tudorprodan!