Collect whole stack dump lines in a buffer and print the whole buffer
when it's ready with pr_info instead of pr_cont. This makes stack dump
lines consistent in SMP case and relies less on pr_cont/printk
differences related to timestamps.
Make size of stack dump configurable.
Drop extra newline output in show_trace as its output format does not
depend on CONFIG_KALLSYMS.
Signed-off-by: Max Filippov <[email protected]>
---
arch/xtensa/Kconfig.debug | 7 +++++++
arch/xtensa/kernel/traps.c | 12 ++++++------
2 files changed, 13 insertions(+), 6 deletions(-)
diff --git a/arch/xtensa/Kconfig.debug b/arch/xtensa/Kconfig.debug
index 39de98e20018..83cc8d12fa0e 100644
--- a/arch/xtensa/Kconfig.debug
+++ b/arch/xtensa/Kconfig.debug
@@ -31,3 +31,10 @@ config S32C1I_SELFTEST
It is easy to make wrong hardware configuration, this test should catch it early.
Say 'N' on stable hardware.
+
+config PRINT_STACK_DEPTH
+ int "Stack depth to print" if DEBUG_KERNEL
+ default 64
+ help
+ This option allows you to set the stack depth that the kernel
+ prints in stack traces.
diff --git a/arch/xtensa/kernel/traps.c b/arch/xtensa/kernel/traps.c
index 4a6c495ce9b6..b0c952652c73 100644
--- a/arch/xtensa/kernel/traps.c
+++ b/arch/xtensa/kernel/traps.c
@@ -491,17 +491,15 @@ void show_trace(struct task_struct *task, unsigned long *sp)
pr_info("Call Trace:\n");
walk_stackframe(sp, show_trace_cb, NULL);
-#ifndef CONFIG_KALLSYMS
- pr_cont("\n");
-#endif
}
-static int kstack_depth_to_print = 24;
+static int kstack_depth_to_print = CONFIG_PRINT_STACK_DEPTH;
void show_stack(struct task_struct *task, unsigned long *sp)
{
int i = 0;
unsigned long *stack;
+ char buf[9 * 8 + 1];
if (!sp)
sp = stack_pointer(task);
@@ -512,10 +510,12 @@ void show_stack(struct task_struct *task, unsigned long *sp)
for (i = 0; i < kstack_depth_to_print; i++) {
if (kstack_end(sp))
break;
- pr_cont(" %08lx", *sp++);
+ sprintf(buf + (i % 8) * 9, " %08lx", *sp++);
if (i % 8 == 7)
- pr_cont("\n");
+ pr_info("%s\n", buf);
}
+ if (i % 8)
+ pr_info("%s\n", buf);
show_trace(task, stack);
}
--
2.20.1
Hi Max,
On 11/6/19 6:16 PM, Max Filippov wrote:
> Collect whole stack dump lines in a buffer and print the whole buffer
> when it's ready with pr_info instead of pr_cont. This makes stack dump
> lines consistent in SMP case and relies less on pr_cont/printk
> differences related to timestamps.
> Make size of stack dump configurable.
> Drop extra newline output in show_trace as its output format does not
> depend on CONFIG_KALLSYMS.
>
> Signed-off-by: Max Filippov <[email protected]>
[..]
> void show_stack(struct task_struct *task, unsigned long *sp)
> {
> int i = 0;
> unsigned long *stack;
> + char buf[9 * 8 + 1];
>
> if (!sp)
> sp = stack_pointer(task);
> @@ -512,10 +510,12 @@ void show_stack(struct task_struct *task, unsigned long *sp)
> for (i = 0; i < kstack_depth_to_print; i++) {
> if (kstack_end(sp))
> break;
> - pr_cont(" %08lx", *sp++);
> + sprintf(buf + (i % 8) * 9, " %08lx", *sp++);
buf is on the stack, does sprintf() put null-terminator for hex?
> if (i % 8 == 7)
> - pr_cont("\n");
> + pr_info("%s\n", buf);
> }
> + if (i % 8)
> + pr_info("%s\n", buf);
If the stack trace ends with (i % 8 == 7), you'll double-print the last
line?
Thanks,
Dmitry
On Wed, Nov 6, 2019 at 12:51 PM Dmitry Safonov <[email protected]> wrote:
> On 11/6/19 6:16 PM, Max Filippov wrote:
> > @@ -512,10 +510,12 @@ void show_stack(struct task_struct *task, unsigned long *sp)
> > for (i = 0; i < kstack_depth_to_print; i++) {
> > if (kstack_end(sp))
> > break;
> > - pr_cont(" %08lx", *sp++);
> > + sprintf(buf + (i % 8) * 9, " %08lx", *sp++);
>
> buf is on the stack, does sprintf() put null-terminator for hex?
It should put null-terminator regardless of the format string.
> > if (i % 8 == 7)
> > - pr_cont("\n");
> > + pr_info("%s\n", buf);
> > }
> > + if (i % 8)
> > + pr_info("%s\n", buf);
>
> If the stack trace ends with (i % 8 == 7), you'll double-print the last
> line?
No, I don't think so. 'For' loop condition is checked after i++, so if
loop ends with i % 8 == 7 then its last iteration was done with
i % 8 == 6 and thus the buf haven't been printed.
--
Thanks.
-- Max
On 11/6/19 10:00 PM, Max Filippov wrote:
> On Wed, Nov 6, 2019 at 12:51 PM Dmitry Safonov <[email protected]> wrote:
>> On 11/6/19 6:16 PM, Max Filippov wrote:
>>> @@ -512,10 +510,12 @@ void show_stack(struct task_struct *task, unsigned long *sp)
>>> for (i = 0; i < kstack_depth_to_print; i++) {
>>> if (kstack_end(sp))
>>> break;
>>> - pr_cont(" %08lx", *sp++);
>>> + sprintf(buf + (i % 8) * 9, " %08lx", *sp++);
>>
>> buf is on the stack, does sprintf() put null-terminator for hex?
>
> It should put null-terminator regardless of the format string.
Always unsure what to expect from printf() :)
>
>>> if (i % 8 == 7)
>>> - pr_cont("\n");
>>> + pr_info("%s\n", buf);
>>> }
>>> + if (i % 8)
>>> + pr_info("%s\n", buf);
>>
>> If the stack trace ends with (i % 8 == 7), you'll double-print the last
>> line?
>
> No, I don't think so. 'For' loop condition is checked after i++, so if
> loop ends with i % 8 == 7 then its last iteration was done with
> i % 8 == 6 and thus the buf haven't been printed.
Ah, right - me being stupid.
Thanks,
Dmitry
On Wed, 2019-11-06 at 10:16 -0800, Max Filippov wrote:
> Collect whole stack dump lines in a buffer and print the whole buffer
> when it's ready with pr_info instead of pr_cont. This makes stack dump
> lines consistent in SMP case and relies less on pr_cont/printk
> differences related to timestamps.
> Make size of stack dump configurable.
> Drop extra newline output in show_trace as its output format does not
> depend on CONFIG_KALLSYMS.
[]
> diff --git a/arch/xtensa/kernel/traps.c b/arch/xtensa/kernel/traps.c
[]
> @@ -512,10 +510,12 @@ void show_stack(struct task_struct *task, unsigned long *sp)
> for (i = 0; i < kstack_depth_to_print; i++) {
> if (kstack_end(sp))
> break;
> - pr_cont(" %08lx", *sp++);
> + sprintf(buf + (i % 8) * 9, " %08lx", *sp++);
> if (i % 8 == 7)
> - pr_cont("\n");
> + pr_info("%s\n", buf);
> }
> + if (i % 8)
> + pr_info("%s\n", buf);
Could this be done using hex_dump_to_buffer
by precalculating kstack_end ?
On Wed, Nov 6, 2019 at 2:34 PM Joe Perches <[email protected]> wrote:
> > @@ -512,10 +510,12 @@ void show_stack(struct task_struct *task, unsigned long *sp)
> > for (i = 0; i < kstack_depth_to_print; i++) {
> > if (kstack_end(sp))
> > break;
> > - pr_cont(" %08lx", *sp++);
> > + sprintf(buf + (i % 8) * 9, " %08lx", *sp++);
> > if (i % 8 == 7)
> > - pr_cont("\n");
> > + pr_info("%s\n", buf);
> > }
> > + if (i % 8)
> > + pr_info("%s\n", buf);
>
> Could this be done using hex_dump_to_buffer
> by precalculating kstack_end ?
I've got this, but it doesn't look very attractive to me:
void show_stack(struct task_struct *task, unsigned long *sp)
{
unsigned long *stack;
int len;
if (!sp)
sp = stack_pointer(task);
stack = sp;
len = min((-(unsigned long)stack) & (THREAD_SIZE - 4),
kstack_depth_to_print * 4ul);
pr_info("Stack:\n");
for (; len > 0; len -= 32) {
char buf[9 * 8 + 1];
hex_dump_to_buffer(sp, min(len, 32), 32, 4,
buf, sizeof(buf), false);
pr_info(" %08lx: %s\n", (unsigned long)sp, buf);
sp += 8;
}
show_trace(task, stack);
}
--
Thanks.
-- Max
On Wed 2019-11-06 16:21:51, Max Filippov wrote:
> On Wed, Nov 6, 2019 at 2:34 PM Joe Perches <[email protected]> wrote:
> > > @@ -512,10 +510,12 @@ void show_stack(struct task_struct *task, unsigned long *sp)
> > > for (i = 0; i < kstack_depth_to_print; i++) {
> > > if (kstack_end(sp))
> > > break;
> > > - pr_cont(" %08lx", *sp++);
> > > + sprintf(buf + (i % 8) * 9, " %08lx", *sp++);
> > > if (i % 8 == 7)
> > > - pr_cont("\n");
> > > + pr_info("%s\n", buf);
> > > }
> > > + if (i % 8)
> > > + pr_info("%s\n", buf);
> >
> > Could this be done using hex_dump_to_buffer
> > by precalculating kstack_end ?
>
> I've got this, but it doesn't look very attractive to me:
>
> void show_stack(struct task_struct *task, unsigned long *sp)
> {
> unsigned long *stack;
> int len;
>
> if (!sp)
> sp = stack_pointer(task);
> stack = sp;
>
> len = min((-(unsigned long)stack) & (THREAD_SIZE - 4),
> kstack_depth_to_print * 4ul);
>
> pr_info("Stack:\n");
>
> for (; len > 0; len -= 32) {
> char buf[9 * 8 + 1];
>
> hex_dump_to_buffer(sp, min(len, 32), 32, 4,
> buf, sizeof(buf), false);
> pr_info(" %08lx: %s\n", (unsigned long)sp, buf);
> sp += 8;
> }
I wonder if the cycle actually could get replaced by a single call:
print_hex_dump(KERN_INFO, "", DUMP_PREFIX_OFFSET,
16, 1, sp, len, false);
print_hex_dump() currently does not allow to print 8 bytes per-line.
Either 16 is acceptable or hex_dump() function could be updated.
Best Regards,
Petr
On Thu, 2019-11-07 at 15:38 +0100, Petr Mladek wrote:
> On Wed 2019-11-06 16:21:51, Max Filippov wrote:
> > On Wed, Nov 6, 2019 at 2:34 PM Joe Perches <[email protected]> wrote:
> > > > @@ -512,10 +510,12 @@ void show_stack(struct task_struct *task, unsigned long *sp)
> > > > for (i = 0; i < kstack_depth_to_print; i++) {
> > > > if (kstack_end(sp))
> > > > break;
> > > > - pr_cont(" %08lx", *sp++);
> > > > + sprintf(buf + (i % 8) * 9, " %08lx", *sp++);
> > > > if (i % 8 == 7)
> > > > - pr_cont("\n");
> > > > + pr_info("%s\n", buf);
> > > > }
> > > > + if (i % 8)
> > > > + pr_info("%s\n", buf);
> > >
> > > Could this be done using hex_dump_to_buffer
> > > by precalculating kstack_end ?
> >
> > I've got this, but it doesn't look very attractive to me:
> >
> > void show_stack(struct task_struct *task, unsigned long *sp)
> > {
> > unsigned long *stack;
> > int len;
> >
> > if (!sp)
> > sp = stack_pointer(task);
> > stack = sp;
> >
> > len = min((-(unsigned long)stack) & (THREAD_SIZE - 4),
> > kstack_depth_to_print * 4ul);
> >
> > pr_info("Stack:\n");
> >
> > for (; len > 0; len -= 32) {
> > char buf[9 * 8 + 1];
> >
> > hex_dump_to_buffer(sp, min(len, 32), 32, 4,
> > buf, sizeof(buf), false);
> > pr_info(" %08lx: %s\n", (unsigned long)sp, buf);
> > sp += 8;
> > }
>
> I wonder if the cycle actually could get replaced by a single call:
>
> print_hex_dump(KERN_INFO, "", DUMP_PREFIX_OFFSET,
> 16, 1, sp, len, false);
I think it could be using 4 and not 1 to keep the same output
of a u32 instead of spaces between bytes.