问题环境:
a:硬件环境:3C5000L 双路服务器
b:软件内核版本:linux-4.19.167-next
问题现象:
系统启动过程中和启动之后,bmc kvm 没有连接的情况下,内核不断的打印
usb 1-3: reset high-speed USB device number 2 using ehci-pci
如下图所示:
在这里插入图片描述

连接上以后,就不再报了。
问题定位:
根据以上现象,查看内核代码得知,这个打印是在函数hub_port_init 内打印出来的,代码如下:
在这里插入图片描述

追踪函数的调用关系得知,调用关系如下:
hub_event–>port_event–>hub_handle_remote_wakeup–>hub_port_connect_change–>usb_remote_wakeup–>usb_autoresume_device–>__pm_runtime_resume–>finish_port_resume–>usb_reset_and_verify_device–>hub_port_init

hub_event函数不断在被调用,导致上述打印一直有,于是查了一下hub_event的是在哪里调用的。

由代码可知:
在函数hub_probe 内将hub_event注册到一个个work队列内,代码如下图所示:
在这里插入图片描述

函数hub_probe是hub driver 中probe的成员,
如下图所示:
在这里插入图片描述
hub_driver在函数usb_hub_init中被注册到驱动里,代码如下:
在这里插入图片描述
usb_hub_init 函数是在函数usb_init中被调用的,usb_init是整个usb 模块驱动的入口,在内核启动的过程中被调用。
在这里插入图片描述
因此由上面的代码逻辑可知:在内核里INIT_WORK创建的hub_event 对应的work是在usb 驱动执行过程中创建的。这个work创建之后,不会马上被调度执行。是有事件发生的时候才会去调度执行,这个调度是在软中断中实现的。

所以当usb设备有事件发生的时候才是函数hub_event 被调用的时刻。比如一个热插拔事件的发生,这种事件实质都是由中断触发的。

bmc 这个 usb 设备是挂在我们ehci 控制器下面的。使用的中断就是ehci的中断,中断处理函数肯定在ehci 驱动里。
所以研究驱动可知:
ehci 驱动使用的接口函数都是在全局变量ehci_hc_driver中包着代码如下:
在这里插入图片描述
中断处理函数,就是使用这里的中断函数,也就是ehci_irq,于是在ehci_irq中加打印信息如下:
在这里插入图片描述
内核启动后打印log 如下:

[  154.322787] ---lq--(ehci_irq)(708)(status:0x8024)---
[  154.327718] ---lq--(ehci_irq)(731)(cmd:0x10021)---
[  154.332477] ---lq--(ehci_irq)(793)(pstatus:0x601803)---对应port 3发生中断的port
[  154.337667] ---lq--(ehci_irq)(793)(pstatus:0x1000)---
[  154.342684] ---lq--(ehci_irq)(793)(pstatus:0x1000)---
[  154.347701] ---lq--(ehci_irq)(838)(bh:0)(pcd_status:32804)---
[  154.353409] ---lq--(usb_hcd_poll_rh_status)(756)---
[  154.358254] ---lq--(usb_hcd_poll_rh_status)(775)---
[  154.363098] ---lq--(usb_hcd_giveback_urb)(1834)---
[  154.367854] ---lq--(usb_hcd_giveback_urb)(1839)---
[  154.372611] ---lq--(usb_hcd_giveback_urb)(1845)---
[  154.377368] ---lq--(usb_hcd_giveback_urb)(1862)---
[  154.382132] -------lq (usb_hcd_irq)(2462)(irq:30)----
[  154.382147] ---lq--(__usb_hcd_giveback_urb)(1745)---
[  154.387150] ---lq--(ehci_irq)(708)(status:0x8000)---
[  154.397034] ---lq--(__usb_hcd_giveback_urb)(1745)---
[  154.402003] ------(hub_event)(5353) begin (9000000871b69800)(state 7) (ports 3) (chg 0000) (evt 0008)------------
[  154.412220] ---------(__pm_runtime_resume)(1038)------------
[  154.422532] ---------(port_event)(5231)(0)(port:3)------------
[  154.422538] ---lq--(usb_hcd_giveback_urb)(1834)---
[  154.422539] ---lq--(usb_hcd_giveback_urb)(1839)---
[  154.422541] ---lq--(usb_hcd_giveback_urb)(1845)---
[  154.422544] ---lq--(usb_hcd_giveback_urb)(1866)---
[  154.422549] ---lq--(__usb_hcd_giveback_urb)(1745)---
[  154.452341] ---------(port_event)(5238)(portchange:0x1)(port:3)------------
[  154.459272] ---------(port_event)(5239)(portstatus:0x501)(port:3)------------
[  154.466379] ---lq--(usb_hcd_giveback_urb)(1834)---
[  154.471139] ---lq--(usb_hcd_giveback_urb)(1839)---
[  154.475896] ---lq--(usb_hcd_giveback_urb)(1845)---
[  154.480653] ---lq--(usb_hcd_giveback_urb)(1866)---
[  154.485425] ---lq--(__usb_hcd_giveback_urb)(1745)---
[  154.490377] ---------(port_event)(5242)------------
[  154.495238] ---------(hub_handle_remote_wakeup)(3618)------------
[  154.501308] ---------(port_event)(5333)------------
[  154.506169] ---------(hub_port_connect_change)(5171)(status 0501) (change 0001) (480 Mb/s)------------
[  154.515436] ---------(hub_port_connect_change)(5180)------------
[  154.521420] ---------(hub_port_connect_change)(5199)------------
[  154.527404] ---------(usb_remote_wakeup)(3594)------------
[  154.532866] ---------(usb_autoresume_device)(1603)------------
[  154.538675] ---------(__pm_runtime_resume)(1038)------------
[  154.544316] ---lq--(usb_hcd_giveback_urb)(1834)---
[  154.549078] ---lq--(usb_hcd_giveback_urb)(1839)---
[  154.553835] ---lq--(usb_hcd_giveback_urb)(1845)---
[  154.558592] ---lq--(usb_hcd_giveback_urb)(1866)---
[  154.563370] ---lq--(__usb_hcd_giveback_urb)(1745)---
[  154.568319] ---------(finish_port_resume)(3368)------------
[  154.573878] ---------(usb_reset_and_verify_device)(5703)------------
[  154.580211] ---lq--(usb_hcd_giveback_urb)(1834)---
[  154.584968] ---lq--(usb_hcd_giveback_urb)(1839)---
[  154.589725] ---lq--(usb_hcd_giveback_urb)(1845)---
[  154.594482] ---lq--(usb_hcd_giveback_urb)(1866)---
[  154.599258] ---lq--(__usb_hcd_giveback_urb)(1745)---
[  154.670657] ---lq--(usb_hcd_giveback_urb)(1834)---
[  154.675414] ---lq--(usb_hcd_giveback_urb)(1839)---
[  154.680171] ---lq--(usb_hcd_giveback_urb)(1845)---
[  154.684929] ---lq--(usb_hcd_giveback_urb)(1866)---
[  154.689700] ---lq--(__usb_hcd_giveback_urb)(1745)---
[  154.694651] ---lq--(usb_hcd_giveback_urb)(1834)---
[  154.699408] ---lq--(usb_hcd_giveback_urb)(1839)---
[  154.704166] ---lq--(usb_hcd_giveback_urb)(1845)---
[  154.708922] ---lq--(usb_hcd_giveback_urb)(1866)---
[  154.713699] ---lq--(__usb_hcd_giveback_urb)(1745)---
[  154.778551] usb 1-3: reset high-speed USB device number 2 using ehci-pci
[  154.785216] ---------(hub_port_init)(4602)------------
[  154.790330] ---------(Busname:0000:00:04.1)(manu:Aspeed)(ser:00000000)(Pro:USB Virtual Hub)------------

由上述打印中以及代码可知hub_event的调用关系如下:
ehci_irq–>usb_hcd_poll_rh_status–>usb_hcd_giveback_urb–>tasklet_hi_schedule–>__tasklet_hi_schedule–>__tasklet_schedule_common–>raise_softirq_irqoff–>wakeup_softirqd–>wake_up_process–>try_to_wake_up–>set_task_cpu–>__set_task_cpu唤醒这个队列中的event,去执行里面的函数也就是hub_event。

在中断处理函数内,读取了echi 控制器的status 寄存器和port statsu寄存器,的值分别为status:0x8024(status寄存器的bit 15/5/2为1值,pstatus:0x601803(port status 寄存器的bit 22/21/12/11/1/0 为1)

根据ehci spec 对status寄存器和port status寄存器的描述:
在这里插入图片描述
在这里插入图片描述
在这里插入图片描述
在这里插入图片描述
在这里插入图片描述
在这里插入图片描述
在这里插入图片描述

根据 status和port status的值可以分析出,发生了wake up 事件,
根据spec 4.3.1 Port Suspend and Resume的描述可知:
在这里插入图片描述
在这里插入图片描述
在这里插入图片描述

满足上述表格中的第三种情况,监测到了一个断开连接的事件发生:

Port is enabled, disabled or suspended, and the port’s WKDSCNNT_E bit is a one. A disconnect is detected.
(也就是port statsus寄存器 bit 2 为0 处于disable 状态,Port status 寄存器bit 21为1时,监测到一个disconnect事件发生。)

发生该事件后,对应的寄存器的值为:
Depending in the initial port state, the PORTSC Connect and Enable status bits are set to zero, and the Connect
Change status bit is set to a one. Port Change Detect bit in
the USBSTS register is set to a one.

(port statsus寄存器 bit 2为0bit 1为1,statsus 寄存器bit 2为1,刚好和我们读出来的寄存器的值相符合)

因此,现在的问题是为什么会一直监测到有disconnect事件发生,猜测硬件信号不稳导致!!!

Logo

更多推荐