Re: [PATCH] initcall_debug: add deferred probe times

[Greg Kroah-Hartman <gregkh@linuxfoundation.org>]

On Tue, Jul 25, 2017 at 08:01:49PM -0700, Todd Poynor wrote:
> On Tue, Jul 25, 2017 at 4:40 PM, Greg Kroah-Hartman
> <gregkh@linuxfoundation.org> wrote:
> > On Tue, Jul 25, 2017 at 04:31:59PM -0700, Todd Poynor wrote:
> >> initcall_debug attributes all deferred device probe retries for the
> >> late_initcall level to function deferred_probe_initcall.  Add logs of
> >> the individual device probe routines called, to identify which drivers
> >> are executing for how long during the initcall path.  Deferred probes
> >> that occur after initcall processing are not shown.
> >>
> >> Example log messages added:
> >>
> >> [    0.505119] deferred probe my-sound-device @ 6
> >> [    0.517656] deferred probe my-sound-device returned after 1227 usecs
> >
> > Can't you subtract the timestamp number right there?
> 
> This patch extends the existing initcall_debug functionality; I've
> copied the methods used by do_one_initcall_debug() to compute and
> report timing info in a compatible format.  If it's better to change
> the way this is reported, I can also suggest changes to the existing
> initcall_debug code.  cc'ed the maintainers (I should have in the
> first place).

Ah, ok, I missed that, I was looking at the driver probe debug path,
this makes a lot more sense then.

> > And doesn't the tools/power/pm-graph/ scripts do this type of thing
> > automatically for you to give you pretty graphs you can use to drill
> > down on what is taking how long and such?
> 
> analyze_boot.py parses the dmesg output printed by initcall_debug to
> produce those graphs (and can also produce ftrace-based function
> callgraphs).  The initcall_debug output printed (and graphed) for
> deferred probe calls are lumped into a single entry
> "deferred_probe_initcall".  This patch logs the times of the
> individual deferred probe calls by device name, to better help
> developers understand where the time is spent.  If this feature finds
> favor, it may also be deemed useful to update analyze_boot.py to graph
> this information.

I think updating it would be good, but for now this should be fine.
Thanks for the information.

greg k-h