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
> Above are my debug lines in dmesg generated just before panic.
>
> The code which prints those lines is below. It's similar for-loop to
> what is currently in CVS in ehci_idone() function. I'm doing this
> for-loop twice. First version of for-loop is executed as is in CVS
> and record condition that panic will happen, then below for-loop is
> executed again with more debug output, otherwise printf() will slow
> the code path so mutch that I will not be able to trigger error
> condition.
>
> With below code (lines from 1 to 29) I already know panic condition is
> met and I'm executing code with printf()s added.
>
> sqtd_count=3 means that for-loop from line 6 to 28 was executed 3 times.
>
> XXX #1# ehci_idone: len=4 actlen=4294951308, xf_actlen=0, status=0x8d00,
> sqtd_count=3
>
> Above message is from line 2 of the code listed below.
>
> Then we enter the for-loop at line 6, which iterates 3 times. Each
> iteration gives following results:
>
> 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
>
> then code proceeds and triggers panic.
>
> 1 if (xfer->length < actlen) {
> 2 printf("XXX #1# ehci_idone: len=%u, actlen=%u,
> xf_actlen=%u, "
> 3 "status=0x%x, sqtd_count=%d\n", xfer->length,
> actlen, xfer->actlen, status, sqtd_count);
> 4 x_actlen = 0;
> 5 sqtd_count = 0;
> 6 for (sqtd = ex->sqtdstart; sqtd != NULL; sqtd = sqtd->nextqtd) {
> 7 sqtd_count++;
> 8 usb_syncmem(&sqtd->dma, sqtd->offs, sizeof(sqtd->qtd),
> 9 BUS_DMASYNC_POSTWRITE | BUS_DMASYNC_POSTREAD);
> 10 nstatus = letoh32(sqtd->qtd.qtd_status);
> 11 qtd_status = nstatus;
> 12 if (nstatus & EHCI_QTD_ACTIVE)
> 13 break;
> 14
> 15 status = nstatus;
> 16 /* halt is ok if descriptor is last, and complete */
> 17 if (sqtd->qtd.qtd_next == htole32(EHCI_LINK_TERMINATE)
> &&
> 18 EHCI_QTD_GET_BYTES(status) == 0)
> 19 status &= ~EHCI_QTD_HALTED;
> 20 if (EHCI_QTD_GET_PID(status) != EHCI_QTD_PID_SETUP) {
> 21 sqtd_len = sqtd->len;
> 22 ehci_qtd_len = EHCI_QTD_GET_BYTES(status);
> 23 x_actlen += sqtd_len - ehci_qtd_len;
> 24 printf("XXX #2# ehci_idone: x_actlen=%u,
> sqtd_len=%u, ehci_qtd_len=%u, "
> 25 "status=0x%x, qtd_status=0x%x,
> sqtd_count=%d\n",
> 26 x_actlen, sqtd_len, ehci_qtd_len,
> status, qtd_status, sqtd_count);
> 27 }
> 28 }
> 29 }
>
> I can provide full patch if someone is interested what exactly I am
> doing.
>
> --
> Regards,
> Mikolaj
>
