diff mbox series

[v3,5/5] kernel: tracepoints: add support for relative references

Message ID 20170819181035.969-6-ard.biesheuvel@linaro.org
State New
Headers show
Series add support for relative references in special sections | expand

Commit Message

Ard Biesheuvel Aug. 19, 2017, 6:10 p.m. UTC 
To avoid the need for relocating absolute references to tracepoint
structures at boot time when running relocatable kernels (which may
take a disproportionate amount of space), add the option to emit
these tables as relative references instead.

Cc: Steven Rostedt <rostedt@goodmis.org>
Cc: Ingo Molnar <mingo@redhat.com>
Signed-off-by: Ard Biesheuvel <ard.biesheuvel@linaro.org>

---
 include/linux/tracepoint.h | 19 +++++++++++++++----
 kernel/tracepoint.c        | 17 +++++++++++++----
 2 files changed, 28 insertions(+), 8 deletions(-)

-- 
2.11.0

Comments

Steven Rostedt Aug. 20, 2017, 2:51 p.m. UTC | #1 
On Sat, 19 Aug 2017 19:10:35 +0100
Ard Biesheuvel <ard.biesheuvel@linaro.org> wrote:

> To avoid the need for relocating absolute references to tracepoint

> structures at boot time when running relocatable kernels (which may

> take a disproportionate amount of space), add the option to emit

> these tables as relative references instead.

> 


This patch looks fine. But I want to test the series before giving it
my Acked-by. I wont be able to do that till Tuesday at the earliest.

-- Steve
Ard Biesheuvel Aug. 30, 2017, 12:52 p.m. UTC | #2 
On 20 August 2017 at 15:51, Steven Rostedt <rostedt@goodmis.org> wrote:
> On Sat, 19 Aug 2017 19:10:35 +0100

> Ard Biesheuvel <ard.biesheuvel@linaro.org> wrote:

>

>> To avoid the need for relocating absolute references to tracepoint

>> structures at boot time when running relocatable kernels (which may

>> take a disproportionate amount of space), add the option to emit

>> these tables as relative references instead.

>>

>

> This patch looks fine. But I want to test the series before giving it

> my Acked-by. I wont be able to do that till Tuesday at the earliest.

>


I guess this has slipped between the cracks?
Steven Rostedt Aug. 30, 2017, 1:17 p.m. UTC | #3 
On Wed, 30 Aug 2017 13:52:26 +0100
Ard Biesheuvel <ard.biesheuvel@linaro.org> wrote:

> On 20 August 2017 at 15:51, Steven Rostedt <rostedt@goodmis.org> wrote:

> > On Sat, 19 Aug 2017 19:10:35 +0100

> > Ard Biesheuvel <ard.biesheuvel@linaro.org> wrote:

> >  

> >> To avoid the need for relocating absolute references to tracepoint

> >> structures at boot time when running relocatable kernels (which may

> >> take a disproportionate amount of space), add the option to emit

> >> these tables as relative references instead.

> >>  

> >

> > This patch looks fine. But I want to test the series before giving it

> > my Acked-by. I wont be able to do that till Tuesday at the earliest.

> >  

> 

> I guess this has slipped between the cracks?


Yes it has. Thanks for the reminder. I'm quite overwhelmed after coming
back from vacation, and getting pulled in various directions.

I'll see if I can run it through some tests today.

-- Steve
Ard Biesheuvel Aug. 30, 2017, 1:18 p.m. UTC | #4 
On 30 August 2017 at 14:17, Steven Rostedt <rostedt@goodmis.org> wrote:
> On Wed, 30 Aug 2017 13:52:26 +0100

> Ard Biesheuvel <ard.biesheuvel@linaro.org> wrote:

>

>> On 20 August 2017 at 15:51, Steven Rostedt <rostedt@goodmis.org> wrote:

>> > On Sat, 19 Aug 2017 19:10:35 +0100

>> > Ard Biesheuvel <ard.biesheuvel@linaro.org> wrote:

>> >

>> >> To avoid the need for relocating absolute references to tracepoint

>> >> structures at boot time when running relocatable kernels (which may

>> >> take a disproportionate amount of space), add the option to emit

>> >> these tables as relative references instead.

>> >>

>> >

>> > This patch looks fine. But I want to test the series before giving it

>> > my Acked-by. I wont be able to do that till Tuesday at the earliest.

>> >

>>

>> I guess this has slipped between the cracks?

>

> Yes it has. Thanks for the reminder. I'm quite overwhelmed after coming

> back from vacation, and getting pulled in various directions.

>

> I'll see if I can run it through some tests today.

>


Thanks, that would be much appreciated.
Steven Rostedt Aug. 30, 2017, 6:13 p.m. UTC | #5 
On Sat, 19 Aug 2017 19:10:35 +0100
Ard Biesheuvel <ard.biesheuvel@linaro.org> wrote:

> To avoid the need for relocating absolute references to tracepoint

> structures at boot time when running relocatable kernels (which may

> take a disproportionate amount of space), add the option to emit

> these tables as relative references instead.

> 

> Cc: Steven Rostedt <rostedt@goodmis.org>


I ran this through various tests (not my full test suite mind you), and
it appears to work as it has before.

Acked-by: Steven Rostedt (VMware) <rostedt@goodmis.org>


-- Steve
Ard Biesheuvel Aug. 30, 2017, 6:26 p.m. UTC | #6 
> On 30 Aug 2017, at 19:13, Steven Rostedt <rostedt@goodmis.org> wrote:

> 

> On Sat, 19 Aug 2017 19:10:35 +0100

> Ard Biesheuvel <ard.biesheuvel@linaro.org> wrote:

> 

>> To avoid the need for relocating absolute references to tracepoint

>> structures at boot time when running relocatable kernels (which may

>> take a disproportionate amount of space), add the option to emit

>> these tables as relative references instead.

>> 

>> Cc: Steven Rostedt <rostedt@goodmis.org>

> 

> I ran this through various tests (not my full test suite mind you), and

> it appears to work as it has before.

> 

> Acked-by: Steven Rostedt (VMware) <rostedt@goodmis.org>

> 


Thanks!
Jessica Yu Sept. 5, 2017, 12:48 p.m. UTC | #7 
+++ Ard Biesheuvel [19/08/17 19:10 +0100]:
>To avoid the need for relocating absolute references to tracepoint

>structures at boot time when running relocatable kernels (which may

>take a disproportionate amount of space), add the option to emit

>these tables as relative references instead.

>

>Cc: Steven Rostedt <rostedt@goodmis.org>

>Cc: Ingo Molnar <mingo@redhat.com>

>Signed-off-by: Ard Biesheuvel <ard.biesheuvel@linaro.org>


Hi Ard,

While testing this patchset I ran into the following general protection
fault when removing a module with tracepoints:

# rmmod kvm
[   25.279049] general protection fault: 0000 [#1] SMP
[   25.279385] Modules linked in: kvm(-) irqbypass
[   25.279829] CPU: 0 PID: 125 Comm: rmmod Not tainted 4.13.0-rc2+ #1
[   25.280007] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.10.2-1.fc26 04/01/2014
[   25.280315] task: ffff9697db7c0000 task.stack: ffffa907802dc000
[   25.280624] RIP: 0010:tracepoint_module_notify+0xd5/0x1d0
[   25.280782] RSP: 0018:ffffa907802dfe68 EFLAGS: 00000287
[   25.280963] RAX: ffffffffc02b6fb0 RBX: ffff9697ddb33440 RCX: ffffffffc02b70f0
[   25.281168] RDX: 000163cc00016410 RSI: ffff9697df21d860 RDI: ffff9697de001900
[   25.281371] RBP: ffffa907802dfe88 R08: 000000000001d860 R09: ffffffff941692b4
[   25.281543] R10: fffff0ec4076ccc0 R11: 0000000000000300 R12: ffffffffc02ce740
[   25.281716] R13: 0000000000000002 R14: ffffffffc02ce740 R15: 0000000000000000
[   25.281917] FS:  0000000000a6e880(0000) GS:ffff9697df200000(0000) knlGS:0000000000000000
[   25.282107] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[   25.282254] CR2: 00000000004adfc0 CR3: 000000001f838000 CR4: 00000000000006f0
[   25.282517] Call Trace:
[   25.283019]  notifier_call_chain+0x4a/0x70
[   25.283287]  blocking_notifier_call_chain+0x43/0x60
[   25.283422]  SyS_delete_module+0x1b8/0x240
[   25.283542]  ? SyS_chdir+0xc4/0xe0
[   25.283648]  entry_SYSCALL_64_fastpath+0x1a/0xa5
[   25.283863] RIP: 0033:0x4ba267
[   25.283947] RSP: 002b:00007ffc3316bdf8 EFLAGS: 00000246 ORIG_RAX: 00000000000000b0
[   25.284134] RAX: ffffffffffffffda RBX: 0000000000000000 RCX: 00000000004ba267
[   25.284310] RDX: 0000000000000000 RSI: 0000000000000880 RDI: 00007ffc3316be00
[   25.284511] RBP: 00007ffc3316be40 R08: 0000000000000003 R09: 0000000000000000
[   25.284699] R10: 0000000000000000 R11: 0000000000000246 R12: 0000000000637672
[   25.284916] R13: 00007ffc3316c1b0 R14: 0000000000000000 R15: 0000000000000000
[   25.285226] Code: 00 48 89 43 08 e8 9c b4 0d 00 49 8b 84 24 90 02 00 00 48 85 c0 74 28 41 8b 94 24 8c 02 00 00 48 8d 0c d0 48 39 c8 73 17 48 8b 10 <48> 83 7a 28 00 0f 85 e8 00 00 00 48 83 c0 08 48 39 c1 77 e9 48 
[   25.286199] RIP: tracepoint_module_notify+0xd5/0x1d0 RSP: ffffa907802dfe68
[   25.286708] ---[ end trace 04f35cade1663177 ]---

The offending line is in tp_module_going_check_quiescent() (shown inlined):

(gdb) list *(tracepoint_module_notify+0xd5)
0xffffffff811692d5 is in tracepoint_module_notify (/home/jeyu/work/jeyu-linux/kernel/tracepoint.c:402).
397             struct tracepoint * const *iter;
398
399             if (!begin)
400                     return;
401             for (iter = begin; iter < end; iter++)
402                     WARN_ON_ONCE((*iter)->funcs);
403     }
404
405     static int tracepoint_module_coming(struct module *mod)
406     {

The relative reference calculations need to be done here too.

Thanks,

Jessica
Ard Biesheuvel Sept. 5, 2017, 12:49 p.m. UTC | #8 
On 5 September 2017 at 13:48, Jessica Yu <jeyu@kernel.org> wrote:
> +++ Ard Biesheuvel [19/08/17 19:10 +0100]:

>>

>> To avoid the need for relocating absolute references to tracepoint

>> structures at boot time when running relocatable kernels (which may

>> take a disproportionate amount of space), add the option to emit

>> these tables as relative references instead.

>>

>> Cc: Steven Rostedt <rostedt@goodmis.org>

>> Cc: Ingo Molnar <mingo@redhat.com>

>> Signed-off-by: Ard Biesheuvel <ard.biesheuvel@linaro.org>

>

>

> Hi Ard,

>

> While testing this patchset I ran into the following general protection

> fault when removing a module with tracepoints:

>

> # rmmod kvm

> [   25.279049] general protection fault: 0000 [#1] SMP

> [   25.279385] Modules linked in: kvm(-) irqbypass

> [   25.279829] CPU: 0 PID: 125 Comm: rmmod Not tainted 4.13.0-rc2+ #1

> [   25.280007] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS

> 1.10.2-1.fc26 04/01/2014

> [   25.280315] task: ffff9697db7c0000 task.stack: ffffa907802dc000

> [   25.280624] RIP: 0010:tracepoint_module_notify+0xd5/0x1d0

> [   25.280782] RSP: 0018:ffffa907802dfe68 EFLAGS: 00000287

> [   25.280963] RAX: ffffffffc02b6fb0 RBX: ffff9697ddb33440 RCX:

> ffffffffc02b70f0

> [   25.281168] RDX: 000163cc00016410 RSI: ffff9697df21d860 RDI:

> ffff9697de001900

> [   25.281371] RBP: ffffa907802dfe88 R08: 000000000001d860 R09:

> ffffffff941692b4

> [   25.281543] R10: fffff0ec4076ccc0 R11: 0000000000000300 R12:

> ffffffffc02ce740

> [   25.281716] R13: 0000000000000002 R14: ffffffffc02ce740 R15:

> 0000000000000000

> [   25.281917] FS:  0000000000a6e880(0000) GS:ffff9697df200000(0000)

> knlGS:0000000000000000

> [   25.282107] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033

> [   25.282254] CR2: 00000000004adfc0 CR3: 000000001f838000 CR4:

> 00000000000006f0

> [   25.282517] Call Trace:

> [   25.283019]  notifier_call_chain+0x4a/0x70

> [   25.283287]  blocking_notifier_call_chain+0x43/0x60

> [   25.283422]  SyS_delete_module+0x1b8/0x240

> [   25.283542]  ? SyS_chdir+0xc4/0xe0

> [   25.283648]  entry_SYSCALL_64_fastpath+0x1a/0xa5

> [   25.283863] RIP: 0033:0x4ba267

> [   25.283947] RSP: 002b:00007ffc3316bdf8 EFLAGS: 00000246 ORIG_RAX:

> 00000000000000b0

> [   25.284134] RAX: ffffffffffffffda RBX: 0000000000000000 RCX:

> 00000000004ba267

> [   25.284310] RDX: 0000000000000000 RSI: 0000000000000880 RDI:

> 00007ffc3316be00

> [   25.284511] RBP: 00007ffc3316be40 R08: 0000000000000003 R09:

> 0000000000000000

> [   25.284699] R10: 0000000000000000 R11: 0000000000000246 R12:

> 0000000000637672

> [   25.284916] R13: 00007ffc3316c1b0 R14: 0000000000000000 R15:

> 0000000000000000

> [   25.285226] Code: 00 48 89 43 08 e8 9c b4 0d 00 49 8b 84 24 90 02 00 00

> 48 85 c0 74 28 41 8b 94 24 8c 02 00 00 48 8d 0c d0 48 39 c8 73 17 48 8b 10

> <48> 83 7a 28 00 0f 85 e8 00 00 00 48 83 c0 08 48 39 c1 77 e9 48 [

> 25.286199] RIP: tracepoint_module_notify+0xd5/0x1d0 RSP: ffffa907802dfe68

> [   25.286708] ---[ end trace 04f35cade1663177 ]---

>

> The offending line is in tp_module_going_check_quiescent() (shown inlined):

>

> (gdb) list *(tracepoint_module_notify+0xd5)

> 0xffffffff811692d5 is in tracepoint_module_notify

> (/home/jeyu/work/jeyu-linux/kernel/tracepoint.c:402).

> 397             struct tracepoint * const *iter;

> 398

> 399             if (!begin)

> 400                     return;

> 401             for (iter = begin; iter < end; iter++)

> 402                     WARN_ON_ONCE((*iter)->funcs);

> 403     }

> 404

> 405     static int tracepoint_module_coming(struct module *mod)

> 406     {

>

> The relative reference calculations need to be done here too.

>


OK, thanks for spotting that.

I will fix and resend after the merge window closes.
Steven Rostedt Sept. 19, 2017, 5:55 p.m. UTC | #9 
On Tue, 5 Sep 2017 13:49:52 +0100
Ard Biesheuvel <ard.biesheuvel@linaro.org> wrote:

> OK, thanks for spotting that.

> 

> I will fix and resend after the merge window closes.


I also just applied your patches (to 4.13-rc7) and ran the ftrace self
tests in tools/testing/selftests/ftrace/ftracetest and it triggered
this:


 =============================
 WARNING: suspicious RCU usage
 4.13.0-rc7-test+ #101 Tainted: G        W      
 -----------------------------
 /work/git/linux-trace.git/arch/x86/kernel/traps.c:305 entry code didn't wake RCU!
 
 other info that might help us debug this:

 
 RCU used illegally from idle CPU!
 rcu_scheduler_active = 2, debug_locks = 1
 RCU used illegally from extended quiescent state!
 no locks held by swapper/0/0.
 
 stack backtrace:
 CPU: 0 PID: 0 Comm: swapper/0 Tainted: G        W       4.13.0-rc7-test+ #101
 Hardware name: Hewlett-Packard HP Compaq Pro 6300 SFF/339A, BIOS K01 v03.03 07/14/2016
 Call Trace:
  dump_stack+0x86/0xcf
  lockdep_rcu_suspicious+0xc5/0x100
  do_error_trap+0x125/0x130
  ? do_error_trap+0x5/0x130
  ? trace_hardirqs_off_thunk+0x1a/0x1c
  ? do_invalid_op+0x5/0x30
  do_invalid_op+0x20/0x30
  invalid_op+0x1e/0x30
 RIP: 0010:module_assert_mutex_or_preempt+0x34/0x40
 RSP: 0018:ffffffff81e03bc0 EFLAGS: 00010046
 RAX: 0000000000000000 RBX: ffffffffa000a077 RCX: 0000000000000002
 RDX: 0000000000000000 RSI: 00000000ffffffff RDI: 0000000000000046
 RBP: ffffffff81e03bc0 R08: ffffffff81e03f40 R09: 0000000000000000
 R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000
 R13: 0000000000000000 R14: ffffffff81e16500 R15: ffffffff81ed5760
  ? 0xffffffffa000a077
  __module_address+0x2c/0xf0
  ? 0xffffffffa000a077
  __module_text_address+0x12/0x60
  ? 0xffffffffa000a077
  is_module_text_address+0x1f/0x50
  ? 0xffffffffa000a077
  __kernel_text_address+0x30/0x90
  unwind_get_return_address+0x1f/0x30
  __save_stack_trace+0x83/0xd0
  ? 0xffffffffa000a077
  ? rcu_dynticks_eqs_exit+0x5/0x40
  save_stack_trace+0x1b/0x20
  check_stack+0xf8/0x2f0
  ? rcu_dynticks_eqs_enter+0x30/0x30
  stack_trace_call+0x6e/0x80
  0xffffffffa000a077
  ? ftrace_graph_caller+0x78/0xa8
  ? rcu_dynticks_eqs_exit+0x5/0x40
  rcu_dynticks_eqs_exit+0x5/0x40
  rcu_idle_exit+0xdf/0xf0
  ? rcu_dynticks_eqs_exit+0x5/0x40
  ? rcu_idle_exit+0xdf/0xf0
  do_idle+0x128/0x200
  cpu_startup_entry+0x1d/0x20
  rest_init+0xd6/0xe0
  start_kernel+0x40c/0x419
  ? early_idt_handler_array+0x120/0x120
  x86_64_start_reservations+0x2a/0x2c
  x86_64_start_kernel+0x13e/0x14d
  secondary_startup_64+0x9f/0x9f

 =============================
 WARNING: suspicious RCU usage
 4.13.0-rc7-test+ #101 Not tainted
 -----------------------------
 /work/git/linux-trace.git/kernel/workqueue.c:712 sched RCU or wq_pool_mutex should be held!

 other info that might help us debug this:


 RCU used illegally from idle CPU!
 rcu_scheduler_active = 2, debug_locks = 1
 RCU used illegally from extended quiescent state!
 2 locks held by swapper/0/0:
  #0:  (console_lock){+.+.+.}, at: [<ffffffff81118786>] vprintk_emit+0x246/0x3d0
  #1:  (printing_lock){......}, at: [<ffffffff81529749>] vt_console_print+0x49/0x3b0

 stack backtrace:
 CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.13.0-rc7-test+ #101
 Hardware name: Hewlett-Packard HP Compaq Pro 6300 SFF/339A, BIOS K01 v03.03 07/14/2016
 Call Trace:

 =============================
 WARNING: suspicious RCU usage
 4.13.0-rc7-test+ #101 Not tainted
 -----------------------------
 /work/git/linux-trace.git/include/linux/rcupdate.h:611 rcu_read_lock() used illegally while idle!

 other info that might help us debug this:


 RCU used illegally from idle CPU!
 rcu_scheduler_active = 2, debug_locks = 1
 RCU used illegally from extended quiescent state!
 3 locks held by swapper/0/0:
  #0:  (console_lock){+.+.+.}, at: [<ffffffff81118786>] vprintk_emit+0x246/0x3d0
  #1:  (printing_lock){......}, at: [<ffffffff81529749>] vt_console_print+0x49/0x3b0
  #2:  (rcu_read_lock){......}, at: [<ffffffff8117d025>] __is_insn_slot_addr+0x5/0x140

 stack backtrace:
 CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.13.0-rc7-test+ #101
 Hardware name: Hewlett-Packard HP Compaq Pro 6300 SFF/339A, BIOS K01 v03.03 07/14/2016
 Call Trace:

 =============================
 WARNING: suspicious RCU usage
 4.13.0-rc7-test+ #101 Not tainted
 -----------------------------
 /work/git/linux-trace.git/include/linux/rcupdate.h:662 rcu_read_unlock() used illegally while idle!

 other info that might help us debug this:


 RCU used illegally from idle CPU!
 rcu_scheduler_active = 2, debug_locks = 1
 RCU used illegally from extended quiescent state!
 4 locks held by swapper/0/0:
  #0:  (console_lock){+.+.+.}, at: [<ffffffff81118786>] vprintk_emit+0x246/0x3d0
  #1:  (printing_lock){......}, at: [<ffffffff81529749>] vt_console_print+0x49/0x3b0
  #2:  (rcu_read_lock){......}, at: [<ffffffff8117d025>] __is_insn_slot_addr+0x5/0x140
  #3:  (rcu_read_lock){......}, at: [<ffffffff8117d025>] __is_insn_slot_addr+0x5/0x140

 stack backtrace:
 CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.13.0-rc7-test+ #101
 Hardware name: Hewlett-Packard HP Compaq Pro 6300 SFF/339A, BIOS K01 v03.03 07/14/2016
 Call Trace:

 =============================
 WARNING: suspicious RCU usage
 4.13.0-rc7-test+ #101 Not tainted
 -----------------------------
 /work/git/linux-trace.git/include/linux/rcupdate.h:611 rcu_read_lock() used illegally while idle!

 other info that might help us debug this:


 RCU used illegally from idle CPU!
 rcu_scheduler_active = 2, debug_locks = 1
 RCU used illegally from extended quiescent state!
 5 locks held by swapper/0/0:
  #0:  (console_lock){+.+.+.}, at: [<ffffffff81118786>] vprintk_emit+0x246/0x3d0
  #1:  (printing_lock){......}, at: [<ffffffff81529749>] vt_console_print+0x49/0x3b0
  #2:  (rcu_read_lock){......}, at: [<ffffffff8117d025>] __is_insn_slot_addr+0x5/0x140
  #3:  (rcu_read_lock){......}, at: [<ffffffff8117d025>] __is_insn_slot_addr+0x5/0x140
  #4:  (rcu_read_lock){......}, at: [<ffffffff811ca0a5>] is_bpf_text_address+0x5/0xe0

 stack backtrace:
 CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.13.0-rc7-test+ #101
 Hardware name: Hewlett-Packard HP Compaq Pro 6300 SFF/339A, BIOS K01 v03.03 07/14/2016
 Call Trace:

 =============================
 WARNING: suspicious RCU usage
 4.13.0-rc7-test+ #101 Not tainted
 -----------------------------
 /work/git/linux-trace.git/include/linux/rcupdate.h:662 rcu_read_unlock() used illegally while idle!

 other info that might help us debug this:


 RCU used illegally from idle CPU!
 rcu_scheduler_active = 2, debug_locks = 1
 RCU used illegally from extended quiescent state!
 6 locks held by swapper/0/0:
  #0:  (console_lock){+.+.+.}, at: [<ffffffff81118786>] vprintk_emit+0x246/0x3d0
  #1:  (printing_lock){......}, at: [<ffffffff81529749>] vt_console_print+0x49/0x3b0
  #2:  (rcu_read_lock){......}, at: [<ffffffff8117d025>] __is_insn_slot_addr+0x5/0x140
  #3:  (rcu_read_lock){......}, at: [<ffffffff8117d025>] __is_insn_slot_addr+0x5/0x140
  #4:  (rcu_read_lock){......}, at: [<ffffffff811ca0a5>] is_bpf_text_address+0x5/0xe0
  #5:  (rcu_read_lock){......}, at: [<ffffffff811ca0a5>] is_bpf_text_address+0x5/0xe0

 stack backtrace:
 CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.13.0-rc7-test+ #101
 Hardware name: Hewlett-Packard HP Compaq Pro 6300 SFF/339A, BIOS K01 v03.03 07/14/2016
 Call Trace:
  dump_stack+0x86/0xcf
  lockdep_rcu_suspicious+0xc5/0x100
  is_bpf_text_address+0xdc/0xe0
  __kernel_text_address+0x74/0x90
  show_trace_log_lvl+0x160/0x380
  ? dump_stack+0x86/0xcf
  show_stack+0x44/0x60
  dump_stack+0x86/0xcf
  lockdep_rcu_suspicious+0xc5/0x100
  is_bpf_text_address+0xb2/0xe0
  __kernel_text_address+0x74/0x90
  show_trace_log_lvl+0x160/0x380
  ? dump_stack+0x86/0xcf
  show_stack+0x44/0x60
  dump_stack+0x86/0xcf
  lockdep_rcu_suspicious+0xc5/0x100
  __is_insn_slot_addr+0x114/0x140
  __kernel_text_address+0x68/0x90
  show_trace_log_lvl+0x160/0x380
  ? dump_stack+0x86/0xcf
  show_stack+0x44/0x60
  dump_stack+0x86/0xcf
  lockdep_rcu_suspicious+0xc5/0x100
  __is_insn_slot_addr+0xe0/0x140
  __kernel_text_address+0x68/0x90
  show_trace_log_lvl+0x160/0x380
  ? dump_stack+0x86/0xcf
  show_stack+0x44/0x60
  dump_stack+0x86/0xcf
  lockdep_rcu_suspicious+0xc5/0x100
  get_work_pool+0x87/0x90
  __queue_work+0x9c/0x5e0
  queue_work_on+0x8a/0xa0

 =============================
 WARNING: suspicious RCU usage
 4.13.0-rc7-test+ #101 Not tainted
 -----------------------------
 /work/git/linux-trace.git/kernel/notifier.c:548 notify_die called but RCU thinks we're quiescent!

 other info that might help us debug this:


 RCU used illegally from idle CPU!
 rcu_scheduler_active = 2, debug_locks = 1
 RCU used illegally from extended quiescent state!
 6 locks held by swapper/0/0:
  #0:  (console_lock){+.+.+.}, at: [<ffffffff81118786>] vprintk_emit+0x246/0x3d0
  #1:  (printing_lock){......}, at: [<ffffffff81529749>] vt_console_print+0x49/0x3b0
  #2:  (rcu_read_lock){......}, at: [<ffffffff8117d025>] __is_insn_slot_addr+0x5/0x140
  #3:  (rcu_read_lock){......}, at: [<ffffffff8117d025>] __is_insn_slot_addr+0x5/0x140
  #4:  (rcu_read_lock){......}, at: [<ffffffff811ca0a5>] is_bpf_text_address+0x5/0xe0
  #5:  (rcu_read_lock){......}, at: [<ffffffff811ca0a5>] is_bpf_text_address+0x5/0xe0

 stack backtrace:
 CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.13.0-rc7-test+ #101
 Hardware name: Hewlett-Packard HP Compaq Pro 6300 SFF/339A, BIOS K01 v03.03 07/14/2016
 Call Trace:
  dump_stack+0x86/0xcf
  lockdep_rcu_suspicious+0xc5/0x100
  notify_die+0x72/0x80
  do_error_trap+0x54/0x130
  ? do_error_trap+0x5/0x130
  ? trace_hardirqs_off_thunk+0x1a/0x1c
  ? do_invalid_op+0x5/0x30

 =============================
 WARNING: suspicious RCU usage
 4.13.0-rc7-test+ #101 Not tainted
 -----------------------------
 /work/git/linux-trace.git/include/linux/rcupdate.h:611 rcu_read_lock() used illegally while idle!

 other info that might help us debug this:


 RCU used illegally from idle CPU!
 rcu_scheduler_active = 2, debug_locks = 1
 RCU used illegally from extended quiescent state!
 7 locks held by swapper/0/0:
  #0:  (console_lock){+.+.+.}, at: [<ffffffff81118786>] vprintk_emit+0x246/0x3d0
  #1:  (printing_lock){......}, at: [<ffffffff81529749>] vt_console_print+0x49/0x3b0
  #2:  (rcu_read_lock){......}, at: [<ffffffff8117d025>] __is_insn_slot_addr+0x5/0x140
  #3:  (rcu_read_lock){......}, at: [<ffffffff8117d025>] __is_insn_slot_add
 Lost 1926 message(s)!


Config attached.

-- Steve
Ard Biesheuvel Sept. 20, 2017, 7:29 p.m. UTC | #10 
On 19 September 2017 at 10:55, Steven Rostedt <rostedt@goodmis.org> wrote:
> On Tue, 5 Sep 2017 13:49:52 +0100

> Ard Biesheuvel <ard.biesheuvel@linaro.org> wrote:

>

>> OK, thanks for spotting that.

>>

>> I will fix and resend after the merge window closes.

>

> I also just applied your patches (to 4.13-rc7) and ran the ftrace self

> tests in tools/testing/selftests/ftrace/ftracetest and it triggered

> this:

>


Thanks Steven.

I'm a bit puzzled how changing the struct tracepoint pointers into
relative references would result in a behavioral change like this, but
I take it this doesn't occur with a plain -rc7 build?
(Just asking)

Unfortunately, I am failing to reproduce this running a kernel built
from your .config on a 4-way SMP QEMU VM running under KVM (log below)

I do get a lot of trace_kprobe errors (attached), but I get these with
a plain v4.13-rc7 as well, so that seems unrelated.

So I will update my series to address the issue reported by Jessica,
and I would appreciate it if you can check whether that version still
triggers this issue, but there is not a whole lot I can do to fix it
atm.

Thanks,
Ard.





$ sudo tools/testing/selftests/ftrace/ftracetest
=== Ftrace unit tests ===
[1] Basic trace file check [PASS]
[2] Basic test for tracers [PASS]
[3] Basic trace clock test [PASS]
[4] Basic event tracing check [PASS]
[5] event tracing - enable/disable with event level files [PASS]
[6] event tracing - restricts events based on pid [PASS]
[7] event tracing - enable/disable with subsystem level files [PASS]
[8] event tracing - enable/disable with top level files [PASS]
[9] ftrace - function graph filters with stack tracer [PASS]
[10] ftrace - function graph filters [PASS]
[11] ftrace - test for function event triggers [PASS]
[12] ftrace - function glob filters [PASS]
[13] ftrace - function pid filters [PASS]
[14] ftrace - function profiler with function tracing [PASS]
[15] ftrace - test reading of set_ftrace_filter [PASS]
[16] ftrace - test for function traceon/off triggers [PASS]
[17] Test creation and deletion of trace instances while setting an event [PASS]
[18] Test creation and deletion of trace instances [PASS]
[19] Kprobe dynamic event - adding and removing [PASS]
[20] Kprobe dynamic event - busy event check [PASS]
[21] Kprobe dynamic event with arguments [PASS]
[22] Kprobes event arguments with types [PASS]
[23] Kprobe event auto/manual naming [PASS]
[24] Kprobe dynamic event with function tracer [PASS]
[25] Kprobe dynamic event - probing module [PASS]
[26] Kretprobe dynamic event with arguments [PASS]
[27] Kretprobe dynamic event with maxactive [PASS]
[28] Register/unregister many kprobe events [PASS]
[29] event trigger - test event enable/disable trigger [PASS]
[30] event trigger - test trigger filter [PASS]
[31] event trigger - test histogram modifiers [PASS]
[32] event trigger - test histogram trigger [PASS]
[33] event trigger - test multiple histogram triggers [PASS]
[34] event trigger - test snapshot-trigger [PASS]
[35] event trigger - test stacktrace-trigger [PASS]
[36] event trigger - test traceon/off trigger [PASS]
[37] (instance)  Basic test for tracers [PASS]
[38] (instance)  Basic trace clock test [PASS]
[39] (instance)  event tracing - enable/disable with event level files [PASS]
[40] (instance)  event tracing - restricts events based on pid [PASS]
[41] (instance)  event tracing - enable/disable with subsystem level
files [PASS]
[42] (instance)  ftrace - test for function event triggers [PASS]
[43] (instance)  ftrace - test for function traceon/off triggers [PASS]
[44] (instance)  event trigger - test event enable/disable trigger [PASS]
[45] (instance)  event trigger - test trigger filter [PASS]
[46] (instance)  event trigger - test histogram modifiers [PASS]
[47] (instance)  event trigger - test histogram trigger [PASS]
[48] (instance)  event trigger - test multiple histogram triggers [PASS]

# of passed:  48
# of failed:  0
# of unresolved:  0
# of untested:  0
# of unsupported:  0
# of xfailed:  0
# of undefined(test bug):  0
diff mbox series

Patch

diff --git a/include/linux/tracepoint.h b/include/linux/tracepoint.h
index a26ffbe09e71..d02bf1a695e8 100644
--- a/include/linux/tracepoint.h
+++ b/include/linux/tracepoint.h
@@ -228,6 +228,19 @@  extern void syscall_unregfunc(void);
 		return static_key_false(&__tracepoint_##name.key);	\
 	}
 
+#ifdef CONFIG_HAVE_ARCH_PREL32_RELOCATIONS
+#define __TRACEPOINT_ENTRY(name)					 \
+	asm("	.section \"__tracepoints_ptrs\", \"a\"		     \n" \
+	    "	.balign 4					     \n" \
+	    "	.long " VMLINUX_SYMBOL_STR(__tracepoint_##name) " - .\n" \
+	    "	.previous					     \n")
+#else
+#define __TRACEPOINT_ENTRY(name)					 \
+	static struct tracepoint * const __tracepoint_ptr_##name __used	 \
+	__attribute__((section("__tracepoints_ptrs"))) =		 \
+		&__tracepoint_##name
+#endif
+
 /*
  * We have no guarantee that gcc and the linker won't up-align the tracepoint
  * structures, so we create an array of pointers that will be used for iteration
@@ -237,11 +250,9 @@  extern void syscall_unregfunc(void);
 	static const char __tpstrtab_##name[]				 \
 	__attribute__((section("__tracepoints_strings"))) = #name;	 \
 	struct tracepoint __tracepoint_##name				 \
-	__attribute__((section("__tracepoints"))) =			 \
+	__attribute__((section("__tracepoints"), used)) =		 \
 		{ __tpstrtab_##name, STATIC_KEY_INIT_FALSE, reg, unreg, NULL };\
-	static struct tracepoint * const __tracepoint_ptr_##name __used	 \
-	__attribute__((section("__tracepoints_ptrs"))) =		 \
-		&__tracepoint_##name;
+	__TRACEPOINT_ENTRY(name);
 
 #define DEFINE_TRACE(name)						\
 	DEFINE_TRACE_FN(name, NULL, NULL);
diff --git a/kernel/tracepoint.c b/kernel/tracepoint.c
index 685c50ae6300..68b0218ef66b 100644
--- a/kernel/tracepoint.c
+++ b/kernel/tracepoint.c
@@ -508,12 +508,21 @@  static void for_each_tracepoint_range(struct tracepoint * const *begin,
 		void (*fct)(struct tracepoint *tp, void *priv),
 		void *priv)
 {
-	struct tracepoint * const *iter;
-
 	if (!begin)
 		return;
-	for (iter = begin; iter < end; iter++)
-		fct(*iter, priv);
+
+	if (IS_ENABLED(CONFIG_HAVE_ARCH_PREL32_RELOCATIONS)) {
+		const int *iter;
+
+		for (iter = (const int *)begin; iter < (const int *)end; iter++)
+			fct((struct tracepoint *)((unsigned long)iter + *iter),
+			    priv);
+	} else {
+		struct tracepoint * const *iter;
+
+		for (iter = begin; iter < end; iter++)
+			fct(*iter, priv);
+	}
 }
 
 /**