Djangoのログ出力をFluentdで集める

Python Django Fluentd

Djangoのログ出力をFluentdで集める方法について。
ログレベルがERRORやWARNINGのものはSentryを使うのが便利だと思うけど、それ以外のINFOやDEBUGはSentryに入れるには数が多すぎるのでどうするか考えてて、最初はローカルのファイルに書き出していた。
けどまあ複数のサーバーにログファイルがあるとやっぱり不便だったので、Fluentdを使って一箇所に集めることにした。
簡単にできるかなーと思ってたんだけど、fluent-logger-pythonのlogging用のハンドラのインターフェースが合わなくて、ちょっとハマってた。
fluent-logger 0.4.1 : Python Package Index
試したバージョンは、Python 2.7、Django 1.6、fluent-logger-python 0.3.3、msgpack-python 0.4.0
fluentdはtd-agentを使用。
以下、詳細。

DjangoのLOGGING設定

settings.py(抜粋)
LOGGING = {
    'version': 1,
    'disable_existing_loggers': True,
    'handlers': {
        'fluent': {
            'level': 'DEBUG',
            'class': 'fluent.handler.FluentHandler',
            'tag': 'django',
            'host': 'localhost',
            'port': 24224,
        },
    },
    'loggers': {
        'django': {
            'handlers': ['fluent'],
            'propagate': True,
            'level': 'DEBUG',
        },
    }
}
fluent(td-agent)の設定(抜粋)
<match django>
  type file
  path /tmp/django.log
</match>

試した結果

試しにこの設定で動かしてみたところ、ログ出力は以下のようになった。

2013-12-03T02:20:39+09:00       django  {"sys_module":"base","sys_name":"django.request","sys_host":"ubuntu"}
2013-12-03T02:21:17+09:00       django  {"sys_module":"util","sys_name":"django.db.backends","sys_host":"ubuntu"}
2013-12-03T02:21:17+09:00       django  {"sys_module":"base","sys_name":"django.request","sys_host":"ubuntu"}
2013-12-03T02:21:17+09:00       django  {"sys_module":"util","sys_name":"django.db.backends","sys_host":"ubuntu"}

メッセージやパラメータが出力されない。

原因

fluent-logger-pythonのソースコードを読んでみたところ、FluentHandlerはlogging出力の1つ目の引数に辞書オブジェクトかJSON文字列を期待してるけども、Djangoの各機能のログ出力は1つ目の引数にメッセージの文字列、2つ目以降の引数にパラメータを指定しているため。
fluent-loggerに合わせて辞書オブジェクトでログを出力するようにもできるけど、Pythonのloggingを使う際はメッセージ+引数の書き方をすることが多いので、汎用的にするならこちらに合わせたほうがよさそう。

fluent_support.py

そこで、FluentHandlerとlogging.Handlerのソースコードを参考に、自分でロギング用のハンドラクラスを書いてみた。

# coding: utf-8
import logging
import socket

from fluent import sender


class DjangoFluentHandler(logging.Handler):
    def __init__(
            self, tag, host='localhost', port=24224, timeout=3.0,
            verbose=False):
        logging.Handler.__init__(self)
        self.tag = tag
        self.sender = sender.FluentSender(tag,
                                          host=host, port=port,
                                          timeout=timeout, verbose=verbose)
        self.hostname = socket.gethostname()

    def emit(self, record):
        if record.levelno < self.level:
            return
        msg = self.format(record)
        data = {
            'host': self.hostname,
            'name': record.name,
            'levelname': record.levelname,
            'process': record.process,
            'message': msg,
        }
        self.sender.emit(None, data)

    def _close(self):
        self.sender._close()

ハンドラをLOGGINGに設定

作成したハンドラを使うようにsettings.pyを修正する。

settings.py(抜粋)

変更点はハンドラのクラスのみ。

LOGGING = {
    'version': 1,
    'disable_existing_loggers': True,
    'handlers': {
        'fluent': {
            'level': 'DEBUG',
            'class': 'fluent_support.DjangoFluentHandler',
            'tag': 'django',
            'host': 'localhost',
            'port': 24224,
        },
    },
    'loggers': {
        'django': {
            'handlers': ['fluent'],
            'propagate': True,
            'level': 'DEBUG',
        },
    }
}

自作したハンドラでの出力結果

これでログ出力は以下のようになった。期待通り。

2013-12-03T02:32:36+09:00       django  {"process":1595,"host":"ubuntu","message":"Not Found: /","name":"django.request","levelname":"WARNING"}
2013-12-03T02:32:50+09:00       django  {"process":1595,"host":"ubuntu","message":"(0.001) QUERY = u'SELECT \"django_session\".\"session_key\", \"django_session\".\"session_data\", \"django_session\".\"expire_date\" FROM \"django_session\" WHERE (\"django_session\".\"session_key\" = %s  AND \"django_session\".\"expire_date\" > %s )' - PARAMS = (u'3yvx2l8tgq7lgt8tbp9b5fkcknxls3km', u'2013-12-02 17:32:50.040118'); args=('3yvx2l8tgq7lgt8tbp9b5fkcknxls3km', u'2013-12-02 17:32:50.040118')","name":"django.db.backends","levelname":"DEBUG"}
2013-12-03T02:32:50+09:00       django  {"process":1595,"host":"ubuntu","message":"(0.002) QUERY = u'SELECT \"auth_user\".\"id\", \"auth_user\".\"password\", \"auth_user\".\"last_login\", \"auth_user\".\"is_superuser\", \"auth_user\".\"username\", \"auth_user\".\"first_name\", \"auth_user\".\"last_name\", \"auth_user\".\"email\", \"auth_user\".\"is_staff\", \"auth_user\".\"is_active\", \"auth_user\".\"date_joined\" FROM \"auth_user\" WHERE \"auth_user\".\"id\" = %s ' - PARAMS = (1,); args=(1,)","name":"django.db.backends","levelname":"DEBUG"}

いろいろ楽になりそう。

参考