arm64: fix show_regs fallout from KERN_CONT changes

PATCH New Mark Rutland 2 participants 4 messages Oct 20, 2016 – Oct 21, 2016 arm64

Share & tools

Mark Rutland

author reviewer

2016-10-20 11:23 UTC #0 lore raw

PATCH 1/1 arm64: fix show_regs fallout from KERN_CONT changes

Recently in commit 4bcc595ccd80decb ("printk: reinstate KERN_CONT for printing continuation lines"), the behaviour of printk changed w.r.t. KERN_CONT. Now, KERN_CONT is mandatory to continue existing lines. Without this, prefixes are inserted, making output illegible, e.g.

[ 1007.069010] pc : [<ffff00000871898c>] lr : [<ffff000008718948>] pstate: 40000145
[ 1007.076329] sp : ffff000008d53ec0
[ 1007.079606] x29: ffff000008d53ec0 [ 1007.082797] x28: 0000000080c50018
[ 1007.086160]
[ 1007.087630] x27: ffff000008e0c7f8 [ 1007.090820] x26: ffff80097631ca00
[ 1007.094183]
[ 1007.095653] x25: 0000000000000001 [ 1007.098843] x24: 000000ea68b61cac
[ 1007.102206]

... or when dumped with the userpace dmesg tool, which has slightly different implicit newline behaviour. e.g.

[ 1007.069010] pc : [<ffff00000871898c>] lr : [<ffff000008718948>] pstate: 40000145
[ 1007.076329] sp : ffff000008d53ec0
[ 1007.079606] x29: ffff000008d53ec0
[ 1007.082797] x28: 0000000080c50018
[ 1007.086160]
[ 1007.087630] x27: ffff000008e0c7f8
[ 1007.090820] x26: ffff80097631ca00
[ 1007.094183]
[ 1007.095653] x25: 0000000000000001
[ 1007.098843] x24: 000000ea68b61cac
[ 1007.102206]

We can't simply always use KERN_CONT for lines which may or may not be continuations. That causes line prefixes (e.g. timestamps) to be supressed, and the alignment of all but the first line will be broken.

For even more fun, we can't simply insert some dummy empty-string printk calls, as GCC warns for an empty printk string, and even if we pass KERN_DEFAULT explcitly to silence the warning, the prefix gets swallowed unless there is an additional part to the string.

Instead, we must manually iterate over pairs of registers, which gives us the legible output we want in either case, e.g.

[  169.771790] pc : [<ffff00000871898c>] lr : [<ffff000008718948>] pstate: 40000145
[  169.779109] sp : ffff000008d53ec0
[  169.782386] x29: ffff000008d53ec0 x28: 0000000080c50018
[  169.787650] x27: ffff000008e0c7f8 x26: ffff80097631de00
[  169.792913] x25: 0000000000000001 x24: 00000027827b2cf4

Signed-off-by Mark Rutland <[email protected]>

Cc Catalin Marinas <[email protected]>

Cc Will Deacon <[email protected]>

---
 arch/arm64/kernel/process.c | 15 ++++++++++++---
 1 file changed, 12 insertions(+), 3 deletions(-)

arch/arm64/kernel/process.c +12 -3

index ddce61b..3f31cf93 100644
@@ -187,10 +187,19 @@ void __show_regs(struct pt_regs *regs)
 	printk("pc : [<%016llx>] lr : [<%016llx>] pstate: %08llx\n",
 	       regs->pc, lr, regs->pstate);
 	printk("sp : %016llx\n", sp);
-	for (i = top_reg; i >= 0; i--) {
+
+	i = top_reg;
+
+	while (i >= 0) {
 		printk("x%-2d: %016llx ", i, regs->regs[i]);
-		if (i % 2 == 0)
-			printk("\n");
+		i--;
+
+		if (i % 2 == 0) {
+			pr_cont("x%-2d: %016llx ", i, regs->regs[i]);
+			i--;
+		}
+
+		pr_cont("\n");
 	}
 	printk("\n");
 }

Signature · 1 line

1.9.1

Robin Murphy

2016-10-21 11:34 UTC #1 lore raw

PATCH 1/1 arm64: fix show_regs fallout from KERN_CONT changes

Hi Mark,

Quoted 69 lines · Mark Rutland

Recently in commit 4bcc595ccd80decb ("printk: reinstate KERN_CONT for printing continuation lines"), the behaviour of printk changed w.r.t. KERN_CONT. Now, KERN_CONT is mandatory to continue existing lines. Without this, prefixes are inserted, making output illegible, e.g.
[ 1007.069010] pc : [<ffff00000871898c>] lr : [<ffff000008718948>] pstate: 40000145
[ 1007.076329] sp : ffff000008d53ec0
[ 1007.079606] x29: ffff000008d53ec0 [ 1007.082797] x28: 0000000080c50018
[ 1007.086160]
[ 1007.087630] x27: ffff000008e0c7f8 [ 1007.090820] x26: ffff80097631ca00
[ 1007.094183]
[ 1007.095653] x25: 0000000000000001 [ 1007.098843] x24: 000000ea68b61cac
[ 1007.102206]
... or when dumped with the userpace dmesg tool, which has slightly different implicit newline behaviour. e.g.
[ 1007.069010] pc : [<ffff00000871898c>] lr : [<ffff000008718948>] pstate: 40000145
[ 1007.076329] sp : ffff000008d53ec0
[ 1007.079606] x29: ffff000008d53ec0
[ 1007.082797] x28: 0000000080c50018
[ 1007.086160]
[ 1007.087630] x27: ffff000008e0c7f8
[ 1007.090820] x26: ffff80097631ca00
[ 1007.094183]
[ 1007.095653] x25: 0000000000000001
[ 1007.098843] x24: 000000ea68b61cac
[ 1007.102206]
We can't simply always use KERN_CONT for lines which may or may not be continuations. That causes line prefixes (e.g. timestamps) to be supressed, and the alignment of all but the first line will be broken.
For even more fun, we can't simply insert some dummy empty-string printk calls, as GCC warns for an empty printk string, and even if we pass KERN_DEFAULT explcitly to silence the warning, the prefix gets swallowed unless there is an additional part to the string.
Instead, we must manually iterate over pairs of registers, which gives us the legible output we want in either case, e.g.
[  169.771790] pc : [<ffff00000871898c>] lr : [<ffff000008718948>] pstate: 40000145
[  169.779109] sp : ffff000008d53ec0
[  169.782386] x29: ffff000008d53ec0 x28: 0000000080c50018
[  169.787650] x27: ffff000008e0c7f8 x26: ffff80097631de00
[  169.792913] x25: 0000000000000001 x24: 00000027827b2cf4
Signed-off-by Mark Rutland <[email protected]>
Cc Catalin Marinas <[email protected]>
Cc Will Deacon <[email protected]>
---
 arch/arm64/kernel/process.c | 15 ++++++++++++---
 1 file changed, 12 insertions(+), 3 deletions(-)
arch/arm64/kernel/process.c +4 -2
index ddce61b..3f31cf93 100644
@@ -187,10 +187,19 @@ void __show_regs(struct pt_regs *regs)
 	printk("pc : [<%016llx>] lr : [<%016llx>] pstate: %08llx\n",
 	       regs->pc, lr, regs->pstate);
 	printk("sp : %016llx\n", sp);
-	for (i = top_reg; i >= 0; i--) {
+
+	i = top_reg;
+
+	while (i >= 0) {
 		printk("x%-2d: %016llx ", i, regs->regs[i]);
-		if (i % 2 == 0)

arch/arm64/kernel/process.c void __show_regs(struct pt_regs *regs) · line 203

Quoted 10 lines

arch/arm64/kernel/process.c +8 -1

-			printk("\n");
+		i--;
+
+		if (i % 2 == 0) {
+			pr_cont("x%-2d: %016llx ", i, regs->regs[i]);
+			i--;
+		}
+
+		pr_cont("\n");
 	}

Might it be nicer to simply do this (or thereabouts)?

	for (i = top_reg; i > 1; i -= 2)
		printk("x%-2d: %016llx x%-2d: %016llx\n", i-1,
			regs->regs[i-1], i, regs->regs[i]);
	if (i > 0)
		printk("x%-2d: %016llx\n", i-1, regs->regs[i-1]);

Robin.

Quoted 3 lines

arch/arm64/kernel/process.c +0 -0
 	printk("\n");
 }

Mark Rutland

author reviewer

2016-10-21 12:54 UTC #2 lore raw

PATCH 1/1 arm64: fix show_regs fallout from KERN_CONT changes

Hi,

Quoted 19 lines · Robin Murphy

Quoted 19 lines

arch/arm64/kernel/process.c +7 -3

index ddce61b..3f31cf93 100644
@@ -187,10 +187,19 @@ void __show_regs(struct pt_regs *regs)
 	printk("pc : [<%016llx>] lr : [<%016llx>] pstate: %08llx\n",
 	       regs->pc, lr, regs->pstate);
 	printk("sp : %016llx\n", sp);
-	for (i = top_reg; i >= 0; i--) {
+
+	i = top_reg;
+
+	while (i >= 0) {
 		printk("x%-2d: %016llx ", i, regs->regs[i]);
-		if (i % 2 == 0)
-			printk("\n");
+		i--;
+
+		if (i % 2 == 0) {

Quoted 8 lines

arch/arm64/kernel/process.c void __show_regs(struct pt_regs *regs) · line 203
Quoted 6 lines
arch/arm64/kernel/process.c +5 -0
+			pr_cont("x%-2d: %016llx ", i, regs->regs[i]);
+			i--;
+		}
+
+		pr_cont("\n");
 	}
Might it be nicer to simply do this (or thereabouts)?

I don't think so; top_reg is either 12 (for compat), or 29 (for native), so for the compat case, with the existing code the first line should be one register (r12), with r1; r0 on the final line.

Quoted 3 lines

	for (i = top_reg; i > 1; i -= 2)
		printk("x%-2d: %016llx x%-2d: %016llx\n", i-1,
			regs->regs[i-1], i, regs->regs[i]);

... whereas here the first line would be two (r12 and r11) ...

Quoted 2 lines

	if (i > 0)
		printk("x%-2d: %016llx\n", i-1, regs->regs[i-1]);

... and then r0 on its own.

Perhaps that's fine, but it would differ from the existing behaviour, and make native and compat noticeably different.

We could try fixing up the first line prior to the loop, but that still requires duplicating the format string thrice, manipulation of i, etc.

It looks like Will's taken my patch as-is, but if we can clean this up further it would certainly be nice.

Thanks,
Mark.

Robin Murphy

2016-10-21 13:48 UTC #3 lore raw

PATCH 1/1 arm64: fix show_regs fallout from KERN_CONT changes

Quoted 31 lines · Mark Rutland

Hi,

Quoted 19 lines · Robin Murphy

Quoted 19 lines

arch/arm64/kernel/process.c +7 -3

index ddce61b..3f31cf93 100644
@@ -187,10 +187,19 @@ void __show_regs(struct pt_regs *regs)
 	printk("pc : [<%016llx>] lr : [<%016llx>] pstate: %08llx\n",
 	       regs->pc, lr, regs->pstate);
 	printk("sp : %016llx\n", sp);
-	for (i = top_reg; i >= 0; i--) {
+
+	i = top_reg;
+
+	while (i >= 0) {
 		printk("x%-2d: %016llx ", i, regs->regs[i]);
-		if (i % 2 == 0)
-			printk("\n");
+		i--;
+
+		if (i % 2 == 0) {

Quoted 8 lines

arch/arm64/kernel/process.c void __show_regs(struct pt_regs *regs) · line 203
Quoted 6 lines
arch/arm64/kernel/process.c +5 -0
+			pr_cont("x%-2d: %016llx ", i, regs->regs[i]);
+			i--;
+		}
+
+		pr_cont("\n");
 	}
Might it be nicer to simply do this (or thereabouts)?

Quoted 3 lines

I don't think so; top_reg is either 12 (for compat), or 29 (for native), so for the compat case, with the existing code the first line should be one register (r12), with r1; r0 on the final line.

Heh, the "or thereabouts" was intended to acknowledge the act of copy-pasting patch context around in an email client without even looking at the original code (or how it's called) ;)

The main idea was that it looks feasible to avoid pr_cont() and the yucky floating "\n"s altogether.

Quoted 11 lines

Quoted 3 lines
	for (i = top_reg; i > 1; i -= 2)
		printk("x%-2d: %016llx x%-2d: %016llx\n", i-1,
			regs->regs[i-1], i, regs->regs[i]);
... whereas here the first line would be two (r12 and r11) ...
Quoted 2 lines
	if (i > 0)
		printk("x%-2d: %016llx\n", i-1, regs->regs[i-1]);
... and then r0 on its own.

Quoted 8 lines

Perhaps that's fine, but it would differ from the existing behaviour, and make native and compat noticeably different.
We could try fixing up the first line prior to the loop, but that still requires duplicating the format string thrice, manipulation of i, etc.
It looks like Will's taken my patch as-is, but if we can clean this up further it would certainly be nice.

Sure, getting it un-broken for 4.9 is the important thing. I'll take a proper look into the refactoring idea next time I get bored.

Robin.

Quoted 4 lines

Thanks,
Mark.