On Wed, 19 Oct 2022 00:19:49 +0900
Masami Hiramatsu (Google) <[email protected]> wrote:
> > You need to make sure that the "pause-on-trace" option is set or tracing_on
> > is set to 0 (disabled). Otherwise, if the tracing is still active, then the
> > reading of the trace file could potentially never end.
>
> initialize_ftrace() does this setting. So it must be set.
> If you run the ftracetest on old kernel, this feature is not there and
> it may cause a trouble. Naveen, can you clarify it?
But for old kernels that do not have "pause-on-trace" it should be the
default. The "pause-on-trace" was added when the default was changed to not
pause the trace while reading it.
-- Steve
Steven Rostedt wrote:
> On Wed, 19 Oct 2022 00:19:49 +0900
> Masami Hiramatsu (Google) <[email protected]> wrote:
>
>> > You need to make sure that the "pause-on-trace" option is set or tracing_on
>> > is set to 0 (disabled). Otherwise, if the tracing is still active, then the
>> > reading of the trace file could potentially never end.
>>
>> initialize_ftrace() does this setting. So it must be set.
>> If you run the ftracetest on old kernel, this feature is not there and
>> it may cause a trouble. Naveen, can you clarify it?
Yes, the change to not pause on opening the trace file looks to be the
problem.
>
> But for old kernels that do not have "pause-on-trace" it should be the
> default. The "pause-on-trace" was added when the default was changed to not
> pause the trace while reading it.
It looks like the kernel patch was picked up, but Masami's patch for the
selftest wasn't backported. I have requested a test with that applied.
Separately, before I saw your response, I came up with the below patch
to update the selftests to disable tracing before reading the trace
file. I have also requested this to be tested.
- Naveen
---
.../selftests/ftrace/test.d/ftrace/fgraph-filter-stack.tc | 4 +++-
tools/testing/selftests/ftrace/test.d/ftrace/fgraph-filter.tc | 2 ++
.../selftests/ftrace/test.d/ftrace/func-filter-notrace-pid.tc | 3 ++-
.../testing/selftests/ftrace/test.d/ftrace/func-filter-pid.tc | 3 ++-
4 files changed, 9 insertions(+), 3 deletions(-)
diff --git a/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-filter-stack.tc b/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-filter-stack.tc
index cf3ea42b12b09f..7e74df1ef928f9 100644
--- a/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-filter-stack.tc
+++ b/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-filter-stack.tc
@@ -39,6 +39,7 @@ disable_tracing
clear_trace
enable_tracing
sleep 1
+disable_tracing
count=`cat trace | grep '()' | grep -v schedule | wc -l`
@@ -54,8 +55,9 @@ fi
echo 0 > /proc/sys/kernel/stack_tracer_enabled
clear_trace
+enable_tracing
sleep 1
-
+disable_tracing
count=`cat trace | grep '()' | grep -v schedule | wc -l`
diff --git a/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-filter.tc b/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-filter.tc
index b3ccdaec2a61ba..7e65a115054127 100644
--- a/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-filter.tc
+++ b/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-filter.tc
@@ -24,6 +24,8 @@ fi
echo function_graph > current_tracer
enable_tracing
sleep 1
+disable_tracing
+
# search for functions (has "()" on the line), and make sure
# that only the schedule function was found
count=`cat trace | grep '()' | grep -v schedule | wc -l`
diff --git a/tools/testing/selftests/ftrace/test.d/ftrace/func-filter-notrace-pid.tc b/tools/testing/selftests/ftrace/test.d/ftrace/func-filter-notrace-pid.tc
index 80541964b9270b..9fb0511b5d2eeb 100644
--- a/tools/testing/selftests/ftrace/test.d/ftrace/func-filter-notrace-pid.tc
+++ b/tools/testing/selftests/ftrace/test.d/ftrace/func-filter-notrace-pid.tc
@@ -51,6 +51,7 @@ do_test() {
enable_tracing
yield
+ disable_tracing
count_pid=`cat trace | grep -v ^# | grep $PID | wc -l`
count_other=`cat trace | grep -v ^# | grep -v $PID | wc -l`
@@ -60,7 +61,6 @@ do_test() {
fail "PID filtering not working? traced task = $count_pid; other tasks = $count_other "
fi
- disable_tracing
clear_trace
if [ $do_function_fork -eq 0 ]; then
@@ -77,6 +77,7 @@ do_test() {
enable_tracing
yield
+ disable_tracing
count_pid=`cat trace | grep -v ^# | grep $PID | wc -l`
count_other=`cat trace | grep -v ^# | grep -v $PID | wc -l`
diff --git a/tools/testing/selftests/ftrace/test.d/ftrace/func-filter-pid.tc b/tools/testing/selftests/ftrace/test.d/ftrace/func-filter-pid.tc
index 2f7211254529ba..c55bcf2fe1966f 100644
--- a/tools/testing/selftests/ftrace/test.d/ftrace/func-filter-pid.tc
+++ b/tools/testing/selftests/ftrace/test.d/ftrace/func-filter-pid.tc
@@ -51,6 +51,7 @@ do_test() {
enable_tracing
yield
+ disable_tracing
count_pid=`cat trace | grep -v ^# | grep $PID | wc -l`
count_other=`cat trace | grep -v ^# | grep -v $PID | wc -l`
@@ -60,7 +61,6 @@ do_test() {
fail "PID filtering not working?"
fi
- disable_tracing
clear_trace
if [ $do_function_fork -eq 0 ]; then
@@ -72,6 +72,7 @@ do_test() {
enable_tracing
yield
+ disable_tracing
count_pid=`cat trace | grep -v ^# | grep $PID | wc -l`
count_other=`cat trace | grep -v ^# | grep -v $PID | wc -l`
On Wed, 19 Oct 2022 15:15:09 +0530
"Naveen N. Rao" <[email protected]> wrote:
> Steven Rostedt wrote:
> > On Wed, 19 Oct 2022 00:19:49 +0900
> > Masami Hiramatsu (Google) <[email protected]> wrote:
> >
> >> > You need to make sure that the "pause-on-trace" option is set or tracing_on
> >> > is set to 0 (disabled). Otherwise, if the tracing is still active, then the
> >> > reading of the trace file could potentially never end.
> >>
> >> initialize_ftrace() does this setting. So it must be set.
> >> If you run the ftracetest on old kernel, this feature is not there and
> >> it may cause a trouble. Naveen, can you clarify it?
>
> Yes, the change to not pause on opening the trace file looks to be the
> problem.
>
> >
> > But for old kernels that do not have "pause-on-trace" it should be the
> > default. The "pause-on-trace" was added when the default was changed to not
> > pause the trace while reading it.
>
> It looks like the kernel patch was picked up, but Masami's patch for the
> selftest wasn't backported. I have requested a test with that applied.
Good! That should be backported too.
BTW, which kernel version do you test?
>
> Separately, before I saw your response, I came up with the below patch
> to update the selftests to disable tracing before reading the trace
> file. I have also requested this to be tested.
Yeah, OK. This also looks OK to me.
Thanks,
>
>
> - Naveen
>
> ---
> .../selftests/ftrace/test.d/ftrace/fgraph-filter-stack.tc | 4 +++-
> tools/testing/selftests/ftrace/test.d/ftrace/fgraph-filter.tc | 2 ++
> .../selftests/ftrace/test.d/ftrace/func-filter-notrace-pid.tc | 3 ++-
> .../testing/selftests/ftrace/test.d/ftrace/func-filter-pid.tc | 3 ++-
> 4 files changed, 9 insertions(+), 3 deletions(-)
>
> diff --git a/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-filter-stack.tc b/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-filter-stack.tc
> index cf3ea42b12b09f..7e74df1ef928f9 100644
> --- a/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-filter-stack.tc
> +++ b/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-filter-stack.tc
> @@ -39,6 +39,7 @@ disable_tracing
> clear_trace
> enable_tracing
> sleep 1
> +disable_tracing
>
> count=`cat trace | grep '()' | grep -v schedule | wc -l`
>
> @@ -54,8 +55,9 @@ fi
>
> echo 0 > /proc/sys/kernel/stack_tracer_enabled
> clear_trace
> +enable_tracing
> sleep 1
> -
> +disable_tracing
>
> count=`cat trace | grep '()' | grep -v schedule | wc -l`
>
> diff --git a/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-filter.tc b/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-filter.tc
> index b3ccdaec2a61ba..7e65a115054127 100644
> --- a/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-filter.tc
> +++ b/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-filter.tc
> @@ -24,6 +24,8 @@ fi
> echo function_graph > current_tracer
> enable_tracing
> sleep 1
> +disable_tracing
> +
> # search for functions (has "()" on the line), and make sure
> # that only the schedule function was found
> count=`cat trace | grep '()' | grep -v schedule | wc -l`
> diff --git a/tools/testing/selftests/ftrace/test.d/ftrace/func-filter-notrace-pid.tc b/tools/testing/selftests/ftrace/test.d/ftrace/func-filter-notrace-pid.tc
> index 80541964b9270b..9fb0511b5d2eeb 100644
> --- a/tools/testing/selftests/ftrace/test.d/ftrace/func-filter-notrace-pid.tc
> +++ b/tools/testing/selftests/ftrace/test.d/ftrace/func-filter-notrace-pid.tc
> @@ -51,6 +51,7 @@ do_test() {
>
> enable_tracing
> yield
> + disable_tracing
>
> count_pid=`cat trace | grep -v ^# | grep $PID | wc -l`
> count_other=`cat trace | grep -v ^# | grep -v $PID | wc -l`
> @@ -60,7 +61,6 @@ do_test() {
> fail "PID filtering not working? traced task = $count_pid; other tasks = $count_other "
> fi
>
> - disable_tracing
> clear_trace
>
> if [ $do_function_fork -eq 0 ]; then
> @@ -77,6 +77,7 @@ do_test() {
>
> enable_tracing
> yield
> + disable_tracing
>
> count_pid=`cat trace | grep -v ^# | grep $PID | wc -l`
> count_other=`cat trace | grep -v ^# | grep -v $PID | wc -l`
> diff --git a/tools/testing/selftests/ftrace/test.d/ftrace/func-filter-pid.tc b/tools/testing/selftests/ftrace/test.d/ftrace/func-filter-pid.tc
> index 2f7211254529ba..c55bcf2fe1966f 100644
> --- a/tools/testing/selftests/ftrace/test.d/ftrace/func-filter-pid.tc
> +++ b/tools/testing/selftests/ftrace/test.d/ftrace/func-filter-pid.tc
> @@ -51,6 +51,7 @@ do_test() {
>
> enable_tracing
> yield
> + disable_tracing
>
> count_pid=`cat trace | grep -v ^# | grep $PID | wc -l`
> count_other=`cat trace | grep -v ^# | grep -v $PID | wc -l`
> @@ -60,7 +61,6 @@ do_test() {
> fail "PID filtering not working?"
> fi
>
> - disable_tracing
> clear_trace
>
> if [ $do_function_fork -eq 0 ]; then
> @@ -72,6 +72,7 @@ do_test() {
>
> enable_tracing
> yield
> + disable_tracing
>
> count_pid=`cat trace | grep -v ^# | grep $PID | wc -l`
> count_other=`cat trace | grep -v ^# | grep -v $PID | wc -l`
>
--
Masami Hiramatsu (Google) <[email protected]>
Masami Hiramatsu wrote:
> On Wed, 19 Oct 2022 15:15:09 +0530
> "Naveen N. Rao" <[email protected]> wrote:
>
>> Steven Rostedt wrote:
>> > On Wed, 19 Oct 2022 00:19:49 +0900
>> > Masami Hiramatsu (Google) <[email protected]> wrote:
>> >
>> >> > You need to make sure that the "pause-on-trace" option is set or tracing_on
>> >> > is set to 0 (disabled). Otherwise, if the tracing is still active, then the
>> >> > reading of the trace file could potentially never end.
>> >>
>> >> initialize_ftrace() does this setting. So it must be set.
>> >> If you run the ftracetest on old kernel, this feature is not there and
>> >> it may cause a trouble. Naveen, can you clarify it?
>>
>> Yes, the change to not pause on opening the trace file looks to be the
>> problem.
>>
>> >
>> > But for old kernels that do not have "pause-on-trace" it should be the
>> > default. The "pause-on-trace" was added when the default was changed to not
>> > pause the trace while reading it.
>>
>> It looks like the kernel patch was picked up, but Masami's patch for the
>> selftest wasn't backported. I have requested a test with that applied.
>
> Good! That should be backported too.
> BTW, which kernel version do you test?
This was reported in internal tests with RHEL kernel.
>
>>
>> Separately, before I saw your response, I came up with the below patch
>> to update the selftests to disable tracing before reading the trace
>> file. I have also requested this to be tested.
>
> Yeah, OK. This also looks OK to me.
This patch doesn't seem to be enough - event/subsystem-enable.tc also
needs updates. In light of that, I'm not sure if the large number of
disable_tracing statements required makes sense. So, I'm inclined to
drop this patch in favour of the existing pause-on-trace option.
Thanks,
Naveen