RE: [PATCH] usb: xhci: enable interrupt only after xhci_start()

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



Hi Mathias,

> On 19.2.2020 1.50, Ajay Gupta wrote:
> > From: Ajay Gupta <ajayg@xxxxxxxxxx>
> >
> > Xhci interrupt must be enabled only after controller is initialized
> > and started. Currently interrupt is enabled first in xhci_run() and
> > later hcd state is set to running in xhci_run_finished().
> >
> > On a slow system (such as FPGA based platform) the time difference
> > between enabling interrupt and setting the hcd state becomes huge
> > enough where interrupt is triggered but controller initialization is
> > not complete yet.
> >
> > Fixing the same by moving the interrupt enable (CMD_EIE) part of code
> > snippet from xhci_run() to xhci_run_finished().
> >
> > Signed-off-by: Ajay Gupta <ajayg@xxxxxxxxxx>
> > ---
> 
> Sounds reasonable, but xHCI specs wants interrupts set and enabled before
> xHC is running state.
> 
> I see this can be an issue if we get a port event for a USB 3 port before the
> USB3 hcd is added.
> What kind of issues did you see? I'd guess NULL pointer dereference in
> handle_port_status()?.
We saw a kernel soft lockup with following dump when a FPGA based system
is booted with ASUS xHCI (Gen 2) PCIe card attached. It was seen with kernel
v4.9.

[    6.110120] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver       
[    6.110602] ehci-pci: EHCI PCI platform driver                               
[    6.112104] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver           
[    6.112586] ohci-pci: OHCI PCI platform driver                               
[    6.113982] ohci-platform: OHCI generic platform driver                      
[    6.117577] xhci_hcd 0000:01:00.0: xHCI Host Controller                      
[    6.118022] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus numb1
[    6.131674] xhci_hcd 0000:01:00.0: hcc params 0x0200eec1 hci version 0x110 q0
[    6.134882] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002    
[    6.135731] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber1
[    6.136172] usb usb1: Product: xHCI Host Controller                          
[    6.136488] usb usb1: Manufacturer: Linux 4.9.38-tegra-g0177c0b-dirty xhci-hd
[    6.136917] usb usb1: SerialNumber: 0000:01:00.0                             
[    6.142334] hub 1-0:1.0: USB hub found                                       
[    6.142866] hub 1-0:1.0: 2 ports detected                                    
[    6.148110] xhci_hcd 0000:01:00.0: xHCI Host Controller                      
[    6.148500] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus numb2
[    6.156660] random: fast init done                                           
[    6.754981] random: crng init done                                           
[   27.147341] INFO: rcu_preempt self-detected stall on CPU                     
[   27.147757]  0-...: (5250 ticks this GP) idle=1ed/140000000000002/0 softirq= 
[   27.148243]   (t=5250 jiffies g=622 c=621 q=12)                              
[   27.148618] rcu_preempt kthread starved for 5250 jiffies! g622 c621 f0x0 RCU1
[   27.149158] rcu_preempt     S    0     7      2 0x00000000                   
[   27.149563] Call trace:                                                      
[   27.149799] [<ffffff8008085790>] __switch_to+0x3c/0x48                       
[   27.150149] [<ffffff8008ee6374>] __schedule+0x25c/0x744                      
[   27.150479] [<ffffff8008ee6898>] schedule+0x3c/0xa0                          
[   27.150808] [<ffffff8008ee9aa8>] schedule_timeout+0x18c/0x37c                
[   27.151186] [<ffffff800811d988>] rcu_gp_kthread+0x4d8/0x79c                  
[   27.151571] [<ffffff80080cb1a0>] kthread+0xf0/0x104                          
[   27.151888] [<ffffff8008082ad0>] ret_from_fork+0x10/0x40                     
[   27.152272] Task dump for CPU 0:                                             
[   27.152497] swapper/0       R  running task        0     1      0 0x00000002 
[   27.153020] Call trace:                                                      
[   27.153224] [<ffffff8008089c5c>] dump_backtrace+0x0/0x16c                    
[   27.153582] [<ffffff8008089f70>] show_stack+0x14/0x1c                        
[   27.153914] [<ffffff800819bc94>] sched_show_task.part.135+0x6c/0x78          
[   27.154318] [<ffffff80080deb30>] dump_cpu_task+0x88/0xc8                     
[   27.154667] [<ffffff800819c0d4>] rcu_dump_cpu_stacks+0xa4/0xec               
[   27.155036] [<ffffff800811aacc>] check_cpu_stall.isra.61+0x334/0x5c8         
[   27.155419] [<ffffff800811ad94>] __rcu_pending+0x34/0x18c                    
[   27.155772] [<ffffff800811e040>] rcu_check_callbacks+0x104/0x2c4             
[   27.156166] [<ffffff8008123e60>] update_process_times+0x60/0xac              
[   27.156547] [<ffffff8008134f80>] tick_sched_timer+0x6c/0xec                  
[   27.156911] [<ffffff80081246e0>] __hrtimer_run_queues+0xd4/0x330             
[   27.157291] [<ffffff80081253c8>] hrtimer_interrupt+0x9c/0x1e0                
[   27.157679] [<ffffff80089e2f10>] arch_timer_handler_phys+0x2c/0x38           
[   27.158069] [<ffffff8008113444>] handle_percpu_devid_irq+0x80/0x248          
[   27.158483] [<ffffff800810e304>] __handle_domain_irq+0x70/0xc4               
[   27.158848] [<ffffff8008080de4>] gic_handle_irq+0x50/0xa0                    
[   27.159196] [<ffffff8008082198>] el1_irq+0xd8/0x168                          
[   27.159530] [<ffffff80080adf18>] irq_exit+0xbc/0xe8                          
[   27.159850] [<ffffff800810e308>] __handle_domain_irq+0x74/0xc4               
[   27.160213] [<ffffff8008080de4>] gic_handle_irq+0x50/0xa0                    
[   27.160560] [<ffffff8008082198>] el1_irq+0xd8/0x168                          
[   27.160897] [<ffffff80088bca88>] xhci_handshake+0x38/0x90                    
[   27.161250] [<ffffff80088bd3cc>] xhci_run+0x300/0x534                        
[   27.161574] [<ffffff8008888ef8>] usb_add_hcd+0x2f0/0x868                     
[   27.161929] [<ffffff80088d2598>] xhci_pci_probe+0x120/0x224                  
[   27.162300] [<ffffff80084c1f10>] pci_device_probe+0x98/0x10c                 
[   27.162671] [<ffffff8008655740>] driver_probe_device+0x29c/0x438             
[   27.163044] [<ffffff80086559ec>] __driver_attach+0x110/0x114                 
[   27.163445] [<ffffff8008653038>] bus_for_each_dev+0x64/0xb4                  
[   27.163801] [<ffffff8008654f9c>] driver_attach+0x20/0x28                     
[   27.164147] [<ffffff8008654a74>] bus_add_driver+0x23c/0x2a8                  
[   27.164506] [<ffffff80086569b0>] driver_register+0x74/0x10c                  
[   27.164862] [<ffffff80084c0c44>] __pci_register_driver+0x44/0x4c             
[   27.165252] [<ffffff8009530614>] xhci_pci_init+0x54/0x60                     
[   27.165601] [<ffffff80080831b4>] do_one_initcall+0x48/0x150                  
[   27.165997] [<ffffff80094f0e54>] kernel_init_freeable+0x1d0/0x284            
[   27.166400] [<ffffff8008ee27f8>] kernel_init+0x10/0xfc                       
[   27.166723] [<ffffff8008082ad0>] ret_from_fork+0x10/0x40   
 
> We could move interrupt enabling to xhci_run_finished() before
> xhci_start() is called, then the USB3 hcd should be initialized before we receive
> interrupts.
> Does that work for you?
Let me check if I can find the system and test it.

Thanks
>nvpublic
> 
> Details:
> xHCI section 4.2 "Host Controller Initialization" has the following sequence:
> 
> - Enable host system interrupt (CMD_EIE),
> - Enable primary interupter (set IE bit in IMAN register)
> - set run bit in USBCMD register.
> 
> And section 5.5.2 has a note:
> 
> "All registers of the Primary Interrupter shall be initialized before setting the
> Run/Stop (RS) flag in the USBCMD register to ‘1’."
> 
> -Mathias




[Index of Archives]     [Linux Media]     [Linux Input]     [Linux Audio Users]     [Yosemite News]     [Linux Kernel]     [Linux SCSI]     [Old Linux USB Devel Archive]

  Powered by Linux