Message ID | 20211018132616.2234853-1-lizhijian@cn.fujitsu.com (mailing list archive) |
---|---|
State | New |
Headers | show |
Series | kselftests: ftrace: limit the executing time by reading from cached trace | expand |
On Mon, 18 Oct 2021 21:26:16 +0800 Li Zhijian <lizhijian@cn.fujitsu.com> wrote: > LKP/0day observed that kselftests/ftrace cannot finish within 1 hour on > a 96 cpus platform where it hangs in the line like: > 'cat trace | grep -v ^# | awk '{ print $5 }' | sort -u | wc -l' > subsystem-enable.tc > > It seems that trace will keep growing during it's read by 'cat' command. > Consequently, trace becomes too large to finish reading. > > replace 'cat trace' by: > $ sed -i 's/cat trace |/read_cached_trace |/g' $(find test.d -name "*.tc") > Instead, what happens if you add this command to each test? if [ -t options/pause-on-trace ]; then echo 1 > options/pause-on-trace fi We also need to add to the "initialize_ftrace" function in test.d/functions. if [ -t options/pause-on-trace ]; then echo 0 > options/pause-on-trace fi -- Steve > CC: Philip Li <philip.li@intel.com> > Reported-by: kernel test robot <lkp@intel.com> > Signed-off-by: Li Zhijian <lizhijian@cn.fujitsu.com> > ---
On Mon, 18 Oct 2021 22:16:36 -0400 Steven Rostedt <rostedt@goodmis.org> wrote: > On Mon, 18 Oct 2021 21:26:16 +0800 > Li Zhijian <lizhijian@cn.fujitsu.com> wrote: > > > LKP/0day observed that kselftests/ftrace cannot finish within 1 hour on > > a 96 cpus platform where it hangs in the line like: > > 'cat trace | grep -v ^# | awk '{ print $5 }' | sort -u | wc -l' > > subsystem-enable.tc > > > > It seems that trace will keep growing during it's read by 'cat' command. > > Consequently, trace becomes too large to finish reading. > > > > replace 'cat trace' by: > > $ sed -i 's/cat trace |/read_cached_trace |/g' $(find test.d -name "*.tc") > > > > Instead, what happens if you add this command to each test? > > if [ -t options/pause-on-trace ]; then > echo 1 > options/pause-on-trace > fi > > We also need to add to the "initialize_ftrace" function in test.d/functions. > > if [ -t options/pause-on-trace ]; then > echo 0 > options/pause-on-trace > fi Hmm, by the way, shouldn't we set this feature by default? There are many "cat trace | grep ..." style test code in ftracetest just for checking whether the event is recorded. At least for the ftracetest, it should be set unless the testcase is explicitly disable it. Thank you. > > -- Steve > > > CC: Philip Li <philip.li@intel.com> > > Reported-by: kernel test robot <lkp@intel.com> > > Signed-off-by: Li Zhijian <lizhijian@cn.fujitsu.com> > > ---
On Wed, 20 Oct 2021 11:20:27 +0900 Masami Hiramatsu <mhiramat@kernel.org> wrote: > Hmm, by the way, shouldn't we set this feature by default? > There are many "cat trace | grep ..." style test code in ftracetest just for > checking whether the event is recorded. At least for the ftracetest, it should > be set unless the testcase is explicitly disable it. For testing, sure. I was criticized by the BPF folks about tracing stopping when the trace file was being read. So for normal operations, it doesn't pause, because that "confuses" people (so I am told). -- Steve
On Tue, 19 Oct 2021 22:34:54 -0400 Steven Rostedt <rostedt@goodmis.org> wrote: > On Wed, 20 Oct 2021 11:20:27 +0900 > Masami Hiramatsu <mhiramat@kernel.org> wrote: > > > Hmm, by the way, shouldn't we set this feature by default? > > There are many "cat trace | grep ..." style test code in ftracetest just for > > checking whether the event is recorded. At least for the ftracetest, it should > > be set unless the testcase is explicitly disable it. > > For testing, sure. > > I was criticized by the BPF folks about tracing stopping when the trace > file was being read. So for normal operations, it doesn't pause, because > that "confuses" people (so I am told). OK, I got it. Here is the patch to enable it by default for ftracetest :) Thanks! From 61e641f494307d9942a8415bc6743e85dd95438e Mon Sep 17 00:00:00 2001 From: Masami Hiramatsu <mhiramat@kernel.org> Date: Wed, 20 Oct 2021 11:50:35 +0900 Subject: [PATCH] selftests/ftrace: Stop tracing while reading the trace file by default Stop tracing while reading the trace file by default, to prevent the test results while checking it and to avoid taking a long time to check the result. If there is any testcase which wants to test the tracing while reading the trace file, please override this setting inside the test case. Signed-off-by: Masami Hiramatsu <mhiramat@kernel.org> --- tools/testing/selftests/ftrace/test.d/functions | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/tools/testing/selftests/ftrace/test.d/functions b/tools/testing/selftests/ftrace/test.d/functions index 000fd05e84b1..8adc0140d03f 100644 --- a/tools/testing/selftests/ftrace/test.d/functions +++ b/tools/testing/selftests/ftrace/test.d/functions @@ -124,6 +124,12 @@ initialize_ftrace() { # Reset ftrace to initial-state [ -f uprobe_events ] && echo > uprobe_events [ -f synthetic_events ] && echo > synthetic_events [ -f snapshot ] && echo 0 > snapshot + +# Stop tracing while reading the trace file by default, to prevent +# the test results while checking it and to avoid taking a long time +# to check the result. + [ -f options/pause-on-trace ] && echo 1 > options/pause-on-trace + clear_trace enable_tracing }
On 20/10/2021 10:55, Masami Hiramatsu wrote: > On Tue, 19 Oct 2021 22:34:54 -0400 > Steven Rostedt <rostedt@goodmis.org> wrote: > >> On Wed, 20 Oct 2021 11:20:27 +0900 >> Masami Hiramatsu <mhiramat@kernel.org> wrote: >> >>> Hmm, by the way, shouldn't we set this feature by default? >>> There are many "cat trace | grep ..." style test code in ftracetest just for >>> checking whether the event is recorded. At least for the ftracetest, it should >>> be set unless the testcase is explicitly disable it. >> For testing, sure. >> >> I was criticized by the BPF folks about tracing stopping when the trace >> file was being read. So for normal operations, it doesn't pause, because >> that "confuses" people (so I am told). > OK, I got it. > > Here is the patch to enable it by default for ftracetest :) > > Thanks! > > From 61e641f494307d9942a8415bc6743e85dd95438e Mon Sep 17 00:00:00 2001 > From: Masami Hiramatsu <mhiramat@kernel.org> > Date: Wed, 20 Oct 2021 11:50:35 +0900 > Subject: [PATCH] selftests/ftrace: Stop tracing while reading the trace file > by default > > Stop tracing while reading the trace file by default, to prevent > the test results while checking it and to avoid taking a long time > to check the result. > If there is any testcase which wants to test the tracing while reading > the trace file, please override this setting inside the test case. > > Signed-off-by: Masami Hiramatsu <mhiramat@kernel.org> LGTM. Tested-by: Li Zhijian <lizhijian@cn.fujitsu.com> Reported-by: kernel test robot<lkp@intel.com> > --- > tools/testing/selftests/ftrace/test.d/functions | 6 ++++++ > 1 file changed, 6 insertions(+) > > diff --git a/tools/testing/selftests/ftrace/test.d/functions b/tools/testing/selftests/ftrace/test.d/functions > index 000fd05e84b1..8adc0140d03f 100644 > --- a/tools/testing/selftests/ftrace/test.d/functions > +++ b/tools/testing/selftests/ftrace/test.d/functions > @@ -124,6 +124,12 @@ initialize_ftrace() { # Reset ftrace to initial-state > [ -f uprobe_events ] && echo > uprobe_events > [ -f synthetic_events ] && echo > synthetic_events > [ -f snapshot ] && echo 0 > snapshot > + > +# Stop tracing while reading the trace file by default, to prevent > +# the test results while checking it and to avoid taking a long time > +# to check the result. > + [ -f options/pause-on-trace ] && echo 1 > options/pause-on-trace > + > clear_trace > enable_tracing > }
On Wed, 20 Oct 2021 11:55:22 +0900 Masami Hiramatsu <mhiramat@kernel.org> wrote: > --- a/tools/testing/selftests/ftrace/test.d/functions > +++ b/tools/testing/selftests/ftrace/test.d/functions > @@ -124,6 +124,12 @@ initialize_ftrace() { # Reset ftrace to initial-state > [ -f uprobe_events ] && echo > uprobe_events > [ -f synthetic_events ] && echo > synthetic_events > [ -f snapshot ] && echo 0 > snapshot > + > +# Stop tracing while reading the trace file by default, to prevent > +# the test results while checking it and to avoid taking a long time > +# to check the result. > + [ -f options/pause-on-trace ] && echo 1 > options/pause-on-trace > + Is there a way we can save the previous setting and put it back on reset? -- Steve
On Wed, 20 Oct 2021 10:16:59 -0400 Steven Rostedt <rostedt@goodmis.org> wrote: > On Wed, 20 Oct 2021 11:55:22 +0900 > Masami Hiramatsu <mhiramat@kernel.org> wrote: > > > --- a/tools/testing/selftests/ftrace/test.d/functions > > +++ b/tools/testing/selftests/ftrace/test.d/functions > > @@ -124,6 +124,12 @@ initialize_ftrace() { # Reset ftrace to initial-state > > [ -f uprobe_events ] && echo > uprobe_events > > [ -f synthetic_events ] && echo > synthetic_events > > [ -f snapshot ] && echo 0 > snapshot > > + > > +# Stop tracing while reading the trace file by default, to prevent > > +# the test results while checking it and to avoid taking a long time > > +# to check the result. > > + [ -f options/pause-on-trace ] && echo 1 > options/pause-on-trace > > + > > Is there a way we can save the previous setting and put it back on reset? No, since each testcase must be run under the clean state. Would we need to recover the settings? Thank you, > > -- Steve
On Thu, 21 Oct 2021 09:31:31 +0900 Masami Hiramatsu <mhiramat@kernel.org> wrote: > > > +# Stop tracing while reading the trace file by default, to prevent > > > +# the test results while checking it and to avoid taking a long time > > > +# to check the result. > > > + [ -f options/pause-on-trace ] && echo 1 > options/pause-on-trace > > > + > > > > Is there a way we can save the previous setting and put it back on reset? > > No, since each testcase must be run under the clean state. Would we need to > recover the settings? I would at least put it back to the default. If someone runs the tests, it should at least put it back to what it was at boot. Otherwise, someone might run the tests, and then wonder why events are being dropped when they are reading the trace. -- Steve
On Mon, 25 Oct 2021 22:17:17 -0400 Steven Rostedt <rostedt@goodmis.org> wrote: > On Thu, 21 Oct 2021 09:31:31 +0900 > Masami Hiramatsu <mhiramat@kernel.org> wrote: > > > > > +# Stop tracing while reading the trace file by default, to prevent > > > > +# the test results while checking it and to avoid taking a long time > > > > +# to check the result. > > > > + [ -f options/pause-on-trace ] && echo 1 > options/pause-on-trace > > > > + > > > > > > Is there a way we can save the previous setting and put it back on reset? > > > > No, since each testcase must be run under the clean state. Would we need to > > recover the settings? > > I would at least put it back to the default. If someone runs the tests, > it should at least put it back to what it was at boot. Otherwise, > someone might run the tests, and then wonder why events are being > dropped when they are reading the trace. Umm, we may need to have a knob to reset the ftrace options... Can we warn such user that if the ftracetest finds that the current value is not the same what it sets? Thank you,
On Tue, 26 Oct 2021 21:13:31 +0900 Masami Hiramatsu <mhiramat@kernel.org> wrote: > > > No, since each testcase must be run under the clean state. Would we need to > > > recover the settings? > > > > I would at least put it back to the default. If someone runs the tests, > > it should at least put it back to what it was at boot. Otherwise, > > someone might run the tests, and then wonder why events are being > > dropped when they are reading the trace. > > Umm, we may need to have a knob to reset the ftrace options... > Can we warn such user that if the ftracetest finds that the current > value is not the same what it sets? You mean before we set pause-on-trace, make sure that it was cleared? That could work too, and then just set everything back to what we expected it to be at the start. -- Steve
On Tue, 26 Oct 2021 09:15:34 -0400 Steven Rostedt <rostedt@goodmis.org> wrote: > On Tue, 26 Oct 2021 21:13:31 +0900 > Masami Hiramatsu <mhiramat@kernel.org> wrote: > > > > > No, since each testcase must be run under the clean state. Would we need to > > > > recover the settings? > > > > > > I would at least put it back to the default. If someone runs the tests, > > > it should at least put it back to what it was at boot. Otherwise, > > > someone might run the tests, and then wonder why events are being > > > dropped when they are reading the trace. > > > > Umm, we may need to have a knob to reset the ftrace options... > > Can we warn such user that if the ftracetest finds that the current > > value is not the same what it sets? > > You mean before we set pause-on-trace, make sure that it was cleared? > > That could work too, and then just set everything back to what we expected > it to be at the start. No, it costs much higher (to save the default settings and recover) OK, then just make it recover to the build default setting. From e6ab7217c8f50dabee0f565764489fdd32e1ff07 Mon Sep 17 00:00:00 2001 From: Masami Hiramatsu <mhiramat@kernel.org> Date: Wed, 20 Oct 2021 11:55:22 +0900 Subject: [PATCH v2] selftests/ftrace: Stop tracing while reading the trace file by default Stop tracing while reading the trace file by default, to prevent the test results while checking it and to avoid taking a long time to check the result. If there is any testcase which wants to test the tracing while reading the trace file, please override this setting inside the test case. This also recovers the pause-on-trace when clean it up. Signed-off-by: Masami Hiramatsu <mhiramat@kernel.org> --- Changes in v2: - Recover pause-on-trace to 0 when exit. --- tools/testing/selftests/ftrace/ftracetest | 2 +- tools/testing/selftests/ftrace/test.d/functions | 12 ++++++++++++ 2 files changed, 13 insertions(+), 1 deletion(-) diff --git a/tools/testing/selftests/ftrace/ftracetest b/tools/testing/selftests/ftrace/ftracetest index 8ec1922e974e..c3311c8c4089 100755 --- a/tools/testing/selftests/ftrace/ftracetest +++ b/tools/testing/selftests/ftrace/ftracetest @@ -428,7 +428,7 @@ for t in $TEST_CASES; do exit 1 fi done -(cd $TRACING_DIR; initialize_ftrace) # for cleanup +(cd $TRACING_DIR; finish_ftrace) # for cleanup prlog "" prlog "# of passed: " `echo $PASSED_CASES | wc -w` diff --git a/tools/testing/selftests/ftrace/test.d/functions b/tools/testing/selftests/ftrace/test.d/functions index 000fd05e84b1..5f6cbec847fc 100644 --- a/tools/testing/selftests/ftrace/test.d/functions +++ b/tools/testing/selftests/ftrace/test.d/functions @@ -124,10 +124,22 @@ initialize_ftrace() { # Reset ftrace to initial-state [ -f uprobe_events ] && echo > uprobe_events [ -f synthetic_events ] && echo > synthetic_events [ -f snapshot ] && echo 0 > snapshot + +# Stop tracing while reading the trace file by default, to prevent +# the test results while checking it and to avoid taking a long time +# to check the result. + [ -f options/pause-on-trace ] && echo 1 > options/pause-on-trace + clear_trace enable_tracing } +finish_ftrace() { + initialize_ftrace +# And recover it to default. + [ -f options/pause-on-trace ] && echo 0 > options/pause-on-trace +} + check_requires() { # Check required files and tracers for i in "$@" ; do r=${i%:README}
On Tue, 26 Oct 2021 23:13:14 +0900 Masami Hiramatsu <mhiramat@kernel.org> wrote: > >From e6ab7217c8f50dabee0f565764489fdd32e1ff07 Mon Sep 17 00:00:00 2001 > From: Masami Hiramatsu <mhiramat@kernel.org> > Date: Wed, 20 Oct 2021 11:55:22 +0900 > Subject: [PATCH v2] selftests/ftrace: Stop tracing while reading the trace file > by default > > Stop tracing while reading the trace file by default, to prevent > the test results while checking it and to avoid taking a long time > to check the result. > If there is any testcase which wants to test the tracing while reading > the trace file, please override this setting inside the test case. > > This also recovers the pause-on-trace when clean it up. > > Signed-off-by: Masami Hiramatsu <mhiramat@kernel.org> Looks good. Can you resend this as a standalone patch, so that it triggers my patchwork? -- Steve
On Tue, 26 Oct 2021 11:16:26 -0400 Steven Rostedt <rostedt@goodmis.org> wrote: > On Tue, 26 Oct 2021 23:13:14 +0900 > Masami Hiramatsu <mhiramat@kernel.org> wrote: > > > >From e6ab7217c8f50dabee0f565764489fdd32e1ff07 Mon Sep 17 00:00:00 2001 > > From: Masami Hiramatsu <mhiramat@kernel.org> > > Date: Wed, 20 Oct 2021 11:55:22 +0900 > > Subject: [PATCH v2] selftests/ftrace: Stop tracing while reading the trace file > > by default > > > > Stop tracing while reading the trace file by default, to prevent > > the test results while checking it and to avoid taking a long time > > to check the result. > > If there is any testcase which wants to test the tracing while reading > > the trace file, please override this setting inside the test case. > > > > This also recovers the pause-on-trace when clean it up. > > > > Signed-off-by: Masami Hiramatsu <mhiramat@kernel.org> > > Looks good. Can you resend this as a standalone patch, so that it triggers > my patchwork? Sure, let me send it :-) Thank you,
diff --git a/tools/testing/selftests/ftrace/test.d/event/event-enable.tc b/tools/testing/selftests/ftrace/test.d/event/event-enable.tc index cfe5bd2d4267..97d64ac407c9 100644 --- a/tools/testing/selftests/ftrace/test.d/event/event-enable.tc +++ b/tools/testing/selftests/ftrace/test.d/event/event-enable.tc @@ -18,7 +18,7 @@ echo 'sched:sched_switch' > set_event yield -count=`cat trace | grep sched_switch | wc -l` +count=`read_cached_trace | grep sched_switch | wc -l` if [ $count -eq 0 ]; then fail "sched_switch events are not recorded" fi @@ -29,7 +29,7 @@ echo 1 > events/sched/sched_switch/enable yield -count=`cat trace | grep sched_switch | wc -l` +count=`read_cached_trace | grep sched_switch | wc -l` if [ $count -eq 0 ]; then fail "sched_switch events are not recorded" fi @@ -40,7 +40,7 @@ echo 0 > events/sched/sched_switch/enable yield -count=`cat trace | grep sched_switch | wc -l` +count=`read_cached_trace | grep sched_switch | wc -l` if [ $count -ne 0 ]; then fail "sched_switch events should not be recorded" fi diff --git a/tools/testing/selftests/ftrace/test.d/event/event-no-pid.tc b/tools/testing/selftests/ftrace/test.d/event/event-no-pid.tc index 9933ed24f901..678f283044cb 100644 --- a/tools/testing/selftests/ftrace/test.d/event/event-no-pid.tc +++ b/tools/testing/selftests/ftrace/test.d/event/event-no-pid.tc @@ -23,12 +23,12 @@ fail() { #msg count_pid() { pid=$@ - cat trace | grep -v '^#' | sed -e 's/[^-]*-\([0-9]*\).*/\1/' | grep $pid | wc -l + read_cached_trace | grep -v '^#' | sed -e 's/[^-]*-\([0-9]*\).*/\1/' | grep $pid | wc -l } count_no_pid() { pid=$1 - cat trace | grep -v '^#' | sed -e 's/[^-]*-\([0-9]*\).*/\1/' | grep -v $pid | wc -l + read_cached_trace | grep -v '^#' | sed -e 's/[^-]*-\([0-9]*\).*/\1/' | grep -v $pid | wc -l } enable_system() { diff --git a/tools/testing/selftests/ftrace/test.d/event/event-pid.tc b/tools/testing/selftests/ftrace/test.d/event/event-pid.tc index 7f5f97dffdc3..da7a5aa8f061 100644 --- a/tools/testing/selftests/ftrace/test.d/event/event-pid.tc +++ b/tools/testing/selftests/ftrace/test.d/event/event-pid.tc @@ -23,7 +23,7 @@ echo 1 > events/sched/sched_switch/enable yield -count=`cat trace | grep sched_switch | wc -l` +count=`read_cached_trace | grep sched_switch | wc -l` if [ $count -eq 0 ]; then fail "sched_switch events are not recorded" fi @@ -38,7 +38,7 @@ echo 'sched:sched_switch' > set_event yield -count=`cat trace | grep sched_switch | grep -v "pid=$mypid" | wc -l` +count=`read_cached_trace | grep sched_switch | grep -v "pid=$mypid" | wc -l` if [ $count -ne 0 ]; then fail "sched_switch events from other task are recorded" fi @@ -51,7 +51,7 @@ echo 1 > events/sched/sched_switch/enable yield -count=`cat trace | grep sched_switch | grep -v "pid=$mypid" | wc -l` +count=`read_cached_trace | grep sched_switch | grep -v "pid=$mypid" | wc -l` if [ $count -eq 0 ]; then fail "sched_switch events from other task are not recorded" fi diff --git a/tools/testing/selftests/ftrace/test.d/event/subsystem-enable.tc b/tools/testing/selftests/ftrace/test.d/event/subsystem-enable.tc index b1ede6249866..e21e923d8aa2 100644 --- a/tools/testing/selftests/ftrace/test.d/event/subsystem-enable.tc +++ b/tools/testing/selftests/ftrace/test.d/event/subsystem-enable.tc @@ -18,7 +18,7 @@ echo 'sched:*' > set_event yield -count=`cat trace | grep -v ^# | awk '{ print $5 }' | sort -u | wc -l` +count=`read_cached_trace | grep -v ^# | awk '{ print $5 }' | sort -u | wc -l` if [ $count -lt 3 ]; then fail "at least fork, exec and exit events should be recorded" fi @@ -29,7 +29,7 @@ echo 1 > events/sched/enable yield -count=`cat trace | grep -v ^# | awk '{ print $5 }' | sort -u | wc -l` +count=`read_cached_trace | grep -v ^# | awk '{ print $5 }' | sort -u | wc -l` if [ $count -lt 3 ]; then fail "at least fork, exec and exit events should be recorded" fi @@ -40,7 +40,7 @@ echo 0 > events/sched/enable yield -count=`cat trace | grep -v ^# | awk '{ print $5 }' | sort -u | wc -l` +count=`read_cached_trace | grep -v ^# | awk '{ print $5 }' | sort -u | wc -l` if [ $count -ne 0 ]; then fail "any of scheduler events should not be recorded" fi diff --git a/tools/testing/selftests/ftrace/test.d/event/toplevel-enable.tc b/tools/testing/selftests/ftrace/test.d/event/toplevel-enable.tc index 93c10ea42a68..b24792987438 100644 --- a/tools/testing/selftests/ftrace/test.d/event/toplevel-enable.tc +++ b/tools/testing/selftests/ftrace/test.d/event/toplevel-enable.tc @@ -43,7 +43,7 @@ echo 0 > events/enable yield -count=`cat trace | grep -v ^# | wc -l` +count=`read_cached_trace | grep -v ^# | wc -l` if [ $count -ne 0 ]; then fail "any of events should not be recorded" fi 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 cf3ea42b12b0..157080f682bf 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 @@ -40,14 +40,14 @@ clear_trace enable_tracing sleep 1 -count=`cat trace | grep '()' | grep -v schedule | wc -l` +count=`read_cached_trace | grep '()' | grep -v schedule | wc -l` if [ $count -ne 0 ]; then fail "Graph filtering not working with stack tracer?" fi # Make sure we did find something -count=`cat trace | grep 'schedule()' | wc -l` +count=`read_cached_trace | grep 'schedule()' | wc -l` if [ $count -eq 0 ]; then fail "No schedule traces found?" fi @@ -57,13 +57,13 @@ clear_trace sleep 1 -count=`cat trace | grep '()' | grep -v schedule | wc -l` +count=`read_cached_trace | grep '()' | grep -v schedule | wc -l` if [ $count -ne 0 ]; then fail "Graph filtering not working after stack tracer disabled?" fi -count=`cat trace | grep 'schedule()' | wc -l` +count=`read_cached_trace | grep 'schedule()' | wc -l` if [ $count -eq 0 ]; then fail "No schedule traces found?" fi 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 b3ccdaec2a61..930dfc06f4ba 100644 --- a/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-filter.tc +++ b/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-filter.tc @@ -26,13 +26,13 @@ enable_tracing sleep 1 # 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` +count=`read_cached_trace | grep '()' | grep -v schedule | wc -l` if [ $count -ne 0 ]; then fail "Graph filtering not working by itself?" fi # Make sure we did find something -count=`cat trace | grep 'schedule()' | wc -l` +count=`read_cached_trace | grep 'schedule()' | wc -l` if [ $count -eq 0 ]; then fail "No schedule traces found?" fi 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 80541964b927..1f08b7207d74 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 @@ -52,8 +52,8 @@ do_test() { enable_tracing yield - count_pid=`cat trace | grep -v ^# | grep $PID | wc -l` - count_other=`cat trace | grep -v ^# | grep -v $PID | wc -l` + count_pid=`read_cached_trace | grep -v ^# | grep $PID | wc -l` + count_other=`read_cached_trace | grep -v ^# | grep -v $PID | wc -l` # count_pid should be 0 if [ $count_pid -ne 0 -o $count_other -eq 0 ]; then @@ -78,8 +78,8 @@ do_test() { enable_tracing yield - count_pid=`cat trace | grep -v ^# | grep $PID | wc -l` - count_other=`cat trace | grep -v ^# | grep -v $PID | wc -l` + count_pid=`read_cached_trace | grep -v ^# | grep $PID | wc -l` + count_other=`read_cached_trace | grep -v ^# | grep -v $PID | wc -l` # both should be zero if [ $count_pid -ne 0 -o $count_other -ne 0 ]; then 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 2f7211254529..30c218b849dc 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 @@ -52,8 +52,8 @@ do_test() { enable_tracing yield - count_pid=`cat trace | grep -v ^# | grep $PID | wc -l` - count_other=`cat trace | grep -v ^# | grep -v $PID | wc -l` + count_pid=`read_cached_trace | grep -v ^# | grep $PID | wc -l` + count_other=`read_cached_trace | grep -v ^# | grep -v $PID | wc -l` # count_other should be 0 if [ $count_pid -eq 0 -o $count_other -ne 0 ]; then @@ -73,8 +73,8 @@ do_test() { enable_tracing yield - count_pid=`cat trace | grep -v ^# | grep $PID | wc -l` - count_other=`cat trace | grep -v ^# | grep -v $PID | wc -l` + count_pid=`read_cached_trace | grep -v ^# | grep $PID | wc -l` + count_other=`read_cached_trace | grep -v ^# | grep -v $PID | wc -l` # count_other should NOT be 0 if [ $count_pid -eq 0 -o $count_other -eq 0 ]; then diff --git a/tools/testing/selftests/ftrace/test.d/functions b/tools/testing/selftests/ftrace/test.d/functions index 000fd05e84b1..35d1d173d44b 100644 --- a/tools/testing/selftests/ftrace/test.d/functions +++ b/tools/testing/selftests/ftrace/test.d/functions @@ -175,3 +175,9 @@ ftrace_errlog_check() { # err-prefix command-with-error-pos-by-^ command-file # " Command: " and "^\n" => 13 test $(expr 13 + $pos) -eq $N } + +read_cached_trace() { + cp trace /tmp/cached_trace + cat /tmp/cached_trace + rm -f /tmp/cached_trace +} diff --git a/tools/testing/selftests/ftrace/test.d/kprobe/kretprobe_args.tc b/tools/testing/selftests/ftrace/test.d/kprobe/kretprobe_args.tc index 197cc2afd404..57b3b215122f 100644 --- a/tools/testing/selftests/ftrace/test.d/kprobe/kretprobe_args.tc +++ b/tools/testing/selftests/ftrace/test.d/kprobe/kretprobe_args.tc @@ -11,7 +11,7 @@ test -d events/kprobes/testprobe2 echo 1 > events/kprobes/testprobe2/enable ( echo "forked") -cat trace | grep testprobe2 | grep -q "<- $FUNCTION_FORK" +read_cached_trace | grep testprobe2 | grep -q "<- $FUNCTION_FORK" echo 0 > events/kprobes/testprobe2/enable echo '-:testprobe2' >> kprobe_events
LKP/0day observed that kselftests/ftrace cannot finish within 1 hour on a 96 cpus platform where it hangs in the line like: 'cat trace | grep -v ^# | awk '{ print $5 }' | sort -u | wc -l' subsystem-enable.tc It seems that trace will keep growing during it's read by 'cat' command. Consequently, trace becomes too large to finish reading. replace 'cat trace' by: $ sed -i 's/cat trace |/read_cached_trace |/g' $(find test.d -name "*.tc") CC: Philip Li <philip.li@intel.com> Reported-by: kernel test robot <lkp@intel.com> Signed-off-by: Li Zhijian <lizhijian@cn.fujitsu.com> --- .../testing/selftests/ftrace/test.d/event/event-enable.tc | 6 +++--- .../testing/selftests/ftrace/test.d/event/event-no-pid.tc | 4 ++-- tools/testing/selftests/ftrace/test.d/event/event-pid.tc | 6 +++--- .../selftests/ftrace/test.d/event/subsystem-enable.tc | 6 +++--- .../selftests/ftrace/test.d/event/toplevel-enable.tc | 2 +- .../selftests/ftrace/test.d/ftrace/fgraph-filter-stack.tc | 8 ++++---- .../selftests/ftrace/test.d/ftrace/fgraph-filter.tc | 4 ++-- .../ftrace/test.d/ftrace/func-filter-notrace-pid.tc | 8 ++++---- .../selftests/ftrace/test.d/ftrace/func-filter-pid.tc | 8 ++++---- tools/testing/selftests/ftrace/test.d/functions | 6 ++++++ .../selftests/ftrace/test.d/kprobe/kretprobe_args.tc | 2 +- 11 files changed, 33 insertions(+), 27 deletions(-)