From owner-freebsd-stable@FreeBSD.ORG Thu Oct 11 11:15:57 2012 Return-Path: Delivered-To: freebsd-stable@freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [69.147.83.52]) by hub.freebsd.org (Postfix) with ESMTP id ECB4F83C; Thu, 11 Oct 2012 11:15:57 +0000 (UTC) (envelope-from Benjamin.Close@clearchain.com) Received: from mail.clearchain.com (leo.clearchain.com [199.73.29.74]) by mx1.freebsd.org (Postfix) with ESMTP id AEEE68FC16; Thu, 11 Oct 2012 11:15:57 +0000 (UTC) Received: from Lynx.local (203-219-57-136.tpgi.com.au [203.219.57.136]) (authenticated bits=0) by mail.clearchain.com (8.14.5/8.14.5) with ESMTP id q9BB11nm055165 (version=TLSv1/SSLv3 cipher=DHE-RSA-CAMELLIA256-SHA bits=256 verify=NO); Thu, 11 Oct 2012 21:31:10 +1030 (CST) (envelope-from Benjamin.Close@clearchain.com) Message-ID: <5076A740.2090203@clearchain.com> Date: Thu, 11 Oct 2012 21:32:24 +1030 From: Benjamin Close User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.7; rv:15.0) Gecko/20120907 Thunderbird/15.0.1 MIME-Version: 1.0 To: "Kenneth D. Merry" Subject: Re: usb port issue in 9.1-Prerelease (Possibly Cam related) References: <504DED78.2010203@clearchain.com> <20121008153546.GA7850@nargothrond.kdm.org> In-Reply-To: <20121008153546.GA7850@nargothrond.kdm.org> Content-Type: text/plain; charset=ISO-8859-1; format=flowed Content-Transfer-Encoding: 7bit X-Greylist: Sender succeeded SMTP AUTH, not delayed by milter-greylist-4.0.1 (mail.clearchain.com [199.73.29.74]); Thu, 11 Oct 2012 21:31:13 +1030 (CST) Cc: freebsd-stable@freebsd.org X-BeenThere: freebsd-stable@freebsd.org X-Mailman-Version: 2.1.14 Precedence: list List-Id: Production branch of FreeBSD source code List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Thu, 11 Oct 2012 11:15:58 -0000 On 9/10/12 2:05 AM, Kenneth D. Merry wrote: > On Mon, Sep 10, 2012 at 23:09:04 +0930, Benjamin Close wrote: >> Hi Folks, >> I've facing an intermittent hang with a USB port which seems cam >> related: >> >> Event's that happen are: >> >> o USB modem (HUAWEI E220) plugged into PC >> >> ugen3.2: at usbus3 >> u3g0: <3G Modem> on usbus3 >> u3g0: Found 3 ports. >> umass0: on usbus3 >> umass0: SCSI over Bulk-Only; quirks = 0x0000 >> umass0:6:0:-1: Attached to scbus6 >> umass1: on usbus3 >> umass1: SCSI over Bulk-Only; quirks = 0x0000 >> umass1:7:1:-1: Attached to scbus7 >> cd1 at umass-sim0 bus 0 scbus6 target 0 lun 0 >> cd1: Removable CD-ROM SCSI-2 device >> cd1: 1.000MB/s transfers >> cd1: Attempt to query device size failed: NOT READY, Medium not present >> da0 at umass-sim1 bus 1 scbus7 target 0 lun 0 >> da0: Removable Direct Access SCSI-2 device >> da0: 1.000MB/s transfers >> da0: Attempt to query device size failed: NOT READY, Medium not present >> >> >> o Time Elapses....many packets passed, no da0 or cd1 used. >> >> >> o USB Modem drops off the bus >> (It does this occasionally as it resets itself) >> >> o Causes USB bus to lose devices >> >> ugen3.2: at usbus3 (disconnected) >> u3g0: at uhub3, port 1, addr 2 (disconnected) >> (cd1:umass-sim0:0:0:0): lost device, 1 refs >> (cd1:umass-sim0:0:0:0): removing device entry >> (pass4:umass-sim0:0:0:0): passdevgonecb: devfs entry is gone >> (da0:umass-sim1:1:0:0): lost device - 0 outstanding, 1 refs >> (da0:umass-sim1:1:0:0): removing device entry >> (pass5:umass-sim1:1:0:0): passdevgonecb: devfs entry is gone >> umass0: at uhub3, port 1, addr 2 (disconnected) >> >> >> At this point that particular USB port is effectively useless. Plugging >> anything into the ports shows no device showing up. >> >> Running usbconfig hangs with: >> >> PID TID COMM TDNAME KSTACK >> 48562 101874 usbconfig - mi_switch+0x186 >> sleepq_wait+0x42 _sx_xlock_hard+0x426 usbd_enum_lock+0xac >> usb_ref_device+0x21c usb_open+0xc7 devfs_open+0x197 vn_open_cred+0x2ff >> kern_openat+0x20a amd64_syscall+0x540 Xfast_syscall+0xf7 >> >> Controller is: >> >> uhci0@pci0:0:26:0: class=0x0c0300 card=0x02091028 chip=0x28348086 >> rev=0x02 hdr=0x00 >> vendor = 'Intel Corporation' >> device = '82801H (ICH8 Family) USB UHCI Controller' >> class = serial bus >> subclass = USB >> uhci1@pci0:0:26:1: class=0x0c0300 card=0x02091028 chip=0x28358086 >> rev=0x02 hdr=0x00 >> vendor = 'Intel Corporation' >> device = '82801H (ICH8 Family) USB UHCI Controller' >> class = serial bus >> subclass = USB >> ehci0@pci0:0:26:7: class=0x0c0320 card=0x02091028 chip=0x283a8086 >> rev=0x02 hdr=0x00 >> vendor = 'Intel Corporation' >> device = '82801H (ICH8 Family) USB2 EHCI Controller' >> class = serial bus >> subclass = USB >> >> It does however seem related to cam as looking at the various threads >> for the usb hub I find: >> >> (kgdb) bt >> #0 sched_switch (td=0xfffffe0002650000, newtd=0xfffffe000227f000, >> flags=Variable "flags" is not available. >> ) at /usr/src/sys/kern/sched_ule.c:1927 >> #1 0xffffffff808f34c6 in mi_switch (flags=260, newtd=0x0) at >> /usr/src/sys/kern/kern_synch.c:485 >> #2 0xffffffff8092bfd2 in sleepq_wait (wchan=0xfffffe001ec2a900, pri=92) >> at /usr/src/sys/kern/subr_sleepqueue.c:623 >> #3 0xffffffff808f3c69 in _sleep (ident=0xfffffe001ec2a900, >> lock=0xfffffe00371e9210, priority=Variable "priority" is not available. >> ) at /usr/src/sys/kern/kern_synch.c:250 >> #4 0xffffffff802bea02 in cam_sim_free (sim=0xfffffe001ec2a900, >> free_devq=1) at /usr/src/sys/cam/cam_sim.c:112 >> #5 0xffffffff8074f8ba in umass_detach (dev=Variable "dev" is not available. >> ) at /usr/src/sys/dev/usb/storage/umass.c:2183 >> #6 0xffffffff8091a054 in device_detach (dev=0xfffffe001ec2e900) at >> device_if.h:214 >> #7 0xffffffff8075c458 in usb_detach_device (udev=0xfffffe0007ce8800, >> iface_index=32 ' ', flag=Variable "flag" is not available. >> ) at /usr/src/sys/dev/usb/usb_device.c:1065 >> #8 0xffffffff8075c5f4 in usb_unconfigure (udev=0xfffffe0007ce8800, >> flag=Variable "flag" is not available. >> ) at /usr/src/sys/dev/usb/usb_device.c:455 >> #9 0xffffffff8075c88e in usb_free_device (udev=0xfffffe0007ce8800, >> flag=Variable "flag" is not available. >> ) at /usr/src/sys/dev/usb/usb_device.c:2093 >> #10 0xffffffff80764e5e in uhub_explore (udev=0xfffffe0007353800) at >> /usr/src/sys/dev/usb/usb_hub.c:358 >> #11 0xffffffff8074f536 in usb_bus_explore (pm=Variable "pm" is not >> available. >> ) at /usr/src/sys/dev/usb/controller/usb_controller.c:359 >> #12 0xffffffff80769173 in usb_process (arg=Variable "arg" is not available. >> ) at /usr/src/sys/dev/usb/usb_process.c:170 >> #13 0xffffffff808bc2df in fork_exit (callout=0xffffffff807690a0 >> , arg=0xffffff80007c0e88, frame=0xffffff804743cc40) at >> /usr/src/sys/kern/kern_fork.c:992 >> #14 0xffffffff80bc216e in fork_trampoline () at >> /usr/src/sys/amd64/amd64/exception.S:602 >> >> >> From: cam_sim_free(struct cam_sim *sim, int free_devq) >> >> (kgdb) l >> 107 { >> 108 int error; >> 109 >> 110 sim->refcount--; >> 111 if (sim->refcount > 0) { >> >> 112 error = msleep(sim, sim->mtx, PRIBIO, "simfree", 0); >> >> 113 KASSERT(error == 0, ("invalid error value for >> msleep(9)")); >> 114 } >> 115 >> 116 KASSERT(sim->refcount == 0, ("sim->refcount == 0")); >> >> >> It almost appears as if the cam layer is trying to finalise a write of >> some sort but the physical device has already gone. >> >> (kgdb) p sim->refcount >> $1 = 1 >> >> Not sure why refcount is still ==1. >> >> The same device in a box running 9.0-Stable (as of about 3 months ago) >> with a ICH9 controller works as expected. >> >> Any suggestions? > Do you happen to have 'camcontrol devlist -v' output for the above > scenario? > > I have attached a patch for the pass(4) driver that might help things > somewhat. The pass(4) driver won't go away completely if there is a > context that has the driver open when the underlying device goes away. > > That might be what is holding up the SIM refcount, although I'm not > certain. > > Ken It took a while before it failed but output is below for when a failure occurs. scbus0 on siisch0 bus 0: at scbus0 target 0 lun 0 (pass0,ada0) <> at scbus0 target -1 lun -1 () scbus1 on siisch1 bus 0: at scbus1 target 0 lun 0 (pass1,ada1) <> at scbus1 target -1 lun -1 () scbus2 on ata0 bus 0: at scbus2 target 0 lun 0 (pass2,cd0) <> at scbus2 target -1 lun -1 () scbus3 on ahcich0 bus 0: at scbus3 target 0 lun 0 (pass3,ada2) <> at scbus3 target -1 lun -1 () scbus4 on ahcich2 bus 0: <> at scbus4 target -1 lun -1 () scbus5 on ctl2cam0 bus 0: <> at scbus5 target -1 lun -1 () scbus6 on umass-sim0 bus 0: at scbus6 target 0 lun 0 (pass4) scbus7 on umass-sim1 bus 1: at scbus7 target 0 lun 0 (da0,pass5) scbus-1 on xpt0 bus 0: <> at scbus-1 target -1 lun -1 (xpt0) Difference from normal is: root@taurus:~/work/temp $BUILD_ENV$GITBRANCH| diff -u working.log failed.log --- working.log 2012-10-11 09:16:53.782748589 +1030 +++ failed.log 2012-10-11 09:11:58.923409082 +1030 @@ -15,7 +15,7 @@ scbus5 on ctl2cam0 bus 0: <> at scbus5 target -1 lun -1 () scbus6 on umass-sim0 bus 0: - at scbus6 target 0 lun 0 (cd1,pass4) + at scbus6 target 0 lun 0 (pass4) scbus7 on umass-sim1 bus 1: at scbus7 target 0 lun 0 (da0,pass5) scbus-1 on xpt0 bus 0: I do wonder if http://lists.freebsd.org/pipermail/svn-src-head/2012-September/040561.html could also relate to the problem. I'll apply the patch and let you know the results. Cheers, Benjamin