日志查看与分析基础：日志级别、关键字段、常见日志格式解析
做密文检索排查，第一件事就是翻日志。没有日志，你就像蒙着眼睛修机器。但我发现很多新手拿到日志就懵，密密麻麻的文本不知道看哪里。
其实日志没那么玄乎。你只需要搞清楚三个东西：日志级别、关键字段、格式。搞懂了，排查效率至少翻一倍。我自己刚入行时，花了一周才找到的 bug，现在半小时就能定位——差别就在会不会看日志。
日志级别：先筛掉噪音
日志级别是个金字塔。越往上，问题越严重，数量越少。你想想看，线上一个服务一秒输出几万条 DEBUG，你一条条看，那不疯了吗？
一般密文检索系统会定义这几个级别：
| 级别 | 含义 | 典型场景 |
|---|---|---|
| DEBUG | 调试用，开发环境才开 | 打印请求参数、中间变量 |
| INFO | 关键流程步骤 | 检索请求到达、结果返回 |
| WARN | 可能有问题但没挂 | 缓存穿透、重试次数超限 |
| ERROR | 功能异常，需要人工介入 | 查询超时、解密失败 |
| FATAL | 系统级崩溃，无法恢复 | 内存溢出、磁盘写入失败 |
我有个习惯：排查时先 grep "ERROR" 或 "FATAL"，缩小范围。如果 ERROR 太多，再降级看 WARN。曾经有个同事，线上挂了半天，他还在 DEBUG 日志里翻来翻去——其实错误日志早就打印了，只不过被他忽略了。嗯，这就是不设级别筛选的代价。
关键字段：一眼锁定问题
光看级别还不够。你要从日志行里快速抓取几个关键信息。我一般会看这几个字段：
- 时间戳 —— 问题发生的时间点，精确到毫秒。跨服务排查时，靠它对齐上下游。
- 线程名 —— 密文检索大多是异步多线程，不同线程处理不同请求。看线程名能区分并发调用。
- 日志级别 —— 上面讲过了。
- 类名/方法名 —— 知道是在代码哪个位置触发，快速定位源代码。
- 消息内容 —— 具体描述，比如 "decrypt failed: illegal key size"。
- 异常堆栈 —— ERROR 级别才带，告诉你从哪行代码开始报错。
举个例子，我排查过一个问题：用户密文检索一直返回空结果。看日志发现一条 INFO：
2025-03-28 14:23:45.678 [pool-3-thread-5] INFO c.m.crypto.SearchService - search completed, total: 0线程名是 "pool-3-thread-5"，说明是线程池里的任务。total:0 表示检索到了数据但匹配数为0。再往前翻 DEBUG 日志，发现 "ciphertext decode failed"——解码都失败了，后面当然查不到。这就是关键字段串联起来的威力。
常见日志格式：看懂每一行
你在不同地方看到的日志格式五花八门，但万变不离其宗。常见的有三种：
| 格式 | 示例 | 优缺点 |
|---|---|---|
| 标准文本 （SLF4J/Log4j） |
2025-03-28 14:23:45.678 [main] ERROR com.my.SearchService - timeout |
人眼可读，但解析困难，字段靠空格分隔 |
| JSON 结构化 （Logstash/Flume） |
|
机器解析友好，可灵活加字段，但阅读性稍差 |
| 自定义格式 | [2025-03-28 14:23:45] E [SearchService] query failed, requestId=abc123 |
团队约定即可，但工具支持不统一 |
我个人更推荐 JSON 格式。为什么呢？因为可以用 jq 命令直接过滤，比如 jq 'select(.level=="ERROR" and .message | test("decrypt"))'。一条命令就把所有解密相关的错误日志拎出来，快得很。传统文本格式你要用 awk、grep 组合，写起来麻烦还容易漏。
不过话说回来，格式只是皮囊，真正要看的是里边的字段。不管什么格式，只要你能快速提取上面说的那几个关键字段，就够用了。
日志分析流程：怎么快速定位
光说不练假把式。我总结了一个简单流程，配合下面的图更方便理解：
- 按级别过滤 —— 先 grep ERROR/FATAL，没有就去掉级别看 WARN。
- 按时间范围切片 —— 选问题发生前后10分钟的日志。
- 按请求ID或线程名分组 —— 找到属于同一个请求的所有日志。
- 从下往上读异常堆栈 —— 看到第一行自己写的代码。
- 对照上下游日志 —— 如果涉及 RPC，翻调用链，看对端返回了什么。
这个流程我用了好几年，基本没翻过车。下图展示的就是这个逻辑：
按这个流程走，基本上不会漏掉关键线索。我在处理一个密文检索超时问题时，就是靠时间切片，发现每天凌晨2:03准时 ERROR——后来排查到是定时任务导致缓存失效，同时大量查询涌入。没有时间切片，这问题可能要查一两天。