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