Fabian Keil <freebsd-listen_at_fabiankeil.de> wrote: > Hans Petter Selasky <hps_at_selasky.org> wrote: > > > On 10/23/14 16:28, Fabian Keil wrote: > > > > kldunload umass.ko lead to a panic, dumping didn't work. > > > > > > Screenshots are available at: > > > http://www.fabiankeil.de/bilder/freebsd/kernel-panic-r273434-usb/ > > > > > > I've seen locked-up usbconfig processes in the past, > > > usually after executing a shell function that does: > > > > > > | usbconfig_output="$(sudo usbconfig -d ${device} add_quirk UQ_MSC_NO_INQUIRY)" > > > | [... error handling snipped ] > > > | usbconfig_output="$(sudo usbconfig -d ${device} reset)" > > > > > > Sometimes the second command seems to mess up the USB system. > > > USB detach is synchronous. If for example umass fails to detach, due to > > reference counts not reaching zero, that might be the root cause. Try to > > get a backtrace from the "usb_process()" processes using kgdb, and > > you'll see right away what is going on. > > Thanks for the quick response. So far I haven't been able to intentionally > reproduce the issue, but I'll try the above the next time I unintentionally > run into this again. A couple of days ago usbconfig got stuck again: fk_at_r500 ~ $sudo procstat -kk $(pgrep usbconfig) PID TID COMM TDNAME KSTACK 2444 100971 usbconfig - mi_switch+0xe1 sleepq_wait+0x3a _sx_xlock_hard+0x522 _sx_xlock+0x5d usbd_enum_lock+0x3a usb_ref_device+0x157 usb_open+0xbf devfs_open+0x122 VOP_OPEN_APV+0xa1 vn_open_vnode+0x234 vn_open_cred+0x310 kern_openat+0x26f amd64_syscall+0x3fd Xfast_syscall+0xfb 2425 100970 usbconfig - mi_switch+0xe1 sleepq_timedwait+0x3a _sleep+0x294 pause_sbt+0xd0 usb_pause_mtx+0x85 usb_ioctl+0x3e7 devfs_ioctl_f+0x13b kern_ioctl+0x3ce sys_ioctl+0x140 amd64_syscall+0x3fd Xfast_syscall+0xfb The USB-related threads: (kgdb) thread 520 [Switching to thread 520 (Thread 100970)]#0 sched_switch (td=0xfffff8001d2044a0, newtd=<value optimized out>, flags=<value optimized out>) at /usr/src/sys/kern/sched_ule.c:1940 1940 cpuid = PCPU_GET(cpuid); (kgdb) where #0 sched_switch (td=0xfffff8001d2044a0, newtd=<value optimized out>, flags=<value optimized out>) at /usr/src/sys/kern/sched_ule.c:1940 #1 0xffffffff805bbf91 in mi_switch (flags=260, newtd=0x0) at /usr/src/sys/kern/kern_synch.c:492 #2 0xffffffff80601a7a in sleepq_timedwait (wchan=0x0, pri=0) at /usr/src/sys/kern/subr_sleepqueue.c:666 #3 0xffffffff805bb984 in _sleep (ident=<value optimized out>, lock=<value optimized out>, priority=<value optimized out>, wmesg=<value optimized out>, sbt=<value optimized out>, pr=<value optimized out>, flags=<value optimized out>) at /usr/src/sys/kern/kern_synch.c:250 #4 0xffffffff805bbe10 in pause_sbt (wmesg=<value optimized out>, sbt=<value optimized out>, pr=0, flags=<value optimized out>) at /usr/src/sys/kern/kern_synch.c:379 #5 0xffffffff81e2f175 in usb_pause_mtx (mtx=<value optimized out>, timo=<value optimized out>) at /usr/src/sys/modules/usb/usb/../../../dev/usb/usb_util.c:143 #6 0xffffffff81e16ed7 in usb_ioctl (dev=<value optimized out>, cmd=<value optimized out>, addr=<value optimized out>, fflag=0, td=<value optimized out>) at /usr/src/sys/modules/usb/usb/../../../dev/usb/usb_dev.c:1128 #7 0xffffffff8047cffb in devfs_ioctl_f (fp=0xfffff8001d3d1b40, com=2147767558, data=0xfffffe009453aa20, cred=<value optimized out>, td=0xfffff8001d2044a0) at /usr/src/sys/fs/devfs/devfs_vnops.c:775 #8 0xffffffff8061041e in kern_ioctl (td=0xfffff8001d2044a0, fd=<value optimized out>, com=0) at file.h:318 #9 0xffffffff8060ffa0 in sys_ioctl (td=0xfffff8001d2044a0, uap=0xfffffe009453ab80) at /usr/src/sys/kern/sys_generic.c:718 #10 0xffffffff80877d5d in amd64_syscall (td=0xfffff8001d2044a0, traced=0) at subr_syscall.c:133 #11 0xffffffff8085ac9b in Xfast_syscall () at /usr/src/sys/amd64/amd64/exception.S:390 #12 0x0000000800b7caea in ?? () Previous frame inner to this frame (corrupt stack?) (kgdb) thread 522 [Switching to thread 522 (Thread 100971)]#0 sched_switch (td=0xfffff8001d3a5940, newtd=<value optimized out>, flags=<value optimized out>) at /usr/src/sys/kern/sched_ule.c:1940 1940 cpuid = PCPU_GET(cpuid); (kgdb) where #0 sched_switch (td=0xfffff8001d3a5940, newtd=<value optimized out>, flags=<value optimized out>) at /usr/src/sys/kern/sched_ule.c:1940 #1 0xffffffff805bbf91 in mi_switch (flags=260, newtd=0x0) at /usr/src/sys/kern/kern_synch.c:492 #2 0xffffffff8060126a in sleepq_wait (wchan=0x0, pri=0) at /usr/src/sys/kern/subr_sleepqueue.c:631 #3 0xffffffff805bae82 in _sx_xlock_hard (sx=0xfffff80015e82050, tid=18446735278106892608, opts=<value optimized out>, file=0x0, line=0) at /usr/src/sys/kern/kern_sx.c:688 #4 0xffffffff805ba6ad in _sx_xlock (sx=0x0, opts=0, file=<value optimized out>, line=0) at sx.h:154 #5 0xffffffff81e19baa in usbd_enum_lock (udev=0xfffff80015e82000) at /usr/src/sys/modules/usb/usb/../../../dev/usb/usb_device.c:2755 #6 0xffffffff81e18967 in usb_ref_device (cpd=0xfffff80015b518c0, crd=0xfffffe009453f630, need_uref=<value optimized out>) at /usr/src/sys/modules/usb/usb/../../../dev/usb/usb_dev.c:231 #7 0xffffffff81e15caf in usb_open (dev=<value optimized out>, fflags=3, devtype=<value optimized out>, td=0x0) at /usr/src/sys/modules/usb/usb/../../../dev/usb/usb_dev.c:887 #8 0xffffffff8047ae52 in devfs_open (ap=<value optimized out>) at /usr/src/sys/fs/devfs/devfs_vnops.c:1108 #9 0xffffffff8091e3d1 in VOP_OPEN_APV (vop=<value optimized out>, a=<value optimized out>) at vnode_if.c:467 #10 0xffffffff8067d544 in vn_open_vnode (vp=0xfffff8004f4283b0, fmode=3, cred=0xfffff80028c83500, td=0xfffff8001d3a5940, fp=0xfffff800283b6be0) at vnode_if.h:196 #11 0xffffffff8067d090 in vn_open_cred (ndp=0xfffffe009453f9b0, flagp=0xfffffe009453fa8c, cmode=<value optimized out>, vn_open_flags=<value optimized out>, cred=0x0, fp=0xfffff800283b6be0) at /usr/src/sys/kern/vfs_vnops.c:258 #12 0xffffffff8067674f in kern_openat (td=0xfffff8001d3a5940, fd=-100, path=0x7fffffffe650 <Address 0x7fffffffe650 out of bounds>, pathseg=UIO_USERSPACE, flags=3, mode=<value optimized out>) at /usr/src/sys/kern/vfs_syscalls.c:1081 #13 0xffffffff80877d5d in amd64_syscall (td=0xfffff8001d3a5940, traced=0) at subr_syscall.c:133 #14 0xffffffff8085ac9b in Xfast_syscall () at /usr/src/sys/amd64/amd64/exception.S:390 #15 0x0000000800b748aa in ?? () Previous frame inner to this frame (corrupt stack?) (kgdb) thread 497 [Switching to thread 497 (Thread 100728)]#0 sched_switch (td=0xfffff80015d51940, newtd=<value optimized out>, flags=<value optimized out>) at /usr/src/sys/kern/sched_ule.c:1940 1940 cpuid = PCPU_GET(cpuid); (kgdb) where #0 sched_switch (td=0xfffff80015d51940, newtd=<value optimized out>, flags=<value optimized out>) at /usr/src/sys/kern/sched_ule.c:1940 #1 0xffffffff805bbf91 in mi_switch (flags=260, newtd=0x0) at /usr/src/sys/kern/kern_synch.c:492 #2 0xffffffff8060126a in sleepq_wait (wchan=0x0, pri=0) at /usr/src/sys/kern/subr_sleepqueue.c:631 #3 0xffffffff80553340 in _cv_wait (cvp=0xfffffe0004590d10, lock=0xfffffe0004591090) at /usr/src/sys/kern/kern_condvar.c:139 #4 0xffffffff81e28544 in usb_process (arg=0xfffffe0004590d00) at /usr/src/sys/modules/usb/usb/../../../dev/usb/usb_process.c:193 #5 0xffffffff80577afa in fork_exit (callout=0xffffffff81e28470 <usb_process>, arg=0xfffffe0004590d00, frame=0xfffffe00942e0c00) at /usr/src/sys/kern/kern_fork.c:978 #6 0xffffffff8085aeee in fork_trampoline () at /usr/src/sys/amd64/amd64/exception.S:605 #7 0x0000000000000000 in ?? () (kgdb) thread 496 [Switching to thread 496 (Thread 100731)]#0 sched_switch (td=0xfffff80015d50940, newtd=<value optimized out>, flags=<value optimized out>) at /usr/src/sys/kern/sched_ule.c:1940 1940 cpuid = PCPU_GET(cpuid); (kgdb) where #0 sched_switch (td=0xfffff80015d50940, newtd=<value optimized out>, flags=<value optimized out>) at /usr/src/sys/kern/sched_ule.c:1940 #1 0xffffffff805bbf91 in mi_switch (flags=260, newtd=0x0) at /usr/src/sys/kern/kern_synch.c:492 #2 0xffffffff8060126a in sleepq_wait (wchan=0x0, pri=0) at /usr/src/sys/kern/subr_sleepqueue.c:631 #3 0xffffffff80553340 in _cv_wait (cvp=0xfffffe0004590d68, lock=0xfffffe0004591090) at /usr/src/sys/kern/kern_condvar.c:139 #4 0xffffffff81e28544 in usb_process (arg=0xfffffe0004590d58) at /usr/src/sys/modules/usb/usb/../../../dev/usb/usb_process.c:193 #5 0xffffffff80577afa in fork_exit (callout=0xffffffff81e28470 <usb_process>, arg=0xfffffe0004590d58, frame=0xfffffe00942efc00) at /usr/src/sys/kern/kern_fork.c:978 #6 0xffffffff8085aeee in fork_trampoline () at /usr/src/sys/amd64/amd64/exception.S:605 #7 0x0000000000000000 in ?? () (kgdb) thread 495 [Switching to thread 495 (Thread 100732)]#0 sched_switch (td=0xfffff80015d504a0, newtd=<value optimized out>, flags=<value optimized out>) at /usr/src/sys/kern/sched_ule.c:1940 1940 cpuid = PCPU_GET(cpuid); (kgdb) where #0 sched_switch (td=0xfffff80015d504a0, newtd=<value optimized out>, flags=<value optimized out>) at /usr/src/sys/kern/sched_ule.c:1940 #1 0xffffffff805bbf91 in mi_switch (flags=260, newtd=0x0) at /usr/src/sys/kern/kern_synch.c:492 #2 0xffffffff8060126a in sleepq_wait (wchan=0x0, pri=0) at /usr/src/sys/kern/subr_sleepqueue.c:631 #3 0xffffffff80553340 in _cv_wait (cvp=0xfffffe0004590dc0, lock=0xfffffe0004591090) at /usr/src/sys/kern/kern_condvar.c:139 #4 0xffffffff81e28544 in usb_process (arg=0xfffffe0004590db0) at /usr/src/sys/modules/usb/usb/../../../dev/usb/usb_process.c:193 #5 0xffffffff80577afa in fork_exit (callout=0xffffffff81e28470 <usb_process>, arg=0xfffffe0004590db0, frame=0xfffffe00942f4c00) at /usr/src/sys/kern/kern_fork.c:978 #6 0xffffffff8085aeee in fork_trampoline () at /usr/src/sys/amd64/amd64/exception.S:605 #7 0x0000000000000000 in ?? () (kgdb) thread 495 [Switching to thread 495 (Thread 100732)]#0 sched_switch (td=0xfffff80015d504a0, newtd=<value optimized out>, flags=<value optimized out>) at /usr/src/sys/kern/sched_ule.c:1940 1940 cpuid = PCPU_GET(cpuid); (kgdb) where #0 sched_switch (td=0xfffff80015d504a0, newtd=<value optimized out>, flags=<value optimized out>) at /usr/src/sys/kern/sched_ule.c:1940 #1 0xffffffff805bbf91 in mi_switch (flags=260, newtd=0x0) at /usr/src/sys/kern/kern_synch.c:492 #2 0xffffffff8060126a in sleepq_wait (wchan=0x0, pri=0) at /usr/src/sys/kern/subr_sleepqueue.c:631 #3 0xffffffff80553340 in _cv_wait (cvp=0xfffffe0004590dc0, lock=0xfffffe0004591090) at /usr/src/sys/kern/kern_condvar.c:139 #4 0xffffffff81e28544 in usb_process (arg=0xfffffe0004590db0) at /usr/src/sys/modules/usb/usb/../../../dev/usb/usb_process.c:193 #5 0xffffffff80577afa in fork_exit (callout=0xffffffff81e28470 <usb_process>, arg=0xfffffe0004590db0, frame=0xfffffe00942f4c00) at /usr/src/sys/kern/kern_fork.c:978 #6 0xffffffff8085aeee in fork_trampoline () at /usr/src/sys/amd64/amd64/exception.S:605 #7 0x0000000000000000 in ?? () (kgdb) thread 494 [Switching to thread 494 (Thread 100733)]#0 sched_switch (td=0xfffff80015d50000, newtd=<value optimized out>, flags=<value optimized out>) at /usr/src/sys/kern/sched_ule.c:1940 1940 cpuid = PCPU_GET(cpuid); (kgdb) where #0 sched_switch (td=0xfffff80015d50000, newtd=<value optimized out>, flags=<value optimized out>) at /usr/src/sys/kern/sched_ule.c:1940 #1 0xffffffff805bbf91 in mi_switch (flags=260, newtd=0x0) at /usr/src/sys/kern/kern_synch.c:492 #2 0xffffffff8060126a in sleepq_wait (wchan=0x0, pri=0) at /usr/src/sys/kern/subr_sleepqueue.c:631 #3 0xffffffff80553340 in _cv_wait (cvp=0xfffffe0004590e18, lock=0xfffffe0004591090) at /usr/src/sys/kern/kern_condvar.c:139 #4 0xffffffff81e28544 in usb_process (arg=0xfffffe0004590e08) at /usr/src/sys/modules/usb/usb/../../../dev/usb/usb_process.c:193 #5 0xffffffff80577afa in fork_exit (callout=0xffffffff81e28470 <usb_process>, arg=0xfffffe0004590e08, frame=0xfffffe00942f9c00) at /usr/src/sys/kern/kern_fork.c:978 #6 0xffffffff8085aeee in fork_trampoline () at /usr/src/sys/amd64/amd64/exception.S:605 #7 0x0000000000000000 in ?? () (kgdb) thread 493 [Switching to thread 493 (Thread 100735)]#0 sched_switch (td=0xfffff80015d7f4a0, newtd=<value optimized out>, flags=<value optimized out>) at /usr/src/sys/kern/sched_ule.c:1940 1940 cpuid = PCPU_GET(cpuid); (kgdb) where #0 sched_switch (td=0xfffff80015d7f4a0, newtd=<value optimized out>, flags=<value optimized out>) at /usr/src/sys/kern/sched_ule.c:1940 #1 0xffffffff805bbf91 in mi_switch (flags=260, newtd=0x0) at /usr/src/sys/kern/kern_synch.c:492 #2 0xffffffff8060126a in sleepq_wait (wchan=0x0, pri=0) at /usr/src/sys/kern/subr_sleepqueue.c:631 #3 0xffffffff80553340 in _cv_wait (cvp=0xfffffe00064a7d10, lock=0xfffffe00064a8090) at /usr/src/sys/kern/kern_condvar.c:139 #4 0xffffffff81e28544 in usb_process (arg=0xfffffe00064a7d00) at /usr/src/sys/modules/usb/usb/../../../dev/usb/usb_process.c:193 #5 0xffffffff80577afa in fork_exit (callout=0xffffffff81e28470 <usb_process>, arg=0xfffffe00064a7d00, frame=0xfffffe0094303c00) at /usr/src/sys/kern/kern_fork.c:978 #6 0xffffffff8085aeee in fork_trampoline () at /usr/src/sys/amd64/amd64/exception.S:605 #7 0x0000000000000000 in ?? () (kgdb) thread 492 [Switching to thread 492 (Thread 100736)]#0 sched_switch (td=0xfffff80015d7f000, newtd=<value optimized out>, flags=<value optimized out>) at /usr/src/sys/kern/sched_ule.c:1940 1940 cpuid = PCPU_GET(cpuid); (kgdb) where #0 sched_switch (td=0xfffff80015d7f000, newtd=<value optimized out>, flags=<value optimized out>) at /usr/src/sys/kern/sched_ule.c:1940 #1 0xffffffff805bbf91 in mi_switch (flags=260, newtd=0x0) at /usr/src/sys/kern/kern_synch.c:492 #2 0xffffffff8060126a in sleepq_wait (wchan=0x0, pri=0) at /usr/src/sys/kern/subr_sleepqueue.c:631 #3 0xffffffff80553340 in _cv_wait (cvp=0xfffffe00064a7d68, lock=0xfffffe00064a8090) at /usr/src/sys/kern/kern_condvar.c:139 #4 0xffffffff81e28544 in usb_process (arg=0xfffffe00064a7d58) at /usr/src/sys/modules/usb/usb/../../../dev/usb/usb_process.c:193 #5 0xffffffff80577afa in fork_exit (callout=0xffffffff81e28470 <usb_process>, arg=0xfffffe00064a7d58, frame=0xfffffe0094308c00) at /usr/src/sys/kern/kern_fork.c:978 #6 0xffffffff8085aeee in fork_trampoline () at /usr/src/sys/amd64/amd64/exception.S:605 #7 0x0000000000000000 in ?? () (kgdb) thread 491 [Switching to thread 491 (Thread 100737)]#0 sched_switch (td=0xfffff80015ea0940, newtd=<value optimized out>, flags=<value optimized out>) at /usr/src/sys/kern/sched_ule.c:1940 1940 cpuid = PCPU_GET(cpuid); (kgdb) where #0 sched_switch (td=0xfffff80015ea0940, newtd=<value optimized out>, flags=<value optimized out>) at /usr/src/sys/kern/sched_ule.c:1940 #1 0xffffffff805bbf91 in mi_switch (flags=260, newtd=0x0) at /usr/src/sys/kern/kern_synch.c:492 #2 0xffffffff8060126a in sleepq_wait (wchan=0x0, pri=0) at /usr/src/sys/kern/subr_sleepqueue.c:631 #3 0xffffffff805bb99d in _sleep (ident=<value optimized out>, lock=<value optimized out>, priority=<value optimized out>, wmesg=<value optimized out>, sbt=<value optimized out>, pr=<value optimized out>, flags=<value optimized out>) at /usr/src/sys/kern/kern_synch.c:254 #4 0xffffffff802a2548 in cam_sim_free (sim=0xfffff8004f9fa800, free_devq=1) at /usr/src/sys/cam/cam_sim.c:109 #5 0xffffffff81e4e78f in umass_detach (dev=<value optimized out>) at /usr/src/sys/modules/usb/umass/../../../dev/usb/storage/umass.c:2136 #6 0xffffffff805e8ce2 in device_detach (dev=0xfffff80028c69000) at device_if.h:214 #7 0xffffffff81e1aad1 in usb_detach_device (udev=0xfffff8004f5bd000, iface_index=<value optimized out>, flag=0 '\0') at /usr/src/sys/modules/usb/usb/../../../dev/usb/usb_device.c:1145 #8 0xffffffff81e19c76 in usb_unconfigure (udev=0xfffff8004f5bd000, flag=0 '\0') at /usr/src/sys/modules/usb/usb/../../../dev/usb/usb_device.c:534 #9 0xffffffff81e196d0 in usbd_set_config_index (udev=0xfffff8004f5bd000, index=255 'ΓΏ') at /usr/src/sys/modules/usb/usb/../../../dev/usb/usb_device.c:597 #10 0xffffffff81e22d77 in uhub_explore_handle_re_enumerate (child=0xfffff8004f5bd000) at /usr/src/sys/modules/usb/usb/../../../dev/usb/usb_hub.c:456 #11 0xffffffff81e25eb5 in uhub_explore (udev=0xfffff80015e82000) at /usr/src/sys/modules/usb/usb/../../../dev/usb/usb_hub.c:551 #12 0xffffffff81e12f75 in usb_bus_explore (pm=<value optimized out>) at /usr/src/sys/modules/usb/usb/../../../dev/usb/controller/usb_controller.c:404 #13 0xffffffff81e2857f in usb_process (arg=0xfffffe00064a7db0) at /usr/src/sys/modules/usb/usb/../../../dev/usb/usb_process.c:176 #14 0xffffffff80577afa in fork_exit (callout=0xffffffff81e28470 <usb_process>, arg=0xfffffe00064a7db0, frame=0xfffffe009430dc00) at /usr/src/sys/kern/kern_fork.c:978 #15 0xffffffff8085aeee in fork_trampoline () at /usr/src/sys/amd64/amd64/exception.S:605 #16 0x0000000000000000 in ?? () (kgdb) thread 490 [Switching to thread 490 (Thread 100738)]#0 sched_switch (td=0xfffff80015ea04a0, newtd=<value optimized out>, flags=<value optimized out>) at /usr/src/sys/kern/sched_ule.c:1940 1940 cpuid = PCPU_GET(cpuid); (kgdb) where #0 sched_switch (td=0xfffff80015ea04a0, newtd=<value optimized out>, flags=<value optimized out>) at /usr/src/sys/kern/sched_ule.c:1940 #1 0xffffffff805bbf91 in mi_switch (flags=260, newtd=0x0) at /usr/src/sys/kern/kern_synch.c:492 #2 0xffffffff8060126a in sleepq_wait (wchan=0x0, pri=0) at /usr/src/sys/kern/subr_sleepqueue.c:631 #3 0xffffffff80553340 in _cv_wait (cvp=0xfffffe00064a7e18, lock=0xfffffe00064a8090) at /usr/src/sys/kern/kern_condvar.c:139 #4 0xffffffff81e28544 in usb_process (arg=0xfffffe00064a7e08) at /usr/src/sys/modules/usb/usb/../../../dev/usb/usb_process.c:193 #5 0xffffffff80577afa in fork_exit (callout=0xffffffff81e28470 <usb_process>, arg=0xfffffe00064a7e08, frame=0xfffffe0094312c00) at /usr/src/sys/kern/kern_fork.c:978 #6 0xffffffff8085aeee in fork_trampoline () at /usr/src/sys/amd64/amd64/exception.S:605 #7 0x0000000000000000 in ?? () So it looks like thread 491 is blocking thread 522 by holding udev->enum_sx? Fabian
This archive was generated by hypermail 2.4.0 : Wed May 19 2021 - 11:40:54 UTC