Search code examples
pythonloggingtornado

Duplicate logging issue in a python tornado app


I am running a python (v 3.6) tornado app (I believe the latest version 6.x). I am trying to remove my print() statements and use a logging module instead. First I created this get_logger() function:

def get_logger(lname, debug_level=logging.DEBUG):
  lname_logger = logging.getLogger(lname)
  lname_logger.setLevel(debug_level)
  ch = logging.StreamHandler(sys.stdout)
  ch.setLevel(debug_level)

  FORMAT = '%(asctime)s,[%(filename)s:%(lineno)d] %(message)s'
  formatter = logging.Formatter(FORMAT)
  ch.setFormatter(formatter)
  lname_logger.addHandler(ch)
  return lname_logger

In my tornado app handler I have the following code (I removed irrelevant bits and stripped it down to the bare minimum):

class App(object):

   def __init__(self):
     self.logger = utils.get_logger("myApp")
     tornado.options.parse_command_line()
     self.application = tornado.web.Application([
        (r"/", MainHandler),
        (r"/login", LoginHandler),
        ...
     ])
     self.application.listen(options.port)
     self.logger.info("Listening on port %d" % options.port)
     tornado.ioloop.IOLoop.current().start()

When I run this code I see the logging happening twice like so:

2019-04-14 12:50:01,636,[server.py:231] Listening on port 8000
[I 190414 12:50:01 server:231] Listening on port 8000

Now the interesting bit is that if I run the logging code outside of a tornado app in a standalone python file it only prints the first line. In the tornado app each call prints twice and in two different formats (the second line is colored based on logging level and more informative). I believe the second line is printed by Tornado via some builtin logging that I am triggering. So how can I set up my logging to not print duplicates and use only the second kind?


Solution

  • Ok, I found the answer while re-reading the documentation on Tornado's inbuilt logging mechanism:

    This formatter is enabled automatically by tornado.options.parse_command_line or tornado.options.parse_config_file (unless --logging=none is used).

    Which is precisely what I was doing. When I switch to using only the Tornado logger the duplicates disappear.