3. 内核日志分析方法:dmesg与USB mon的使用

驱动加载失败,第一反应是什么?

我个人习惯,先看 dmesg。它就像系统的黑匣子,USB 控制器、PHY、OTG 状态切换,几乎所有内核级别的报错都会在这里留下痕迹。另一个利器是 usbmon,它能抓到 USB 总线上的原始数据包,说白了就是链路层的“Wireshark”。

这一章我们就聊聊这两个工具怎么用、怎么看、怎么配合。

3.1 dmesg:先扫一眼系统说了啥

驱动加载失败,dmesg 里通常会有明显的 error、warning 或者 usb 1-1: device not accepting address 这类信息。但日志量很大,不能傻看。

我的做法:先清空旧日志 dmesg -c,再复现一次失败场景,最后 dmesg 只看增量内容。省得在几千行里翻。

关键信息点:

  • USB 控制器初始化:比如 dwc3_probe 或 ci_hdrc_probe 成功/失败
  • 角色切换:otg: set state to device 或 otg: set state to host,看是否卡在某个状态
  • 电源与时钟:failed to enable clk、regulator get failed 之类
  • 设备枚举:device descriptor read/64, error -71(-71 是 EPROTO,协议错误)
# 示例:查看 dwc3 驱动加载相关日志
dmesg | grep -i dwc3
dmesg | grep -i "usb 1-1"

我曾经遇到一个坑:某款 SoC 的 OTG 驱动反复注册失败,dmesg 只报了 dwc3: failed to get usb3 phy,但 PHY 设备树明明配了。查了三天,最后发现是 PHY 的电源时序没搞定,导致 probe 顺序颠倒。嗯,所以别只看 ERROR,INFO 级别的初始化顺序也值得瞄一眼。

3.2 usbmon:抓包看链路细节

dmesg 告诉你“坏掉了”,usbmon 告诉你“怎么坏掉的”。

加载 usbmon 模块:

modprobe usbmon
ls /sys/kernel/debug/usb/usbmon/    # 会看到 0u, 1u, 2u 等接口

抓包命令:

cat /sys/kernel/debug/usb/usbmon/0u > usb.log &
# 复现问题
# 然后 Ctrl+C 停掉
cat usb.log | head -50

每一行对应一个USB事务,格式:

U B URB_BULK 0xffff8800xxxxx 1 1:1:0 64 = 00 01 02 ...

字段含义:

字段说明
U / S / EURB 提交(Submit) / 完成(Complete) / 错误(Error)
总线:设备:端点比如 1:1:0 表示总线1设备1端点0(控制端点)
数据长度实际传输字节数
数据十六进制 payload,可截断
注意:usbmon 抓到的数据包是内核级别的原始帧,不会经过上层驱动处理。如果发现端点一直返回 NAK,或者控制传输超时,那就是物理层或控制器的问题,跟驱动软件关系不大。

3.3 两者配合:从日志到根因

我的调试流程大致这样:

  1. dmesg 扫轮廓:确认驱动是否 probe 成功,是否进入 OTG 状态机
  2. usbmon 抓细节:如果 dmesg 提示枚举失败,立刻抓 usbmon 看设备描述符请求的交互
  3. 对比正常设备:拿一个能正常工作的 USB 设备,在同一平台上抓一次 usbmon,对比差异
  4. 定位到具体阶段:比如是 get_descriptor 阶段 device 无响应,还是 set_configuration 阶段返回错误

举个例子:某次客户反馈 USB 硬盘插入后无法挂载。dmesg 报:hub 1-0:1.0: connect-debounce failed, port 1 disabled。我一看,可能是物理接触不良或上电时序。用 usbmon 抓包,发现主机发出第一个 SETUP 令牌后,设备完全没有 ACK。最后查硬件,原来是 VBUS 电压掉了 0.3V,不满足设备要求。软件调的什么驱动?白调。

3.4 核心知识图谱

dmesg 与 usbmon 联合调试流程 驱动加载失败 dmesg 日志采集 grep 关键错误 / 状态切换 usbmon 抓包 分析 URB 序列 / 错误码 对比分析 / 交叉验证 定位根因 常见根因:设备树配错、PHY未初始化、电源时序、VBUS供电不足、USB-2.0/3.0混合问题

3.5 实用技巧与避坑

  • dmesg 时间戳:加 -T 参数显示可读时间,方便和 usbmon 日志对齐
  • usbmon 缓冲区:默认 4KB 可能丢包,尤其高速设备。增大:echo 8192 > /sys/kernel/debug/usb/usbmon/0u/buflen
  • 过滤:usbmon 支持只抓特定设备 cat /sys/kernel/debug/usb/usbmon/1u,1 代表总线号。先 lsusb 找到设备所在总线
  • 配合 Wireshark:usbmon 抓的文本可转换成 pcap 格式,用 usbmon2pcap 或直接 Wireshark 的 “从管道导入” 功能
我曾经犯错:有一次 usbmon 抓了一堆数据,发现设备在枚举阶段发了一个奇怪的描述符。我兴奋地以为是协议问题,结果花了两天查 USB 规范,最后发现是抓包的工具本身有 bug——那块主板上的 EHCI 控制器在 usbmon 下会多输出无意义的空事务。所以,遇到异常数据,先换一台机器或者换一个 USB 口复现一下。

3.6 总结一下

dmesg 和 usbmon 是一对黄金搭档。dmesg 帮你快速定位“哪一步出了问题”,usbmon 帮你深挖“到底怎么出的问题”。

我个人习惯把这两者绑定成脚本,一键抓取:

#!/bin/bash
dmesg -c > /dev/null
cat /sys/kernel/debug/usb/usbmon/0u > /tmp/usb.log &
sleep 30   # 等待问题复现
kill %1
dmesg > /tmp/kernel.log
echo "收集完毕:kernel.log + usb.log"

你想想看,这么一套下来,大部分 OTG 加载失败的问题都能找到线索。剩下的,就是具体分析寄存器、PHY 配置这些更深层次的东西了。