[PATCH] usb: xhci: fix event trb handling missed

[Ran Wang]

Hi Bin

On Tuesday, November 10, 2020 5:55 PM, Ran Wang wrote:
> 
> Hi Bin,
> 

<snip>

> > > record_transfer_result():comp_code: 1 csw org 00000000fbb4ec90,
> > > adjusted to 00000000fbb4fffe
> > > record_transfer_result():comp_code: 1
> > > record_transfer_result():comp_code: 1
> > > record_transfer_result():comp_code: 1 csw org 00000000fbb4ec90,
> > > adjusted to 00000000fbb4fffe
> > > record_transfer_result():comp_code: 1
> > > record_transfer_result():comp_code: 1
> > > record_transfer_result():comp_code: 1 csw org 00000000fbb4ec90,
> > > adjusted to 00000000fbb4fffe
> > > record_transfer_result():comp_code: 1
> > > record_transfer_result():comp_code: 1
> > > record_transfer_result():comp_code: 1
> >
> > In the earlier log you sent, you have the following:
> >
> > dev=00000000fbb4f3c0, pipe=c0010283, buffer=00000000fbb4fd80,
> > length=2048----------------------------buffer would cross 64KB
> > boundary, so we will send request in more than 1 TRB, this is the key
> > issue trigger condition
> > xhci_bulk_tx()#0.1.running_total:0x280
> > xhci_bulk_tx()#0.2.trb_buff_len:0x280
> > xhci_bulk_tx()#0.3.running_total:0x280
> > xhci_bulk_tx()#0.4.num_trbs:0x2--------------------------2 Transfer
> > TRB
> > xhci_bulk_tx()#0.5.running_total:0x10280
> > xhci_bulk_tx()#0.start_trb:0x00000000fbb47140
> > ----------xhci_bulk_tx()#0.&ring->enqueue->generic:0x00000000fbb47140-
> > --------
> > -Assemble
> > 1st Transfer TRB
> > xhci_bulk_tx()#0.addr:0xfbb4fd80
> > xhci_bulk_tx()#0.trb_buff_len:0x280
> > xhci_bulk_tx()#0.running_total:0x280
> > xhci_bulk_tx()#0.length:0x800
> > xhci_bulk_tx()#0.TRB_MAX_BUFF_SIZE:0x10000
> > ----------xhci_bulk_tx()#0.&ring->enqueue->generic:0x00000000fbb47150-
> > --------
> > -Assemble
> > 2nd Transfer TRB
> > xhci_bulk_tx()#0.addr:0xfbb50000
> > xhci_bulk_tx()#0.trb_buff_len:0x580
> > xhci_bulk_tx()#0.running_total:0x800
> > xhci_bulk_tx()#0.length:0x800
> > xhci_bulk_tx()#0.TRB_MAX_BUFF_SIZE:0x10000
> >
> > Could you please specify where this output is for?
> 
> All this prints is within function xhci_bulk_tx(),
> 
> Let me open those verbose output and check if that crossing 64KB case has been
> triggered or not.
> But I have to get back to you later (tomorrow).

With your test commit and my verbose print code, issue cannot be reproduced in mass storage usage
(although crossing 64KB boundary condition has met), so looks like the only different to ethernet device
is that if xHC would receive short packet:

=> pri t
t=usb read 0x82000000 0 300000
=> run t

usb read: device 0 block # 0, count 3145728 ... 
usb_stor_BBB_transport()csw org 00000000fbb4ac90, adjusted to 00000000fbb4fffe
xhci_bulk_tx()dev=00000000fbb49950, pipe=c0010203, buffer=00000000fbb1a9c0, length=0x1f
xhci_bulk_tx()#0.4.num_trbs:0x1
++++++++++++xhci_bulk_tx()#0.&ring->enqueue->generic:0x00000000fbb49570
xhci_bulk_tx()#0.last_transfer_trb_addr:0x00000000fbb49570
--------------xhci_bulk_tx()#0.event->trans_event.buffer:0x00000000fbb49570
xhci_bulk_tx()#0.event->complete_code:1
xhci_bulk_tx()#3.ep_index:0x3
xhci_bulk_tx()dev=00000000fbb49950, pipe=c0008283, buffer=00000000fbb1ab00, length=0x200
xhci_bulk_tx()#0.4.num_trbs:0x1
xhci_bulk_tx()#set TRB_ISP------------------------------------ 
++++++++++++xhci_bulk_tx()#0.&ring->enqueue->generic:0x00000000fbb49180
xhci_bulk_tx()#0.last_transfer_trb_addr:0x00000000fbb49180
--------------xhci_bulk_tx()#0.event->trans_event.buffer:0x00000000fbb49180
xhci_bulk_tx()#0.event->complete_code:1
xhci_bulk_tx()#3.ep_index:0x2
xhci_bulk_tx()dev=00000000fbb49950, pipe=c0008283, buffer=00000000fbb4fffe, length=0xd-----------------buffer cross 64KB boundary
xhci_bulk_tx()#0.4.num_trbs:0x2
xhci_bulk_tx()#set TRB_ISP---------------------------------------------------------------------------------------Set ISP
++++++++++++xhci_bulk_tx()#0.&ring->enqueue->generic:0x00000000fbb49190----------------1st transfer TRB queued
xhci_bulk_tx()#0.last_transfer_trb_addr:0x00000000fbb49190
xhci_bulk_tx()#set TRB_ISP---------------------------------------------------------------------------------------Set ISP
++++++++++++xhci_bulk_tx()#0.&ring->enqueue->generic:0x00000000fbb491a0----------------2nd transfer TRB queued
xhci_bulk_tx()#0.last_transfer_trb_addr:0x00000000fbb491a0
--------------xhci_bulk_tx()#0.event->trans_event.buffer:0x00000000fbb491a0---------------------event TRB that pointing to 2nd transfer TRB
xhci_bulk_tx()#0.event->complete_code:1-----------------------------------------------------------------not short packet
xhci_bulk_tx()#3.ep_index:0x2
num_trbs_count > 1!!!!!!!!!
...
usb_stor_BBB_transport()csw org 00000000fbb4aea0, adjusted to 00000000fbb4fffe
xhci_bulk_tx()dev=00000000fbb49950, pipe=c0010203, buffer=00000000fbb1ad00, length=0x1f
xhci_bulk_tx()#0.4.num_trbs:0x1
++++++++++++xhci_bulk_tx()#0.&ring->enqueue->generic:0x00000000fbb49790
xhci_bulk_tx()#0.last_transfer_trb_addr:0x00000000fbb49790
--------------xhci_bulk_tx()#0.event->trans_event.buffer:0x00000000fbb49790
xhci_bulk_tx()#0.event->complete_code:1
xhci_bulk_tx()#3.ep_index:0x3
xhci_bulk_tx()dev=00000000fbb49950, pipe=c0008283, buffer=00000000883d8000, length=0x1e000-----------------buffer cross 64KB boundary
xhci_bulk_tx()#0.4.num_trbs:0x3
xhci_bulk_tx()#set TRB_ISP---------------------------------------------------------------------------------------Set ISP
++++++++++++xhci_bulk_tx()#0.&ring->enqueue->generic:0x00000000fbb492a0----------------1st transfer TRB queued
xhci_bulk_tx()#0.last_transfer_trb_addr:0x00000000fbb492a0
xhci_bulk_tx()#set TRB_ISP---------------------------------------------------------------------------------------Set ISP
++++++++++++xhci_bulk_tx()#0.&ring->enqueue->generic:0x00000000fbb492b0----------------2nd transfer TRB queued
xhci_bulk_tx()#0.last_transfer_trb_addr:0x00000000fbb492b0
xhci_bulk_tx()#set TRB_ISP---------------------------------------------------------------------------------------Set ISP
++++++++++++xhci_bulk_tx()#0.&ring->enqueue->generic:0x00000000fbb492c0----------------3rd transfer TRB queued
xhci_bulk_tx()#0.last_transfer_trb_addr:0x00000000fbb492c0
--------------xhci_bulk_tx()#0.event->trans_event.buffer:0x00000000fbb492c0---------------------event TRB that pointing to 3rd transfer TRB
xhci_bulk_tx()#0.event->complete_code:1-----------------------------------------------------------------not short packet
xhci_bulk_tx()#3.ep_index:0x2
num_trbs_count > 1!!!!!!!!!
xhci_bulk_tx()dev=00000000fbb49950, pipe=c0008283, buffer=00000000fbb4fffe, length=0xd
xhci_bulk_tx()#0.4.num_trbs:0x2
xhci_bulk_tx()#set TRB_ISP---------------------------------------------------------------------------------------Set ISP
++++++++++++xhci_bulk_tx()#0.&ring->enqueue->generic:0x00000000fbb492d0
xhci_bulk_tx()#0.last_transfer_trb_addr:0x00000000fbb492d0
xhci_bulk_tx()#set TRB_ISP---------------------------------------------------------------------------------------Set ISP
++++++++++++xhci_bulk_tx()#0.&ring->enqueue->generic:0x00000000fbb492e0
xhci_bulk_tx()#0.last_transfer_trb_addr:0x00000000fbb492e0
--------------xhci_bulk_tx()#0.event->trans_event.buffer:0x00000000fbb492e0
xhci_bulk_tx()#0.event->complete_code:1
xhci_bulk_tx()#3.ep_index:0x2
num_trbs_count > 1!!!!!!!!!

Regards
Ran