高效的多线程日志
- 日志(logging)有两个意思:
- 诊断日志(diagnostic log), 常用日志库提供日志功能;
- 交易日志(transaction log), 用于记录状态变更, 通过回放日志可以逐步恢复每一次修改后的状态;
- 日志通常用于故障诊断和追踪(trace), 也可用于性能分析;
- 日志通常是分布式系统中事故调查时的唯一线索, 用来追寻蛛丝马迹, 查出原凶;
- Log Everything All The Time;
- 关于进程, 日志通常要记录:
- 收到每条内部消息的ID(还可以包括关键字段、长度、hash等);
- 收到的每条外部消息的全文;
- 发出每条消息的全文, 每条消息都有全局唯一的id;
- 关键内部状态的变更, 等等;
- 每条日志都有时间戳, 这样就能完整追踪分布式系统中一个事件的来龙去脉;
- 一个日志文件可分为前端(frontend)和后端(backend)两部分;
- 前端提供应用程序使用的接口(API), 并生成日志消息(log message);
- 后端则负责把日志消息写到目的地(destination);
- 典型的多生产者-单消费者问题, 对生产者(前端)而言, 要尽量做到低延迟、低CPU开销、无阻塞;
- 对消费者(后端)而言, 要做到足够大的吞吐量, 并占用较少资源;
- 对C++程序而言, 最好整个程序(包括主程序和程序库)都使用相同的日志库, 日志有一个整体的日志输出, 而且不要各个组件有各自的日志输出;
- 从这个意义上讲, 日志库是个singleton模式(单例模式);
- muduo没有用标准库中的iostream, 而是自己写的LogStream class, 主要是出于性能原因;
功能需求
- 日志消息有多种级别(level): TRACE、DEBUG、INFO、ERROR、FATAL等;
- 日志消息可能有多个目的地(appender), 如文件、socket、SMTP等;
- 日志消息的格式可配置(layout), 例如org.apache.log4j.PatternLayout;
- 可以设置运行时过滤器(filter), 控制不同组件的日志消息的级别和目的地;
- 质量保证(QA)测试环境的时候输出DEBUG级别的日志, 在生产环境输出INFO级别的日志;
- 只要调用muduo::Logger::setLogLevel()就能立即生效;
- 对于分布式系统中的服务进程而言, 日志的目的第(destination)只有一个:本地文件;
- 日志文件的滚动(rolling)是必需的, 这样可以简化日志归档(archive)的实现;
- rolling的条件通常有两个: 文件大小(例如每写满1GB就换下一个文件)和时间(例如每天零点新建一个日志文件, 不论前一个文件有没有写满);
- 一般的日志库都会自动根据文件大小和时间来主动滚动日志文件;
- 能主动rolling, 自然也就不必支持SIGUSR1了, 毕竟多线程程序处理signal很麻烦;
- 日志库的压缩与归档(archive)不是日志库应该有的功能, 而应该交给专门的脚本去做;
- 磁盘空间监控也不是日志库的必备功能;
- muduo日志库: 其一是定期(默认3秒), 将缓冲区内的日志消息flush到磁盘;
- 其二是每条内存中的日志消息都带有cookie(或者叫哨兵值/sentry), 其值为某个函数的地址, 这样通过core dump文件中查找cookie就能找到尚未来得及写入磁盘的消息;
- 日志消息格式有几个要点:
- 尽量每条日志占一行;
- 时间戳精确到微妙;
- 始终使用GMT时区(Z);
- 答应线程id;
- 打印日志级别;
- 打印源文件名和行号;
性能需求
- 日志库的高效性体现在几个方面:
- 每秒写上千万条日志的时候没有明显的性能损失;
- 能应对一个进程生产大量日志数据的场景, 例如1GB/min;
- 不阻塞正常的执行流程;
- 在多程序程序中, 不造成争用(contention);
- 磁盘带宽约是110MB/S, 日志库应该能瞬时写满这个带宽(不必持续太久);
- 假如每条日志消息的平均长度是110字节, 这就意味着1秒要写100万条日志;
- muduo日志库实现了几点优化措施:
- 时间戳字符串中的日期和时间部分是缓存的, 一秒内的多条日志只需要重新格式化微妙部分;
- 日志消息的前4个字段是定长的, 因此可以避免在运行期求字符串长度(不会反复调用strlen);
- 因为编译器认识memcpy()函数, 对于定长的内存复制, 会在编译期把它的inline展开为高效的目标代码;
- 线程id是预先格式化为字符串, 在输出日志消息时只需要简单拷贝几个字节;
- 每行日志消息的源文件名部分采用了编译期计算来获得basename, 避免运行期strrchr()开销;
多线程异步日志
- 多线程程序对日志库提出了新的需求:线程安全, 即多个程序可以并发写日志, 两个线程的日志消息不会出现交织;
- 多线程的每个进程最好只写一个日志文件;
- 用一个背景线程收集日志消息, 并写入日志文件, 其他业务线程只管往这个日志线程发送日志消息, 这称为异步日志;
- 非阻塞日志;
- 我们需要一个队列将日志前端的数据传送到后端(日志线程);
- muduo日志库采用的是双缓冲(double buffering)技术;
- 基本思路是准备两块buffer:A和B, 前端负责往buffer A填数据(日志消息), 后端负责将buffer B的数据写入文件;
- 当buffer A写满之后, 交换A和B, 让后端将buffer A的数据写入文件, 而前端则往buffer B填入新的日志消息, 如此往复;
- 为了及时将日志消息写入文件, 即便buffer A未满, 日志库也会每3秒执行一次上述交换写入操作;
- 对于异步日志来说, 这是典型的生产速度高于消费速度问题, 会造成数据在内存中的堆积, 严重时引发性能问题(可用内存不足)或程序崩溃(分配内存失败);
- 直接丢弃掉多余的日志buffer, 以腾出内存, 这样可以防止程序库本身引起程序故障, 是一种自我保护措施;
- 也可以加入网络报警功能, 通知人工介入, 以尽快修复故障;
- 性能不能凭感觉说了算, 一定要有典型场景的测试数据做为支撑;
- muduo库的异步日志实现用了一个全局锁;
- java的ConcurrentHashMap那样用多个桶子(bucket), 前端写日志的时候再按线程id哈希到不同的bucket中, 以减少contention(后端实现比较复杂);
- Linux默认会把core dump写到当前目录, 而且文件名是固定的core;
posted @
2018-10-14 16:30
coding-for-self
阅读(
327)
评论()
编辑
收藏
举报