[RFC PATCH] Allow for stack traces to be printed on serial console

[RFC PATCH] Allow for stack traces to be printed on serial console

[Pavel Ivanov]

When I tried to chase some mysterious lockup of my PC the only means to
see some error reports for me was serial console. But it looks like only
printk with KERN_ERR is sent to serial console. So when hung task
detector tried to show me stack traces for hung tasks I didn't see them
on serial console and I didn't see them after reboot as they couldn't be
saved to dmesg. Thus the following patch allowed me to actually see
those stack traces.

I believe kernel prints stack traces only in some serious cases and
expects that they would be actually seen, so KERN_ERR looks justified
for me in all changed places. I understand that patch is incomplete and
would need some other places to be changed for consistency (at least
other arch code). But first I want to hear comments on whether this
approach is good enough to be included in mainline or it should be left
for me as a hack.


Signed-off-by: Pavel Ivanov <paivanof@gmail.com>
---

diff --git a/arch/x86/kernel/dumpstack.c b/arch/x86/kernel/dumpstack.c
index 1aae78f..52770aa 100644
--- a/arch/x86/kernel/dumpstack.c
+++ b/arch/x86/kernel/dumpstack.c
@@ -27,7 +27,7 @@ static int die_counter;
 
 void printk_address(unsigned long address, int reliable)
 {
-	printk(" [<%p>] %s%pB\n", (void *) address,
+	printk("[<%p>] %s%pB\n", (void *) address,
 			reliable ? "" : "? ", (void *) address);
 }
 
@@ -147,7 +147,7 @@ static int print_trace_stack(void *data, char *name)
 static void print_trace_address(void *data, unsigned long addr, int reliable)
 {
 	touch_nmi_watchdog();
-	printk(data);
+	printk("%s ", (char*)data);
 	printk_address(addr, reliable);
 }
 
@@ -173,7 +173,7 @@ void show_trace(struct task_struct *task, struct pt_regs *regs,
 
 void show_stack(struct task_struct *task, unsigned long *sp)
 {
-	show_stack_log_lvl(task, NULL, sp, 0, "");
+	show_stack_log_lvl(task, NULL, sp, 0, KERN_ERR);
 }
 
 /*
@@ -281,7 +281,7 @@ int __kprobes __die(const char *str, struct pt_regs *regs, long err)
 	printk(" SS:ESP %04x:%08lx\n", ss, sp);
 #else
 	/* Executive summary in case the oops scrolled away */
-	printk(KERN_ALERT "RIP ");
+	printk(KERN_ALERT "RIP  ");
 	printk_address(regs->ip, 1);
 	printk(" RSP <%016lx>\n", regs->sp);
 #endif
diff --git a/kernel/lockdep.c b/kernel/lockdep.c
index 91d67ce..eb525ba 100644
--- a/kernel/lockdep.c
+++ b/kernel/lockdep.c
@@ -547,14 +547,14 @@ static void lockdep_print_held_locks(struct task_struct *curr)
 	int i, depth = curr->lockdep_depth;
 
 	if (!depth) {
-		printk("no locks held by %s/%d.\n", curr->comm, task_pid_nr(curr));
+		printk(KERN_ERR "no locks held by %s/%d.\n", curr->comm, task_pid_nr(curr));
 		return;
 	}
-	printk("%d lock%s held by %s/%d:\n",
+	printk(KERN_ERR "%d lock%s held by %s/%d:\n",
 		depth, depth > 1 ? "s" : "", curr->comm, task_pid_nr(curr));
 
 	for (i = 0; i < depth; i++) {
-		printk(" #%d: ", i);
+		printk(KERN_ERR " #%d: ", i);
 		print_lock(curr->held_locks + i);
 	}
 }
@@ -3977,7 +3977,7 @@ EXPORT_SYMBOL_GPL(debug_show_all_locks);
 void debug_show_held_locks(struct task_struct *task)
 {
 	if (unlikely(!debug_locks)) {
-		printk("INFO: lockdep is turned off.\n");
+		printk(KERN_ERR "INFO: lockdep is turned off.\n");
 		return;
 	}
 	lockdep_print_held_locks(task);
diff --git a/kernel/sched.c b/kernel/sched.c
index ec5f472..e05d443 100644
--- a/kernel/sched.c
+++ b/kernel/sched.c
@@ -5865,7 +5865,7 @@ void sched_show_task(struct task_struct *p)
 	unsigned state;
 
 	state = p->state ? __ffs(p->state) + 1 : 0;
-	printk(KERN_INFO "%-15.15s %c", p->comm,
+	printk(KERN_ERR "%-15.15s %c", p->comm,
 		state < sizeof(stat_nam) - 1 ? stat_nam[state] : '?');
 #if BITS_PER_LONG == 32
 	if (state == TASK_RUNNING)

Re: [RFC PATCH] Allow for stack traces to be printed on serial console

[Srivatsa S. Bhat]

On 09/30/2011 10:19 AM, Pavel Ivanov wrote:
> When I tried to chase some mysterious lockup of my PC the only means to
> see some error reports for me was serial console. But it looks like only
> printk with KERN_ERR is sent to serial console. So when hung task
> detector tried to show me stack traces for hung tasks I didn't see them
> on serial console and I didn't see them after reboot as they couldn't be
> saved to dmesg. Thus the following patch allowed me to actually see
> those stack traces.

Which kernel messages gets displayed on your serial console is controlled by
your system configuration which can be altered by modifying /etc/rsyslog.conf
or /etc/sysconfig/syslog.conf 
There you can specify that you want to print every kernel message by specifying
kern.* for example.

There are also some kernel command line options you can use to specify which 
level of kernel messages you want to get displayed.

Since you clearly have a system configuration problem here, you don't need to alter the
kernel source to print with KERN_ERR everywhere. Doing that would also defeat the very
purpose of having that nice distinction between informational messages, error messages
and so on, isn't it?

> I believe kernel prints stack traces only in some serious cases and
> expects that they would be actually seen, so KERN_ERR looks justified
> for me in all changed places. I understand that patch is incomplete and
> would need some other places to be changed for consistency (at least
> other arch code). But first I want to hear comments on whether this
> approach is good enough to be included in mainline or it should be left
> for me as a hack.
> 
-- 
Regards,
Srivatsa S. Bhat  <srivatsa.bhat@linux.vnet.ibm.com>
Linux Technology Center,
IBM India Systems and Technology Lab

Re: [RFC PATCH] Allow for stack traces to be printed on serial console

[Pavel Ivanov]

On Mon, Oct 3, 2011 at 5:30 AM, Srivatsa S. Bhat
<srivatsa.bhat@linux.vnet.ibm.com> wrote:
> On 09/30/2011 10:19 AM, Pavel Ivanov wrote:
>> When I tried to chase some mysterious lockup of my PC the only means to
>> see some error reports for me was serial console. But it looks like only
>> printk with KERN_ERR is sent to serial console. So when hung task
>> detector tried to show me stack traces for hung tasks I didn't see them
>> on serial console and I didn't see them after reboot as they couldn't be
>> saved to dmesg. Thus the following patch allowed me to actually see
>> those stack traces.
>
> Which kernel messages gets displayed on your serial console is controlled by
> your system configuration which can be altered by modifying /etc/rsyslog.conf
> or /etc/sysconfig/syslog.conf
> There you can specify that you want to print every kernel message by specifying
> kern.* for example.

I've tried to add "kern.* /dev/ttyS0" and "*.* /dev/ttyS0" to
/etc/rsyslog.conf but it didn't help at all.

> There are also some kernel command line options you can use to specify which
> level of kernel messages you want to get displayed.

I've tried to add loglevel=7 as bootup parameter but it didn't help.
Then I've tried to
"echo $'7\t7\t1\t7' >/proc/sys/kernel/printk" and it helped a little
(message with level KERN_INFO was printed from sched_show_task() to
serial console). But still I wasn't able to see stack traces. Do I
miss something?

> Since you clearly have a system configuration problem here, you don't need to alter the
> kernel source to print with KERN_ERR everywhere. Doing that would also defeat the very
> purpose of having that nice distinction between informational messages, error messages
> and so on, isn't it?

Sure. But what configuration parameter should I tune?

I proposed this patch because I didn't believe that there can be cases
when kernel wants to print stack trace and somebody looking at serial
console doesn't want to see it. But of course I can live with some
configuration parameter as long as I find it.


>> I believe kernel prints stack traces only in some serious cases and
>> expects that they would be actually seen, so KERN_ERR looks justified
>> for me in all changed places. I understand that patch is incomplete and
>> would need some other places to be changed for consistency (at least
>> other arch code). But first I want to hear comments on whether this
>> approach is good enough to be included in mainline or it should be left
>> for me as a hack.