Re: aarch64 boot time increases with rt

[Steven Rostedt <rostedt@goodmis.org>]

On Tue, 14 Jul 2020 15:18:01 +0300
Itai Handler <itai.handler@gmail.com> wrote:

> Hi Steven,
> 
> On Tue, Jul 14, 2020 at 4:20 AM Steven Rostedt <rostedt@goodmis.org> wrote:
> 
> > You mean compared to non PREEMPT_RT_FULL of the same kernel?  
> 
> Yes.
> 
> > I'd suggest trying 5.4 or even 5.6-rt.  
> 
> I tried 5.4.47-rt28, and the problem still persists.
> 
> > Well, you could try: ftrace=function_graph ftrace_graph_filter workqueue_prepare_cpu
> >
> > If workqueue_prepare_cpu is a traceable function (not inlined nor notrace set).  
> 
> I tried "ftrace=function_graph ftrace_graph_filter=workqueue_prepare_cpu",
> however, the trace appears to be empty.
> The function workqueue_prepare_cpu is not defined inline nor notrace.
> 
> Please see log below:
> # mount -t debugfs none /sys/kernel/debug
> # cd /sys/kernel/debug/tracing/
> # cat trace
> # tracer: function_graph
> #
> # CPU  DURATION                  FUNCTION CALLS
> # |     |   |                     |   |   |   |
> # cat set_graph_function
> workqueue_prepare_cpu
> # cat tracing_on
> 1
> 
> Do you have any idea why it's empty?

To rule out that this may be an issue with the function_graph tracer,
can you also try it with:

 ftrace=function ftrace_filter=worqueue_prepare_cpu

And see if the function tracer shows anything.

/me just looked at the code.

Yes, the function tracer is set up to trace really early, but the
function_graph tracer is initialized by core_initcall(), which is much
later.

Perhaps try this patch (note, it's from latest mainline):

And retry the function_graph tracer.

-- Steve


diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index 4aab712f9567..35bcac3edcee 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -9475,6 +9475,7 @@ __init static int tracer_alloc_buffers(void)
 
 	/* Function tracing may start here (via kernel command line) */
 	init_function_trace();
+	init_graph_trace();
 
 	/* All seems OK, enable tracing */
 	tracing_disabled = 0;
diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h
index f21607f87189..d861bd34dfb6 100644
--- a/kernel/trace/trace.h
+++ b/kernel/trace/trace.h
@@ -1129,6 +1129,11 @@ void ftrace_init_tracefs_toplevel(struct trace_array *tr,
 void ftrace_clear_pids(struct trace_array *tr);
 int init_function_trace(void);
 void ftrace_pid_follow_fork(struct trace_array *tr, bool enable);
+# ifdef CONFIG_FUNCTION_GRAPH_TRACER
+int init_graph_trace(void);
+# else
+static inline int init_graph_trace(void) { return 0; }
+# endif
 #else
 static inline int ftrace_trace_task(struct trace_array *tr)
 {
@@ -1149,6 +1154,7 @@ static inline void ftrace_init_tracefs(struct trace_array *tr, struct dentry *d)
 static inline void ftrace_init_tracefs_toplevel(struct trace_array *tr, struct dentry *d) { }
 static inline void ftrace_clear_pids(struct trace_array *tr) { }
 static inline int init_function_trace(void) { return 0; }
+static inline int init_graph_trace(void) { return 0; }
 static inline void ftrace_pid_follow_fork(struct trace_array *tr, bool enable) { }
 /* ftace_func_t type is not defined, use macro instead of static inline */
 #define ftrace_init_array_ops(tr, func) do { } while (0)
diff --git a/kernel/trace/trace_functions_graph.c b/kernel/trace/trace_functions_graph.c
index 4a9c49c08ec9..e18cc90585fb 100644
--- a/kernel/trace/trace_functions_graph.c
+++ b/kernel/trace/trace_functions_graph.c
@@ -1349,7 +1349,7 @@ static __init int init_graph_tracefs(void)
 }
 fs_initcall(init_graph_tracefs);
 
-static __init int init_graph_trace(void)
+__init int init_graph_trace(void)
 {
 	max_bytes_for_cpu = snprintf(NULL, 0, "%u", nr_cpu_ids - 1);
 
@@ -1365,5 +1365,3 @@ static __init int init_graph_trace(void)
 
 	return register_tracer(&graph_trace);
 }
-
-core_initcall(init_graph_trace);