Python's logging issue in Tornado coroutine

Question

A couple of days ago I found strange logging issue working with Tornado.

I have a set of files:

main.py:

 1  import logging
 2  import logging.config
 3  import os

 4  from somemodule.mod import ModClass
 5  from tornado import ioloop

 6  if __name__ == "__main__":
 7      logging.config.fileConfig("logging.ini")
 8      print ioloop.IOLoop.current().run_sync(ModClass.my_coroutine)

logging.ini:

 1  [loggers]
 2  keys=root

 3  [logger_root]
 4  level=NOTSET
 5  handlers=file

 6  [handlers]
 7  keys=file

 8  [handler_file]
 9  level=DEBUG
10  formatter=default
11  class=handlers.TimedRotatingFileHandler
12  args=('/tmp/some-system.log', 'D', 1, 7)

13  [formatters]
14  keys=default

15  [formatter_default]
16  format=%(asctime)s [%(levelname)s] %(name)s@%(lineno)d: %(message)s

somemodule/mod.py:

 1  import logging
 2  from tornado import gen

 3  logger = logging.getLogger(__name__)

 4  class ModClass(object):

 5      @classmethod
 6      @gen.coroutine
 7      def my_coroutine(cls):
 8          # logger = logging.getLogger(__name__)
 9          logger.critical("SOME MESSAGE")
10          raise gen.Return("Some string")

Also I have an empty __init__.py in somemodule directory.

If I run main.py, I see "Some string" in console, and I have a created, but empty file /tmp/some-system.log. I don't know what is wrong with this small system.

To make it work correctly I have to comment line (3) and uncomment line (8) in file somemodule/mod.py.

Does anybody know how to make module logger work without need to declare it in each function in module? And what is the cause of so strange behavior in this simple example?

P.S. My environment:
Python 2.7.6
tornado==3.1.1

Answer 1

You need to change the call to fileConfig to fileConfig("logging.ini", disable_existing_loggers=False) as documented here.