モンモンブログ

Ruby, Python, PHP, JavaScript/jQuery などなど気分に応じて

Symfony2 のログを見やすく設定する

symfony2 のログってデフォルトだと余計なものが多くて見難いです。

例えばこんなです。

$ tail -f app/logs/dev.log
[2013-08-08 21:53:41] event.DEBUG: Notified event "kernel.request" to listener "Symfony\Component\Security\Http\Firewall::onKernelRequest". [] []
[2013-08-08 21:53:41] event.DEBUG: Notified event "kernel.request" to listener "Symfony\Bundle\AsseticBundle\EventListener\RequestListener::onKernelRequest". [] []
[2013-08-08 21:53:41] event.DEBUG: Notified event "kernel.request" to listener "Hoe\HoeBundle\Hoe\EventListener\tvSeoRequestListener::onKernelRequest". [] []
[2013-08-08 21:53:41] event.DEBUG: Notified event "kernel.controller" to listener "Symfony\Bundle\FrameworkBundle\DataCollector\RouterDataCollector::onKernelController". [] []
[2013-08-08 21:53:41] event.DEBUG: Notified event "kernel.controller" to listener "Sensio\Bundle\FrameworkExtraBundle\EventListener\ControllerListener::onKernelController". [] []
[2013-08-08 21:53:41] event.DEBUG: Notified event "kernel.controller" to listener "Sensio\Bundle\FrameworkExtraBundle\EventListener\ParamConverterListener::onKernelController". [] []
[2013-08-08 21:53:41] event.DEBUG: Notified event "kernel.controller" to listener "Sensio\Bundle\FrameworkExtraBundle\EventListener\TemplateListener::onKernelController". [] []
[2013-08-08 21:53:41] event.DEBUG: Notified event "kernel.controller" to listener "Symfony\Component\HttpKernel\DataCollector\RequestDataCollector::onKernelController". [] []
[2013-08-08 21:53:41] event.DEBUG: Notified event "kernel.view" to listener "Sensio\Bundle\FrameworkExtraBundle\EventListener\TemplateListener::onKernelView". [] []
[2013-08-08 21:53:41] event.DEBUG: Listener "Sensio\Bundle\FrameworkExtraBundle\EventListener\TemplateListener::onKernelView" stopped propagation of the event "kernel.view". [] []
[2013-08-08 21:53:41] event.DEBUG: Notified event "kernel.response" to listener "Symfony\Component\Security\Http\Firewall\ContextListener::onKernelResponse". [] []
[2013-08-08 21:53:41] event.DEBUG: Notified event "kernel.response" to listener "Symfony\Component\Security\Http\RememberMe\ResponseListener::onKernelResponse". [] []
[2013-08-08 21:53:41] event.DEBUG: Notified event "kernel.response" to listener "Symfony\Bridge\Monolog\Handler\FirePHPHandler::onKernelResponse". [] []
[2013-08-08 21:53:41] event.DEBUG: Notified event "kernel.response" to listener "Sensio\Bundle\FrameworkExtraBundle\EventListener\CacheListener::onKernelResponse". [] []
[2013-08-08 21:53:41] event.DEBUG: Notified event "kernel.response" to listener "Hoe\HoeBundle\Hoe\EventListener\tvAnalyticsTrackerListener::onKernelResponse". [] []
[2013-08-08 21:53:41] event.DEBUG: Notified event "kernel.response" to listener "Symfony\Component\HttpKernel\EventListener\ResponseListener::onKernelResponse". [] []
[2013-08-08 21:53:41] event.DEBUG: Notified event "kernel.response" to listener "Symfony\Component\HttpKernel\EventListener\LocaleListener::onKernelResponse". [] []
[2013-08-08 21:53:41] event.DEBUG: Notified event "kernel.response" to listener "Symfony\Component\HttpKernel\EventListener\ProfilerListener::onKernelResponse". [] []
[2013-08-08 21:53:41] event.DEBUG: Notified event "kernel.response" to listener "Symfony\Bundle\WebProfilerBundle\EventListener\WebDebugToolbarListener::onKernelResponse". [] []
[2013-08-08 21:53:41] event.DEBUG: Notified event "kernel.response" to listener "Symfony\Component\HttpKernel\EventListener\StreamedResponseListener::onKernelResponse". [] []
[2013-08-08 21:53:41] event.DEBUG: Listener "Sensio\Bundle\FrameworkExtraBundle\EventListener\TemplateListener::onKernelView" stopped propagation of the event "kernel.view". [] []
[2013-08-08 21:53:41] event.DEBUG: Notified event "kernel.response" to listener "Symfony\Component\Security\Http\Firewall\ContextListener::onKernelResponse". [] []
[2013-08-08 21:53:41] security.DEBUG: Write SecurityContext in the session [] []
[2013-08-08 21:53:41] event.DEBUG: Notified event "kernel.response" to listener "Symfony\Component\Security\Http\RememberMe\ResponseListener::onKernelResponse". [] []
[2013-08-08 21:53:41] event.DEBUG: Notified event "kernel.response" to listener "Symfony\Bridge\Monolog\Handler\FirePHPHandler::onKernelResponse". [] []
...
  • ほぼ不要な "Notified event" 行だらけで、重要な行が埋もれてしまう
  • ログの末尾に必ずついてる空カッコ "[] []" がウザい

です。

見やすくなるよう設定をいじってみました。

"Notified event" をログしない

symfony2 のロギングには標準で Monolog を使ってます。 で、Monolog によるロギングはいくつかのチャネルからなり、そのうち event チャネルが "Notified event" ログを出力してるようです。

設定ファイルを修正して、この "event" チャネルをログしないように(event チャネル以外をログするように)設定します。

$ vim app/config/config_dev.yml
monolog:
    handlers:
        main:
            type:  stream
            path:  "%kernel.logs_dir%/%kernel.environment%.log"
            level: debug
            # この行を追加。ビックリマーク "!" で「event 以外」って意味になる
            channels: !event

末尾の "[] []" を出力しない

ログのフォーマットは Monolog のフォーマッタ、LineFormatter が担当しています。 LineFormatter はデフォルトで↓のようなフォーマットで出力します(https://github.com/Seldaek/monolog/blob/master/src/Monolog/Formatter/LineFormatter.php#L24)。

"[%datetime%] %channel%.%level_name%: %message% %context% %extra%\n"

この末尾の %context%, %extra% に相当するデータが空な場合に、ログに "[] []"(空配列の JSON 表現)と吐き出されちゃうようです。じゃあ設定変更して余分(?)な %context% %extra% を省いちゃえばいーじゃん?

$ vim app/config/config_dev.yml
monolog:
    handlers:
        main:
            type:  stream
            path:  "%kernel.logs_dir%/%kernel.environment%.log"
            level: debug
            channels: !event
            # main ハンドラで使うフォーマッタを指定
            formatter: my_formatter

# フォーマッタ設定を追加
services:
    my_formatter:
        class: Monolog\Formatter\LineFormatter
        arguments:
            # フォーマットを定義
            - "[%%datetime%%] %%channel%%.%%level_name%%: %%message%%\n"

ただ、僕は %context% や %extra% が何なのかよく分からんままやってるので注意です。 もし %context% %extra% をログに全く出さなくしちゃうのに抵抗があるなら、こいつらの位置を末尾から %message% の前あたりに移動すれば、空カッコ "[] []" も目立たなくなっていいのでは。例えばこんな感じ?

            # フォーマットを定義
            - "[%%datetime%%] %%channel%%.%%level_name%%: %%context%% %%extra%%: %%message%%\n"

どうでしょうか。

参考: