Laravelのログ出力のカスタマイズ
2021.09.03
Laravelのアクセスログとクエリログを独自フォーマットで出力する方法をご紹介します。
環境
- Laravel6
Loggingクラスの作成
まず、app/Logging/ にActiondログの内容を定義するFormatterクラスを作成します。ActionとQueryは出力内容に関するフォーマット部分が違っています。また、これは環境にもよるのですが Auth::id() によりユーザIDを取得する際にDBへのアクセスが発生することがある為、QueryLogFormatterでは staticの変数 $disableUserId を使ってそれを制御しています。この制御方法はもっと適切な方法がありましたら教えて欲しいです。
// app/Logging/ActionLogFormatter.php
<?php
namespace App\Logging;
use Illuminate\Support\Facades\Auth;
use Monolog\Formatter\LineFormatter;
use Monolog\Logger;
use Monolog\Processor\IntrospectionProcessor;
use Monolog\Processor\UidProcessor;
class ActionLogFormatter
{
private $dateFormat = 'Y-m-d H:i:s.v';
public function __invoke($logger)
{
// ログのフォーマットと日付のフォーマットを指定する
$format = '[%datetime%] action %channel%.%level_name% %extra.uid% %extra.userid%" %message% %context% ' . PHP_EOL;
$lineFormatter = new LineFormatter($format, $this->dateFormat, true, true);
// 出力されるログをリクエストと紐付けるためのIDをつけるための処理
$uidProcessor = app()->make(UidProcessor::class);
// ログ出力から除外するnamespaceの指定
$introProcessor = new IntrospectionProcessor(Logger::DEBUG, [
'Monolog\\',
'Illuminate\\',
'App\\Providers\\',
'App\\Logging\\',
]);
// フォーマとおよび内容の設定
foreach ($logger->getHandlers() as $handler) {
$handler->setFormatter($lineFormatter);
$handler->pushProcessor($introProcessor);
$handler->pushProcessor($uidProcessor);
$handler->pushProcessor(function (array $record) {
$record['extra']['userid'] = Auth::id() ?? '';
return $record;
});
}
}
}
// app/Logging/QueryLogFormatter.php
<?php
namespace App\Logging;
use Illuminate\Support\Facades\Auth;
use Monolog\Formatter\LineFormatter;
use Monolog\Logger;
use Monolog\Processor\IntrospectionProcessor;
use Monolog\Processor\UidProcessor;
class QueryLogFormatter
{
/**
* NOTE
* ユーザIDを取得する Auth::id() を実行するとDBアクセスが発生してクエリログ出力の無限ループを回避するためのフラグ
* @var bool
*/
private static bool $disableUserId = false;
private $dateFormat = 'Y-m-d H:i:s.v';
public function __invoke($logger)
{
$format = '[%datetime%] query %channel%.%level_name% %extra.uid% %extra.userid% query %extra.file%(%extra.line%) %message% %context% ' . PHP_EOL;
if (self::$disableUserId) {
$format = '[%datetime%] query %channel%.%level_name% %extra.uid% %extra.file%(%extra.line%) %message% %context% ' . PHP_EOL;
}
// ログのフォーマットと日付のフォーマットを指定する
$lineFormatter = new LineFormatter($format, $this->dateFormat, true, true);
$uidProcessor = app()->make(UidProcessor::class);
$introProcessor = new IntrospectionProcessor(Logger::DEBUG, [
'Monolog\\',
'Illuminate\\',
'App\\Providers\\',
'App\\Logging\\',
]);
foreach ($logger->getHandlers() as $handler) {
$handler->setFormatter($lineFormatter);
$handler->pushProcessor($introProcessor);
$handler->pushProcessor($uidProcessor);
$handler->pushProcessor(function (array $record) {
if (self::$disableUserId) {
return $record;
}
try {
self::$disableUserId = true;
$record['extra']['userid'] = Auth::id() ?? '';
} finally {
self::$disableUserId = false;
}
return $record;
});
}
}
}
logging.phpの設定
次に、Laravelではログについての設定は config/logging.php に記述する。このファイルはインストール時に作成されているので編集します。作成したイベントとクエリのログを出力するためのチャンネルを追加します。tapに先程作ったFormatterクラスを指定することで、ログ出力時に指定されたチャンネルでFormatterを切り替えることができます。
// config/logging.php
<?php
return [
'channels' => [
...
'action' => [
'driver' => 'daily',
'path' => storage_path('logs/laravel.log'),
'level' => 'info',
'days' => 7,
'permission' => 0777,
'tap' => [App\Logging\ActionLogFormatter::class],
],
'query' => [
'driver' => 'daily',
'path' => storage_path('logs/laravel.log'),
'level' => 'info',
'days' => 7,
'permission' => 0777,
'tap' => [App\Logging\QueryLogFormatter::class],
],
],
];
ログを出力する
出力するを行う箇所にログ出力を行うコードを実装します。当然アクションログとクエリログでは出力されるタイミングが違うので実装する場所も違ってきます。
アクションログ
アクションログはMiddlewareにLarvelがリクエストを受け取ったタイミングでログを出力したいので、Middlewareを作成してそこでログ出力をします。また、パスワードや個人情報などの平文でログに残すべきではない内容はこのクラスでマスクを行います。
// Http/Middleware/ActionLogMiddleware.php
<?php
namespace App\Http\Middleware;
use Closure;
use Illuminate\Support\Facades\Log;
class ActionLogMiddleware
{
public function handle($request, Closure $next)
{
$logContext = [
'url' => $request->path(),
'request' => $this->maskRequest($request->all()),
];
Log::channel('action')->info($request->method(), $logContext);
return $next($request);
}
public function maskRequest($params)
{
# password、password_confirmationという名目で送られてきた内容のマスクをしています。
# 他の項目にもマスクをかける場合はここに追記します
array_walk_recursive($params, function (&$val, $key) {
if (($key === 'password')||($key === 'password_confirmation')) {
$val = '********';
}
});
return $params;
}
}
クエリログ
クエリログはSQLが実行されたタイミングでログを出力します。Laravelでこれを実現するには、クエリログ出力用のServiceProviderを作成してアプリケーションに登録を行います。
// Providers/QueryLogServiceProvider.php
<?php
namespace App\Providers;
use Illuminate\Database\Events\TransactionBeginning;
use Illuminate\Database\Events\TransactionCommitted;
use Illuminate\Database\Events\TransactionRolledBack;
use Illuminate\Support\Facades\DB;
use Illuminate\Support\Facades\Event;
use Illuminate\Support\Facades\Log;
use Illuminate\Support\ServiceProvider;
class QueryLogServiceProvider extends ServiceProvider
{
public function register(): void
{
DB::listen(function ($query) {
$sql = $query->sql;
for ($i = 0; $i < count($query->bindings); $i++) {
if (! is_object($query->bindings[$i])) {
$sql = preg_replace("/\?/", $query->bindings[$i], $sql, 1);
} else {
$sql = preg_replace("/\?/", date_format($query->bindings[$i], 'Y-m-d'), $sql, 1);
}
}
$this->writeLog($sql);
});
Event::listen(TransactionBeginning::class, function (TransactionBeginning $event): void {
$this->writeLog('begin transaction');
});
Event::listen(TransactionCommitted::class, function (TransactionCommitted $event): void {
$this->writeLog('commit transaction');
});
Event::listen(TransactionRolledBack::class, function (TransactionRolledBack $event): void {
$this->writeLog('rollback transaction');
});
}
private function writeLog($msg)
{
Log::channel('query')->info($msg);
}
}
// config/app.php
<?php
return [
...
'providers' => [
...
\App\Providers\QueryLogServiceProvider::class
...
]
...
]
