教你更优雅地写 API 之「记录日志」

前言

日常工作中，项目不管是在开发阶段，还是已经部署上线，记录日志来分析项目的运行情况都是很常用的方式。比如，通过记录 SQL 日志来检查是否有 N+1 问题，通过记录请求日志来分析 API 的响应时间等。

在 lumen-api-starter 中针对记录日志进行了优化，可以更方便地来记录 SQL 和 Request日志。

关于lumen-api-starter 的介绍可以参考文章是时候使用 Lumen 8 + API Resource 开发项目了！。

本篇是在前一篇的基础上，重新整理并独立出了 package，可以同时支持最新版本 Laravel 和 Lumen 项目。

相关地址：

Package 地址：laravel-logger

Laravel 版本 Api 开发初始化项目：laravel-api-starter

Lumen 版本 Api 开发初始化项目：lumen-api-starter

实现过程

需求

• 能够有效地记录 SQL 日志，来分析隐藏的 N+1 、慢查询等问题
• 能够记录 API 请求日志，来分析响应时间；
• 可以追溯单次请求中的执行过程（并发场景下传统文件日志方式可能会出现串行）
• 日志能够更容易地查看和搜索
• 能够反向追溯应用中所有记录日志的节点
• 日志记录不会额外对业务处理增加负担
• 能够灵活地配置开启和关闭

功能

• 提供 logger_async 辅助函数，通过异步 Job 方式来记录日志；
• 增加 RequestLog 中间件来记录 api 的请求和响应；对于单个请求关联 UNIQUE_ID，根据UNIQUE_ID可以跟踪请求执行过程
• 适配 MongoDB 驱动，支持记录日志到 MongoDB；collection 支持按天、按月和按年拆分；
• 日志的 message 适配 laravel-enum，统一日志的 message 格式；方便统计项目中记录日志的节点
• 提供 LOG_QUERY、LOG_REQUEST 配置参数来开启关闭 sql 日志和 request 日志

思路

• 通过 DB::listen 来监听 SQL 的执行并生成 SQL 日志记录
• 通过 RequestLog 中间件中的 handle 方法来生成请求 UNIQUE_ID ，terminate 方法来记录 Request 日志
• 在单次请求过程中，所有的日志记录都关联 RequestLog 中间件中产生的UNIQUE_ID
• 日志支持异步方式记录，来减少业务负担；（LogJob 走 default 队列，生产环境可以将优先级高的异步任务放在其他队列中）
• logger_async 辅助函数，用来便捷调度 LogJob

实现

针对 larave-logger源码分析下大致流程。

• RequestLog 中间件中触发 RequestArrivedEvent 和 RequestHandledEvent 事件
• RequestArrivedListener 监听 RequestArrivedEvent 事件，往 server 中写入 UNIQUE_ID
• RequestHandledListener 监听 RequestHandledEvent 事件，通过 logger_async 调度 LogJob
• logger_async 辅助函数中调度 LogJob 时末尾参数传入 request()->server()

function logger_async(string $message, array $context = []) { return dispatch(new \Jiannei\Logger\Laravel\Jobs\LogJob($message, $context, request()->server())); }

• LogJob 中通过Monolog\Logger 的 WebProcessor 来增加额外的 SERVER 信息（url、ip、http_method 等）到日志中

// vendor/jiannei/laravel-logger/src/Jobs/LogJob.php <?php namespace Jiannei\Logger\Laravel\Jobs; use Illuminate\Bus\Queueable; use Illuminate\Contracts\Queue\ShouldQueue; use Illuminate\Queue\InteractsWithQueue; use Monolog\Logger; use Monolog\Processor\WebProcessor; use Psr\Log\LoggerInterface; class LogJob implements ShouldQueue { use InteractsWithQueue; use Queueable; private $context; private $message; private $serverData; public function __construct(string $message, array $context = null, array $serverData = null) { $this->message = $message; $this->context = $context; $this->serverData = $serverData; } public function handle() { app()->forgetInstance(LoggerInterface::class); // unset(app()[LoggerInterface::class]); $logger = app(LoggerInterface::class)->getLogger(); if ($logger instanceof Logger) { $logger->pushProcessor(new WebProcessor($this->serverData)); } $logger->debug($this->message, $this->context); } }

• Monolog\Logger 的 WebProcessor 中检查 serverData 中是否有UNIQUE_ID，如果有则记录到日志的 extra 字段中

// vendor/monolog/monolog/src/Monolog/Processor/WebProcessor.php <?php // ... class WebProcessor implements ProcessorInterface { /** * @var array|\ArrayAccess */ protected $serverData; /** * Default fields * * Array is structured as [key in record.extra => key in $serverData] * * @var array */ protected $extraFields = [ 'url' => 'REQUEST_URI', 'ip' => 'REMOTE_ADDR', 'http_method' => 'REQUEST_METHOD', 'server' => 'SERVER_NAME', 'referrer' => 'HTTP_REFERER', ]; public function __construct($serverData = null, array $extraFields = null) { if (null === $serverData) { $this->serverData = &$_SERVER; } elseif (is_array($serverData) || $serverData instanceof \ArrayAccess) { $this->serverData = $serverData; } else { throw new \UnexpectedValueException('$serverData must be an array or object implementing ArrayAccess.'); } if (isset($this->serverData['UNIQUE_ID'])) { $this->extraFields['unique_id'] = 'UNIQUE_ID'; } if (null !== $extraFields) { if (isset($extraFields[0])) { foreach (array_keys($this->extraFields) as $fieldName) { if (!in_array($fieldName, $extraFields)) { unset($this->extraFields[$fieldName]); } } } else { $this->extraFields = $extraFields; } } }

如何使用

安装

composer require jiannei/laravel-enum -vvv composer require jiannei/laravel-logger -vvv

配置

• 注册服务容器（Laravel 可以省略这一步骤）

Lumen在 bootstrap/app.php 中注册服务容器

$app->register(\Jiannei\Logger\Laravel\Providers\ServiceProvider::class);

• 中间件启用

Laravel 在 app/Http/Kernel.php 的 $middlewareGroups 中添加

protected $middlewareGroups = [ 'api' => [ \Jiannei\Logger\Laravel\Http\Middleware\RequestLog::class,// 加在这个地方 ], ];

Lumen 在 bootstrap/app.php 中添加

$app->middleware([ \Jiannei\Logger\Laravel\Http\Middleware\RequestLog::class, ]);

• 修改配置参数

config/logging.php 中增加以下配置，并根据自身实际情况进行部分调整，可以对比查看最终配置 lumen-api-starter

'channels' => [// 下面这些移到原先的 channels 中 'mongo' => [ 'driver' => 'custom', // 此处必须为 custom 'via' => \Jiannei\Logger\Laravel\MongoLogger::class, // 当 driver 设置为 custom 时，使用 via 配置项所指向的工厂类创建 logger 'channel' => env('LOG_MONGODB_CHANNEL', 'mongo'), 'level' => env('LOG_MONGODB_LEVEL', 'debug'), // 日志级别 'separate' => env('LOG_MONGODB_SEPARATE', false), // false,daily,monthly,yearly 'host' => env('LOG_MONGODB_HOST', config('database.connections.mongodb.host')), 'port' => env('LOG_MONGODB_PORT', config('database.connections.mongodb.port')), 'username' => env('LOG_MONGODB_USERNAME', config('database.connections.mongodb.username')), 'password' => env('LOG_MONGODB_PASSWORD', config('database.connections.mongodb.password')), 'database' => env('LOG_MONGODB_DATABASE', config('database.connections.mongodb.database')), ], ], // 下面是新增项，移到文件末尾即可 'enum' => \Jiannei\Enum\Laravel\Repositories\Enums\LogEnum::class, 'query' => [ 'enabled' => env('LOG_QUERY', false), // Only record queries that are slower than the following time // Unit: milliseconds 'slower_than' => 0, ], 'request' => [ 'enabled' => env('LOG_REQUEST', false), ],

• .env 中配置

LOG_CHANNEL=mongo LOG_SLACK_WEBHOOK_URL= LOG_QUERY=true LOG_REQUEST=true LOG_MONGODB_SEPARATE=daily LOG_MONGODB_LEVEL=debug # 如果使用的是 mongo channel 需要配置 LOG_MONGODB_SEPARATE=daily LOG_MONGODB_LEVEL=debug LOG_MONGODB_HOST=127.0.0.1 LOG_MONGODB_PORT=27017 LOG_MONGODB_DATABASE=logs LOG_MONGODB_USERNAME= LOG_MONGODB_PASSWORD= LOG_MONGODB_AUTHENTICATION_DATABASE=admin

• 如果需要记录日志到 MongoDB，需要先安装并配置laravel-mongodb

如何使用

可以参考 lumen-api-starter 中的实际使用示例。

使用

• app/Repositories/Enums/LogEnum.php 中定义记录日志时的 message
• 通过 logger_async 方法记录日志

logger_async(LogEnum::SYSTEM_SQL, $arrayData);

• 如果队列任务异步执行，则需要开启队列消费 php artisan queue:work

日志内容

• 记录到文件中的日志内容

[2021-01-18 12:03:36] local.DEBUG: System sql {"database":"lumen-api","duration":"11.08ms","sql":"select `roles`.*, `model_has_roles`.`model_id` as `pivot_model_id`, `model_has_roles`.`role_id` as `pivot_role_id`, `model_has_roles`.`model_type` as `pivot_model_type` from `roles` inner join `model_has_roles` on `roles`.`id` = `model_has_roles`.`role_id` where `model_has_roles`.`model_id` = '11' and `model_has_roles`.`model_type` = 'App\\\\Repositories\\\\Models\\\\User'"} {"url":"/users","ip":"172.22.0.1","http_method":"get","server":"lumen-api.test","referrer":null,"unique_id":"43f54ea9-4ad4-47cf-b9da-1d3aa150ff61"} [2021-01-18 12:03:36] local.DEBUG: System request {"request":[],"response":{"status":"success","code":200,"message":"操作成功","data":{"data":[{"id":1,"nickname":"Evert Stracke DVM","email":"aufderhar.kaden@example.net"},{"id":2,"nickname":"Milton Toy","email":"keagan.eichmann@example.org"},{"id":3,"nickname":"Mrs. Alyce O'Hara","email":"cartwright.sidney@example.org"},{"id":4,"nickname":"Prof. Evalyn Windler I","email":"bertram.bartoletti@example.org"},{"id":5,"nickname":"Brant Skiles","email":"jane16@example.net"},{"id":6,"nickname":"Sage Rodriguez I","email":"ryder50@example.org"},{"id":7,"nickname":"Ms. Angelica Wiegand DVM","email":"kaelyn.mueller@example.net"},{"id":8,"nickname":"Newton Zieme","email":"sipes.kip@example.com"},{"id":9,"nickname":"Natalia Ruecker","email":"stroman.kiley@example.com"},{"id":10,"nickname":"Hallie Parisian","email":"rosina74@example.net"},{"id":11,"nickname":"Jiannei","email":"longjian.huang@foxmail.com"}],"meta":{"pagination":{"total":11,"count":11,"per_page":15,"current_page":1,"total_pages":1,"links":[]}}},"error":[]},"start":1610942614.450748,"end":1610942615.785696,"duration":"1.33s"} {"url":"/users","ip":"172.22.0.1","http_method":"GET","server":"lumen-api.test","referrer":null,"unique_id":"43f54ea9-4ad4-47cf-b9da-1d3aa150ff61"}

• 记录到 Mongodb 的日志内容

/* 1 */ { "_id" : ObjectId("60050999ee7d025d4c62c8c2"), "message" : "System sql", "context" : { "database" : "lumen-api", "duration" : "54.19ms", "sql" : "select count(*) as aggregate from `users`" }, "level" : 100, "level_name" : "DEBUG", "channel" : "mongo", "datetime" : ISODate("2021-01-18T12:07:53.410+08:00"), "extra" : { "url" : "/users", "ip" : "172.22.0.1", "http_method" : "get", "server" : "lumen-api.test", "referrer" : null, "unique_id" : "0cda1927-bf14-4acf-88e8-1d9ed67170b5" } } /* 2 */ { "_id" : ObjectId("60050999ee7d025d4c62c8c3"), "message" : "System sql", "context" : { "database" : "lumen-api", "duration" : "2.42ms", "sql" : "select * from `users` limit 15 offset 0" }, "level" : 100, "level_name" : "DEBUG", "channel" : "mongo", "datetime" : ISODate("2021-01-18T12:07:53.500+08:00"), "extra" : { "url" : "/users", "ip" : "172.22.0.1", "http_method" : "get", "server" : "lumen-api.test", "referrer" : null, "unique_id" : "0cda1927-bf14-4acf-88e8-1d9ed67170b5" } }

特别说明

• SQL 日志记录参考：laravel-query-logger

其他

如果对您的日常工作有所帮助或启发，欢迎三连 star + fork + follow。

如果有任何批评建议，通过邮箱（longjian.huang@foxmail.com）的方式可以联系到我。

总之，欢迎各路英雄好汉。

QQ 群：1105120693

本作品采用《CC 协议》，转载必须注明作者和本文链接