Hical 踩坑实录五部曲(三):自研日志系统的 8 个血泪教训
Hical 踩坑实录五部曲(三):自研日志系统的 8 个血泪教训 引言 Hical 没有用 spdlog、glog 或任何第三方日志库——整套日志系统完全自研,覆盖 20+ 个源文件:格式化、Sink 后端、文件轮转、异步双缓冲、通道分流、HTTP 集成、运行时调级。 自研日志的好处在开发心得里聊过了。这篇只聊坑——从"能跑"到"能在生产环境跑"的过程中,踩过的 8 个真实问题。 目录 Hical 踩坑实录五部曲(三):自研日志系统的 8 个血泪教训 引言 目录 坑 1:异步写盘的背压——日志不应该成为延迟来源 坑 2:双缓冲析构时丢日志 坑 3:多线程 Sink 分发的锁竞争——COW 模式的引入 坑 4:日志注入——一条恶意日志伪造十行告警 坑 5:LogAdmin 的审计致盲攻击 坑 6:TRACE 日志在 Release 构建中的隐性开销 坑 7:trace-id 生成的性能瓶颈——OpenSSL 全局锁 坑 8:文件轮转的误删风险 总结:自研日志系统的检查清单 坑 1:异步写盘的背压——日志不应该成为延迟来源 现象:压测时发现 P99 延迟间歇性飙高。排查发现不是业务逻辑慢,而是日志写入阻塞了请求线程。 根因:早期版本的日志直接在调用线程同步 fwrite。高并发下磁盘 I/O 成为瓶颈,日志调用从微秒级退化为毫秒级。 引入异步 AsyncFileSink 后,新的问题出现——如果日志产生速度远超写盘速度(比如某个 bug 触发了大量 ERROR 日志),前端缓冲区会无限增长直到 OOM。 解决方案:背压保护——缓冲区超限时主动丢弃,而非阻塞或 OOM: 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 // AsyncFileSink.cpp — write() 中的背压丢弃 void AsyncFileSink::write(std::string_view formattedLine) { std::lock_guard<std::mutex> lock(m_bufMutex); // 背压保护:缓冲区过大时丢弃(防止内存爆炸) if (m_curBuf.size() > m_opts.backpressureLimit) { m_dropped.fetch_add(1, std::memory_order_relaxed); return; // 丢弃这条日志,但不阻塞调用线程 } m_curBuf.append(formattedLine.data(), formattedLine.size()); // 缓冲区接近满时通知后台线程 if (m_curBuf.size() >= m_opts.bufferSize) { m_cond.notify_one(); } } 关键细节:丢弃计数不是默默吞掉的——后台线程在每次刷盘时检查丢弃计数,并将统计写入日志文件: ...