I got a system running Python Tornado behing Haproxy.
As Haproxy provide a check-health functionnality, I of course activate it, but it create a simple problem: every 2 seconds (or 1), I got a log entry on tornado side, saying ‘OPTIONS /checkhealth’…
I wanted to disable only this, and keep default logging for other requests, so here is a quick recipe on how to achieve this.
First of all, the haproxy configuration used (only the revelant part):
backend tornado balance roundrobin option forwardfor option httpclose #check request to see if server is up or down option httpchk OPTIONS /checkhealth HTTP/1.0 server tornado1 localhost:8588 weight 1 check
I send on /checkhealth path, a simple HTTP OPTIONS command to see if server respond a HTTP 200 OK.
Now let’s see how to manage this on Tornado side.
As every tornado element, I create a simple class to provide the checkhealth functionnality:
#!/usr/bin/env python # -*- coding: utf-8 -*- import tornado.web class CheckHealthHandler(tornado.web.RequestHandler): ''' Manage checkhealth haproxy check ''' def get(self): self.set_status(200) def post(self): self.set_status(200) def put(self): self.set_status(200) def delete(self): self.set_status(200) def head(self): self.set_status(200) def options(self): self.set_status(200)
Not really needed to do more, of course, I include it into the Tornado application:
app = tornado.web.Application([ # Haproxy (r'/checkhealth', CheckHealthHandler), (r'/check-health', CheckHealthHandler), (r'/check', CheckHealthHandler), (r'/health', CheckHealthHandler) ])
Like every basic RequestHandler, now if you start both, you will see such kind of log:
2014-03-28 13:23:09 - INFO | tornado.access -> 200 OPTIONS /checkhealth (127.0.0.1) 0.00ms 2014-03-28 13:23:10 - INFO | tornado.access -> 200 OPTIONS /checkhealth (127.0.0.1) 0.00ms 2014-03-28 13:23:11 - INFO | tornado.access -> 200 OPTIONS /checkhealth (127.0.0.1) 0.00ms
Haproxy is contacting Tornado as expected, but it becomes too much… Let’s configure that.
Tornado and the Logging
Tornado rely on the excellent Logging module provided by Python. As Logging can configure many Logger (regarding their name), configuring the ‘global’ logger is a bad things, and will probably not work. We need to grab the Tornado logger. And add filter to them.
The three Logger are:
If you check the log above, you see the name of the logger used: tornado.access. So we have to configure this one. The idea will simply, when we see 200 OPTIONS /checkhealth incomming, we refuse to log this. This can be done using a filter:
import logging class NoHaproxyLoggingFilter(logging.Filter): ''' Disable haproxy logging filter ''' def __init__(self, name='NoHaproxyLoggingFilter'): logging.Filter.__init__(self, name) def filter(self, record): return not record.getMessage().startswith('200 OPTIONS /checkhealth')
Simple, and yet powerfull. Now we need to link it with our Tornado system (probably just before the Tornado IOLoop):
import logging # May change from NoHaproxyLoggingFilter import NoHaproxyLoggingFilter logging.getLogger('tornado.access').addFilter(NoHaproxyLoggingFilter())
We take tornado.access logger, and add a filter, which refuse if it’s see the beginning of 200 OPTIONS…. But other requests, are still logged as expected!
The python logging system, is definitely one of the best i’ve ever seen, you can have tons of configuration and possibilities, as Tornado use it, it also provide to Tornado a great logging tool, so, don’t forget to configure it!