Received: by 2002:ac0:a581:0:0:0:0:0 with SMTP id m1-v6csp3030945imm; Sun, 24 Jun 2018 09:50:51 -0700 (PDT) X-Google-Smtp-Source: ADUXVKIkU7pvFUE5l3DCg7RZOM9H19YVLU4bsfn38W2jQ20v5Vs3TTUmi80tXhrh8i8Deyq+SOdw X-Received: by 2002:a17:902:262:: with SMTP id 89-v6mr9329445plc.252.1529859051874; Sun, 24 Jun 2018 09:50:51 -0700 (PDT) ARC-Seal: i=1; a=rsa-sha256; t=1529859051; cv=none; d=google.com; s=arc-20160816; b=mbiCTnHm/aHUbhagmOjDzx6GCg0+X/4o3APbJzczOmaGKjAHFROfiDpNFiEfKi7cpS JOMu1wIm2ewVgYrED10ukMoqu/q4LovNiH8oIDup/zNjo9Os+ebk/hxLn1n6+RRxS/u1 A71Q26fNQ98OkFzoG4bXMNCpVnqj+ye12I2q+KFgF01vZDlCNH6s84ffrGUiOG1sNrOz vIpT0i20H4Fnhb7W5ymsNeoSEKyQs106BIVj2Sh6aXFzVZaLPaLTrF+MvWcCvJurTbRJ ZVto3QGgJHcIMYTP07t8sQvHJYeqNueUkbnP9YHvuDTfa5KAQwma8P83N0U1sjVKpZ+3 wM/w== ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=google.com; s=arc-20160816; h=list-id:precedence:sender:content-transfer-encoding :content-language:in-reply-to:mime-version:user-agent:date :message-id:from:references:cc:to:subject:arc-authentication-results; bh=9OtcZlKQamG6QOwRw0Tr951iSrZbBriBgG5yRk6maXg=; b=xNxrnzvMACrS0vHd4iiU7Q3YF+6BPT2KLEQAjGbBXVY8axC3zMdv1vUfZpb7K67Uf9 oOnEbEf8+j8NhtfaX7uuDmN7VVGTyZlrJOyKwHkxh1gDsEJauJj/zzFDgSdQ11s4Ju7g LkvvmvNgIBUwSCip6LYMtZKOrwNlYn3WacAyDFSRlqQ+wysUxuUXnFyNsRZsuae9Dfzq LKLpKxCI/5nB43n0NLPU0E355lFp64iMjMXiXkU2f4fy+7OuvGg+EOBpPwG/Uly+rrOO M/CscvXwtlAr9FKXOIPqt8fUTXk3JdEIYk5MVS/YdSAoVXI3TxyUE/qKHEprMSKk37jr VE8w== ARC-Authentication-Results: i=1; mx.google.com; spf=pass (google.com: best guess record for domain of linux-kernel-owner@vger.kernel.org designates 209.132.180.67 as permitted sender) smtp.mailfrom=linux-kernel-owner@vger.kernel.org Return-Path: Received: from vger.kernel.org (vger.kernel.org. [209.132.180.67]) by mx.google.com with ESMTP id q61-v6si8009235plb.93.2018.06.24.09.50.34; Sun, 24 Jun 2018 09:50:51 -0700 (PDT) Received-SPF: pass (google.com: best guess record for domain of linux-kernel-owner@vger.kernel.org designates 209.132.180.67 as permitted sender) client-ip=209.132.180.67; Authentication-Results: mx.google.com; spf=pass (google.com: best guess record for domain of linux-kernel-owner@vger.kernel.org designates 209.132.180.67 as permitted sender) smtp.mailfrom=linux-kernel-owner@vger.kernel.org Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1751999AbeFXQt4 (ORCPT + 99 others); Sun, 24 Jun 2018 12:49:56 -0400 Received: from mx3.molgen.mpg.de ([141.14.17.11]:53807 "EHLO mx1.molgen.mpg.de" rhost-flags-OK-OK-OK-FAIL) by vger.kernel.org with ESMTP id S1751034AbeFXQtz (ORCPT ); Sun, 24 Jun 2018 12:49:55 -0400 Received: from [10.0.178.91] (unknown [62.214.191.65]) (using TLSv1.2 with cipher ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits)) (No client certificate requested) (Authenticated sender: pmenzel) by mx.molgen.mpg.de (Postfix) with ESMTPSA id DB6B62012BA066; Sun, 24 Jun 2018 18:49:51 +0200 (CEST) Subject: `quirk_usb_handoff_ohci` takes over 73 ms (twice) on AMD system (was: `pci_apply_final_quirks()` taking half a second) To: Alan Stern Cc: Bjorn Helgaas , linux-pci@vger.kernel.org, linux-kernel@vger.kernel.org, David Woodhouse , Andy Shevchenko , linux-usb@vger.kernel.org References: From: Paul Menzel Message-ID: <5e89a3ad-2210-800f-89b9-17152b5ad7c8@molgen.mpg.de> Date: Sun, 24 Jun 2018 18:49:51 +0200 User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:52.0) Gecko/20100101 Thunderbird/52.8.0 MIME-Version: 1.0 In-Reply-To: Content-Type: text/plain; charset=utf-8; format=flowed Content-Language: de-DE Content-Transfer-Encoding: 8bit Sender: linux-kernel-owner@vger.kernel.org Precedence: bulk List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Dear Alan, Sorry for the long delay. Am 31.12.2017 um 22:16 schrieb Alan Stern: > On Sun, 31 Dec 2017, Paul Menzel wrote: > >> Am 29.12.2017 um 17:14 schrieb Alan Stern: >>> On Thu, 28 Dec 2017, Bjorn Helgaas wrote: >>> >>>> On Tue, Dec 26, 2017 at 04:55:20PM +0100, Paul Menzel wrote: […] >>>>> So it’s `pci fixup quirk_usb_early_handoff` taking around 85 ms, and >>>>> that twice. >>>> >>>> Wow. That's pretty painful, but of course I don't know how to fix it. >>>> From looking at quirk_usb_early_handoff(), it may depend on BIOS >>>> details. Maybe the USB folks will have some ideas. >>> >>> Can we see the output from lspci? It would help to know what the 12.0 >>> and 13.0 devices are. >> >> Sorry, that was trimmed from the original message. Here is the output >> from the ASRock A780FullD. >> >>> ``` >>> $ more /proc/version >>> Linux version 4.9.0-0.bpo.2-amd64 (debian-kernel@lists.debian.org) >>> (gcc version 4.9.2 (Debian 4.9.2-10) ) #1 SMP Debian 4.9.13-1~bpo8+1 (2017-02-27) >>> $ lspci -nn > >>> 00:12.0 USB controller [0c03]: Advanced Micro Devices, Inc. [AMD/ATI] SB7x0/SB8x0/SB9x0 USB OHCI0 Controller [1002:4397] >>> 00:12.1 USB controller [0c03]: Advanced Micro Devices, Inc. [AMD/ATI] SB7x0 USB OHCI1 Controller [1002:4398] >>> 00:12.2 USB controller [0c03]: Advanced Micro Devices, Inc. [AMD/ATI] SB7x0/SB8x0/SB9x0 USB EHCI Controller [1002:4396] >>> 00:13.0 USB controller [0c03]: Advanced Micro Devices, Inc. [AMD/ATI] SB7x0/SB8x0/SB9x0 USB OHCI0 Controller [1002:4397] >>> 00:13.1 USB controller [0c03]: Advanced Micro Devices, Inc. [AMD/ATI] SB7x0 USB OHCI1 Controller [1002:4398] >>> 00:13.2 USB controller [0c03]: Advanced Micro Devices, Inc. [AMD/ATI] SB7x0/SB8x0/SB9x0 USB EHCI Controller [1002:4396] > >> So far, this can be reproduce on all AMD systems I have (ASRock >> A780FullHD, ASRock E350M1, Asus F2A85-M Pro). > > So they are OHCI controllers. You could add some debugging statements > to quirk_usb_handoff_ohci() to try and locate the part that's taking so > long. > 737 static void quirk_usb_handoff_ohci(struct pci_dev *pdev) > 738 { > 739 void __iomem *base; > 740 u32 control; > 741 u32 fminterval = 0; > 742 bool no_fminterval = false; > 743 int cnt; > 744 > 745 if (!mmio_resource_enabled(pdev, 0)) > 746 return; > 747 > 748 base = pci_ioremap_bar(pdev, 0); > 749 if (base == NULL) > 750 return; > 751 > 752 /* > 753 * ULi M5237 OHCI controller locks the whole system when accessing > 754 * the OHCI_FMINTERVAL offset. > 755 */ > 756 if (pdev->vendor == PCI_VENDOR_ID_AL && pdev->device == 0x5237) > 757 no_fminterval = true; > 758 > 759 control = readl(base + OHCI_CONTROL); > 760 > 761 printk(KERN_INFO "1\n"); > 762 /* On PA-RISC, PDC can leave IR set incorrectly; ignore it there. */ > 763 #ifdef __hppa__ > 764 #define OHCI_CTRL_MASK (OHCI_CTRL_RWC | OHCI_CTRL_IR) > 765 #else > 766 #define OHCI_CTRL_MASK OHCI_CTRL_RWC > 767 > 768 if (control & OHCI_CTRL_IR) { > 769 int wait_time = 500; /* arbitrary; 5 seconds */ > 770 writel(OHCI_INTR_OC, base + OHCI_INTRENABLE); > 771 writel(OHCI_OCR, base + OHCI_CMDSTATUS); > 772 while (wait_time > 0 && > 773 readl(base + OHCI_CONTROL) & OHCI_CTRL_IR) { > 774 wait_time -= 10; > 775 msleep(10); > 776 } > 777 if (wait_time <= 0) > 778 dev_warn(&pdev->dev, > 779 "OHCI: BIOS handoff failed (BIOS bug?) %08x\n", > 780 readl(base + OHCI_CONTROL)); > 781 } > 782 #endif > 783 > 784 printk(KERN_INFO "2\n"); > 785 /* disable interrupts */ > 786 writel((u32) ~0, base + OHCI_INTRDISABLE); > 787 > 788 printk(KERN_INFO "3\n"); > 789 /* Reset the USB bus, if the controller isn't already in RESET */ > 790 if (control & OHCI_HCFS) { > 791 /* Go into RESET, preserving RWC (and possibly IR) */ > 792 writel(control & OHCI_CTRL_MASK, base + OHCI_CONTROL); > 793 readl(base + OHCI_CONTROL); > 794 > 795 /* drive bus reset for at least 50 ms (7.1.7.5) */ > 796 msleep(50); > 797 } > 798 printk(KERN_INFO "4\n"); > 799 > 800 /* software reset of the controller, preserving HcFmInterval */ > 801 if (!no_fminterval) > 802 fminterval = readl(base + OHCI_FMINTERVAL); > 803 > 804 writel(OHCI_HCR, base + OHCI_CMDSTATUS); > 805 printk(KERN_INFO "5\n"); > 806 > 807 /* reset requires max 10 us delay */ > 808 for (cnt = 30; cnt > 0; --cnt) { /* ... allow extra time */ > 809 printk(KERN_INFO "6 cnt = %d\n", cnt); > 810 if ((readl(base + OHCI_CMDSTATUS) & OHCI_HCR) == 0) > 811 break; > 812 udelay(1); > 813 } > 814 > 815 printk(KERN_INFO "7\n"); > 816 if (!no_fminterval) > 817 writel(fminterval, base + OHCI_FMINTERVAL); > 818 > 819 /* Now the controller is safely in SUSPEND and nothing can wake it up */ > 820 iounmap(base); > 821 } Here is the result. > [ 0.062796] pci 0000:00:12.0: calling quirk_usb_early_handoff+0x0/0x700 @ 1 > [ 0.062860] 1 > [ 0.086662] 2 Around 24 ms are spent in the loop checking `readl(base + OHCI_CONTROL) & OHCI_CTRL_IR)` in line 772. > [ 0.086663] 3 > [ 0.138645] 4 That’s the 50 ms from resetting the USB bus, if the controller isn't already in RESET in line 796. > [ 0.138647] 5 > [ 0.138649] 6 cnt = 30 > [ 0.138650] 7 > [ 0.138771] pci 0000:00:12.0: quirk_usb_early_handoff+0x0/0x700 took 74188 usecs > [ 0.138778] pci 0000:00:12.2: calling quirk_usb_early_handoff+0x0/0x700 @ 1 > [ 0.138917] pci 0000:00:12.2: quirk_usb_early_handoff+0x0/0x700 took 133 usecs > [ 0.138919] pci 0000:00:12.2: calling pci_fixup_amd_ehci_pme+0x0/0x30 @ 1 > [ 0.138920] pci 0000:00:12.2: PME# does not work under D3, disabling it > [ 0.138922] pci 0000:00:12.2: pci_fixup_amd_ehci_pme+0x0/0x30 took 0 usecs > [ 0.138926] pci 0000:00:13.0: calling quirk_usb_early_handoff+0x0/0x700 @ 1 > [ 0.138987] 1 > [ 0.161639] 2 > [ 0.161640] 3 > [ 0.213622] 4 > [ 0.213625] 5 > [ 0.213626] 6 cnt = 30 > [ 0.213627] 7 > [ 0.213748] pci 0000:00:13.0: quirk_usb_early_handoff+0x0/0x700 took 73062 usecs So, is there a way to not reset the controller? In my case the firmware and GRUB already used the controller and set it up. Additionally, can this be done in parallel for both PCI devices? Can you think of other ways to decrease the time? Kind regards, Paul