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

On 2007/8/23, Alan Stern <[email protected]> wrote:
> 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!

Interesting - I did note that "HALT" message. However, it does not
crash always, but it always disconnects the stick.

I'm attaching separately the logs from a testing session where it
crash at first - I plug the card, try using it and get a disconnection
of the card, unplug and replug it, the hub crashes, I disconnect it,
then I remove and reload the DVB-USB modules (it kept sending message
for status request, i.e. 84 and/or 81), and the controller was working
again (without unbind/bind).

I should have added which is the USB controller. To my surprise, it
seem this board is using a standard VIA controller. And the controller
in the original mail was from VIA too (with the same chip!). Btw, this
is an old revision of this controller - do you think it is worth
looking for an errata datasheet? (I've seen revision 80-82 on this and
other webpages http://kerneltrap.org/node/5500#comment-130854, while
the one I have is 61-63).

And since this is a common controller, do you think this problem is
somehow workaroundable, or at least worth investigating more? Because
it is not totally broken - it usually works.

>From this thread I've seen that they have in practice a single USB hub
chip which they evolve, and that they do not release errata any more;
but they also give technical answers (and there is a forum for Linux
support), so I wonder if it is worth contacting them.

http://forums.viaarena.com/messageview.aspx?catid=16&threadid=73502&enterthread=y

Also, I wonder (as a wild guess) if the PCI bus busmaster feature
supports "bus parking" or not - that thread mentions this requirement
and "park" often appears in log messages.

This is the lspci output:

# lspci -v -s 00:01
00:01.0 USB Controller: VIA Technologies, Inc. VT82xxxxx UHCI USB 1.1
Controller (rev 61) (prog-if 00 [UHCI])
        Subsystem: VIA Technologies, Inc. VT82xxxxx UHCI USB 1.1 Controller
        Flags: bus master, medium devsel, latency 22, IRQ 26
        I/O ports at 2000 [size=32]
        Capabilities: [80] Power Management version 2

00:01.1 USB Controller: VIA Technologies, Inc. VT82xxxxx UHCI USB 1.1
Controller (rev 61) (prog-if 00 [UHCI])
        Subsystem: VIA Technologies, Inc. VT82xxxxx UHCI USB 1.1 Controller
        Flags: bus master, medium devsel, latency 22, IRQ 27
        I/O ports at 2020 [size=32]
        Capabilities: [80] Power Management version 2

00:01.2 USB Controller: VIA Technologies, Inc. USB 2.0 (rev 63)
(prog-if 20 [EHCI])
        Subsystem: VIA Technologies, Inc. USB 2.0
        Flags: bus master, medium devsel, latency 22, IRQ 28
        Memory at 08042000 (32-bit, non-prefetchable) [size=256]
        Capabilities: [80] Power Management version 2

> > 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?

Yes, indeed. I've connected my external HD and they happen, too. And
anyway, they happen even long before the problem; the status also goes
back to 0 at times, and I've been reading my HD content. For instance,
while doing this:

# time cat /local_storage/media/usb-a2/kubuntu_7_04_dvd_amd64.iso > /dev/null

(that is a 4GB file), this is an excerpt of the kernel output (note
the three "Start ASS: 0" out of many more "Start ASS: 8000").

[24394.245322] Start ASS: 8000
[24394.885947] End ASS: 8000
[24396.309774] Start ASS: 0
[24396.501180] End ASS: 8000
[24443.204281] Start ASS: 8000
[24443.838070] End ASS: 8000
[24505.246242] Start ASS: 8000
[24505.259914] End ASS: 8000
[24545.246221] Start ASS: 8000
[24545.264776] End ASS: 8000
[24595.766703] Start ASS: 8000
[24596.392680] End ASS: 8000
[24610.926852] Start ASS: 8000
[24611.751070] End ASS: 8000
[24611.842867] Start ASS: 8000
[24611.880953] End ASS: 8000
[24611.972750] Start ASS: 8000
[24612.402437] End ASS: 8000
[24613.584077] Start ASS: 8000
[24613.906342] End ASS: 8000
[24615.006928] Start ASS: 8000
[24615.439545] End ASS: 8000
[24616.625091] Start ASS: 8000
[24616.990325] End ASS: 8000
[24617.079192] Start ASS: 8000
[24617.529388] End ASS: 8000
[24618.510832] Start ASS: 8000
[24624.578212] End ASS: 8000
[24624.664149] Start ASS: 8000
[24626.914148] End ASS: 8000
[24627.005945] Start ASS: 0
[24629.609459] End ASS: 8000
[24629.695397] Start ASS: 0

So that is not enough to cause the root problem. Note however that
during the execution only Bulk transfers are used, while the DVBT case
mixes more transfer types.

In fact, the following command line does not print anything at all
while reading from the HD, while when removing the "grep -v B" part it
fills up the screen immediately (that sed command extracts the "URB
type and direction" field of usbmon output).

# cat /sys/kernel/debug/usbmon/1t|sed -e 's/^.*\([BZIC][io]\).*$/\1/'|grep -v B

I have the full kernel logs (saved by syslogd) - I can send all of
them to you, but you'd be missing the context of what I was doing, so
it'd be more complex to decode them. Choose what you prefer to get.

> > 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.

Yep, but it is "triggered" by something in the communication (say, it
work perfectly until you try to do X transfers with certain params,
say interrupt transfers with x, y and z). Because it works otherwise
(see above with the HD).

> > [ 5385.991382] usb 1-2: USB disconnect, address 3
[...]

> > 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?

I'll retest current version and open this bug report.

> 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.

Thanks, it works (I forgot the -n at the beginning and it didn't tell
anything on dmesg).

It seems to work again, in fact:

# cat /sys/class/usb_host/usb_host1/registers
bus pci, device 0000:00:01.2 (driver 10 Dec 2004)
EHCI Host Controller
EHCI 1.00, hcd state 1
ownership 00000001
SMI sts/enable 0xc0080000
structural params 0x00002204
capability params 0x00006872
status 0008 FLR
command 010009 (park)=0 ithresh=1 period=256 RUN
intrenable 37 IAA FATAL PCD ERR INT
uframe 0e2a
port 1 status 001000 POWER sig=se0
port 2 status 001000 POWER sig=se0
port 3 status 001000 POWER sig=se0
port 4 status 001000 POWER sig=se0
irq normal 0 err 0 reclaim 0 (lost 0)
complete 0 unlink 0

After resurrecting the controller by
rmmod dvb-usb-dtt200u
rmmod dvb-usb
and reloading them, I have instead (note the "lost" field):

# cat /sys/class/usb_host/usb_host1/registers
bus pci, device 0000:00:01.2 (driver 10 Dec 2004)
EHCI Host Controller
EHCI 1.00, hcd state 1
ownership 00000001
SMI sts/enable 0xc0080000
structural params 0x00002204
capability params 0x00006872
status 8008 Async FLR
command 010009 (park)=0 ithresh=1 period=256 RUN
intrenable 37 IAA FATAL PCD ERR INT
uframe 2cac
port 1 status 001000 POWER sig=se0
port 2 status 001000 POWER sig=se0
port 3 status 001000 POWER sig=se0
port 4 status 001000 POWER sig=se0
irq normal 550418 err 13 reclaim 2079 (lost 1403)
complete 4361 unlink 398

I afterwards plugged my HD and read the content of this file multiple
times - the result is saved in the tarball, in
logs-24-Aug/registers-dumps-during-HD-hotplug.txt .

> 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.

We'll see. Thanks for the prompt answer, hope you can suggest
something with these additional infos.
-- 
Paolo 'Blaisorblade' Giarrusso

-------------------------------------------------------------------------
This SF.net email is sponsored by: Splunk Inc.
Still grepping through log files to find problems?  Stop.
Now Search log events and configuration files using AJAX and a browser.
Download your FREE copy of Splunk now >>  http://get.splunk.com/

_______________________________________________
[email protected]
To unsubscribe, use the last form field at:
https://lists.sourceforge.net/lists/listinfo/linux-usb-devel