PHPUnitの実行時に出ていた不要なログを出力しないようにした話

2024年10月10日

URLをコピーしました！

こんにちは、フロントエンドエンジニアのやなぎ（ @apple_yagi ）です。

PR TIMESのバックエンドではPHPUnitを使用してUnitテストが書かれているのですが、テスト実行時に不要なログが大量に出力されていました。これは Notice Error や Logger によるログ出力によるもので長年放置されてきました。次の画像はGitHub Actions上でPHPUnitを実行した時の画像です。この画像では全体のログの1/3ほどしか写っておらず、実際にはまだまだログが出ています。

GitHub Actions上でPHPUnitを実行した際に大量のログが出ています

最近、私はFlakyなPHPUnitの調査を行っていたのですが、上記のように不要なログがあると調査がしづらいため、綺麗にしました。

本エントリーではその際に行ったことをご紹介します。

Notice Errorを出力しないようにする

PR TIMESにはレガシーなコードと新しく再実装し直したモダンなコードの2種類があります。モダンなコードに対してテストを実行する際は Notice Error などは出ないのですが、一部のモダンコードの中でレガシーコードを使用している部分があり、そこで Notice Error が発生しています。

具体的には以下のような定数を重複して定義しようとしているエラーが大量に発生しています。

PHP Notice:  Constant {変数名} already defined in {ファイル名} on line 13

レガシーコードでは定数の扱い方が悪く、さまざまなファイルで同じ名前の定数を定義しており、たくさんのコードがその定数に依存しています。そのため、このエラーを修正するのは難しく、影響範囲も広いため、今回は以下のようにCI上で実行するときだけエラーレベルを上げ、無視するようにしました。

    - name: Run PHPUnit
	  run: vendor/bin/phpunit -c ./phpunit.xml
	  env: 
        CI: true

// CI上ではNoticeエラーを無視する
$isCi = getenv('CI') === 'true';
if ($isCi) {
    error_reporting(E_ALL & ~E_NOTICE);
}

NullLoggerを使用する

PR TIMESのモダンコードでは以下のようにロガーを関数の引数で渡すようにしています。ロガーの型は Psr\Log\LoggerInterface になっています。

<?php

class UserService
{
    public static function getById(int $user_id, Psr\Log\LoggerInterface $logger): ?User
    {
        $user = UserRepo::getById($user_id);
				
        if (is_null($user)) {
            $logger->error('Not found user.');
        }
				
        return $user;
    }
}

これまではテストをする際にもプロダクションコードと同様に Monolog の Logger が使用されており、テストは成功するもののエラーログなどが出力されていました。

<?php

class UserServiceTest extends TestCase
{
    public function test_存在しないユーザーIDを指定した時、nullが返ってくること()
    {
        $logger = new Monolog\Logger('_');
        // 実際にエラーログが出力されてしまう
        $user = UserService::getById(0, $logger);
				
        $this->assertNull($user);
    }
}

これを回避するために Psr\Log\NullLogger を使用し、ログを出力しないように変更しました。

<?php

class UserServiceTest extends TestCase
{
    public function test_存在しないユーザーIDを指定した時、nullが返ってくること()
    {
        $logger = new Psr\Log\NullLogger();
        // ログが出力されない
        $user = UserService::getById(0, $logger);
				
        $this->assertNull($user);
    }
}

しかし、NullLogger を渡すことができないパターンがあり、次に紹介する対応も行いました。

LoggerにNullHandlerを渡してログを出力しないようにする

関数の引数の型が Psr\Log\LoggerInterface であれば NullLogger を渡すことができますが、型に Monolog\Logger が指定されている場合は NullLogger を渡すことができません。

<?php

class PressReleaseService
{
    // $logger の型が Monolog\Logger になっている
    public static function getById(int $press_release_id, Monolog\Logger $logger): ?PressRelease
    {
        $press_release = PressReleaseRepo::getById($press_release_id);
				
        if (is_null($press_release)) {
            $logger->error('Not found press release.');
        }
				
        return $press_release;
    }
}

$logger = new Monolog\Logger('_');
$press_release = PressReleaseService::getById(1, $logger);

そのため、今回は以下のように Monolog\Logger に Monolog\Handler\NullHandler を渡し、ログが出力されない状態の Logger を渡すようにしました。

今回はプロダクションコードを変更せずにログを綺麗にしたかったため、このような変更をしています。本来は引数の型を Psr\Log\LoggerInterface に変更し、NullLoggerを渡すことが最善であると考えています。

<?php

class PressReleaseServiceTest extends TestCase
{
    public function test_存在しないプレスリリースIDを指定した時、nullが返ってくること()
    {
        $logger = new Monolog\Logger('_');
        $null_handler = new Monolog\Handler\NullHandler();
        $logger->pushHandler($null_handler);

        // ログが出力されない
        $press_release = PressReleaseService::getById(0, $logger);
				
        $this->assertNull($press_release);
    }
}

このようにすることでプロダクションコードを変更せずにログの出力を抑えることができます。