Skip to contentSkip to conversation

Allow for stack traces to be printed on serial console

RFC PATCH In review Pavel Ivanov 2 participants 3 messages Sep 30, 2011 – Oct 5, 2011 1 message not in the archive

Subsystems (2)
lore
Share & tools
lore

A message that is not in the archive (sent off-list or not yet received): CAG1a4rtrh7=+gr=kUGO6y4wt926F8rBusOcFgvu4CmvrmR5PCw@mail.gmail.com

#1 lore raw

RFC PATCH 1/1 Allow for stack traces to be printed on serial console

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.

---

arch/x86/kernel/dumpstack.c +4 -4
index 1aae78f..52770aa 100644
@@ -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
kernel/lockdep.c +4 -4
index 91d67ce..eb525ba 100644
@@ -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);
kernel/sched.c +1 -1
index ec5f472..e05d443 100644
@@ -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)
#2 lore raw
Quoted 7 lines · 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.

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?

Quoted 8 lines

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.

Signature · 4 lines
Regards,
Srivatsa S. Bhat  <[email protected]>
Linux Technology Center,
IBM India Systems and Technology Lab
#3 lore raw
Quoted 9 lines · Srivatsa S. Bhat
Quoted 7 lines · 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.

Quoted 5 lines

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.

Quoted 2 lines

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?

Quoted 4 lines

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.

Quoted 7 lines
Quoted 7 lines

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.