Ongoing battle with umass(4) and xhci(4)

[Brandon Gooch]

On Tue, Mar 13, 2012 at 1:22 AM, Hans Petter Selasky <hselasky at c2i.net> wrote:
> On Tuesday 13 March 2012 04:37:55 Brandon Gooch wrote:
>> On Mon, Mar 12, 2012 at 3:15 AM, Hans Petter Selasky <hselasky at c2i.net>
> wrote:
>> >> Is there something fishy happening between the USB stack and CAM?
>> >> hmmm...
>> >
>> > No,
>> >
>> > It is not the CAM layer this time, though there are some bugs there too.
>> >
>> >
>> > In the beginning of the log I see that in the successful case we receive
>> > a stall event:
>> >
>> > -xhci_check_transfer: slot=1 epno=3 remainder=13 status=6
>> > -xhci_check_transfer: TD is last
>> > -xhci_cmd_stop_ep:
>> > -xhci_check_command: Received command event
>> > -xhci_configure_reset_endpoint: Could not stop endpoint 3
>> > -xhci_cmd_reset_ep:
>> > -xhci_check_command: Received command event
>> > -xhci_cmd_set_tr_dequeue_ptr:
>> > -xhci_check_command: Received command event
>> > -xhci_cmd_evaluate_ctx:
>> > -xhci_check_command: Received command event
>> > -xhci_cmd_configure_ep:
>> > -xhci_check_command: Received command event
>> > -xhci_configure_reset_endpoint: Could not configure endpoint 3
>> > -xhci_ep_clear_stall:
>> > -xhci_device_generic_enter:
>> > -xhci_setup_generic_chain_sub: NTRB=1
>> > -xhci_setup_generic_chain_sub: LINK=0x82883180
>> > -xhci_setup_generic_chain_sub: NTRB=1
>> > -xhci_setup_generic_chain_sub: LINK=0x82883000
>> > -xhci_setup_generic_chain: first=0xffffff8460883300
>> > last=0xffffff8460883180 -xhci_device_generic_start:
>> > -xhci_transfer_insert: qh_pos = 1
>> > -xhci_check_transfer: slot=1 epno=1 remainder=0 status=1
>> > -xhci_check_transfer: slot=1 epno=1 remainder=0 status=1
>> > -xhci_check_transfer: Following next TD
>> > -xhci_check_transfer: slot=1 epno=1 remainder=0 status=1
>> > -xhci_check_transfer: slot=1 epno=1 remainder=0 status=1
>> > -xhci_check_transfer: TD is last
>> >
>> >
>> > This is not received in the failing case.
>> >
>> > Maybe this indicates a lost interrupt or something like that?
>> >
>> > In /sys/dev/usb/controller/xhci.c
>> >
>> > static void
>> > xhci_interrupt_poll(struct xhci_softc *sc)
>> >
>> > Add a printf:
>> >
>> >                if (i == XHCI_MAX_EVENTS) {
>> >                        i = 0;
>> >                        j ^= 1;
>> >
>> >                        /* check for timeout */
>> >                        if (!--t) {
>> >                                +                       printf("XHCI:
>> > Timeout\n"); break;
>> >                                }
>> >                }
>> >
>> >
>> > See if what happens.
>> >
>> > Also change the xhci.c code to call
>> >
>> > xhci_interrupt_poll() two times instead of one.
>> >
>> >
>> > --HPS
>>
>> Unfortunately, the condition was never reached.
>>
>> I've started trying to dtrace xhci(4) function boundaries, and, well
>> there's a lot of recursion with xhci_interrupt_poll().  However, I
>> never see that function called from xhci_do_poll(), which is called
>> from xhci_interrupt() (to "catch any lost interrupts" according to the
>> comment).
>>
>> You may have already told me this, but what does "Down reving Protocol
>> Version from 2 to 0?" in the success case on my system?  Is this the
>> USB protocol which is "down rev'ed"?  If so, what USB level is this
>> flash drive running at?
>
> Hi,
>
> The XHCI supports all the wire USB protocols up to date. Is that what you ask?
>
> --HPS

I'm curious what the "down reving" means, and whether it is a USB
thing or something else.

I wonder if it could be a clue to help figure out the actual issue I'm facing.

Also, the missing interrupt notion has come into play before while
trying to investigate this in the past -- if you could come up with a
method that could eliminate that as a cause altogether, I think it
would a big step.  Of course, a method to show that missing interrupts
are absolutely the problem, that would be great too :)

-Brandon