From: "Steven Rostedt (Google)" <[email protected]>
Currently trace_printk() can be used as soon as early_trace_init() is
called from start_kernel(). But if a crash happens, and
"ftrace_dump_on_oops" is set on the kernel command line, all you get will
be:
[ 0.456075] <idle>-0 0dN.2. 347519us : Unknown type 6
[ 0.456075] <idle>-0 0dN.2. 353141us : Unknown type 6
[ 0.456075] <idle>-0 0dN.2. 358684us : Unknown type 6
This is because the trace_printk() event (type 6) hasn't been registered
yet. That gets done via an early_initcall(), which may be early, but not
early enough.
Instead of registering the trace_printk() event (and other ftrace events,
which are not trace events) via an early_initcall(), have them registered at
the same time that trace_printk() can be used. This way, if there is a
crash before early_initcall(), then the trace_printk()s will actually be
useful.
Cc: [email protected]
Reported-by: "Joel Fernandes (Google)" <[email protected]>
Fixes: e725c731e3bb1 ("tracing: Split tracing initialization into two for early initialization")
Signed-off-by: Steven Rostedt (Google) <[email protected]>
---
kernel/trace/trace.c | 2 ++
kernel/trace/trace.h | 1 +
kernel/trace/trace_output.c | 3 +--
3 files changed, 4 insertions(+), 2 deletions(-)
diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index d3005279165d..80de338f1277 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -10196,6 +10196,8 @@ void __init early_trace_init(void)
static_key_enable(&tracepoint_printk_key.key);
}
tracer_alloc_buffers();
+
+ init_events();
}
void __init trace_init(void)
diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h
index 900e75d96c84..11c4918ff202 100644
--- a/kernel/trace/trace.h
+++ b/kernel/trace/trace.h
@@ -1504,6 +1504,7 @@ extern void trace_event_enable_cmd_record(bool enable);
extern void trace_event_enable_tgid_record(bool enable);
extern int event_trace_init(void);
+extern int init_events(void);
extern int event_trace_add_tracer(struct dentry *parent, struct trace_array *tr);
extern int event_trace_del_tracer(struct trace_array *tr);
extern void __trace_early_add_events(struct trace_array *tr);
diff --git a/kernel/trace/trace_output.c b/kernel/trace/trace_output.c
index 67f47ea27921..5cd4fb656306 100644
--- a/kernel/trace/trace_output.c
+++ b/kernel/trace/trace_output.c
@@ -1568,7 +1568,7 @@ static struct trace_event *events[] __initdata = {
NULL
};
-__init static int init_events(void)
+__init int init_events(void)
{
struct trace_event *event;
int i, ret;
@@ -1581,4 +1581,3 @@ __init static int init_events(void)
return 0;
}
-early_initcall(init_events);
--
2.35.1
On Wed, Jan 04, 2023 at 04:14:12PM -0500, Steven Rostedt wrote:
> From: "Steven Rostedt (Google)" <[email protected]>
>
> Currently trace_printk() can be used as soon as early_trace_init() is
> called from start_kernel(). But if a crash happens, and
> "ftrace_dump_on_oops" is set on the kernel command line, all you get will
> be:
>
> [ 0.456075] <idle>-0 0dN.2. 347519us : Unknown type 6
> [ 0.456075] <idle>-0 0dN.2. 353141us : Unknown type 6
> [ 0.456075] <idle>-0 0dN.2. 358684us : Unknown type 6
>
> This is because the trace_printk() event (type 6) hasn't been registered
> yet. That gets done via an early_initcall(), which may be early, but not
> early enough.
>
> Instead of registering the trace_printk() event (and other ftrace events,
> which are not trace events) via an early_initcall(), have them registered at
> the same time that trace_printk() can be used. This way, if there is a
> crash before early_initcall(), then the trace_printk()s will actually be
> useful.
>
> Cc: [email protected]
> Reported-by: "Joel Fernandes (Google)" <[email protected]>
> Fixes: e725c731e3bb1 ("tracing: Split tracing initialization into two for early initialization")
> Signed-off-by: Steven Rostedt (Google) <[email protected]>
Tested-by: Joel Fernandes (Google) <[email protected]>
thanks,
- Joel
> ---
> kernel/trace/trace.c | 2 ++
> kernel/trace/trace.h | 1 +
> kernel/trace/trace_output.c | 3 +--
> 3 files changed, 4 insertions(+), 2 deletions(-)
>
> diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
> index d3005279165d..80de338f1277 100644
> --- a/kernel/trace/trace.c
> +++ b/kernel/trace/trace.c
> @@ -10196,6 +10196,8 @@ void __init early_trace_init(void)
> static_key_enable(&tracepoint_printk_key.key);
> }
> tracer_alloc_buffers();
> +
> + init_events();
> }
>
> void __init trace_init(void)
> diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h
> index 900e75d96c84..11c4918ff202 100644
> --- a/kernel/trace/trace.h
> +++ b/kernel/trace/trace.h
> @@ -1504,6 +1504,7 @@ extern void trace_event_enable_cmd_record(bool enable);
> extern void trace_event_enable_tgid_record(bool enable);
>
> extern int event_trace_init(void);
> +extern int init_events(void);
> extern int event_trace_add_tracer(struct dentry *parent, struct trace_array *tr);
> extern int event_trace_del_tracer(struct trace_array *tr);
> extern void __trace_early_add_events(struct trace_array *tr);
> diff --git a/kernel/trace/trace_output.c b/kernel/trace/trace_output.c
> index 67f47ea27921..5cd4fb656306 100644
> --- a/kernel/trace/trace_output.c
> +++ b/kernel/trace/trace_output.c
> @@ -1568,7 +1568,7 @@ static struct trace_event *events[] __initdata = {
> NULL
> };
>
> -__init static int init_events(void)
> +__init int init_events(void)
> {
> struct trace_event *event;
> int i, ret;
> @@ -1581,4 +1581,3 @@ __init static int init_events(void)
>
> return 0;
> }
> -early_initcall(init_events);
> --
> 2.35.1
>