From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on aws-us-west-2-korg-lkml-1.web.codeaurora.org X-Spam-Level: X-Spam-Status: No, score=-5.1 required=3.0 tests=BAYES_00,DKIM_INVALID, DKIM_SIGNED,HEADER_FROM_DIFFERENT_DOMAINS,MAILING_LIST_MULTI,NICE_REPLY_A, SPF_HELO_NONE,SPF_PASS,USER_AGENT_SANE_1 autolearn=no autolearn_force=no version=3.4.0 Received: from mail.kernel.org (mail.kernel.org [198.145.29.99]) by smtp.lore.kernel.org (Postfix) with ESMTP id 35663C433DB for ; Sun, 24 Jan 2021 17:29:38 +0000 (UTC) Received: from vger.kernel.org (vger.kernel.org [23.128.96.18]) by mail.kernel.org (Postfix) with ESMTP id F346E22D58 for ; Sun, 24 Jan 2021 17:29:37 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1725789AbhAXR3T (ORCPT ); Sun, 24 Jan 2021 12:29:19 -0500 Received: from lindbergh.monkeyblade.net ([23.128.96.19]:57540 "EHLO lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1725968AbhAXR3K (ORCPT ); Sun, 24 Jan 2021 12:29:10 -0500 Received: from mout1.freenet.de (mout1.freenet.de [IPv6:2001:748:100:40::2:3]) by lindbergh.monkeyblade.net (Postfix) with ESMTPS id A091FC061573 for ; Sun, 24 Jan 2021 09:28:14 -0800 (PST) Received: from [195.4.92.120] (helo=sub1.freenet.de) by mout1.freenet.de with esmtpa (ID andihartmann@freenet.de) (port 25) (Exim 4.92 #3) id 1l3jBL-0002dx-94; Sun, 24 Jan 2021 18:28:11 +0100 DKIM-Signature: v=1; a=rsa-sha256; q=dns/txt; c=relaxed/relaxed; d=01019freenet.de; s=mjaymdexmjqk; h=Content-Transfer-Encoding:Content-Type: In-Reply-To:MIME-Version:Date:Message-ID:Subject:References:To:From:Sender: Reply-To:Cc:Content-ID:Content-Description:Resent-Date:Resent-From: Resent-Sender:Resent-To:Resent-Cc:Resent-Message-ID:List-Id:List-Help: List-Unsubscribe:List-Subscribe:List-Post:List-Owner:List-Archive; bh=CZEiwlbX+lreH9o2nWyYKdjGBY6J+eqnGThsv5HsJQQ=; b=R3RQ3lYAoALBYwfg1JfqWtBbAs Yx7ymBA5MNprtR3ebXGZELbnoZ/K1SDxBEtVmcmyCBs+HqTBeyIoCQpUjpuXS9GCDABvQR7dNnDRA zsSF/q3TYjVb9E6ommsVvXK8I6pJlEp5707kM5Ax9C1k6Vr+aqoNtDZwsOXQgfubQ+j/Oof5ZJjvI U7bAg62ynx4PcDwFiMA/pUZ80FVJvREmcVIB8/hmhjHwAxXZjt5RgLkq1g/GOwaZ2jXxQiWbigWbY GsIU87vbh2s5OvjHi8N08WhBBhXFSlHAhdf3Q2jP4Lyqmr/kNTipNuZBuzqEvc5j8hMkt09Eb+gn0 EEMnprKQ==; Received: from p200300de573c8400505400fffe15ac42.dip0.t-ipconnect.de ([2003:de:573c:8400:5054:ff:fe15:ac42]:48472 helo=mail.maya.org) by sub1.freenet.de with esmtpsa (ID andihartmann@freenet.de) (TLSv1.2:ECDHE-RSA-AES128-GCM-SHA256:128) (port 465) (Exim 4.92 #3) id 1l3jBL-0003Mp-5v; Sun, 24 Jan 2021 18:28:11 +0100 Received: internal info suppressed From: Andreas Hartmann To: linux-usb@vger.kernel.org, mathias.nyman@linux.intel.com References: <3b4e35d2-9508-e0aa-eaf8-32e524ad81c4@01019freenet.de> <756e7b88-1142-4758-b8f7-a8eaf510b422@01019freenet.de> Subject: Re: USB2 / USB3 compatibility problems: xhci_hcd 0000:00:06.0: WARN Wrong bounce buffer write length: 0 != 512 Message-ID: Date: Sun, 24 Jan 2021 18:28:08 +0100 User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:78.0) Gecko/20100101 Thunderbird/78.6.1 MIME-Version: 1.0 In-Reply-To: <756e7b88-1142-4758-b8f7-a8eaf510b422@01019freenet.de> Content-Type: text/plain; charset=utf-8; format=flowed Content-Language: en-US Content-Transfer-Encoding: 8bit X-Originated-At: 2003:de:573c:8400:5054:ff:fe15:ac42!48472 X-FNSign: v=2 s=66F2D8F94E6E0216E633339F334E4D6E93E684DFB6D0157FFE126DCEB32297AB X-Scan-TS: Sun, 24 Jan 2021 18:28:11 +0100 Precedence: bulk List-ID: X-Mailing-List: linux-usb@vger.kernel.org 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- SERR-