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? 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? > Signed-off-by: Todd Poynor <toddpoy...@google.com> > --- > drivers/base/dd.c | 28 +++++++++++++++++++++++++++- > 1 file changed, 27 insertions(+), 1 deletion(-) > > diff --git a/drivers/base/dd.c b/drivers/base/dd.c > index 4882f06d12df..6831cb48e9dd 100644 > --- a/drivers/base/dd.c > +++ b/drivers/base/dd.c > @@ -20,6 +20,7 @@ > #include <linux/device.h> > #include <linux/delay.h> > #include <linux/dma-mapping.h> > +#include <linux/init.h> > #include <linux/module.h> > #include <linux/kthread.h> > #include <linux/wait.h> > @@ -53,6 +54,7 @@ static DEFINE_MUTEX(deferred_probe_mutex); > static LIST_HEAD(deferred_probe_pending_list); > static LIST_HEAD(deferred_probe_active_list); > static atomic_t deferred_trigger_count = ATOMIC_INIT(0); > +static bool initcalls_done; > > /* > * In some cases, like suspend to RAM or hibernation, It might be reasonable > @@ -61,6 +63,26 @@ static atomic_t deferred_trigger_count = ATOMIC_INIT(0); > */ > static bool defer_all_probes; > > +/* > + * For initcall_debug, show the deferred probes executed in late_initcall > + * processing. > + */ > +static void deferred_probe_debug(struct device *dev) > +{ > + ktime_t calltime, delta, rettime; > + unsigned long long duration; > + > + printk(KERN_DEBUG "deferred probe %s @ %i\n", dev_name(dev), > + task_pid_nr(current)); _if_ I were to take something like this, it would be best to use dev_info(), right? But look at the analyze_boot.py script, I think it does all of this for you automagically... thanks, greg k-h