OTOBANK Engineering Blog

オトバンクはコンテンツが大好きなエンジニアを募集しています!

Symfony Console のコマンド名を自動的に Monolog のログに出そう

この記事は Symfony Advent Calendar 2016 - Qiita 10日目の記事です。

みんな大好き Console のお話です。

CLI から Monolog Logger を使う

Symfony2 or 3 を使っているのであれば Console Component のお世話になっていると思います。

そしてほとんどの場合は便利なサービスを使いたいはずなので、 ContainerAwareCommand を使いますよね。

これを使えばサービスコンテナから Logger を取得し、Web と同じように CLI でもログを吐くことができます。 *1

例えば、下記のようなコマンドを定義し、

<?php

namespace AppBundle\Command;

use Symfony\Bundle\FrameworkBundle\Command\ContainerAwareCommand;
use Symfony\Component\Console\Input\InputInterface;
use Symfony\Component\Console\Output\OutputInterface;

class AppMyCommandCommand extends ContainerAwareCommand
{
    protected function configure()
    {
        $this
            ->setName('app:my-command')
        ;
    }

    protected function execute(InputInterface $input, OutputInterface $output)
    {
        $logger = $this->getContainer()->get('logger');
        $logger->info('hello otobank');
    }
}

こういうコマンドを叩くと

$ ./bin/console app:my-command

var/logs/dev.log には下記のようなログが出力されます。

[2016-12-08 11:21:34] app.INFO: hello otobank [] []

OK. いいですね。

しかしこの var/logs/dev.log は Web でも使用されますし、別のコマンドを作ればそちらでも使用されることになるので、いろんなログが混ざり合い、とても見づらくなってしまいます。 *2

コマンド名がログに出力されれば、他と見分けがつくのでとても便利だと思いませんか?

といっても、毎回自分で

<?php
$logger->info('[my-command] hello otobank');

なんて書きたくないですよね。 *3

Monolog Processor を使う

そういった場合に有効なのが Monolog Processor です。

app/config/services.yml などに、ちょちょいとこいつを使うように定義してあげれば、

あら不思議、すべてのログに思いのままに付加情報をつけることができます。

デフォルトで用意されているプロセッサーは ここ にある限りだと思うのですが、

URL を出せる WebProcessor

プロセスIDを出せる ProcessIdProcessor はあっても、

コマンド名を出せるプロセッサーはありません。

それもそのはず、Monolog は Symfony Console のことなんて知らないですからね。

そうなってくると Symfony と Monolog を橋渡し(Bridge)する役目の ここ にあるかと思いきや、

残念、ちょっとそれらしきものはないわけです。

というわけで作りましょう。

Monolog Console Processor を作った

作ったものがこちらになります。 otobank/monolog-console-processor - Packagist

ソースコードは monolog-console-processor/ConsoleProcessor.php at 1.0.0 これだけ。

やってることは至極単純で、ConsoleEvents::COMMAND イベントを Subscribe して、コマンド名を保持しておき、ログが吐かれるタイミングで extra フィールドに保持しておいたコマンド名を付加するだけです。

使い方は monolog-console-processor/README.md に書いてあるとおりですが、

composer require otobank/monolog-console-processor

でインストールして、

app/config/services.yml などに

services:
    monolog.processor.console:
        class: Otobank\Monolog\Processor\ConsoleProcessor
        tags:
            - { name: monolog.processor }
            - { name: kernel.event_subscriber }

と書くだけ。

では再度コマンドを叩いてみましょう。

$ ./bin/console app:my-command

var/logs/dev.log には下記のようなログが出力されました。

[2016-12-09 17:55:26] app.INFO: hello otobank [] {"command_name":"app:my-command"}

いいですね。最高ですね。

おわりに

なんてことないプログラムですが、毎回書くことを考えれば便利なんじゃないかと思います。

だるいことはどんどんプログラムに任せよう!

そして空いた時間で龍が如く6をやろう!

はたまたオーディオブックを聴こう!

*1:バッチ処理ではなければわざわざ Logger を使わずに OutputInterface を使って標準出力に出せばいいと思うので、今回の記事はバッチ処理にコマンドを使う場合に有効な話です。とはいえ、サービス内で Logger を使用してロギングしている場合もあると思うので、そういう場合にも有効です。

*2:単純な解決方法として、ファイル名を分けるという方法もありますが、1つのアプリケーションログを構造化されたログとしてそのままFluent経由で送信していたのでログを分けたくなかったという経緯があります。

*3:これを書くことをいとわない人はプログラマーの三大美徳を思い出しましょう