All the mail mirrored from lore.kernel.org
 help / color / mirror / Atom feed
From: "Michał Pecio" <michal.pecio@gmail.com>
To: Mathias Nyman <mathias.nyman@linux.intel.com>
Cc: Paul Menzel <pmenzel@molgen.mpg.de>,
	Mathias Nyman <mathias.nyman@intel.com>,
	LKML <linux-kernel@vger.kernel.org>,
	linux-usb@vger.kernel.org
Subject: Re: xhci_hcd 0000:00:14.0: ERROR Transfer event TRB DMA ptr not part of current TD ep_index 1 comp_code 1
Date: Mon, 8 Apr 2024 21:05:41 +0200	[thread overview]
Message-ID: <20240408210541.771253ff@foxbook> (raw)
In-Reply-To: <1f64af9a-0618-a7da-4acc-f043b6580308@linux.intel.com>

> It's also possible this TD/TRB was cancelled due to the disconnect.
> Could be that even if driver removes the TD from the list and cleans
> out the TRB from the ring buffer (turns TRB to no-op) hardware may
> have read ahead and cached the TRB, and process it anyway.

I thought about it, but my debug patch says that the missing TD was
freed by finish_td(), which is called on TDs considered completed by
hardware. A cancelled TD would show giveback_invalidated_tds().


Anyway, we now have new information from the reporter. My v2 patch
keeps a log of the last five events processed on each transfer ring
and dumps the log on TRB mismatch errors.

Unfortunately, it looks like the host controller is broken and signals
completion of those transfers twice. The log below shows two distinct
events for TRB 32959a1c0 and that the coresponding TD has just been
freed by finish_td().

[33819.676314] usb 1-2: USB disconnect, device number 7
[33819.676331] usb 1-2: unregistering device
[33819.676347] usb 1-2: unregistering interface 1-2:1.0
[33819.677861] xhci_hcd 0000:00:14.0: ERROR Transfer event TRB DMA ptr not part of current TD ep_index 1 comp_code 1
[33819.677886] xhci_hcd 0000:00:14.0: Looking for event-dma 000000032959a1c0 trb-start 000000032959a1d0 trb-end 000000032959a1d0 seg-start 000000032959a000 seg-end 000000032959aff0
[33819.677902] xhci_hcd 0000:00:14.0: last xhci_td_cleanup: first_dma 32959a1c0 last_dma 32959a1c0 status -115 from finish_td
[33819.677915] xhci_hcd 0000:00:14.0: handle_tx_event log -4: event ffff9e19c38eb1f0 ep_trb_dma 32959a190 comp_code 1 len 0 slot 6 ep 1
[33819.677925] xhci_hcd 0000:00:14.0: handle_tx_event log -3: event ffff9e19c38eb200 ep_trb_dma 32959a1a0 comp_code 1 len 0 slot 6 ep 1
[33819.677934] xhci_hcd 0000:00:14.0: handle_tx_event log -2: event ffff9e19c38eb220 ep_trb_dma 32959a1b0 comp_code 1 len 0 slot 6 ep 1
[33819.677941] xhci_hcd 0000:00:14.0: handle_tx_event log -1: event ffff9e19c38eb230 ep_trb_dma 32959a1c0 comp_code 1 len 0 slot 6 ep 1
[33819.677949] xhci_hcd 0000:00:14.0: handle_tx_event log  0: event ffff9e19c38eb260 ep_trb_dma 32959a1c0 comp_code 1 len 0 slot 6 ep 1

At this point we have set the "interesting" flag on this transfer ring,
so the handling of the next event is logged. We observe TD 32959a1d0
completing normally here.

[33819.677965] xhci_hcd 0000:00:14.0: handle_tx_event event ffff9e19c38eb270 ep_trb_dma 32959a1d0 comp_code 1 len 0 slot 6 ep 1
[33819.677979] xhci_hcd 0000:00:14.0: handle_tx_event event ffff9e19c38eb270 first_trb 32959a1d0 last_trb 32959a1d0 ep_seg 32959a000
[33819.677993] xhci_hcd 0000:00:14.0: process_isoc_td event ffff9e19c38eb270 requested 192 ep_trb_len 192 remaining 0
[33819.678004] xhci_hcd 0000:00:14.0: finish_td td_status -115 comp_code 1 frame_status 0 frame_actual_length 192

And then we get a TRB mismatch error on this same TD.
The dumped log shows duplicate events once again.

[33819.678022] xhci_hcd 0000:00:14.0: ERROR Transfer event TRB DMA ptr not part of current TD ep_index 1 comp_code 1
[33819.678034] xhci_hcd 0000:00:14.0: Looking for event-dma 000000032959a1d0 trb-start 000000032959a1e0 trb-end 000000032959a1e0 seg-start 000000032959a000 seg-end 000000032959aff0
[33819.678047] xhci_hcd 0000:00:14.0: last xhci_td_cleanup: first_dma 32959a1d0 last_dma 32959a1d0 status -115 from finish_td
[33819.678058] xhci_hcd 0000:00:14.0: handle_tx_event log -4: event ffff9e19c38eb220 ep_trb_dma 32959a1b0 comp_code 1 len 0 slot 6 ep 1
[33819.678066] xhci_hcd 0000:00:14.0: handle_tx_event log -3: event ffff9e19c38eb230 ep_trb_dma 32959a1c0 comp_code 1 len 0 slot 6 ep 1
[33819.678074] xhci_hcd 0000:00:14.0: handle_tx_event log -2: event ffff9e19c38eb260 ep_trb_dma 32959a1c0 comp_code 1 len 0 slot 6 ep 1
[33819.678082] xhci_hcd 0000:00:14.0: handle_tx_event log -1: event ffff9e19c38eb270 ep_trb_dma 32959a1d0 comp_code 1 len 0 slot 6 ep 1
[33819.678089] xhci_hcd 0000:00:14.0: handle_tx_event log  0: event ffff9e19c38eb280 ep_trb_dma 32959a1d0 comp_code 1 len 0 slot 6 ep 1

Regards,
Michal

  parent reply	other threads:[~2024-04-08 19:05 UTC|newest]

Thread overview: 16+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2024-03-29 10:47 xhci_hcd 0000:00:14.0: ERROR Transfer event TRB DMA ptr not part of current TD ep_index 1 comp_code 1 Paul Menzel
2024-04-05  9:32 ` Michał Pecio
2024-04-06 14:37   ` Paul Menzel
2024-04-06 16:36     ` Michał Pecio
2024-04-06 17:01       ` Paul Menzel
2024-04-07 12:25         ` Michał Pecio
2024-04-08  7:17           ` Mathias Nyman
2024-04-08 16:37             ` Paul Menzel
2024-04-08 16:42               ` Paul Menzel
2024-04-08 19:05             ` Michał Pecio [this message]
2024-04-09 11:22               ` Mathias Nyman
2024-04-10  7:59                 ` Paul Menzel
2024-04-11  7:18                   ` Mathias Nyman
2024-04-11 19:55                     ` Paul Menzel
2024-04-13  9:17                   ` Michał Pecio
2024-04-10  9:46                 ` Michał Pecio

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=20240408210541.771253ff@foxbook \
    --to=michal.pecio@gmail.com \
    --cc=linux-kernel@vger.kernel.org \
    --cc=linux-usb@vger.kernel.org \
    --cc=mathias.nyman@intel.com \
    --cc=mathias.nyman@linux.intel.com \
    --cc=pmenzel@molgen.mpg.de \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line before the message body.
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.