Commit 07416af1 authored by Rasmus Villemoes's avatar Rasmus Villemoes Committed by Linus Torvalds
Browse files

kernel/async.c: stop guarding pr_debug() statements 

It's currently nigh impossible to get these pr_debug()s to print
something.  Being guarded by initcall_debug means one has to enable tons
of other debug output during boot, and the system_state condition further
means it's impossible to get them when loading modules later.

Also, the compiler can't know that these global conditions do not change,
so there are W=2 warnings

kernel/async.c:125:9: warning: `calltime' may be used uninitialized in this function [-Wmaybe-uninitialized]
kernel/async.c:300:9: warning: `starttime' may be used uninitialized in this function [-Wmaybe-uninitialized]

Make it possible, for a DYNAMIC_DEBUG kernel, to get these to print their
messages by booting with appropriate 'dyndbg="file async.c +p"' command
line argument.  For a non-DYNAMIC_DEBUG kernel, pr_debug() compiles to
nothing.

This does cost doing an unconditional ktime_get() for the starttime value,
but the corresponding ktime_get for the end time can be elided by
factoring it into a function which only gets called if the printk()
arguments end up being evaluated.

Link: https://lkml.kernel.org/r/20210309151723.1907838-1-linux@rasmusvillemoes.dk


Signed-off-by: default avatarRasmus Villemoes <linux@rasmusvillemoes.dk>
Cc: Tejun Heo <tj@kernel.org>
Signed-off-by: default avatarAndrew Morton <akpm@linux-foundation.org>
Signed-off-by: default avatarLinus Torvalds <torvalds@linux-foundation.org>
parent 9c39c6ff

kernel/async.c

+20 −28
Original line number Diff line number Diff line
@@ -78,6 +78,12 @@ static DECLARE_WAIT_QUEUE_HEAD(async_done); 


static atomic_t entry_count;



static long long microseconds_since(ktime_t start)

{

	ktime_t now = ktime_get();

	return ktime_to_ns(ktime_sub(now, start)) >> 10;

}



static async_cookie_t lowest_in_progress(struct async_domain *domain)

{

	struct async_entry *first = NULL;
@@ -111,24 +117,18 @@ static void async_run_entry_fn(struct work_struct *work) 
	struct async_entry *entry =

		container_of(work, struct async_entry, work);

	unsigned long flags;

	ktime_t calltime, delta, rettime;

	ktime_t calltime;



	/* 1) run (and print duration) */

	if (initcall_debug && system_state < SYSTEM_RUNNING) {

		pr_debug("calling  %lli_%pS @ %i\n",

			(long long)entry->cookie,

	pr_debug("calling  %lli_%pS @ %i\n", (long long)entry->cookie,

		 entry->func, task_pid_nr(current));

	calltime = ktime_get();

	}



	entry->func(entry->data, entry->cookie);

	if (initcall_debug && system_state < SYSTEM_RUNNING) {

		rettime = ktime_get();

		delta = ktime_sub(rettime, calltime);



	pr_debug("initcall %lli_%pS returned after %lld usecs\n",

			(long long)entry->cookie,

			entry->func,

			(long long)ktime_to_ns(delta) >> 10);

	}

		 (long long)entry->cookie, entry->func,

		 microseconds_since(calltime));



	/* 2) remove self from the pending queues */

	spin_lock_irqsave(&async_lock, flags);
@@ -287,23 +287,15 @@ EXPORT_SYMBOL_GPL(async_synchronize_full_domain); 
 */

void async_synchronize_cookie_domain(async_cookie_t cookie, struct async_domain *domain)

{

	ktime_t starttime, delta, endtime;

	ktime_t starttime;



	if (initcall_debug && system_state < SYSTEM_RUNNING) {

	pr_debug("async_waiting @ %i\n", task_pid_nr(current));

	starttime = ktime_get();

	}



	wait_event(async_done, lowest_in_progress(domain) >= cookie);



	if (initcall_debug && system_state < SYSTEM_RUNNING) {

		endtime = ktime_get();

		delta = ktime_sub(endtime, starttime);



		pr_debug("async_continuing @ %i after %lli usec\n",

			task_pid_nr(current),

			(long long)ktime_to_ns(delta) >> 10);

	}

	pr_debug("async_continuing @ %i after %lli usec\n", task_pid_nr(current),

		 microseconds_since(starttime));

}

EXPORT_SYMBOL_GPL(async_synchronize_cookie_domain);