[PATCH 1/2] powerpc/process: fix nested output in show_user_instructions()

When two processes crash at the same time, we sometimes encounter
nesting in the middle of a line:

[    4.365317] init[1]: segfault (11) at 0 nip 0 lr 0 code 1
[    4.370452] init[1]: code: XXXXXXXX XXXXXXXX XXXXXXXX XXXXXXXX
[    4.372042] init[74]: segfault (11) at 10a74 nip 1000c198 lr 100078c8 code 1 in sh[10000000+14000]
[    4.386829] XXXXXXXX XXXXXXXX XXXXXXXX XXXXXXXX
[    4.391542] init[1]: code: XXXXXXXX XXXXXXXX XXXXXXXX XXXXXXXX XXXXXXXX XXXXXXXX XXXXXXXX XXXXXXXX
[    4.400863] init[74]: code: 90010024 bf61000c 91490a7c 3fa01002 3be00000 7d3e4b78 3bbd0c20 3b600000
[    4.409867] init[74]: code: 3b9d0040 7c7fe02e 2f830000 419e0028 <89230000> 2f890000 41be001c 4b7f6e79

This patch fixes it by preparing complete lines in a buffer and
printing it at once.

Fixes: 88b0fe1757359 ("powerpc: Add show_user_instructions()")
Cc: Murilo Opsfelder Araujo <redacted>
Signed-off-by: Christophe Leroy <redacted>
---
 arch/powerpc/kernel/process.c | 17 +++++++++--------
 1 file changed, 9 insertions(+), 8 deletions(-)

diff --git a/arch/powerpc/kernel/process.c b/arch/powerpc/kernel/process.c
index 913c5725cdb2..c722ce4ca1c0 100644
--- a/arch/powerpc/kernel/process.c
+++ b/arch/powerpc/kernel/process.c

@@ -1303,32 +1303,33 @@ void show_user_instructions(struct pt_regs *regs)
 {
 	unsigned long pc;
 	int i;
+	char buf[96]; /* enough for 8 times 9 + 2 chars */
+	int l = 0;
 
 	pc = regs->nip - (instructions_to_print * 3 / 4 * sizeof(int));
 
-	pr_info("%s[%d]: code: ", current->comm, current->pid);
-
 	for (i = 0; i < instructions_to_print; i++) {
 		int instr;
 
 		if (!(i % 8) && (i > 0)) {
-			pr_cont("\n");
-			pr_info("%s[%d]: code: ", current->comm, current->pid);
+			pr_info("%s[%d]: code: %s\n", current->comm, current->pid, buf);
+			l = 0;
 		}
 
 		if (probe_kernel_address((unsigned int __user *)pc, instr)) {
-			pr_cont("XXXXXXXX ");
+			l += sprintf(buf + l, "XXXXXXXX ");
 		} else {
 			if (regs->nip == pc)
-				pr_cont("<%08x> ", instr);
+				l += sprintf(buf + l, "<%08x> ", instr);
 			else
-				pr_cont("%08x ", instr);
+				l += sprintf(buf + l, "%08x ", instr);
 		}
 
 		pc += sizeof(int);
 	}
 
-	pr_cont("\n");
+	if (l)
+		pr_info("%s[%d]: code: %s\n", current->comm, current->pid, buf);
 }
 
 struct regbit {

-- 
2.13.3

instructions_to_print var is assigned value 16 and there is no
way to change it.

This patch replaces it by a constant.

Signed-off-by: Christophe Leroy <redacted>
---
 arch/powerpc/kernel/process.c | 11 +++++------
 1 file changed, 5 insertions(+), 6 deletions(-)

diff --git a/arch/powerpc/kernel/process.c b/arch/powerpc/kernel/process.c
index c722ce4ca1c0..6317f2ed04ab 100644
--- a/arch/powerpc/kernel/process.c
+++ b/arch/powerpc/kernel/process.c

@@ -1259,17 +1259,16 @@ struct task_struct *__switch_to(struct task_struct *prev,
 	return last;
 }
 
-static int instructions_to_print = 16;
+#define NR_INSN_TO_PRINT	16
 
 static void show_instructions(struct pt_regs *regs)
 {
 	int i;
-	unsigned long pc = regs->nip - (instructions_to_print * 3 / 4 *
-			sizeof(int));
+	unsigned long pc = regs->nip - (NR_INSN_TO_PRINT * 3 / 4 * sizeof(int));
 
 	printk("Instruction dump:");
 
-	for (i = 0; i < instructions_to_print; i++) {
+	for (i = 0; i < NR_INSN_TO_PRINT; i++) {
 		int instr;
 
 		if (!(i % 8))

@@ -1306,9 +1305,9 @@ void show_user_instructions(struct pt_regs *regs)
 	char buf[96]; /* enough for 8 times 9 + 2 chars */
 	int l = 0;
 
-	pc = regs->nip - (instructions_to_print * 3 / 4 * sizeof(int));
+	pc = regs->nip - (NR_INSN_TO_PRINT * 3 / 4 * sizeof(int));
 
-	for (i = 0; i < instructions_to_print; i++) {
+	for (i = 0; i < NR_INSN_TO_PRINT; i++) {
 		int instr;
 
 		if (!(i % 8) && (i > 0)) {

-- 
2.13.3

Hi, Christophe.

On Tue, Aug 14, 2018 at 08:59:18AM +0000, Christophe Leroy wrote:

When two processes crash at the same time, we sometimes encounter
nesting in the middle of a line:

[    4.365317] init[1]: segfault (11) at 0 nip 0 lr 0 code 1
[    4.370452] init[1]: code: XXXXXXXX XXXXXXXX XXXXXXXX XXXXXXXX
[    4.372042] init[74]: segfault (11) at 10a74 nip 1000c198 lr 100078c8 code 1 in sh[10000000+14000]
[    4.386829] XXXXXXXX XXXXXXXX XXXXXXXX XXXXXXXX
[    4.391542] init[1]: code: XXXXXXXX XXXXXXXX XXXXXXXX XXXXXXXX XXXXXXXX XXXXXXXX XXXXXXXX XXXXXXXX
[    4.400863] init[74]: code: 90010024 bf61000c 91490a7c 3fa01002 3be00000 7d3e4b78 3bbd0c20 3b600000
[    4.409867] init[74]: code: 3b9d0040 7c7fe02e 2f830000 419e0028 <89230000> 2f890000 41be001c 4b7f6e79

My smoke test passed with the two patches.

Perhaps adding an output sample of how messages would look like after your patch
could be an enhancement to the commit message.

Otherwise:

Reviewed-by: Murilo Opsfelder Araujo <redacted>

-- 
Murilo

Hi, Christophe.

On Tue, Aug 14, 2018 at 08:59:20AM +0000, Christophe Leroy wrote:

instructions_to_print var is assigned value 16 and there is no
way to change it.

This patch replaces it by a constant.

Signed-off-by: Christophe Leroy <redacted>

Reviewed-by: Murilo Opsfelder Araujo <redacted>

-- 
Murilo

Christophe Leroy [off-list ref] writes:

When two processes crash at the same time, we sometimes encounter
nesting in the middle of a line:

I think "interleaved" is the right word, rather than "nesting".

They're actually (potentially) completely unrelated segfaults, that just
happen to occur at the same time.

And in fact any output that happens simultaneously will mess things up,
it doesn't have to be another segfault.

I'm sure your math is right, but still an on-stack buffer with sprintf()
is a bit scary.

Can you try using seq_buf instead? It is safe against overflow.

eg, something like:

struct seq_buf s;
char buf[96];

seq_buf_init(&s, buf, sizeof(buf));
...
seq_buf_printf(&s, ...);

cheers

Le 21/08/2018 à 08:27, Michael Ellerman a écrit :

Christophe Leroy [off-list ref] writes:

quoted

When two processes crash at the same time, we sometimes encounter
nesting in the middle of a line:

I think "interleaved" is the right word, rather than "nesting".

They're actually (potentially) completely unrelated segfaults, that just
happen to occur at the same time.

And in fact any output that happens simultaneously will mess things up,
it doesn't have to be another segfault.

Ok, i reworded in v2.

quoted

[    4.365317] init[1]: segfault (11) at 0 nip 0 lr 0 code 1
[    4.370452] init[1]: code: XXXXXXXX XXXXXXXX XXXXXXXX XXXXXXXX
[    4.372042] init[74]: segfault (11) at 10a74 nip 1000c198 lr 100078c8 code 1 in sh[10000000+14000]
[    4.386829] XXXXXXXX XXXXXXXX XXXXXXXX XXXXXXXX
[    4.391542] init[1]: code: XXXXXXXX XXXXXXXX XXXXXXXX XXXXXXXX XXXXXXXX XXXXXXXX XXXXXXXX XXXXXXXX
[    4.400863] init[74]: code: 90010024 bf61000c 91490a7c 3fa01002 3be00000 7d3e4b78 3bbd0c20 3b600000
[    4.409867] init[74]: code: 3b9d0040 7c7fe02e 2f830000 419e0028 <89230000> 2f890000 41be001c 4b7f6e79

This patch fixes it by preparing complete lines in a buffer and
printing it at once.

Fixes: 88b0fe1757359 ("powerpc: Add show_user_instructions()")
Cc: Murilo Opsfelder Araujo <redacted>
Signed-off-by: Christophe Leroy <redacted>
---
  arch/powerpc/kernel/process.c | 17 +++++++++--------
  1 file changed, 9 insertions(+), 8 deletions(-)

diff --git a/arch/powerpc/kernel/process.c b/arch/powerpc/kernel/process.c
index 913c5725cdb2..c722ce4ca1c0 100644
--- a/arch/powerpc/kernel/process.c
+++ b/arch/powerpc/kernel/process.c

@@ -1303,32 +1303,33 @@ void show_user_instructions(struct pt_regs *regs)
  {
  	unsigned long pc;
  	int i;
+	char buf[96]; /* enough for 8 times 9 + 2 chars */
+	int l = 0;

I'm sure your math is right, but still an on-stack buffer with sprintf()
is a bit scary.

Can you try using seq_buf instead? It is safe against overflow.

eg, something like:

struct seq_buf s;
char buf[96];

seq_buf_init(&s, buf, sizeof(buf));
...
seq_buf_printf(&s, ...);

Ok, I did that in v2. In the meantime I reworked the loop to avoid this 
uggly test against i % 8 and this duplication of the pr_info() of the 
code line.

Christophe