usbconfig reset ugen4.2 hanging since an hour

Tue Nov 2 11:02:32 UTC 2010

Alexander Leidinger wrote:
> 
> Quoting Hans Petter Selasky <hselasky at freebsd.org> (from Tue, 2 Nov 2010
> 10:36:41 +0100):
> 
>> On Tuesday 02 November 2010 10:32:08 Alexander Leidinger wrote:
>>> Hi,
>>>
>>> I have a memory stick which made problems (the stick is used as a ZFS
>>> cache and it moaned about 8xxM write problems) in 9-current r214509. I
>>> removed the device from the config, made a camcontrol reset all,
>>> camcontrol rescan all (-> device disappeared), and then tried an
>>> usbconfig reset ugen4.2 (relevant devlist part from before the call is
>>> below). The usbconfig reset does not return to the shell.
>>>
>>> I do not know if the problem with the USB memory stick is related to
>>> software or hardware. The stick survived just a weekend, I replaced it
>>> because the old one showed similar problems after surviving about 9
>>> months... I updated -current just before the problems appeared (and
>>> then again after a week or two), but I do not remember from which
>>> revision of -current I was updating from. I will try to stress-test
>>> the memory sticks on a 8.1 system so see if it is some software problem.
>>>
>>> The big question I have for now is: shouldn't there be some kind of
>>> safety mechanism kicking in (timeout) with the usbconfig command (in
>>> this case the reset)?
>>>
>>> devlist:
>>> ---snip---
>>> ugen4.1: <EHCI root HUB Intel> at usbus4, cfg=0 md=HOST spd=HIGH
>>> (480Mbps) pwr=SAVE
>>> ugen4.2: <Flash Disk USB 2.0> at usbus4, cfg=0 md=HOST spd=HIGH
>>> (480Mbps) pwr=ON
>>> ---snip---
>>>
>>> dmesg | grep -i usb:
>>> ---snip---
>>> uhci0: <Intel 82801EB (ICH5) USB controller USB-A> port 0xdc00-0xdc1f
>>> irq 16 at device 29.0 on pci0
>>> usbus0: <Intel 82801EB (ICH5) USB controller USB-A> on uhci0
>>> uhci1: <Intel 82801EB (ICH5) USB controller USB-B> port 0xe000-0xe01f
>>> irq 19 at device 29.1 on pci0
>>> usbus1: <Intel 82801EB (ICH5) USB controller USB-B> on uhci1
>>> uhci2: <Intel 82801EB (ICH5) USB controller USB-C> port 0xe400-0xe41f
>>> irq 18 at device 29.2 on pci0
>>> usbus2: <Intel 82801EB (ICH5) USB controller USB-C> on uhci2
>>> uhci3: <Intel 82801EB (ICH5) USB controller USB-D> port 0xe800-0xe81f
>>> irq 16 at device 29.3 on pci0
>>> usbus3: <Intel 82801EB (ICH5) USB controller USB-D> on uhci3
>>> ehci0: <Intel 82801EB/R (ICH5) USB 2.0 controller> mem
>>> 0xfe77fc00-0xfe77ffff irq 23 at device 29.7 on pci0
>>> usbus4: EHCI version 1.0
>>> usbus4: <Intel 82801EB/R (ICH5) USB 2.0 controller> on ehci0
>>> usbus0: 12Mbps Full Speed USB v1.0
>>> usbus1: 12Mbps Full Speed USB v1.0
>>> usbus2: 12Mbps Full Speed USB v1.0
>>> usbus3: 12Mbps Full Speed USB v1.0
>>> usbus4: 480Mbps High Speed USB v2.0
>>> ugen0.1: <Intel> at usbus0
>>> uhub0: <Intel UHCI root HUB, class 9/0, rev 1.00/1.00, addr 1> on usbus0
>>> ugen1.1: <Intel> at usbus1
>>> uhub1: <Intel UHCI root HUB, class 9/0, rev 1.00/1.00, addr 1> on usbus1
>>> ugen2.1: <Intel> at usbus2
>>> uhub2: <Intel UHCI root HUB, class 9/0, rev 1.00/1.00, addr 1> on usbus2
>>> ugen3.1: <Intel> at usbus3
>>> uhub3: <Intel UHCI root HUB, class 9/0, rev 1.00/1.00, addr 1> on usbus3
>>> ugen4.1: <Intel> at usbus4
>>> uhub4: <Intel EHCI root HUB, class 9/0, rev 2.00/1.00, addr 1> on usbus4
>>> Root mount waiting for: usbus4
>>> Root mount waiting for: usbus4
>>> Root mount waiting for: usbus4
>>> Root mount waiting for: usbus4
>>> ugen4.2: <USB 2.0> at usbus4
>>> umass0: <USB 2.0 Flash Disk, class 0/0, rev 2.00/1.00, addr 2> on usbus4
>>> Root mount waiting for: usbus4
>>> pass3: <USB 2.0 Flash Disk 5.00> Removable Direct Access SCSI-2 device
>>> da0: <USB 2.0 Flash Disk 5.00> Removable Direct Access SCSI-2 device
>>> Root mount waiting for: usbus4
>>> ugen1.2: <vendor 0x1941> at usbus1
>>> ugen1.3: <vendor 0x04f9> at usbus1
>>> ulpt0: <vendor 0x04f9 product 0x0100, class 0/0, rev 1.00/1.00, addr
>>> 3> on usbus1
>>> ugen2.2: <Logitech> at usbus2
>>> uhub5: <Logitech Logitech BT Mini-Receiver, class 9/0, rev 2.00/49.00,
>>> addr 2> on usbus2
>>> ugen2.3: <Logitech> at usbus2
>>> ukbd0: <Logitech Logitech BT Mini-Receiver, class 0/0, rev 2.00/49.00,
>>> addr 3> on usbus2
>>> ugen2.4: <Logitech> at usbus2
>>> ums0: <Logitech Logitech BT Mini-Receiver, class 0/0, rev 2.00/49.00,
>>> addr 4> on usbus2
>>> ---snip---
>>
>> Hi,
>>
>> If you dump all threads in this state I think you will see that USB is
>> waiting
> 
> # procstat -kk 29213
>   PID    TID COMM             TDNAME           KSTACK
> 29213 100291 usbconfig        -                mi_switch+0x188
> sleepq_switch+0x13c sleepq_timedwait+0x40 _sleep+0x320 pause+0x30
> usb_pause_mtx+0x94 usb_ioctl+0x171 devfs_ioctl_f+0x73 kern_ioctl+0x9d
> ioctl+0xc5 syscallenter+0x1af syscall+0x34 Xint0x80_syscall+0x21
> 
>> somewhere in umass_detach(), which is preventing the usbconfig reset from
> 
> No umass_detach in there...

umass_detach() (if there) should be in some other thread.

>> grabbing the SX-lock associated with serialisation. Because
>> umass_detach() is
>> not returning we are stuck.
> 
> And there is no way to use some kind of timeout for cases which cause
> problem reports (like umass_detach() and maybe this one)? I could
> imagine several possibilities: usbconfig tries a trylock first (maybe
> several times) and if it does not succeed in a specified timeperiode, it
> returns an error. Adidtionally there is maybe the possibility to
> determine if a command did not finish in a given timeperiode and print
> out a warning message (syslog) to have an indication, that somthing is
> not in a good condition.

Not sure what should it give. We should track the real problem, not the
consequences. Possible reason could be that due to some error umass/CAM
leaked some references, which made impossible to destroy CAM bus on
stick disconnection. But to diagnose it we need much more info.

-- 
Alexander Motin