日志分析需统一trace_id与iso8601时间戳、配置journald驱动、用正则提取耗时字段、perf需覆盖内核态及系统调用。
日志分散在多台机器上，grep 一条命令根本搜不到完整请求链
集群日志天然分散，靠单机 grep 只能看局部，漏掉跨节点的调用上下文。真正要定位一次慢请求，得把入口、网关、服务A、服务B的日志按时间戳对齐——但各节点时钟不同步、日志格式不统一、甚至有的没打 trace_id，直接拼时间线会错乱。
实操建议：
- 强制所有服务在日志开头输出
trace_id和timestamp（ISO8601 格式，带毫秒和时区），避免依赖系统默认格式 - 用
ssh+awk批量拉取并归一化时间：例如ssh node1 'grep "trace-abc123" /var/log/app.log' | awk '{gsub(/UTC/, "+0000"); print}' - 别用
sort -k2直接排时间字段——日志里的时间可能是字符串，得先用date -d转成秒级时间戳再排序，否则 “2024-03-15 10:05:01” 会排在 “2024-03-15 10:05:009” 后面
journalctl 查容器日志总显示 “No entries”，但 docker logs 又有内容
因为 journalctl 默认只查本机 systemd 日志，而 Docker 容器若用 json-file 驱动（默认），日志根本没进 journald；只有配置了 log-driver = journald 并重启 dockerd，journalctl -u docker --since "2 hours ago" 才有效。
实操建议：
- 检查当前驱动：
docker info | grep "Logging Driver"，不是journald就别硬用journalctl - 想统一查，改
/etc/docker/daemon.json加"log-driver": "journald"，然后systemctl restart docker—— 注意：已有容器不会自动切换，得重跑 - 如果只是临时查某个容器，
docker logs -t --since "2h" container_name更直接，-t带时间戳，--since支持自然语言
用 awk 统计接口耗时分布，结果总是偏高或漏掉超时请求
常见原因是日志里耗时字段位置不固定（比如有的在第7列，有的因错误日志多打了堆栈变成第12列），或者字段本身含空格/引号干扰字段分割。更隐蔽的是：超时请求往往只记了 “timeout” 字样，根本没写具体数字，awk '{sum += } END {print sum/NR}' 会把这类行当成 0 算进去，拉低平均值。
实操建议：
- 先用
head -20 log | cat -n看耗时字段实际在哪一列，别凭经验写$8 - 用正则提取更稳：
awk '/200|500/ && match($0, /cost_ms[[:space:]]*:[[:space:]]*([0-9]+)/, arr) {sum += arr[1]; n++} END {print sum/n}' - 单独统计超时：
grep -c "timeout|context deadline exceeded" *.log，别混进平均值分母
分析 CPU 高时，top 显示某进程占 95%，但 perf record -g 却看不出热点函数
因为 top 统计的是 wall-clock 时间占比，而 perf 默认采样的是用户态指令。如果高 CPU 是由频繁系统调用（如 read/write 阻塞在磁盘或网络）、锁竞争、或内核模块导致，perf record -g 不加参数很可能采不到关键路径。
实操建议：
- 先确认是用户态还是内核态耗时：
perf top -e cycles:k（:k表示只看内核态），如果这里也高，说明问题在内核路径 - 抓全栈：
perf record -g -e cycles,instructions,syscalls:sys_enter_read，明确带上系统调用事件 - 注意采样频率：默认 1000Hz 可能漏短时尖峰，压力大时可提至
-F 4000，但别超过 8000，否则 perf 自身开销反成瓶颈
日志时间对齐、驱动配置、字段提取逻辑、perf 采样范围——这些地方看着小，但任何一个没对齐，分析结论就差一个数量级。尤其 trace_id 和时钟同步，线上跑一周后才发现漏了时区，基本等于白忙。