From patchwork Wed Mar 14 13:30:40 2018 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Bjorn Helgaas X-Patchwork-Id: 10282169 X-Patchwork-Delegate: bhelgaas@google.com Return-Path: Received: from mail.wl.linuxfoundation.org (pdx-wl-mail.web.codeaurora.org [172.30.200.125]) by pdx-korg-patchwork.web.codeaurora.org (Postfix) with ESMTP id 2D0E3601E9 for ; Wed, 14 Mar 2018 13:30:56 +0000 (UTC) Received: from mail.wl.linuxfoundation.org (localhost [127.0.0.1]) by mail.wl.linuxfoundation.org (Postfix) with ESMTP id 16FF92896A for ; Wed, 14 Mar 2018 13:30:56 +0000 (UTC) Received: by mail.wl.linuxfoundation.org (Postfix, from userid 486) id 129EB2891B; Wed, 14 Mar 2018 13:30:56 +0000 (UTC) X-Spam-Checker-Version: SpamAssassin 3.3.1 (2010-03-16) on pdx-wl-mail.web.codeaurora.org X-Spam-Level: X-Spam-Status: No, score=-6.9 required=2.0 tests=BAYES_00,RCVD_IN_DNSWL_HI autolearn=unavailable version=3.3.1 Received: from vger.kernel.org (vger.kernel.org [209.132.180.67]) by mail.wl.linuxfoundation.org (Postfix) with ESMTP id C5E732896A for ; Wed, 14 Mar 2018 13:30:53 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1752181AbeCNNao (ORCPT ); Wed, 14 Mar 2018 09:30:44 -0400 Received: from mail.kernel.org ([198.145.29.99]:48596 "EHLO mail.kernel.org" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1751758AbeCNNan (ORCPT ); Wed, 14 Mar 2018 09:30:43 -0400 Received: from localhost (173-24-246-110.client.mchsi.com [173.24.246.110]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by mail.kernel.org (Postfix) with ESMTPSA id 0A47821778; Wed, 14 Mar 2018 13:30:41 +0000 (UTC) DMARC-Filter: OpenDMARC Filter v1.3.2 mail.kernel.org 0A47821778 Authentication-Results: mail.kernel.org; dmarc=none (p=none dis=none) header.from=kernel.org Authentication-Results: mail.kernel.org; spf=none smtp.mailfrom=helgaas@kernel.org Subject: [PATCH v2 2/2] PCI: Report quirks that take more than 10ms From: Bjorn Helgaas To: linux-pci@vger.kernel.org Cc: linux-kernel@vger.kernel.org, Myron Stowe , Paul Menzel , Andreas Noever , Alan Stern , Andy Shevchenko Date: Wed, 14 Mar 2018 08:30:40 -0500 Message-ID: <152103424057.167541.9559805983145916469.stgit@bhelgaas-glaptop.roam.corp.google.com> In-Reply-To: <152103417018.167541.3290752859388672112.stgit@bhelgaas-glaptop.roam.corp.google.com> References: <152103417018.167541.3290752859388672112.stgit@bhelgaas-glaptop.roam.corp.google.com> User-Agent: StGit/0.18 MIME-Version: 1.0 Sender: linux-pci-owner@vger.kernel.org Precedence: bulk List-ID: X-Mailing-List: linux-pci@vger.kernel.org X-Virus-Scanned: ClamAV using ClamSMTP From: Bjorn Helgaas With "initcall_debug", we report how long every PCI quirk took. Even without "initcall_debug", report the runtime of any quirk that takes longer than 10ms. This is to make it easier to notice quirks that slow down boot. This was motivated by a report from Paul Menzel that PCI final quirks took half a second at boot. Link: https://lkml.kernel.org/r/44cada166e42007d27b4c3e3aa0744d7@molgen.mpg.de Reported-by: Paul Menzel Signed-off-by: Bjorn Helgaas --- drivers/pci/quirks.c | 17 ++++++----------- 1 file changed, 6 insertions(+), 11 deletions(-) diff --git a/drivers/pci/quirks.c b/drivers/pci/quirks.c index 97c74e386bcc..1466ee729e0a 100644 --- a/drivers/pci/quirks.c +++ b/drivers/pci/quirks.c @@ -3002,14 +3002,10 @@ DECLARE_PCI_FIXUP_HEADER(PCI_VENDOR_ID_INTEL, 0x0e0d, quirk_intel_ntb); static ktime_t fixup_debug_start(struct pci_dev *dev, void (*fn)(struct pci_dev *dev)) { - ktime_t calltime = 0; - - if (initcall_debug) { + if (initcall_debug) pci_info(dev, "calling %pF @ %i\n", fn, task_pid_nr(current)); - calltime = ktime_get(); - } - return calltime; + return ktime_get(); } static void fixup_debug_report(struct pci_dev *dev, ktime_t calltime, @@ -3018,12 +3014,11 @@ static void fixup_debug_report(struct pci_dev *dev, ktime_t calltime, ktime_t delta, rettime; unsigned long long duration; - if (initcall_debug) { - rettime = ktime_get(); - delta = ktime_sub(rettime, calltime); - duration = (unsigned long long) ktime_to_ns(delta) >> 10; + rettime = ktime_get(); + delta = ktime_sub(rettime, calltime); + duration = (unsigned long long) ktime_to_ns(delta) >> 10; + if (initcall_debug || duration > 10000) pci_info(dev, "%pF took %lld usecs\n", fn, duration); - } } /*