多彩编程 多彩编程MZPH · CODE BLOG
ARTICLE DETAIL

文章详情

深耕前端与后端开发技术的一线实战笔记与踩坑复盘。

Webman实战:Monolog日志优化指南(精准定位、分级存储、彩色输出)

Webman实战:Monolog日志优化指南(精准定位、分级存储、彩色输出) 很多人用 Webman 跑线上服务最后都会卡在同一个地方日志。默认装完就带一套 Monolog 日志方案但说实话默认配置在真实项目里基本不够用——一个webman.log文件所有级别、所有业务日志混在一起出了问题去grep的时候你会怀疑人生。我自己维护的几套 API 服务都踩过这个坑后来专门在 Monolog 层面做了三轮优化精准定位、分级存储、控制台彩色输出。这篇文章就当是整理出来的升级手册适合用 Webman 做接口服务、跑队列任务、维护后台系统的同学参考。1. 先搞清楚Webman的日志机制再谈优化1.1 默认日志配置到底长什么样用composer create-project workerman/webman装好项目后日志相关配置在config/log.php默认结构大概是这样的return [ default [ handlers [ [ class Monolog\Handler\RotatingFileHandler::class, constructor [ filename runtime_path() . /logs/webman.log, max_files 7, level Monolog\Logger::DEBUG, ], formatter [ class Monolog\Formatter\LineFormatter::class, constructor [ format null, dateFormat Y-m-d H:i:s, allowInlineLineBreaks true, ], ], ], ], processors [], ], ];业务里直接用support\Log::info(xxx)就会走到这个默认通道最终所有记录汇入同一个文件。它能用但不好用没有上下文、没有级别隔离、输出格式单一。Webman 的Log类是 Monolog 的封装Log::channel(xxx)可以切换到其他通道但默认情况下你只有 default 这一个通道所以后续所有改动都集中在 default 通道上做业务代码不需要改。1.2 Handler、Formatter、Processor 各司其职在动手之前得先把 Monolog 的几个概念捋清楚。很多优化做不好都是因为这层没理解透。一条日志从记录到落盘会经过这样的链路进程调用 Logger 的info()/error()方法 → Logger 把级别、消息、上下文打包成一条 record → Processor 依次处理这条 record比如塞 request_id→ Handler 判断这条 record 是否达到自己设置的 level 门槛 → 达到后用 Formatter 格式化 → 写入 stdout 或文件。用一个生活类比Logger 是接待台Handler 是快递员Formatter 决定快递单长什么样Processor 相当于寄件前先帮你在包裹上贴一圈信息请求ID、用户ID。这里有个关键点级别过滤不是 Logger 管而是每个 Handler 自己管。同一个 Logger 可以挂多个 Handler一条日志会依次经过所有 Handler。每个 Handler 有自己的bubble属性如果是true处理完这条日志后还会继续传给下一个 Handler如果是false处理完就短路。这个机制后面分级存储会反复用到先记在心里。2. 精准定位让每条日志自带“身份证”2.1 为什么日志会“找不到北”线上 QPS 一上来日志是并发交错写的。你搜索一个订单号能搜出一堆关联记录但没法确认哪些是同一时刻同一个用户发的。更难受的是前端报了个错误后端日志只有一句“查询用户失败”没有 IP、没有路由、没有请求ID查起来全靠缘分。精准定位的目标就是每条日志天然携带请求上下文不需要从其他系统去反查。这个目标拆解下来其实就两步先生成一个唯一的请求 ID再把这个 ID 注入到日志记录里。2.2 用中间件生成 Request-ID首先得让每一次请求有一个唯一 ID。在 Webman 里加一个全局中间件成本很低namespace app\middleware; use support\Request; use Webman\MiddlewareInterface; class RequestIdMiddleware { public function process(Request $request, callable $next): \Webman\Http\Response { $request-rid str_replace(., , uniqid(req_, true)); return $next($request); } }然后在config/middleware.php的global里注册它return [ global [ \app\middleware\RequestIdMiddleware::class, ], ];为什么用uniqid而不是mt_rand()高并发下即使概率很低也不能赌真随机有极小概率重复uniqid结合时间戳和进程 ID重复概率可以压到足够低。如果你对接了网关也可以直接取网关传过来的 traceId 或 x-request-id那串 ID 贯穿全链路排查能力更强。2.3 用 Processor 把请求信息注入每一条日志请求 ID 生成之后怎么让日志系统自动带上它Monolog 的 Processor 机制就是干这件事的。写一个自定义 Processornamespace support\Log\Processor; use Monolog\LogRecord; class RequestContextProcessor { public function __invoke(LogRecord $record): LogRecord { $request request(); if ($request) { $record[extra][request_id] $request-rid ?? ; $record[extra][method] $request-method(); $record[extra][uri] $request-uri(); $record[extra][ip] $request-getRemoteIp(); } else { $record[extra][request_id] cli; } return $record; } }然后在config/log.php的 default 通道里注册processors [ \support\Log\Processor\RequestContextProcessor::class, ],这里要注意版本差异我写的是 Monolog 3 的LogRecord类型如果你的项目还在用 Monolog 2把参数类型改成array即可。request()在请求链路里返回当前 Request 对象在命令行下返回 null所以 else 分支给一个默认值不然队列任务或定时任务里打日志时会缺字段。2.4 输出格式设计与业务关键词注入光有 extra 里的字段还不够必须让格式化输出把它们打印出来。在config/log.php的 formatter 里把默认格式改成formatter [ class Monolog\Formatter\LineFormatter::class, constructor [ format [%datetime%] %level_name% %message% %context% %extra%\n, dateFormat Y-m-d H:i:s, allowInlineLineBreaks true, ], ],%extra%会把 Processor 塞进去的请求信息以 JSON 形式输出。实际效果长这样[2025-01-31 15:04:03] INFO 查询订单成功 {order_id:10086} {request_id:req_abc123,method:GET,uri:/order/detail,ip:10.0.0.3}一眼就能看出这条日志属于哪次请求、打了哪个接口、客户端从哪来。业务侧还有一类定位需求比如支付回调时写日志你希望后续能按订单号搜索。这种场景建议不要把业务 ID 只写在消息里而是放进 context 数组Log::info(支付回调处理完成, [order_id $orderId, channel wechat]);Monolog 会把 context 自动 JSON 化配合 grep 订单号就能把同一个订单的所有日志捞出来。消息负责给人看context 负责给机器和 grep 用这个习惯养成了后面排查效率能翻倍。3. 分级存储让日志文件各回各家3.1 单文件日志在线上有多痛苦第一部分说的默认配置就是把 debug、info、warning、error 全部写进同一个文件。上线初期问题不大流量起来之后痛点非常明显文件写入量大你想看 error 的时候也要在几十 MB 的文件里翻error 和 info 混在一起告警脚本没法简单按文件 tail日志保留周期不好做全量保留浪费磁盘想只保留 error 又没法分。所以分级存储不是炫技是运维监控的基本盘。我推荐的分层方案是文件内容debug.logdebug 及以上纯调试用info.loginfo 及以上业务主线warning.logwarning 及以上需要留意error.logerror 及以上故障排查每一层文件都包含当前级别和更高级别的日志越往下越“浓缩”。3.2 方案A多个Handler组合的分级写法及其坑最简单的方式是给 default 通道直接挂多个 RotatingFileHandlerhandlers [ [ class \Monolog\Handler\RotatingFileHandler::class, constructor [ filename runtime_path() . /logs/info.log, level \Monolog\Logger::DEBUG, ], ], [ class \Monolog\Handler\RotatingFileHandler::class, constructor [ filename runtime_path() . /logs/error.log, level \Monolog\Logger::ERROR, ], ], ],这样一条 error 会同时写进 info.log 和 error.log。info.log 是全量error.log 是错误集看起来能满足需求。问题在于如果你想 error 只进 error.log不污染 info.log就需要把 info.log 的bubble设为 false并且把 error handler 放在前面。但一旦 bubblefalse更高的日志在第一个 handler 就短路了warning、error 都进不了后置 handler文件分配一下子就乱了。多用多 Handler 组合的天然缺点是多个 handler 共享同一套 formatter 配置分隔逻辑全靠先后顺序和 bubble层数多了以后非常难调。作为临时方案可以但别想靠它把三个文件都切干净。3.3 方案B自定义Handler按级别路由到不同文件更好的办法是写一个自定义 Handler自己接管“这条日志该进哪个文件”。核心代码namespace support\Log\Handler; use Monolog\Handler\AbstractProcessingHandler; use Monolog\Handler\RotatingFileHandler; use Monolog\Logger; use Monolog\LogRecord; use Monolog\Formatter\FormatterInterface; use Monolog\Handler\HandlerInterface; class LevelSplitHandler extends AbstractProcessingHandler { private array $targetHandlers []; public function __construct(array $fileMap, $level Logger::DEBUG, bool $bubble true) { parent::__construct($level, $bubble); foreach ($fileMap as $targetLevel $fileConfig) { [$filename, $maxFiles] $fileConfig; $lv Logger::toMonologLevel($targetLevel); $this-targetHandlers[$lv-value] new RotatingFileHandler($filename, $maxFiles, $lv); } } public function setFormatter(FormatterInterface $formatter): HandlerInterface { $this-formatter $formatter; foreach ($this-targetHandlers as $handler) { $handler-setFormatter($formatter); } return $this; } protected function write(LogRecord $record): void { foreach ($this-targetHandlers as $threshold $handler) { if ($record-level-value $threshold) { $handler-handle($record); } } } }逻辑很简单把fileMap里每个级别对应的文件名和保留天数实例化成独立的 RotatingFileHandlerwrite()时只要 record 的级别大于等于某个目标 handler 的阈值就写进去。这样 info 会进 debug/info 两份如果 debug 阈值是 DEBUG、info 阈值是 INFOwarning 会进 warning/error 两份error 只进 error 一份——正是上面那张表的效果。有一个坑必须提醒Monolog 内部会调用外层 Handler 的setFormatter()但内部这些 RotatingFileHandler 不会自动继承。如果不重写setFormatter()并把 formatter 同步下去你会看到文件里输出一堆缺格式的 JSON 数据。这个细节我在第一次实现时踩过而且踩得很深。然后config/log.php里注册handlers [ [ class \support\Log\Handler\LevelSplitHandler::class, constructor [ fileMap [ debug [runtime_path() . /logs/debug.log, 3], info [runtime_path() . /logs/info.log, 7], warning [runtime_path() . /logs/warning.log, 14], error [runtime_path() . /logs/error.log, 30], ], level \Monolog\Logger::DEBUG, ], formatter [ class \Monolog\Formatter\LineFormatter::class, constructor [ format [%datetime%] %level_name% %message% %context% %extra%\n, dateFormat Y-m-d H:i:s, allowInlineLineBreaks true, ], ], ], ],这也意味着业务代码里Log::info()/Log::error()不需要改一行。你只是在通道层面增加了路由规则侵入性非常低。3.4 文件切片与保留策略RotatingFileHandler 的日志文件名会自动加上日期比如error-2025-01-31.logmax_files控制最多保留多少份。这里有几个经验值可以参考debug 文件保留 3 天足够因为它定位是临时排查info 一周warning 两周error 至少一个月线上事故复盘经常要翻几周之前的错误记录。磁盘紧张的话warning 和 info 可以合并成相同周期但 error 务必留够。另外如果容器里跑 Webman日志目录最好挂载到宿主机并通过 logrotate 或定时任务做归档否则容器重建时日志跟着没了事后想找原因也无从下手。4. 控制台彩色输出调试时一眼分辨日志级别4.1 终端日志可读性问题与ANSI原理开发环境跑php start.php start时日志大部分时间是在终端里看的。黑白日志最大的问题是warning 和 error 淹没在信息流里眼睛看漏一个告警可能等到用户投诉才发现。彩色日志本质只是在输出里嵌入 ANSI 转义码例如\033[31m表示后面文字变红\033[0m恢复默认。终端识别这些码但在文件里看就是乱码所以这个功能的使用场景集中在开发调试和命令行辅助脚本生产环境写文件必须关掉。4.2 实现一个带颜色的ConsoleHandler先写一个向 STDOUT 输出的 Handlernamespace support\Log\Handler; use Monolog\Handler\StreamHandler; use Monolog\Logger; class ConsoleHandler extends StreamHandler { public function __construct($level Logger::DEBUG, bool $bubble true) { parent::__construct(php://stdout, $level, $bubble); } }再写一个带颜色的 Formatternamespace support\Log\Formatter; use Monolog\Formatter\LineFormatter; use Monolog\LogRecord; class ColorFormatter extends LineFormatter { private const COLOR_MAP [ DEBUG 0;36, INFO 0;32, NOTICE 0;33, WARNING 1;33, ERROR 1;31, CRITICAL 1;41, ALERT 1;45, EMERGENCY 1;31, ]; public function format(LogRecord $record): string { $color self::COLOR_MAP[$record-level-getName()] ?? 0; return \033[{$color}m . parent::format($record) . \033[0m; } }看到COLOR_MAP里的那串数字不用慌这是固定格式第一位 0/1 控制普通/加粗第二位 30-37 控制前景色41/45 是背景色。我给 WARNING 用1;33黄色加粗ERROR 用1;31红色加粗CRITICAL 直接红底严重级别扫一眼就能看到。4.3 在Webman中按环境启用彩色输出关键一步是按环境决定开发环境挂 ConsoleHandler生产环境不挂。在config/log.php里用 PHP 动态拼$handlers []; if (config(app.debug, false)) { $handlers[] [ class \support\Log\Handler\ConsoleHandler::class, constructor [level \Monolog\Logger::DEBUG], formatter [ class \support\Log\Formatter\ColorFormatter::class, constructor [ format [%datetime%] %level_name% %message% %context% %extra%\n, dateFormat Y-m-d H:i:s, allowInlineLineBreaks true, ], ], ]; } $handlers[] [ class \support\Log\Handler\LevelSplitHandler::class, constructor [ fileMap [ debug [runtime_path() . /logs/debug.log, 3], info [runtime_path() . /logs/info.log, 7], warning [runtime_path() . /logs/warning.log, 14], error [runtime_path() . /logs/error.log, 30], ], level \Monolog\Logger::DEBUG, ], formatter [ class \Monolog\Formatter\LineFormatter::class, constructor [ format [%datetime%] %level_name% %message% %context% %extra%\n, dateFormat Y-m-d H:i:s, allowInlineLineBreaks true, ], ], ]; return [ default [ handlers $handlers, processors [ \support\Log\Processor\RequestContextProcessor::class, ], ], ];这样开发环境终端有颜色、文件有分级生产环境文件分级照旧不输出到控制台。开发时你tail -f runtime/logs/error.log看到的还是正常无颜色文本不会脏。要特别注意如果你在生产把彩色日志重定向到了文件之后用编辑器打开全是^[[31m这几乎是这个方案最常见的翻车现场。我见过有人把 ConsoleHandler 挂到了生产配置里一天下来日志文件里全是转义字符排查脚本直接失效。5. 常见问题与排查技巧实录把我在实际使用中遇到过的典型问题整理成一张速查表基本都是新手比较容易踩的现象原因快速解决日志时间比本地时间慢8小时PHPdate.timezone未设置Monolog 默认 UTC设置date.timezoneAsia/Shanghai或给 Formatter 设置时区日志文件出现^[[31m乱码生产环境误开彩色输出用config(app.debug)控制是否注册 ConsoleHandlererror 没写进 error.logHandler 顺序和 bubble 配置问题改用 LevelSplitHandler别手工控制顺序自定义 Handler 输出格式不对内部 Handler 没继承顶层 formatter重写setFormatter()并同步内部 Handler日志目录权限导致写入失败CLI/FPM 运行用户不一致统一运行用户目录权限 755 或 775磁盘被日志占满保留周期过长或未配 maxFiles按级别设置不同保留天数及时轮转每个问题都可以多说两句。时间慢 8 小时那个我建议直接在 php.ini 里设置date.timezone一劳永逸不要在每个项目里写date_default_timezone_set()否则换了环境又忘了。如果用的是 DockerDockerfile 里也顺手加上。彩色乱码那个排查思路很简单先看config(app.debug)是不是在生产环境被误设成了 true再看php.ini有没有把 display_errors 打开影响判断。这两个因素都很常见。error 没进 error.log 这个问题本质是没吃透 bubble。Monolog 的 Logger 会按 handlers 数组顺序逐层处理bubbletrue 表示“这条日志我可以处理但处理完不拦住继续传给下一个 handler”bubblefalse 表示“我处理完就结束别传给后面的”。多 handler 方案里想用顺序和 bubble 实现精确分级逻辑非常绕这也是我后来直接写自定义 Handler 的原因。formatter 不生效那个是最容易忽略的。Monolog 装配 Handler 时会把 formatter 设置在外层 Handler 实例上你自己包的那些内部 Handler 不在管理范围内。不重写setFormatter()内部 Handler 就一直用默认的 JSON 格式输出你看到的日志就是一行行“裸”数据。这个问题排查起来耗时但改起来就一行。日志权限问题多见于 Webman 以 root 启动 master 进程、worker 进程以 www 用户运行的情况或 CLI 和 PHP-FPM 用户不一致。统一运行用户或者保证 runtime 目录组权限正确即可。有些团队把日志目录挂在 NFS 上也要注意协议对文件锁的支持不然并发写入会有性能问题。最后再分享一点个人经验日志系统做到这个程度基本就够用了。我的落地顺序建议是先做 Processor 注入 request_id再做分级存储最后再折腾彩色输出。前两步是保命用的第三部纯粹是开发体验优化。遇到线上问题先 tail error.log再按 request_id 把 info 日志串起来看上下文基本能覆盖大部分故障场景。有个小技巧在终端里给 error 日志配个别名比如alias logerrtail -f runtime/logs/error.log每次排查能省不少打字时间。别忘了日志系统是写给未来的自己看的今天多花半小时配置未来排查能省下五个小时。
返回列表