| lists.openwall.net | lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC | |
|
Open Source and information security mailing list archives
| ||
|
Message-ID: <20090122090221.GA5891@nowhere>
Date: Thu, 22 Jan 2009 10:02:22 +0100
From: Frederic Weisbecker <fweisbec@...il.com>
To: Steven Rostedt <rostedt@...dmis.org>
Cc: Ingo Molnar <mingo@...e.hu>,
Linux Kernel Mailing List <linux-kernel@...r.kernel.org>
Subject: Re: [PATCH 1/2] tracing/function-graph-tracer: various fixes and
features
On Wed, Jan 21, 2009 at 08:43:24PM -0500, Steven Rostedt wrote:
>
> On Wed, 21 Jan 2009, Frederic Weisbecker wrote:
>
> > I thought I would have the time to implement the callbacks in trace_event too but I
> > really have to sleep :-(
> > That will be for later.
>
> No need to rush. Get to sleep.
>
> > --
> >
> > This patch brings various bugfixes:
> >
> > _ Drop the first irrelevant task switch on the very beginning of a trace.
> > But actually that only solves the first time one does print the trace file.
> > I have to fix the others cases too.
>
> I'm not sure what you mean by the first time here. Can you explain it
> a bit better.
On the very first time one cat the trace file, the per cpu pid array is init to -1.
So the comparison between the current pid and the previous one (-1) is always false
and then a task switch is printed.
This one is fixed.
The other cases are when one cat the trace file after closing it.
The pid array is not anymore filled with -1 values but with old traced pid, and then
a task switch is printed here too.
I will have to hook on open and reset the pid table to -1 to fix that.
> > _ Drop the OVERHEAD word from the headers, the DURATION word is sufficient and will not
> > overlap other columns.
> > _ Make the headers fit well their respective columns whatever the selected options.
> >
> > Ie, default options:
> >
> > # tracer: function_graph
> > #
> > # CPU DURATION FUNCTION CALLS
> > # | | | | | | |
> >
> > 1) 0.646 us | }
> > 1) | mem_cgroup_del_lru_list() {
> > 1) 0.624 us | lookup_page_cgroup();
> > 1) 1.970 us | }
> >
> > echo funcgraph-proc > trace_options
> >
> > # tracer: function_graph
> > #
> > # CPU TASK/PID DURATION FUNCTION CALLS
> > # | | | | | | | | |
> >
> > 0) bash-2937 | 0.895 us | }
> > 0) bash-2937 | 0.888 us | __rcu_read_unlock();
> > 0) bash-2937 | 0.864 us | conv_uni_to_pc();
> > 0) bash-2937 | 1.015 us | __rcu_read_lock();
> >
> > echo nofuncgraph-cpu > trace_options
> > echo nofuncgraph-proc > trace_options
> >
> > # tracer: function_graph
> > #
> > # DURATION FUNCTION CALLS
> > # | | | | | |
> >
> > 3.752 us | native_pud_val();
> > 0.616 us | native_pud_val();
> > 0.624 us | native_pmd_val();
> >
> >
> > About features, one can now disable the duration (this will hide the overhead too
> > for convenient reasons and because on doesn't need overhead if it hasn't the duration
> >
> > echo nofuncgraph-duration > trace_options
> >
> > # tracer: function_graph
> > #
> > # FUNCTION CALLS
> > # | | | |
> >
> > cap_vm_enough_memory() {
> > __vm_enough_memory() {
> > vm_acct_memory();
> > }
> > }
> > }
> >
> > And at last, an option to print the absolute time:
> >
> > //Restart from default options
> > echo funcgraph-abstime > trace_options
> >
> > # tracer: function_graph
> > #
> > # TIME CPU DURATION FUNCTION CALLS
> > # | | | | | | | |
> >
> > 261.339774 | 1) + 42.823 us | }
> > 261.339775 | 1) 1.045 us | _spin_lock_irq();
> > 261.339777 | 1) 0.940 us | _spin_lock_irqsave();
> > 261.339778 | 1) 0.752 us | _spin_unlock_irqrestore();
> > 261.339780 | 1) 0.857 us | _spin_unlock_irq();
> > 261.339782 | 1) | flush_to_ldisc() {
> > 261.339783 | 1) | tty_ldisc_ref() {
> > 261.339783 | 1) | tty_ldisc_try() {
> > 261.339784 | 1) 1.075 us | _spin_lock_irqsave();
> > 261.339786 | 1) 0.842 us | _spin_unlock_irqrestore();
> > 261.339788 | 1) 4.211 us | }
> > 261.339788 | 1) 5.662 us | }
> >
> > The format is seconds.usecs
> > I guess no one needs the nanosec precision here, the main goal is to find when happened
> > the events on a cpu when the trace switches from one cpu to another.
> >
> > ie:
> >
> > 274.874760 | 1) 0.676 us | _spin_unlock();
> > 274.874762 | 1) 0.609 us | native_load_sp0();
> > 274.874763 | 1) 0.602 us | native_load_tls();
> > 274.878739 | 0) 0.722 us | }
> > 274.878740 | 0) 0.714 us | native_pmd_val();
> > 274.878741 | 0) 0.730 us | native_pmd_val();
> >
> > Here there is a 4000 usecs difference when we switch the cpu.
>
> These examples will most likely be cut from the change log. Updating
> ftrace.txt would be nice ;-)
Yes, definetly. I didn't drop my hands into this yet because of my
messy english :-)
But I know some people who could review it :-)
> >
> > Signed-off-by: Frederic Weisbecker <fweisbec@...il.com>
> > ---
> > kernel/trace/trace_functions_graph.c | 245 +++++++++++++++++++++-------------
> > 1 files changed, 151 insertions(+), 94 deletions(-)
> >
>
> -- Steve
>
Thanks.
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@...r.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Powered by blists - more mailing lists