drivers: base: initcall_debug logs for driver probe times

Add initcall_debug logs for each driver device probe call, for example:

   probe of a3800000.ramoops returned 1 after 3007 usecs

This replaces the previous code added to report times for deferred
probes.  It also reports OF platform bus device creates that were
formerly lumped together in a single entry for function
of_platform_default_populate_init, as well as helping to annotate other
initcalls that involve device probing.

Remove restriction on printing probe times only during initcalls, since
initcall_debug now continues to show driver timing info past the boot
phase.

Signed-off-by: Todd Poynor <toddpoynor@google.com>
Reviewed-by: Rob Herring <robh@kernel.org>
Signed-off-by: Greg Kroah-Hartman <gregkh@linuxfoundation.org>
This commit is contained in:
Todd Poynor 2018-06-20 17:35:56 -07:00 committed by Greg Kroah-Hartman
parent 7daf201d7f
commit 0a50f61c4f

View file

@ -53,7 +53,6 @@ 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
@ -62,26 +61,6 @@ static bool initcalls_done;
*/
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));
calltime = ktime_get();
bus_probe_device(dev);
rettime = ktime_get();
delta = ktime_sub(rettime, calltime);
duration = (unsigned long long) ktime_to_ns(delta) >> 10;
printk(KERN_DEBUG "deferred probe %s returned after %lld usecs\n",
dev_name(dev), duration);
}
/*
* deferred_probe_work_func() - Retry probing devices in the active list.
*/
@ -125,11 +104,7 @@ static void deferred_probe_work_func(struct work_struct *work)
device_pm_move_to_tail(dev);
dev_dbg(dev, "Retrying from deferred list\n");
if (initcall_debug && !initcalls_done)
deferred_probe_debug(dev);
else
bus_probe_device(dev);
bus_probe_device(dev);
mutex_lock(&deferred_probe_mutex);
put_device(dev);
@ -237,7 +212,6 @@ static int deferred_probe_initcall(void)
driver_deferred_probe_trigger();
/* Sort as many dependencies as possible before exiting initcalls */
flush_work(&deferred_probe_work);
initcalls_done = true;
return 0;
}
late_initcall(deferred_probe_initcall);
@ -527,6 +501,23 @@ static int really_probe(struct device *dev, struct device_driver *drv)
return ret;
}
/*
* For initcall_debug, show the driver probe time.
*/
static int really_probe_debug(struct device *dev, struct device_driver *drv)
{
ktime_t calltime, delta, rettime;
int ret;
calltime = ktime_get();
ret = really_probe(dev, drv);
rettime = ktime_get();
delta = ktime_sub(rettime, calltime);
printk(KERN_DEBUG "probe of %s returned %d after %lld usecs\n",
dev_name(dev), ret, (s64) ktime_to_us(delta));
return ret;
}
/**
* driver_probe_done
* Determine if the probe sequence is finished or not.
@ -585,7 +576,10 @@ int driver_probe_device(struct device_driver *drv, struct device *dev)
pm_runtime_get_sync(dev->parent);
pm_runtime_barrier(dev);
ret = really_probe(dev, drv);
if (initcall_debug)
ret = really_probe_debug(dev, drv);
else
ret = really_probe(dev, drv);
pm_request_idle(dev);
if (dev->parent)