From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from mail-fx0-f11.google.com (mail-fx0-f11.google.com [209.85.220.11]) by ozlabs.org (Postfix) with ESMTP id 7EE72DDDE4 for ; Thu, 12 Feb 2009 13:02:02 +1100 (EST) Received: by fxm4 with SMTP id 4so1995292fxm.9 for ; Wed, 11 Feb 2009 18:02:00 -0800 (PST) Date: Thu, 12 Feb 2009 02:55:04 +0100 From: Frederic Weisbecker To: Steven Rostedt Subject: Re: [PATCH 0/7][RFC] function graph tracer port to PowerPC Message-ID: <20090212015503.GA4697@nowhere> References: <20090212011051.265346435@goodmis.org> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii In-Reply-To: <20090212011051.265346435@goodmis.org> Cc: linux-kernel@vger.kernel.org, linuxppc-dev@ozlabs.org, Paul Mackerras , Ingo Molnar , Andrew Morton List-Id: Linux on PowerPC Developers Mail List List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , On Wed, Feb 11, 2009 at 08:10:51PM -0500, Steven Rostedt wrote: > > The following set of patches are RFC and not for inclusion > (unless everyone is fine with them as is). > > This is the port to PowerPC of the function graph tracer that was written > by Frederic Weisbecker for the x86 architecture. It is broken up > into a series of logical steps. > > 1) get generic code ready for other archs > 2) get PowerPC 64-bit working with just static function tracing > 3) get PowerPC 64-bit working with dynamic function tracing > 4) get PowerPC 32-bit working with just static function tracing > 5) get PowerPC 32-bit working with dynamic function tracing > > (with some clean ups in between) > Thanks a lot Steven! I'm sad to not having a Power Pc to test it... > The function graph tracer not only traces the start of a function > (uses the function tracer part for that) but also uses the kprobes > trick to replace the return address with a hook to trace the exit > of the function. These hooks are generic in that other tracers > can also use them. But the function graph tracer itself is very > powerful. Simply doing the following: > > # echo function_graph > /debug/tracing/current_tracer > # cat /debug/tracing/trace > > # tracer: function_graph > # > # CPU OVERHEAD/DURATION FUNCTION CALLS > # | | | | | | | > ------------------------------------------ > 0) less-2228 => cat-2229 > ------------------------------------------ > > 0) | .__do_fault() { > 0) | .filemap_fault() { > 0) | .find_lock_page() { > 0) | .find_get_page() { > 0) 3.168 us | .__rcu_read_lock(); > 0) 2.704 us | .__rcu_read_unlock(); > 0) + 14.640 us | } > 0) + 20.112 us | } > 0) + 26.464 us | } > 0) 2.912 us | ._spin_lock(); > 0) 2.656 us | .page_add_file_rmap(); > 0) | .update_mmu_cache() { > 0) | .hash_preload() { > 0) 2.368 us | .get_slice_psize(); > 0) 2.752 us | .hash_page_do_lazy_icache(); > 0) 3.568 us | .native_hpte_insert(); > 0) + 19.680 us | } > 0) + 24.960 us | } > 0) 2.336 us | ._spin_unlock(); > 0) | .unlock_page() { > 0) 2.688 us | .page_waitqueue(); > 0) 2.608 us | .__wake_up_bit(); > 0) + 12.912 us | } > 0) ! 351.776 us | } > 0) ! 357.392 us | } > 0) 3.040 us | .up_read(); > 0) | .compat_sys_ioctl() { > 0) 3.024 us | .fget_light(); > 0) | .tty_compat_ioctl() { > 0) 2.704 us | .tty_paranoia_check(); > 0) | .tty_ldisc_ref_wait() { > 0) | .tty_ldisc_try() { > 0) 2.880 us | ._spin_lock_irqsave(); > 0) 2.928 us | ._spin_unlock_irqrestore(); > 0) + 13.776 us | } > 0) + 19.424 us | } > > [...] > > As you can see, it gives a nice call trace of the functions being called > at run time, as well as a time stamp of how much time the function > took to execute. > > Adding dynamic tracing to the mix, we can trace a single function: > > # echo .do_fork > /debug/tracing/set_graph_function > # echo function_graph > /debug/tracing/current_tracer > # cat /debug/tracing/trace > > # tracer: function_graph > # > # CPU OVERHEAD/DURATION FUNCTION CALLS > # | | | | | | | > 1) | .do_fork() { > 1) | .copy_process() { > 1) | .prepare_to_copy() { > 1) 2.944 us | .flush_fp_to_thread(); > 1) 2.800 us | .flush_altivec_to_thread(); > 1) 2.608 us | .flush_vsx_to_thread(); > 1) + 19.184 us | } > 1) | .kmem_cache_alloc() { > 1) 2.464 us | .slab_should_failslab(); > 1) 8.304 us | } > 1) | .alloc_thread_info() { > 1) | .kmem_cache_alloc() { > 1) 2.512 us | .slab_should_failslab(); > 1) 8.224 us | } > 1) + 13.344 us | } > 1) 7.584 us | .arch_dup_task_struct(); > 1) | .copy_creds() { > 1) 2.736 us | .__mutex_init(); > 1) | .prepare_creds() { > 1) | .kmem_cache_alloc() { > 1) 2.640 us | .slab_should_failslab(); > 1) 8.368 us | } > > [...] > > > Note, the '.' in the '.do_fork' is a PowerPC64 thing. PowerPC32 and > other archs just need to do 'do_fork', without the dot. > > > The following patches are in: > > git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-2.6-trace.git > > branch: rfc/ppc/ftrace > > > Steven Rostedt (7): > tracing/function-graph-tracer: make arch generic push pop functions > powerpc64: port of the function graph tracer > powerpc64, tracing: add function graph tracer with dynamic tracing > powerpc64, ftrace: save toc only on modules for function graph > powerpc32, ftrace: save and restore mcount regs with macro > powerpc32, ftrace: port function graph tracer to ppc32, static only > powerpc32, ftrace: dynamic function graph tracer > > ---- > arch/powerpc/Kconfig | 1 + > arch/powerpc/include/asm/ftrace.h | 39 ++++++++++- > arch/powerpc/kernel/Makefile | 9 +- > arch/powerpc/kernel/entry_32.S | 115 ++++++++++++++--------------- > arch/powerpc/kernel/entry_64.S | 89 +++++++++++++++++++++- > arch/powerpc/kernel/ftrace.c | 135 ++++++++++++++++++++++++++++++++-- > arch/powerpc/kernel/process.c | 16 ++++ > arch/powerpc/kernel/vmlinux.lds.S | 1 + > arch/x86/include/asm/ftrace.h | 25 ------ > arch/x86/kernel/ftrace.c | 75 +------------------ > include/linux/ftrace.h | 24 ++++++ > kernel/trace/trace_functions_graph.c | 75 +++++++++++++++++++ > 12 files changed, 428 insertions(+), 176 deletions(-) > --