Re: powerpc/pseries: EEH detected with xhci_hcd

[Sourabh Jain <sourabhjain@linux.ibm.com>]

On 19/07/26 10:55, Narayana Murty N wrote:
>
>
> On 19/07/26 9:47 AM, Sourabh Jain wrote:
>>
>>
>> On 17/07/26 10:26, Narayana Murty N wrote:
>>>
>>>
>>> On 15/07/26 7:33 PM, Sourabh Jain wrote:
>>>>
>>>> This issue only occurs with the Radix MMU.
>>>> Booting the same kernel with disable_radix=1 does not reproduce the 
>>>> issue.
>>>>
>>>> The system also has pmem.
>>>>
>>>> +CC Shivang and Shiva
>>>>
>>>> - Sourabh Jain
>>>>
>>>>
>>>> On 15/07/26 15:01, Sourabh Jain wrote:
>>>>> Hello,
>>>>>
>>>>> Upstream kernel with head at commit 
>>>>> 3b029c035b34bbc693405ddf759f0e9b920c27f1
>>>>> hitting EEH with xhci_hcd during kernel boot.
>>>>>
>>>>> The issue was not observed on the distro kernel running on the the 
>>>>> same machine.
>>>>>
>>>>> Trace:
>>>>> [    2.130359] [      C8] ibmvscsi 30000066: SRP_LOGIN succeeded
>>>>> [    2.132280] [    T362] xhci_hcd 0014:01:00.0: xHCI Host Controller
>>>>> [    2.132289] [    T362] xhci_hcd 0014:01:00.0: new USB bus 
>>>>> registered, assigned bus number 1
>>>>> [    2.132449] [    T362] xhci_hcd 0014:01:00.0: 
>>>>> ibm,query-pe-dma-windows(53) 10000 8000000 20000014 returned 0, 
>>>>> lb=1000000 ps=103 wn=1
>>>>> [    2.132453] [    T362] xhci_hcd 0014:01:00.0: Skipping ibm,pmemory
>>>>> [    2.141861] [    T110] scsi 0:0:1:0: Direct-Access  AIX VDASD  
>>>>>           0001 PQ: 0 ANSI: 3
>>>>> [    2.143707] [    T362] xhci_hcd 0014:01:00.0: 
>>>>> ibm,create-pe-dma-window(54) 10000 8000000 20000014 15 28 returned 
>>>>> 0 (liobn = 0x70000014 starting addr = 8000000 0)
>>>>> [    2.147236] [    T362] xhci_hcd 0014:01:00.0: lsa_required: 0, 
>>>>> lsa_enabled: 0, direct mapping: 1
>>>>> [    2.147239] [    T362] xhci_hcd 0014:01:00.0: iommu: 64-bit OK 
>>>>> but direct DMA is limited by 800010000000000
>>>>> [    2.147250] [    T362] xhci_hcd 0014:01:00.0: lsa_required: 0, 
>>>>> lsa_enabled: 0, direct mapping: 1
>>>>> [    2.147252] [    T362] xhci_hcd 0014:01:00.0: iommu: 64-bit OK 
>>>>> but direct DMA is limited by 800010000000000
>>>>> [    2.147476] [    T362] xhci_hcd 0014:01:00.0: hcc params 
>>>>> 0x0270f06d hci version 0x96 quirks 0x0000000004000000
>>>>> [    2.149530] [    T362] xhci_hcd 0014:01:00.0: xHCI Host Controller
>>>>> [    2.149536] [    T362] xhci_hcd 0014:01:00.0: new USB bus 
>>>>> registered, assigned bus number 2
>>>>> [    2.149542] [    T362] xhci_hcd 0014:01:00.0: Host supports USB 
>>>>> 3.0 SuperSpeed
>>>>> [    2.149638] [    T362] usb usb1: New USB device found, 
>>>>> idVendor=1d6b, idProduct=0002, bcdDevice= 7.02
>>>>> [    2.149642] [    T362] usb usb1: New USB device strings: Mfr=3, 
>>>>> Product=2, SerialNumber=1
>>>>> [    2.149644] [    T362] usb usb1: Product: xHCI Host Controller
>>>>> [    2.149646] [    T362] usb usb1: Manufacturer: Linux 
>>>>> 7.2.0-rc3upstream+ xhci-hcd
>>>>> [    2.149647] [    T362] usb usb1: SerialNumber: 0014:01:00.0
>>>>> [    2.149817] [    T362] hub 1-0:1.0: USB hub found
>>>>> [    2.149937] [    T362] hub 1-0:1.0: 4 ports detected
>>>>> [    2.150020] [    T362] xhci_hcd 0014:01:00.0: xHCI host 
>>>>> controller not responding, assume dead
>>>>> [    2.150044] [    T362] xhci_hcd 0014:01:00.0: HC died; cleaning up
>>>>> [    2.150125] [    T118] EEH: Recovering PHB#14-PE#10000
>>>>> [    2.150135] [    T118] EEH: PE location: N/A, PHB location: N/A
>>>>> [    2.150143] [    T118] EEH: Frozen PHB#14-PE#10000 detected
>>>>> [    2.150149] [    T118] EEH: Call Trace:
>>>>> [    2.150154] [    T362] xhci_hcd 0014:01:00.0: HC died; cleaning up
>>>>> [    2.150154] [    T118] EEH: [0000000066e7b6f8] 
>>>>> __eeh_send_failure_event+0xa8/0x190
>>>>> [    2.150167] [    T362] xhci_hcd 0014:01:00.0: USB bus 2 
>>>>> deregistered
>>>>> [    2.150171] [    T362] xhci_hcd 0014:01:00.0: remove, state 1
>>>>> [    2.150174] [    T118] EEH: [000000004754a593] 
>>>>> eeh_dev_check_failure+0x408/0x7a0
>>>>> [    2.150177] [    T362] usb usb1: USB disconnect, device number 1
>>>>> [    2.150185] [    T118] EEH: [00000000063df7cc] 
>>>>> xhci_portsc_readl+0x64/0x90 [xhci_hcd]
>>>>> [    2.150216] [    T118] EEH: [00000000593ad484] 
>>>>> xhci_hub_control+0xe28/0x27f0 [xhci_hcd]
>>>>> [    2.150244] [    T118] EEH: [00000000190f1012] 
>>>>> usb_hcd_submit_urb+0x508/0xd30 [usbcore]
>>>>> [    2.150276] [    T118] EEH: [0000000072d7c35d] 
>>>>> usb_submit_urb+0x254/0x840 [usbcore]
>>>>> [    2.150303] [    T118] EEH: [0000000009787909] 
>>>>> usb_start_wait_urb+0x88/0x270 [usbcore]
>>>>> [    2.150331] [    T118] EEH: [00000000e6ec433e] 
>>>>> usb_control_msg+0x134/0x1f0 [usbcore]
>>>>> [    2.150357] [    T118] EEH: [00000000d77b1b30] 
>>>>> hub_probe+0x570/0x12b8 [usbcore]
>>>>> [    2.150385] [    T118] EEH: [0000000091c7d281] 
>>>>> usb_probe_interface+0x124/0x490 [usbcore]
>>>>> [    2.150412] [    T118] EEH: [00000000dc656a09] 
>>>>> really_probe+0x118/0x580
>>>>> [    2.150425] [    T118] EEH: [00000000131d8dfb] 
>>>>> __driver_probe_device+0xc4/0x270
>>>>> [    2.150434] [    T118] EEH: [00000000e26dfd1d] 
>>>>> driver_probe_device+0x5c/0x110
>>>>> [    2.150442] [    T118] EEH: [000000006312c397] 
>>>>> __device_attach_driver+0x10c/0x210
>>>>> [    2.150451] [    T118] EEH: [000000004edd640b] 
>>>>> bus_for_each_drv+0xb0/0x130
>>>>> [    2.150460] [    T118] EEH: [000000009b173e09] 
>>>>> __device_attach+0xdc/0x2a0
>>>>> [    2.150467] [    T118] EEH: [000000004588b69c] 
>>>>> device_initial_probe+0x70/0x80
>>>>> [    2.150473] [    T118] EEH: [000000003dba8fbb] 
>>>>> bus_probe_device+0x50/0xf0
>>>>> [    2.150479] [    T118] EEH: [00000000f1fd4a53] 
>>>>> device_add+0x8f0/0xc00
>>>>> [    2.150486] [    T118] EEH: [00000000a74fc843] 
>>>>> usb_set_configuration+0x78c/0xb60 [usbcore]
>>>>> [    2.150526] [    T118] EEH: [000000001df4c94f] 
>>>>> usb_generic_driver_probe+0x78/0xd0 [usbcore]
>>>>> [    2.150556] [    T118] EEH: [00000000a7086db7] 
>>>>> usb_probe_device+0x60/0x200 [usbcore]
>>>>> [    2.150584] [    T118] EEH: [00000000dc656a09] 
>>>>> really_probe+0x118/0x580
>>>>> [    2.150591] [    T118] EEH: [00000000131d8dfb] 
>>>>> __driver_probe_device+0xc4/0x270
>>>>> [    2.150603] [    T118] EEH: [00000000e26dfd1d] 
>>>>> driver_probe_device+0x5c/0x110
>>>>> [    2.150611] [    T118] EEH: [000000006312c397] 
>>>>> __device_attach_driver+0x10c/0x210
>>>>> [    2.150620] [    T118] EEH: [000000004edd640b] 
>>>>> bus_for_each_drv+0xb0/0x130
>>>>> [    2.150629] [    T118] EEH: [000000009b173e09] 
>>>>> __device_attach+0xdc/0x2a0
>>>>> [    2.150636] [    T118] EEH: [000000004588b69c] 
>>>>> device_initial_probe+0x70/0x80
>>>>> [    2.150648] [    T118] EEH: [000000003dba8fbb] 
>>>>> bus_probe_device+0x50/0xf0
>>>>> [    2.150655] [    T118] EEH: [00000000f1fd4a53] 
>>>>> device_add+0x8f0/0xc00
>>>>> [    2.150664] [    T118] EEH: [000000005bca6639] 
>>>>> usb_new_device+0x2f4/0x890 [usbcore]
>>>>> [    2.150693] [    T118] EEH: [0000000023d4a3a1] 
>>>>> register_root_hub+0x1e4/0x2a0 [usbcore]
>>>>> [    2.150721] [    T118] EEH: [00000000941149db] 
>>>>> usb_add_hcd+0x82c/0x8f0 [usbcore]
>>>>> [    2.150749] [    T118] EEH: [00000000f13842f6] 
>>>>> xhci_pci_common_probe+0x1e4/0x3d0 [xhci_pci]
>>>>> [    2.150760] [    T118] EEH: [00000000862a8445] 
>>>>> local_pci_probe+0x64/0x100
>>>>> [    2.150770] [    T118] EEH: [00000000c124ce3b] 
>>>>> pci_device_probe+0x330/0x370
>>>>> [    2.150778] [    T118] EEH: [00000000dc656a09] 
>>>>> really_probe+0x118/0x580
>>>>> [    2.150792] [    T118] EEH: [00000000131d8dfb] 
>>>>> __driver_probe_device+0xc4/0x270
>>>>> [    2.150800] [    T118] EEH: [00000000e26dfd1d] 
>>>>> driver_probe_device+0x5c/0x110
>>>>> [    2.150808] [    T118] EEH: [00000000f3819f2a] 
>>>>> __driver_attach+0x12c/0x2d0
>>>>> [    2.150816] [    T118] EEH: [00000000b7c6a37c] 
>>>>> bus_for_each_dev+0xa4/0x130
>>>>> [    2.150824] [    T118] EEH: [000000009bdf640c] 
>>>>> driver_attach+0x30/0x50
>>>>> [    2.150836] [    T118] EEH: [0000000039921381] 
>>>>> bus_add_driver+0x1c0/0x380
>>>>> [    2.150844] [    T118] EEH: [0000000034a0727d] 
>>>>> driver_register+0x9c/0x1b0
>>>>> [    2.150852] [    T362] xhci_hcd 0014:01:00.0: USB bus 1 
>>>>> deregistered
>>>>> [    2.150851] [    T118] EEH: [000000002faf9b88] 
>>>>> __pci_register_driver+0x64/0x80
>>>>> [    2.150861] [    T118] EEH: [000000005142b255] 
>>>>> xhci_pci_init+0x90/0xb0 [xhci_pci]
>>>>> [    2.150869] [    T118] EEH: [00000000a9fe4af6] 
>>>>> do_one_initcall+0x5c/0x40c
>>>>> [    2.150883] [    T118] EEH: [00000000e2b1b716] 
>>>>> do_init_module+0xac/0x3c0
>>>>> [    2.150893] [    T118] EEH: [00000000fc06f562] 
>>>>> init_module_from_file+0x120/0x1b0
>>>>> [    2.150902] [    T118] EEH: [000000004ca14a9d] 
>>>>> sys_finit_module+0x1b4/0x4d0
>>>>> [    2.150910] [    T118] EEH: [000000005e56c4e5] 
>>>>> system_call_exception+0x184/0x430
>>>>> [    2.150919] [    T362] xhci_hcd 0014:01:00.0: probe with driver 
>>>>> xhci_hcd failed with error -108
>>>>> [    2.150930] [    T118] EEH: [0000000024ebcbb3] 
>>>>> system_call_vectored_common+0x15c/0x2ec
>>>>> [    2.150941] [    T118] EEH: This PCI device has failed 1 times 
>>>>> in the last hour and will be permanently disabled after 5 failures.
>>>>> [    2.150943] [    T118] EEH: Notify device drivers to shutdown
>>>>> [    2.150947] [    T118] EEH: Beginning: 'error_detected(IO frozen)'
>>>>>
>>>>> Snip.....
>>>>> And after sometime the device is disabled.
>>>>>
>>>>> [   40.450010] [    T118] EEH: PHB#14-PE#10000 has failed 6 times 
>>>>> in the last hour and has been permanently disabled.
>>>>> [   40.450027] [    T118] EEH: Unable to recover from failure from 
>>>>> PHB#14-PE#10000.
>>>>>                           Please try reseating or replacing it
>>>>>
>>>>> Attached the kernel config and dmesg.
>>>>>
>>>>> - Sourabh Jain
>>>>
>>> Is the device EEH capable? it seems
>>> error_detected is not invoked any driver
>>> callbacks. 
>>
>> How to verify that? Is the below data enough to conclude the above 
>> statement?
>>
>> root> lspci 0014:01:00.0 USB controller: Texas Instruments TUSB73x0 
>> SuperSpeed USB 3.0 xHCI Host Controller (rev 02)
>>
>> root> cat /sys/bus/pci/devices/0014\:01\:00.0/eeh_mode
>> 0x200
>>
>> root> cat /sys/bus/pci/devices/0014\:01\:00.0/eeh_pe_config_addr
>> 0x10000
>>
>> root> cat /sys/bus/pci/devices/0014\:01\:00.0/eeh_pe_state
>> 0x00000000 0x00000003
>
> Could you please verify whether the bound driver provides the minimum 
> EEH recovery callbacks by running:
>
> |BDF=0014:01:00.0 lspci -Dk -s "$BDF" echo "$BDF" > 
> /sys/kernel/debug/powerpc/eeh_dev_can_recover echo $? |
>
> A return status of |0| confirms that the driver provides the required 
> |error_detected()| and |slot_reset()| callbacks.
>
> If the write fails with |Operation not supported|, the driver does not 
> support driver-assisted EEH recovery.
>
> Please also check the EEH log for either:
>
> |EEH: Invoking <driver>->error_detected(...) |
>
> or:
>
> |EEH: driver not EEH aware | 


root> export BDF=0014:01:00.0

root> lspci -Dk -s "$BDF"
0014:01:00.0 USB controller: Texas Instruments TUSB73x0 SuperSpeed USB 
3.0 xHCI Host Controller (rev 02)
     Subsystem: IBM Device 0690
     Kernel modules: xhci_pci

root> echo "$BDF" > /sys/kernel/debug/powerpc/eeh_dev_can_recover
-bash: echo: write error: Operation not supported

root> echo $?
1

ltcden10-lp2:~ # dmesg | grep -i EEH
[    0.062839] [      T1] EEH: pSeries platform initialized
[    0.120733] [      T1] EEH: Capable adapter found: recovery enabled.
[  988.128432] [    T119] INFO: task eehd:118 blocked for more than 491 
seconds.
[  988.128466] [    T119] task:eehd            state:D stack:0  pid:118  
  tgid:118   ppid:2      task_flags:0x208040 flags:0x00000000
[  988.128501] [    T119] [c00000000921be20] [c00000000004ae68] 
eeh_pe_bus_get+0x48/0xc0
[  988.128506] [    T119] [c00000000921be50] [c00000000004c734] 
eeh_handle_normal_event+0x64/0xa50
[  988.128510] [    T119] [c00000000921bf30] [c00000000004e118] 
eeh_event_handler+0xf8/0x190
[  988.128526] [    T119] INFO: task eehd:118 is blocked on a mutex 
likely owned by task eehd:118.
[ 1479.648166] [    T119] INFO: task eehd:118 blocked for more than 983 
seconds.
[ 1479.648199] [    T119] task:eehd            state:D stack:0  pid:118  
  tgid:118   ppid:2      task_flags:0x208040 flags:0x00000000
[ 1479.648235] [    T119] [c00000000921be20] [c00000000004ae68] 
eeh_pe_bus_get+0x48/0xc0
[ 1479.648239] [    T119] [c00000000921be50] [c00000000004c734] 
eeh_handle_normal_event+0x64/0xa50
[ 1479.648243] [    T119] [c00000000921bf30] [c00000000004e118] 
eeh_event_handler+0xf8/0x190
[ 1479.648257] [    T119] INFO: task eehd:118 is blocked on a mutex 
likely owned by task eehd:118.
[ 1971.167877] [    T119] INFO: task eehd:118 blocked for more than 1474 
seconds.
[ 1971.167905] [    T119] task:eehd            state:D stack:0  pid:118  
  tgid:118   ppid:2      task_flags:0x208040 flags:0x00000000
[ 1971.167940] [    T119] [c00000000921be20] [c00000000004ae68] 
eeh_pe_bus_get+0x48/0xc0
[ 1971.167944] [    T119] [c00000000921be50] [c00000000004c734] 
eeh_handle_normal_event+0x64/0xa50
[ 1971.167948] [    T119] [c00000000921bf30] [c00000000004e118] 
eeh_event_handler+0xf8/0x190
[ 1971.167961] [    T119] INFO: task eehd:118 is blocked on a mutex 
likely owned by task eehd:118.
[ 2462.687577] [    T119] INFO: task eehd:118 blocked for more than 1966 
seconds.
[ 2462.687607] [    T119] task:eehd            state:D stack:0  pid:118  
  tgid:118   ppid:2      task_flags:0x208040 flags:0x00000000
[ 2462.687641] [    T119] [c00000000921be20] [c00000000004ae68] 
eeh_pe_bus_get+0x48/0xc0
[ 2462.687646] [    T119] [c00000000921be50] [c00000000004c734] 
eeh_handle_normal_event+0x64/0xa50
[ 2462.687650] [    T119] [c00000000921bf30] [c00000000004e118] 
eeh_event_handler+0xf8/0x190
[ 2462.687663] [    T119] INFO: task eehd:118 is blocked on a mutex 
likely owned by task eehd:118.
[ 2954.207293] [    T119] INFO: task eehd:118 blocked for more than 2457 
seconds.
[ 2954.207323] [    T119] task:eehd            state:D stack:0  pid:118  
  tgid:118   ppid:2      task_flags:0x208040 flags:0x00000000
[ 2954.207358] [    T119] [c00000000921be20] [c00000000004ae68] 
eeh_pe_bus_get+0x48/0xc0
[ 2954.207362] [    T119] [c00000000921be50] [c00000000004c734] 
eeh_handle_normal_event+0x64/0xa50
[ 2954.207367] [    T119] [c00000000921bf30] [c00000000004e118] 
eeh_event_handler+0xf8/0x190
[ 2954.207379] [    T119] INFO: task eehd:118 is blocked on a mutex 
likely owned by task eehd:118.
[ 3445.726999] [    T119] INFO: task eehd:118 blocked for more than 2949 
seconds.
[ 3445.727029] [    T119] task:eehd            state:D stack:0  pid:118  
  tgid:118   ppid:2      task_flags:0x208040 flags:0x00000000
[ 3445.727062] [    T119] [c00000000921be20] [c00000000004ae68] 
eeh_pe_bus_get+0x48/0xc0
[ 3445.727066] [    T119] [c00000000921be50] [c00000000004c734] 
eeh_handle_normal_event+0x64/0xa50
[ 3445.727070] [    T119] [c00000000921bf30] [c00000000004e118] 
eeh_event_handler+0xf8/0x190
[ 3445.727083] [    T119] INFO: task eehd:118 is blocked on a mutex 
likely owned by task eehd:118.
[ 3937.246734] [    T119] INFO: task eehd:118 blocked for more than 3440 
seconds.
[ 3937.246761] [    T119] task:eehd            state:D stack:0  pid:118  
  tgid:118   ppid:2      task_flags:0x208040 flags:0x00000000
[ 3937.246795] [    T119] [c00000000921be20] [c00000000004ae68] 
eeh_pe_bus_get+0x48/0xc0
[ 3937.246799] [    T119] [c00000000921be50] [c00000000004c734] 
eeh_handle_normal_event+0x64/0xa50
[ 3937.246803] [    T119] [c00000000921bf30] [c00000000004e118] 
eeh_event_handler+0xf8/0x190
[ 3937.246816] [    T119] INFO: task eehd:118 is blocked on a mutex 
likely owned by task eehd:118.
[ 4428.766432] [    T119] INFO: task eehd:118 blocked for more than 3932 
seconds.
[ 4428.766468] [    T119] task:eehd            state:D stack:0  pid:118  
  tgid:118   ppid:2      task_flags:0x208040 flags:0x00000000
[ 4428.766505] [    T119] [c00000000921be20] [c00000000004ae68] 
eeh_pe_bus_get+0x48/0xc0
[ 4428.766509] [    T119] [c00000000921be50] [c00000000004c734] 
eeh_handle_normal_event+0x64/0xa50
[ 4428.766514] [    T119] [c00000000921bf30] [c00000000004e118] 
eeh_event_handler+0xf8/0x190
[ 4428.766526] [    T119] INFO: task eehd:118 is blocked on a mutex 
likely owned by task eehd:118.
[ 4920.286148] [    T119] INFO: task eehd:118 blocked for more than 4423 
seconds.
[ 4920.286178] [    T119] task:eehd            state:D stack:0  pid:118  
  tgid:118   ppid:2      task_flags:0x208040 flags:0x00000000
[ 4920.286213] [    T119] [c00000000921be20] [c00000000004ae68] 
eeh_pe_bus_get+0x48/0xc0
[ 4920.286218] [    T119] [c00000000921be50] [c00000000004c734] 
eeh_handle_normal_event+0x64/0xa50
[ 4920.286222] [    T119] [c00000000921bf30] [c00000000004e118] 
eeh_event_handler+0xf8/0x190
[ 4920.286235] [    T119] INFO: task eehd:118 is blocked on a mutex 
likely owned by task eehd:118.
[ 5411.805864] [    T119] INFO: task eehd:118 blocked for more than 4915 
seconds.
[ 5411.805895] [    T119] task:eehd            state:D stack:0  pid:118  
  tgid:118   ppid:2      task_flags:0x208040 flags:0x00000000
[ 5411.805931] [    T119] [c00000000921be20] [c00000000004ae68] 
eeh_pe_bus_get+0x48/0xc0
[ 5411.805935] [    T119] [c00000000921be50] [c00000000004c734] 
eeh_handle_normal_event+0x64/0xa50
[ 5411.805939] [    T119] [c00000000921bf30] [c00000000004e118] 
eeh_event_handler+0xf8/0x190
[ 5411.805952] [    T119] INFO: task eehd:118 is blocked on a mutex 
likely owned by task eehd:118.

- Sourabh Jain