Re: question on kernel stack trace

[David Wysochanski <dwysocha@redhat.com>]

In this case I'm almost 100% certain you can ignore that - it's
unfortunate stack trace symbol.

The backtrace code looks on the stack for addresses of code and often
prints symbols that are from older executions.  If you ever are not
sure you should use a tool like eu-addr2line and see if the code flow
makes sense.


On Wed, 2018-02-21 at 22:10 +0100, Mkrtchyan, Tigran wrote:
> Hi Dave,
> 
> Thanks for the reply. I am confused by line:
> 
> ext4_mark_inode_dirty+0x83/0x1d0 [ext4]
> 
> Is it in ext4 module or just an unfortunate stack trace?
> 
> Thanks,
>    Tigran.
> 
> 
> ----- Original Message -----
> > From: "David Wysochanski" <dwysocha@redhat.com>
> > To: "Tigran Mkrtchyan" <tigran.mkrtchyan@desy.de>, "linux-nfs" <lin
> > ux-nfs@vger.kernel.org>
> > Sent: Wednesday, February 21, 2018 8:44:10 PM
> > Subject: Re: question on kernel stack trace
> > On Wed, 2018-02-21 at 11:46 +0100, Mkrtchyan, Tigran wrote:
> > > On one of our nodes we got the following stack trace:
> > > 
> > > 
> > > Feb 19 16:55:53 nafhh kernel: updatedb      D
> > > 000000000000000f     0
> > > 32087  32081 0x00000080
> > > Feb 19 16:55:53 nafhh kernel: ffff880852d13a88 0000000000000082
> > > 0000000000000000 ffffffffa00bfe13
> > > Feb 19 16:55:53 nafhh kernel: 0000000000000050 0000000300000001
> > > 000d5a7576495a7a 0000000000000286
> > > Feb 19 16:55:53 nafhh kernel: 0000000000000286 00000001dfd51213
> > > ffff8810207c5068 ffff880852d13fd8
> > > Feb 19 16:55:53 nafhh kernel: Call Trace:
> > > Feb 19 16:55:53 nafhh kernel: [<ffffffffa00bfe13>] ?
> > > ext4_mark_inode_dirty+0x83/0x1d0 [ext4]
> > > Feb 19 16:55:53 nafhh kernel: [<ffffffffa029b1e4>] ?
> > > __rpc_sleep_on_priority+0xf4/0x330 [sunrpc]
> > > Feb 19 16:55:53 nafhh kernel: [<ffffffffa029a5b0>] ?
> > > rpc_wait_bit_killable+0x0/0xa0 [sunrpc]
> > > Feb 19 16:55:53 nafhh kernel: [<ffffffffa029a5f2>]
> > > rpc_wait_bit_killable+0x42/0xa0 [sunrpc]
> > > Feb 19 16:55:53 nafhh kernel: [<ffffffff8154ca7f>]
> > > __wait_on_bit+0x5f/0x90
> > > Feb 19 16:55:53 nafhh kernel: [<ffffffffa0294217>] ?
> > > xprt_reserve_xprt+0x87/0x110 [sunrpc]
> > > Feb 19 16:55:53 nafhh kernel: [<ffffffffa029a5b0>] ?
> > > rpc_wait_bit_killable+0x0/0xa0 [sunrpc]
> > > Feb 19 16:55:53 nafhh kernel: [<ffffffff8154cb28>]
> > > out_of_line_wait_on_bit+0x78/0x90
> > > Feb 19 16:55:53 nafhh kernel: [<ffffffff810a7220>] ?
> > > wake_bit_function+0x0/0x50
> > > Feb 19 16:55:53 nafhh kernel: [<ffffffffa029ab35>]
> > > __rpc_execute+0xf5/0x350 [sunrpc]
> > > Feb 19 16:55:53 nafhh kernel: [<ffffffff810a7027>] ?
> > > bit_waitqueue+0x17/0xd0
> > > Feb 19 16:55:53 nafhh kernel: [<ffffffffa029adf1>]
> > > rpc_execute+0x61/0xa0 [sunrpc]
> > > Feb 19 16:55:53 nafhh kernel: [<ffffffffa0291475>]
> > > rpc_run_task+0x75/0x90 [sunrpc]
> > > Feb 19 16:55:53 nafhh kernel: [<ffffffffa0291592>]
> > > rpc_call_sync+0x42/0x70 [sunrpc]
> > > Feb 19 16:55:53 nafhh kernel: [<ffffffffa035cf2e>]
> > > _nfs4_call_sync+0x3e/0x40 [nfs]
> > > Feb 19 16:55:53 nafhh kernel: [<ffffffffa035574c>]
> > > _nfs4_proc_getattr+0xac/0xc0 [nfs]
> > > Feb 19 16:55:53 nafhh kernel: [<ffffffffa0358796>]
> > > nfs4_proc_getattr+0x56/0x80 [nfs]
> > > Feb 19 16:55:53 nafhh kernel: [<ffffffffa033e293>]
> > > __nfs_revalidate_inode+0xe3/0x220 [nfs]
> > > Feb 19 16:55:53 nafhh kernel: [<ffffffffa033f12e>]
> > > nfs_getattr+0xde/0x210 [nfs]
> > > Feb 19 16:55:53 nafhh kernel: [<ffffffff811a0391>]
> > > vfs_getattr+0x51/0x80
> > > Feb 19 16:55:53 nafhh kernel: [<ffffffff811a01d4>] ?
> > > cp_new_stat+0xe4/0x100
> > > Feb 19 16:55:53 nafhh kernel: [<ffffffff811a0424>]
> > > vfs_fstatat+0x64/0xa0
> > > Feb 19 16:55:53 nafhh kernel: [<ffffffff811a04ce>]
> > > vfs_lstat+0x1e/0x20
> > > Feb 19 16:55:53 nafhh kernel: [<ffffffff811a04f4>]
> > > sys_newlstat+0x24/0x50
> > > Feb 19 16:55:53 nafhh kernel: [<ffffffff81556627>] ?
> > > system_call_after_swapgs+0x187/0x220
> > > Feb 19 16:55:53 nafhh kernel: [<ffffffff81556620>] ?
> > > system_call_after_swapgs+0x180/0x220
> > > Feb 19 16:55:53 nafhh kernel: [<ffffffff810eeef7>] ?
> > > audit_syscall_entry+0x1d7/0x200
> > > Feb 19 16:55:53 nafhh kernel: [<ffffffff8155660b>] ?
> > > system_call_after_swapgs+0x16b/0x220
> > > Feb 19 16:55:53 nafhh kernel: [<ffffffff81556604>] ?
> > > system_call_after_swapgs+0x164/0x220
> > > Feb 19 16:55:53 nafhh kernel: [<ffffffff815565fd>] ?
> > > system_call_after_swapgs+0x15d/0x220
> > > Feb 19 16:55:53 nafhh kernel: [<ffffffff815565f6>] ?
> > > system_call_after_swapgs+0x156/0x220
> > > Feb 19 16:55:53 nafhh kernel: [<ffffffff815565ef>] ?
> > > system_call_after_swapgs+0x14f/0x220
> > > Feb 19 16:55:53 nafhh kernel: [<ffffffff815566d6>]
> > > system_call_fastpath+0x16/0x1b
> > > Feb 19 16:55:53 nafhh kernel: [<ffffffff8155656a>] ?
> > > system_call_after_swapgs+0xca/0x220
> > > 
> > > 
> > > I am surprised, that top of the stack trace is in ext4 module.
> > > Can
> > > some one put a light on it?
> > > 
> > 
> > Ignore the symbols with '?' next to them as they are not reliable.
> > 
> > If you want to map this to code use something like 'eu-addr2line'
> > and
> > see if the symbols make sense in terms of source code lines.
> > 
> > This looks like the process is just blocked for a long time waiting
> > on
> > an NFS4 GETATTR to complete, and does not look unusual to me.
> > 
> > --
> > To unsubscribe from this list: send the line "unsubscribe linux-
> > nfs" in
> > the body of a message to majordomo@vger.kernel.org
> > More majordomo info at  http://vger.kernel.org/majordomo-info.html