3、日志系统设计:日志级别与分类、结构化日志输出、日志轮转与性能影响

日志这东西,说白了就是桌面应用的「黑匣子」。

我刚入行那会儿,觉得日志就是printf,随便打打就行。结果有一次,用户反馈程序崩溃,我愣是盯着满屏的「info: xxx」看了三天,啥也没找到。从那以后,我彻底明白了——日志系统设计不好,调试就是噩梦。

今天咱们聊聊怎么把日志系统设计得既好用又不拖累性能。

3.1 日志级别与分类:别什么都往一个桶里扔

日志级别,我习惯用这五个:TRACE、DEBUG、INFO、WARN、ERROR

你想想看,如果所有日志都打成一个级别,那跟没打有什么区别?

核心原则:生产环境只开INFO及以上,DEBUG和TRACE留给开发调试用。

我个人习惯这样分配:

  • TRACE:函数入口出口、循环每次迭代。这东西日志量巨大,我一般只在定位死循环或逻辑分支问题时才开。
  • DEBUG:变量中间值、关键判断结果。开发阶段必开,上线前关掉。
  • INFO:用户操作、模块启动关闭、配置加载。记录「谁在什么时候干了什么」。
  • WARN:配置异常、重试操作、降级处理。不影响运行,但值得关注。
  • ERROR:异常捕获、资源加载失败、数据校验不通过。必须立即处理。

我在项目中遇到过一个问题:有个同事把所有日志都打成了ERROR。结果每天几千条ERROR日志,真正的崩溃反而被淹没了。嗯,这就是典型的「狼来了」效应。

小技巧:可以用枚举或常量定义日志级别,运行时动态调整。比如在设置界面加个「调试模式」开关,打开后自动切换到DEBUG级别。

3.2 结构化日志输出:让机器也能读懂

传统的日志长这样:

2024-01-15 10:30:22 [INFO] 用户登录成功,用户名:张三,IP:192.168.1.1

看着还行对吧?但如果你要写脚本分析日志,或者接入ELK这类日志平台,这种格式就让人头疼了。

为什么?因为它是非结构化的。你想提取「用户名」字段,得用正则匹配,而且不同模块的日志格式可能还不一样。

我建议用结构化日志,说白了就是JSON格式:

{
  "timestamp": "2024-01-15T10:30:22.123Z",
  "level": "INFO",
  "module": "AuthService",
  "action": "login",
  "username": "张三",
  "ip": "192.168.1.1",
  "duration_ms": 45,
  "thread_id": 1234
}

这样做的好处很明显:

  • 机器解析方便,直接JSON.parse就能用
  • 字段统一,不同模块的日志可以合并分析
  • 可以加自定义字段,比如耗时、线程ID、请求追踪ID

注意:结构化日志不要手写JSON字符串,容易出错。用现成的日志库,比如C++的spdlog、C#的Serilog、Python的structlog,它们都支持直接输出结构化格式。

我曾经踩过一个坑:手写JSON拼接,结果某个字段里带了双引号,直接把日志搞崩了。后来老老实实用库,再也没出过问题。

3.3 日志轮转:别让日志撑爆硬盘

桌面应用跑个几天,日志文件可能就几百MB了。如果不做轮转,硬盘迟早被撑爆。

日志轮转,说白了就是「旧日志该删就删,该压缩就压缩」。

我常用的策略有三种:

策略 说明 适用场景
按大小轮转 单个日志文件达到10MB,自动切分 日志量稳定的应用
按时间轮转 每天/每小时生成一个新文件 需要按时间回溯的场景
混合轮转 同时限制大小和时间,哪个先到切哪个 大多数桌面应用

我个人习惯用混合轮转:每个文件不超过10MB,每天最多保留7个文件。超过7天的自动删除,或者压缩归档。

经验之谈:保留策略不要太激进。我见过有人只保留3天的日志,结果周末出问题,周一上班日志已经被清了。建议至少保留7天,关键应用保留30天。

3.4 性能影响:日志不能成为性能瓶颈

日志写得太频繁,IO会成为瓶颈。你想想看,如果每次打日志都同步写磁盘,那用户操作卡顿是必然的。

怎么优化?我总结了几个要点:

  • 异步写入:日志先写到内存缓冲区,后台线程批量刷盘。大部分日志库都支持这个模式。
  • 批量刷盘:攒够一定数量或一定时间再写一次,减少IO次数。
  • 分级过滤:生产环境只输出INFO及以上,DEBUG日志直接丢弃,不产生IO。
  • 避免字符串拼接:很多日志库支持格式化参数,比如log.info("用户 {} 登录", username),只在真正输出时才拼接字符串。

实测数据:在我之前的一个项目中,同步日志导致界面响应延迟从5ms飙升到200ms。改成异步后,延迟降回8ms,几乎无感。

还有一个容易被忽略的点:日志级别判断。如果你写的是:

log.debug("当前用户信息:" + user.toString());

即使DEBUG级别被关闭,user.toString()也会被执行,白白浪费性能。

正确的写法是:

if (log.isDebugEnabled()) {
    log.debug("当前用户信息:{}", user);
}

或者直接用支持惰性求值的日志库,比如slf4j的占位符方式。

避坑指南:我曾经在一个高频调用的循环里打了TRACE日志,结果程序直接卡死。后来发现每秒写了上万条日志,IO完全跟不上。记住:高频路径上,日志能省则省。

3.5 总结一下

日志系统设计,其实就三件事:

  1. 分好级别:别什么都打INFO,也别什么都打ERROR。
  2. 结构化输出:方便机器分析,也方便人看。
  3. 控制性能:异步、批量、惰性求值,一个都不能少。

嗯,做到这三点,你的日志系统基本就合格了。剩下的就是根据实际场景微调参数了。