On Mon, Jun 01, 2020 at 08:46:32AM +0000, Mikolaj Kucharski wrote: > On Sat, Apr 18, 2020 at 02:01:14PM +0200, Patrick Wildt wrote: > > On Tue, Apr 14, 2020 at 06:42:53PM +0000, Mikolaj Kucharski wrote: > > > On Tue, Apr 14, 2020 at 11:06:00AM +0200, Patrick Wildt wrote: > > > > On Mon, Apr 13, 2020 at 09:36:04PM +0200, Mark Kettenis wrote: > > > > > Can you print the status (full 32 bits) of that particular QTD? > > > > > > > > Yeah, I wish I could see the status field for each sqtd in that > > > > chain. > > > > > > XXX #1# ehci_idone: len=4 actlen=4294951308, xf_actlen=0, status=0x8d00, > > > sqtd_count=3 > > > XXX #2# ehci_idone: x_actlen=4294951304, sqtd_len=8, ehci_qtd_len=16000, > > > status=0xbe808d00, qtd_status=0xbe808d00, sqtd_count=1 > > > XXX #2# ehci_idone: x_actlen=4294951308, sqtd_len=4, ehci_qtd_len=0, > > > status=0xc00, qtd_status=0xc00, sqtd_count=2 > > > XXX #2# ehci_idone: x_actlen=4294951308, sqtd_len=0, ehci_qtd_len=0, > > > status=0x8d00, qtd_status=0x8d00, sqtd_count=3 > > > panic: _dmamap_sync: ran off map! > > > > Thanks for the information! I'll try and see if I can find what's > > happening. But yeah, that's good information. This is a control > > transfers, which has 3 transfer descriptors. > > > > The three TDs should be: SETUP, DATA (because of len=4), and STATUS. > > > > As you can see, the middle one, DATA, has a len of 4, and the BYTES > > field in the status is 0, indicating that the transfer completed. > > > > Then we have STATUS, which has no len, looks just fine as well. > > > > But the first one, the SETUP, is weird. The len is fine, 8 bytes, > > but ehci_qtd_len looks completely off, the BYTES field also says > > "lots of bytes remaining". This is where we fuck up, I suppose. > > > > What's weird is that we actually account it, because we have this > > check: > > > > if (EHCI_QTD_GET_PID(status) != EHCI_QTD_PID_SETUP) > > actlen += sqtd->len - EHCI_QTD_GET_BYTES(status); > > > > But it looks like the status field on the SETUP descriptor does > > not say PID_SETUP, but PID_IN. Did the DMA controller change the > > bit? Or did someone else overwrite it? > > > > Patrick > > I'm kinda stuck with this. I added KASSERT()s in places where I think > condtions should be checked and otherwise kernel should panic. Obviously > as I can trigger bogus condition I ended up with following ddb trace: > > urtwn0: SCAN -> INIT > XXX S1 ehci_idone: actlen=4, sqtd_len=0, ehci_qtd_len=16000, status=0x3e808d00 > XXX S2 ehci_idone: actlen=-15996, sqtd_len=0, ehci_qtd_len=16000, > status=0x3e808d00 > panic: kernel diagnostic assertion "sqtd_len >= ehci_qtd_len" failed: file > "/home/mkucharski/src/sys/dev/usb/ehci.c", line 915 > ... > db_enter() at panic+0x14c > panic() at ehci_idone+0x264 > ehci_isoc_idone() at ehci_softintr+0x158 > ehci_softintr() at softintr_biglock_wrap+0x1c > softintr_biglock_wrap() at softintr_dispatch+0x9c > softintr_dispatch() at arm_do_pending_intr+0xa8 > arm_do_pending_intr() at ampintc_irq_handler+0x178 > > This is retyped by hand from a glass console, be aware of typos. > > I don't understand why ehci_idone() goes to ehci_isoc_idone() in above > ddb trace output.
Hi, I haven't gotten to it yet, but mpi@ said we should try to rely less on the hardware. I think an idea would be to store in each sqtd whether or not it carries data (that needs to be counted). So then you only read the actlen from the SQTD if it actually is supposed to carry data. This way we don't even try to read a length from anything else, like STATUS. Patrick
