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-next>] [day] [month] [year] [list]
Message-ID: <20211018132616.2234853-1-lizhijian@cn.fujitsu.com>
Date:   Mon, 18 Oct 2021 21:26:16 +0800
From:   Li Zhijian <lizhijian@...fujitsu.com>
To:     <rostedt@...dmis.org>, <mingo@...hat.com>, <shuah@...nel.org>,
        <linux-kselftest@...r.kernel.org>
CC:     <linux-kernel@...r.kernel.org>,
        Li Zhijian <lizhijian@...fujitsu.com>,
        Philip Li <philip.li@...el.com>,
        kernel test robot <lkp@...el.com>
Subject: [PATCH] kselftests: ftrace: limit the executing time by reading from cached trace

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@...el.com>
Reported-by: kernel test robot <lkp@...el.com>
Signed-off-by: Li Zhijian <lizhijian@...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(-)

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
-- 
2.31.1



Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ