From owner-freebsd-usb@FreeBSD.ORG Thu Mar 20 04:40:44 2014 Return-Path: Delivered-To: freebsd-usb@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2001:1900:2254:206a::19:1]) (using TLSv1 with cipher ADH-AES256-SHA (256/256 bits)) (No client certificate requested) by hub.freebsd.org (Postfix) with ESMTPS id 3EF225B9 for ; Thu, 20 Mar 2014 04:40:44 +0000 (UTC) Received: from cain.gsoft.com.au (cain.gsoft.com.au [203.31.81.10]) (using TLSv1 with cipher DHE-RSA-AES256-SHA (256/256 bits)) (No client certificate requested) by mx1.freebsd.org (Postfix) with ESMTPS id 61487DBA for ; Thu, 20 Mar 2014 04:40:42 +0000 (UTC) Received: from ur.gsoft.com.au (Ur.gsoft.com.au [203.31.81.34]) (authenticated bits=0) by cain.gsoft.com.au (8.14.4/8.14.3) with ESMTP id s2K4eB54093417 (version=TLSv1/SSLv3 cipher=AES128-SHA bits=128 verify=NO); Thu, 20 Mar 2014 15:10:18 +1030 (CST) (envelope-from doconnor@gsoft.com.au) Subject: Re: USB config SX lock deadlock Mime-Version: 1.0 (Mac OS X Mail 7.2 \(1874\)) Content-Type: multipart/signed; boundary="Apple-Mail=_E230DD3A-5B09-4F17-A638-593974F6F8F2"; protocol="application/pgp-signature"; micalg=pgp-sha1 From: "Daniel O'Connor" In-Reply-To: <52565BB1.8070506@bitfrost.no> Date: Thu, 20 Mar 2014 15:10:10 +1030 Message-Id: <084BCD21-ADE9-4E60-B637-99EEE1D26389@gsoft.com.au> References: <9783900F-08A1-41FB-81B8-3C9809B82521@gsoft.com.au> <52553000.2010003@bitfrost.no> <52554855.6030404@bitfrost.no> <52564953.8080707@bitfrost.no> <7610BC59-ED91-4807-B145-7F7DD2C725E9@gsoft.com.au> <52565BB1.8070506@bitfrost.no> To: Hans Petter Selasky X-Mailer: Apple Mail (2.1874) X-Spam-Score: -2.51 () ALL_TRUSTED,BAYES_00,T_RP_MATCHES_RCVD X-Scanned-By: MIMEDefang 2.67 on 203.31.81.10 Cc: freebsd-usb@freebsd.org X-BeenThere: freebsd-usb@freebsd.org X-Mailman-Version: 2.1.17 Precedence: list List-Id: FreeBSD support for USB List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Thu, 20 Mar 2014 04:40:44 -0000 --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 wrote: > On 10/10/13 09:38, Daniel O'Connor wrote: >>=20 >> On 10/10/2013, at 16:59, Hans Petter Selasky 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) 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, file=3D, line=3D) 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, = cmd=3D3222040644, data=3D0xfffffe011fab8270, fflags=3D) at ugsio.c:1038 #8 0xffffffff8070f932 in usb_ioctl (dev=3D, = cmd=3D3222040644, addr=3D0xfffffe011fab8270 "\001", fflag=3D, td=3D) at /local0/src/sys/dev/usb/usb_dev.c:1075 #9 0xffffffff8078f01a in devfs_ioctl_f (fp=3D0xfffffe0008f21be0, = com=3D3222040644, data=3D, cred=3D, 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) at /local0/src/sys/kern/sched_ule.c:1904 #0 sched_switch (td=3D0xfffffe0004e75490, newtd=3D0xfffffe0002953000, = flags=3D) 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) 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) at = /local0/src/sys/dev/usb/usb_device.c:1050 #9 0xffffffff80713a7c in usb_unconfigure (udev=3D0xfffffe011faed000, = flag=3D) 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) = at /local0/src/sys/dev/usb/controller/usb_controller.c:381 #14 0xffffffff80720403 in usb_process (arg=3D) at = /local0/src/sys/dev/usb/usb_process.c:169 #15 0xffffffff8086b4cd in fork_exit (callout=3D0xffffffff80720340 = , 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--