[PATCH v2 2/2] PCI: Report quirks that take more than 10ms

From: Bjorn Helgaas
Date: Wed Mar 14 2018 - 09:30:48 EST


From: Bjorn Helgaas <bhelgaas@xxxxxxxxxx>

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@xxxxxxxxxxxxx
Reported-by: Paul Menzel <pmenzel@xxxxxxxxxxxxx>
Signed-off-by: Bjorn Helgaas <bhelgaas@xxxxxxxxxx>
---
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);
- }
}

/*