Re: [PATCH] tracing / synthetic: Disable events after testing in synth_event_gen_test_init()

From: Alexander Graf
Date: Thu Dec 21 2023 - 05:07:03 EST


Hi Steve,

On 20.12.23 17:15, Steven Rostedt wrote:

From: "Steven Rostedt (Google)" <rostedt@xxxxxxxxxxx>

The synth_event_gen_test module can be built in, if someone wants to run
the tests at boot up and not have to load them.

The synth_event_gen_test_init() function creates and enables the synthetic
events and runs its tests.

The synth_event_gen_test_exit() disables the events it created and
destroys the events.

If the module is builtin, the events are never disabled. The issue is, the
events should be disable after the tests are run. This could be an issue
if the rest of the boot up tests are enabled, as they expect the events to
be in a known state before testing. That known state happens to be
disabled.

When CONFIG_SYNTH_EVENT_GEN_TEST=y and CONFIG_EVENT_TRACE_STARTUP_TEST=y
a warning will trigger:

Running tests on trace events:
Testing event create_synth_test:
Enabled event during self test!
------------[ cut here ]------------
WARNING: CPU: 2 PID: 1 at kernel/trace/trace_events.c:4150 event_trace_self_tests+0x1c2/0x480
Modules linked in:
CPU: 2 PID: 1 Comm: swapper/0 Not tainted 6.7.0-rc2-test-00031-gb803d7c664d5-dirty #276
Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.16.2-debian-1.16.2-1 04/01/2014
RIP: 0010:event_trace_self_tests+0x1c2/0x480
Code: bb e8 a2 ab 5d fc 48 8d 7b 48 e8 f9 3d 99 fc 48 8b 73 48 40 f6 c6 01 0f 84 d6 fe ff ff 48 c7 c7 20 b6 ad bb e8 7f ab 5d fc 90 <0f> 0b 90 48 89 df e8 d3 3d 99 fc 48 8b 1b 4c 39 f3 0f 85 2c ff ff
RSP: 0000:ffffc9000001fdc0 EFLAGS: 00010246
RAX: 0000000000000029 RBX: ffff88810399ca80 RCX: 0000000000000000
RDX: 0000000000000000 RSI: ffffffffb9f19478 RDI: ffff88823c734e64
RBP: ffff88810399f300 R08: 0000000000000000 R09: fffffbfff79eb32a
R10: ffffffffbcf59957 R11: 0000000000000001 R12: ffff888104068090
R13: ffffffffbc89f0a0 R14: ffffffffbc8a0f08 R15: 0000000000000078
FS: 0000000000000000(0000) GS:ffff88823c700000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 0000000000000000 CR3: 00000001f6282001 CR4: 0000000000170ef0
Call Trace:
<TASK>
? __warn+0xa5/0x200
? event_trace_self_tests+0x1c2/0x480
? report_bug+0x1f6/0x220
? handle_bug+0x6f/0x90
? exc_invalid_op+0x17/0x50
? asm_exc_invalid_op+0x1a/0x20
? tracer_preempt_on+0x78/0x1c0
? event_trace_self_tests+0x1c2/0x480
? __pfx_event_trace_self_tests_init+0x10/0x10
event_trace_self_tests_init+0x27/0xe0
do_one_initcall+0xd6/0x3c0
? __pfx_do_one_initcall+0x10/0x10
? kasan_set_track+0x25/0x30
? rcu_is_watching+0x38/0x60
kernel_init_freeable+0x324/0x450
? __pfx_kernel_init+0x10/0x10
kernel_init+0x1f/0x1e0
? _raw_spin_unlock_irq+0x33/0x50
ret_from_fork+0x34/0x60
? __pfx_kernel_init+0x10/0x10
ret_from_fork_asm+0x1b/0x30
</TASK>

This is because the synth_event_gen_test_init() left the synthetic events
that it created enabled. By having it disable them after testing, the
other selftests will run fine.

Cc: stable@xxxxxxxxxxxxxxx
Fixes: 9fe41efaca084 ("tracing: Add synth event generation test module")
Reported-by: Alexander Graf <graf@xxxxxxxxxx>
Signed-off-by: Steven Rostedt (Google) <rostedt@xxxxxxxxxxx>


Thanks a bunch for the super quick turnaround time for the fix! I can confirm that I'm no longer seeing the warning :)

Tested-by: Alexander Graf <graf@xxxxxxxxxx>


Do we need another similar patch for the kprobe self tests? The below is with 55cb5f43689d7 plus an unrelated initrd patch plus this patch and the following .config: http://csgraf.de/tmp2/config-ftrace.xz

[  919.717134] Testing all events: OK
[  924.418194] Testing ftrace filter: OK
[  924.418887] trace_kprobe: Testing kprobe tracing:
[  924.424244] ------------[ cut here ]------------
[  924.424952] WARNING: CPU: 2 PID: 1 at kernel/trace/trace_kprobe.c:2073 kprobe_trace_self_tests_init+0x192/0x540
[  924.425659] Modules linked in:
[  924.425886] CPU: 2 PID: 1 Comm: swapper/0 Not tainted 6.7.0-rc6-00024-gc10698ad3c9a #298
[  924.426448] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS rel-1.16.2-0-gea1b7a073390-prebuilt.qemu.org 04/01/2014
[  924.427230] RIP: 0010:kprobe_trace_self_tests_init+0x192/0x540
[  924.427639] Code: 7e 10 74 3b 48 8b 36 48 39 d6 75 f2 0f 0b 48 c7 c7 58 71 79 a5 e8 ee 3e 5a fe 48 c7 c7 20 38 b7 a5 e8 a2 51 68 fe 85 c0 74 33 <0f> 0b 48 c7 c7 38 73 79 a5 e8 d0 3e 5a fe e8 4b 64 62 fe eb 23 48
[  924.428922] RSP: 0000:ffffab508001be58 EFLAGS: 00010286
[  924.429288] RAX: 00000000fffffff0 RBX: 000000000000005a RCX: 0000000000000202
[  924.429800] RDX: 0000000000000000 RSI: 000000000002e970 RDI: ffffffffa5b708a0
[  924.430295] RBP: 0000000000000000 R08: 0000000000000001 R09: ffffffffa4855a90
[  924.430794] R10: 0000000000000007 R11: 000000000000028a R12: 0000000000000001
[  924.431286] R13: ffffffffa5cc9a00 R14: ffff8cec81bebe00 R15: ffffffffa619f0f0
[  924.431785] FS:  0000000000000000(0000) GS:ffff8cecf9100000(0000) knlGS:0000000000000000
[  924.432346] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  924.432748] CR2: 0000000000000000 CR3: 000000004883e001 CR4: 00000000003706f0
[  924.433246] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[  924.433739] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[  924.434233] Call Trace:
[  924.434418]  <TASK>
[  924.434569]  ? __warn+0x7d/0x140
[  924.434807]  ? kprobe_trace_self_tests_init+0x192/0x540
[  924.435172]  ? report_bug+0xf8/0x1e0
[  924.435430]  ? handle_bug+0x3f/0x70
[  924.435677]  ? exc_invalid_op+0x13/0x60
[  924.435954]  ? asm_exc_invalid_op+0x16/0x20
[  924.436249]  ? rdinit_setup+0x40/0x40
[  924.436509]  ? trace_kprobe_release+0x70/0xb0
[  924.436822]  ? kprobe_trace_self_tests_init+0x192/0x540
[  924.437189]  ? kprobe_trace_self_tests_init+0x421/0x540
[  924.437551]  ? init_kprobe_trace+0x1b0/0x1b0
[  924.437855]  do_one_initcall+0x44/0x200
[  924.438131]  kernel_init_freeable+0x1e8/0x330
[  924.438439]  ? rest_init+0xd0/0xd0
[  924.438682]  kernel_init+0x16/0x130
[  924.438943]  ret_from_fork+0x30/0x50
[  924.439202]  ? rest_init+0xd0/0xd0
[  924.439445]  ret_from_fork_asm+0x11/0x20
[  924.439734]  </TASK>
[  924.439893] ---[ end trace 0000000000000000 ]---
[  924.440217] trace_kprobe: error on cleaning up probes.
[  924.440575] NG: Some tests are failed. Please check them.


Alex




Amazon Development Center Germany GmbH
Krausenstr. 38
10117 Berlin
Geschaeftsfuehrung: Christian Schlaeger, Jonathan Weiss
Eingetragen am Amtsgericht Charlottenburg unter HRB 149173 B
Sitz: Berlin
Ust-ID: DE 289 237 879