Re: new mail: USB controller problem on MIPSEL embedded board

On Thu, 23 Aug 2007, Paolo Giarrusso wrote:

> I'm trying to get working a Freecom DVB-T USB stick (ID 14aa:0225) on
> an embedded MIPS board; it works with an x86 PC, and I've tested it on
> more MIPS boards and even with other DVB-T sticks, while most other
> peripherals are ok. I initially thought of portability problems in the
> driver, but after some analysis (I'm not an USB expert but I'm
> comfortable with kernel sources) and reading this thread (on this ML):
> 
> http://www.spinics.net/lists/usb/msg07868.html
> 
> it seems a problem in the USB controller. Can somebody please help me
> with solving this problem?
> 
> == STEPS TO REPRODUCE ==
> 
> I plug the stick, load the firmware, run the scan (or dvbscan)
> utility, and the stick is abruptly disconnected by the controller (see
> below) after the DVBT driver sends a certain command (for reference,

The stick gets disconnected because the EHCI host controller has 
crashed!

> the driver is drivers/media/dvb/dvb-usb/dvb-usb-dtt200u.ko). I think
> this command requires the stick to something "unusual", because most
> other USB devices work fine (both high speed and low speed devices do
> work, while both high speed and low speed DVBT sticks do not).

When using those other high-speed USB devices, do you still get the 
"Start ASS: 8000" messages?

> I've applied the patch in that mail to a 2.6.22.4 kernel (it applied
> fine); it did not solve the problem, and moreover I see various
> instances of "Start ASS: 8000" (and I was using 2050 as timeout, not
> 500 as suggested by subsequent email !). So I fear an hardware problem
> is involved, but I hope it is possible to workaround it.
> 
> == LOGS ==
> Some logs are attached, I can give you any detail you want (I read
> that thread so most things are already included).
> 
> First, an excerpt of dmesg without USB debugging (with only some DVBT
> debugging parameters enabled).
> The '>>>' lines are commands sent to the USB stick by the DVBT driver
> (see functions drivers/media/dvb/dvb-usb/dvb-usb-urb.c:dvb_usb_generic_write,dvb_usb_generic_rw).
> 
> [ 5385.970875] function : dvb_dmxdev_filter_set
> [ 5385.971851] start pid: 0x0000, feedtype: 1
> [ 5385.972828] setting pid (yes):     0 0000 at index 0 'on'
> 
> [ 5385.973804] >>> 04 00 00 00
> This is caused by drivers/media/dvb/dvb-usb/dtt200u.c:dtt200u_pid_filter().
> 
> [ 5385.979664] submitting all URBs
> [ 5385.980640] submitting URB no. 0
> [ 5385.981617] submitting URB no. 1
> [ 5385.982593] submitting URB no. 2
> [ 5385.983570] submitting URB no. 3
> [ 5385.984547] submitting URB no. 4
> [ 5385.985523] submitting URB no. 5
> [ 5385.986500] submitting URB no. 6
> [ 5385.987476] controlling pid parser
> [ 5385.988453] start feeding
> [ 5385.989429] >>> 08 01
> 
> This is caused by dtt200u_streaming_ctrl(). Every time I test this,
> this is the last command sent before disconnection. I'm curious about
> why this command causes problems - what unusual feature of the USB
> standard is the pen now going to use?

It has nothing to do with the stick.  The problem is in the controller.

> [ 5385.991382] usb 1-2: USB disconnect, address 3
> 
> Below there is an excerpt of dmesg around the disconnection. You can
> note the "Start ASS: 8000" (which is abnormal) in the output. '>> 08
> 01' is missing, but I bet it is a problem of busybox syslogd, since it
> is still shown in usbmon output.
> 
> [  582.762396] >>> 81
> //81 is drivers/media/dvb/dvb-usb/dtt200u.h:GET_TUNE_STATUS, which is
> sent periodically during the tuning.
> [  582.763373] Start ASS: 8000
> [  582.764350] <<< 01 c8 0a
> [  582.778998] End ASS: 8000
> [  582.787787] >>> 81
> [  582.788764] Start ASS: 8000
> [  582.789740] <<< 01 c8 0a
> [  582.792670] >>> 81
> [  582.800482] function : dvb_dmxdev_filter_set
> [  582.801459] >>> 04 00 00 00
> //The command sent by dtt200u_pid_filter()
> // >> 08 01 is lost here
> [  582.817084] ehci_hcd 0000:00:01.2: fatal command 010038 (park)=0
> ithresh=1 Async Periodic period=256 HALT

At this point the controller has died.

> [  582.817084] ehci_hcd 0000:00:01.2: fatal status e008 Async Periodic Recl FLR
> [  582.817084] hub 1-0:1.0: state 7 ports 4 chg 0000 evt 0004
> [  582.817084] ehci_hcd 0000:00:01.2: GetStatus port 2 status 00100a
> POWER sig=se0 PEC CSC
> [  582.817084] hub 1-0:1.0: port 2, status 0100, change 0003, 12 Mb/s
> [  582.817084] usb 1-2: USB disconnect, address 8

And here is where the disconnect appears.

> [  582.818060] usb 1-2: unregistering device
> [  582.818060] usb 1-2: usb_disable_device nuking all URBs
> [  582.818060] usb 1-2: unlink qh64-0001/a11f7200 start 63 [2/0 us]
> [  582.818060] ehci_hcd 0000:00:01.2: shutdown urb 80941780 pipe
> 40410880 ep2in-intr
> [  582.818060] ehci_hcd 0000:00:01.2: shutdown urb 80941c80 pipe
> c0030880 ep6in-bulk
> [  582.818060] ehci_hcd 0000:00:01.2: shutdown urb 80941880 pipe
> c0030880 ep6in-bulk
> [  582.818060] ehci_hcd 0000:00:01.2: shutdown urb 80941d00 pipe
> c0030880 ep6in-bulk
> [  582.818060] ehci_hcd 0000:00:01.2: shutdown urb 80941300 pipe
> c0030880 ep6in-bulk
> [  582.818060] ehci_hcd 0000:00:01.2: shutdown urb 80941380 pipe
> c0030880 ep6in-bulk
> [  582.818060] ehci_hcd 0000:00:01.2: shutdown urb 80941400 pipe
> c0030880 ep6in-bulk
> [  582.818060] ehci_hcd 0000:00:01.2: shutdown urb 80941600 pipe
> c0030880 ep6in-bulk
> [  582.818060] usb 1-2: unregistering interface 1-2:1.0
> [  582.826850] function : dvb_dmxdev_filter_set
> [  582.827826] End ASS: 8000

> in this status, I cannot connect any high-speed device to any USB
> port, while I can connect low-speed devices (a USB mouse was
> successfully recognized).
> It is the first time I see this, all other times I could unplug the
> stick and retest it; unfortunately, the ehci driver is statically
> linked in the kernel so I cannot retest unloading and reloading the
> kernel module (I've hit oops in the past with ehci_hcd as a module
> when using usbmon, with a 2.6.20 kernel).

Did you file a bug report about those oopses?

You can unbind ehci-hcd from the controller and then rebind it by 
doing:

	cd /sys/bus/pci/drivers/ehci_hcd
	echo -n ... >unbind
	echo -n ... >bind

where you have to fill in the ... with the filename of the controller 
as it appears in that directory.  The effect will be the same as if you 
had unloaded and reloaded the ehci-hcd module.

In the end I'm not sure what you can do.  The "Start ASS: 8000" message
means that the driver has told the controller to turn part of its
circuitry off but the controller says it hasn't done so (even after
more than 2050 us).  Under these circumstances it's not surprising the
controller should encounter errors and crash.

Alan Stern