* [PATCH] docs: ftrace: Specifies when buffers get clear
@ 2019-12-16 4:27 Frank A. Cancio Bello
2019-12-16 14:52 ` Steven Rostedt
0 siblings, 1 reply; 3+ messages in thread
From: Frank A. Cancio Bello @ 2019-12-16 4:27 UTC (permalink / raw)
To: Steven Rostedt, Ingo Molnar, Jonathan Corbet, linux-doc, linux-kernel
Cc: joel, nachukannan, saiprakash.ranjan
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@generalsoftwareinc.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.
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.
+
trace_marker:
This is a very useful file for synchronizing user space
--
2.17.1
^ permalink raw reply related [flat|nested] 3+ messages in thread
* Re: [PATCH] docs: ftrace: Specifies when buffers get clear
2019-12-16 4:27 [PATCH] docs: ftrace: Specifies when buffers get clear Frank A. Cancio Bello
@ 2019-12-16 14:52 ` Steven Rostedt
2019-12-18 19:47 ` Frank A. Cancio Bello
0 siblings, 1 reply; 3+ messages in thread
From: Steven Rostedt @ 2019-12-16 14:52 UTC (permalink / raw)
To: Frank A. Cancio Bello
Cc: Ingo Molnar, Jonathan Corbet, linux-doc, linux-kernel, joel,
nachukannan, saiprakash.ranjan
On Sun, 15 Dec 2019 23:27:56 -0500
"Frank A. Cancio Bello" <frank@generalsoftwareinc.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@generalsoftwareinc.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):
# 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.
-- Steve
> trace_marker:
>
> This is a very useful file for synchronizing user space
^ permalink raw reply [flat|nested] 3+ messages in thread* Re: [PATCH] docs: ftrace: Specifies when buffers get clear
2019-12-16 14:52 ` Steven Rostedt
@ 2019-12-18 19:47 ` Frank A. Cancio Bello
0 siblings, 0 replies; 3+ messages in thread
From: Frank A. Cancio Bello @ 2019-12-18 19:47 UTC (permalink / raw)
To: Steven Rostedt
Cc: Ingo Molnar, Jonathan Corbet, linux-doc, linux-kernel, joel,
nachukannan, saiprakash.ranjan
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@generalsoftwareinc.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@generalsoftwareinc.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
>
^ permalink raw reply [flat|nested] 3+ messages in thread
end of thread, other threads:[~2019-12-18 19:47 UTC | newest]
Thread overview: 3+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2019-12-16 4:27 [PATCH] docs: ftrace: Specifies when buffers get clear Frank A. Cancio Bello
2019-12-16 14:52 ` Steven Rostedt
2019-12-18 19:47 ` Frank A. Cancio Bello
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).