Hi, all, Recently I get a dead lock in ehci_hcd and hope someone can look at my analysis. The symptom is: When I set loglevel=8 in command line and set console=ttyUSB0, 115200n8..., and connect a usb-serial adapter to my target device (a tablet running kernel 3.5.3 with several other changes but I guess ehci parts should be same as mainstream), the device is dead withing several seconds after reboot. I wrote a small program in user space to dump to disk and enabled several debug options in kernel configuration. The result is the dead lock caught in ehci_hcd as below backtrace shows. My analysis is when a function driver submits a urb to ehci_hcd in a process, it will finally grab the spin lock "ehci->lock" in functions called by ehci_urb_enqueue() to do the job, but it seems some lower layer will print out echi's debug information in the further steps. If console is set to a usb-serial adapter and loglevel is big enough to allow these debug messages out, the prink() just output log to the user-serial module which should be a function driver based on ehci_hcd stack. Then a new sequence of urb submitting starts and calls the same ehci_urb_enqueue() again. The result is the same process will try to get the ehci->lock it has held. Does my analysis make sense? any good solutions if it is so? Thanks! Chang ============================== =============================== <6>[ 6.773337] usbcore: registered new interface driver uvcvideo <6>[ 6.773341] USB Video Class driver (1.1.1) <7>[ 6.817907] btusb 2-1.3:1.0: usb_probe_interface <7>[ 6.817921] btusb 2-1.3:1.0: usb_probe_interface - got id <7>[ 6.819159] usb 2-1.3: link qh1-0e01/f39f1180 start 0 [1/2 us] <0>[ 6.819164] BUG: spinlock recursion on CPU#1, kworker/1:1/902 <0>[ 6.819169] lock: 0xf38f7918, .magic: dead4ead, .owner: kworker/1:1/902, .owner_cpu: 1 <7>[ 6.819171] Pid: 902, comm: kworker/1:1 Tainted: G W 3.5.3-aia2+ #1 <7>[ 6.819171] Call Trace: <7>[ 6.819177] [<c1764ca6>] spin_dump+0x95/0x9d <7>[ 6.819179] [<c1764cc9>] spin_bug+0x1b/0x1f <7>[ 6.819184] [<c12bfcc1>] do_raw_spin_lock+0xe1/0x130 <7>[ 6.819188] [<c14a11a1>] ? ehci_urb_enqueue+0x81/0x1000 <7>[ 6.819191] [<c176b367>] _raw_spin_lock_irqsave+0x67/0x80 <7>[ 6.819193] [<c14a11a1>] ? ehci_urb_enqueue+0x81/0x1000 <7>[ 6.819195] [<c14a11a1>] ehci_urb_enqueue+0x81/0x1000 <7>[ 6.819198] [<c1006cb8>] ? nommu_map_page+0x38/0x70 <7>[ 6.819203] [<c1485f92>] usb_hcd_submit_urb+0x82/0x810 <7>[ 6.819206] [<c12b6f66>] ? number.isra.2+0x336/0x380 <7>[ 6.819208] [<c148747f>] usb_submit_urb+0x1cf/0x4a0 <7>[ 6.819211] [<c14e2b18>] ? usb_serial_generic_write_start+0x48/0x230 <7>[ 6.819213] [<c14e2ff2>] ? usb_serial_generic_prepare_write_buffer+0x42/0x60 <7>[ 6.819215] [<c14e2b3e>] usb_serial_generic_write_start+0x6e/0x230 <7>[ 6.819218] [<c1052a85>] ? kfifo_copy_in+0x55/0x70 <7>[ 6.819220] [<c14e2f28>] ? usb_serial_generic_write+0x58/0x80 <7>[ 6.819222] [<c14e2f2f>] usb_serial_generic_write+0x5f/0x80 <7>[ 6.819224] [<c14e3892>] usb_console_write+0xb2/0x210 <7>[ 6.819226] [<c14e2ed0>] ? usb_serial_generic_resume+0xb0/0xb0 <7>[ 6.819228] [<c14e37e0>] ? usb_console_setup+0x3a0/0x3a0 <7>[ 6.819231] [<c1032bd8>] call_console_drivers.constprop.10+0x88/0x100 <7>[ 6.819233] [<c176b371>] ? _raw_spin_lock_irqsave+0x71/0x80 <7>[ 6.819235] [<c1032e77>] ? console_unlock+0x227/0x430 <7>[ 6.819238] [<c1032e81>] console_unlock+0x231/0x430 <7>[ 6.819240] [<c1057de7>] ? down_trylock+0x27/0x40 <7>[ 6.819242] [<c10332bb>] vprintk_emit+0x16b/0x4d0 <7>[ 6.819245] [<c1761fcc>] printk_emit+0x34/0x36 <7>[ 6.819248] [<c13bb26c>] __dev_printk+0x15c/0x290 <7>[ 6.819252] [<c1101756>] ? dma_pool_alloc+0x146/0x2a0 <7>[ 6.819255] [<c12b829a>] ? snprintf+0x1a/0x20 <7>[ 6.819257] [<c12cb39d>] ? dynamic_emit_prefix+0x2d/0x1d0 <7>[ 6.819259] [<c12cb655>] __dynamic_dev_dbg+0x45/0x60 <7>[ 6.819261] [<c1498ddc>] ? check_period.part.49+0x2c/0x90 <7>[ 6.819264] [<c149d920>] ? check_intr_schedule+0xf0/0x150 <7>[ 6.819266] [<c149dd23>] qh_schedule+0x3a3/0x3d0 <7>[ 6.819268] [<c14a1393>] ehci_urb_enqueue+0x273/0x1000 <7>[ 6.819270] [<c10051be>] ? print_context_stack+0x4e/0xb0 <7>[ 6.819273] [<c1006cb8>] ? nommu_map_page+0x38/0x70 <7>[ 6.819276] [<c1485f92>] usb_hcd_submit_urb+0x82/0x810 <7>[ 6.819278] [<c1063da5>] ? sched_clock_cpu+0xf5/0x160 <7>[ 6.819280] [<c148747f>] usb_submit_urb+0x1cf/0x4a0 <7>[ 6.819282] [<c14877cd>] ? usb_anchor_urb+0x4d/0x60 <7>[ 6.819286] [<fab5333c>] btusb_submit_intr_urb+0xfc/0x1c0 [btusb] <7>[ 6.819289] [<c176ecc0>] ? vmalloc_fault+0xd3/0xd3 <7>[ 6.819291] [<fab53a64>] btusb_open+0x74/0xf0 [btusb] <7>[ 6.819295] [<c169185e>] hci_dev_open+0xde/0x280 <7>[ 6.819297] [<c1691a21>] hci_power_on+0x21/0xa0 <7>[ 6.819300] [<c104b570>] process_one_work+0x180/0x4a0 <7>[ 6.819303] [<c104b4f4>] ? process_one_work+0x104/0x4a0 <7>[ 6.819305] [<c1691a00>] ? hci_dev_open+0x280/0x280 <7>[ 6.819308] [<c104d43c>] worker_thread+0x11c/0x2f0 <7>[ 6.819311] [<c104d320>] ? manage_workers.isra.26+0x1f0/0x1f0 <7>[ 6.819313] [<c1051b98>] kthread+0x78/0x80 <7>[ 6.819315] [<c1760000>] ? cpu_stop_cpu_callback+0x68/0x158 <7>[ 6.819318] [<c1051b20>] ? __init_kthread_worker+0x60/0x60 <7>[ 6.819320] [<c1772c7e>] kernel_thread_helper+0x6/0xd <6>[ 6.820004] usbcore: registered new interface driver btusb -- To unsubscribe from this list: send the line "unsubscribe linux-usb" in the body of a message to majordomo@xxxxxxxxxxxxxxx More majordomo info at http://vger.kernel.org/majordomo-info.html
