📚 课程目录第3章系统级日志与追踪体系

3. 系统级日志与追踪体系

在 NVIDIA DRIVE 平台上定位复杂问题，单一日志源往往只能给出局部线索。内核崩溃可能只在 dmesg 中留下 Oops，而用户态服务异常重启记录在 journalctl，硬件初始化失败可能只出现在 Tegra UART 的早期串口输出里，调度延迟则要靠 ftrace 或 perfetto 才能看清。真正有效的调试，是把这些来源按时间轴和事件因果关联起来，形成一条可追溯的证据链。

各日志源的定位与采集方式

dmesg 反映内核环形缓冲区，覆盖驱动 probe、内存分配、PCIe/Camera 链路、热区与电源域等事件。采集时建议带时间戳并保留原始级别：

dmesg -T --level=err,warn,crit,alert,emerg | tail -n 200
dmesg -w -T > /var/log/dmesg_live.log   # 复现问题时持续抓取

注意 -T 使用本地时区转换，跨设备比对时应改用 dmesg --time-format=iso 或直接读取 /dev/kmsg 的单调时钟，避免时区与 NTP 跳变造成错位。

journalctl 管理 systemd 体系下的用户态与内核日志，适合按单元、优先级、时间窗过滤：

journalctl -b -1 -p err --no-pager          # 上一次启动的错误
journalctl -u nvsipl-camera.service -S "10:00" -U "10:05"
journalctl -k -o short-monotonic            # 内核消息，单调时钟

Tegra UART 日志是 DRIVE 平台最不可替代的一环。它来自 SoC 的调试串口，在 Linux 内核接管之前就能输出 BPMP、MB1/MB2、A/B 分区引导、XUSB、PCIe 控制器初始化等信息。典型连接为 115200 8N1，通过 USB-TTL 转接或板载调试口接入：

picocom -b 115200 /dev/ttyUSB2
# 或落盘
stty -F /dev/ttyUSB2 115200 raw -echo
cat /dev/ttyUSB2 | tee /var/log/tegra_uart.log

UART 日志的价值在于：当系统在启动早期挂死、内核尚未挂载根文件系统时，dmesg 和 journalctl 都不可用，只有串口能给出最后一行输出，从而把故障点锁定到具体引导阶段。

syslog 在部分 DRIVE 软件栈中仍作为兼容通道存在，通常由 rsyslog 汇聚 /var/log/syslog 与 /var/log/kern.log，便于与外部日志服务器对接。若系统已完全迁移到 journald，可通过 ForwardToSyslog=yes 保留一份纯文本副本，方便脚本化解析。

ftrace 用于内核态函数级与事件级追踪，开销可控，适合定位调度延迟、中断风暴、驱动耗时：

cd /sys/kernel/debug/tracing
echo function_graph > current_tracer
echo 'nvhost_*' > set_ftrace_filter
echo 1 > tracing_on
# 复现问题后
echo 0 > tracing_on
cat trace > /var/log/ftrace_nvhost.log

也可用 trace-cmd record -p function_graph -l 'tegra*' 录制后由 trace-cmd report 或 KernelShark 图形化分析。

perfetto 是 DRIVE 上做系统级时间线关联的主力工具，能同时采集 ftrace、atrace、CPU 频率、GPU 活动、进程调度与用户态自定义 trace 点，输出统一的 .perfetto-trace：

perfetto -c - --txt -o /data/drive_trace.perfetto-trace <<EOF
buffers { size_kb: 65536 }
data_sources { config { name: "linux.ftrace"
  ftrace_config { ftrace_events: "sched/sched_switch"
    ftrace_events: "power/cpu_frequency"
    atrace_categories: "gfx" atrace_categories: "view" } } }
duration_ms: 10000
EOF

关联分析：把六路日志对齐到同一条时间轴

关联的核心是统一时钟基准。建议以 UART 日志中的引导时间戳为锚点，将 dmesg 的单调时钟、journalctl 的 _SOURCE_MONOTONIC_TIMESTAMP、ftrace 的 trace_clock（默认 local，可切 global）以及 perfetto 的 boot time 全部换算到同一参考系。实践中常用做法是：在复现脚本里先执行 echo 1 > /sys/kernel/debug/tracing/trace_marker 或写入一个自定义 atrace 标记，再触发业务操作，这样在 ftrace 与 perfetto 中都能看到同一标记，从而与 journalctl 中该时刻的服务日志对齐。

下面这张图给出六类日志源在 DRIVE 启动与运行阶段的时间覆盖关系，以及它们如何汇入统一时间轴进行关联分析。

典型关联排查示例

假设现象是：车辆上电后摄像头服务偶发启动失败，约 3 秒后自动恢复。排查路径如下。

第一步，在 UART 日志中搜索 nvsipl 与 deserializer，确认失败时刻是否伴随 I2C 或 CSI 链路初始化超时。若 UART 显示 tegra-camrtc 相关错误，则问题偏硬件链路；若 UART 干净，则转向内核与用户态。

第二步，用 journalctl -u nvsipl-camera.service -b -p warning 查看服务退出码与重试记录，确认是进程崩溃还是依赖未就绪。

第三步，用 dmesg 检查同一时间窗内是否有 tegra-i2c 超时或 nvhost 报错：

dmesg -T | grep -E "i2c|nvhost|camrtc|timeout" | tail -n 50

第四步，若怀疑是调度或中断延迟导致超时，用 ftrace 抓取该时间窗的调度切换与中断事件，或用 perfetto 录制 10 秒时间线，观察失败瞬间 CPU 是否被高优先级任务长时间占用、GPU 是否出现长任务阻塞。

第五步，把上述四路证据按单调时钟对齐，若 UART 无异常、dmesg 出现 I2C 超时、journalctl 显示服务重试、perfetto 显示该时刻 CPU7 被实时线程占满，则可判定为实时负载干扰导致的 I2C 访问超时，而非硬件损坏。此时应调整线程优先级或 CPU 亲和性，再复现验证。

采集顺序建议：先开 UART 落盘与 perfetto 录制，再触发复现，最后统一导出 dmesg、journalctl 与 ftrace。事后补采的日志往往缺少关键时间窗，关联价值大幅下降。

ftrace 的 function_graph 全量追踪会显著增加内核开销，可能掩盖真实的时序问题。应使用 set_ftrace_filter 限定函数范围，或改用事件追踪与 perfetto 采样，避免“观测即干扰”。

关联分析检查清单

检查项	关键动作	判断依据
时钟基准	确认各源使用单调时钟或已换算	时间戳可对齐，无跳变
UART 覆盖	确认串口全程落盘	引导早期事件可追溯
内核证据	dmesg 按级别过滤并保留原始行	存在 Oops/超时/链路错误
用户态证据	journalctl 按单元与时间窗过滤	服务退出码与重试记录明确
时序证据	ftrace/perfetto 覆盖复现窗口	调度、中断、频率变化可见
因果闭环	多源事件按时间轴串联	能解释现象并给出可验证假设

掌握这套体系的关键，不在于记住每条命令，而在于建立“先锚定时间、再分层取证、最后因果串联”的分析习惯。UART 提供最早期的可见性，dmesg 与 journalctl 覆盖内核与用户态，ftrace 与 perfetto 揭示时序与资源竞争，syslog 则保证日志可外送与长期留存。六者协同，才能把 DRIVE 平台上偶发、跨层、时序相关的问题稳定定位到可修复的根因。