| Message ID | 1476962596-21046-1-git-send-email-mark.rutland@arm.com |
|---|---|
| State | Accepted |
| Commit | db4b0710fae90a4407bfa77b23db396e580b9e23 |
| Headers | show |
Hi Mark, On 20/10/16 12:23, Mark Rutland wrote: > 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 <mark.rutland@arm.com> > Cc: Catalin Marinas <catalin.marinas@arm.com> > Cc: Will Deacon <will.deacon@arm.com> > --- > arch/arm64/kernel/process.c | 15 ++++++++++++--- > 1 file changed, 12 insertions(+), 3 deletions(-) > > diff --git a/arch/arm64/kernel/process.c b/arch/arm64/kernel/process.c > index ddce61b..3f31cf93 100644 > --- a/arch/arm64/kernel/process.c > +++ b/arch/arm64/kernel/process.c > @@ -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"); > } 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. > printk("\n"); > } > _______________________________________________ linux-arm-kernel mailing list linux-arm-kernel@lists.infradead.org http://lists.infradead.org/mailman/listinfo/linux-arm-kernel
Hi, On Fri, Oct 21, 2016 at 12:34:11PM +0100, Robin Murphy wrote: > > diff --git a/arch/arm64/kernel/process.c b/arch/arm64/kernel/process.c > > index ddce61b..3f31cf93 100644 > > --- a/arch/arm64/kernel/process.c > > +++ b/arch/arm64/kernel/process.c > > @@ -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"); > > } > > 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. > 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) ... > 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. _______________________________________________ linux-arm-kernel mailing list linux-arm-kernel@lists.infradead.org http://lists.infradead.org/mailman/listinfo/linux-arm-kernel
On 21/10/16 13:54, Mark Rutland wrote: > Hi, > > On Fri, Oct 21, 2016 at 12:34:11PM +0100, Robin Murphy wrote: >>> diff --git a/arch/arm64/kernel/process.c b/arch/arm64/kernel/process.c >>> index ddce61b..3f31cf93 100644 >>> --- a/arch/arm64/kernel/process.c >>> +++ b/arch/arm64/kernel/process.c >>> @@ -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"); >>> } >> >> 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. 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. >> 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) ... > >> 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. 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. > > Thanks, > Mark. > _______________________________________________ linux-arm-kernel mailing list linux-arm-kernel@lists.infradead.org http://lists.infradead.org/mailman/listinfo/linux-arm-kernel
diff --git a/arch/arm64/kernel/process.c b/arch/arm64/kernel/process.c index ddce61b..3f31cf93 100644 --- a/arch/arm64/kernel/process.c +++ b/arch/arm64/kernel/process.c @@ -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"); }
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 <mark.rutland@arm.com> Cc: Catalin Marinas <catalin.marinas@arm.com> Cc: Will Deacon <will.deacon@arm.com> --- arch/arm64/kernel/process.c | 15 ++++++++++++--- 1 file changed, 12 insertions(+), 3 deletions(-) -- 1.9.1 _______________________________________________ linux-arm-kernel mailing list linux-arm-kernel@lists.infradead.org http://lists.infradead.org/mailman/listinfo/linux-arm-kernel