thr3ads.net - freebsd stable - Help debugging stable/10 [Mar 2015]

If this information is useful, please help other people find it:
Share via:

Andriy Gapon

2014-Dec-25 12:33 UTC

Help debugging stable/10

On 25/12/2014 11:29, Hans Petter Selasky wrote:> The cam_sim_free() is stuck, blocking the rest of that controller from
> enumerating. It might look like a non-USB stack issue.
> 
> MAV: Do you have some ideas where to start looking, now we have a dump? Any
> refcounts to check in particular?
Apparently sim->refcount > 0.
Not sure how to check who has the reference(s).
>> Thread 254 (Thread 100039):
>> #0  sched_switch (td=0xfffff8000669e000, newtd=<value optimized
out>,
>> flags=<value optimized out>)
>>     at /usr/src/sys/kern/sched_ule.c:1945
>> #1  0xffffffff809350b1 in mi_switch (flags=260, newtd=0x0) at
>> /usr/src/sys/kern/kern_synch.c:493
>> #2  0xffffffff80972a2a in sleepq_wait (wchan=0x0, pri=0) at
>> /usr/src/sys/kern/subr_sleepqueue.c:617
>> #3  0xffffffff80934ad7 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:255
>> #4  0xffffffff802df838 in cam_sim_free (sim=0xfffff801f5ee8900,
free_devq=1)
>> at /usr/src/sys/cam/cam_sim.c:109
>> #5  0xffffffff807a5549 in umass_detach (dev=<value optimized
out>) at
>> /usr/src/sys/dev/usb/storage/umass.c:2139
>> #6  0xffffffff8095d042 in device_detach (dev=0xfffff8018b028900) at
>> device_if.h:214
>> #7  0xffffffff807b23b1 in usb_detach_device (udev=0xfffff801ea710000,
>> iface_index=<value optimized out>, flag=0 '\0')
>>     at /usr/src/sys/dev/usb/usb_device.c:1148
>> #8  0xffffffff807b14d6 in usb_unconfigure (udev=0xfffff801ea710000,
flag=2
>> '\002')
>>     at /usr/src/sys/dev/usb/usb_device.c:537
>> #9  0xffffffff807b4466 in usb_free_device (udev=0xfffff801ea710000,
>> flag=<value optimized out>)
>>     at /usr/src/sys/dev/usb/usb_device.c:2175
>> #10 0xffffffff807bda6f in uhub_explore (udev=0xfffff8000d6c4000) at
>> /usr/src/sys/dev/usb/usb_hub.c:647
>> #11 0xffffffff807be0d9 in uhub_explore (udev=0xfffff8000d07d000) at
>> /usr/src/sys/dev/usb/usb_hub.c:574
>> #12 0xffffffff807a42c0 in usb_bus_explore (pm=<value optimized
out>)
>>     at /usr/src/sys/dev/usb/controller/usb_controller.c:406
>> #13 0xffffffff807c05af in usb_process (arg=0xfffffe0000ac4db0) at
>> /usr/src/sys/dev/usb/usb_process.c:177
>> #14 0xffffffff808fc66a in fork_exit (callout=0xffffffff807c0490
<usb_process>,
>> arg=0xfffffe0000ac4db0,
>> ---Type <return> to continue, or q <return> to quit---
>>     frame=0xfffffe0212f7aac0) at /usr/src/sys/kern/kern_fork.c:996
>> #15 0xffffffff80d10eee in fork_trampoline () at
>> /usr/src/sys/amd64/amd64/exception.S:611
>> #16 0x0000000000000000 in ?? ()
> 
> 
> _______________________________________________
> freebsd-stable at freebsd.org mailing list
> http://lists.freebsd.org/mailman/listinfo/freebsd-stable
> To unsubscribe, send any mail to "freebsd-stable-unsubscribe at
freebsd.org"
> 

-- 
Andriy Gapon

Shane Ambler

2015-Mar-23 15:25 UTC

head link

Help debugging stable/10

On 25/12/2014 23:03, Andriy Gapon wrote:> On 25/12/2014 11:29, Hans Petter Selasky wrote:
>> The cam_sim_free() is stuck, blocking the rest of that controller from
>> enumerating. It might look like a non-USB stack issue.
>>
>> MAV: Do you have some ideas where to start looking, now we have a dump?
Any
>> refcounts to check in particular?
>
> Apparently sim->refcount > 0.
> Not sure how to check who has the reference(s).
>
I am now running
FreeBSD leader.local 10.1-STABLE FreeBSD 10.1-STABLE #4 r279865: Thu
Mar 12 14:25:28 ACDT 2015     root at leader.local:/usr/obj/usr/src/sys
/GENERIC  amd64

I have just tried running with a custom kernel, GENERIC plus DDB GDB
DEADLKRES INVARIANTS INVARIANT_SUPPORT WITNESS WITNESS_SKIPSPIN

When starting Xorg I got a duplicate lock message coming from nvidia,
after running for maybe 20 mins it just reset without warning. I then
decided to go back to the GENERIC kernel and on restarting I got some
lock reversal messages.

nvidia-driver-346.47

nvidia0: <GeForce GT 520> on vgapci0
vgapci0: child nvidia0 requested pci_enable_io
vgapci0: child nvidia0 requested pci_enable_io
vgapci0: Boot video device
hdac0: <NVIDIA GF119 HDA Controller> mem 0xfb080000-0xfb083fff irq 17 at 
device 0.1 on pci1

Full dmesg and other kgdb outputs I have collected are at -
http://shaneware.biz/freebsddebugdata/

Trying to mount root from zfs:zrpleader []...
ums0: <Logitech USB-PS2 Optical Mouse, class 0/0, rev 2.00/11.10, addr 
4> on usbus2
ums0: 3 buttons and [XYZ] coordinates ID=0
ums1: <Wacom Co.,Ltd. CTH-470, class 0/0, rev 2.00/1.00, addr 5> on usbus2
ums1: 6 buttons and [XY] coordinates ID=1
uhid0: <Wacom Co.,Ltd. CTH-470, class 0/0, rev 2.00/1.00, addr 5> on
usbus2
uhid1: <vendor 0x05af USB Keyboard, class 0/0, rev 2.00/1.92, addr 6> on 
usbus2
uhid0: at uhub5, port 2, addr 5 (disconnected)
ums1: at uhub5, port 2, addr 5 (disconnected)
ipfw2 (+ipv6) initialized, divert loadable, nat loadable, default to 
deny, logging disabled
acquiring duplicate lock of same type: "os.lock_sx"
  1st os.lock_sx @ nvidia_os.c:609
  2nd os.lock_sx @ nvidia_os.c:609
KDB: stack backtrace:
db_trace_self_wrapper() at db_trace_self_wrapper+0x2b/frame 
0xfffffe0238b8d400
kdb_backtrace() at kdb_backtrace+0x39/frame 0xfffffe0238b8d4b0
witness_checkorder() at witness_checkorder+0xdc2/frame 0xfffffe0238b8d540
_sx_xlock() at _sx_xlock+0x75/frame 0xfffffe0238b8d580
os_acquire_mutex() at os_acquire_mutex+0x32/frame 0xfffffe0238b8d5a0
_nv010785rm() at _nv010785rm+0x18/frame 0xfffffe000f2fee90
dmapbase() at 0xfffff8001cc40e80/frame 0xfffff8001cc40e18
kernphys() at 0xc1d00001/frame 0xfffff8001cc40e00
(null)() at 0xfffffe0000c5e000/frame 0xc1d0000100000001
acquiring duplicate lock of same type: "os.lock_mtx"
  1st os.lock_mtx @ nvidia_os.c:783
  2nd os.lock_mtx @ nvidia_os.c:783
KDB: stack backtrace:
db_trace_self_wrapper() at db_trace_self_wrapper+0x2b/frame 
0xfffffe0238b8d0e0
kdb_backtrace() at kdb_backtrace+0x39/frame 0xfffffe0238b8d190
witness_checkorder() at witness_checkorder+0xdc2/frame 0xfffffe0238b8d220
__mtx_lock_flags() at __mtx_lock_flags+0xa8/frame 0xfffffe0238b8d270
os_acquire_spinlock() at os_acquire_spinlock+0x1b/frame 0xfffffe0238b8d280
_nv012385rm() at _nv012385rm+0xd75/frame 0xfffffe0000bceef0
pid 3568 (gsettings-data-conv), uid 1001: exited on signal 5

Mar 24 00:24:25 leader kernel: Waiting (max 60 seconds) for system 
process `vnlru' to stop...done
Mar 24 00:24:25 leader kernel: Waiting (max 60 seconds) for system 
process `bufdaemon' to stop...done
Mar 24 00:24:25 leader kernel: Waiting (max 60 seconds) for system 
process `syncer' to stop...
Mar 24 00:24:25 leader kernel: Syncing disks, vnodes remaining...0 0 0 0 
0 0 0 0 done
Mar 24 00:24:25 leader kernel: All buffers synced.
Mar 24 00:24:25 leader kernel: lock order reversal:
Mar 24 00:24:25 leader kernel: 1st 0xfffff800224555f0 zfs (zfs) @ 
/usr/src/sys/kern/vfs_mount.c:1229
Mar 24 00:24:25 leader kernel: 2nd 0xfffff800222d67c8 syncer (syncer) @ 
/usr/src/sys/kern/vfs_subr.c:2268
Mar 24 00:24:25 leader kernel: KDB: stack backtrace:
Mar 24 00:24:25 leader kernel: db_trace_self_wrapper() at 
db_trace_self_wrapper+0x2b/frame 0xfffffe022df6e4c0
Mar 24 00:24:25 leader kernel: kdb_backtrace() at 
kdb_backtrace+0x39/frame 0xfffffe022df6e570
Mar 24 00:24:25 leader kernel: witness_checkorder() at 
witness_checkorder+0xdc2/frame 0xfffffe022df6e600
Mar 24 00:24:25 leader kernel: __lockmgr_args() at 
__lockmgr_args+0x9ea/frame 0xfffffe022df6e740
Mar 24 00:24:25 leader kernel: vop_stdlock() at vop_stdlock+0x3c/frame 
0xfffffe022df6e760
Mar 24 00:24:25 leader kernel: VOP_LOCK1_APV() at 
VOP_LOCK1_APV+0xfc/frame 0xfffffe022df6e790
Mar 24 00:24:25 leader kernel: _vn_lock() at _vn_lock+0xaa/frame 
0xfffffe022df6e800
Mar 24 00:24:25 leader kernel: vputx() at vputx+0x232/frame 
0xfffffe022df6e860
Mar 24 00:24:25 leader kernel: dounmount() at dounmount+0x301/frame 
0xfffffe022df6e8e0
Mar 24 00:24:25 leader kernel: vfs_unmountall() at 
vfs_unmountall+0x61/frame 0xfffffe022df6e910
Mar 24 00:24:25 leader kernel: kern_reboot() at kern_reboot+0x540/frame 
0xfffffe022df6e980
Mar 24 00:24:25 leader kernel: sys_reboot() at sys_reboot+0x5a/frame 
0xfffffe022df6e9a0
Mar 24 00:24:25 leader kernel: amd64_syscall() at 
amd64_syscall+0x25a/frame 0xfffffe022df6eab0
Mar 24 00:24:25 leader kernel: Xfast_syscall() at 
Xfast_syscall+0xfb/frame 0xfffffe022df6eab0
Mar 24 00:24:25 leader kernel: --- syscall (55, FreeBSD ELF64, 
sys_reboot), rip = 0x40f1bc, rsp = 0x7fffffffe6d8, rbp = 0x7fffffffe7d0 ---
Mar 24 00:24:25 leader kernel: lock order reversal:
Mar 24 00:24:25 leader kernel: 1st 0xfffff800222d6b78 zfs (zfs) @ 
/usr/src/sys/modules/zfs/../../cddl/contrib/opensolaris/uts/common/fs/zfs/zfs_vfsops.c:1814
Mar 24 00:24:25 leader kernel: 2nd 0xffffffff818514a8 allproc (allproc) 
@ /usr/src/sys/kern/kern_descrip.c:2872
Mar 24 00:24:25 leader kernel: KDB: stack backtrace:
Mar 24 00:24:25 leader kernel: db_trace_self_wrapper() at 
db_trace_self_wrapper+0x2b/frame 0xfffffe022df6e690
Mar 24 00:24:25 leader kernel: kdb_backtrace() at 
kdb_backtrace+0x39/frame 0xfffffe022df6e740
Mar 24 00:24:25 leader kernel: witness_checkorder() at 
witness_checkorder+0xdc2/frame 0xfffffe022df6e7d0
Mar 24 00:24:25 leader kernel: _sx_slock() at _sx_slock+0x76/frame 
0xfffffe022df6e810
Mar 24 00:24:25 leader kernel: mountcheckdirs() at 
mountcheckdirs+0x47/frame 0xfffffe022df6e860
Mar 24 00:24:25 leader kernel: dounmount() at dounmount+0x36f/frame 
0xfffffe022df6e8e0
Mar 24 00:24:25 leader kernel: vfs_unmountall() at 
vfs_unmountall+0x61/frame 0xfffffe022df6e910
Mar 24 00:24:25 leader kernel: kern_reboot() at kern_reboot+0x540/frame 
0xfffffe022df6e980
Mar 24 00:24:25 leader kernel: sys_reboot() at sys_reboot+0x5a/frame 
0xfffffe022df6e9a0
Mar 24 00:24:25 leader kernel: amd64_syscall() at 
amd64_syscall+0x25a/frame 0xfffffe022df6eab0
Mar 24 00:24:25 leader kernel: Xfast_syscall() at 
Xfast_syscall+0xfb/frame 0xfffffe022df6eab0
Mar 24 00:24:25 leader kernel: --- syscall (55, FreeBSD ELF64, 
sys_reboot), rip = 0x40f1bc, rsp = 0x7fffffffe6d8, rbp = 0x7fffffffe7d0 ---
Mar 24 00:24:25 leader kernel: lock order reversal:
Mar 24 00:24:25 leader kernel: 1st 0xfffff8001ca8e240 zfs (zfs) @ 
/usr/src/sys/kern/vfs_mount.c:1229
Mar 24 00:24:25 leader kernel: 2nd 0xfffff8001ca8e5f0 devfs (devfs) @ 
/usr/src/sys/kern/vfs_subr.c:2157
Mar 24 00:24:25 leader kernel: KDB: stack backtrace:
Mar 24 00:24:25 leader kernel: db_trace_self_wrapper() at 
db_trace_self_wrapper+0x2b/frame 0xfffffe022df6e460
Mar 24 00:24:25 leader kernel: kdb_backtrace() at 
kdb_backtrace+0x39/frame 0xfffffe022df6e510
Mar 24 00:24:25 leader kernel: witness_checkorder() at 
witness_checkorder+0xdc2/frame 0xfffffe022df6e5a0
Mar 24 00:24:25 leader kernel: __lockmgr_args() at 
__lockmgr_args+0x9ea/frame 0xfffffe022df6e6e0
Mar 24 00:24:25 leader kernel: vop_stdlock() at vop_stdlock+0x3c/frame 
0xfffffe022df6e700
Mar 24 00:24:25 leader kernel: VOP_LOCK1_APV() at 
VOP_LOCK1_APV+0xfc/frame 0xfffffe022df6e730
Mar 24 00:24:25 leader kernel: _vn_lock() at _vn_lock+0xaa/frame 
0xfffffe022df6e7a0
Mar 24 00:24:25 leader kernel: vget() at vget+0x67/frame 0xfffffe022df6e7e0
Mar 24 00:24:25 leader kernel: devfs_allocv() at devfs_allocv+0xfd/frame 
0xfffffe022df6e830
Mar 24 00:24:25 leader kernel: devfs_root() at devfs_root+0x43/frame 
0xfffffe022df6e860
Mar 24 00:24:25 leader kernel: dounmount() at dounmount+0x345/frame 
0xfffffe022df6e8e0
Mar 24 00:24:25 leader kernel: vfs_unmountall() at 
vfs_unmountall+0x61/frame 0xfffffe022df6e910
Mar 24 00:24:25 leader kernel: kern_reboot() at kern_reboot+0x540/frame 
0xfffffe022df6e980
Mar 24 00:24:25 leader kernel: sys_reboot() at sys_reboot+0x5a/frame 
0xfffffe022df6e9a0
Mar 24 00:24:25 leader kernel: amd64_syscall() at 
amd64_syscall+0x25a/frame 0xfffffe022df6eab0
Mar 24 00:24:25 leader kernel: Xfast_syscall() at 
Xfast_syscall+0xfb/frame 0xfffffe022df6eab0
Mar 24 00:24:25 leader kernel: --- syscall (55, FreeBSD ELF64, 
sys_reboot), rip = 0x40f1bc, rsp = 0x7fffffffe6d8, rbp = 0x7fffffffe7d0 ---
Mar 24 00:24:25 leader kernel: Uptime: 12m42s

-- 
FreeBSD - the place to B...Software Developing

Shane Ambler

freebsd stable - Mar 2015 - Help debugging stable/10

Help debugging stable/10

Help debugging stable/10