Search code examples
pythonloggingtornado

Python Tornado: logging infos


I have a problem with writing logs in my Tornado API (Python).

My application writes logs in the file "api.log". Always at 0hrs (using logging.handlers.TimedRotatingFileHandler class), the file is rotated. With this, the current file is named "api.log.yyyy-mm-dd" and a new "api.log" is created. Then, the application goes on to write in this new file. However, some threads still writing on oldest file (api.log.yyyy-mm-dd) and others threads in the new "api.log". I always need to give a restart in the application to hit the problem. Below is a snippet of the code I have.

import logging
import logging.config
import tornado.ioloop
from tornado_json.application import Application
from tornado.httpserver import HTTPServer

import tornado.ioloop
from tornado_json.application import Application
from tornado.httpserver import HTTPServer
from tornado_json.requesthandlers import APIHandler


class HelloWorldHandler(APIHandler):
    def get(self):
        logging.getLogger('api').info('hello world!')
        return "Hello world!"


logging.config.dictConfig({
    'version': 1,
    'formatters': {
        'default': {
            'format': '%(asctime)s %(levelname)s %(message)s'
        },
    },
    'loggers': {
        'api': {
            'level': 'NOTSET',
            'handlers': ['api_handler'],
        }
    },
    'handlers': {
        'api_handler': {
            'class': 'logging.handlers.TimedRotatingFileHandler',
            'when': 'midnight',
            'backupCount': 1,
            'formatter': 'default',
            'filename': 'api.log'
        },
    }
})

app = Application(routes=[('/api/helloworld', HelloWorldHandler)], settings={})

server = HTTPServer(app, xheaders=True)

server.bind(8888)
server.start(150)

tornado.ioloop.IOLoop.instance().start()

The question is: why log rotation does not work on some threads?


Solution

  • server.start(150) starts 150 processes, not threads. (This is a lot. It's unusual to use many more processes than you have CPUs). Processes don't share memory, so each one decides independently when to rotate its log.

    Logging is generally funky when you're creating multiple processes like this. I recommend avoiding server.start(N) (for n != 1) and using a process manager like supervisord to start the desired number of processes. Then you can give each one its own log file and avoid the complications that come from having everything fork from one parent process.