* [PATCH v2 0/2] PCI: Update quirk timing
@ 2018-03-14 13:30 Bjorn Helgaas
2018-03-14 13:30 ` [PATCH v2 1/2] PCI: Report quirk timings with pci_info() instead of pr_debug() Bjorn Helgaas
` (2 more replies)
0 siblings, 3 replies; 4+ messages in thread
From: Bjorn Helgaas @ 2018-03-14 13:30 UTC (permalink / raw)
To: linux-pci
Cc: linux-kernel, Myron Stowe, Paul Menzel, Andreas Noever,
Alan Stern, Andy Shevchenko
This is a minor update of a patch I posted earlier [1] when Paul
reported an unreasonably long time spent in PCI quirks during boot
[2]. This doesn't fix the slow quirks, but might help find them.
We previously printed the time taken by each quirk if "initcall_debug"
was specified. With these patches, we'll print it even without
"initcall_debug" if the quirk takes longer than 10ms.
I did notice one quirk (quirk_apple_poweroff_thunderbolt()) in the
suspend path that sleeps for 300ms, so this will probably make suspend
noisier on Apple systems.
[1] https://lkml.kernel.org/r/20171228212723.GB211339@bhelgaas-glaptop.roam.corp.google.com
[2] https://lkml.kernel.org/r/44cada166e42007d27b4c3e3aa0744d7@molgen.mpg.de
---
Bjorn Helgaas (2):
PCI: Report quirk timings with pci_info() instead of pr_debug()
PCI: Report quirks that take more than 10ms
drivers/pci/quirks.c | 24 ++++++++----------------
1 file changed, 8 insertions(+), 16 deletions(-)
^ permalink raw reply [flat|nested] 4+ messages in thread
* [PATCH v2 1/2] PCI: Report quirk timings with pci_info() instead of pr_debug()
2018-03-14 13:30 [PATCH v2 0/2] PCI: Update quirk timing Bjorn Helgaas
@ 2018-03-14 13:30 ` Bjorn Helgaas
2018-03-14 13:30 ` [PATCH v2 2/2] PCI: Report quirks that take more than 10ms Bjorn Helgaas
2018-03-19 18:51 ` [PATCH v2 0/2] PCI: Update quirk timing Bjorn Helgaas
2 siblings, 0 replies; 4+ messages in thread
From: Bjorn Helgaas @ 2018-03-14 13:30 UTC (permalink / raw)
To: linux-pci
Cc: linux-kernel, Myron Stowe, Paul Menzel, Andreas Noever,
Alan Stern, Andy Shevchenko
From: Bjorn Helgaas <bhelgaas@google.com>
With "initcall_debug", we report how long every PCI quirk took. Previously
we used pr_debug(), which means you have to figure out how to enable debug
output.
Log these timings using pci_info() instead so it doesn't depend on DEBUG,
CONFIG_DYNAMIC_DEBUG, etc.
Also, don't log anything at all unless "initcall_debug" is specified. This
matches what we do in do_one_initcall_debug().
Signed-off-by: Bjorn Helgaas <bhelgaas@google.com>
---
drivers/pci/quirks.c | 7 ++-----
1 file changed, 2 insertions(+), 5 deletions(-)
diff --git a/drivers/pci/quirks.c b/drivers/pci/quirks.c
index ec280f2223b3..97c74e386bcc 100644
--- a/drivers/pci/quirks.c
+++ b/drivers/pci/quirks.c
@@ -3004,10 +3004,8 @@ static ktime_t fixup_debug_start(struct pci_dev *dev,
{
ktime_t calltime = 0;
- pci_dbg(dev, "calling %pF\n", fn);
if (initcall_debug) {
- pr_debug("calling %pF @ %i for %s\n",
- fn, task_pid_nr(current), dev_name(&dev->dev));
+ pci_info(dev, "calling %pF @ %i\n", fn, task_pid_nr(current));
calltime = ktime_get();
}
@@ -3024,8 +3022,7 @@ static void fixup_debug_report(struct pci_dev *dev, ktime_t calltime,
rettime = ktime_get();
delta = ktime_sub(rettime, calltime);
duration = (unsigned long long) ktime_to_ns(delta) >> 10;
- pr_debug("pci fixup %pF returned after %lld usecs for %s\n",
- fn, duration, dev_name(&dev->dev));
+ pci_info(dev, "%pF took %lld usecs\n", fn, duration);
}
}
^ permalink raw reply related [flat|nested] 4+ messages in thread
* [PATCH v2 2/2] PCI: Report quirks that take more than 10ms
2018-03-14 13:30 [PATCH v2 0/2] PCI: Update quirk timing Bjorn Helgaas
2018-03-14 13:30 ` [PATCH v2 1/2] PCI: Report quirk timings with pci_info() instead of pr_debug() Bjorn Helgaas
@ 2018-03-14 13:30 ` Bjorn Helgaas
2018-03-19 18:51 ` [PATCH v2 0/2] PCI: Update quirk timing Bjorn Helgaas
2 siblings, 0 replies; 4+ messages in thread
From: Bjorn Helgaas @ 2018-03-14 13:30 UTC (permalink / raw)
To: linux-pci
Cc: linux-kernel, Myron Stowe, Paul Menzel, Andreas Noever,
Alan Stern, Andy Shevchenko
From: Bjorn Helgaas <bhelgaas@google.com>
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 <pmenzel@molgen.mpg.de>
Signed-off-by: Bjorn Helgaas <bhelgaas@google.com>
---
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);
- }
}
/*
^ permalink raw reply related [flat|nested] 4+ messages in thread
* Re: [PATCH v2 0/2] PCI: Update quirk timing
2018-03-14 13:30 [PATCH v2 0/2] PCI: Update quirk timing Bjorn Helgaas
2018-03-14 13:30 ` [PATCH v2 1/2] PCI: Report quirk timings with pci_info() instead of pr_debug() Bjorn Helgaas
2018-03-14 13:30 ` [PATCH v2 2/2] PCI: Report quirks that take more than 10ms Bjorn Helgaas
@ 2018-03-19 18:51 ` Bjorn Helgaas
2 siblings, 0 replies; 4+ messages in thread
From: Bjorn Helgaas @ 2018-03-19 18:51 UTC (permalink / raw)
To: linux-pci
Cc: linux-kernel, Myron Stowe, Paul Menzel, Andreas Noever,
Alan Stern, Andy Shevchenko
On Wed, Mar 14, 2018 at 08:30:26AM -0500, Bjorn Helgaas wrote:
> This is a minor update of a patch I posted earlier [1] when Paul
> reported an unreasonably long time spent in PCI quirks during boot
> [2]. This doesn't fix the slow quirks, but might help find them.
>
> We previously printed the time taken by each quirk if "initcall_debug"
> was specified. With these patches, we'll print it even without
> "initcall_debug" if the quirk takes longer than 10ms.
>
> I did notice one quirk (quirk_apple_poweroff_thunderbolt()) in the
> suspend path that sleeps for 300ms, so this will probably make suspend
> noisier on Apple systems.
>
> [1] https://lkml.kernel.org/r/20171228212723.GB211339@bhelgaas-glaptop.roam.corp.google.com
> [2] https://lkml.kernel.org/r/44cada166e42007d27b4c3e3aa0744d7@molgen.mpg.de
>
> ---
>
> Bjorn Helgaas (2):
> PCI: Report quirk timings with pci_info() instead of pr_debug()
> PCI: Report quirks that take more than 10ms
>
>
> drivers/pci/quirks.c | 24 ++++++++----------------
> 1 file changed, 8 insertions(+), 16 deletions(-)
Applied to pci/misc for v4.17.
^ permalink raw reply [flat|nested] 4+ messages in thread
end of thread, other threads:[~2018-03-19 18:51 UTC | newest]
Thread overview: 4+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2018-03-14 13:30 [PATCH v2 0/2] PCI: Update quirk timing Bjorn Helgaas
2018-03-14 13:30 ` [PATCH v2 1/2] PCI: Report quirk timings with pci_info() instead of pr_debug() Bjorn Helgaas
2018-03-14 13:30 ` [PATCH v2 2/2] PCI: Report quirks that take more than 10ms Bjorn Helgaas
2018-03-19 18:51 ` [PATCH v2 0/2] PCI: Update quirk timing Bjorn Helgaas
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).