perf: perf_fuzzer lockup in perf_cgroup_attach

perf: perf_fuzzer lockup in perf_cgroup_attach

[Vince Weaver]

so the skylake that was fuzzing finally is mostly locked up.

Really hard to tell what's going, especially as KASLR made looking up the 
addresses a big pain.

The best I can tell things are getting wedged somehow in 
perf_cgroup_switch() while interrupts are disabled.  Interrupts are never 
getting re-enabled, causing the RCU and NMI watchdogs to trigger (and more 
alarming things like the SATA bus resetting).

[26292.413603] Task dump for CPU 4:
[26292.413604] perf_fuzzer     R  running task        0  8870   1096 0x10000008
[26292.413605]  ffff9045f29e1100 00000000e7143ab0 ffff9045fdd03db8 ffffffff938accef
[26292.413606]  0000000000000004 0000000000000087 ffff9045fdd03dd0 ffffffff938af5e9
[26292.413607]  0000000000000004 ffff9045fdd03e00 ffffffff93984928 ffff9045fdd19440
[26292.413608] Call Trace:
[26292.413609]  <IRQ>  [<ffffffff938accef>] sched_show_task+0xaf/0x110
[26292.413611]  [<ffffffff938af5e9>] dump_cpu_task+0x39/0x40
[26292.413613]  [<ffffffff93984928>] rcu_dump_cpu_stacks+0x80/0xbb
[26292.413614]  [<ffffffff938e78ce>] rcu_check_callbacks+0x71e/0x880
[26292.413615]  [<ffffffff9393364c>] ? acct_account_cputime+0x1c/0x20
[26292.413616]  [<ffffffff938b0049>] ? account_system_time+0x79/0x120
[26292.413617]  [<ffffffff938fe8b0>] ? tick_sched_do_timer+0x30/0x30
[26292.413619]  [<ffffffff938ee88f>] update_process_times+0x2f/0x60
[26292.413619]  [<ffffffff938fe285>] tick_sched_handle.isra.13+0x25/0x60
[26292.413620]  [<ffffffff938fe8ed>] tick_sched_timer+0x3d/0x70
[26292.413621]  [<ffffffff938ef633>] __hrtimer_run_queues+0xf3/0x280
[26292.413623]  [<ffffffff938efb08>] hrtimer_interrupt+0xa8/0x1a0
[26292.413624]  [<ffffffff93852d88>] local_apic_timer_interrupt+0x38/0x60
[26292.413625]  [<ffffffff93e1dee4>] smp_trace_apic_timer_interrupt+0x44/0xde
[26292.413627]  [<ffffffff9396ff60>] ? perf_cgroup_attach+0x70/0x70
[26292.413628]  [<ffffffff93e1d232>] trace_apic_timer_interrupt+0x82/0x90
[26292.413628]  <EOI>  [<ffffffff9396ff60>] ? perf_cgroup_attach+0x70/0x70
[26292.413631]  [<ffffffff939039d6>] ? smp_call_function_single+0xd6/0x130
[26292.413632]  [<ffffffff9396ff60>] ? perf_cgroup_attach+0x70/0x70
[26292.413633]  [<ffffffff9396ec53>] cpu_function_call+0x43/0x60
[26292.413634]  [<ffffffff93976840>] ? __perf_event_enable+0x260/0x260
[26292.413635]  [<ffffffff939737e1>] perf_install_in_context+0x141/0x150
[26292.413636]  [<ffffffff9397956e>] SYSC_perf_event_open+0x70e/0xfe0
[26292.413637]  [<ffffffff938a99e4>] ? check_preempt_curr+0x54/0x90
[26292.413639]  [<ffffffff9397c099>] SyS_perf_event_open+0x9/0x10
[26292.413640]  [<ffffffff93803bb4>] do_syscall_64+0x64/0x160
[26292.413641]  [<ffffffff93e1b625>] entry_SYSCALL64_slow_path+0x25/0x25

[26316.489382] NMI watchdog: BUG: soft lockup - CPU#4 stuck for 23s! [perf_fuzzer:8870]
[26316.497309] CPU: 4 PID: 8870 Comm: perf_fuzzer Tainted: G        W       4.8.0-rc6+ #5
[26316.497310] Hardware name: LENOVO 10FY0017US/SKYBAY, BIOS FWKT53A   06/06/2016
[26316.497310] task: ffff9045f29e1100 task.stack: ffff9045f0a48000
[26316.497311] RIP: 0010:[<ffffffff939039d6>]  [<ffffffff939039d6>] smp_call_function_single+0xd6/0x130
[26316.497312] RSP: 0018:ffff9045f0a4bd30  EFLAGS: 00000202
[26316.497313] RAX: 0000000000000000 RBX: 0000000000000002 RCX: 0000000000000000
[26316.497313] RDX: 0000000000000001 RSI: 00000000000000fb RDI: 0000000000000286
[26316.497314] RBP: ffff9045f0a4bd78 R08: ffff9045fdc9bed0 R09: ffff9045f2ac8000
[26316.497314] R10: 0000000000000000 R11: 0000000000000246 R12: ffffffff9396ff60
[26316.497315] R13: ffff9045fdc9bed0 R14: 000000000000001e R15: ffff9045fdc9bee0
[26316.497315] FS:  00007f4157a08700(0000) GS:ffff9045fdd00000(0000) knlGS:0000000000000000
[26316.497316] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[26316.497316] CR2: 000000000693a048 CR3: 0000000231049000 CR4: 00000000003407e0
[26316.497317] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[26316.497317] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000600
[26316.497318] Stack:
[26316.497318]  0000000000000000 ffff9045ee35da80 0000000000000000 ffffffff9396ff60
[26316.497319]  ffff9045f0a4bd88 0000000000000003 00000000e7143ab0 ffff9045ee47613a
[26316.497321]  ffff9045ee476000 ffff9045f0a4bdb0 ffffffff9396ec53 0000000000000000
[26316.497322] Call Trace:
[26316.497323]  [<ffffffff9396ff60>] ? perf_cgroup_attach+0x70/0x70
[26316.497324]  [<ffffffff9396ec53>] cpu_function_call+0x43/0x60
[26316.497325]  [<ffffffff93976840>] ? __perf_event_enable+0x260/0x260
[26316.497326]  [<ffffffff939737e1>] perf_install_in_context+0x141/0x150
[26316.497327]  [<ffffffff9397956e>] SYSC_perf_event_open+0x70e/0xfe0
[26316.497328]  [<ffffffff938a99e4>] ? check_preempt_curr+0x54/0x90
[26316.497330]  [<ffffffff9397c099>] SyS_perf_event_open+0x9/0x10
[26316.497331]  [<ffffffff93803bb4>] do_syscall_64+0x64/0x160
[26316.497332]  [<ffffffff93e1b625>] entry_SYSCALL64_slow_path+0x25/0x25
[26316.497332] Code: 25 28 00 00 00 75 70 48 83 c4 38 5b 41 5c 5d c3 48 8d 75 c8 48 89 d1 89 df 4c 89 e2 e8 14 fe ff ff 8b 55 e0 83 e2 01 74 0a f3 90 <8b> 55 e0 83 e2 01 75 f6 eb c3 8b 05 ba e5 dd 00 85 c0 75 85 80 

Re: perf: perf_fuzzer lockup in perf_cgroup_attach

[Stephane Eranian]

On Wed, Sep 14, 2016 at 7:43 PM, Vince Weaver <vincent.weaver@maine.edu> wrote:
>
> so the skylake that was fuzzing finally is mostly locked up.
>
> Really hard to tell what's going, especially as KASLR made looking up the
> addresses a big pain.
>
I would think there is a way to disable KASLR for this kind of testing!

Which of your fuzzer scripts are you using? fast_repro99.sh?

> The best I can tell things are getting wedged somehow in
> perf_cgroup_switch() while interrupts are disabled.  Interrupts are never
> getting re-enabled, causing the RCU and NMI watchdogs to trigger (and more
> alarming things like the SATA bus resetting).
>
How do you get to perf_cgroup_switch() from the traces you provide below?

> [26292.413603] Task dump for CPU 4:
> [26292.413604] perf_fuzzer     R  running task        0  8870   1096 0x10000008
> [26292.413605]  ffff9045f29e1100 00000000e7143ab0 ffff9045fdd03db8 ffffffff938accef
> [26292.413606]  0000000000000004 0000000000000087 ffff9045fdd03dd0 ffffffff938af5e9
> [26292.413607]  0000000000000004 ffff9045fdd03e00 ffffffff93984928 ffff9045fdd19440
> [26292.413608] Call Trace:
> [26292.413609]  <IRQ>  [<ffffffff938accef>] sched_show_task+0xaf/0x110
> [26292.413611]  [<ffffffff938af5e9>] dump_cpu_task+0x39/0x40
> [26292.413613]  [<ffffffff93984928>] rcu_dump_cpu_stacks+0x80/0xbb
> [26292.413614]  [<ffffffff938e78ce>] rcu_check_callbacks+0x71e/0x880
> [26292.413615]  [<ffffffff9393364c>] ? acct_account_cputime+0x1c/0x20
> [26292.413616]  [<ffffffff938b0049>] ? account_system_time+0x79/0x120
> [26292.413617]  [<ffffffff938fe8b0>] ? tick_sched_do_timer+0x30/0x30
> [26292.413619]  [<ffffffff938ee88f>] update_process_times+0x2f/0x60
> [26292.413619]  [<ffffffff938fe285>] tick_sched_handle.isra.13+0x25/0x60
> [26292.413620]  [<ffffffff938fe8ed>] tick_sched_timer+0x3d/0x70
> [26292.413621]  [<ffffffff938ef633>] __hrtimer_run_queues+0xf3/0x280
> [26292.413623]  [<ffffffff938efb08>] hrtimer_interrupt+0xa8/0x1a0
> [26292.413624]  [<ffffffff93852d88>] local_apic_timer_interrupt+0x38/0x60
> [26292.413625]  [<ffffffff93e1dee4>] smp_trace_apic_timer_interrupt+0x44/0xde
> [26292.413627]  [<ffffffff9396ff60>] ? perf_cgroup_attach+0x70/0x70
> [26292.413628]  [<ffffffff93e1d232>] trace_apic_timer_interrupt+0x82/0x90
> [26292.413628]  <EOI>  [<ffffffff9396ff60>] ? perf_cgroup_attach+0x70/0x70
> [26292.413631]  [<ffffffff939039d6>] ? smp_call_function_single+0xd6/0x130
> [26292.413632]  [<ffffffff9396ff60>] ? perf_cgroup_attach+0x70/0x70
> [26292.413633]  [<ffffffff9396ec53>] cpu_function_call+0x43/0x60
> [26292.413634]  [<ffffffff93976840>] ? __perf_event_enable+0x260/0x260
> [26292.413635]  [<ffffffff939737e1>] perf_install_in_context+0x141/0x150
> [26292.413636]  [<ffffffff9397956e>] SYSC_perf_event_open+0x70e/0xfe0
> [26292.413637]  [<ffffffff938a99e4>] ? check_preempt_curr+0x54/0x90
> [26292.413639]  [<ffffffff9397c099>] SyS_perf_event_open+0x9/0x10
> [26292.413640]  [<ffffffff93803bb4>] do_syscall_64+0x64/0x160
> [26292.413641]  [<ffffffff93e1b625>] entry_SYSCALL64_slow_path+0x25/0x25
>
> [26316.489382] NMI watchdog: BUG: soft lockup - CPU#4 stuck for 23s! [perf_fuzzer:8870]
> [26316.497309] CPU: 4 PID: 8870 Comm: perf_fuzzer Tainted: G        W       4.8.0-rc6+ #5
> [26316.497310] Hardware name: LENOVO 10FY0017US/SKYBAY, BIOS FWKT53A   06/06/2016
> [26316.497310] task: ffff9045f29e1100 task.stack: ffff9045f0a48000
> [26316.497311] RIP: 0010:[<ffffffff939039d6>]  [<ffffffff939039d6>] smp_call_function_single+0xd6/0x130
> [26316.497312] RSP: 0018:ffff9045f0a4bd30  EFLAGS: 00000202
> [26316.497313] RAX: 0000000000000000 RBX: 0000000000000002 RCX: 0000000000000000
> [26316.497313] RDX: 0000000000000001 RSI: 00000000000000fb RDI: 0000000000000286
> [26316.497314] RBP: ffff9045f0a4bd78 R08: ffff9045fdc9bed0 R09: ffff9045f2ac8000
> [26316.497314] R10: 0000000000000000 R11: 0000000000000246 R12: ffffffff9396ff60
> [26316.497315] R13: ffff9045fdc9bed0 R14: 000000000000001e R15: ffff9045fdc9bee0
> [26316.497315] FS:  00007f4157a08700(0000) GS:ffff9045fdd00000(0000) knlGS:0000000000000000
> [26316.497316] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [26316.497316] CR2: 000000000693a048 CR3: 0000000231049000 CR4: 00000000003407e0
> [26316.497317] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> [26316.497317] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000600
> [26316.497318] Stack:
> [26316.497318]  0000000000000000 ffff9045ee35da80 0000000000000000 ffffffff9396ff60
> [26316.497319]  ffff9045f0a4bd88 0000000000000003 00000000e7143ab0 ffff9045ee47613a
> [26316.497321]  ffff9045ee476000 ffff9045f0a4bdb0 ffffffff9396ec53 0000000000000000
> [26316.497322] Call Trace:
> [26316.497323]  [<ffffffff9396ff60>] ? perf_cgroup_attach+0x70/0x70
> [26316.497324]  [<ffffffff9396ec53>] cpu_function_call+0x43/0x60
> [26316.497325]  [<ffffffff93976840>] ? __perf_event_enable+0x260/0x260
> [26316.497326]  [<ffffffff939737e1>] perf_install_in_context+0x141/0x150
> [26316.497327]  [<ffffffff9397956e>] SYSC_perf_event_open+0x70e/0xfe0
> [26316.497328]  [<ffffffff938a99e4>] ? check_preempt_curr+0x54/0x90
> [26316.497330]  [<ffffffff9397c099>] SyS_perf_event_open+0x9/0x10
> [26316.497331]  [<ffffffff93803bb4>] do_syscall_64+0x64/0x160
> [26316.497332]  [<ffffffff93e1b625>] entry_SYSCALL64_slow_path+0x25/0x25
> [26316.497332] Code: 25 28 00 00 00 75 70 48 83 c4 38 5b 41 5c 5d c3 48 8d 75 c8 48 89 d1 89 df 4c 89 e2 e8 14 fe ff ff 8b 55 e0 83 e2 01 74 0a f3 90 <8b> 55 e0 83 e2 01 75 f6 eb c3 8b 05 ba e5 dd 00 85 c0 75 85 80
>

Re: perf: perf_fuzzer lockup in perf_cgroup_attach

[Peter Zijlstra]

On Wed, Sep 14, 2016 at 10:43:29PM -0400, Vince Weaver wrote:
> 
> so the skylake that was fuzzing finally is mostly locked up.
> 
> Really hard to tell what's going, especially as KASLR made looking up the 
> addresses a big pain.
> 
> The best I can tell things are getting wedged somehow in 
> perf_cgroup_switch() while interrupts are disabled.  Interrupts are never 
> getting re-enabled, causing the RCU and NMI watchdogs to trigger (and more 
> alarming things like the SATA bus resetting).

How do you go about using cgroups? Do you set them up yourself, does the
fuzzer do so?

Re: perf: perf_fuzzer lockup in perf_cgroup_attach

[Peter Zijlstra]

On Wed, Sep 14, 2016 at 10:35:49PM -0700, Stephane Eranian wrote:
> On Wed, Sep 14, 2016 at 7:43 PM, Vince Weaver <vincent.weaver@maine.edu> wrote:
> >
> > so the skylake that was fuzzing finally is mostly locked up.
> >
> > Really hard to tell what's going, especially as KASLR made looking up the
> > addresses a big pain.
> >
> I would think there is a way to disable KASLR for this kind of testing!

I always kill CONFIG_RANDOMIZE_BASE, but there's also talk of killing
the address print entirely..  :-(

  https://lkml.kernel.org/r/20160831165303.tvcudt7wkpechuqt@treble

Re: perf: perf_fuzzer lockup in perf_cgroup_attach

[Josh Poimboeuf]

On Thu, Sep 15, 2016 at 09:24:25AM +0200, Peter Zijlstra wrote:
> On Wed, Sep 14, 2016 at 10:35:49PM -0700, Stephane Eranian wrote:
> > On Wed, Sep 14, 2016 at 7:43 PM, Vince Weaver <vincent.weaver@maine.edu> wrote:
> > >
> > > so the skylake that was fuzzing finally is mostly locked up.
> > >
> > > Really hard to tell what's going, especially as KASLR made looking up the
> > > addresses a big pain.
> > >
> > I would think there is a way to disable KASLR for this kind of testing!
> 
> I always kill CONFIG_RANDOMIZE_BASE, but there's also talk of killing
> the address print entirely..  :-(
> 
>   https://lkml.kernel.org/r/20160831165303.tvcudt7wkpechuqt@treble

So you should be able to do something like:

  echo "list *driver_probe_device+0x223" |gdb vmlinux |grep "is in"

Though that's admittedly quite a bit slower than addr2line.

-- 
Josh

Re: perf: perf_fuzzer lockup in perf_cgroup_attach

[Vince Weaver]

On Thu, 15 Sep 2016, Peter Zijlstra wrote:

> On Wed, Sep 14, 2016 at 10:43:29PM -0400, Vince Weaver wrote:
> > 
> > so the skylake that was fuzzing finally is mostly locked up.
> > 
> > Really hard to tell what's going, especially as KASLR made looking up the 
> > addresses a big pain.
> > 
> > The best I can tell things are getting wedged somehow in 
> > perf_cgroup_switch() while interrupts are disabled.  Interrupts are never 
> > getting re-enabled, causing the RCU and NMI watchdogs to trigger (and more 
> > alarming things like the SATA bus resetting).
> 
> How do you go about using cgroups? Do you set them up yourself, does the
> fuzzer do so?

that's an interesting thing, I don't think the fuzzer actually sets up any 
cgroups.  It will try creating events with PERF_FLAG_PID_CGROUP but it 
will just use a random number as the cgroup fd.  

I know at one time I meant to do more interesting things with cgroups
but if I recall it wasn't really possible without running as root and I 
usually don't fuzz as root.

Vince

Re: perf: perf_fuzzer lockup in perf_cgroup_attach

[Vince Weaver]

On Wed, 14 Sep 2016, Stephane Eranian wrote:

> I would think there is a way to disable KASLR for this kind of testing!

yes, it's just I hadn't realized I had it enabled until I couldn't figure 
out why addr2line wasn't working.

> Which of your fuzzer scripts are you using? fast_repro99.sh?

yes.  I should probably give that script a more meaningful name, but by 
now I think it's too late for that.

I also am running with paranoid set to "0"

> 
> > The best I can tell things are getting wedged somehow in
> > perf_cgroup_switch() while interrupts are disabled.  Interrupts are never
> > getting re-enabled, causing the RCU and NMI watchdogs to trigger (and more
> > alarming things like the SATA bus resetting).
> >
> How do you get to perf_cgroup_switch() from the traces you provide below?

It was my best guess after trying to trace through the code.  It could
in theory be anywhere but it definitely seems like it is happening after
perf_cgroup_attach at some point when interrupts are disabled (possibly
ftrace too?)

It's difficult because some code gets inlined and then it's jumping to a 
function pointer.  And then mid-debug the system finally had enough and 
started making threads hang forever while I was getting close.

I've rebooted the machine I'll see if I can replicate.

Vince

[PATCH] scripts: add script for translating stack dump function offsets

[Josh Poimboeuf]

On Thu, Sep 15, 2016 at 07:10:14AM -0500, Josh Poimboeuf wrote:
> On Thu, Sep 15, 2016 at 09:24:25AM +0200, Peter Zijlstra wrote:
> > On Wed, Sep 14, 2016 at 10:35:49PM -0700, Stephane Eranian wrote:
> > > On Wed, Sep 14, 2016 at 7:43 PM, Vince Weaver <vincent.weaver@maine.edu> wrote:
> > > >
> > > > so the skylake that was fuzzing finally is mostly locked up.
> > > >
> > > > Really hard to tell what's going, especially as KASLR made looking up the
> > > > addresses a big pain.
> > > >
> > > I would think there is a way to disable KASLR for this kind of testing!
> > 
> > I always kill CONFIG_RANDOMIZE_BASE, but there's also talk of killing
> > the address print entirely..  :-(
> > 
> >   https://lkml.kernel.org/r/20160831165303.tvcudt7wkpechuqt@treble
> 
> So you should be able to do something like:
> 
>   echo "list *driver_probe_device+0x223" |gdb vmlinux |grep "is in"
> 
> Though that's admittedly quite a bit slower than addr2line.

Here's something a lot faster than gdb, which also handles duplicate
symbols properly.

---

From: Josh Poimboeuf <jpoimboe@redhat.com>
Subject: [PATCH] scripts: add script for translating stack dump function
 offsets

addr2line doesn't work with KASLR addresses.  Add a basic addr2line
wrapper script which takes the 'func+0x123' format as input.

Signed-off-by: Josh Poimboeuf <jpoimboe@redhat.com>
---
 scripts/faddr2line | 54 ++++++++++++++++++++++++++++++++++++++++++++++++++++++
 1 file changed, 54 insertions(+)
 create mode 100755 scripts/faddr2line

diff --git a/scripts/faddr2line b/scripts/faddr2line
new file mode 100755
index 0000000..17f300f
--- /dev/null
+++ b/scripts/faddr2line
@@ -0,0 +1,54 @@
+#!/bin/bash
+#
+# Translate stack dump function offsets.
+#
+# addr2line doesn't work with KASLR addresses.  This works similarly to
+# addr2line, but instead takes the 'func+0x123' format as input:
+#
+#   $ scripts/faddr2line vmlinux meminfo_proc_show+0x5/0x1b0
+#   fs/proc/meminfo.c:27
+#
+# It also supports duplicate symbols:
+#
+#   $ scripts/faddr2line vmlinux raw_ioctl+0x5
+#   drivers/char/raw.c:122
+#   net/ipv4/raw.c:876
+
+set -o errexit
+set -o nounset
+
+usage() {
+	echo "usage: faddr2line <object file> <func+offset>" >&2
+	exit 1
+}
+
+die() {
+	echo "ERROR: $1" >&2
+	exit 1
+}
+
+[[ $# != 2 ]] && usage
+
+objfile=$1
+[[ ! -f $objfile ]] && die "can't find objfile $objfile"
+
+func_offset=$2
+func=${func_offset%+*}
+offset=${func_offset#*+}
+offset=${offset%/*}
+[[ -z $func ]] || [[ -z $offset ]] || [[ $func = $func_offset ]] ||
+	[[ $offset = $func_offset ]] && die "bad func+offset $func_offset"
+
+command -v objdump >/dev/null 2>&1 || die "objdump isn't installed"
+command -v addr2line >/dev/null 2>&1 || die "addr2line isn't installed"
+
+addrs=$(objdump -t $objfile | awk -v f=$func '$6 == f {print $1}')
+[[ -z $addrs ]] && die "can't find $func in $objfile"
+
+for base in $addrs; do
+	addr=$((0x$base + $offset))
+	[[ -z $addr ]] || [[ $addr = 0 ]] && die "bad address: 0x$base + $offset"
+
+	hexaddr=$(printf %x $addr)
+	addr2line -ie $objfile $hexaddr
+done
-- 
2.7.4

Re: [PATCH] scripts: add script for translating stack dump function offsets

[Linus Torvalds]

On Fri, Sep 16, 2016 at 7:48 AM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
>
> Here's something a lot faster than gdb, which also handles duplicate
> symbols properly.

Ack.

Side note: I find addr2line almost completely useless in many cases
not because of address space randomization, but because of how complex
the inlining often is. I just had something where I decided to use
addr2line and it just pointed me to the __read_once_size_nocheck()
line in <linux/compiler.h>. That was not very useful.

I ended up actually looking at the instructions *around* it, to find
where that one instruction had been inlined from.

So I'm wondering if this kind of helper script could be extended to
have that "look around it" thing to help.

Finally, I note that *if* you hit the "multiple copies of the same
function name" issue, it might be a good idea to limit the function
name copies by their size/offset. Also, shouldn't you filter the
objdump for just functions Both the size and the function filtering
should be possible with some additional awk script magic.

For example, in my current kernel build, I have the following object
names that are both functions and non-functions:

  event_function, irq_trigger, p_start, tbl_size, verbose, watchdog

and I have 10 different versions of the function ("type_show()", with
sizes ranging from 26 bytes to 166 bytes. So both the function offset
filtering and the type filtering could definitely make a difference.

            Linus

Re: [PATCH] scripts: add script for translating stack dump function offsets

[Josh Poimboeuf]

On Fri, Sep 16, 2016 at 11:12:10AM -0700, Linus Torvalds wrote:
> On Fri, Sep 16, 2016 at 7:48 AM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
> >
> > Here's something a lot faster than gdb, which also handles duplicate
> > symbols properly.
> 
> Ack.
> 
> Side note: I find addr2line almost completely useless in many cases
> not because of address space randomization, but because of how complex
> the inlining often is. I just had something where I decided to use
> addr2line and it just pointed me to the __read_once_size_nocheck()
> line in <linux/compiler.h>. That was not very useful.
> 
> I ended up actually looking at the instructions *around* it, to find
> where that one instruction had been inlined from.
> 
> So I'm wondering if this kind of helper script could be extended to
> have that "look around it" thing to help.

I think that issue is solved by addr2line's '--inline' option, which the
script uses:

  $ scripts/faddr2line vmlinux show_stack_log_lvl+0x28
  /home/jpoimboe/git/linux/include/linux/compiler.h:220
  /home/jpoimboe/git/linux/arch/x86/include/asm/atomic.h:26
  /home/jpoimboe/git/linux/arch/x86/include/asm/atomic.h:240
  /home/jpoimboe/git/linux/include/linux/atomic.h:506
  /home/jpoimboe/git/linux/include/linux/sched.h:3154
  /home/jpoimboe/git/linux/arch/x86/kernel/dumpstack_64.c:151

> Finally, I note that *if* you hit the "multiple copies of the same
> function name" issue, it might be a good idea to limit the function
> name copies by their size/offset. Also, shouldn't you filter the
> objdump for just functions Both the size and the function filtering
> should be possible with some additional awk script magic.
> 
> For example, in my current kernel build, I have the following object
> names that are both functions and non-functions:
> 
>   event_function, irq_trigger, p_start, tbl_size, verbose, watchdog
> 
> and I have 10 different versions of the function ("type_show()", with
> sizes ranging from 26 bytes to 166 bytes. So both the function offset
> filtering and the type filtering could definitely make a difference.

Yeah, good ideas.  That would help reduce some of the false duplicates,
though they are quite rare.  I'll see what I can do.

-- 
Josh

Re: [PATCH] scripts: add script for translating stack dump function offsets

[Linus Torvalds]

On Fri, Sep 16, 2016 at 12:17 PM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
>
> I think that issue is solved by addr2line's '--inline' option, which the
> script uses:

Oh, well, even better. I clearly don't know addr2line well enough, and
having a script that does this correctly automatically is clearly what
*I* need too.

>>                 So both the function offset
>> filtering and the type filtering could definitely make a difference.
>
> Yeah, good ideas.  That would help reduce some of the false duplicates,
> though they are quite rare.  I'll see what I can do.

Yeah, in practice the false duplicates almost never happen. We do have
duplicate function names, but they tend to be for simple things.

And the call trace often makes it obvious which particular function it
is for the human that is reading the output, but since it should be
easy to cut down on the potential duplicates, I think it's a good
thing to do.

           Linus

[PATCH v2] scripts: add script for translating stack dump function offsets

[Josh Poimboeuf]

On Fri, Sep 16, 2016 at 12:26:31PM -0700, Linus Torvalds wrote:
> On Fri, Sep 16, 2016 at 12:17 PM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
> >
> > I think that issue is solved by addr2line's '--inline' option, which the
> > script uses:
> 
> Oh, well, even better. I clearly don't know addr2line well enough, and
> having a script that does this correctly automatically is clearly what
> *I* need too.
> 
> >>                 So both the function offset
> >> filtering and the type filtering could definitely make a difference.
> >
> > Yeah, good ideas.  That would help reduce some of the false duplicates,
> > though they are quite rare.  I'll see what I can do.
> 
> Yeah, in practice the false duplicates almost never happen. We do have
> duplicate function names, but they tend to be for simple things.
> 
> And the call trace often makes it obvious which particular function it
> is for the human that is reading the output, but since it should be
> easy to cut down on the potential duplicates, I think it's a good
> thing to do.

Ok, how about this.  If this looks ok, would you be willing to apply it?

---

From: Josh Poimboeuf <jpoimboe@redhat.com>
Subject: [PATCH v2] scripts: add script for translating stack dump function
 offsets

addr2line doesn't work with KASLR addresses.  Add a basic addr2line
wrapper script which takes the 'func+offset/size' format as input.

Signed-off-by: Josh Poimboeuf <jpoimboe@redhat.com>
---
v2:
- add size and function type checking
- use readelf for more deterministic output

 scripts/faddr2line | 96 ++++++++++++++++++++++++++++++++++++++++++++++++++++++
 1 file changed, 96 insertions(+)
 create mode 100755 scripts/faddr2line

diff --git a/scripts/faddr2line b/scripts/faddr2line
new file mode 100755
index 0000000..a837815
--- /dev/null
+++ b/scripts/faddr2line
@@ -0,0 +1,96 @@
+#!/bin/bash
+#
+# Translate stack dump function offsets.
+#
+# addr2line doesn't work with KASLR addresses.  This works similarly to
+# addr2line, but instead takes the 'func+0x123' format as input:
+#
+#   $ ./scripts/faddr2line vmlinux meminfo_proc_show+0x5/0x568
+#   fs/proc/meminfo.c:27
+#
+# If the address is part of an inlined function, the full inline call chain is
+# printed:
+#
+#   $ ./scripts/faddr2line vmlinux native_write_msr+0x6/0x27
+#   arch/x86/include/asm/msr.h:121
+#   include/linux/jump_label.h:125
+#   arch/x86/include/asm/msr.h:125
+#
+# The function size after the '/' in the input is optional, but recommended.
+# It's used to help disambiguate any duplicate symbol names, which can occur
+# rarely.  If the size is omitted for a duplicate symbol then it's possible for
+# multiple code sites to be printed:
+#
+#   $ ./scripts/faddr2line vmlinux raw_ioctl+0x5
+#   drivers/char/raw.c:122
+#   net/ipv4/raw.c:876
+
+set -o errexit
+set -o nounset
+
+usage() {
+	echo "usage: faddr2line <object file> <func+offset>" >&2
+	exit 1
+}
+
+die() {
+	echo "ERROR: $1" >&2
+	exit 1
+}
+
+command -v awk >/dev/null 2>&1 || die "awk isn't installed"
+command -v readelf >/dev/null 2>&1 || die "readelf isn't installed"
+command -v addr2line >/dev/null 2>&1 || die "addr2line isn't installed"
+
+[[ $# != 2 ]] && usage
+
+objfile=$1
+[[ ! -f $objfile ]] && die "can't find objfile $objfile"
+
+func_addr=$2
+func=${func_addr%+*}
+offset=${func_addr#*+}
+offset=${offset%/*}
+size=
+[[ $func_addr =~ "/" ]] && size=${func_addr#*/}
+
+if [[ -z $func ]] || [[ -z $offset ]] || [[ $func = $func_addr ]]; then
+	die "bad func+offset $func_addr"
+fi
+
+# Go through each of the object's symbols which match the func name.
+# In rare cases there might be duplicates.
+while read symbol; do
+	fields=($symbol)
+	sym_base=0x${fields[1]}
+	sym_size=${fields[2]}
+	sym_type=${fields[3]}
+
+	# calculate the address
+	addr=$(($sym_base + $offset))
+	if [[ -z $addr ]] || [[ $addr = 0 ]]; then
+		die "bad address: $sym_base + $offset"
+	fi
+	hexaddr=0x$(printf %x $addr)
+
+	# weed out non-function symbols
+	if [[ $sym_type != "FUNC" ]]; then
+		echo "skipping $func address at $hexaddr due to non-function symbol"
+		continue
+	fi
+
+	# if the user provided a size, make sure it matches the symbol's size
+	if [[ -n $size ]] && [[ $size -ne $sym_size ]]; then
+		echo "skipping $func address at $hexaddr due to size mismatch ($size != $sym_size)"
+		continue;
+	fi
+
+	# make sure the provided offset is within the symbol's range
+	if [[ $offset -gt $sym_size ]]; then
+		echo "skipping $func address at $hexaddr due to size mismatch ($offset <= $sym_size)"
+		continue
+	fi
+
+	addr2line -ie $objfile $hexaddr
+
+done < <(readelf -s $objfile | awk -v f=$func '$8 == f {print}')
-- 
2.7.4

Re: [PATCH v2] scripts: add script for translating stack dump function offsets

[Linus Torvalds]

On Fri, Sep 16, 2016 at 2:26 PM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
>
> Ok, how about this.  If this looks ok, would you be willing to apply it?

Looks good to me. Did you test the size verification with some made-up cases?

                Linus

Re: [PATCH v2] scripts: add script for translating stack dump function offsets

[Josh Poimboeuf]

On Fri, Sep 16, 2016 at 05:09:15PM -0700, Linus Torvalds wrote:
> On Fri, Sep 16, 2016 at 2:26 PM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
> >
> > Ok, how about this.  If this looks ok, would you be willing to apply it?
> 
> Looks good to me. Did you test the size verification with some made-up cases?

Yep.  And I tested all the other edge cases that occurred to me.

-- 
Josh

Re: [PATCH v2] scripts: add script for translating stack dump function offsets

[Peter Zijlstra]

On Fri, Sep 16, 2016 at 04:26:56PM -0500, Josh Poimboeuf wrote:
> Ok, how about this.  If this looks ok, would you be willing to apply it?

Looks good, and yes without --inline addr2line would be tons less useful
;-) Thanks for cooking this up.

Re: [PATCH v2] scripts: add script for translating stack dump function offsets

[Linus Torvalds]

On Fri, Sep 16, 2016 at 5:42 PM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
> On Fri, Sep 16, 2016 at 05:09:15PM -0700, Linus Torvalds wrote:
>> On Fri, Sep 16, 2016 at 2:26 PM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
>> >
>> > Ok, how about this.  If this looks ok, would you be willing to apply it?
>>
>> Looks good to me. Did you test the size verification with some made-up cases?
>
> Yep.  And I tested all the other edge cases that occurred to me.

Hmm. So I tested it a bit, and I found a few issues..

 (1) actual bug: you really need the "-W" flag to 'readelf'. Otherwise
it will truncate the lines to fit in 80 columns, which in turn limits
symbol names to 25 characters or something like that.

 (2) usability: I have been known to want to look up multiple symbols.
So could we support a syntax like

       /scripts/faddr2line vmlinux function1+15/226 other_fn_name+32/128

     or something like that?

 (3) noise: I have to say that it seems to work really well, but the
"skipping" messages are a bit verbose.

     I guess they practically never actually *trigger*, but

     [torvalds@i7 linux]$ ./scripts/faddr2line vmlinux type_show+0x10/45
     skipping type_show address at 0xffffffff81023690 due to size
mismatch (45 != 166)
     skipping type_show address at 0xffffffff811894f0 due to size
mismatch (45 != 41)
     /home/torvalds/v2.6/linux/drivers/video/backlight/backlight.c:213
     skipping type_show address at 0xffffffff814e9340 due to size
mismatch (45 != 119)
     skipping type_show address at 0xffffffff8157a080 due to size
mismatch (45 != 50)
     skipping type_show address at 0xffffffff815bbeb0 due to size
mismatch (45 != 38)
     skipping type_show address at 0xffffffff815ea8c0 due to size
mismatch (45 != 35)
     skipping type_show address at 0xffffffff8162c650 due to size
mismatch (45 != 40)
     skipping type_show address at 0xffffffff8162f910 due to size
mismatch (45 != 38)
     skipping type_show address at 0xffffffff81694ec0 due to size
mismatch (45 != 26)

     it's almost hard to pick out the case that succeeded from all the
noise from the ones that didn't.

 (4) ambiguous "inlining" vs "multiple possible cases":

     [torvalds@i7 linux]$ ./scripts/faddr2line vmlinux free+15/36
     /home/torvalds/v2.6/linux/./include/crypto/algapi.h:302
     /home/torvalds/v2.6/linux/crypto/lrw.c:377
     /home/torvalds/v2.6/linux/./include/crypto/algapi.h:302
     /home/torvalds/v2.6/linux/crypto/xts.c:334

     That's actually two different cases, both of which inline
crypto_instance_ctx(), and both of which are really the exact same
code (just lrw vs xts), so they have the same name and size.

 (5) I'd love for the pathnames to be shown relative to the root of the project

And (1) is trivial to fix (use "-Ws" instead of "-s" to readelf).

I don't think (2) is a huge deal, but I suspect it wouldn't be nasty
to do by just using a shell function and iterating over the
arguments..

But (3) might be a "don't care, it's so unusual as to not be an
issue", although it might also be a case of "maybe we should only show
the mismatches if there are *no* matches, or if teh user specified
verbose output with '-v' or something"

I think (4) is worth fixing. Maybe by simply outputting the function
name/offset/size again for each hit, which is something you'd need to
do for (2) anyway, so that the above case would become

     [torvalds@i7 linux]$ ./scripts/faddr2line vmlinux free+15
     vmlinux free+15/36:
     /home/torvalds/v2.6/linux/./include/crypto/algapi.h:302
     /home/torvalds/v2.6/linux/crypto/lrw.c:377
     vmlinux free+15/36:
     /home/torvalds/v2.6/linux/./include/crypto/algapi.h:302
     /home/torvalds/v2.6/linux/crypto/xts.c:334

(Note how I didn't give the size on the command line, but the printout
showed it anyway).

And finally, I suspect (5) is not reasonably fixable. Oh well. It
would require some kind of "figure out the largest common prefix of
all the filenames in the whole object file". So I'm *not* talking
about just passing "--basenames" to addr2line.

Hmm. Maybe looking up the "DW_AT_comp_dir" tag in the debug info would
work? And just stripping that off?

But on the whole, this is really nice. I always disliked the stupid
addr2line crap. This just looks like we can get *much* better output
by tweaking things to what the kernel uses/needs..

Would you mind looking at those things? Just (1) I can do myself, but
I'm hoping you'd be willing to maybe do a bit more surgery on your own
script..

              Linus

Re: [PATCH v2] scripts: add script for translating stack dump function offsets

[Linus Torvalds]

On Fri, Sep 16, 2016 at 6:59 PM, Linus Torvalds
<torvalds@linux-foundation.org> wrote:
>
> And finally, I suspect (5) is not reasonably fixable. Oh well. It
> would require some kind of "figure out the largest common prefix of
> all the filenames in the whole object file". So I'm *not* talking
> about just passing "--basenames" to addr2line.
>
> Hmm. Maybe looking up the "DW_AT_comp_dir" tag in the debug info would
> work? And just stripping that off?

Thinking more about this, that actually sounds like it might be the
right thing to do.

It doesn't work for most projects, but the way the kernel build system
is set up, we don't actually recursively descend into subdirectories,
we always build at the top level. So DW_AT_comp_dir should always (?)
be the actual top-level build directory, and we could just scrape that
off from the addr2line output.

That said, I don't even know what the "real" way to dump the debug
symbol data is. I do *not* believe that you should use

  readelf -W --debug-dump vmlinux | grep DW_AT_comp_dir | head -1

to get the information. There is bound to be something much better.
Somebody who knows the ELF tools can now pipe in and show the world
what a maroon I am.

               Linus

Re: [PATCH v2] scripts: add script for translating stack dump function offsets

[Rabin Vincent]

On Fri, Sep 16, 2016 at 04:26:56PM -0500, Josh Poimboeuf wrote:
> +	addr2line -ie $objfile $hexaddr

Could you pass in -f and -p too to addr2line?

Before:

 $ scripts/faddr2line ~/dev/kvm2/vmlinux free_reserved_area+0x90
 /home/rabin/dev/linux/include/linux/compiler.h:222
 /home/rabin/dev/linux/include/linux/page-flags.h:149
 /home/rabin/dev/linux/include/linux/page-flags.h:154
 /home/rabin/dev/linux/include/linux/page-flags.h:287
 /home/rabin/dev/linux/include/linux/mm.h:1778
 /home/rabin/dev/linux/include/linux/mm.h:1785
 /home/rabin/dev/linux/mm/page_alloc.c:6599

After:

 $ scripts/faddr2line ~/dev/kvm2/vmlinux free_reserved_area+0x90
 __read_once_size at /home/rabin/dev/linux/include/linux/compiler.h:222
  (inlined by) PageTail at /home/rabin/dev/linux/include/linux/page-flags.h:149
  (inlined by) PageCompound at /home/rabin/dev/linux/include/linux/page-flags.h:154
  (inlined by) ClearPageReserved at /home/rabin/dev/linux/include/linux/page-flags.h:287
  (inlined by) __free_reserved_page at /home/rabin/dev/linux/include/linux/mm.h:1778
  (inlined by) free_reserved_page at /home/rabin/dev/linux/include/linux/mm.h:1785
  (inlined by) free_reserved_area at /home/rabin/dev/linux/mm/page_alloc.c:6599

Re: [PATCH] scripts: add script for translating stack dump function offsets

[Vegard Nossum]

On 16 September 2016 at 21:17, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
> On Fri, Sep 16, 2016 at 11:12:10AM -0700, Linus Torvalds wrote:
>> Side note: I find addr2line almost completely useless in many cases
>> not because of address space randomization, but because of how complex
>> the inlining often is. I just had something where I decided to use
>> addr2line and it just pointed me to the __read_once_size_nocheck()
>> line in <linux/compiler.h>. That was not very useful.
>>
>> I ended up actually looking at the instructions *around* it, to find
>> where that one instruction had been inlined from.
>>
>> So I'm wondering if this kind of helper script could be extended to
>> have that "look around it" thing to help.
>
> I think that issue is solved by addr2line's '--inline' option, which the
> script uses:

Another small gotcha is that stack trace addresses are _return
addresses_, not callsites. So you'll sometimes want to pass 'addr - 1'
instead of just addr, as the next address (the return address) may
belong to a completely unrelated deeply inlined function.


Vegard

Re: [PATCH v2] scripts: add script for translating stack dump function offsets

[Josh Poimboeuf]

On Fri, Sep 16, 2016 at 06:59:22PM -0700, Linus Torvalds wrote:
> On Fri, Sep 16, 2016 at 5:42 PM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
> > On Fri, Sep 16, 2016 at 05:09:15PM -0700, Linus Torvalds wrote:
> >> On Fri, Sep 16, 2016 at 2:26 PM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
> >> >
> >> > Ok, how about this.  If this looks ok, would you be willing to apply it?
> >>
> >> Looks good to me. Did you test the size verification with some made-up cases?
> >
> > Yep.  And I tested all the other edge cases that occurred to me.
> 
> Hmm. So I tested it a bit, and I found a few issues..

Ok, I agree with pretty much everything you said.  I'll try to add those
improvements next week.

-- 
Josh

Re: [PATCH v2] scripts: add script for translating stack dump function offsets

[Josh Poimboeuf]

On Sat, Sep 17, 2016 at 10:15:45AM +0200, Rabin Vincent wrote:
> On Fri, Sep 16, 2016 at 04:26:56PM -0500, Josh Poimboeuf wrote:
> > +	addr2line -ie $objfile $hexaddr
> 
> Could you pass in -f and -p too to addr2line?
> 
> Before:
> 
>  $ scripts/faddr2line ~/dev/kvm2/vmlinux free_reserved_area+0x90
>  /home/rabin/dev/linux/include/linux/compiler.h:222
>  /home/rabin/dev/linux/include/linux/page-flags.h:149
>  /home/rabin/dev/linux/include/linux/page-flags.h:154
>  /home/rabin/dev/linux/include/linux/page-flags.h:287
>  /home/rabin/dev/linux/include/linux/mm.h:1778
>  /home/rabin/dev/linux/include/linux/mm.h:1785
>  /home/rabin/dev/linux/mm/page_alloc.c:6599
> 
> After:
> 
>  $ scripts/faddr2line ~/dev/kvm2/vmlinux free_reserved_area+0x90
>  __read_once_size at /home/rabin/dev/linux/include/linux/compiler.h:222
>   (inlined by) PageTail at /home/rabin/dev/linux/include/linux/page-flags.h:149
>   (inlined by) PageCompound at /home/rabin/dev/linux/include/linux/page-flags.h:154
>   (inlined by) ClearPageReserved at /home/rabin/dev/linux/include/linux/page-flags.h:287
>   (inlined by) __free_reserved_page at /home/rabin/dev/linux/include/linux/mm.h:1778
>   (inlined by) free_reserved_page at /home/rabin/dev/linux/include/linux/mm.h:1785
>   (inlined by) free_reserved_area at /home/rabin/dev/linux/mm/page_alloc.c:6599

Yeah, I think that's much better.

-- 
Josh

Re: [PATCH] scripts: add script for translating stack dump function offsets

[Josh Poimboeuf]

On Sat, Sep 17, 2016 at 11:11:44AM +0200, Vegard Nossum wrote:
> On 16 September 2016 at 21:17, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
> > On Fri, Sep 16, 2016 at 11:12:10AM -0700, Linus Torvalds wrote:
> >> Side note: I find addr2line almost completely useless in many cases
> >> not because of address space randomization, but because of how complex
> >> the inlining often is. I just had something where I decided to use
> >> addr2line and it just pointed me to the __read_once_size_nocheck()
> >> line in <linux/compiler.h>. That was not very useful.
> >>
> >> I ended up actually looking at the instructions *around* it, to find
> >> where that one instruction had been inlined from.
> >>
> >> So I'm wondering if this kind of helper script could be extended to
> >> have that "look around it" thing to help.
> >
> > I think that issue is solved by addr2line's '--inline' option, which the
> > script uses:
> 
> Another small gotcha is that stack trace addresses are _return
> addresses_, not callsites. So you'll sometimes want to pass 'addr - 1'
> instead of just addr, as the next address (the return address) may
> belong to a completely unrelated deeply inlined function.

Hm, good point.  In that case, should it *always* subtract 1?  (Except
when the offset is already 0, of course.)

-- 
Josh

[PATCH v3] scripts: add script for translating stack dump function

[Josh Poimboeuf]

On Fri, Sep 16, 2016 at 06:59:22PM -0700, Linus Torvalds wrote:
> On Fri, Sep 16, 2016 at 5:42 PM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
> > On Fri, Sep 16, 2016 at 05:09:15PM -0700, Linus Torvalds wrote:
> >> On Fri, Sep 16, 2016 at 2:26 PM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
> >> >
> >> > Ok, how about this.  If this looks ok, would you be willing to apply it?
> >>
> >> Looks good to me. Did you test the size verification with some made-up cases?
> >
> > Yep.  And I tested all the other edge cases that occurred to me.
> 
> Hmm. So I tested it a bit, and I found a few issues..
> 
>  (1) actual bug: you really need the "-W" flag to 'readelf'. Otherwise
> it will truncate the lines to fit in 80 columns, which in turn limits
> symbol names to 25 characters or something like that.
> 
>  (2) usability: I have been known to want to look up multiple symbols.
> So could we support a syntax like
> 
>        /scripts/faddr2line vmlinux function1+15/226 other_fn_name+32/128
> 
>      or something like that?
> 
>  (3) noise: I have to say that it seems to work really well, but the
> "skipping" messages are a bit verbose.
> 
>      I guess they practically never actually *trigger*, but
> 
>      [torvalds@i7 linux]$ ./scripts/faddr2line vmlinux type_show+0x10/45
>      skipping type_show address at 0xffffffff81023690 due to size
> mismatch (45 != 166)
>      skipping type_show address at 0xffffffff811894f0 due to size
> mismatch (45 != 41)
>      /home/torvalds/v2.6/linux/drivers/video/backlight/backlight.c:213
>      skipping type_show address at 0xffffffff814e9340 due to size
> mismatch (45 != 119)
>      skipping type_show address at 0xffffffff8157a080 due to size
> mismatch (45 != 50)
>      skipping type_show address at 0xffffffff815bbeb0 due to size
> mismatch (45 != 38)
>      skipping type_show address at 0xffffffff815ea8c0 due to size
> mismatch (45 != 35)
>      skipping type_show address at 0xffffffff8162c650 due to size
> mismatch (45 != 40)
>      skipping type_show address at 0xffffffff8162f910 due to size
> mismatch (45 != 38)
>      skipping type_show address at 0xffffffff81694ec0 due to size
> mismatch (45 != 26)
> 
>      it's almost hard to pick out the case that succeeded from all the
> noise from the ones that didn't.
> 
>  (4) ambiguous "inlining" vs "multiple possible cases":
> 
>      [torvalds@i7 linux]$ ./scripts/faddr2line vmlinux free+15/36
>      /home/torvalds/v2.6/linux/./include/crypto/algapi.h:302
>      /home/torvalds/v2.6/linux/crypto/lrw.c:377
>      /home/torvalds/v2.6/linux/./include/crypto/algapi.h:302
>      /home/torvalds/v2.6/linux/crypto/xts.c:334
> 
>      That's actually two different cases, both of which inline
> crypto_instance_ctx(), and both of which are really the exact same
> code (just lrw vs xts), so they have the same name and size.
> 
>  (5) I'd love for the pathnames to be shown relative to the root of the project

I addressed all of the above issues, and also added the -f and -p flags
to addr2line which Rabin suggested.

One caveat with #5 (relative path names).  Looking at DW_AT_comp_dir
wouldn't work, because that's the *object* directory, not the source
directory.

The only working (and fast) approach I could come up with was an ugly
hack.  It assumes that start_kernel() is in init/main.c.  Before doing
the _real_ addr2line, it first runs addr2line for start_kernel() and
strips the relative path:

	local start_kernel_addr=$(readelf -sW $objfile | awk '$8 == "start_kernel" {printf "0x%s", $2}')
	[[ -z $start_kernel_addr ]] && return

	local file_line=$(addr2line -e $objfile $start_kernel_addr)
	[[ -z $file_line ]] && return

	local prefix=${file_line%init/main.c:*}
	[[ $prefix = $file_line ]] && return

	DIR_PREFIX=$prefix

And of course that only works when the object file is vmlinux.  If it
can't find start_kernel() in init/main.c, it gracefully falls back to
just printing the absolute path.

---

From: Josh Poimboeuf <jpoimboe@redhat.com>
Subject: [PATCH v3] scripts: add script for translating stack dump function
 offsets

addr2line doesn't work with KASLR addresses.  Add a basic addr2line
wrapper script which takes the 'func+offset/size' format as input.

Signed-off-by: Josh Poimboeuf <jpoimboe@redhat.com>
---
 scripts/faddr2line | 177 +++++++++++++++++++++++++++++++++++++++++++++++++++++
 1 file changed, 177 insertions(+)
 create mode 100755 scripts/faddr2line

diff --git a/scripts/faddr2line b/scripts/faddr2line
new file mode 100755
index 0000000..4fbfe83
--- /dev/null
+++ b/scripts/faddr2line
@@ -0,0 +1,177 @@
+#!/bin/bash
+#
+# Translate stack dump function offsets.
+#
+# addr2line doesn't work with KASLR addresses.  This works similarly to
+# addr2line, but instead takes the 'func+0x123' format as input:
+#
+#   $ ./scripts/faddr2line ~/k/vmlinux meminfo_proc_show+0x5/0x568
+#   meminfo_proc_show+0x5/0x568:
+#   meminfo_proc_show at fs/proc/meminfo.c:27
+#
+# If the address is part of an inlined function, the full inline call chain is
+# printed:
+#
+#   $ ./scripts/faddr2line ~/k/vmlinux native_write_msr+0x6/0x27
+#   native_write_msr+0x6/0x27:
+#   arch_static_branch at arch/x86/include/asm/msr.h:121
+#    (inlined by) static_key_false at include/linux/jump_label.h:125
+#    (inlined by) native_write_msr at arch/x86/include/asm/msr.h:125
+#
+# The function size after the '/' in the input is optional, but recommended.
+# It's used to help disambiguate any duplicate symbol names, which can occur
+# rarely.  If the size is omitted for a duplicate symbol then it's possible for
+# multiple code sites to be printed:
+#
+#   $ ./scripts/faddr2line ~/k/vmlinux raw_ioctl+0x5
+#   raw_ioctl+0x5/0x20:
+#   raw_ioctl at drivers/char/raw.c:122
+#
+#   raw_ioctl+0x5/0xb1:
+#   raw_ioctl at net/ipv4/raw.c:876
+#
+# Multiple addresses can be specified on a single command line:
+#
+#   $ ./scripts/faddr2line ~/k/vmlinux type_show+0x10/45 free_reserved_area+0x90
+#   type_show+0x10/0x2d:
+#   type_show at drivers/video/backlight/backlight.c:213
+#
+#   free_reserved_area+0x90/0x123:
+#   free_reserved_area at mm/page_alloc.c:6429 (discriminator 2)
+
+
+set -o errexit
+set -o nounset
+
+command -v awk >/dev/null 2>&1 || die "awk isn't installed"
+command -v readelf >/dev/null 2>&1 || die "readelf isn't installed"
+command -v addr2line >/dev/null 2>&1 || die "addr2line isn't installed"
+
+usage() {
+	echo "usage: faddr2line <object file> <func+offset> <func+offset>..." >&2
+	exit 1
+}
+
+warn() {
+	echo "$1" >&2
+}
+
+die() {
+	echo "ERROR: $1" >&2
+	exit 1
+}
+
+# Try to figure out the source directory prefix so we can remove it from the
+# addr2line output.  HACK ALERT: This assumes that start_kernel() is in
+# kernel/init.c!  This only works for vmlinux.  Otherwise it falls back to
+# printing the absolute path.
+find_dir_prefix() {
+	local objfile=$1
+
+	local start_kernel_addr=$(readelf -sW $objfile | awk '$8 == "start_kernel" {printf "0x%s", $2}')
+	[[ -z $start_kernel_addr ]] && return
+
+	local file_line=$(addr2line -e $objfile $start_kernel_addr)
+	[[ -z $file_line ]] && return
+
+	local prefix=${file_line%init/main.c:*}
+	if [[ -z $prefix ]] || [[ $prefix = $file_line ]]; then
+		return
+	fi
+
+	DIR_PREFIX=$prefix
+	return 0
+}
+
+__faddr2line() {
+	local objfile=$1
+	local func_addr=$2
+	local dir_prefix=$3
+	local print_warnings=$4
+
+	local func=${func_addr%+*}
+	local offset=${func_addr#*+}
+	offset=${offset%/*}
+	local size=
+	[[ $func_addr =~ "/" ]] && size=${func_addr#*/}
+
+	if [[ -z $func ]] || [[ -z $offset ]] || [[ $func = $func_addr ]]; then
+		warn "bad func+offset $func_addr"
+		DONE=1
+		return
+	fi
+
+	# Go through each of the object's symbols which match the func name.
+	# In rare cases there might be duplicates.
+	while read symbol; do
+		local fields=($symbol)
+		local sym_base=0x${fields[1]}
+		local sym_size=${fields[2]}
+		local sym_type=${fields[3]}
+
+		# calculate the address
+		local addr=$(($sym_base + $offset))
+		if [[ -z $addr ]] || [[ $addr = 0 ]]; then
+			warn "bad address: $sym_base + $offset"
+			DONE=1
+			return
+		fi
+		local hexaddr=0x$(printf %x $addr)
+
+		# weed out non-function symbols
+		if [[ $sym_type != "FUNC" ]]; then
+			[[ $print_warnings = 1 ]] &&
+				echo "skipping $func address at $hexaddr due to non-function symbol"
+			continue
+		fi
+
+		# if the user provided a size, make sure it matches the symbol's size
+		if [[ -n $size ]] && [[ $size -ne $sym_size ]]; then
+			[[ $print_warnings = 1 ]] &&
+				echo "skipping $func address at $hexaddr due to size mismatch ($size != $sym_size)"
+			continue;
+		fi
+
+		# make sure the provided offset is within the symbol's range
+		if [[ $offset -gt $sym_size ]]; then
+			[[ $print_warnings = 1 ]] &&
+				echo "skipping $func address at $hexaddr due to size mismatch ($offset > $sym_size)"
+			continue
+		fi
+
+		# separate multiple entries with a blank line
+		[[ $FIRST = 0 ]] && echo
+		FIRST=0
+
+		local hexsize=0x$(printf %x $sym_size)
+		echo "$func+$offset/$hexsize:"
+		addr2line -fpie $objfile $hexaddr | sed "s;$dir_prefix;;"
+		DONE=1
+
+	done < <(readelf -sW $objfile | awk -v f=$func '$8 == f {print}')
+}
+
+[[ $# -lt 2 ]] && usage
+
+objfile=$1
+[[ ! -f $objfile ]] && die "can't find objfile $objfile"
+shift
+
+DIR_PREFIX=supercalifragilisticexpialidocious
+find_dir_prefix $objfile
+
+FIRST=1
+while [[ $# -gt 0 ]]; do
+	func_addr=$1
+	shift
+
+	# print any matches found
+	DONE=0
+	__faddr2line $objfile $func_addr $DIR_PREFIX 0
+
+	# if no match was found, print warnings
+	if [[ $DONE = 0 ]]; then
+		__faddr2line $objfile $func_addr $DIR_PREFIX 1
+		warn "no match for $func_addr"
+	fi
+done
-- 
2.7.4

Re: [PATCH v3] scripts: add script for translating stack dump function

[Linus Torvalds]

On Mon, Sep 19, 2016 at 8:52 AM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
>
> One caveat with #5 (relative path names).  Looking at DW_AT_comp_dir
> wouldn't work, because that's the *object* directory, not the source
> directory.
>
> The only working (and fast) approach I could come up with was an ugly
> hack.  It assumes that start_kernel() is in init/main.c.

That sounds entirely reasonable. Maybe somebody can come up with a
better and more general approach, but that sounds like a fine starting
point, and any incremental improvents can happen in the tree. So I'll
apply your patch (assuming it passes my basic testing, which I expect
it will).

                Linus

Re: [PATCH v3] scripts: add script for translating stack dump function

[Linus Torvalds]

On Mon, Sep 19, 2016 at 11:56 AM, Linus Torvalds
<torvalds@linux-foundation.org> wrote:
>>
>> The only working (and fast) approach I could come up with was an ugly
>> hack.  It assumes that start_kernel() is in init/main.c.
>
> That sounds entirely reasonable. Maybe somebody can come up with a
> better and more general approach, but that sounds like a fine starting
> point, and any incremental improvents can happen in the tree. So I'll
> apply your patch (assuming it passes my basic testing, which I expect
> it will).

Hmm. Would you mind if I change the

        addr2line -fpie $objfile $hexaddr | sed "s;$dir_prefix;;"

into

        addr2line -fpie $objfile $hexaddr |
                sed "s; at $dir_prefix\(\./\)*; at ;"

instead? There's two changes there: matching the " at " part (to just
make the match stricter) but also matching any following "./" thing
(which shows up for our include tree files, at least for me).

With that, all the cases I threw at it looked pretty good.

But the stricter matching might not matter, of course, and maybe there
is some addr2line version that doesn't do that? So I'm checking here..

                Linus

Re: [PATCH v3] scripts: add script for translating stack dump function

[Josh Poimboeuf]

On Mon, Sep 19, 2016 at 12:15:42PM -0700, Linus Torvalds wrote:
> On Mon, Sep 19, 2016 at 11:56 AM, Linus Torvalds
> <torvalds@linux-foundation.org> wrote:
> >>
> >> The only working (and fast) approach I could come up with was an ugly
> >> hack.  It assumes that start_kernel() is in init/main.c.
> >
> > That sounds entirely reasonable. Maybe somebody can come up with a
> > better and more general approach, but that sounds like a fine starting
> > point, and any incremental improvents can happen in the tree. So I'll
> > apply your patch (assuming it passes my basic testing, which I expect
> > it will).
> 
> Hmm. Would you mind if I change the
> 
>         addr2line -fpie $objfile $hexaddr | sed "s;$dir_prefix;;"
> 
> into
> 
>         addr2line -fpie $objfile $hexaddr |
>                 sed "s; at $dir_prefix\(\./\)*; at ;"
> 
> instead? There's two changes there: matching the " at " part (to just
> make the match stricter) but also matching any following "./" thing
> (which shows up for our include tree files, at least for me).
> 
> With that, all the cases I threw at it looked pretty good.
> 
> But the stricter matching might not matter, of course, and maybe there
> is some addr2line version that doesn't do that? So I'm checking here..

For some reason, I don't see the "./" for my include files.  But
regardless, your changes look good to me.

-- 
Josh

Re: [PATCH v3] scripts: add script for translating stack dump function

[Rabin Vincent]

On Mon, Sep 19, 2016 at 12:15:42PM -0700, Linus Torvalds wrote:
> Hmm. Would you mind if I change the
> 
>         addr2line -fpie $objfile $hexaddr | sed "s;$dir_prefix;;"
> 
> into
> 
>         addr2line -fpie $objfile $hexaddr |
>                 sed "s; at $dir_prefix\(\./\)*; at ;"
> 
> instead? There's two changes there: matching the " at " part (to just
> make the match stricter) but also matching any following "./" thing
> (which shows up for our include tree files, at least for me).

Note that addr2line has localized strings, so the regex with the " at "
won't match for everyone unless you invoke addr2line with LANG=C.

$ ../linux/scripts/faddr2line vmlinux free_reserved_area+61
free_reserved_area+61/0xe4:
__write_once_size på /home/rabinv/dev/linux/include/linux/compiler.h:248
(inline:ad av)set_page_count på /home/rabinv/dev/linux/include/linux/page_ref.h:76
(inline:ad av)init_page_count på /home/rabinv/dev/linux/include/linux/page_ref.h:87
(inline:ad av)__free_reserved_page på /home/rabinv/dev/linux/include/linux/mm.h:1818
(inline:ad av)free_reserved_page på /home/rabinv/dev/linux/include/linux/mm.h:1824
(inline:ad av)free_reserved_area på /home/rabinv/dev/linux/mm/page_alloc.c:6476

$ LANG=C ../linux/scripts/faddr2line vmlinux free_reserved_area+61
free_reserved_area+61/0xe4:
__write_once_size at include/linux/compiler.h:248
 (inlined by) set_page_count at include/linux/page_ref.h:76
 (inlined by) init_page_count at include/linux/page_ref.h:87
 (inlined by) __free_reserved_page at include/linux/mm.h:1818
 (inlined by) free_reserved_page at include/linux/mm.h:1824
 (inlined by) free_reserved_area at mm/page_alloc.c:6476

Re: [PATCH v3] scripts: add script for translating stack dump function

[Linus Torvalds]

On Mon, Sep 19, 2016 at 1:00 PM, Rabin Vincent <rabin@rab.in> wrote:
>
> Note that addr2line has localized strings, so the regex with the " at "
> won't match for everyone unless you invoke addr2line with LANG=C.

Ok, I'll make it match just on the space instead.

> __write_once_size på /home/rabinv/dev/linux/include/linux/compiler.h:248

That's an odd localization choice.

"på"? Wouldn't "i" (or perhaps "vid") be a better choice?

Anyway, this works for me in the Swedish locale too. Look ok?

   -       addr2line -fpie $objfile $hexaddr | sed "s;$dir_prefix;;"
   +       addr2line -fpie $objfile $hexaddr |
   +               sed "s; $dir_prefix\(\./\)*; ;"

because I certainly hope there is always a space there.

              Linus

Re: [PATCH v3] scripts: add script for translating stack dump function

[Josh Poimboeuf]

On Mon, Sep 19, 2016 at 01:24:03PM -0700, Linus Torvalds wrote:
> On Mon, Sep 19, 2016 at 1:00 PM, Rabin Vincent <rabin@rab.in> wrote:
> >
> > Note that addr2line has localized strings, so the regex with the " at "
> > won't match for everyone unless you invoke addr2line with LANG=C.
> 
> Ok, I'll make it match just on the space instead.
> 
> > __write_once_size på /home/rabinv/dev/linux/include/linux/compiler.h:248
> 
> That's an odd localization choice.
> 
> "på"? Wouldn't "i" (or perhaps "vid") be a better choice?
> 
> Anyway, this works for me in the Swedish locale too. Look ok?
> 
>    -       addr2line -fpie $objfile $hexaddr | sed "s;$dir_prefix;;"
>    +       addr2line -fpie $objfile $hexaddr |
>    +               sed "s; $dir_prefix\(\./\)*; ;"
> 
> because I certainly hope there is always a space there.

No luck.  The Japanese translation uses an empty string:

  $ grep -A1 '" at "' binutils/po/ja.po
  msgid " at "
  msgstr ""

-- 
Josh

Re: [PATCH v3] scripts: add script for translating stack dump function

[Linus Torvalds]

On Mon, Sep 19, 2016 at 1:56 PM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
> On Mon, Sep 19, 2016 at 01:24:03PM -0700, Linus Torvalds wrote:
>>
>> because I certainly hope there is always a space there.
>
> No luck.  The Japanese translation uses an empty string:

Heh.

Ok, we don't want to *just* have the "./" pattern ever be replaced,
because for all I know there could be a directory name ending with "."
in there somewhere.

But I guess we could do it this way instead:

  --- a/scripts/faddr2line
  +++ b/scripts/faddr2line
  @@ -79,7 +79,7 @@ find_dir_prefix() {
                  return
          fi

  -       DIR_PREFIX=$prefix
  +       DIR_PREFIX="$prefix\(\./\)*"
          return 0
   }

and thus just make it part of the auto-generated pattern string instead.

             Linus

Re: [PATCH v3] scripts: add script for translating stack dump function

[Josh Poimboeuf]

On Mon, Sep 19, 2016 at 02:02:18PM -0700, Linus Torvalds wrote:
> On Mon, Sep 19, 2016 at 1:56 PM, Josh Poimboeuf <jpoimboe@redhat.com> wrote:
> > On Mon, Sep 19, 2016 at 01:24:03PM -0700, Linus Torvalds wrote:
> >>
> >> because I certainly hope there is always a space there.
> >
> > No luck.  The Japanese translation uses an empty string:
> 
> Heh.
> 
> Ok, we don't want to *just* have the "./" pattern ever be replaced,
> because for all I know there could be a directory name ending with "."
> in there somewhere.
> 
> But I guess we could do it this way instead:
> 
>   --- a/scripts/faddr2line
>   +++ b/scripts/faddr2line
>   @@ -79,7 +79,7 @@ find_dir_prefix() {
>                   return
>           fi
> 
>   -       DIR_PREFIX=$prefix
>   +       DIR_PREFIX="$prefix\(\./\)*"
>           return 0
>    }
> 
> and thus just make it part of the auto-generated pattern string instead.

Actually, false alarm.  The empty translation string seems to mean "use
the original string":

  $ export LANG=ja_JP.utf8
  $ ./scripts/faddr2line ~/k/vmlinux type_show+0x10/45
  type_show+0x10/0x2d:
  type_show at drivers/video/backlight/backlight.c:213

So your previous patch which checks for a space looks good after all :-)

-- 
Josh