On Wed, 2017-03-08 at 11:15 -0800, Todd Brandt wrote:
> On Tue, 2017-03-07 at 16:28 -0500, Steven Rostedt wrote:
> > I've had people ask about moving tracing up further in the boot process.
> > This patch series looks at function tracing only. It allows for tracing
> > (and function filtering) to be moved right after memory is initialized.
> > To have it happen before memory initialization would require a bit more
> > work with allocating the ring buffer. But this is a start.
>
> I just tested out the patch and it does move function trace up to about
> 100ms from boot which is nice. What I'd really like is for graph trace
> to start sooner as well.
>
> P.S. I've noticed that the dmesg log and ftrace log times don't seem to
> match up anymore since the v10.0 release. Is the default still the local
> clock? On v10.0-rc8 I was able to match initcall_debug output with
> do_one_initcall function_graph trace perfectly. But the latest is off by
> anywhere from several microseconds to several milliseconds. Did I just
> get lucky with v10.0-rc8 or should these still align?
>
> v10.0-rc8 (ftrace time = dmesg time)
>
> FTRACE:
> 0.519902 | 0) systemd-1 | | do_one_initcall() {
> 0.519921 | 0) systemd-1 | | do_one_initcall() {
> 0.519929 | 0) systemd-1 | | do_one_initcall() {
> 0.519938 | 0) systemd-1 | | do_one_initcall() {
> 0.519946 | 0) systemd-1 | | do_one_initcall() {
> DMESG:
> [ 0.519909] calling init_per_zone_wmark_min+0x0/0x73 @ 1
> [ 0.519925] calling init_zero_pfn+0x0/0x3d @ 1
> [ 0.519932] calling memory_failure_init+0x0/0xa4 @ 1
> [ 0.519941] calling cma_init_reserved_areas+0x0/0x1cd @ 1
> [ 0.519949] calling fsnotify_init+0x0/0x26 @ 1
>
> v4.11-rc1 (ftrace = dmesg + 5.089 ms)
>
> FTRACE:
> 0.445317 | 2) systemd-1 | | do_one_initcall() {
> 0.445338 | 2) systemd-1 | | do_one_initcall() {
> 0.445346 | 2) systemd-1 | | do_one_initcall() {
> 0.445355 | 2) systemd-1 | | do_one_initcall() {
> 0.445363 | 2) systemd-1 | | do_one_initcall() {
> DMESG:
> [ 0.440232] calling init_per_zone_wmark_min+0x0/0x73 @ 1
> [ 0.440249] calling init_zero_pfn+0x0/0x3d @ 1
> [ 0.440257] calling memory_failure_init+0x0/0xa4 @ 1
> [ 0.440266] calling cma_init_reserved_areas+0x0/0x1cd @ 1
> [ 0.440275] calling fsnotify_init+0x0/0x26 @ 1
Oops, no sooner than 5 minutes after I sent this did I figure out
there's a trace_clock kernel parameter (not in kernel-parameters.txt).
Once I set it to global all is well. Never mind :)
>
>
> >
> > I placed a hook into free_reserved_area() which is used by all archs
> > to free the init memory. Having it pass the range being freed to ftrace
> > lets ftrace clean up any function that is registered such that it doesn't
> > try to modify code that no longer exists.
> >
> >
> > Steven Rostedt (VMware) (4):
> > tracing: Split tracing initialization into two for early
> > initialization
> > ftrace: Move ftrace_init() to right after memory initialization
> > ftrace: Have function tracing start in early boot up
> > ftrace: Allow for function tracing to record init functions on boot up
> >
> > ----
> > include/linux/ftrace.h | 5 +++++
> > include/linux/init.h | 4 +++-
> > init/main.c | 9 ++++++---
> > kernel/trace/ftrace.c | 44
> > ++++++++++++++++++++++++++++++++++++++++++
> > kernel/trace/trace.c | 9 ++++++++-
> > kernel/trace/trace.h | 2 ++
> > kernel/trace/trace_functions.c | 3 +--
> > mm/page_alloc.c | 4 ++++
> > scripts/recordmcount.c | 1 +
> > scripts/recordmcount.pl | 1 +
> > 10 files changed, 75 insertions(+), 7 deletions(-)
>
