On Thu, 29 Jan 2026 22:26:08 -0500
Steven Rostedt <[email protected]> wrote:
> Use trace_printk() instead. printk now has a "deferred" output. I'm not
> sure if the timestamps of when it prints is when the print took place
> or when it got to the console :-/
I added the below patch and have this result:
kworker/u33:1-79 [002] ..... 1.840855: trace_event_update_all:
Start syncing
swapper/0-1 [005] ..... 6.045742: trace_eval_sync: sync maps
kworker/u33:1-79 [002] ..... 12.289296: trace_event_update_all:
Finish syncing
swapper/0-1 [005] ..... 12.289387: trace_eval_sync: sync maps
complete
Which shows that the final initcall waited for the work queue to complete:
-- Steve
diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index 396d59202438..33180d5622a8 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -10817,9 +10817,11 @@ subsys_initcall(trace_eval_init);
static int __init trace_eval_sync(void)
{
+ trace_printk("sync maps\n");
/* Make sure the eval map updates are finished */
if (eval_map_wq)
destroy_workqueue(eval_map_wq);
+ trace_printk("sync maps complete\n");
return 0;
}
diff --git a/kernel/trace/trace_events.c b/kernel/trace/trace_events.c
index af6d1fe5cab7..194b344400e9 100644
--- a/kernel/trace/trace_events.c
+++ b/kernel/trace/trace_events.c
@@ -3555,6 +3555,7 @@ void trace_event_update_all(struct trace_eval_map **map,
int len)
int last_i;
int i;
+ trace_printk("Start syncing\n");
down_write(&trace_event_sem);
list_for_each_entry_safe(call, p, &ftrace_events, list) {
/* events are usually grouped together with systems */
@@ -3593,6 +3594,8 @@ void trace_event_update_all(struct trace_eval_map **map,
int len)
cond_resched();
}
up_write(&trace_event_sem);
+ msleep(10000);
+ trace_printk("Finish syncing\n");
}
static bool event_in_systems(struct trace_event_call *call,