Skip site navigation (1)Skip section navigation (2)
Date:      Thu, 20 Mar 2014 15:10:10 +1030
From:      "Daniel O'Connor" <doconnor@gsoft.com.au>
To:        Hans Petter Selasky <hps@bitfrost.no>
Cc:        freebsd-usb@freebsd.org
Subject:   Re: USB config SX lock deadlock
Message-ID:  <084BCD21-ADE9-4E60-B637-99EEE1D26389@gsoft.com.au>
In-Reply-To: <52565BB1.8070506@bitfrost.no>
References:  <9783900F-08A1-41FB-81B8-3C9809B82521@gsoft.com.au> <52553000.2010003@bitfrost.no> <A2C6A9D3-1595-41D2-A5C6-B544A3E40058@gsoft.com.au> <52554855.6030404@bitfrost.no> <FFD6BC71-0CAC-41AE-9450-6549F4B0E9C5@gsoft.com.au> <52564953.8080707@bitfrost.no> <7610BC59-ED91-4807-B145-7F7DD2C725E9@gsoft.com.au> <52565BB1.8070506@bitfrost.no>

next in thread | previous in thread | raw e-mail | index | archive | help

--Apple-Mail=_E230DD3A-5B09-4F17-A638-593974F6F8F2
Content-Transfer-Encoding: quoted-printable
Content-Type: text/plain;
	charset=utf-8


On 10 Oct 2013, at 18:18, Hans Petter Selasky <hps@bitfrost.no> wrote:
> On 10/10/13 09:38, Daniel O'Connor wrote:
>>=20
>> On 10/10/2013, at 16:59, Hans Petter Selasky <hps@bitfrost.no> wrote:
>> The usb_fifo_* code handles all wakeups so I am not sure.
>=20
> The usb_fifo code only will only do refcounting. If you do USB control =
requests, you should use the f_ioctl_post, callback, because the f_ioctl =
callback does not protect against attach and detach or the enumeration =
thread running.
>=20
>        err =3D (f->methods->f_ioctl) (f, cmd, addr, fflags);
>=20
>        DPRINTFN(2, "f_ioctl cmd 0x%lx =3D %d\n", cmd, err);
>=20
>        if (err !=3D ENOIOCTL)
>                goto done;
>=20
>        if (usb_usb_ref_device(cpd, &refs)) {
>                err =3D ENXIO;
>                goto done;
>        }
>=20
>        err =3D (f->methods->f_ioctl_post) (f, cmd, addr, fflags);
>=20
>        DPRINTFN(2, "f_ioctl_post cmd 0x%lx =3D %d\n", cmd, err);

After a long hiatus I have come back to this problem.

I updated a test system to 9-STABLE (r263062) and the problem occurs =
quite often. I'm still trying to find _why_ my device disconnects =
(unfortunately it has no debugger so it's tricky), however with this =
kernel is very reliably hangs (under and hour of tests).

I end up with the following backtrace of the thread in question..
(kgdb) bt
#0  sched_switch (td=3D0xfffffe011fa9c000, newtd=3D0xfffffe0002953000, =
flags=3D<value optimized out>) at /local0/src/sys/kern/sched_ule.c:1904
#1  0xffffffff8089e5b0 in mi_switch (flags=3D260, newtd=3D0x0) at =
/local0/src/sys/kern/kern_synch.c:485
#2  0xffffffff808d5274 in sleepq_wait (wchan=3D0xfffffe011faed050, =
pri=3D0) at /local0/src/sys/kern/subr_sleepqueue.c:618
#3  0xffffffff8089d916 in _sx_xlock_hard (sx=3D0xfffffe011faed050, =
tid=3D18446741879512481792, opts=3D<value optimized out>, file=3D<value =
optimized out>,
    line=3D<value optimized out>) at /local0/src/sys/kern/kern_sx.c:678
#4  0xffffffff8089de06 in _sx_xlock (sx=3D0xfffffe011faed050, opts=3D0, =
file=3D0xffffffff80e4d528 "/local0/src/sys/dev/usb/usb_device.c", =
line=3D2651) at sx.h:161
#5  0xffffffff8071245a in usbd_enum_lock (udev=3D0xfffffe011faed000) at =
/local0/src/sys/dev/usb/usb_device.c:2651
#6  0xffffffff807207a2 in usbd_do_request_flags =
(udev=3D0xfffffe011faed000, mtx=3D0x0, req=3D0xffffff812c402920, =
data=3D0xfffffe011fab8274, flags=3D4, actlen=3D0x0, timeout=3D5000)
    at /local0/src/sys/dev/usb/usb_request.c:459
#7  0xffffffff81c6493c in ugsio_udioctl (fifo=3D<value optimized out>, =
cmd=3D3222040644, data=3D0xfffffe011fab8270, fflags=3D<value optimized =
out>) at ugsio.c:1038
#8  0xffffffff8070f932 in usb_ioctl (dev=3D<value optimized out>, =
cmd=3D3222040644, addr=3D0xfffffe011fab8270 "\001", fflag=3D<value =
optimized out>, td=3D<value optimized out>)
    at /local0/src/sys/dev/usb/usb_dev.c:1075
#9  0xffffffff8078f01a in devfs_ioctl_f (fp=3D0xfffffe0008f21be0, =
com=3D3222040644, data=3D<value optimized out>, cred=3D<value optimized =
out>, td=3D0xfffffe011fa9c000)
    at /local0/src/sys/fs/devfs/devfs_vnops.c:758
#10 0xffffffff808df946 in kern_ioctl (td=3D0xfffffe011fa9c000, fd=3D3, =
com=3D3222040644, data=3D0xfffffe011fab8270 "\001") at file.h:311
#11 0xffffffff808dfb5d in sys_ioctl (td=3D0xfffffe011fa9c000, =
uap=3D0xffffff812c402b70) at /local0/src/sys/kern/sys_generic.c:696
#12 0xffffffff80c4ee58 in amd64_syscall (td=3D0xfffffe011fa9c000, =
traced=3D0) at subr_syscall.c:135
#13 0xffffffff80c3aa67 in Xfast_syscall () at =
/local0/src/sys/amd64/amd64/exception.S:391
#14 0x00000008010e7d9c in ?? ()

and the code at frame 7
1033	    usbreq.bRequest =3D VC_CMD;
1034	    USETW(usbreq.wValue, vccmd->value);
1035	    USETW(usbreq.wIndex, vccmd->index);
1036	    USETW(usbreq.wLength, sizeof(vccmd->data));
1037
1038	    if ((err =3D usbd_do_request_flags(udev, NULL, &usbreq, =
vccmd->data, USB_SHORT_XFER_OK, NULL, 20000)) !=3D =
USB_ERR_NORMAL_COMPLETION) {
1039		DPRINTFN(1, "USB request failed: %d\n", err);
1040		return(err);
1041	    }
1042

The lock object looks like..
(kgdb) print sx
$1 =3D (struct sx *) 0xfffffe011faed050
(kgdb) print *sx
$2 =3D {lock_object =3D {lo_name =3D 0xffffffff80e4d3d7 "USB config SX =
lock", lo_flags =3D 41091072, lo_data =3D 0, lo_witness =3D 0x0}, =
sx_lock =3D 18446741874768565396}

I tried 'show alllocks' in DDB but it doesn't list anything even though =
witness is in the kernel :(

However some digging shows most of the USB process threads look the same =
except for..

* 42 Thread 100030 (PID=3D15: usb/usbus0)  sched_switch =
(td=3D0xfffffe0004e75490, newtd=3D0xfffffe0002953000, flags=3D<value =
optimized out>)
    at /local0/src/sys/kern/sched_ule.c:1904
#0  sched_switch (td=3D0xfffffe0004e75490, newtd=3D0xfffffe0002953000, =
flags=3D<value optimized out>) at /local0/src/sys/kern/sched_ule.c:1904
#1  0xffffffff8089e5b0 in mi_switch (flags=3D260, newtd=3D0x0) at =
/local0/src/sys/kern/kern_synch.c:485
#2  0xffffffff808d5274 in sleepq_wait (wchan=3D0xfffffe000851a288, =
pri=3D0) at /local0/src/sys/kern/subr_sleepqueue.c:618
#3  0xffffffff80852c6d in _cv_wait (cvp=3D0xfffffe000851a288, =
lock=3D0xffffffff81403700) at /local0/src/sys/kern/kern_condvar.c:139
#4  0xffffffff8071195c in usb_fifo_free (f=3D0xfffffe000851a200) at =
/local0/src/sys/dev/usb/usb_dev.c:609
#5  0xffffffff80711a52 in usb_fifo_detach (f_sc=3D0xfffffe0008802458) at =
/local0/src/sys/dev/usb/usb_dev.c:1824
#6  0xffffffff81c64041 in ugsio_detach (dev=3D<value optimized out>) at =
ugsio.c:341
#7  0xffffffff808c35a4 in device_detach (dev=3D0xfffffe0008bf3100) at =
device_if.h:214
#8  0xffffffff807130b8 in usb_detach_device (udev=3D0xfffffe011faed000, =
iface_index=3D32 ' ', flag=3D<value optimized out>) at =
/local0/src/sys/dev/usb/usb_device.c:1050
#9  0xffffffff80713a7c in usb_unconfigure (udev=3D0xfffffe011faed000, =
flag=3D<value optimized out>) at =
/local0/src/sys/dev/usb/usb_device.c:450
#10 0xffffffff80714287 in usbd_set_config_index =
(udev=3D0xfffffe011faed000, index=3D255 '=EF=BF=BD') at =
/local0/src/sys/dev/usb/usb_device.c:513
#11 0xffffffff8071ce11 in uhub_explore (udev=3D0xfffffe0008166000) at =
/local0/src/sys/dev/usb/usb_hub.c:460
#12 0xffffffff8071ca4b in uhub_explore (udev=3D0xfffffe0006f2f000) at =
/local0/src/sys/dev/usb/usb_hub.c:524
#13 0xffffffff80707782 in usb_bus_explore (pm=3D<value optimized out>) =
at /local0/src/sys/dev/usb/controller/usb_controller.c:381
#14 0xffffffff80720403 in usb_process (arg=3D<value optimized out>) at =
/local0/src/sys/dev/usb/usb_process.c:169
#15 0xffffffff8086b4cd in fork_exit (callout=3D0xffffffff80720340 =
<usb_process>, arg=3D0xffffff80007e5db0, frame=3D0xffffff80f5d34c00) at =
/local0/src/sys/kern/kern_fork.c:996
#16 0xffffffff80c3acae in fork_trampoline () at =
/local0/src/sys/amd64/amd64/exception.S:606
#17 0x0000000000000000 in ?? ()

So I think usb_detach_device has grabbed the enum lock, but I'm not sure =
what sort of fix would be appropriate, any ideas?

Thanks.

--
Daniel O'Connor software and network engineer
for Genesis Software - http://www.gsoft.com.au
"The nice thing about standards is that there
are so many of them to choose from."
  -- Andrew Tanenbaum
GPG Fingerprint - 5596 B766 97C0 0E94 4347 295E E593 DC20 7B3F CE8C







--Apple-Mail=_E230DD3A-5B09-4F17-A638-593974F6F8F2
Content-Transfer-Encoding: 7bit
Content-Disposition: attachment;
	filename=signature.asc
Content-Type: application/pgp-signature;
	name=signature.asc
Content-Description: Message signed with OpenPGP using GPGMail

-----BEGIN PGP SIGNATURE-----
Comment: GPGTools - http://gpgtools.org

iD8DBQFTKnEq5ZPcIHs/zowRAnoyAJ94+B1XL0phdga1oIV0PNDshNZCuwCgo+t0
FplIWvpl4rBPARcFd/pMucs=
=mKDA
-----END PGP SIGNATURE-----

--Apple-Mail=_E230DD3A-5B09-4F17-A638-593974F6F8F2--



Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?084BCD21-ADE9-4E60-B637-99EEE1D26389>