C++ 日志库大体上有两种 API 风格:
image.png
Stream 风格使用起来更自然,不必费心保持格式字符串与参数类型的一致性。而且当输出日志级别高于日志级别时,打印日志是个空操作运行时开销接近零

5.1 功能需求

日志需要有多种 level:TRACE、DEBUG、INFO、WARN、ERROR、FATAL等。

日志输出级别应该在运行时可调整,不应重新编译,也不需要重启进程,只要调用setLogLevel()就能即时生效。

对于分布式系统中的服务进程,日志的目的地——本地文件。不能往网络写日志消息,因为诊断日志的功能之一就是诊断网络故障。

如果日志输出到本地文件,那么必须要滚动,这样可以简化日志归档的实现。滚动条件如下:

  • 文件大小(达到阈值就换下一个文件)
  • 时间(每天固定时间新建一个日志文件,不论前一个文件有没有写满)

日志命名规范
一个典型日志文件名如下:
image.png

  • 第一部分logfile_test进程名,通常是main()函数参数中argv[0]的 basename,必要时可以加入程序 version。(basename 得到特定路径中的最后一个’/‘后面的内容)
  • 第二部分:文件创建时间(GMT 时区),可以通过文件名来选择某一时间范围内的日志。
  • 第三部分:机器名称,这样即便日志文件发生机器间拷贝,也可以溯源。
  • 第四部分:进程 id,如果一个程序一秒之内反复启动,那么每次都会生成不同的日志文件。
  • 第五部分:统一后缀名.log

程序 crash 时日志相关问题
如果程序发生崩溃,那么最后若干条日志往往会丢失,因为日志库不能每条消息都刷盘更不能每条消息都 open/close 文件,性能开销过大。
muduo 采用两种办法:

  • 定期(默认 3 秒)将缓冲区的日志消息 flush 到硬盘。
  • 每条内存中的日志消息都带有 cookie(或者叫哨兵/sentry),其值为某个函数的地址,这样可以在 core dump 文件中查找 cookie,定位到尚未来得及写入磁盘的消息。

日志消息格式 HINTS

  • 每条日志占一行。方便用awk``sed``grep等命令行工具定位。
  • 时间戳精确到微秒。每条消息都通过gettimeofday()获得当前时间,因为不是系统调用所以没有性能损失。
  • 始终使用 GMT 时区。
  • 打印线程 id。便于缝隙多线程程序的时序,也可以检测死锁。(此处指调用 LOG_INFO<< 的线程)
  • 打印日志级别
  • 打印源文件名和行号

    5.2 性能需求

    image.png

muduo 中使用了几个优化措施,以达到性能指标:

  • 时间戳字符串中的日期和时间两部分是缓存的,一秒之内的多条日志只需重新格式化微秒部分。
  • 日志消息的前 4 个字段是定长的,可以避免在运行期求字符串长度(避免反复调用strlen())。因为编译期认识memcpy()函数,对于定长的内存复制,会在编译期把它 inline 展开为高效的目标代码
  • 线程 id 是预格式化为字符串,在输出日志消息时只发生拷贝,而不产生调用。
  • 源文件名采用编译期计算获得 basename,避免运行期strrchr()开销。

    5.3 多线程异步日志

    多线程日志追求线程安全,简单的做法和其后果是:

  • 用一个全局mutex保护 IO——造成全部线程抢一个锁;

  • 每个线程单独写一个日志文件——让业务线程阻塞在写磁盘操作上。

异步日志(非阻塞日志):用一个背景线程负责收集日志消息,并写入日志文件,其他业务线程只往这个背景线程发送日志消息。
因为网络 IO 线程或业务线程,直接进行写磁盘的话,可能偶尔会发生阻塞。这可能导致请求方超时、耽误发送心跳消息等。

需要一个“队列”将各个线程待写的日志消息传送到日志线程不必每次产生一条消息都通知背景线程

muduo 日志库采用双缓冲技术
准备两块 buffer:A & B。业务线程负责往 buffer A 填充日志消息,背景线程负责将 buffer B 的数据写入文件。当 buffer A 写满之后,交换 A & B,让背景线程将 buffer A 的数据写入文件,业务线程往 buffer B 中填充日志消息。如此往复。此外,为了及时刷盘,即便 buffer 未满也会定期(预设值 == 3 秒)执行上述 swap-write 操作。
使用两个 buffer 的好处:产生新的日志消息时不必等待磁盘文件操作,也避免每条新日志消息都 wake-up 背景线程。减少了 wake-up 频度、降低开销

muduo 部分源码内容和解读可以看原书 § 5.3最后。

5.4 其他方案

image.png