* USB2 / USB3 compatibility problems: xhci_hcd 0000:00:06.0: WARN Wrong bounce buffer write length: 0 != 512 @ 2021-01-22 8:06 Andreas Hartmann 2021-01-22 8:09 ` Andreas Hartmann 0 siblings, 1 reply; 17+ messages in thread From: Andreas Hartmann @ 2021-01-22 8:06 UTC (permalink / raw) To: linux-usb Hello! Since a new Notebook, which sadly only provides USB 3 interfaces, I have a more or less big problem with an old driver (rt5572sta), which not just sometimes produces those warn messages, but even stalls sometimes after those warn messages (e,g, Kernel 5.3.x or 5.10.x or 5.8.x) - see attached log file. The driver uses the bulk method to communicate with the USB bus. By reducing the max. bulk size from 24 kByte to 12 kByte, I was able to massively reduce those warning messages and now, the USB bus even seldom stalls any more. I achieved this by changing the building of the bulk package from if (((ThisBulkSize&0xffff8000) != 0) || ((ThisBulkSize&0x6000) == 0x6000)) to if (((ThisBulkSize&0xffff8000) != 0) || ((ThisBulkSize&0x3000) == 0x3000)) I can see this problem on two different AMD USB 3 controller, e.g. X370 Series Chipset USB 3.1 xHCI Controller [1022:43b9] (rev 02). I'm wondering how to solve this problem? But mostly I'm wondering, why a USB 2 device is handled by USB 3 code, expecting to follow USB 3 rules at all? Is it possible to bind the driver to the USB 2 code path? At the moment I think, that the attempt to "transfer" a valid USB 2 package to a valid USB 3 package by xhci_hcd seems not always to be transparent to the driver producing and controlling its send packets. Could it be possible, that there are some situations, where the driver can't check the package after manipulation through xhci_hcd any more? Please see the attached log file. Or how should I fix the driver to be USB 3 ready? Please take into account, that I'm not an USB protocol specialist and I don't know, at which level or how to build a valid bulk packet which confirms to USB3 rules. At the time being, I'm debugging on base of the pretty loud debug messages of the rt5572sta driver and the xhci_hcd debug messages (echo "module xhci_hcd =pf" > /sys/kernel/debug/dynamic_debug/control) Thanks for any idea how to proceed! Andreas Hartmann ^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: USB2 / USB3 compatibility problems: xhci_hcd 0000:00:06.0: WARN Wrong bounce buffer write length: 0 != 512 2021-01-22 8:06 USB2 / USB3 compatibility problems: xhci_hcd 0000:00:06.0: WARN Wrong bounce buffer write length: 0 != 512 Andreas Hartmann @ 2021-01-22 8:09 ` Andreas Hartmann 2021-01-24 17:28 ` Andreas Hartmann 0 siblings, 1 reply; 17+ messages in thread From: Andreas Hartmann @ 2021-01-22 8:09 UTC (permalink / raw) To: linux-usb [-- Attachment #1: Type: text/plain, Size: 2207 bytes --] Sorry, forgot to attach the log file ... . Now, it's there. Thanks Andreas Hartmann On 22.01.21 at 09:06 Andreas Hartmann wrote: > > Hello! > > Since a new Notebook, which sadly only provides USB 3 interfaces, I have a more or > less big problem with an old driver (rt5572sta), which not just sometimes produces > those warn messages, but even stalls sometimes after those warn messages (e,g, > Kernel 5.3.x or 5.10.x or 5.8.x) - see attached log file. > > The driver uses the bulk method to communicate with the USB bus. By reducing the > max. bulk size from 24 kByte to 12 kByte, I was able to massively reduce those > warning messages and now, the USB bus even seldom stalls any more. > > I achieved this by changing the building of the bulk package from > > if (((ThisBulkSize&0xffff8000) != 0) || ((ThisBulkSize&0x6000) == 0x6000)) > > to > > if (((ThisBulkSize&0xffff8000) != 0) || ((ThisBulkSize&0x3000) == 0x3000)) > > > I can see this problem on two different AMD USB 3 controller, e.g. X370 Series > Chipset USB 3.1 xHCI Controller [1022:43b9] (rev 02). > > I'm wondering how to solve this problem? But mostly I'm wondering, why a USB 2 > device is handled by USB 3 code, expecting to follow USB 3 rules at all? Is it > possible to bind the driver to the USB 2 code path? > > At the moment I think, that the attempt to "transfer" a valid USB 2 package to a > valid USB 3 package by xhci_hcd seems not always to be transparent to the driver > producing and controlling its send packets. Could it be possible, that there are > some situations, where the driver can't check the package after manipulation > through xhci_hcd any more? Please see the attached log file. > > Or how should I fix the driver to be USB 3 ready? Please take into account, that > I'm not an USB protocol specialist and I don't know, at which level or how to > build a valid bulk packet which confirms to USB3 rules. > > At the time being, I'm debugging on base of the pretty loud debug messages of the > rt5572sta driver and the xhci_hcd debug messages (echo "module xhci_hcd =pf" > > /sys/kernel/debug/dynamic_debug/control) > > > Thanks for any idea how to proceed! > Andreas Hartmann [-- Attachment #2: usb3-alignment_error.txt --] [-- Type: text/plain, Size: 3198 bytes --] 2021-01-19T14:01:47.492316+01:00 localhost kernel: [26509.686972] xhci_hcd 0000:00:06.0: WARN Wrong bounce buffer write length: 0 != 512 2021-01-19T14:01:48.947710+01:00 localhost kernel: [26511.142333] BulkOutDataPacket failed: ReasonCode=-2! 2021-01-19T14:01:48.947737+01:00 localhost kernel: [26511.142356] >>BulkOut Req=0xc7f93, Complete=0xc7f92, Other=0x2 2021-01-19T14:01:48.947739+01:00 localhost kernel: [26511.142361] >>BulkOut Header:10 6 0 44 d0 0 8f 80 2021-01-19T14:01:54.303312+01:00 localhost kernel: [26516.498060] BulkOutDataPacket failed: ReasonCode=-2! 2021-01-19T14:01:54.303333+01:00 localhost kernel: [26516.498078] >>BulkOut Req=0xc7f93, Complete=0xc7f92, Other=0x3 2021-01-19T14:01:54.303335+01:00 localhost kernel: [26516.498083] >>BulkOut Header:10 6 0 44 d0 0 8f 80 2021-01-19T14:01:59.676016+01:00 localhost kernel: [26521.870773] BulkOutDataPacket failed: ReasonCode=-2! 2021-01-19T14:01:59.676044+01:00 localhost kernel: [26521.870800] >>BulkOut Req=0xc7f93, Complete=0xc7f92, Other=0x4 2021-01-19T14:01:59.676046+01:00 localhost kernel: [26521.870815] >>BulkOut Header:10 6 0 44 d0 0 8f 80 2021-01-19T14:02:04.999737+01:00 localhost kernel: [26527.194549] BulkOutDataPacket failed: ReasonCode=-2! 2021-01-19T14:02:04.999762+01:00 localhost kernel: [26527.194573] >>BulkOut Req=0xc7f93, Complete=0xc7f92, Other=0x5 2021-01-19T14:02:04.999764+01:00 localhost kernel: [26527.194577] >>BulkOut Header:10 6 0 44 d0 0 8f 80 2021-01-19T14:02:10.439333+01:00 localhost kernel: [26532.634186] BulkOutDataPacket failed: ReasonCode=-2! 2021-01-19T14:02:10.439355+01:00 localhost kernel: [26532.634202] >>BulkOut Req=0xc7f93, Complete=0xc7f92, Other=0x6 2021-01-19T14:02:10.439357+01:00 localhost kernel: [26532.634207] >>BulkOut Header:10 6 0 44 d0 0 8f 80 2021-01-19T14:02:15.788389+01:00 localhost kernel: [26537.983270] BulkOutDataPacket failed: ReasonCode=-2! 2021-01-19T14:02:15.788413+01:00 localhost kernel: [26537.983292] >>BulkOut Req=0xc7f93, Complete=0xc7f92, Other=0x7 2021-01-19T14:02:15.788414+01:00 localhost kernel: [26537.983297] >>BulkOut Header:10 6 0 44 d0 0 8f 80 2021-01-19T14:02:21.231765+01:00 localhost kernel: [26543.426680] BulkOutDataPacket failed: ReasonCode=-2! 2021-01-19T14:02:21.231788+01:00 localhost kernel: [26543.426701] >>BulkOut Req=0xc7f93, Complete=0xc7f92, Other=0x8 2021-01-19T14:02:21.231790+01:00 localhost kernel: [26543.426706] >>BulkOut Header:10 6 0 44 d0 0 8f 80 2021-01-19T14:02:26.527355+01:00 localhost kernel: [26548.722310] BulkOutDataPacket failed: ReasonCode=-2! 2021-01-19T14:02:26.527377+01:00 localhost kernel: [26548.722327] >>BulkOut Req=0xc7f93, Complete=0xc7f92, Other=0x9 2021-01-19T14:02:26.527379+01:00 localhost kernel: [26548.722331] >>BulkOut Header:10 6 0 44 d0 0 8f 80 2021-01-19T14:02:31.999097+01:00 localhost kernel: [26554.194080] BulkOutDataPacket failed: ReasonCode=-2! 2021-01-19T14:02:31.999121+01:00 localhost kernel: [26554.194101] >>BulkOut Req=0xc7f93, Complete=0xc7f92, Other=0xa 2021-01-19T14:02:31.999122+01:00 localhost kernel: [26554.194106] >>BulkOut Header:10 6 0 44 d0 0 8f 80 ^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: USB2 / USB3 compatibility problems: xhci_hcd 0000:00:06.0: WARN Wrong bounce buffer write length: 0 != 512 2021-01-22 8:09 ` Andreas Hartmann @ 2021-01-24 17:28 ` Andreas Hartmann 2021-01-25 10:18 ` Andreas Hartmann 0 siblings, 1 reply; 17+ messages in thread From: Andreas Hartmann @ 2021-01-24 17:28 UTC (permalink / raw) To: linux-usb, mathias.nyman On 22.01.21 at 09:09 Andreas Hartmann wrote: > On 22.01.21 at 09:06 Andreas Hartmann wrote: >> >> Hello! >> >> Since a new Notebook, which sadly only provides USB 3 interfaces, I have a more >> or less big problem with an old driver (rt5572sta), which not just sometimes >> produces those warn messages, but even stalls sometimes after those warn >> messages (e,g, Kernel 5.3.x or 5.10.x or 5.8.x) - see attached log file. >> >> The driver uses the bulk method to communicate with the USB bus. By reducing the >> max. bulk size from 24 kByte to 12 kByte, I was able to massively reduce those >> warning messages and now, the USB bus even seldom stalls any more. >> >> I achieved this by changing the building of the bulk package from >> >> if (((ThisBulkSize&0xffff8000) != 0) || ((ThisBulkSize&0x6000) == 0x6000)) >> >> to >> >> if (((ThisBulkSize&0xffff8000) != 0) || ((ThisBulkSize&0x3000) == 0x3000)) >> >> >> I can see this problem on two different AMD USB 3 controller, e.g. X370 Series >> Chipset USB 3.1 xHCI Controller [1022:43b9] (rev 02). After doing some deeper investigations, I can say, that there are 4(!) different behaviors - besides the point, that the original sized bulk packages (24 kB) are working much more worse than 12 kB (reducing it further more doesn't make any difference any more): 1. No problem at all even over hours of stress test (netperf). 2. Sometimes "WARN Wrong bounce buffer write length" entries appear - but nothing more. 3. The problems shown in the attachment of the previous mail are coming up. The communication to the device stalls for some time or even breaks completely. It's when the completion routine called by the kernel detects the problem: 2021-01-19T14:01:47.492316+01:00 localhost kernel: [26509.686972] xhci_hcd 0000:00:06.0: WARN Wrong bounce buffer write length: 0 != 512 2021-01-19T14:01:48.947710+01:00 localhost kernel: [26511.142333] BulkOutDataPacket failed: ReasonCode=-2! 2021-01-19T14:01:48.947737+01:00 localhost kernel: [26511.142356] >>BulkOut Req=0xc7f93, Complete=0xc7f92, Other=0x2 2021-01-19T14:01:48.947739+01:00 localhost kernel: [26511.142361] >>BulkOut Header:10 6 0 44 d0 0 8f 80 2021-01-19T14:01:54.303312+01:00 localhost kernel: [26516.498060] BulkOutDataPacket failed: ReasonCode=-2! 2021-01-19T14:01:54.303333+01:00 localhost kernel: [26516.498078] >>BulkOut Req=0xc7f93, Complete=0xc7f92, Other=0x3 2021-01-19T14:01:54.303335+01:00 localhost kernel: [26516.498083] >>BulkOut Header:10 6 0 44 d0 0 8f 80 2021-01-19T14:01:59.676016+01:00 localhost kernel: [26521.870773] BulkOutDataPacket failed: ReasonCode=-2! 2021-01-19T14:01:59.676044+01:00 localhost kernel: [26521.870800] >>BulkOut Req=0xc7f93, Complete=0xc7f92, Other=0x4 2021-01-19T14:01:59.676046+01:00 localhost kernel: [26521.870815] >>BulkOut Header:10 6 0 44 d0 0 8f 80 The reason code -2 (ENOENT?) is the status given by the urb struct. The driver tries to send the same packet again and again and suddenly it's working again after n retries. This mostly "works" - but not always. 4. There isn't any completion any more received. At this point, the watchdog kicks in and tries to reset the hardware. This mostly works (after some time) - but not always. Question is, why there isn't any completion call at all coming up. Something seems to hang completely in this case. 2021-01-24T17:11:17.562705+01:00 localhost kernel: [ 3181.024863] xhci_hcd 0000:00:06.0: WARN Wrong bounce buffer write length: 0 != 512 2021-01-24T17:11:20.191792+01:00 localhost kernel: [ 3183.651100] Maybe the Tx Bulk-Out hanged! Cancel the pending Tx bulks request of idx(0)! 2021-01-24T17:11:20.191821+01:00 localhost kernel: [ 3183.651103] Unlink the pending URB! 2021-01-24T17:11:20.191823+01:00 localhost kernel: [ 3183.651287] set RTMP_ADAPTER_BULKOUT_RESET (rtusb_dataout_complete - called from done_tasklet) 2021-01-24T17:11:20.191825+01:00 localhost kernel: [ 3183.651288] BulkOutDataPacket failed: ReasonCode=-2! 2021-01-24T17:11:20.191826+01:00 localhost kernel: [ 3183.651290] >>BulkOut Req=0x4566e8, Complete=0x4566e7, Other=0x7 2021-01-24T17:11:20.191828+01:00 localhost kernel: [ 3183.651292] >>BulkOut Header:10 6 0 44 d0 0 96 80 2021-01-24T17:11:20.191829+01:00 localhost kernel: [ 3183.651299] CMDTHREAD_RESET_BULK_OUT(ResetPipeid=0x0)===> 2021-01-24T17:11:21.559776+01:00 localhost kernel: [ 3185.018969] Set 0x2a0 bit19. Clear USB DMA TX path 2021-01-24T17:11:21.559801+01:00 localhost kernel: [ 3185.018977] CMDTHREAD_RESET_BULK_OUT: TxContext[0]:CWPos=52912, NBPos=74696, ENBPos=87144, bCopy=1, pending=1! 2021-01-24T17:11:21.559803+01:00 localhost kernel: [ 3185.018978] BulkOut Req=0x4566e8, Complete=0x4566e7, Other=0x7 2021-01-24T17:11:21.559804+01:00 localhost kernel: [ 3185.018980] CMDTHREAD_RESET_BULK_OUT: Submit Tx DATA URB for failed BulkReq(0x4566e8) Done, status=-115! 2021-01-24T17:11:21.559805+01:00 localhost kernel: [ 3185.019001] CmdThread : CMDTHREAD_RESET_BULK_OUT<=== 2021-01-24T17:11:25.479870+01:00 localhost kernel: [ 3188.938847] Maybe the Tx Bulk-Out hanged! Cancel the pending Tx bulks request of idx(0)! 2021-01-24T17:11:25.479898+01:00 localhost kernel: [ 3188.938850] Unlink the pending URB! 2021-01-24T17:11:25.479899+01:00 localhost kernel: [ 3188.939052] set RTMP_ADAPTER_BULKOUT_RESET 2021-01-24T17:11:25.479901+01:00 localhost kernel: [ 3188.939054] BulkOutDataPacket failed: ReasonCode=-2! 2021-01-24T17:11:25.479902+01:00 localhost kernel: [ 3188.939055] >>BulkOut Req=0x4566e8, Complete=0x4566e7, Other=0x8 2021-01-24T17:11:25.479903+01:00 localhost kernel: [ 3188.939057] >>BulkOut Header:10 6 0 44 d0 0 96 80 2021-01-24T17:11:25.479904+01:00 localhost kernel: [ 3188.939065] CMDTHREAD_RESET_BULK_OUT(ResetPipeid=0x0)===> 2021-01-24T17:11:26.844167+01:00 localhost kernel: [ 3190.303636] Set 0x2a0 bit19. Clear USB DMA TX path 2021-01-24T17:11:26.844192+01:00 localhost kernel: [ 3190.303644] CMDTHREAD_RESET_BULK_OUT: TxContext[0]:CWPos=59136, NBPos=74696, ENBPos=87144, bCopy=1, pending=1! 2021-01-24T17:11:26.844194+01:00 localhost kernel: [ 3190.303645] BulkOut Req=0x4566e8, Complete=0x4566e7, Other=0x8 2021-01-24T17:11:26.844195+01:00 localhost kernel: [ 3190.303646] CMDTHREAD_RESET_BULK_OUT: Submit Tx DATA URB for failed BulkReq(0x4566e8) Done, status=-115! 2021-01-24T17:11:26.844196+01:00 localhost kernel: [ 3190.303659] CmdThread : CMDTHREAD_RESET_BULK_OUT<=== Sending the urb again (usb_submit_urb) after resetting the hardware and unlinking the urb fails with status -115 (EINPROGRESS) and the watchdog kicks in again after 4 s, trying the same process again - until it works again (= submit is ok and completion doesn't complain - could take up to 1 minute or more). Hope this helps to get an idea of the problem! Thanks Andreas About the hardware I'm currently testing on: # lspci -s0000:00:06.0 -vv 00:06.0 USB controller: Advanced Micro Devices, Inc. [AMD] X370 Series Chipset USB 3.1 xHCI Controller (rev 02) (prog-if 30 [XHCI]) Subsystem: ASMedia Technology Inc. Device 1142 Physical Slot: 6 Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR+ FastB2B- DisINTx+ Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx- Latency: 0, Cache Line Size: 64 bytes Interrupt: pin A routed to IRQ 29 Region 0: Memory at febd0000 (64-bit, non-prefetchable) [size=32K] Capabilities: [50] MSI: Enable+ Count=1/8 Maskable- 64bit+ Address: 00000000fee0e000 Data: 4023 Capabilities: [78] Power Management version 3 Flags: PMEClk- DSI- D1- D2- AuxCurrent=55mA PME(D0-,D1-,D2-,D3hot+,D3cold+) Status: D0 NoSoftRst+ PME-Enable- DSel=0 DScale=0 PME- Capabilities: [80] Express (v2) Legacy Endpoint, MSI 00 DevCap: MaxPayload 512 bytes, PhantFunc 0, Latency L0s <64ns, L1 <2us ExtTag+ AttnBtn- AttnInd- PwrInd- RBE+ FLReset- DevCtl: Report errors: Correctable- Non-Fatal- Fatal- Unsupported- RlxdOrd+ ExtTag+ PhantFunc- AuxPwr- NoSnoop+ MaxPayload 128 bytes, MaxReadReq 512 bytes DevSta: CorrErr+ UncorrErr- FatalErr- UnsuppReq+ AuxPwr+ TransPend- LnkCap: Port #0, Speed 8GT/s, Width x4, ASPM L0s L1, Exit Latency L0s <2us, L1 unlimited ClockPM- Surprise- LLActRep- BwNot- ASPMOptComp+ LnkCtl: ASPM Disabled; RCB 64 bytes Disabled- CommClk+ ExtSynch- ClockPM- AutWidDis- BWInt- AutBWInt- LnkSta: Speed 8GT/s, Width x4, TrErr- Train- SlotClk+ DLActive- BWMgmt- ABWMgmt- DevCap2: Completion Timeout: Not Supported, TimeoutDis-, LTR+, OBFF Not Supported AtomicOpsCap: 32bit- 64bit- 128bitCAS- DevCtl2: Completion Timeout: 50us to 50ms, TimeoutDis-, LTR-, OBFF Disabled AtomicOpsCtl: ReqEn- LnkSta2: Current De-emphasis Level: -6dB, EqualizationComplete+, EqualizationPhase1+ EqualizationPhase2-, EqualizationPhase3-, LinkEqualizationRequest- Kernel driver in use: xhci_hcd Kernel modules: xhci_pci Bus 003 Device 002: ID 05e3:0732 Genesys Logic, Inc. All-in-One Cardreader Bus 003 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub Bus 001 Device 002: ID 13b1:003b Linksys AE3000 802.11abgn (3x3) Wireless Adapter [Ralink RT3573] Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub Bus 002 Device 001: ID 1d6b:0001 Linux Foundation 1.1 root hub # lsusb -t /: Bus 03.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/8p, 10000M |__ Port 4: Dev 2, If 0, Class=Mass Storage, Driver=usb-storage, 5000M /: Bus 02.Port 1: Dev 1, Class=root_hub, Driver=uhci_hcd/2p, 12M /: Bus 01.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/14p, 480M |__ Port 3: Dev 2, If 0, Class=Vendor Specific Class, Driver=rt2870, 480M ^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: USB2 / USB3 compatibility problems: xhci_hcd 0000:00:06.0: WARN Wrong bounce buffer write length: 0 != 512 2021-01-24 17:28 ` Andreas Hartmann @ 2021-01-25 10:18 ` Andreas Hartmann 2021-01-25 18:28 ` Mathias Nyman 0 siblings, 1 reply; 17+ messages in thread From: Andreas Hartmann @ 2021-01-25 10:18 UTC (permalink / raw) To: linux-usb, mathias.nyman [-- Attachment #1: Type: text/plain, Size: 6114 bytes --] Hello! Meanwhile I found the culprit: https://www.spinics.net/lists/linux-usb/msg141467.html and https://www.spinics.net/lists/linux-usb/msg141468.html Especially the last change breaks things here completely. After removing them by the attached patch, problems are gone and device works again as expected (I tested with the original 24 kB bulk size which was horribly broken w/o the attached patch). This means: the additional repair steps are not just breaking things but are even unnecessary (it's working perfectly without those changes) here. I tested with 2 USB 3.1 host controllers: USB controller: Advanced Micro Devices, Inc. [AMD] Raven USB 3.1 (prog-if 30 [XHCI]) 05:00.3 0c03: 1022:15e0 (prog-if 30 [XHCI]) Subsystem: 1043:201f Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR- FastB2B- DisINTx+ Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx- Latency: 0, Cache Line Size: 64 bytes Interrupt: pin D routed to IRQ 37 Region 0: Memory at f7300000 (64-bit, non-prefetchable) [size=1M] Capabilities: [48] Vendor Specific Information: Len=08 <?> Capabilities: [50] Power Management version 3 Flags: PMEClk- DSI- D1- D2- AuxCurrent=0mA PME(D0+,D1-,D2-,D3hot+,D3cold+) Status: D0 NoSoftRst- PME-Enable- DSel=0 DScale=0 PME- Capabilities: [64] Express (v2) Endpoint, MSI 00 DevCap: MaxPayload 256 bytes, PhantFunc 0, Latency L0s <4us, L1 unlimited ExtTag+ AttnBtn- AttnInd- PwrInd- RBE+ FLReset- SlotPowerLimit 0.000W DevCtl: Report errors: Correctable- Non-Fatal- Fatal- Unsupported- RlxdOrd+ ExtTag+ PhantFunc- AuxPwr- NoSnoop+ MaxPayload 256 bytes, MaxReadReq 512 bytes DevSta: CorrErr- UncorrErr- FatalErr- UnsuppReq- AuxPwr- TransPend- LnkCap: Port #0, Speed 8GT/s, Width x16, ASPM L0s L1, Exit Latency L0s <64ns, L1 <1us ClockPM- Surprise- LLActRep- BwNot- ASPMOptComp+ LnkCtl: ASPM Disabled; RCB 64 bytes Disabled- CommClk+ ExtSynch- ClockPM- AutWidDis- BWInt- AutBWInt- LnkSta: Speed 8GT/s, Width x16, TrErr- Train- SlotClk+ DLActive- BWMgmt- ABWMgmt- DevCap2: Completion Timeout: Not Supported, TimeoutDis-, LTR+, OBFF Not Supported AtomicOpsCap: 32bit- 64bit- 128bitCAS- DevCtl2: Completion Timeout: 50us to 50ms, TimeoutDis-, LTR-, OBFF Disabled AtomicOpsCtl: ReqEn- LnkSta2: Current De-emphasis Level: -3.5dB, EqualizationComplete-, EqualizationPhase1- EqualizationPhase2-, EqualizationPhase3-, LinkEqualizationRequest- Capabilities: [a0] MSI: Enable- Count=1/8 Maskable- 64bit+ Address: 0000000000000000 Data: 0000 Capabilities: [c0] MSI-X: Enable+ Count=8 Masked- Vector table: BAR=0 offset=000fe000 PBA: BAR=0 offset=000ff000 Capabilities: [100 v1] Vendor Specific Information: ID=0001 Rev=1 Len=010 <?> Kernel driver in use: xhci_hcd Kernel modules: xhci_pci The 2. device on the same machine has the PCI-ID 1022:15e1 Another USB3.1 host device tested with was: USB controller: Advanced Micro Devices, Inc. [AMD] X370 Series Chipset USB 3.1 xHCI Controller (rev 02) (prog-if 30 [XHCI]) 00:06.0 0c03: 1022:43b9 (rev 02) (prog-if 30 [XHCI]) Subsystem: 1b21:1142 Physical Slot: 6 Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr- Stepping- SERR+ FastB2B- DisINTx+ Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- >SERR- <PERR- INTx- Latency: 0, Cache Line Size: 64 bytes Interrupt: pin A routed to IRQ 29 Region 0: Memory at febd0000 (64-bit, non-prefetchable) [size=32K] Capabilities: [50] MSI: Enable+ Count=1/8 Maskable- 64bit+ Address: 00000000fee0e000 Data: 4023 Capabilities: [78] Power Management version 3 Flags: PMEClk- DSI- D1- D2- AuxCurrent=55mA PME(D0-,D1-,D2-,D3hot+,D3cold+) Status: D0 NoSoftRst+ PME-Enable- DSel=0 DScale=0 PME- Capabilities: [80] Express (v2) Legacy Endpoint, MSI 00 DevCap: MaxPayload 512 bytes, PhantFunc 0, Latency L0s <64ns, L1 <2us ExtTag+ AttnBtn- AttnInd- PwrInd- RBE+ FLReset- DevCtl: Report errors: Correctable- Non-Fatal- Fatal- Unsupported- RlxdOrd+ ExtTag+ PhantFunc- AuxPwr- NoSnoop+ MaxPayload 128 bytes, MaxReadReq 512 bytes DevSta: CorrErr+ UncorrErr- FatalErr- UnsuppReq+ AuxPwr+ TransPend- LnkCap: Port #0, Speed 8GT/s, Width x4, ASPM L0s L1, Exit Latency L0s <2us, L1 unlimited ClockPM- Surprise- LLActRep- BwNot- ASPMOptComp+ LnkCtl: ASPM Disabled; RCB 64 bytes Disabled- CommClk+ ExtSynch- ClockPM- AutWidDis- BWInt- AutBWInt- LnkSta: Speed 8GT/s, Width x4, TrErr- Train- SlotClk+ DLActive- BWMgmt- ABWMgmt- DevCap2: Completion Timeout: Not Supported, TimeoutDis-, LTR+, OBFF Not Supported AtomicOpsCap: 32bit- 64bit- 128bitCAS- DevCtl2: Completion Timeout: 50us to 50ms, TimeoutDis-, LTR-, OBFF Disabled AtomicOpsCtl: ReqEn- LnkSta2: Current De-emphasis Level: -6dB, EqualizationComplete+, EqualizationPhase1+ EqualizationPhase2-, EqualizationPhase3-, LinkEqualizationRequest- Kernel driver in use: xhci_hcd Kernel modules: xhci_pci Please fix those changes or disable them for the mentioned devices or add an option to disable this additional alignment feature. Thanks Andreas [-- Attachment #2: xhci-ring-no-alignment.c.diff --] [-- Type: text/x-patch, Size: 483 bytes --] --- 1/drivers/usb/host/xhci-ring.c 2021-01-25 08:57:52.199210954 +0100 +++ 2/drivers/usb/host/xhci-ring.c 2021-01-25 08:59:29.450511420 +0100 @@ -3250,6 +3250,10 @@ static int xhci_align_td(struct xhci_hcd /* we got lucky, last normal TRB data on segment is packet aligned */ if (unalign == 0) return 0; + else { + xhci_dbg(xhci, "unaligned - but ignored\n"); + return 0; + } xhci_dbg(xhci, "Unaligned %d bytes, buff len %d\n", unalign, *trb_buff_len); ^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: USB2 / USB3 compatibility problems: xhci_hcd 0000:00:06.0: WARN Wrong bounce buffer write length: 0 != 512 2021-01-25 10:18 ` Andreas Hartmann @ 2021-01-25 18:28 ` Mathias Nyman 2021-01-25 18:48 ` Andreas Hartmann 2021-01-25 20:06 ` Andreas Hartmann 0 siblings, 2 replies; 17+ messages in thread From: Mathias Nyman @ 2021-01-25 18:28 UTC (permalink / raw) To: Andreas Hartmann, linux-usb Hi On 25.1.2021 12.18, Andreas Hartmann wrote: > > Hello! > > Meanwhile I found the culprit: > > https://www.spinics.net/lists/linux-usb/msg141467.html > and > https://www.spinics.net/lists/linux-usb/msg141468.html > > Especially the last change breaks things here completely. After removing them > by the attached patch, problems are gone and device works again as expected > (I tested with the original 24 kB bulk size which was horribly broken w/o the > attached patch). This means: the additional repair steps are not just breaking > things but are even unnecessary (it's working perfectly without those changes) > here. Unfortunately this isn't enough to remove the alignment code for those controllers. This is just once specific usecase. We need to figure out what really goes wrong. Looks like 0 bytes is copied from sg list to bounce buffer when we want 512 bytes copied. Just noticed the alignment code assumes sg lists are used without checking it first. Could you add the below code and test again, it should print more debugging info. Thanks -Mathias 8<--- diff --git a/drivers/usb/host/xhci-ring.c b/drivers/usb/host/xhci-ring.c index 5677b81c0915..6a4578a45eb1 100644 --- a/drivers/usb/host/xhci-ring.c +++ b/drivers/usb/host/xhci-ring.c @@ -3253,13 +3253,13 @@ static int xhci_align_td(struct xhci_hcd *xhci, struct urb *urb, u32 enqd_len, if (unalign == 0) return 0; - xhci_dbg(xhci, "Unaligned %d bytes, buff len %d\n", + xhci_warn(xhci, "Unaligned %d bytes, buff len %d\n", unalign, *trb_buff_len); /* is the last nornal TRB alignable by splitting it */ if (*trb_buff_len > unalign) { *trb_buff_len -= unalign; - xhci_dbg(xhci, "split align, new buff len %d\n", *trb_buff_len); + xhci_warn(xhci, "split align, new buff len %d\n", *trb_buff_len); return 0; } @@ -3275,12 +3275,26 @@ static int xhci_align_td(struct xhci_hcd *xhci, struct urb *urb, u32 enqd_len, /* create a max max_pkt sized bounce buffer pointed to by last trb */ if (usb_urb_dir_out(urb)) { + unsigned int nents; len = sg_pcopy_to_buffer(urb->sg, urb->num_sgs, seg->bounce_buf, new_buff_len, enqd_len); - if (len != new_buff_len) + if (len != new_buff_len) { xhci_warn(xhci, "WARN Wrong bounce buffer write length: %zu != %d\n", len, new_buff_len); + xhci_warn(xhci, "urb->num_sgs %d\n", urb->num_sgs); + xhci_warn(xhci, "urb->num_mapped_sgs %d\n", urb->num_mapped_sgs); + xhci_warn(xhci, "urb->transfer_buffer_length %d\n", urb->transfer_buffer_length); + xhci_warn(xhci, "enqd_len %d\n", enqd_len); + xhci_warn(xhci, "max_pkt %d\n", max_pkt); + if (urb->sg) { + struct scatterlist *sg; + for (nents = 0; sg; sg = sg_next(sg)) { + nents++; + xhci_warn(xhci, "%d: sg->length %d\n", nents, sg->length); + } + } + } seg->bounce_dma = dma_map_single(dev, seg->bounce_buf, max_pkt, DMA_TO_DEVICE); } else { ^ permalink raw reply related [flat|nested] 17+ messages in thread
* Re: USB2 / USB3 compatibility problems: xhci_hcd 0000:00:06.0: WARN Wrong bounce buffer write length: 0 != 512 2021-01-25 18:28 ` Mathias Nyman @ 2021-01-25 18:48 ` Andreas Hartmann 2021-01-25 20:06 ` Andreas Hartmann 1 sibling, 0 replies; 17+ messages in thread From: Andreas Hartmann @ 2021-01-25 18:48 UTC (permalink / raw) To: Mathias Nyman, linux-usb Hello Mathias! On 25.01.21 at 19:28 Mathias Nyman wrote: > Hi > > On 25.1.2021 12.18, Andreas Hartmann wrote: >> >> Hello! >> >> Meanwhile I found the culprit: >> >> https://www.spinics.net/lists/linux-usb/msg141467.html >> and >> https://www.spinics.net/lists/linux-usb/msg141468.html >> >> Especially the last change breaks things here completely. After removing them >> by the attached patch, problems are gone and device works again as expected >> (I tested with the original 24 kB bulk size which was horribly broken w/o the >> attached patch). This means: the additional repair steps are not just breaking >> things but are even unnecessary (it's working perfectly without those changes) >> here. > > Unfortunately this isn't enough to remove the alignment code for those > controllers. This is just once specific usecase. We need to figure out what > really goes wrong. > > Looks like 0 bytes is copied from sg list to bounce buffer when we want 512 > bytes copied. I don't have only 512 bytes cases, but also 100, 136, 424, 396, 144, 292. It's working anyway w/o any modifications. Why does it work w/o any modification? Do those chips really need any alignment? > Just noticed the alignment code assumes sg lists are used without > checking it first. > > Could you add the below code and test again, it should print more debugging info. Is there a way to compile this code external - w/o recompiling the whole kernel? Thanks Andreas ^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: USB2 / USB3 compatibility problems: xhci_hcd 0000:00:06.0: WARN Wrong bounce buffer write length: 0 != 512 2021-01-25 18:28 ` Mathias Nyman 2021-01-25 18:48 ` Andreas Hartmann @ 2021-01-25 20:06 ` Andreas Hartmann 2021-01-26 7:26 ` Andreas Hartmann 1 sibling, 1 reply; 17+ messages in thread From: Andreas Hartmann @ 2021-01-25 20:06 UTC (permalink / raw) To: Mathias Nyman, linux-usb [-- Attachment #1: Type: text/plain, Size: 1506 bytes --] Hello Mathias, On 25.01.21 at 19:28 Mathias Nyman wrote: > Hi > > On 25.1.2021 12.18, Andreas Hartmann wrote: >> >> Hello! >> >> Meanwhile I found the culprit: >> >> https://www.spinics.net/lists/linux-usb/msg141467.html >> and >> https://www.spinics.net/lists/linux-usb/msg141468.html >> >> Especially the last change breaks things here completely. After removing them >> by the attached patch, problems are gone and device works again as expected >> (I tested with the original 24 kB bulk size which was horribly broken w/o the >> attached patch). This means: the additional repair steps are not just breaking >> things but are even unnecessary (it's working perfectly without those changes) >> here. > > Unfortunately this isn't enough to remove the alignment code for those > controllers. This is just once specific usecase. We need to figure out what > really goes wrong. > > Looks like 0 bytes is copied from sg list to bounce buffer when we want 512 > bytes copied. Just noticed the alignment code assumes sg lists are used without > checking it first. > > Could you add the below code and test again, it should print more debugging info. See the attached file. That's the result of two times coping 1.3 GB via scp. As the transfer mostly breaks after the wrong alignments and because there isn't any further alignment needed at all, I didn't do more tests. Hope this helps. Most importantly it should be investigated, why there isn't any additional alignment needed at all. Thanks Andreas [-- Attachment #2: debug.txt --] [-- Type: text/plain, Size: 28573 bytes --] 2021-01-25T20:48:05.432669+01:00 localhost kernel: [ 219.779879] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:48:05.432696+01:00 localhost kernel: [ 219.779886] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:48:06.684039+01:00 localhost kernel: [ 221.031279] xhci_hcd 0000:05:00.3: Unaligned 244 bytes, buff len 7924 2021-01-25T20:48:06.684064+01:00 localhost kernel: [ 221.031283] xhci_hcd 0000:05:00.3: split align, new buff len 7680 2021-01-25T20:48:06.963774+01:00 localhost kernel: [ 221.311019] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:48:06.963797+01:00 localhost kernel: [ 221.311023] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:48:07.544122+01:00 localhost kernel: [ 221.891370] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:48:07.544142+01:00 localhost kernel: [ 221.891374] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:48:14.059866+01:00 localhost kernel: [ 228.407127] xhci_hcd 0000:05:00.3: Unaligned 300 bytes, buff len 11052 2021-01-25T20:48:14.059890+01:00 localhost kernel: [ 228.407131] xhci_hcd 0000:05:00.3: split align, new buff len 10752 2021-01-25T20:48:14.253496+01:00 localhost kernel: [ 228.599397] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:48:14.253520+01:00 localhost kernel: [ 228.599401] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:48:15.133583+01:00 localhost kernel: [ 229.480857] xhci_hcd 0000:05:00.3: Unaligned 160 bytes, buff len 160 2021-01-25T20:48:15.133598+01:00 localhost kernel: [ 229.480860] xhci_hcd 0000:05:00.3: WARN Wrong bounce buffer write length: 0 != 512 2021-01-25T20:48:15.133599+01:00 localhost kernel: [ 229.480861] xhci_hcd 0000:05:00.3: urb->num_sgs 0 2021-01-25T20:48:15.133600+01:00 localhost kernel: [ 229.480862] xhci_hcd 0000:05:00.3: urb->num_mapped_sgs 0 2021-01-25T20:48:15.133600+01:00 localhost kernel: [ 229.480863] xhci_hcd 0000:05:00.3: urb->transfer_buffer_length 24900 2021-01-25T20:48:15.133601+01:00 localhost kernel: [ 229.480864] xhci_hcd 0000:05:00.3: enqd_len 0 2021-01-25T20:48:15.133601+01:00 localhost kernel: [ 229.480864] xhci_hcd 0000:05:00.3: max_pkt 512 2021-01-25T20:48:16.315613+01:00 localhost kernel: [ 230.662880] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:48:16.315639+01:00 localhost kernel: [ 230.662885] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:48:18.648749+01:00 localhost kernel: [ 232.996022] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:48:18.648773+01:00 localhost kernel: [ 232.996027] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:48:19.219018+01:00 localhost kernel: [ 233.566301] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:48:19.219043+01:00 localhost kernel: [ 233.566306] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:48:20.818958+01:00 localhost kernel: [ 235.166240] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:48:20.818986+01:00 localhost kernel: [ 235.166245] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:48:21.896537+01:00 localhost kernel: [ 236.243835] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:48:21.896558+01:00 localhost kernel: [ 236.243839] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:48:23.962820+01:00 localhost kernel: [ 238.310123] xhci_hcd 0000:05:00.3: Unaligned 232 bytes, buff len 6376 2021-01-25T20:48:23.962836+01:00 localhost kernel: [ 238.310127] xhci_hcd 0000:05:00.3: split align, new buff len 6144 2021-01-25T20:48:26.477497+01:00 localhost kernel: [ 240.822066] xhci_hcd 0000:05:00.3: Unaligned 288 bytes, buff len 12576 2021-01-25T20:48:26.477528+01:00 localhost kernel: [ 240.822072] xhci_hcd 0000:05:00.3: split align, new buff len 12288 2021-01-25T20:48:32.237504+01:00 localhost kernel: [ 246.583028] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:48:32.237529+01:00 localhost kernel: [ 246.583032] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:48:32.609500+01:00 localhost kernel: [ 246.956710] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:48:32.609528+01:00 localhost kernel: [ 246.956715] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:48:33.384467+01:00 localhost kernel: [ 247.731802] xhci_hcd 0000:05:00.3: Unaligned 204 bytes, buff len 4812 2021-01-25T20:48:33.384489+01:00 localhost kernel: [ 247.731808] xhci_hcd 0000:05:00.3: split align, new buff len 4608 2021-01-25T20:48:36.168882+01:00 localhost kernel: [ 250.516217] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:48:36.168905+01:00 localhost kernel: [ 250.516221] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:48:36.390007+01:00 localhost kernel: [ 250.737347] xhci_hcd 0000:05:00.3: Unaligned 368 bytes, buff len 15728 2021-01-25T20:48:36.390031+01:00 localhost kernel: [ 250.737351] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:48:36.888094+01:00 localhost kernel: [ 251.235422] xhci_hcd 0000:05:00.3: Unaligned 280 bytes, buff len 9496 2021-01-25T20:48:36.888122+01:00 localhost kernel: [ 251.235426] xhci_hcd 0000:05:00.3: split align, new buff len 9216 2021-01-25T20:48:39.457905+01:00 localhost kernel: [ 253.805243] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:48:39.457933+01:00 localhost kernel: [ 253.805247] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:48:44.096031+01:00 localhost kernel: [ 258.443399] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:48:44.096051+01:00 localhost kernel: [ 258.443401] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:48:47.166279+01:00 localhost kernel: [ 261.513632] xhci_hcd 0000:05:00.3: Unaligned 280 bytes, buff len 15640 2021-01-25T20:48:47.166307+01:00 localhost kernel: [ 261.513636] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:48:47.573499+01:00 localhost kernel: [ 261.919729] xhci_hcd 0000:05:00.3: Unaligned 368 bytes, buff len 15728 2021-01-25T20:48:47.573523+01:00 localhost kernel: [ 261.919733] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:48:50.720531+01:00 localhost kernel: [ 265.067893] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:48:50.720559+01:00 localhost kernel: [ 265.067897] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:48:54.182808+01:00 localhost kernel: [ 268.278671] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:48:54.182834+01:00 localhost kernel: [ 268.278677] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:48:54.401591+01:00 localhost kernel: [ 268.480636] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:48:54.401616+01:00 localhost kernel: [ 268.480641] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:48:56.100003+01:00 localhost kernel: [ 270.048395] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:48:56.100028+01:00 localhost kernel: [ 270.048400] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:48:56.312818+01:00 localhost kernel: [ 270.250076] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:48:56.312842+01:00 localhost kernel: [ 270.250081] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:48:56.501147+01:00 localhost kernel: [ 270.438530] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:48:56.501171+01:00 localhost kernel: [ 270.438535] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:49:03.551863+01:00 localhost kernel: [ 277.489761] xhci_hcd 0000:05:00.3: Unaligned 368 bytes, buff len 15728 2021-01-25T20:49:03.551888+01:00 localhost kernel: [ 277.489765] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:49:04.137489+01:00 localhost kernel: [ 278.071863] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:49:04.137512+01:00 localhost kernel: [ 278.071868] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:49:05.852773+01:00 localhost kernel: [ 279.790685] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:49:05.852794+01:00 localhost kernel: [ 279.790690] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:49:06.303813+01:00 localhost kernel: [ 280.241731] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:49:06.303837+01:00 localhost kernel: [ 280.241736] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:49:06.862751+01:00 localhost kernel: [ 280.800670] xhci_hcd 0000:05:00.3: Unaligned 280 bytes, buff len 15640 2021-01-25T20:49:06.862770+01:00 localhost kernel: [ 280.800675] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:49:08.366705+01:00 localhost kernel: [ 282.304624] xhci_hcd 0000:05:00.3: Unaligned 280 bytes, buff len 15640 2021-01-25T20:49:08.366729+01:00 localhost kernel: [ 282.304629] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:49:09.358719+01:00 localhost kernel: [ 283.296633] xhci_hcd 0000:05:00.3: Unaligned 144 bytes, buff len 144 2021-01-25T20:49:09.358741+01:00 localhost kernel: [ 283.296638] xhci_hcd 0000:05:00.3: WARN Wrong bounce buffer write length: 0 != 512 2021-01-25T20:49:09.358743+01:00 localhost kernel: [ 283.296640] xhci_hcd 0000:05:00.3: urb->num_sgs 0 2021-01-25T20:49:09.358745+01:00 localhost kernel: [ 283.296642] xhci_hcd 0000:05:00.3: urb->num_mapped_sgs 0 2021-01-25T20:49:09.358746+01:00 localhost kernel: [ 283.296644] xhci_hcd 0000:05:00.3: urb->transfer_buffer_length 6228 2021-01-25T20:49:09.358747+01:00 localhost kernel: [ 283.296646] xhci_hcd 0000:05:00.3: enqd_len 0 2021-01-25T20:49:09.358748+01:00 localhost kernel: [ 283.296647] xhci_hcd 0000:05:00.3: max_pkt 512 2021-01-25T20:49:09.559923+01:00 localhost kernel: [ 283.497856] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:49:09.559943+01:00 localhost kernel: [ 283.497859] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:49:10.249484+01:00 localhost kernel: [ 284.187186] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:49:10.249504+01:00 localhost kernel: [ 284.187189] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:49:13.310514+01:00 localhost kernel: [ 287.248469] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:49:13.310530+01:00 localhost kernel: [ 287.248471] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:49:14.732785+01:00 localhost kernel: [ 288.670725] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:49:14.732809+01:00 localhost kernel: [ 288.670730] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:49:17.650404+01:00 localhost kernel: [ 291.588351] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:49:17.650427+01:00 localhost kernel: [ 291.588356] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:49:18.052537+01:00 localhost kernel: [ 291.990508] xhci_hcd 0000:05:00.3: Unaligned 280 bytes, buff len 15640 2021-01-25T20:49:18.052551+01:00 localhost kernel: [ 291.990510] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:49:18.777480+01:00 localhost kernel: [ 292.715323] xhci_hcd 0000:05:00.3: Unaligned 160 bytes, buff len 3232 2021-01-25T20:49:18.777494+01:00 localhost kernel: [ 292.715325] xhci_hcd 0000:05:00.3: split align, new buff len 3072 2021-01-25T20:49:20.845487+01:00 localhost kernel: [ 294.781639] xhci_hcd 0000:05:00.3: Unaligned 368 bytes, buff len 15728 2021-01-25T20:49:20.845507+01:00 localhost kernel: [ 294.781642] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:49:21.033620+01:00 localhost kernel: [ 294.971593] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:49:21.033641+01:00 localhost kernel: [ 294.971597] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:49:22.847230+01:00 localhost kernel: [ 296.785201] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:49:22.847254+01:00 localhost kernel: [ 296.785206] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:49:26.653505+01:00 localhost kernel: [ 300.589168] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:49:26.653536+01:00 localhost kernel: [ 300.589172] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:49:28.068406+01:00 localhost kernel: [ 302.006391] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:49:28.068431+01:00 localhost kernel: [ 302.006396] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:49:29.014069+01:00 localhost kernel: [ 302.952052] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:49:29.014093+01:00 localhost kernel: [ 302.952057] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:49:29.942425+01:00 localhost kernel: [ 303.880414] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:49:29.942447+01:00 localhost kernel: [ 303.880419] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:49:30.942988+01:00 localhost kernel: [ 304.880987] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:49:30.943012+01:00 localhost kernel: [ 304.880992] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:52:54.649241+01:00 localhost kernel: [ 508.586898] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:52:54.649267+01:00 localhost kernel: [ 508.586903] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:52:55.917197+01:00 localhost kernel: [ 509.854848] xhci_hcd 0000:05:00.3: Unaligned 468 bytes, buff len 23508 2021-01-25T20:52:55.917223+01:00 localhost kernel: [ 509.854854] xhci_hcd 0000:05:00.3: split align, new buff len 23040 2021-01-25T20:52:56.208083+01:00 localhost kernel: [ 510.145741] xhci_hcd 0000:05:00.3: Unaligned 280 bytes, buff len 15640 2021-01-25T20:52:56.208110+01:00 localhost kernel: [ 510.145746] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:52:56.506004+01:00 localhost kernel: [ 510.443649] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:52:56.506030+01:00 localhost kernel: [ 510.443654] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:52:57.006628+01:00 localhost kernel: [ 510.944273] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:52:57.006655+01:00 localhost kernel: [ 510.944278] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:53:01.084710+01:00 localhost kernel: [ 515.022362] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:53:01.084736+01:00 localhost kernel: [ 515.022368] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:53:07.813507+01:00 localhost kernel: [ 521.750591] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:53:07.813541+01:00 localhost kernel: [ 521.750597] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:53:08.337508+01:00 localhost kernel: [ 522.272737] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:53:08.337538+01:00 localhost kernel: [ 522.272742] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:53:08.741501+01:00 localhost kernel: [ 522.677834] xhci_hcd 0000:05:00.3: Unaligned 336 bytes, buff len 15696 2021-01-25T20:53:08.741525+01:00 localhost kernel: [ 522.677838] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:53:09.345505+01:00 localhost kernel: [ 523.279711] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:53:09.345535+01:00 localhost kernel: [ 523.279716] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:53:09.553507+01:00 localhost kernel: [ 523.488681] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:53:09.553538+01:00 localhost kernel: [ 523.488687] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:53:10.581501+01:00 localhost kernel: [ 524.518552] xhci_hcd 0000:05:00.3: Unaligned 280 bytes, buff len 15640 2021-01-25T20:53:10.581526+01:00 localhost kernel: [ 524.518557] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:53:11.022998+01:00 localhost kernel: [ 524.960689] xhci_hcd 0000:05:00.3: Unaligned 368 bytes, buff len 15728 2021-01-25T20:53:11.023021+01:00 localhost kernel: [ 524.960694] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:53:11.866753+01:00 localhost kernel: [ 525.804428] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:53:11.866777+01:00 localhost kernel: [ 525.804433] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:53:14.299164+01:00 localhost kernel: [ 528.236850] xhci_hcd 0000:05:00.3: Unaligned 252 bytes, buff len 7932 2021-01-25T20:53:14.299190+01:00 localhost kernel: [ 528.236855] xhci_hcd 0000:05:00.3: split align, new buff len 7680 2021-01-25T20:53:17.021509+01:00 localhost kernel: [ 530.957559] xhci_hcd 0000:05:00.3: Unaligned 168 bytes, buff len 3240 2021-01-25T20:53:17.021534+01:00 localhost kernel: [ 530.957564] xhci_hcd 0000:05:00.3: split align, new buff len 3072 2021-01-25T20:53:17.200557+01:00 localhost kernel: [ 531.138252] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:53:17.200584+01:00 localhost kernel: [ 531.138257] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:53:17.376444+01:00 localhost kernel: [ 531.314128] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:53:17.376470+01:00 localhost kernel: [ 531.314133] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:53:21.103355+01:00 localhost kernel: [ 535.041064] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:53:21.103377+01:00 localhost kernel: [ 535.041068] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:53:22.681712+01:00 localhost kernel: [ 536.615630] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:53:22.681738+01:00 localhost kernel: [ 536.615635] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:53:23.262498+01:00 localhost kernel: [ 537.200175] xhci_hcd 0000:05:00.3: Unaligned 144 bytes, buff len 144 2021-01-25T20:53:23.262524+01:00 localhost kernel: [ 537.200181] xhci_hcd 0000:05:00.3: WARN Wrong bounce buffer write length: 0 != 512 2021-01-25T20:53:23.262527+01:00 localhost kernel: [ 537.200183] xhci_hcd 0000:05:00.3: urb->num_sgs 0 2021-01-25T20:53:23.262529+01:00 localhost kernel: [ 537.200185] xhci_hcd 0000:05:00.3: urb->num_mapped_sgs 0 2021-01-25T20:53:23.262530+01:00 localhost kernel: [ 537.200187] xhci_hcd 0000:05:00.3: urb->transfer_buffer_length 24900 2021-01-25T20:53:23.262532+01:00 localhost kernel: [ 537.200188] xhci_hcd 0000:05:00.3: enqd_len 0 2021-01-25T20:53:23.262533+01:00 localhost kernel: [ 537.200190] xhci_hcd 0000:05:00.3: max_pkt 512 2021-01-25T20:53:23.685505+01:00 localhost kernel: [ 537.622567] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:53:23.685757+01:00 localhost kernel: [ 537.622572] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:53:23.881468+01:00 localhost kernel: [ 537.819157] xhci_hcd 0000:05:00.3: Unaligned 200 bytes, buff len 3272 2021-01-25T20:53:23.881492+01:00 localhost kernel: [ 537.819163] xhci_hcd 0000:05:00.3: split align, new buff len 3072 2021-01-25T20:53:26.398176+01:00 localhost kernel: [ 540.335857] xhci_hcd 0000:05:00.3: Unaligned 248 bytes, buff len 9464 2021-01-25T20:53:26.398203+01:00 localhost kernel: [ 540.335862] xhci_hcd 0000:05:00.3: split align, new buff len 9216 2021-01-25T20:53:29.086359+01:00 localhost kernel: [ 543.024087] xhci_hcd 0000:05:00.3: Unaligned 392 bytes, buff len 18824 2021-01-25T20:53:29.086380+01:00 localhost kernel: [ 543.024091] xhci_hcd 0000:05:00.3: split align, new buff len 18432 2021-01-25T20:53:29.489512+01:00 localhost kernel: [ 543.425986] xhci_hcd 0000:05:00.3: Unaligned 360 bytes, buff len 15720 2021-01-25T20:53:29.489539+01:00 localhost kernel: [ 543.425991] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:53:30.578180+01:00 localhost kernel: [ 544.515887] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:53:30.578211+01:00 localhost kernel: [ 544.515892] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:53:33.416061+01:00 localhost kernel: [ 547.353782] xhci_hcd 0000:05:00.3: Unaligned 420 bytes, buff len 20388 2021-01-25T20:53:33.416089+01:00 localhost kernel: [ 547.353788] xhci_hcd 0000:05:00.3: split align, new buff len 19968 2021-01-25T20:53:34.081496+01:00 localhost kernel: [ 548.017944] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:53:34.081780+01:00 localhost kernel: [ 548.017949] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:53:34.621505+01:00 localhost kernel: [ 548.559085] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:53:34.621532+01:00 localhost kernel: [ 548.559089] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:53:37.834070+01:00 localhost kernel: [ 551.771798] xhci_hcd 0000:05:00.3: Unaligned 340 bytes, buff len 14164 2021-01-25T20:53:37.834100+01:00 localhost kernel: [ 551.771803] xhci_hcd 0000:05:00.3: split align, new buff len 13824 2021-01-25T20:53:38.449501+01:00 localhost kernel: [ 552.384534] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:53:38.449527+01:00 localhost kernel: [ 552.384539] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:53:45.565760+01:00 localhost kernel: [ 559.503498] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:53:45.565790+01:00 localhost kernel: [ 559.503503] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:53:47.137570+01:00 localhost kernel: [ 561.075199] xhci_hcd 0000:05:00.3: Unaligned 168 bytes, buff len 168 2021-01-25T20:53:47.137594+01:00 localhost kernel: [ 561.075205] xhci_hcd 0000:05:00.3: WARN Wrong bounce buffer write length: 0 != 512 2021-01-25T20:53:47.137597+01:00 localhost kernel: [ 561.075208] xhci_hcd 0000:05:00.3: urb->num_sgs 0 2021-01-25T20:53:47.137599+01:00 localhost kernel: [ 561.075210] xhci_hcd 0000:05:00.3: urb->num_mapped_sgs 0 2021-01-25T20:53:47.137603+01:00 localhost kernel: [ 561.075212] xhci_hcd 0000:05:00.3: urb->transfer_buffer_length 1560 2021-01-25T20:53:47.137605+01:00 localhost kernel: [ 561.075214] xhci_hcd 0000:05:00.3: enqd_len 0 2021-01-25T20:53:47.137606+01:00 localhost kernel: [ 561.075215] xhci_hcd 0000:05:00.3: max_pkt 512 2021-01-25T20:53:51.525297+01:00 localhost kernel: [ 565.463059] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:53:51.525320+01:00 localhost kernel: [ 565.463063] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:53:54.331675+01:00 localhost kernel: [ 568.269446] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:53:54.331699+01:00 localhost kernel: [ 568.269450] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:53:56.588689+01:00 localhost kernel: [ 570.526439] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:53:56.588714+01:00 localhost kernel: [ 570.526445] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:54:01.622038+01:00 localhost kernel: [ 575.559798] xhci_hcd 0000:05:00.3: Unaligned 340 bytes, buff len 14164 2021-01-25T20:54:01.622065+01:00 localhost kernel: [ 575.559804] xhci_hcd 0000:05:00.3: split align, new buff len 13824 2021-01-25T20:54:03.807069+01:00 localhost kernel: [ 577.744837] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:54:03.807094+01:00 localhost kernel: [ 577.744843] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:54:04.133080+01:00 localhost kernel: [ 578.070862] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:54:04.133109+01:00 localhost kernel: [ 578.070867] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:54:04.601587+01:00 localhost kernel: [ 578.539362] xhci_hcd 0000:05:00.3: Unaligned 220 bytes, buff len 4828 2021-01-25T20:54:04.601614+01:00 localhost kernel: [ 578.539367] xhci_hcd 0000:05:00.3: split align, new buff len 4608 2021-01-25T20:54:07.485308+01:00 localhost kernel: [ 581.423106] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:54:07.485329+01:00 localhost kernel: [ 581.423110] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:54:08.049501+01:00 localhost kernel: [ 581.985364] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:54:08.049529+01:00 localhost kernel: [ 581.985368] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:54:08.633543+01:00 localhost kernel: [ 582.569227] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:54:08.633587+01:00 localhost kernel: [ 582.569235] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:54:09.197516+01:00 localhost kernel: [ 583.131888] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:54:09.197539+01:00 localhost kernel: [ 583.131893] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:54:18.825193+01:00 localhost kernel: [ 592.763004] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:54:18.825217+01:00 localhost kernel: [ 592.763008] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:54:19.191806+01:00 localhost kernel: [ 593.129517] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:54:19.191833+01:00 localhost kernel: [ 593.129522] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:54:20.256271+01:00 localhost kernel: [ 594.194106] xhci_hcd 0000:05:00.3: Unaligned 156 bytes, buff len 1692 2021-01-25T20:54:20.256300+01:00 localhost kernel: [ 594.194111] xhci_hcd 0000:05:00.3: split align, new buff len 1536 2021-01-25T20:54:20.466527+01:00 localhost kernel: [ 594.404144] xhci_hcd 0000:05:00.3: Unaligned 368 bytes, buff len 18800 2021-01-25T20:54:20.466553+01:00 localhost kernel: [ 594.404149] xhci_hcd 0000:05:00.3: split align, new buff len 18432 2021-01-25T20:54:22.901256+01:00 localhost kernel: [ 596.839080] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:54:22.901284+01:00 localhost kernel: [ 596.839085] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:54:23.098582+01:00 localhost kernel: [ 597.036427] xhci_hcd 0000:05:00.3: Unaligned 388 bytes, buff len 17284 2021-01-25T20:54:23.098610+01:00 localhost kernel: [ 597.036432] xhci_hcd 0000:05:00.3: split align, new buff len 16896 2021-01-25T20:54:26.543491+01:00 localhost kernel: [ 600.481319] xhci_hcd 0000:05:00.3: Unaligned 376 bytes, buff len 15736 2021-01-25T20:54:26.543517+01:00 localhost kernel: [ 600.481324] xhci_hcd 0000:05:00.3: split align, new buff len 15360 2021-01-25T20:54:27.545714+01:00 localhost kernel: [ 601.481064] xhci_hcd 0000:05:00.3: Unaligned 160 bytes, buff len 160 2021-01-25T20:54:27.545740+01:00 localhost kernel: [ 601.481070] xhci_hcd 0000:05:00.3: WARN Wrong bounce buffer write length: 0 != 512 2021-01-25T20:54:27.545742+01:00 localhost kernel: [ 601.481074] xhci_hcd 0000:05:00.3: urb->num_sgs 0 2021-01-25T20:54:27.545744+01:00 localhost kernel: [ 601.481076] xhci_hcd 0000:05:00.3: urb->num_mapped_sgs 0 2021-01-25T20:54:27.545745+01:00 localhost kernel: [ 601.481079] xhci_hcd 0000:05:00.3: urb->transfer_buffer_length 24900 2021-01-25T20:54:27.545746+01:00 localhost kernel: [ 601.481082] xhci_hcd 0000:05:00.3: enqd_len 0 2021-01-25T20:54:27.545748+01:00 localhost kernel: [ 601.481084] xhci_hcd 0000:05:00.3: max_pkt 512 ^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: USB2 / USB3 compatibility problems: xhci_hcd 0000:00:06.0: WARN Wrong bounce buffer write length: 0 != 512 2021-01-25 20:06 ` Andreas Hartmann @ 2021-01-26 7:26 ` Andreas Hartmann 2021-01-26 14:11 ` Mathias Nyman 0 siblings, 1 reply; 17+ messages in thread From: Andreas Hartmann @ 2021-01-26 7:26 UTC (permalink / raw) To: Mathias Nyman, linux-usb On 25.01.21 at 21:06 Andreas Hartmann wrote: > Hello Mathias, > > On 25.01.21 at 19:28 Mathias Nyman wrote: >> Hi >> >> On 25.1.2021 12.18, Andreas Hartmann wrote: >>> >>> Hello! >>> >>> Meanwhile I found the culprit: >>> >>> https://www.spinics.net/lists/linux-usb/msg141467.html >>> and >>> https://www.spinics.net/lists/linux-usb/msg141468.html >>> >>> Especially the last change breaks things here completely. After removing them >>> by the attached patch, problems are gone and device works again as expected >>> (I tested with the original 24 kB bulk size which was horribly broken w/o the >>> attached patch). This means: the additional repair steps are not just breaking >>> things but are even unnecessary (it's working perfectly without those changes) >>> here. >> >> Unfortunately this isn't enough to remove the alignment code for those >> controllers. This is just once specific usecase. We need to figure out what >> really goes wrong. >> >> Looks like 0 bytes is copied from sg list to bounce buffer when we want 512 >> bytes copied. Just noticed the alignment code assumes sg lists are used without >> checking it first. >> >> Could you add the below code and test again, it should print more debugging info. > > See the attached file. That's the result of two times coping 1.3 GB via scp. > > As the transfer mostly breaks after the wrong alignments and because > there isn't any further alignment needed at all, I didn't do more tests. > Hope this helps. Most importantly it should be investigated, why there > isn't any additional alignment needed at all. I'm not sure if it's important for you to know: The driver doesn't use struct scatterlist or num_mapped_sgs at all (if it's meant to be used by the sender at all). But it sets URB_NO_TRANSFER_DMA_MAP (for data transfer among others). Mlme packets are sent w/o bulk and w/o setting URB_NO_TRANSFER_DMA_MAP. All other packets are sent with URB_NO_TRANSFER_DMA_MAP turned on. Thanks Andreas ^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: USB2 / USB3 compatibility problems: xhci_hcd 0000:00:06.0: WARN Wrong bounce buffer write length: 0 != 512 2021-01-26 7:26 ` Andreas Hartmann @ 2021-01-26 14:11 ` Mathias Nyman 2021-01-26 17:29 ` Mathias Nyman 0 siblings, 1 reply; 17+ messages in thread From: Mathias Nyman @ 2021-01-26 14:11 UTC (permalink / raw) To: Andreas Hartmann, linux-usb On 26.1.2021 9.26, Andreas Hartmann wrote: > > On 25.01.21 at 21:06 Andreas Hartmann wrote: >> Hello Mathias, >> >> On 25.01.21 at 19:28 Mathias Nyman wrote: >>> Hi >>> >>> On 25.1.2021 12.18, Andreas Hartmann wrote: >>>> >>>> Hello! >>>> >>>> Meanwhile I found the culprit: >>>> >>>> https://www.spinics.net/lists/linux-usb/msg141467.html >>>> and >>>> https://www.spinics.net/lists/linux-usb/msg141468.html >>>> >>>> Especially the last change breaks things here completely. After removing them >>>> by the attached patch, problems are gone and device works again as expected >>>> (I tested with the original 24 kB bulk size which was horribly broken w/o the >>>> attached patch). This means: the additional repair steps are not just breaking >>>> things but are even unnecessary (it's working perfectly without those changes) >>>> here. >>> >>> Unfortunately this isn't enough to remove the alignment code for those >>> controllers. This is just once specific usecase. We need to figure out what >>> really goes wrong. >>> >>> Looks like 0 bytes is copied from sg list to bounce buffer when we want 512 >>> bytes copied. Just noticed the alignment code assumes sg lists are used without >>> checking it first. >>> >>> Could you add the below code and test again, it should print more debugging info. >> >> See the attached file. That's the result of two times coping 1.3 GB via scp. >> >> As the transfer mostly breaks after the wrong alignments and because >> there isn't any further alignment needed at all, I didn't do more tests. >> Hope this helps. Most importantly it should be investigated, why there >> isn't any additional alignment needed at all. > > I'm not sure if it's important for you to know: The driver doesn't use struct scatterlist or num_mapped_sgs at all (if it's meant to be used by the sender at all). > > But it sets URB_NO_TRANSFER_DMA_MAP (for data transfer among others). > > Mlme packets are sent w/o bulk and w/o setting URB_NO_TRANSFER_DMA_MAP. All other packets are sent with URB_NO_TRANSFER_DMA_MAP turned on. > Ok, thanks, I see what's going on here. Short recap of xhci alignment requirements. 1. Data pointed to by a transfer request block (TRB) may not span 64k boundary 2. If a transfer contains several TRBs, and spans over two TRB ringbuffer segments, then the sum of the TRB data in the first segment must be a multiple of max packets in size. Code assumes that if transfer is split into several blocks,(TRBs) and a block in the middle of a transfer is smaller than max packet size, then it must be sg list. But this is not necessarily the case if data was already DMA mapped beforehand. Data might start just before a 64k boundary, causing first TRB to be less than packet size. I'll start implementing a fix for this. -Mathias ^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: USB2 / USB3 compatibility problems: xhci_hcd 0000:00:06.0: WARN Wrong bounce buffer write length: 0 != 512 2021-01-26 14:11 ` Mathias Nyman @ 2021-01-26 17:29 ` Mathias Nyman 2021-01-26 17:48 ` Andreas Hartmann 2021-01-26 21:16 ` Andreas Hartmann 0 siblings, 2 replies; 17+ messages in thread From: Mathias Nyman @ 2021-01-26 17:29 UTC (permalink / raw) To: Andreas Hartmann, linux-usb >> I'm not sure if it's important for you to know: The driver doesn't use struct scatterlist or num_mapped_sgs at all (if it's meant to be used by the sender at all). >> >> But it sets URB_NO_TRANSFER_DMA_MAP (for data transfer among others). >> >> Mlme packets are sent w/o bulk and w/o setting URB_NO_TRANSFER_DMA_MAP. All other packets are sent with URB_NO_TRANSFER_DMA_MAP turned on. >> > > Ok, thanks, I see what's going on here. > > Short recap of xhci alignment requirements. > 1. Data pointed to by a transfer request block (TRB) may not span 64k boundary > 2. If a transfer contains several TRBs, and spans over two TRB ringbuffer > segments, then the sum of the TRB data in the first segment must be a > multiple of max packets in size. > > Code assumes that if transfer is split into several blocks,(TRBs) and a block > in the middle of a transfer is smaller than max packet size, then it must be sg list. > > But this is not necessarily the case if data was already DMA mapped beforehand. > Data might start just before a 64k boundary, causing first TRB to be less than > packet size. > > I'll start implementing a fix for this. Got a first iteration ready, any change you could try it out? Thanks -Mathias 8<--- diff --git a/drivers/usb/host/xhci-ring.c b/drivers/usb/host/xhci-ring.c index 5677b81c0915..8df30618aaf1 100644 --- a/drivers/usb/host/xhci-ring.c +++ b/drivers/usb/host/xhci-ring.c @@ -699,11 +699,16 @@ static void xhci_unmap_td_bounce_buffer(struct xhci_hcd *xhci, dma_unmap_single(dev, seg->bounce_dma, ring->bounce_buf_len, DMA_FROM_DEVICE); /* for in tranfers we need to copy the data from bounce to sg */ - len = sg_pcopy_from_buffer(urb->sg, urb->num_sgs, seg->bounce_buf, - seg->bounce_len, seg->bounce_offs); - if (len != seg->bounce_len) - xhci_warn(xhci, "WARN Wrong bounce buffer read length: %zu != %d\n", - len, seg->bounce_len); + if (urb->num_sgs) { + len = sg_pcopy_from_buffer(urb->sg, urb->num_sgs, seg->bounce_buf, + seg->bounce_len, seg->bounce_offs); + if (len != seg->bounce_len) + xhci_warn(xhci, "WARN Wrong bounce buffer read length: %zu != %d\n", + len, seg->bounce_len); + } else { + memcpy(urb->transfer_buffer + seg->bounce_offs, seg->bounce_buf, + seg->bounce_len); + } seg->bounce_len = 0; seg->bounce_offs = 0; } @@ -3275,12 +3280,16 @@ static int xhci_align_td(struct xhci_hcd *xhci, struct urb *urb, u32 enqd_len, /* create a max max_pkt sized bounce buffer pointed to by last trb */ if (usb_urb_dir_out(urb)) { - len = sg_pcopy_to_buffer(urb->sg, urb->num_sgs, - seg->bounce_buf, new_buff_len, enqd_len); - if (len != new_buff_len) - xhci_warn(xhci, - "WARN Wrong bounce buffer write length: %zu != %d\n", - len, new_buff_len); + if (urb->num_sgs) { + len = sg_pcopy_to_buffer(urb->sg, urb->num_sgs, + seg->bounce_buf, new_buff_len, enqd_len); + if (len != new_buff_len) + xhci_warn(xhci, "WARN Wrong bounce buffer write length: %zu != %d\n", + len, new_buff_len); + } else { + memcpy(seg->bounce_buf, urb->transfer_buffer + enqd_len, new_buff_len); + } + seg->bounce_dma = dma_map_single(dev, seg->bounce_buf, max_pkt, DMA_TO_DEVICE); } else { ^ permalink raw reply related [flat|nested] 17+ messages in thread
* Re: USB2 / USB3 compatibility problems: xhci_hcd 0000:00:06.0: WARN Wrong bounce buffer write length: 0 != 512 2021-01-26 17:29 ` Mathias Nyman @ 2021-01-26 17:48 ` Andreas Hartmann 2021-01-26 21:16 ` Andreas Hartmann 1 sibling, 0 replies; 17+ messages in thread From: Andreas Hartmann @ 2021-01-26 17:48 UTC (permalink / raw) To: Mathias Nyman, linux-usb Hello Mathias, I'll test it ASAP! Thanks Andreas On 26.01.21 at 18:29 Mathias Nyman wrote: > >>> I'm not sure if it's important for you to know: The driver doesn't use struct scatterlist or num_mapped_sgs at all (if it's meant to be used by the sender at all). >>> >>> But it sets URB_NO_TRANSFER_DMA_MAP (for data transfer among others). >>> >>> Mlme packets are sent w/o bulk and w/o setting URB_NO_TRANSFER_DMA_MAP. All other packets are sent with URB_NO_TRANSFER_DMA_MAP turned on. >>> >> >> Ok, thanks, I see what's going on here. >> >> Short recap of xhci alignment requirements. >> 1. Data pointed to by a transfer request block (TRB) may not span 64k boundary >> 2. If a transfer contains several TRBs, and spans over two TRB ringbuffer >> segments, then the sum of the TRB data in the first segment must be a >> multiple of max packets in size. >> >> Code assumes that if transfer is split into several blocks,(TRBs) and a block >> in the middle of a transfer is smaller than max packet size, then it must be sg list. >> >> But this is not necessarily the case if data was already DMA mapped beforehand. >> Data might start just before a 64k boundary, causing first TRB to be less than >> packet size. >> >> I'll start implementing a fix for this. > > Got a first iteration ready, > any change you could try it out? > > Thanks > -Mathias > > 8<--- > > diff --git a/drivers/usb/host/xhci-ring.c b/drivers/usb/host/xhci-ring.c > index 5677b81c0915..8df30618aaf1 100644 > --- a/drivers/usb/host/xhci-ring.c > +++ b/drivers/usb/host/xhci-ring.c > @@ -699,11 +699,16 @@ static void xhci_unmap_td_bounce_buffer(struct xhci_hcd *xhci, > dma_unmap_single(dev, seg->bounce_dma, ring->bounce_buf_len, > DMA_FROM_DEVICE); > /* for in tranfers we need to copy the data from bounce to sg */ > - len = sg_pcopy_from_buffer(urb->sg, urb->num_sgs, seg->bounce_buf, > - seg->bounce_len, seg->bounce_offs); > - if (len != seg->bounce_len) > - xhci_warn(xhci, "WARN Wrong bounce buffer read length: %zu != %d\n", > - len, seg->bounce_len); > + if (urb->num_sgs) { > + len = sg_pcopy_from_buffer(urb->sg, urb->num_sgs, seg->bounce_buf, > + seg->bounce_len, seg->bounce_offs); > + if (len != seg->bounce_len) > + xhci_warn(xhci, "WARN Wrong bounce buffer read length: %zu != %d\n", > + len, seg->bounce_len); > + } else { > + memcpy(urb->transfer_buffer + seg->bounce_offs, seg->bounce_buf, > + seg->bounce_len); > + } > seg->bounce_len = 0; > seg->bounce_offs = 0; > } > @@ -3275,12 +3280,16 @@ static int xhci_align_td(struct xhci_hcd *xhci, struct urb *urb, u32 enqd_len, > > /* create a max max_pkt sized bounce buffer pointed to by last trb */ > if (usb_urb_dir_out(urb)) { > - len = sg_pcopy_to_buffer(urb->sg, urb->num_sgs, > - seg->bounce_buf, new_buff_len, enqd_len); > - if (len != new_buff_len) > - xhci_warn(xhci, > - "WARN Wrong bounce buffer write length: %zu != %d\n", > - len, new_buff_len); > + if (urb->num_sgs) { > + len = sg_pcopy_to_buffer(urb->sg, urb->num_sgs, > + seg->bounce_buf, new_buff_len, enqd_len); > + if (len != new_buff_len) > + xhci_warn(xhci, "WARN Wrong bounce buffer write length: %zu != %d\n", > + len, new_buff_len); > + } else { > + memcpy(seg->bounce_buf, urb->transfer_buffer + enqd_len, new_buff_len); > + } > + > seg->bounce_dma = dma_map_single(dev, seg->bounce_buf, > max_pkt, DMA_TO_DEVICE); > } else { > ^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: USB2 / USB3 compatibility problems: xhci_hcd 0000:00:06.0: WARN Wrong bounce buffer write length: 0 != 512 2021-01-26 17:29 ` Mathias Nyman 2021-01-26 17:48 ` Andreas Hartmann @ 2021-01-26 21:16 ` Andreas Hartmann 2021-01-27 6:43 ` Andreas Hartmann 1 sibling, 1 reply; 17+ messages in thread From: Andreas Hartmann @ 2021-01-26 21:16 UTC (permalink / raw) To: Mathias Nyman, linux-usb Hello Mathias! On 26.01.21 at 18:29 Mathias Nyman wrote: > >>> I'm not sure if it's important for you to know: The driver doesn't use struct scatterlist or num_mapped_sgs at all (if it's meant to be used by the sender at all). >>> >>> But it sets URB_NO_TRANSFER_DMA_MAP (for data transfer among others). >>> >>> Mlme packets are sent w/o bulk and w/o setting URB_NO_TRANSFER_DMA_MAP. All other packets are sent with URB_NO_TRANSFER_DMA_MAP turned on. >>> >> >> Ok, thanks, I see what's going on here. >> >> Short recap of xhci alignment requirements. >> 1. Data pointed to by a transfer request block (TRB) may not span 64k boundary >> 2. If a transfer contains several TRBs, and spans over two TRB ringbuffer >> segments, then the sum of the TRB data in the first segment must be a >> multiple of max packets in size. >> >> Code assumes that if transfer is split into several blocks,(TRBs) and a block >> in the middle of a transfer is smaller than max packet size, then it must be sg list. >> >> But this is not necessarily the case if data was already DMA mapped beforehand. >> Data might start just before a 64k boundary, causing first TRB to be less than >> packet size. >> >> I'll start implementing a fix for this. > > Got a first iteration ready, > any change you could try it out? > > Thanks > -Mathias > > 8<--- > > diff --git a/drivers/usb/host/xhci-ring.c b/drivers/usb/host/xhci-ring.c > index 5677b81c0915..8df30618aaf1 100644 > --- a/drivers/usb/host/xhci-ring.c > +++ b/drivers/usb/host/xhci-ring.c > @@ -699,11 +699,16 @@ static void xhci_unmap_td_bounce_buffer(struct xhci_hcd *xhci, > dma_unmap_single(dev, seg->bounce_dma, ring->bounce_buf_len, > DMA_FROM_DEVICE); > /* for in tranfers we need to copy the data from bounce to sg */ > - len = sg_pcopy_from_buffer(urb->sg, urb->num_sgs, seg->bounce_buf, > - seg->bounce_len, seg->bounce_offs); > - if (len != seg->bounce_len) > - xhci_warn(xhci, "WARN Wrong bounce buffer read length: %zu != %d\n", > - len, seg->bounce_len); > + if (urb->num_sgs) { > + len = sg_pcopy_from_buffer(urb->sg, urb->num_sgs, seg->bounce_buf, > + seg->bounce_len, seg->bounce_offs); > + if (len != seg->bounce_len) > + xhci_warn(xhci, "WARN Wrong bounce buffer read length: %zu != %d\n", > + len, seg->bounce_len); > + } else { > + memcpy(urb->transfer_buffer + seg->bounce_offs, seg->bounce_buf, > + seg->bounce_len); > + } > seg->bounce_len = 0; > seg->bounce_offs = 0; > } > @@ -3275,12 +3280,16 @@ static int xhci_align_td(struct xhci_hcd *xhci, struct urb *urb, u32 enqd_len, > > /* create a max max_pkt sized bounce buffer pointed to by last trb */ > if (usb_urb_dir_out(urb)) { > - len = sg_pcopy_to_buffer(urb->sg, urb->num_sgs, > - seg->bounce_buf, new_buff_len, enqd_len); > - if (len != new_buff_len) > - xhci_warn(xhci, > - "WARN Wrong bounce buffer write length: %zu != %d\n", > - len, new_buff_len); > + if (urb->num_sgs) { > + len = sg_pcopy_to_buffer(urb->sg, urb->num_sgs, > + seg->bounce_buf, new_buff_len, enqd_len); > + if (len != new_buff_len) > + xhci_warn(xhci, "WARN Wrong bounce buffer write length: %zu != %d\n", > + len, new_buff_len); > + } else { > + memcpy(seg->bounce_buf, urb->transfer_buffer + enqd_len, new_buff_len); > + } > + If I'm understanding it correctly, you're always creating a bounce buffer though it is not necessary (at least in my case - my test patch proofed, that no changes at all are necessary). Why aren't you checking for URB_NO_TRANSFER_DMA_MAP at the very beginning? Or is it your purpose to first basically test your new code path? That would be ok. I tested with the notebook (in both directions) - it seems to work - I didn't get any problems though I used 24 kB bulk packets. Throughput was unaltered high. I'm doing the same test tomorrow with the other USB 3.1 controller! > seg->bounce_dma = dma_map_single(dev, seg->bounce_buf, > max_pkt, DMA_TO_DEVICE); > } else { > Thanks Andreas ^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: USB2 / USB3 compatibility problems: xhci_hcd 0000:00:06.0: WARN Wrong bounce buffer write length: 0 != 512 2021-01-26 21:16 ` Andreas Hartmann @ 2021-01-27 6:43 ` Andreas Hartmann 2021-01-28 14:14 ` Mathias Nyman 0 siblings, 1 reply; 17+ messages in thread From: Andreas Hartmann @ 2021-01-27 6:43 UTC (permalink / raw) To: Mathias Nyman, linux-usb On 26.01.21 at 22:16 Andreas Hartmann wrote: > Hello Mathias! > > On 26.01.21 at 18:29 Mathias Nyman wrote: >> Got a first iteration ready, >> any change you could try it out? >> >> Thanks >> -Mathias >> >> 8<--- >> >> diff --git a/drivers/usb/host/xhci-ring.c b/drivers/usb/host/xhci-ring.c >> index 5677b81c0915..8df30618aaf1 100644 >> --- a/drivers/usb/host/xhci-ring.c >> +++ b/drivers/usb/host/xhci-ring.c >> @@ -699,11 +699,16 @@ static void xhci_unmap_td_bounce_buffer(struct xhci_hcd *xhci, >> dma_unmap_single(dev, seg->bounce_dma, ring->bounce_buf_len, >> DMA_FROM_DEVICE); >> /* for in tranfers we need to copy the data from bounce to sg */ >> - len = sg_pcopy_from_buffer(urb->sg, urb->num_sgs, seg->bounce_buf, >> - seg->bounce_len, seg->bounce_offs); >> - if (len != seg->bounce_len) >> - xhci_warn(xhci, "WARN Wrong bounce buffer read length: %zu != %d\n", >> - len, seg->bounce_len); >> + if (urb->num_sgs) { >> + len = sg_pcopy_from_buffer(urb->sg, urb->num_sgs, seg->bounce_buf, >> + seg->bounce_len, seg->bounce_offs); >> + if (len != seg->bounce_len) >> + xhci_warn(xhci, "WARN Wrong bounce buffer read length: %zu != %d\n", >> + len, seg->bounce_len); >> + } else { >> + memcpy(urb->transfer_buffer + seg->bounce_offs, seg->bounce_buf, >> + seg->bounce_len); >> + } >> seg->bounce_len = 0; >> seg->bounce_offs = 0; >> } >> @@ -3275,12 +3280,16 @@ static int xhci_align_td(struct xhci_hcd *xhci, struct urb *urb, u32 enqd_len, >> >> /* create a max max_pkt sized bounce buffer pointed to by last trb */ >> if (usb_urb_dir_out(urb)) { >> - len = sg_pcopy_to_buffer(urb->sg, urb->num_sgs, >> - seg->bounce_buf, new_buff_len, enqd_len); >> - if (len != new_buff_len) >> - xhci_warn(xhci, >> - "WARN Wrong bounce buffer write length: %zu != %d\n", >> - len, new_buff_len); >> + if (urb->num_sgs) { >> + len = sg_pcopy_to_buffer(urb->sg, urb->num_sgs, >> + seg->bounce_buf, new_buff_len, enqd_len); >> + if (len != new_buff_len) >> + xhci_warn(xhci, "WARN Wrong bounce buffer write length: %zu != %d\n", >> + len, new_buff_len); >> + } else { >> + memcpy(seg->bounce_buf, urb->transfer_buffer + enqd_len, new_buff_len); >> + } >> + > > If I'm understanding it correctly, you're always creating a bounce > buffer though it is not necessary (at least in my case - my test patch > proofed, that no changes at all are necessary). Why aren't you checking > for URB_NO_TRANSFER_DMA_MAP at the very beginning? Or is it your purpose > to first basically test your new code path? That would be ok. > > I tested with the notebook (in both directions) - it seems to work - I > didn't get any problems though I used 24 kB bulk packets. Throughput was > unaltered high. > > I'm doing the same test tomorrow with the other USB 3.1 controller! Successfully tested on the other USB 3.1 host. > >> seg->bounce_dma = dma_map_single(dev, seg->bounce_buf, >> max_pkt, DMA_TO_DEVICE); >> } else { >> > > Thanks > Andreas > ^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: USB2 / USB3 compatibility problems: xhci_hcd 0000:00:06.0: WARN Wrong bounce buffer write length: 0 != 512 2021-01-27 6:43 ` Andreas Hartmann @ 2021-01-28 14:14 ` Mathias Nyman 2021-01-28 17:01 ` Andreas Hartmann ` (2 more replies) 0 siblings, 3 replies; 17+ messages in thread From: Mathias Nyman @ 2021-01-28 14:14 UTC (permalink / raw) To: Andreas Hartmann, linux-usb >> If I'm understanding it correctly, you're always creating a bounce >> buffer though it is not necessary (at least in my case - my test patch >> proofed, that no changes at all are necessary). Why aren't you checking >> for URB_NO_TRANSFER_DMA_MAP at the very beginning? Or is it your purpose >> to first basically test your new code path? That would be ok. Bounce buffer is only used when there is no other way of meeting the xHCI alignment requirements. Worst case is once every 255 TRB, and for maximum 1024bytes. Each TRB can point to 64K of data. I can't go against the spec just because it doesn't cause issues in your two usecases. The overhead of the bounce buffer usage is so small there's no point in that kind of optimization. URB_NO_TRANSFER_DMA_MAP only indicates the data was DMA mapped before driver submitted the URB, so usb core does not need to map it. I was speculating that it could be a cause why data is so oddly aligned (urbs with data starting at less than 512 bytes from 64k boundary), and thus not meeting the xHC boundary and aligment requirements even if data is otherwise contiguous. xHC controller doesn't care who mapped the data, or if data is in a sg list or already contiguous in urb->transfer_buffer as long as we follow the aligment and boudary rules. Bug was that driver assumed the data that needed to be bounce buffered was in a sg list. Your cased proved it could be in urb->tranfer_buffer instead. >> >> I tested with the notebook (in both directions) - it seems to work - I >> didn't get any problems though I used 24 kB bulk packets. Throughput was >> unaltered high. >> >> I'm doing the same test tomorrow with the other USB 3.1 controller! > > Successfully tested on the other USB 3.1 host. > Thank you, much appreciated. I think I'll submit this patch as it is (with a proper commit message) can I add reported-by: Andreas Hartmann <andihartmann@01019freenet.de>, and tested-by: Andreas Hartmann <andihartmann@01019freenet.de> tags to the patch? -Mathias ^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: USB2 / USB3 compatibility problems: xhci_hcd 0000:00:06.0: WARN Wrong bounce buffer write length: 0 != 512 2021-01-28 14:14 ` Mathias Nyman @ 2021-01-28 17:01 ` Andreas Hartmann 2021-01-28 17:36 ` Andreas Hartmann 2021-01-28 18:27 ` Andreas Hartmann 2 siblings, 0 replies; 17+ messages in thread From: Andreas Hartmann @ 2021-01-28 17:01 UTC (permalink / raw) To: Mathias Nyman, linux-usb On 28.01.21 at 15:14 Mathias Nyman wrote: > >>> If I'm understanding it correctly, you're always creating a bounce >>> buffer though it is not necessary (at least in my case - my test patch >>> proofed, that no changes at all are necessary). Why aren't you checking >>> for URB_NO_TRANSFER_DMA_MAP at the very beginning? Or is it your purpose >>> to first basically test your new code path? That would be ok. > > Bounce buffer is only used when there is no other way of meeting the xHCI > alignment requirements. Worst case is once every 255 TRB, and for maximum 1024bytes. > Each TRB can point to 64K of data. This driver is from ~2012 - I'm not sure if they already considered USB 3.x at this time (comments to USB 2 and 1 can be found). *I* could not find any 512 Bytes related alignment code - but that doesn't say much. I tried to map the xHCI spec to the Linux urb API - I'm not sure how to map TRBs or TDs. Could a urb be understood as a TRB? > I can't go against the spec just because it doesn't cause issues in your > two usecases. The overhead of the bounce buffer usage is so small there's no > point in that kind of optimization. That's why I am a bit unsure at the moment regarding the result of the test. As I meanwhile know that it's working even w/o doing anything (by chance?), I can't say for sure that your patch is working as expected. The only thing I can say, is (see below): it doesn't hurt any more. > URB_NO_TRANSFER_DMA_MAP only indicates the data was DMA mapped before driver > submitted the URB, so usb core does not need to map it. > > I was speculating that it could be a cause why data is so oddly aligned > (urbs with data starting at less than 512 bytes from 64k boundary), and > thus not meeting the xHC boundary and aligment requirements even if data > is otherwise contiguous. > > xHC controller doesn't care who mapped the data, or if data is in a sg list > or already contiguous in urb->transfer_buffer as long as we follow > the aligment and boudary rules. > > Bug was that driver assumed the data that needed to be bounce > buffered was in a sg list. Your cased proved it could be in > urb->transfer_buffer instead. That's true for sure: the driver fills the data into transfer_buffer (it uses usb_fill_bulk_urb). >>> I tested with the notebook (in both directions) - it seems to work - I >>> didn't get any problems though I used 24 kB bulk packets. Throughput was >>> unaltered high. >>> >>> I'm doing the same test tomorrow with the other USB 3.1 controller! >> >> Successfully tested on the other USB 3.1 host. >> > > Thank you, much appreciated. > > I think I'll submit this patch as it is (with a proper commit message) > can I add reported-by: Andreas Hartmann <andihartmann@01019freenet.de>, and > tested-by: Andreas Hartmann <andihartmann@01019freenet.de> tags to the patch? That's OK for me. Thanks Andreas ^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: USB2 / USB3 compatibility problems: xhci_hcd 0000:00:06.0: WARN Wrong bounce buffer write length: 0 != 512 2021-01-28 14:14 ` Mathias Nyman 2021-01-28 17:01 ` Andreas Hartmann @ 2021-01-28 17:36 ` Andreas Hartmann 2021-01-28 18:27 ` Andreas Hartmann 2 siblings, 0 replies; 17+ messages in thread From: Andreas Hartmann @ 2021-01-28 17:36 UTC (permalink / raw) To: Mathias Nyman, linux-usb Hello Mathias, On 28.01.21 at 15:14 Mathias Nyman wrote: > > I think I'll submit this patch as it is (with a proper commit message) > can I add reported-by: Andreas Hartmann <andihartmann@01019freenet.de>, and > tested-by: Andreas Hartmann <andihartmann@01019freenet.de> tags to the patch? I forgot: Would it be possible to add the warning about wrong bounce buffer write length to the transfer_buffer-case, too? Thanks Andreas ^ permalink raw reply [flat|nested] 17+ messages in thread
* Re: USB2 / USB3 compatibility problems: xhci_hcd 0000:00:06.0: WARN Wrong bounce buffer write length: 0 != 512 2021-01-28 14:14 ` Mathias Nyman 2021-01-28 17:01 ` Andreas Hartmann 2021-01-28 17:36 ` Andreas Hartmann @ 2021-01-28 18:27 ` Andreas Hartmann 2 siblings, 0 replies; 17+ messages in thread From: Andreas Hartmann @ 2021-01-28 18:27 UTC (permalink / raw) To: Mathias Nyman, linux-usb Hello Mathias, out of curiosity: could the same happen, too, on the receive side? I can see a similar check in static void xhci_unmap_td_bounce_buffer. rt5572sta e.g. uses for receiving urb->transfer_buffer, too. I can see no problems at all for this path at the moment (not even a warning) - but couldn't this just be chance? Thanks Michael ^ permalink raw reply [flat|nested] 17+ messages in thread
end of thread, other threads:[~2021-01-28 18:30 UTC | newest] Thread overview: 17+ messages (download: mbox.gz follow: Atom feed -- links below jump to the message on this page -- 2021-01-22 8:06 USB2 / USB3 compatibility problems: xhci_hcd 0000:00:06.0: WARN Wrong bounce buffer write length: 0 != 512 Andreas Hartmann 2021-01-22 8:09 ` Andreas Hartmann 2021-01-24 17:28 ` Andreas Hartmann 2021-01-25 10:18 ` Andreas Hartmann 2021-01-25 18:28 ` Mathias Nyman 2021-01-25 18:48 ` Andreas Hartmann 2021-01-25 20:06 ` Andreas Hartmann 2021-01-26 7:26 ` Andreas Hartmann 2021-01-26 14:11 ` Mathias Nyman 2021-01-26 17:29 ` Mathias Nyman 2021-01-26 17:48 ` Andreas Hartmann 2021-01-26 21:16 ` Andreas Hartmann 2021-01-27 6:43 ` Andreas Hartmann 2021-01-28 14:14 ` Mathias Nyman 2021-01-28 17:01 ` Andreas Hartmann 2021-01-28 17:36 ` Andreas Hartmann 2021-01-28 18:27 ` Andreas Hartmann
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox