Laravel5.5 ログ出力内容をテストする
モック？フェイク？ (よくわかってない)
モチベーション
- ログ出力要件に対応する自動テスト
- ログイン成功時
- 例外発生時
環境
- Laravel 5.5 LTS
アプリケーションコード
routes/web.php
<?php use Illuminate\Routing\RouteRegistrar; use Illuminate\Support\Facades\Log; use Carbon\Carbon; /** @var RouteRegistrar $router */ $router->get('/', function () { Log::notice('アクセス', ['datetime' => Carbon::now()]); Log::notice('なにか別のログ'); return view('welcome'); });
Facadeのexpectationだとうまくいかない
普通のモック
<?php ... /** * @test * @dataProvider dataProvider_アクセスログの日時 */ public function root_GETでアクセスするとアクセス日時がnoticeでロギングされる_NG1( Carbon $testNow ) { // ---------------------------------------- // 1. setup and expectation // ---------------------------------------- Carbon::setTestNow($testNow); Log::shouldReceive('notice') ->once() ->with( 'アクセス', [ 'datetime' => $testNow ] ); // ---------------------------------------- // 2. action // ---------------------------------------- $this->get('/'); }
- Facadeの__callStaticまわりでエラーが出る
1) Tests\Feature\ExampleTest::root_GETでアクセスするとアクセス日時がnoticeでロギングされる_NG1 with data set #0 (Carbon\Carbon Object (...)) BadMethodCallException: Method Mockery_0_Illuminate_Log_Writer::error() does not exist on this mock object
Partial Mock
- これならいけるでしょ
<?php ... /** * @test * @dataProvider dataProvider_アクセスログの日時 */ public function root_GETでアクセスするとアクセス日時がnoticeでロギングされる_NG2( Carbon $testNow ) { // ---------------------------------------- // 1. setup and expectation // ---------------------------------------- Carbon::setTestNow($testNow); Log::shouldReceive('notice') ->once() ->with( 'アクセス', [ 'datetime' => $testNow ] ); + Log::makePartial(); // ---------------------------------------- // 2. action // ---------------------------------------- $this->get('/'); }
- は？
2) Tests\Feature\ExampleTest::root_GETでアクセスするとアクセス日時がnoticeでロギングされる_NG2 with data set #0 (Carbon\Carbon Object (...)) Error: Call to a member function error() on null
- shouldReceiveに該当しない = mockされてほしくない呼び出しが、正常にpassthroughされてない
PSR-3 LoggerInterfaceを実装するモックを自作して注入
- メモリ上に積むだけのやつ
- 10分でできた
- 抜粋
<?php declare(strict_types=1); namespace App\Util; use Psr\Log\LoggerInterface; /** * ログのテスト用 オンメモリfake */ class LoggerFake implements LoggerInterface { /** * ログレベル別にメッセージを格納する * @var string[][] $repository */ protected $repository = []; /** * {@inheritDoc} */ public function notice($message, array $context = array()) { $this->log('notice', $message, $context); } /** * {@inheritDoc} */ public function log($level, $message, array $context = array()) { if (!isset($this->repository[$level])) { $this->repository[$level] = []; } $this->repository[$level][] = [$message, $context]; } /** * 指定のログレベルでメッセージ、コンテキストを出力しているか * @param string $level ログレベル * @param string $message メッセージ * @param array $context=[] コンテキスト * @return bool 指定のログレベルでメッセージ、コンテキストを出力していればtrue */ public function contains($level, $message, array $context = array()): bool { return in_array([$message, $context], ($this->repository[$level] ?? [])); } }
- 利用側
<?php ... /** * @test * @dataProvider dataProvider_アクセスログの日時 */ public function root_GETでアクセスするとアクセス日時がnoticeでロギングされる( Carbon $testNow ) { // ---------------------------------------- // 1. setup // ---------------------------------------- Carbon::setTestNow($testNow); $loggerFake = new LoggerFake; Log::swap($loggerFake); // ---------------------------------------- // 2. action // ---------------------------------------- $this->get('/'); // ---------------------------------------- // 3. assertion // ---------------------------------------- $this->assertTrue( $loggerFake->contains( 'notice', 'アクセス', [ 'datetime' => $testNow ] ) ); }
