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
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [<thread-prev] [day] [month] [year] [list]
Message-ID: <20191218194735.nfgkps35r25emy33@frank-laptop>
Date:   Wed, 18 Dec 2019 14:47:35 -0500
From:   "Frank A. Cancio Bello" <frank@...eralsoftwareinc.com>
To:     Steven Rostedt <rostedt@...dmis.org>
Cc:     Ingo Molnar <mingo@...hat.com>, Jonathan Corbet <corbet@....net>,
        linux-doc@...r.kernel.org, linux-kernel@...r.kernel.org,
        joel@...lfernandes.org, nachukannan@...il.com,
        saiprakash.ranjan@...look.com
Subject: Re: [PATCH] docs: ftrace: Specifies when buffers get clear

On Mon, Dec 16, 2019 at 09:52:51AM -0500, Steven Rostedt wrote:
> On Sun, 15 Dec 2019 23:27:56 -0500
> "Frank A. Cancio Bello" <frank@...eralsoftwareinc.com> wrote:
> 
> > Clarify in a few places where the ring buffer and the "snapshot"
> > buffer are cleared as a side effect of an operation.
> > 
> > This will avoid users lost of tracing data because of these so far
> > undocumented behavior.
> > 
> > Signed-off-by: Frank A. Cancio Bello <frank@...eralsoftwareinc.com>
> > ---
> >  Documentation/trace/ftrace.rst | 10 ++++++++--
> >  1 file changed, 8 insertions(+), 2 deletions(-)
> > 
> > diff --git a/Documentation/trace/ftrace.rst b/Documentation/trace/ftrace.rst
> > index d2b5657ed33e..5cc65314e16d 100644
> > --- a/Documentation/trace/ftrace.rst
> > +++ b/Documentation/trace/ftrace.rst
> > @@ -95,7 +95,8 @@ of ftrace. Here is a list of some of the key files:
> >    current_tracer:
> >  
> >  	This is used to set or display the current tracer
> > -	that is configured.
> > +	that is configured. Changing the current tracer clears
> > +        the ring buffer content as well as the "snapshot" buffer.
> >  
> >    available_tracers:
> >  
> > @@ -126,7 +127,9 @@ of ftrace. Here is a list of some of the key files:
> >  	This file holds the output of the trace in a human
> >  	readable format (described below). Note, tracing is temporarily
> >  	disabled when the file is open for reading. Once all readers
> > -	are closed, tracing is re-enabled.
> > +	are closed, tracing is re-enabled. Opening this file for
> > +        writing with the O_TRUNC flag clears the ring buffer content
> > +        as well as the "snapshot" buffer.
> 
> Writing O_TRUNC into trace does not touch the snapshot buffer. I just
> tested to make sure (because that's not the behavior I remember making):
>

You are right. I should test it before email you. Sorry about that.
I miss read tracing_reset_all_online_cpus() when in reality it was
tracing_reset_online_cpus(), this kind of things happens to me when I
read kernel source code more than 12 hours per day to try to catchup ;)

vim-linux-coding-style does not include .rst files, so this patch has
the spacing wrong too, I fixed it in the v2 that I sent you too.

>  # cd /sys/kernel/tracing
>  # echo 1 > events/sched/enable
>  # echo 1 > snapshot
>  # head -15 snapshot  
> # tracer: nop
> #
> # entries-in-buffer/entries-written: 3563/3563   #P:8
> #
> #                              _-----=> irqs-off
> #                             / _----=> need-resched
> #                            | / _---=> hardirq/softirq
> #                            || / _--=> preempt-depth
> #                            ||| /     delay
> #           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
> #              | |       |   ||||       |         |
>             bash-20130 [007] d.h. 243924.135391: sched_stat_runtime: comm=bash pid=20130 runtime=584815 [ns] vruntime=116509213 [ns]
>             bash-20130 [007] d... 243924.135853: sched_waking: comm=kworker/u16:2 pid=20112 prio=120 target_cpu=002
>             bash-20130 [007] d... 243924.135859: sched_wake_idle_without_ipi: cpu=2
>             bash-20130 [007] d... 243924.135861: sched_wakeup: comm=kworker/u16:2 pid=20112 prio=120 target_cpu=002
>  # echo 0 > tracing_on
>  # head -15 trace
> # tracer: nop
> #
> # entries-in-buffer/entries-written: 1697/1697   #P:8
> #
> #                              _-----=> irqs-off
> #                             / _----=> need-resched
> #                            | / _---=> hardirq/softirq
> #                            || / _--=> preempt-depth
> #                            ||| /     delay
> #           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
> #              | |       |   ||||       |         |
>             sshd-20125 [005] d... 244126.123095: sched_stat_runtime: comm=sshd pid=20125 runtime=101555 [ns] vruntime=153686839 [ns]
>             sshd-20125 [005] d... 244126.123100: sched_switch: prev_comm=sshd prev_pid=20125 prev_prio=120 prev_state=S ==> next_comm=swapper/5 next_pid=0 next_prio=120
>             bash-20130 [007] d... 244126.123173: sched_waking: comm=kworker/u16:3 pid=20190 prio=120 target_cpu=006
>             bash-20130 [007] d... 244126.123177: sched_wake_idle_without_ipi: cpu=6
>  # echo > trace
>  # head -15 trace
> # tracer: nop
> #
> # entries-in-buffer/entries-written: 0/0   #P:8
> #
> #                              _-----=> irqs-off
> #                             / _----=> need-resched
> #                            | / _---=> hardirq/softirq
> #                            || / _--=> preempt-depth
> #                            ||| /     delay
> #           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
> #              | |       |   ||||       |         |
>  # head -15 snapshot
>  # tracer: nop
> #
> # entries-in-buffer/entries-written: 3563/3563   #P:8
> #
> #                              _-----=> irqs-off
> #                             / _----=> need-resched
> #                            | / _---=> hardirq/softirq
> #                            || / _--=> preempt-depth
> #                            ||| /     delay
> #           TASK-PID   CPU#  ||||    TIMESTAMP  FUNCTION
> #              | |       |   ||||       |         |
>             bash-20130 [007] d.h. 243924.135391: sched_stat_runtime: comm=bash pid=20130 runtime=584815 [ns] vruntime=116509213 [ns]
>             bash-20130 [007] d... 243924.135853: sched_waking: comm=kworker/u16:2 pid=20112 prio=120 target_cpu=002
>             bash-20130 [007] d... 243924.135859: sched_wake_idle_without_ipi: cpu=2
>             bash-20130 [007] d... 243924.135861: sched_wakeup: comm=kworker/u16:2 pid=20112 prio=120 target_cpu=002
> 
> >  
> >    trace_pipe:
> >  
> > @@ -490,6 +493,9 @@ of ftrace. Here is a list of some of the key files:
> >  
> >  	  # echo global > trace_clock
> >  
> > +        Setting a clock clears the ring buffer content as well as the
> > +        "snapshot" buffer.
> > +
> 
> Yeah, this is true, because the sorting algorithm relies on the trace
> clocks matching in the buffers. If this becomes an issue, I'm sure we
> could change it.
> 

Besides, if the new clock is not in nanoseconds or "a clock at
all" (e.g. it is a counter) changing the clock it would produce an
inaccurate interpretation of the snapshot if we don't store the clock
that was used to fill the buffer that is in the snapshot. So, I think
that it is OK to reset the snapshot in this case. I just wanted to
document this behavior.

Thanks a lot for your quick response and sorry for my delay. I'm still
playing with email filters to properly accommodate the email flow of the
lists.

I want to congratulate you for such a nice piece of code you wrote:
ftrace. Being an Outreachy intern (mentors and co-interns CCed in this
email) and be able to learn so much from your code is a great
opportunity!

thanks
frank a.


> -- Steve
> 
> >    trace_marker:
> >  
> >  	This is a very useful file for synchronizing user space
> 

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ