[RFC/PATCH] printk: detect incomplete lines

[Vegard Nossum]

Hi,

This printk() problem has been bugging me for a long time. Consider the
following code:

diff --git a/init/main.c b/init/main.c
index ddada7a..777e02d 100644
--- a/init/main.c
+++ b/init/main.c
@@ -452,17 +452,38 @@ static void __init setup_command_line(char *command_line)
  * gcc-3.4 accidentally inlines this function, so use noinline.
  */
 
+static void printk_thread(const char *msg, unsigned long wait)
+{
+	int i = 0;
+
+	while(true) {
+		if (i == 0)
+			printk(KERN_INFO "Here we go: ");
+
+		printk("%s%s", msg, i < 7 ? ", " : "\n");
+		if (++i == 8)
+			i = 0;
+		msleep(wait);
+	}
+}
+
+static void printk_thread_1(void) { printk_thread("thread 1", 30); }
+static void printk_thread_2(void) { printk_thread("thread 2", 20); }
+
 static void noinline __init_refok rest_init(void)
 	__releases(kernel_lock)
 {
 	int pid;
 
-	kernel_thread(kernel_init, NULL, CLONE_FS | CLONE_SIGHAND);
+	//kernel_thread(kernel_init, NULL, CLONE_FS | CLONE_SIGHAND);
 	numa_default_policy();
 	pid = kernel_thread(kthreadd, NULL, CLONE_FS | CLONE_FILES);
 	kthreadd_task = find_task_by_pid_ns(pid, &init_pid_ns);
 	unlock_kernel();
 
+	kernel_thread(printk_thread_1, NULL, CLONE_FS | CLONE_SIGHAND);
+	kernel_thread(printk_thread_2, NULL, CLONE_FS | CLONE_SIGHAND);
+
 	/*
 	 * The boot idle thread must execute schedule()
 	 * at least once to get things moving:

This will normally create an output that looks something like this:

Here we go: thread 2, <6>Here we go: thread 1, thread 2, thread 1, thread 2, thread 1, thread 2, thread 2, thread 1, thread 2, thread 1, thread 2, thread 2
thread 1, <6>Here we go: thread 2, thread 1, thread 2, thread 2, thread 1
thread 2, <6>Here we go: thread 1, thread 2, thread 2, thread 1, thread 2, thread 1, thread 2

(Notice the log-level tokens appearing in the middle of some lines.)

With my patch to printk(), the same code now produces this output:

Here we go: thread 1, ...
Here we go: thread 2, thread 2, ...
thread 1, ...
thread 2, ...
thread 1, ...
thread 2, thread 2, ...
thread 1, ...

I first thought of using "current" as the way to distinguish two callers,
but there are two issues with this: 1) I don't think "current" is legal to
access in all contexts, but maybe I am wrong. 2) Executing some kernel
code, say a system call, and an IRQ happening while we are executing inside
that system call will not make "current" change.

Then I thought of using __builtin_return_address(), but in a function, two
different printks will have a different return address.

So we are now using __builtin_frame_address(). This should work everywhere
and should not cause any harmful side effects.

(Yes, this means that "continuation calls across functions" won't work. But
that's broken by design, at least in my opinion.)

The GCC manual says "This function should only be used with a nonzero
argument for debugging purposes", but it is nothing to worry about, as we
are in fact calling it with a zero argument.

The only thing I worry about is whether it will work on all architectures.
Does anybody see anything that can go wrong with this patch?

(The remaining issue is to figure out what the loglevel of the next message
should be, the one that is being continued. It may lead to "leaking" of
certain loglevel messages, but that's a much more fundamental problem and
this patch is at least a step in the right direction.)

Vegard