Help! How to get arguments to last function call of blocked task?

From: Chris Friesen
Date: Sun Sep 16 2012 - 19:13:42 EST


Hi,

I'm running an x86_64 kernel and I've got a task that is blocked on a mutex. The stack trace shows:

[<ffffffff815ab5ae>] __mutex_lock_slowpath+0x7e/0xd0
[<ffffffff815ab3be>] mutex_lock+0xe/0x10
[<ffffffff81177d67>] nfsd_sync+0x47/0xd0
[<ffffffff81179800>] nfsd_commit+0x70/0xa0
[<ffffffff8117fd80>] nfsd3_proc_commit+0x80/0x100
[<ffffffff81173b1b>] nfsd_dispatch+0xbb/0x260
[<ffffffff81578f6e>] svc_process+0x48e/0x800
[<ffffffff81174299>] nfsd+0x199/0x2b0

I need to find out the argument of the call to __mutex_lock_slowpath() so that I can figure out which file it's trying to write to. Based on disassembling the functions, I know that it is stored in r12 going into the call to schedule().

Rebooting is not possible, building kernel modules is. Kprobes are enabled. The stack for the task in question looks like this (printed out as 64-bit values):


stack pointer: ffff8807dfd8bc40

i: 0, addr: ffff8807dfd8bc48, val: 46
i: 1, addr: ffff8807dfd8bc50, val: 0
i: 2, addr: ffff8807dfd8bc58, val: ffff8807dfd8bcf4
i: 3, addr: ffff8807dfd8bc60, val: ffff8806f90ece40
i: 4, addr: ffff8807dfd8bc68, val: ff8806ee4a0260
i: 5, addr: ffff8807dfd8bc70, val: ffffffff818b5988
i: 6, addr: ffff8807dfd8bc78, val: ffffffff818b59a0
i: 7, addr: ffff8807dfd8bc80, val: ff8807dfd8bcb0
i: 8, addr: ffff8807dfd8bc88, val: ffffffff818b9d00
i: 9, addr: ffff8807dfd8bc90, val: ffff8807e91e6c80
i: 10, addr: ffff8807dfd8bc98, val: ffffffff8174e380
i: 11, addr: ffff8807dfd8bca0, val: ffff8807e91e6ff0
i: 12, addr: ffff8807dfd8bca8, val: dcd123c0
i: 13, addr: ffff8807dfd8bcb0, val: 1004826dc
i: 14, addr: ffff8807dfd8bcb8, val: ffff8807e91e70cc
i: 15, addr: ffff8807dfd8bcc0, val: ffff8807e91e6ff0
i: 16, addr: ffff8807dfd8bcc8, val: 818
i: 17, addr: ffff8807dfd8bcd0, val: fffffff7
i: 18, addr: ffff8807dfd8bcd8, val: 2
i: 19, addr: ffff8807dfd8bce0, val: 8001
i: 20, addr: ffff8807dfd8bce8, val: 0
i: 21, addr: ffff8807dfd8bcf0, val: 73dfd8bda0
i: 22, addr: ffff8807dfd8bcf8, val: 1
i: 23, addr: ffff8807dfd8bd00, val: 0
i: 24, addr: ffff8807dfd8bd08, val: ffff8807dcd1247c
i: 25, addr: ffff8807dfd8bd10, val: ffff8807dcd12478
i: 26, addr: ffff8807dfd8bd18, val: ffffffffffffffff
i: 27, addr: ffff8807dfd8bd20, val: ffff8807e91e6c80
i: 28, addr: ffff8807dfd8bd28, val: ffff8807dcd12480
i: 29, addr: ffff8807dfd8bd30, val: ffff8807dfd8bd90 -- pointer to previous rbp?
i: 30, addr: ffff8807dfd8bd38, val: ffffffff815ab5ae -- return address (__mutex_lock_slowpath)
i: 31, addr: ffff8807dfd8bd40, val: ffff8807dcd12480
i: 32, addr: ffff8807dfd8bd48, val: ffff8807decdbd40
i: 33, addr: ffff8807dfd8bd50, val: ffff8807e91e6c80
i: 34, addr: ffff8807dfd8bd58, val: ffff8807f1c00000
i: 35, addr: ffff8807dfd8bd60, val: ffff8807f19e8808
i: 36, addr: ffff8807dfd8bd68, val: ffff8807dcd12478
i: 37, addr: ffff8807dfd8bd70, val: ffff8806f90ece40
i: 38, addr: ffff8807dfd8bd78, val: ffff8807f19e9000
i: 39, addr: ffff8807dfd8bd80, val: ffff8807f19e8800
i: 40, addr: ffff8807dfd8bd88, val: ffff8807dfc90000
i: 41, addr: ffff8807dfd8bd90, val: ffff8807dfd8bda0 -- pointer to previous rbp?
i: 42, addr: ffff8807dfd8bd98, val: ffffffff815ab3be -- return address (mutex_lock)


The __mutex_lock_slowpath() disassembly starts out like this:


Dump of assembler code for function __mutex_lock_slowpath:
0xffffffff815ab530 <+0>: push %rbp
0xffffffff815ab531 <+1>: mov %rsp,%rbp
0xffffffff815ab534 <+4>: push %r15
0xffffffff815ab536 <+6>: push %r14
0xffffffff815ab538 <+8>: push %r13
0xffffffff815ab53a <+10>: push %r12
0xffffffff815ab53c <+12>: mov %rdi,%r12
0xffffffff815ab53f <+15>: push %rbx
0xffffffff815ab540 <+16>: lea 0x8(%r12),%r15

so does that mean that address ffff8807dfd8bd28 stores r15, ffff8807dfd8bd20 stores r14, etc.?


The schedule() function starts out like this:
0xffffffff815a9ea0 <+0>: push %rbp
0xffffffff815a9ea1 <+1>: mov $0xffffffff818b59a0,%rdx
0xffffffff815a9ea8 <+8>: mov %rsp,%rbp
0xffffffff815a9eab <+11>: mov $0xffffffff818b5988,%rcx
0xffffffff815a9eb2 <+18>: push %r15
0xffffffff815a9eb4 <+20>: push %r14
0xffffffff815a9eb6 <+22>: push %r13
0xffffffff815a9eb8 <+24>: push %r12
0xffffffff815a9eba <+26>: mov $0x0,%al
0xffffffff815a9ebc <+28>: push %rbx


I'm interested in the r12 value going into schedule(). How do I identify it in my stack above?


Thanks,
Chris

--

Chris Friesen
Software Designer

3500 Carling Avenue
Ottawa, Ontario K2H 8E9
www.genband.com
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/