My device driver (a proprietary USB device called 'scmicro') appears to have tickled a lock order reversal. When witness.watch is enabled, all goes well until my driver detach()es. At which point my system panics with: lock order reversal: 1st 0xc0c932a0 syscons video lock (syscons video lock) @ dev/syscons/syscons.c:2534 2nd 0xc0c23400 sched lock 0 (sched lock) @ kern/kern_clock.c:286 panic: blockable sleep lock (sleep mutex) sellck @ kern/sys_generic.c:1127 My driver creates two taskqueue(9) threads in attach() and destroys them in detach(). It has 4 mutexes which it uses to protect it's own data structures. In addition, it holds Giant around any code section which calls usb functions. With the exception of wakeup(9), cv_signal(9), cv_destroy(9) and taskqueue_enqueue_fast(), it always release it's own locks (except for Giant) before it calls external code. Of course, this does not happen when my devices uses the ugen(4) driver. Is this a known issue? Am I doing something wrong? How-To-Repeat: Sorry, my client wont let me release details of the driver.
State Changed From-To: open->feedback To submitter: are you able to get a backtrace of this panic? Assuming you have the debugger compiled into the kernel, the output produced by "bt" will help to figure out where the problem lies.
Responsible Changed From-To: freebsd-bugs->gavin Track
Ok, here we are. I did a shutdown (the '<118>#'), plugged in the device (called 'scmicro'), then pulled the usb plug. The 'scmicro:...' lines are debug cruft from my detach() method and it's helper functions. The final statement of do_detach() is (a macro which produces): printf("scmicro: scmicro detached\n"); The lock order reversal occurs after the text is output, but before the "\n". All this occurred w/ Giant locked by the detach() method. brad <118># scmicro0: at uhub1 port 2 (addr 3) disconnected scmicro: do_detach(sc=0xc6872a00) scmicro: aborting Interupt pipe scmicro: scmicro_intr(sc=0xc6872a00,uerr=CANCELLED) scmicro: scm_reserve() failed to reserve sc=0xc6872a00! scmicro: aborting BulkIn pipe scmicro: aborting BulkOut pipe scmicro: terminating BulkIn/BulkOut taskqueue scmicro: BulkIn/BulkOut taskqueue terminated scmicro: terminating Interupt taskqueue scmicro: Interupt taskqueue terminated scmicro: straglers: 0 scmicro: sc_inuse=0 scmicro: freeing BulkOut buffer scmicro: freeing BulkIn buffer scmicro: freeing BulkOut xfer scmicro: freeing BulkIn xfer scmicro: closing Interupt pipe scmicro: closing BulkOut pipe scmicro: closing BulkIn pipe scmicro: removing cdev entry scmicro: sc_cmd_q mutex destroyed scmicro: wasting Interupt queue scmicro: Interupt queue zeroed scmicro: scmicro_intr mutex destroyed scmicro: destroying sc_inuse_mtx... scmicro: scmicro detachedlock order reversal: 1st 0xc0caefa0 syscons video lock (syscons video lock) @ dev/syscons/syscons.c:2534 2nd 0xc0c3f200 sched lock 2 (sched lock) @ kern/kern_clock.c:286 KDB: stack backtrace: db_trace_self_wrapper(c0b09c00,e6a7b8c8,c07bb6b5,c0b0afce,c0c3f200,...) at db_trace_self_wrapper+0x26 kdb_backtrace(c0b0afce,c0c3f200,c0c3f234,c0b08cf1,c0b04244,...) at kdb_backtrace+0x29 witness_checkorder(c0c3f200,9,c0b0423b,11e,9,...) at witness_checkorder+0x5e5 _thread_lock_flags(c63eeaf0,0,c0b0423b,11e,e6a7b928,...) at _thread_lock_flags+0x50 hardclock_cpu(0,c0aefb8f,2,c00b8000,c6230728,...) at hardclock_cpu+0x129 lapic_handle_timer(e6a7b948) at lapic_handle_timer+0xc3 Xtimerint() at Xtimerint+0x1f --- interrupt, eip = 0xc0a643ae, esp = 0xe6a7b988, ebp = 0xe6a7b9a8 --- generic_bcopy(c0c32588,0,c0c3256c,0,7d0,c0aefb86,703,c63eeaf0) at generic_bcopy+0x1a vga_txtdraw(c0c32560,0,7d0,0,1,...) at vga_txtdraw+0xe4 scrn_update(c0c32560,e6a7ba38,c06a4e3d,c0c32560,e6a7ba2f,...) at scrn_update+0x295 sccnupdate(c0c32560,e6a7ba2f,1,ac8898c) at sccnupdate+0xa6 sc_cnputc(c0b8ae40,a,e6a7bbc4,5,a,...) at sc_cnputc+0xcd cnputc(a,e6a7bbc4,e6a7ba84,c07b1741,c63eeaf0,...) at cnputc+0x5f putcons(c63eeaf0,e6a7ba7c,1000246,c6872a50,c74ff39a,...) at putcons+0x17 putchar(a,e6a7bbc4,c07baeeb,0,c0b02c49,...) at putchar+0x61 kvprintf(c74ff37f,c07b16e0,e6a7bbc4,a,e6a7bbf0,...) at kvprintf+0x75 printf(c74ff37f,0,c74ff02b,1e1,c74ff02b,...) at printf+0x4e do_detach(c0c36750,0,c74ff02b,2b7,c6ca7b80,...) at do_detach+0x4e8 scmicro_detach(c6ca7b80,c6667858,c0bca700,0,0,...) at scmicro_detach+0x48 device_detach(c6ca7b80,3,c63d69e0,c0706048,c63d69e0,...) at device_detach+0x68 usb_disconnect_port(c63e82c4,c63e8300,10,c0afa3b1,27f,...) at usb_disconnect_port+0x107 uhub_explore(c63e8500,c63eb100,e6a7bcf8,c0700387,c63f3210,...) at uhub_explore+0x2a1 usb_discover(c63f3210,0,5c,c0afc9ad,ea60,...) at usb_discover+0x55 usb_event_thread(c63eb100,e6a7bd38,c0b050d7,31c,c63fc828,...) at usb_event_thread+0xa7 fork_exit(c07002e0,c63eb100,e6a7bd38) at fork_exit+0x94 fork_trampoline() at fork_trampoline+0x8 --- trap 0, eip = 0, esp = 0xe6a7bd70, ebp = 0 --- KDB: enter: witness_checkorder panic: blockable sleep lock (sleep mutex) sellck @ kern/sys_generic.c:1127 cpuid = 2 Uptime: 3m36s Physical memory: 3016 MB Dumping 141 MB: 126 110 94 78 62 46 30 14 #0 doadump () at pcpu.h:196 196 __asm __volatile("movl %%fs:0,%0" : "=r" (td)); (kgdb)
State Changed From-To: feedback->open Looks like there's probably enough info here now for interested parties to figure out what's happening
Responsible Changed From-To: gavin->freebsd-bugs Back into the pool
For bugs matching the following criteria: Status: In Progress Changed: (is less than) 2014-06-01 Reset to default assignee and clear in-progress tags. Mail being skipped