Re: [PATCH] tracing / synthetic: Disable events after testing in synth_event_gen_test_init()
On Thu, 21 Dec 2023 11:06:38 +0100 Alexander Graf wrote: > 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 Thanks Alex, > > > 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 Sure, now you tell me ;-) I just finished all my tests and will be sending Linus a pull request soon. I'll let Masami handle this one, as it's under his department. -- Steve > > [ 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: :ab508001be58 EFLAGS: 00010286 > [ 924.429288] RAX: fff0 RBX: 005a RCX: > 0202 > [ 924.429800] RDX: RSI: 0002e970 RDI: > a5b708a0 > [ 924.430295] RBP: R08: 0001 R09: > a4855a90 > [ 924.430794] R10: 0007 R11: 028a R12: > 0001 > [ 924.431286] R13: a5cc9a00 R14: 8cec81bebe00 R15: > a619f0f0 > [ 924.431785] FS: () GS:8cecf910() > knlGS: > [ 924.432346] CS: 0010 DS: ES: CR0: 80050033 > [ 924.432748] CR2: CR3: 4883e001 CR4: > 003706f0 > [ 924.433246] DR0: DR1: DR2: > > [ 924.433739] DR3: DR6: fffe0ff0 DR7: > 0400 > [ 924.434233] Call Trace: > [ 924.434418] > [ 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] > [ 924.439893] ---[ end trace ]--- > [ 924.440217] trace_kprobe: error on cleaning up probes. > [ 924.440575] NG: Some tests are failed. Please check them.
Re: [PATCH] tracing / synthetic: Disable events after testing in synth_event_gen_test_init()
Hi Steve,
On 20.12.23 17:15, Steven Rostedt wrote:
From: "Steven Rostedt (Google)"
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: :c901fdc0 EFLAGS: 00010246
RAX: 0029 RBX: 88810399ca80 RCX:
RDX: RSI: b9f19478 RDI: 88823c734e64
RBP: 88810399f300 R08: R09: fbfff79eb32a
R10: bcf59957 R11: 0001 R12: 888104068090
R13: bc89f0a0 R14: bc8a0f08 R15: 0078
FS: () GS:88823c70() knlGS:
CS: 0010 DS: ES: CR0: 80050033
CR2: CR3: 0001f6282001 CR4: 00170ef0
Call Trace:
? __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
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: sta...@vger.kernel.org
Fixes: 9fe41efaca084 ("tracing: Add synth event generation test module")
Reported-by: Alexander Graf
Signed-off-by: Steven Rostedt (Google)
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
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: :ab508001be58 EFLAGS: 00010286
[ 924.429288] RAX: fff0 RBX: 005a RCX:
0202
[ 924.429800] RDX: RSI: 0002e970 RDI:
a5b708a0
[ 924.430295] RBP: R08: 0001 R09:
a4855a90
[ 924.430794] R10: 0007 R11: 028a R12:
0001
[ 924.431286] R13: a5cc9a00 R14: 8cec81bebe00 R15:
a619f0f0
[ 924.431785] FS: () GS:8cecf910()
knlGS:
[ 924.432346] CS: 0010 DS: ES: CR0: 80050033
[ 924.432748] CR2:
Re: [PATCH] tracing / synthetic: Disable events after testing in synth_event_gen_test_init()
On Wed, 20 Dec 2023 11:15:25 -0500
Steven Rostedt wrote:
> From: "Steven Rostedt (Google)"
>
> 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: :c901fdc0 EFLAGS: 00010246
> RAX: 0029 RBX: 88810399ca80 RCX:
> RDX: RSI: b9f19478 RDI: 88823c734e64
> RBP: 88810399f300 R08: R09: fbfff79eb32a
> R10: bcf59957 R11: 0001 R12: 888104068090
> R13: bc89f0a0 R14: bc8a0f08 R15: 0078
> FS: () GS:88823c70() knlGS:
> CS: 0010 DS: ES: CR0: 80050033
> CR2: CR3: 0001f6282001 CR4: 00170ef0
> Call Trace:
>
> ? __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
>
>
> 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.
>
Ah, OK. It has to clean up the testing events.
Acked-by: Masami Hiramatsu (Google)
Thank you,
> Cc: sta...@vger.kernel.org
> Fixes: 9fe41efaca084 ("tracing: Add synth event generation test module")
> Reported-by: Alexander Graf
> Signed-off-by: Steven Rostedt (Google)
> ---
> kernel/trace/synth_event_gen_test.c | 11 +++
> 1 file changed, 11 insertions(+)
>
> diff --git a/kernel/trace/synth_event_gen_test.c
> b/kernel/trace/synth_event_gen_test.c
> index 8dfe85499d4a..354c2117be43 100644
> --- a/kernel/trace/synth_event_gen_test.c
> +++ b/kernel/trace/synth_event_gen_test.c
> @@ -477,6 +477,17 @@ static int __init synth_event_gen_test_init(void)
>
> ret = test_trace_synth_event();
> WARN_ON(ret);
> +
> + /* Disable when done */
> + trace_array_set_clr_event(gen_synth_test->tr,
> + "synthetic",
> + "gen_synth_test", false);
> + trace_array_set_clr_event(empty_synth_test->tr,
> + "synthetic",
> + "empty_synth_test", false);
> + trace_array_set_clr_event(create_synth_test->tr,
> + "synthetic",
> + "create_synth_test", false);
> out:
> return ret;
> }
> --
> 2.42.0
>
--
Masami Hiramatsu (Google)
[PATCH] tracing / synthetic: Disable events after testing in synth_event_gen_test_init()
From: "Steven Rostedt (Google)"
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: :c901fdc0 EFLAGS: 00010246
RAX: 0029 RBX: 88810399ca80 RCX:
RDX: RSI: b9f19478 RDI: 88823c734e64
RBP: 88810399f300 R08: R09: fbfff79eb32a
R10: bcf59957 R11: 0001 R12: 888104068090
R13: bc89f0a0 R14: bc8a0f08 R15: 0078
FS: () GS:88823c70() knlGS:
CS: 0010 DS: ES: CR0: 80050033
CR2: CR3: 0001f6282001 CR4: 00170ef0
Call Trace:
? __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
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: sta...@vger.kernel.org
Fixes: 9fe41efaca084 ("tracing: Add synth event generation test module")
Reported-by: Alexander Graf
Signed-off-by: Steven Rostedt (Google)
---
kernel/trace/synth_event_gen_test.c | 11 +++
1 file changed, 11 insertions(+)
diff --git a/kernel/trace/synth_event_gen_test.c
b/kernel/trace/synth_event_gen_test.c
index 8dfe85499d4a..354c2117be43 100644
--- a/kernel/trace/synth_event_gen_test.c
+++ b/kernel/trace/synth_event_gen_test.c
@@ -477,6 +477,17 @@ static int __init synth_event_gen_test_init(void)
ret = test_trace_synth_event();
WARN_ON(ret);
+
+ /* Disable when done */
+ trace_array_set_clr_event(gen_synth_test->tr,
+ "synthetic",
+ "gen_synth_test", false);
+ trace_array_set_clr_event(empty_synth_test->tr,
+ "synthetic",
+ "empty_synth_test", false);
+ trace_array_set_clr_event(create_synth_test->tr,
+ "synthetic",
+ "create_synth_test", false);
out:
return ret;
}
--
2.42.0
