Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]

Groups > linux.kernel > #1552045 > unrolled thread

Re: stack unwinder warning.

Back to article view | Back to linux.kernel

This discussion starts older than the indexed window; earlier articles aren't shown. The article labeled Started by below is the oldest one visible, not the original post.

Contents

  Re: stack unwinder warning. Josh Poimboeuf <jpoimboe@redhat.com> - 2017-01-05 16:20 +0100
    Re: stack unwinder warning. Dave Jones <davej@codemonkey.org.uk> - 2017-01-05 18:10 +0100
    Re: stack unwinder warning. Josh Poimboeuf <jpoimboe@redhat.com> - 2017-01-05 18:10 +0100
      Re: stack unwinder warning. Dave Jones <davej@codemonkey.org.uk> - 2017-01-06 02:10 +0100
      Re: stack unwinder warning. Dave Jones <davej@codemonkey.org.uk> - 2017-01-06 06:20 +0100
        Re: stack unwinder warning. Josh Poimboeuf <jpoimboe@redhat.com> - 2017-01-06 18:00 +0100
          Re: stack unwinder warning. Dave Jones <davej@codemonkey.org.uk> - 2017-01-08 01:10 +0100

#1552045 — Re: stack unwinder warning.

On Tue, Dec 27, 2016 at 02:00:30PM -0500, Dave Jones wrote:
> I'm not sure what to make of this. Josh ?  (4.10-rc1)
> 
> WARNING: kernel stack frame pointer at ffffc900003e7858 in trinity-c6:29122 has bad value ffffffff82103a80
> unwind stack type:0 next_sp:          (null) mask:2 graph_idx:0
> ffffc900003e7808: ffffffff811a02e5 (ring_buffer_lock_reserve+0x1d5/0x580)
> ffffc900003e7810: ffffffff8119adc3 (rb_commit+0x93/0x350)
> ffffc900003e7818: ffffffff811b31d4 (function_trace_call+0x104/0x1f0)
> ffffc900003e7820: ffff8804f10ec000 (0xffff8804f10ec000)
> ffffc900003e7828: 0000000000000000 ...
> ffffc900003e7830: ffffffff8119b3ae (ring_buffer_unlock_commit+0x8e/0x120)
> ffffc900003e7838: 0000000000000001 (0x1)
> ffffc900003e7840: ffffea0002854e00 (0xffffea0002854e00)
> ffffc900003e7848: 000000000000000a (0xa)
> ffffc900003e7850: ffffea0002854ec0 (0xffffea0002854ec0)
> ffffc900003e7858: ffffea000287c480 (0xffffea000287c480)

The value reported by the warning contradicts the value reported by the
dump.  So this seems to have been caused by dumping the stack of a task
which is running on another CPU.  There are still some places in the
code where that's possible.  So I'm going to need to remove these
unwinder warnings for now.

-- 
Josh

[toc] | [next] | [standalone]

#1552116

On Thu, Jan 05, 2017 at 11:02:14AM -0600, Josh Poimboeuf wrote:
 > On Thu, Jan 05, 2017 at 08:52:49AM -0600, Josh Poimboeuf wrote:
 > > On Tue, Dec 27, 2016 at 02:00:30PM -0500, Dave Jones wrote:
 > > > I'm not sure what to make of this. Josh ?  (4.10-rc1)
 > > > 
 > > > WARNING: kernel stack frame pointer at ffffc900003e7858 in trinity-c6:29122 has bad value ffffffff82103a80
 > > > unwind stack type:0 next_sp:          (null) mask:2 graph_idx:0
 > > > ffffc900003e7808: ffffffff811a02e5 (ring_buffer_lock_reserve+0x1d5/0x580)
 > > > ffffc900003e7810: ffffffff8119adc3 (rb_commit+0x93/0x350)
 > > > ffffc900003e7818: ffffffff811b31d4 (function_trace_call+0x104/0x1f0)
 > > > ffffc900003e7820: ffff8804f10ec000 (0xffff8804f10ec000)
 > > > ffffc900003e7828: 0000000000000000 ...
 > > > ffffc900003e7830: ffffffff8119b3ae (ring_buffer_unlock_commit+0x8e/0x120)
 > > > ffffc900003e7838: 0000000000000001 (0x1)
 > > > ffffc900003e7840: ffffea0002854e00 (0xffffea0002854e00)
 > > > ffffc900003e7848: 000000000000000a (0xa)
 > > > ffffc900003e7850: ffffea0002854ec0 (0xffffea0002854ec0)
 > > > ffffc900003e7858: ffffea000287c480 (0xffffea000287c480)
 > > 
 > > The value reported by the warning contradicts the value reported by the
 > > dump.  So this seems to have been caused by dumping the stack of a task
 > > which is running on another CPU.  There are still some places in the
 > > code where that's possible.  So I'm going to need to remove these
 > > unwinder warnings for now.
 > 
 > I'll be submitting the following patch soon, which I think should
 > silence the warning.  If the warning is recreatable, would you mind
 > testing it?

Sure. It usually spits it out pretty quickly. I'll give it a run..

	Dave

[toc] | [prev] | [next] | [standalone]

#1552121

On Thu, Jan 05, 2017 at 08:52:49AM -0600, Josh Poimboeuf wrote:
> On Tue, Dec 27, 2016 at 02:00:30PM -0500, Dave Jones wrote:
> > I'm not sure what to make of this. Josh ?  (4.10-rc1)
> > 
> > WARNING: kernel stack frame pointer at ffffc900003e7858 in trinity-c6:29122 has bad value ffffffff82103a80
> > unwind stack type:0 next_sp:          (null) mask:2 graph_idx:0
> > ffffc900003e7808: ffffffff811a02e5 (ring_buffer_lock_reserve+0x1d5/0x580)
> > ffffc900003e7810: ffffffff8119adc3 (rb_commit+0x93/0x350)
> > ffffc900003e7818: ffffffff811b31d4 (function_trace_call+0x104/0x1f0)
> > ffffc900003e7820: ffff8804f10ec000 (0xffff8804f10ec000)
> > ffffc900003e7828: 0000000000000000 ...
> > ffffc900003e7830: ffffffff8119b3ae (ring_buffer_unlock_commit+0x8e/0x120)
> > ffffc900003e7838: 0000000000000001 (0x1)
> > ffffc900003e7840: ffffea0002854e00 (0xffffea0002854e00)
> > ffffc900003e7848: 000000000000000a (0xa)
> > ffffc900003e7850: ffffea0002854ec0 (0xffffea0002854ec0)
> > ffffc900003e7858: ffffea000287c480 (0xffffea000287c480)
> 
> The value reported by the warning contradicts the value reported by the
> dump.  So this seems to have been caused by dumping the stack of a task
> which is running on another CPU.  There are still some places in the
> code where that's possible.  So I'm going to need to remove these
> unwinder warnings for now.

I'll be submitting the following patch soon, which I think should
silence the warning.  If the warning is recreatable, would you mind
testing it?


diff --git a/arch/x86/kernel/unwind_frame.c b/arch/x86/kernel/unwind_frame.c
index 4443e49..6fda186 100644
--- a/arch/x86/kernel/unwind_frame.c
+++ b/arch/x86/kernel/unwind_frame.c
@@ -207,6 +207,16 @@ bool unwind_next_frame(struct unwind_state *state)
 	return true;
 
 bad_address:
+	/*
+	 * When dumping a task other than current, the task might actually be
+	 * running on another CPU, in which case it could be modifying its
+	 * stack while we're reading it.  This is generally not a problem and
+	 * can be ignored as long as the caller understands that unwinding
+	 * another task will not always succeed.
+	 */
+	if (state->task != current)
+		goto the_end;
+
 	if (state->regs) {
 		printk_deferred_once(KERN_WARNING
 			"WARNING: kernel stack regs at %p in %s:%d has bad 'bp' value %p\n",
-- 
2.7.4

[toc] | [prev] | [next] | [standalone]

#1552440

On Thu, Jan 05, 2017 at 11:02:14AM -0600, Josh Poimboeuf wrote:
 > On Thu, Jan 05, 2017 at 08:52:49AM -0600, Josh Poimboeuf wrote:
 > > On Tue, Dec 27, 2016 at 02:00:30PM -0500, Dave Jones wrote:
 > > > I'm not sure what to make of this. Josh ?  (4.10-rc1)
 > > > 
 > > > WARNING: kernel stack frame pointer at ffffc900003e7858 in trinity-c6:29122 has bad value ffffffff82103a80
 > > > unwind stack type:0 next_sp:          (null) mask:2 graph_idx:0
 > > > ffffc900003e7808: ffffffff811a02e5 (ring_buffer_lock_reserve+0x1d5/0x580)
 > > > ffffc900003e7810: ffffffff8119adc3 (rb_commit+0x93/0x350)
 > > > ffffc900003e7818: ffffffff811b31d4 (function_trace_call+0x104/0x1f0)
 > > > ffffc900003e7820: ffff8804f10ec000 (0xffff8804f10ec000)
 > > > ffffc900003e7828: 0000000000000000 ...
 > > > ffffc900003e7830: ffffffff8119b3ae (ring_buffer_unlock_commit+0x8e/0x120)
 > > > ffffc900003e7838: 0000000000000001 (0x1)
 > > > ffffc900003e7840: ffffea0002854e00 (0xffffea0002854e00)
 > > > ffffc900003e7848: 000000000000000a (0xa)
 > > > ffffc900003e7850: ffffea0002854ec0 (0xffffea0002854ec0)
 > > > ffffc900003e7858: ffffea000287c480 (0xffffea000287c480)
 > > 
 > > The value reported by the warning contradicts the value reported by the
 > > dump.  So this seems to have been caused by dumping the stack of a task
 > > which is running on another CPU.  There are still some places in the
 > > code where that's possible.  So I'm going to need to remove these
 > > unwinder warnings for now.
 > 
 > I'll be submitting the following patch soon, which I think should
 > silence the warning.  If the warning is recreatable, would you mind
 > testing it?

Ok, haven't seen anything fall out today while running with this, I'd
call it good. It usually showed up pretty quickly.

	Dave

[toc] | [prev] | [next] | [standalone]

#1552534

On Thu, Jan 05, 2017 at 11:02:14AM -0600, Josh Poimboeuf wrote:
 > On Thu, Jan 05, 2017 at 08:52:49AM -0600, Josh Poimboeuf wrote:
 > > On Tue, Dec 27, 2016 at 02:00:30PM -0500, Dave Jones wrote:
 > > > I'm not sure what to make of this. Josh ?  (4.10-rc1)
 > > > 
 > > > WARNING: kernel stack frame pointer at ffffc900003e7858 in trinity-c6:29122 has bad value ffffffff82103a80
 > > > unwind stack type:0 next_sp:          (null) mask:2 graph_idx:0
 > > > ffffc900003e7808: ffffffff811a02e5 (ring_buffer_lock_reserve+0x1d5/0x580)
 > > > ffffc900003e7810: ffffffff8119adc3 (rb_commit+0x93/0x350)
 > > > ffffc900003e7818: ffffffff811b31d4 (function_trace_call+0x104/0x1f0)
 > > > ffffc900003e7820: ffff8804f10ec000 (0xffff8804f10ec000)
 > > > ffffc900003e7828: 0000000000000000 ...
 > > > ffffc900003e7830: ffffffff8119b3ae (ring_buffer_unlock_commit+0x8e/0x120)
 > > > ffffc900003e7838: 0000000000000001 (0x1)
 > > > ffffc900003e7840: ffffea0002854e00 (0xffffea0002854e00)
 > > > ffffc900003e7848: 000000000000000a (0xa)
 > > > ffffc900003e7850: ffffea0002854ec0 (0xffffea0002854ec0)
 > > > ffffc900003e7858: ffffea000287c480 (0xffffea000287c480)
 > > 
 > > The value reported by the warning contradicts the value reported by the
 > > dump.  So this seems to have been caused by dumping the stack of a task
 > > which is running on another CPU.  There are still some places in the
 > > code where that's possible.  So I'm going to need to remove these
 > > unwinder warnings for now.
 > 
 > I'll be submitting the following patch soon, which I think should
 > silence the warning.  If the warning is recreatable, would you mind
 > testing it?

I didn't wait long enough..

WARNING: kernel stack frame pointer at ffffc90001443f30 in kworker/u8:8:30468 has bad value           (null)
unwind stack type:0 next_sp:          (null) mask:6 graph_idx:0
ffffc90001443d88: d0d0d0d0d0d0d0d0 (0xd0d0d0d0d0d0d0d0)
ffffc90001443d90: ffffffff81e5c420 (ftrace_trace_arrays+0x10/0x10)
ffffc90001443d98: d0d0d0d0d0d0d0d0 (0xd0d0d0d0d0d0d0d0)
ffffc90001443da0: ffff880253ff0848 (0xffff880253ff0848)
ffffc90001443da8: ffffc90001443e68 (0xffffc90001443e68)
ffffc90001443db0: ffffffff810a1430 (umh_complete+0x40/0x40)
ffffc90001443db8: 00000000000002a0 (0x2a0)
ffffc90001443dc0: 0000000000000001 (0x1)
ffffc90001443dc8: 0000000000000000 ...
ffffc90001443dd0: 0000000000000001 (0x1)
ffffc90001443dd8: 0000000000000001 (0x1)
ffffc90001443de0: 0000000000000000 ...
ffffc90001443de8: ffffffff81e5bcc0 (fgraph_sleep_time+0x20/0x20)
ffffc90001443df0: ffffffff818cb022 (ret_from_fork+0x22/0x30)
ffffc90001443df8: ffffffff810a1430 (umh_complete+0x40/0x40)
ffffc90001443e00: ffffffffffffff10 (0xffffffffffffff10)
ffffc90001443e08: ffffffff8117140c (function_trace_call+0x1c/0x190)
ffffc90001443e10: 0000000000000010 (0x10)
ffffc90001443e18: 0000000000000292 (0x292)
ffffc90001443e20: ffffc90001443e38 (0xffffc90001443e38)
ffffc90001443e28: 0000000000000000 ...
ffffc90001443e30: 0000000000000020 (0x20)
ffffc90001443e38: ffff8804f254a468 (0xffff8804f254a468)
ffffc90001443e40: ffffffff810a1430 (umh_complete+0x40/0x40)
ffffc90001443e48: ffff880253ff0848 (0xffff880253ff0848)
ffffc90001443e50: d0d0d0d0d0d0d0d0 (0xd0d0d0d0d0d0d0d0)
ffffc90001443e58: d0d0d0d0d0d0d0d0 (0xd0d0d0d0d0d0d0d0)
ffffc90001443e60: d0d0d0d0d0d0d0d0 (0xd0d0d0d0d0d0d0d0)
ffffc90001443e68: ffffc90001443f20 (0xffffc90001443f20)
ffffc90001443e70: ffffffffa0333077 (0xffffffffa0333077)
ffffc90001443e78: ffffc90001443ee0 (0xffffc90001443ee0)
ffffc90001443e80: 0000000000000086 (0x86)
ffffc90001443e88: ffffffff810b4618 (finish_task_switch+0x78/0x280)
ffffc90001443e90: ffff8804f2549c00 (0xffff8804f2549c00)
ffffc90001443e98: 0000000000000000 ...
ffffc90001443ea0: ffff880507bd8780 (0xffff880507bd8780)
ffffc90001443ea8: ffff880507bd8780 (0xffff880507bd8780)
ffffc90001443eb0: ffff8803211b5380 (0xffff8803211b5380)
ffffc90001443eb8: 0000000000000000 ...
ffffc90001443ec0: 0000000000000001 (0x1)
ffffc90001443ec8: 0000000080000000 (0x80000000)
ffffc90001443ed0: 0000000000000001 (0x1)
ffffc90001443ed8: 0000000080000001 (0x80000001)
ffffc90001443ee0: 0000000000000000 ...
ffffc90001443ee8: ffff880253ff0848 (0xffff880253ff0848)
ffffc90001443ef0: ffffffff810b4618 (finish_task_switch+0x78/0x280)
ffffc90001443ef8: ffffffff810a1435 (call_usermodehelper_exec_async+0x5/0x140)
ffffc90001443f00: ffff8803211b6a00 (0xffff8803211b6a00)
ffffc90001443f08: ffffffff810a1430 (umh_complete+0x40/0x40)
ffffc90001443f10: ffff880253ff0848 (0xffff880253ff0848)
ffffc90001443f18: d0d0d0d0d0d0d0d0 (0xd0d0d0d0d0d0d0d0)
ffffc90001443f20: ffffc90001443f30 (0xffffc90001443f30)
ffffc90001443f28: ffffffff810a1435 (call_usermodehelper_exec_async+0x5/0x140)
ffffc90001443f30: 0000000000000000 ...
ffffc90001443f38: ffffffff818cb022 (ret_from_fork+0x22/0x30)
ffffc90001443f40: 0000000000000000 ...
ffffc90001443f48: ffffffff810a1435 (call_usermodehelper_exec_async+0x5/0x140)
ffffc90001443f50: ffffffff818cb022 (ret_from_fork+0x22/0x30)
ffffc90001443f58: 0000000000000000 ...

[toc] | [prev] | [next] | [standalone]

#1552961

On Fri, Jan 06, 2017 at 12:09:47AM -0500, Dave Jones wrote:
> On Thu, Jan 05, 2017 at 11:02:14AM -0600, Josh Poimboeuf wrote:
>  > On Thu, Jan 05, 2017 at 08:52:49AM -0600, Josh Poimboeuf wrote:
>  > > On Tue, Dec 27, 2016 at 02:00:30PM -0500, Dave Jones wrote:
>  > > > I'm not sure what to make of this. Josh ?  (4.10-rc1)
>  > > > 
>  > > > WARNING: kernel stack frame pointer at ffffc900003e7858 in trinity-c6:29122 has bad value ffffffff82103a80
>  > > > unwind stack type:0 next_sp:          (null) mask:2 graph_idx:0
>  > > > ffffc900003e7808: ffffffff811a02e5 (ring_buffer_lock_reserve+0x1d5/0x580)
>  > > > ffffc900003e7810: ffffffff8119adc3 (rb_commit+0x93/0x350)
>  > > > ffffc900003e7818: ffffffff811b31d4 (function_trace_call+0x104/0x1f0)
>  > > > ffffc900003e7820: ffff8804f10ec000 (0xffff8804f10ec000)
>  > > > ffffc900003e7828: 0000000000000000 ...
>  > > > ffffc900003e7830: ffffffff8119b3ae (ring_buffer_unlock_commit+0x8e/0x120)
>  > > > ffffc900003e7838: 0000000000000001 (0x1)
>  > > > ffffc900003e7840: ffffea0002854e00 (0xffffea0002854e00)
>  > > > ffffc900003e7848: 000000000000000a (0xa)
>  > > > ffffc900003e7850: ffffea0002854ec0 (0xffffea0002854ec0)
>  > > > ffffc900003e7858: ffffea000287c480 (0xffffea000287c480)
>  > > 
>  > > The value reported by the warning contradicts the value reported by the
>  > > dump.  So this seems to have been caused by dumping the stack of a task
>  > > which is running on another CPU.  There are still some places in the
>  > > code where that's possible.  So I'm going to need to remove these
>  > > unwinder warnings for now.
>  > 
>  > I'll be submitting the following patch soon, which I think should
>  > silence the warning.  If the warning is recreatable, would you mind
>  > testing it?
> 
> I didn't wait long enough..
> 
> WARNING: kernel stack frame pointer at ffffc90001443f30 in kworker/u8:8:30468 has bad value           (null)
> unwind stack type:0 next_sp:          (null) mask:6 graph_idx:0

This is actually a separate issue.  The below patch should fix it.

Would you mind running it for a bit along with the other patch?


diff --git a/arch/x86/entry/entry_64.S b/arch/x86/entry/entry_64.S
index 5b21970..044d18e 100644
--- a/arch/x86/entry/entry_64.S
+++ b/arch/x86/entry/entry_64.S
@@ -36,6 +36,7 @@
 #include <asm/smap.h>
 #include <asm/pgtable_types.h>
 #include <asm/export.h>
+#include <asm/frame.h>
 #include <linux/err.h>
 
 .code64
@@ -408,17 +409,19 @@ END(__switch_to_asm)
  * r12: kernel thread arg
  */
 ENTRY(ret_from_fork)
+	FRAME_BEGIN			/* help unwinder find end of stack */
 	movq	%rax, %rdi
-	call	schedule_tail			/* rdi: 'prev' task parameter */
+	call	schedule_tail		/* rdi: 'prev' task parameter */
 
-	testq	%rbx, %rbx			/* from kernel_thread? */
-	jnz	1f				/* kernel threads are uncommon */
+	testq	%rbx, %rbx		/* from kernel_thread? */
+	jnz	1f			/* kernel threads are uncommon */
 
 2:
-	movq	%rsp, %rdi
+	leaq	FRAME_OFFSET(%rsp),%rdi	/* pt_regs pointer */
 	call	syscall_return_slowpath	/* returns with IRQs disabled */
 	TRACE_IRQS_ON			/* user mode is traced as IRQS on */
 	SWAPGS
+	FRAME_END
 	jmp	restore_regs_and_iret
 
 1:

[toc] | [prev] | [next] | [standalone]

#1553769

On Fri, Jan 06, 2017 at 10:50:32AM -0600, Josh Poimboeuf wrote:

 > > WARNING: kernel stack frame pointer at ffffc90001443f30 in kworker/u8:8:30468 has bad value           (null)
 > > unwind stack type:0 next_sp:          (null) mask:6 graph_idx:0
 > 
 > This is actually a separate issue.  The below patch should fix it.
 > 
 > Would you mind running it for a bit along with the other patch?

haven't seen any reoccurance of that trace in the last day.

	Dave

[toc] | [prev] | [standalone]

Back to top | Article view | linux.kernel

csiph-web