From mboxrd@z Thu Jan 1 00:00:00 1970 From: stefan.wahren@i2se.com (Stefan Wahren) Date: Mon, 31 Oct 2016 21:34:23 +0100 (CET) Subject: usb: dwc2: NMI watchdog: BUG: soft lockup - CPU#0 stuck for 146s Message-ID: <1795308650.27171.9a53158f-312d-40ce-80ce-8bf792d8db34.open-xchange@email.1und1.de> To: linux-arm-kernel@lists.infradead.org List-Id: linux-arm-kernel.lists.infradead.org I inspired by this issue [1] i build up a slightly modified setup with a Raspberry Pi B (mainline kernel 4.9rc3), a powered 7 port USB hub and 5 Prolific PL2303 USB to serial convertors. I modified the usb_test for dwc2 [2], which only tries to open all ttyUSB devices one after the other. Unfortunately the complete system stuck after opening the first ttyUSB device ( heartbeat LED stop blinking, no reaction to debug UART). The only way to reanimate the system is to powerdown the USB hub with the USB to serial convertors. [1] - https://github.com/raspberrypi/linux/issues/1692 [2] - https://gist.github.com/lategoodbye/dd0d30af27b6f101b03d5923b279dbaa pi at raspberrypi:~$ lsusb -t /: Bus 01.Port 1: Dev 1, Class=root_hub, Driver=dwc2/1p, 480M |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/3p, 480M |__ Port 1: Dev 3, If 0, Class=Vendor Specific Class, Driver=smsc95xx, 480M |__ Port 2: Dev 11, If 0, Class=Hub, Driver=hub/4p, 480M |__ Port 3: Dev 15, If 0, Class=Vendor Specific Class, Driver=pl2303, 12M |__ Port 1: Dev 12, If 0, Class=Hub, Driver=hub/4p, 480M |__ Port 2: Dev 14, If 0, Class=Vendor Specific Class, Driver=pl2303, 12M |__ Port 3: Dev 16, If 0, Class=Vendor Specific Class, Driver=pl2303, 12M |__ Port 4: Dev 17, If 0, Class=Vendor Specific Class, Driver=pl2303, 12M |__ Port 2: Dev 13, If 0, Class=Vendor Specific Class, Driver=pl2303, 12M pi at raspberrypi:~$ ./usb_test idle opening [/dev/ttyUSB0] ok [ 232.658768] NMI watchdog: BUG: soft lockup - CPU#0 stuck for 146s! [usb_test:522] [ 232.678443] Modules linked in: pwm_bcm2835 vchiq(C) [ 232.678481] CPU: 0 PID: 522 Comm: usb_test Tainted: G C 4.9.0-rc3+ #33 [ 232.678486] Hardware name: BCM2835 [ 232.678498] task: cab54e40 task.stack: c688c000 [ 232.678520] PC is at __do_softirq+0x68/0x2a8 [ 232.678538] LR is at irq_exit+0xb8/0x120 [ 232.678552] pc : [] lr : [] psr: 60000113 sp : c688da60 ip : c688daa8 fp : c688daa4 [ 232.678560] r10: c0b7f800 r9 : c688c000 r8 : 00400000 [ 232.678567] r7 : 0000000a r6 : cb802400 r5 : 00000000 r4 : 00000001 [ 232.678575] r3 : 00000000 r2 : 00000100 r1 : 00400000 r0 : 00000000 [ 232.678585] Flags: nZCv IRQs on FIQs on Mode SVC_32 ISA ARM Segment none [ 232.678593] Control: 00c5387d Table: 068a4008 DAC: 00000051 [ 232.678604] CPU: 0 PID: 522 Comm: usb_test Tainted: G C 4.9.0-rc3+ #33 [ 232.678609] Hardware name: BCM2835 [ 232.678667] [] (unwind_backtrace) from [] (show_stack+0x20/0x24) [ 232.678695] [] (show_stack) from [] (dump_stack+0x20/0x28) [ 232.678718] [] (dump_stack) from [] (show_regs+0x1c/0x20) [ 232.678752] [] (show_regs) from [] (watchdog_timer_fn+0x140/0x19c) [ 232.678779] [] (watchdog_timer_fn) from [] (__hrtimer_run_queues.constprop.3+0xec/0x210) [ 232.678798] [] (__hrtimer_run_queues.constprop.3) from [] (hrtimer_interrupt+0xa4/0x1cc) [ 232.678827] [] (hrtimer_interrupt) from [] (bcm2835_time_interrupt+0x40/0x48) [ 232.678865] [] (bcm2835_time_interrupt) from [] (__handle_irq_event_percpu+0x68/0x1b8) [ 232.678891] [] (__handle_irq_event_percpu) from [] (handle_irq_event_percpu+0x2c/0x68) [ 232.678915] [] (handle_irq_event_percpu) from [] (handle_irq_event+0x38/0x4c) [ 232.678939] [] (handle_irq_event) from [] (handle_level_irq+0xc4/0xf8) [ 232.678960] [] (handle_level_irq) from [] (generic_handle_irq+0x28/0x38) [ 232.678983] [] (generic_handle_irq) from [] (__handle_domain_irq+0x90/0xb8) [ 232.679004] [] (__handle_domain_irq) from [] (bcm2835_handle_irq+0x30/0x48) [ 232.679022] [] (bcm2835_handle_irq) from [] (__irq_svc+0x6c/0x90) [ 232.679031] Exception stack(0xc688da10 to 0xc688da58) [ 232.679044] da00: 00000000 00400000 00000100 00000000 [ 232.679062] da20: 00000001 00000000 cb802400 0000000a 00400000 c688c000 c0b7f800 c688daa4 [ 232.679078] da40: c688daa8 c688da60 c0121270 c01014d0 60000113 fffff000000 c687a300 c9374900 ca918b00 caff1200 c688db84 [ 232.679235] db20: c688db28 c688db40 c04a1cf8 c049cb64 60000013 ffffffff [ 232.679272] [] (__irq_svc) from [] (_dwc2_hcd_urb_enqueue+0x414/0x560) [ 232.679302] [] (_dwc2_hcd_urb_enqueue) from [] (usb_hcd_submit_urb+0x704/0x8c4) [ 232.679327] [] (usb_hcd_submit_urb) from [] (usb_submit_urb+0x438/0x4e0) [ 232.679358] [] (usb_submit_urb) from [] (usb_serial_generic_submit_read_urb+0x50/0xc8) [ 232.679382] [] (usb_serial_generic_submit_read_urb) from [] (usb_serial_generic_submit_read_urbs+0x28/0x70) [ 232.679407] [] (usb_serial_generic_submit_read_urbs) from [] (usb_serial_generic_open+0x44/0x4c) [ 232.679435] [] (usb_serial_generic_open) from [] (pl2303_open+0xc0/0xe0) [ 232.679458] [] (pl2303_open) from [] (serial_port_activate+0x54/0x8c) [ 232.679486] [] (serial_port_activate) from [] (tty_port_open+0x84/0xd4) [ 232.679509] [] (tty_port_open) from [] (serial_open+0x34/0x5c) [ 232.679546] [] (serial_open) from [] (tty_open+0x380/0x534) [ 232.679578] [] (tty_open) from [] (chrdev_open+0x120/0x14c) [ 232.679612] [] (chrdev_open) from [] (do_dentry_open+0x1b8/0x304) [ 232.679638] [] (do_dentry_open) from [] (vfs_open+0x7c/0x80) [ 232.679663] [] (vfs_open) from [] (path_openat+0xb60/0xd88) [ 232.679682] [] (path_openat) from [] (do_filp_open+0x48/0x94) [ 232.679704] [] (do_filp_open) from [] (do_sys_open+0x12c/0x1cc) [ 232.679728] [] (do_sys_open) from [] (SyS_open+0x30/0x34) [ 232.679754] [] (SyS_open) from [] (ret_fast_syscall+0x0/0x3c) [ 233.852571] usb 1-1.2: clear tt 1 (9063) error -110 [ 233.853046] usb 1-1.2.1: clear tt 1 (9073) error -110 [ 234.892554] usb 1-1.2.1: clear tt 1 (9071) error -110 [ 234.892995] usb 1-1.2: clear tt 1 (9061) error -110 [ 235.932574] usb 1-1.2.1: clear tt 1 (9073) error -110 [ 235.933542] usb 1-1.2: clear tt 1 (9063) error -110 [ 236.972595] usb 1-1.2.1: clear tt 1 (9071) error -110 [ 236.973235] usb 1-1.2: clear tt 1 (9061) error -110 [ 238.012573] usb 1-1.2: clear tt 1 (9063) error -110 [ 238.013052] usb 1-1.2.1: clear tt 1 (9073) error -110 [ 238.013456] hub 1-1:1.0: hub_ext_port_status failed (err = -110) [ 239.052567] usb 1-1.2.1: clear tt 1 (9071) error -110 [ 239.053076] usb 1-1.2: clear tt 1 (9061) error -110 [ 240.092573] usb 1-1.2: clear tt 1 (9063) error -110 [ 240.093050] usb 1-1.2.1: clear tt 1 (9073) error -110 [ 240.239643] usb 1-1.2.1: USB disconnect, device number 5 [ 240.239685] usb 1-1.2.1.2: USB disconnect, device number 7 [ 240.262707] usb 1-1.2: clear tt 1 (9061) error -71 [ 240.263123] usb 1-1.2.1: clear tt 1 (9071) error -71 [ 240.263708] usb 1-1.2: USB disconnect, device number 4 [ 694304] pl2303 ttyUSB0: pl2303 converter now disconnected from ttyUSB0 [ 251.694645] pl2303 1-1.2.2:1.0: device disconnected [ 251.704668] usb 1-1.2.3: USB disconnect, device number 8 [ 251.706468] pl2303 ttyUSB2: pl2303 converter now disconnected from ttyUSB2 [ 251.706894] pl2303 1-1.2.3:1.0: device disconnected [ 251.714720] usb 1-1.2.4: USB disconnect, device number 10 [ 251.733019] pl2303 ttyUSB4: pl2303 converter now disconnected from ttyUSB4 [ 251.733459] pl2303 1-1.2.4:1.0: device disconnected [ 251.852767] hub 1-1.2:1.0: activate --> -19