内核报reet ehci 问题分析
问题环境:a:硬件环境:3C5000L 双路服务器b:软件内核版本:linux-4.19.167-next问题现象:系统启动过程中和启动之后,bmc kvm 没有连接的情况下,内核不断的打印usb 1-3: reset high-speed USB device number 2 using ehci-pci如下图所示:连接上以后,就不再报了。问题定位:根据以上现象,查看内核代码得知,这个打印是在
问题环境:
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事件发生,猜测硬件信号不稳导致!!!
更多推荐
所有评论(0)