Skip to contentSkip to conversation

Tracing/fastboot: Only trace non-module initcalls

PATCH In review Frederic Weisbecker 4 participants 7 messages Oct 3, 2008 – Oct 4, 2008

Subsystems (2)
lore
Share & tools
lore
#0 lore raw

PATCH 1/1 Tracing/fastboot: Only trace non-module initcalls

At this time, only built-in initcalls interest us. We can't really produce a relevant graph if we include the modules initcall too.

I had good results after this patch (see svg in attachment).

---
 include/linux/ftrace.h    |    2 ++
 init/main.c               |    1 +
 kernel/trace/trace_boot.c |   11 ++++++++---
 3 files changed, 11 insertions(+), 3 deletions(-)
include/linux/ftrace.h +2 -0
index ed53265..5812dba 100644
@@ -225,9 +225,11 @@ struct boot_trace {
 #ifdef CONFIG_BOOT_TRACER
 extern void trace_boot(struct boot_trace *it, initcall_t fn);
 extern void start_boot_trace(void);
+extern void stop_boot_trace(void);
 #else
 static inline void trace_boot(struct boot_trace *it, initcall_t fn) { }
 static inline void start_boot_trace(void) { }
+static inline void stop_boot_trace(void) { }
 #endif
 
 
init/main.c +1 -0
index 47d621a..2e5c37e 100644
@@ -976,6 +976,7 @@ static int __init kernel_init(void * unused)
 	 * we're essentially up and running. Get rid of the
 	 * initmem segments and start the user-mode stuff..
 	 */
+	stop_boot_trace();
 	init_post();
 	return 0;
 }
kernel/trace/trace_boot.c +8 -3
index b9dc2c0..a7efe35 100644
@@ -22,11 +22,16 @@ void start_boot_trace(void)
 	trace_boot_enabled = 1;
 }
 
-void stop_boot_trace(struct trace_array *tr)
+void stop_boot_trace(void)
 {
 	trace_boot_enabled = 0;
 }
 
+void reset_boot_trace(struct trace_array *tr)
+{
+	stop_boot_trace();
+}
+
 static void boot_trace_init(struct trace_array *tr)
 {
 	int cpu;
@@ -43,7 +48,7 @@ static void boot_trace_ctrl_update(struct trace_array *tr)
 	if (tr->ctrl)
 		start_boot_trace();
 	else
-		stop_boot_trace(tr);
+		stop_boot_trace();
 }
 
 static enum print_line_t initcall_print_line(struct trace_iterator *iter)
@@ -81,7 +86,7 @@ struct tracer boot_tracer __read_mostly =
 {
 	.name		= "initcall",
 	.init		= boot_trace_init,
-	.reset		= stop_boot_trace,
+	.reset		= reset_boot_trace,
 	.ctrl_update	= boot_trace_ctrl_update,
 	.print_line	= initcall_print_line,
 };
#1 lore raw
Quoted 4 lines · Frederic Weisbecker

At this time, only built-in initcalls interest us. We can't really produce a relevant graph if we include the modules initcall too.

Quoted 8 lines

I had good results after this patch (see svg in attachment).

---
 include/linux/ftrace.h    |    2 ++
 init/main.c               |    1 +
 kernel/trace/trace_boot.c |   11 ++++++++---
 3 files changed, 11 insertions(+), 3 deletions(-)

applied to tip/tracing/fastboot, thanks,

Ingo

#2 lore raw
In reply to Frederic Weisbecker
Quoted 5 lines · Frederic Weisbecker

At this time, only built-in initcalls interest us. We can't really produce a relevant graph if we include the modules initcall too.

I had good results after this patch (see svg in attachment).

Sorry to butt in. I think tracing module initcalls was a deliberate addition by Arjan (a06e1c2b448b317bc141934879cbbbed8319b4d4).

Maybe you use an initrd and that affects the trace? It would be nice to see the "before" svg as well as the "after", to explain the change.

Thanks
Alan

#3 lore raw

2008/10/3 Alan Jenkins <[email protected]>:

Quoted 6 lines

Sorry to butt in. I think tracing module initcalls was a deliberate addition by Arjan (a06e1c2b448b317bc141934879cbbbed8319b4d4).

Maybe you use an initrd and that affects the trace? It would be nice to see the "before" svg as well as the "after", to explain the change.

Thanks
Alan

Hi Alan,

The script bootgraph.pl in -tip stops the analyzing when it sees "Freeing unused kernel memory". That's
exactly when the built-in initcalls are finished.
And as a result, the graph produced with dmesg always finishes at this point.

If you try to generate a graph whithout this limitation, you will not be able to see something interesting because
the script will not find a lot of initcalls with a long enough time proportion against the total boot time.
Perhaps it can be improved in that way but unfortunately I don't know any word in Perl....

#4 lore raw
Quoted 2 lines

2008/10/3 Alan Jenkins <[email protected]>:
It would be nice to see the "before" svg as well as the "after", to explain the change.

(Sorry, didn't see that line...)

I have to go, but when I will have more time, I will show you the difference....

#5 lore raw
In reply to Frédéric Weisbecker
Quoted 18 lines · Frédéric Weisbecker

2008/10/3 Alan Jenkins <[email protected]>:

Quoted 7 lines

Sorry to butt in. I think tracing module initcalls was a deliberate addition by Arjan (a06e1c2b448b317bc141934879cbbbed8319b4d4).

Maybe you use an initrd and that affects the trace? It would be nice to see the "before" svg as well as the "after", to explain the change.

Thanks
Alan

Hi Alan,

The script bootgraph.pl in -tip stops the analyzing when it sees "Freeing unused kernel memory". That's
exactly when the built-in initcalls are finished.
And as a result, the graph produced with dmesg always finishes at this point.

Quoted 7 lines

If you try to generate a graph whithout this limitation, you will not be able to see something interesting because
the script will not find a lot of initcalls with a long enough time proportion against the total boot time.
Perhaps it can be improved in that way but unfortunately I don't know any word in Perl....

If you want to disable non-module initcalls, then what do you have left that you want to trace after "Freeing unused kernel memory"?

On my desktop dmesg I can see that the initramfs is loaded and started some time before the initcalls finish. The initramfs includes udev which loads many modules; I see network, usb, sata being initialised before the "Freeing unused kernel memory" message. Um... your changes will _not_ stop the initcalls from these modules being shown.

So I think your patch description is a bit inaccurate, and I don't understand what you are trying to achieve.

Thanks
Alan

#6 lore raw

2008/10/3 Alan Jenkins <[email protected]>:

Quoted 11 lines

If you want to disable non-module initcalls, then what do you have left that you want to trace after "Freeing unused kernel memory"?

On my desktop dmesg I can see that the initramfs is loaded and started some time before the initcalls finish. The initramfs includes udev which loads many modules; I see network, usb, sata being initialised before the "Freeing unused kernel memory" message. Um... your changes will _not_ stop the initcalls from these modules being shown.

So I think your patch description is a bit inaccurate, and I don't understand what you are trying to achieve.

Hmm I'm beginning to understand what you say. Actually I didn't think about initramfs that could launch
modules initcalls early.
It seems that modules initcalls are launched with the builtin initcalls when one use initramfs.
Since I'm not using it, I see only the builtin initcalls before the message of memory freeing.

I missed that point. And actually I misunderstood the real problem. My issues with the graph happened
because of a bug in the bootgraph.pl script.
I have a patch ready that corrects it. I'm going to post it and explain the real problem.

Thanks Alan!