On Fri, Sep 08, 2017 at 01:12:45PM +0200, Jiri Kosina wrote: > On Wed, 6 Sep 2017, Josh Poimboeuf wrote: > > > > I just got the below stack trace with current Linus' tree with ORC > > > unwinder enabled: > > > > > > [ 8.652765] Call Trace: > > > [ 8.652767] dump_stack+0x7c/0xbf > > > [ 8.652769] print_circular_bug+0x2d3/0x2e0 > > > [ 8.652771] check_prev_add+0x666/0x700 > > > [ 8.652772] ? print_bfs_bug+0x40/0x40 > > > [ 8.652775] lock_commit_crosslock+0x3f1/0x570 > > > [ 8.652777] complete+0x24/0x60 > > > [ 8.652779] __kthread_parkme+0x42/0x90 > > > [ 8.652780] smpboot_thread_fn+0x92/0x210 > > > [ 8.652782] kthread+0x145/0x180 > > > [ 8.652783] ? sort_range+0x20/0x20 > > > [ 8.652785] ? kthread_create_on_node+0x40/0x40 > > > [ 8.652787] ret_from_fork+0x2a/0x40 > > > > > > Please note the kthread_create_on_node(), sort_range() and > > > print_bfs_bug() > > > entries ... I believe they actually shouldn't be there at all. All of > > > them > > > are at the last byte belonging to the function. Am I missing something? > > > > The question marks are still supposed to be there. They show any text > > addresses found on the stack that weren't otherwise found by the > > unwinder. 99.9% of the time, they're left over from a previous call > > chain, and should be ignored. > > It's interesting though that all of them (and even in other instances I've > encountered in the meantime) are always at the "last address" of the > function address range. That's hardly a conincidence, and also hardly a > result of a legitimate stacktrace -- 'call' is rather unlikely to be the > last insn in a function.
Ah, I missed that detail. In this case, these aren't actually bread crumbs from a previous stack. They're actually function pointers which are saved on the current stack. In my vmlinux, the function which comes after kthread_create_on_node() is kthread(). Which means kthread_create_on_node+0x40/0x40 is the same address as kthread+0x0. So it's the 'kthread' function pointer. Similarly, sort_range+0x20/0x20 is the same as smpboot_thread_fn+0x0. So the 'kthread' and 'smpboot_thread_fn' function pointers are getting saved on the stack in kthread()'s frame. The oops dump code in show_trace_log_lvl() sees those text addresses and prints them as bread crumbs. So your next question might be, why is it printed as kthread_create_on_node+0x40/0x40 instead of kthread+0x0/0x18e ? The reason is, there are some "noreturn" functions which never return, like panic(). They sometimes have a CALL instruction at the very end. So if kthread_create_on_node()'s last instruction were a CALL, we'd want to show *that* function name instead of kthread(). So when printing splats, we always assume that the boundary between the end of a function and the beginning of a function belongs to the previous function. That's what the printk '%pB' specifier does. The only exception to that is when printing regs->ip. In that case, the interrupt could have occurred right at the beginning of a function. So we would print 'kthread+0x0'. Which is what the '%pS' specifier does. -- Josh
