From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1754165AbdCHTzi (ORCPT ); Wed, 8 Mar 2017 14:55:38 -0500 Received: from mga11.intel.com ([192.55.52.93]:57315 "EHLO mga11.intel.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1751720AbdCHTze (ORCPT ); Wed, 8 Mar 2017 14:55:34 -0500 X-ExtLoop1: 1 X-IronPort-AV: E=Sophos;i="5.36,265,1486454400"; d="scan'208";a="65562664" Message-ID: <1489000557.7212.58.camel@linux.intel.com> Subject: Re: [RFC][PATCH 0/4] tracing: Allow function tracing to start earlier in boot up From: Todd Brandt Reply-To: todd.e.brandt@linux.intel.com To: Steven Rostedt Cc: linux-kernel@vger.kernel.org, Ingo Molnar , Andrew Morton Date: Wed, 08 Mar 2017 11:15:57 -0800 In-Reply-To: <20170307212833.964734229@goodmis.org> References: <20170307212833.964734229@goodmis.org> Content-Type: text/plain; charset="UTF-8" X-Mailer: Evolution 3.12.11-0ubuntu3 Mime-Version: 1.0 Content-Transfer-Encoding: 7bit Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org 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 > > 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(-)