The func_traceonoff_triggers.tc sometimes goes to fail on my board, Kunpeng-920.
[root@localhost]# ./ftracetest ./test.d/ftrace/func_traceonoff_triggers.tc -l fail.log === Ftrace unit tests === [1] ftrace - test for function traceon/off triggers [FAIL] [2] (instance) ftrace - test for function traceon/off triggers [UNSUPPORTED]
I look up the log, and it shows that the md5sum is different between csum1 and csum2.
++ cnt=611 ++ sleep .1 +++ cnt_trace +++ grep -v '^#' trace +++ wc -l ++ cnt2=611 ++ '[' 611 -ne 611 ']' +++ cat tracing_on ++ on=0 ++ '[' 0 '!=' 0 ']' +++ md5sum trace ++ csum1='76896aa74362fff66a6a5f3cf8a8a500 trace' ++ sleep .1 +++ md5sum trace ++ csum2='ee8625a21c058818fc26e45c1ed3f6de trace' ++ '[' '76896aa74362fff66a6a5f3cf8a8a500 trace' '!=' 'ee8625a21c058818fc26e45c1ed3f6de trace' ']' ++ fail 'Tracing file is still changing' ++ echo Tracing file is still changing Tracing file is still changing ++ exit_fail ++ exit 1
So I directly dump the trace file before md5sum, the diff shows that:
[root@localhost]# diff trace_1.log trace_2.log -y --suppress-common-lines dockerd-12285 [036] d.... 18385.510290: sched_stat | <...>-12285 [036] d.... 18385.510290: sched_stat dockerd-12285 [036] d.... 18385.510291: sched_swit | <...>-12285 [036] d.... 18385.510291: sched_swit <...>-740 [044] d.... 18385.602859: sched_stat | kworker/44:1-740 [044] d.... 18385.602859: sched_stat <...>-740 [044] d.... 18385.602860: sched_swit | kworker/44:1-740 [044] d.... 18385.602860: sched_swit
And we can see that <...> filed be filled with names.
We can strip off the names there to fix that.
After strip off the names:
kworker/u257:0-12 [019] d..2. 2528.758910: sched_stat | -12 [019] d..2. 2528.758910: sched_stat_runtime: comm=k kworker/u257:0-12 [019] d..2. 2528.758912: sched_swit | -12 [019] d..2. 2528.758912: sched_switch: prev_comm=kw <idle>-0 [000] d.s5. 2528.762318: sched_waki | -0 [000] d.s5. 2528.762318: sched_waking: comm=sshd pi <idle>-0 [037] dNh2. 2528.762326: sched_wake | -0 [037] dNh2. 2528.762326: sched_wakeup: comm=sshd pi <idle>-0 [037] d..2. 2528.762334: sched_swit | -0 [037] d..2. 2528.762334: sched_switch: prev_comm=sw
Fixes: d87b29179aa0 ("selftests: ftrace: Use md5sum to take less time of checking logs") Suggested-by: Steven Rostedt (Google) rostedt@goodmis.org Signed-off-by: Yipeng Zou zouyipeng@huawei.com --- .../ftrace/test.d/ftrace/func_traceonoff_triggers.tc | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-)
diff --git a/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc b/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc index aee22289536b..c5783999582d 100644 --- a/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc +++ b/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc @@ -90,9 +90,9 @@ if [ $on != "0" ]; then fail "Tracing is not off" fi
-csum1=`md5sum trace` +csum1=`cat trace | sed -e 's/^ *[^ ]*(-[0-9][0-9]*)/\1/' | md5sum` sleep $SLEEP_TIME -csum2=`md5sum trace` +csum2=`cat trace | sed -e 's/^ *[^ ]*(-[0-9][0-9]*)/\1/' | md5sum`
if [ "$csum1" != "$csum2" ]; then fail "Tracing file is still changing"
On Thu, 17 Aug 2023 10:50:28 +0800 Yipeng Zou zouyipeng@huawei.com wrote:
The func_traceonoff_triggers.tc sometimes goes to fail on my board, Kunpeng-920.
[root@localhost]# ./ftracetest ./test.d/ftrace/func_traceonoff_triggers.tc -l fail.log === Ftrace unit tests === [1] ftrace - test for function traceon/off triggers [FAIL] [2] (instance) ftrace - test for function traceon/off triggers [UNSUPPORTED]
I look up the log, and it shows that the md5sum is different between csum1 and csum2.
++ cnt=611 ++ sleep .1 +++ cnt_trace +++ grep -v '^#' trace +++ wc -l ++ cnt2=611 ++ '[' 611 -ne 611 ']' +++ cat tracing_on ++ on=0 ++ '[' 0 '!=' 0 ']' +++ md5sum trace ++ csum1='76896aa74362fff66a6a5f3cf8a8a500 trace' ++ sleep .1 +++ md5sum trace ++ csum2='ee8625a21c058818fc26e45c1ed3f6de trace' ++ '[' '76896aa74362fff66a6a5f3cf8a8a500 trace' '!=' 'ee8625a21c058818fc26e45c1ed3f6de trace' ']' ++ fail 'Tracing file is still changing' ++ echo Tracing file is still changing Tracing file is still changing ++ exit_fail ++ exit 1
So I directly dump the trace file before md5sum, the diff shows that:
[root@localhost]# diff trace_1.log trace_2.log -y --suppress-common-lines dockerd-12285 [036] d.... 18385.510290: sched_stat | <...>-12285 [036] d.... 18385.510290: sched_stat dockerd-12285 [036] d.... 18385.510291: sched_swit | <...>-12285 [036] d.... 18385.510291: sched_swit <...>-740 [044] d.... 18385.602859: sched_stat | kworker/44:1-740 [044] d.... 18385.602859: sched_stat <...>-740 [044] d.... 18385.602860: sched_swit | kworker/44:1-740 [044] d.... 18385.602860: sched_swit
And we can see that <...> filed be filled with names.
We can strip off the names there to fix that.
After strip off the names:
kworker/u257:0-12 [019] d..2. 2528.758910: sched_stat | -12 [019] d..2. 2528.758910: sched_stat_runtime: comm=k kworker/u257:0-12 [019] d..2. 2528.758912: sched_swit | -12 [019] d..2. 2528.758912: sched_switch: prev_comm=kw <idle>-0 [000] d.s5. 2528.762318: sched_waki | -0 [000] d.s5. 2528.762318: sched_waking: comm=sshd pi <idle>-0 [037] dNh2. 2528.762326: sched_wake | -0 [037] dNh2. 2528.762326: sched_wakeup: comm=sshd pi <idle>-0 [037] d..2. 2528.762334: sched_swit | -0 [037] d..2. 2528.762334: sched_switch: prev_comm=sw
Looks good to me.
Acked-by: Masami Hiramatsu (Google) mhiramat@kernel.org
Thank you!
Fixes: d87b29179aa0 ("selftests: ftrace: Use md5sum to take less time of checking logs") Suggested-by: Steven Rostedt (Google) rostedt@goodmis.org Signed-off-by: Yipeng Zou zouyipeng@huawei.com
.../ftrace/test.d/ftrace/func_traceonoff_triggers.tc | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-)
diff --git a/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc b/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc index aee22289536b..c5783999582d 100644 --- a/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc +++ b/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc @@ -90,9 +90,9 @@ if [ $on != "0" ]; then fail "Tracing is not off" fi -csum1=`md5sum trace` +csum1=`cat trace | sed -e 's/^ *[^ ]*(-[0-9][0-9]*)/\1/' | md5sum` sleep $SLEEP_TIME -csum2=`md5sum trace` +csum2=`cat trace | sed -e 's/^ *[^ ]*(-[0-9][0-9]*)/\1/' | md5sum` if [ "$csum1" != "$csum2" ]; then fail "Tracing file is still changing" -- 2.34.1
Shuah,
Can you take this in your tree?
Reviewed-by: Steven Rostedt (Google) rostedt@goodmis.org
-- Steve
On Thu, 17 Aug 2023 14:16:03 +0900 Masami Hiramatsu (Google) mhiramat@kernel.org wrote:
On Thu, 17 Aug 2023 10:50:28 +0800 Yipeng Zou zouyipeng@huawei.com wrote:
The func_traceonoff_triggers.tc sometimes goes to fail on my board, Kunpeng-920.
[root@localhost]# ./ftracetest ./test.d/ftrace/func_traceonoff_triggers.tc -l fail.log === Ftrace unit tests === [1] ftrace - test for function traceon/off triggers [FAIL] [2] (instance) ftrace - test for function traceon/off triggers [UNSUPPORTED]
I look up the log, and it shows that the md5sum is different between csum1 and csum2.
++ cnt=611 ++ sleep .1 +++ cnt_trace +++ grep -v '^#' trace +++ wc -l ++ cnt2=611 ++ '[' 611 -ne 611 ']' +++ cat tracing_on ++ on=0 ++ '[' 0 '!=' 0 ']' +++ md5sum trace ++ csum1='76896aa74362fff66a6a5f3cf8a8a500 trace' ++ sleep .1 +++ md5sum trace ++ csum2='ee8625a21c058818fc26e45c1ed3f6de trace' ++ '[' '76896aa74362fff66a6a5f3cf8a8a500 trace' '!=' 'ee8625a21c058818fc26e45c1ed3f6de trace' ']' ++ fail 'Tracing file is still changing' ++ echo Tracing file is still changing Tracing file is still changing ++ exit_fail ++ exit 1
So I directly dump the trace file before md5sum, the diff shows that:
[root@localhost]# diff trace_1.log trace_2.log -y --suppress-common-lines dockerd-12285 [036] d.... 18385.510290: sched_stat | <...>-12285 [036] d.... 18385.510290: sched_stat dockerd-12285 [036] d.... 18385.510291: sched_swit | <...>-12285 [036] d.... 18385.510291: sched_swit <...>-740 [044] d.... 18385.602859: sched_stat | kworker/44:1-740 [044] d.... 18385.602859: sched_stat <...>-740 [044] d.... 18385.602860: sched_swit | kworker/44:1-740 [044] d.... 18385.602860: sched_swit
And we can see that <...> filed be filled with names.
We can strip off the names there to fix that.
After strip off the names:
kworker/u257:0-12 [019] d..2. 2528.758910: sched_stat | -12 [019] d..2. 2528.758910: sched_stat_runtime: comm=k kworker/u257:0-12 [019] d..2. 2528.758912: sched_swit | -12 [019] d..2. 2528.758912: sched_switch: prev_comm=kw <idle>-0 [000] d.s5. 2528.762318: sched_waki | -0 [000] d.s5. 2528.762318: sched_waking: comm=sshd pi <idle>-0 [037] dNh2. 2528.762326: sched_wake | -0 [037] dNh2. 2528.762326: sched_wakeup: comm=sshd pi <idle>-0 [037] d..2. 2528.762334: sched_swit | -0 [037] d..2. 2528.762334: sched_switch: prev_comm=sw
Looks good to me.
Acked-by: Masami Hiramatsu (Google) mhiramat@kernel.org
Thank you!
Fixes: d87b29179aa0 ("selftests: ftrace: Use md5sum to take less time of checking logs") Suggested-by: Steven Rostedt (Google) rostedt@goodmis.org Signed-off-by: Yipeng Zou zouyipeng@huawei.com
.../ftrace/test.d/ftrace/func_traceonoff_triggers.tc | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-)
diff --git a/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc b/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc index aee22289536b..c5783999582d 100644 --- a/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc +++ b/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc @@ -90,9 +90,9 @@ if [ $on != "0" ]; then fail "Tracing is not off" fi -csum1=`md5sum trace` +csum1=`cat trace | sed -e 's/^ *[^ ]*(-[0-9][0-9]*)/\1/' | md5sum` sleep $SLEEP_TIME -csum2=`md5sum trace` +csum2=`cat trace | sed -e 's/^ *[^ ]*(-[0-9][0-9]*)/\1/' | md5sum` if [ "$csum1" != "$csum2" ]; then fail "Tracing file is still changing" -- 2.34.1
On Thu, 17 Aug 2023 09:02:33 -0400 Steven Rostedt rostedt@goodmis.org wrote:
Shuah,
Can you take this in your tree?
Actually, hold off please.
Reviewed-by: Steven Rostedt (Google) rostedt@goodmis.org
-- Steve
On Thu, 17 Aug 2023 14:16:03 +0900 Masami Hiramatsu (Google) mhiramat@kernel.org wrote:
On Thu, 17 Aug 2023 10:50:28 +0800 Yipeng Zou zouyipeng@huawei.com wrote:
Fixes: d87b29179aa0 ("selftests: ftrace: Use md5sum to take less time of checking logs") Suggested-by: Steven Rostedt (Google) rostedt@goodmis.org Signed-off-by: Yipeng Zou zouyipeng@huawei.com
.../ftrace/test.d/ftrace/func_traceonoff_triggers.tc | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-)
diff --git a/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc b/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc index aee22289536b..c5783999582d 100644 --- a/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc +++ b/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc @@ -90,9 +90,9 @@ if [ $on != "0" ]; then fail "Tracing is not off" fi -csum1=`md5sum trace`
Yipeng, can you please add the comment here:
# Cannot rely on names being around as they are only cached, strip them
+csum1=`cat trace | sed -e 's/^ *[^ ]*(-[0-9][0-9]*)/\1/' | md5sum`
-- Steve
sleep $SLEEP_TIME -csum2=`md5sum trace` +csum2=`cat trace | sed -e 's/^ *[^ ]*(-[0-9][0-9]*)/\1/' | md5sum` if [ "$csum1" != "$csum2" ]; then fail "Tracing file is still changing" -- 2.34.1
在 2023/8/17 21:04, Steven Rostedt 写道:
On Thu, 17 Aug 2023 09:02:33 -0400 Steven Rostedt rostedt@goodmis.org wrote:
Shuah,
Can you take this in your tree?
Actually, hold off please.
Reviewed-by: Steven Rostedt (Google) rostedt@goodmis.org
-- Steve
On Thu, 17 Aug 2023 14:16:03 +0900 Masami Hiramatsu (Google) mhiramat@kernel.org wrote:
On Thu, 17 Aug 2023 10:50:28 +0800 Yipeng Zou zouyipeng@huawei.com wrote:
Fixes: d87b29179aa0 ("selftests: ftrace: Use md5sum to take less time of checking logs") Suggested-by: Steven Rostedt (Google) rostedt@goodmis.org Signed-off-by: Yipeng Zou zouyipeng@huawei.com
.../ftrace/test.d/ftrace/func_traceonoff_triggers.tc | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-)
diff --git a/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc b/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc index aee22289536b..c5783999582d 100644 --- a/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc +++ b/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc @@ -90,9 +90,9 @@ if [ $on != "0" ]; then fail "Tracing is not off" fi -csum1=`md5sum trace`
Yipeng, can you please add the comment here:
# Cannot rely on names being around as they are only cached, strip them
Of course, There is need to have some comment here.
Sending v3 right now.
+csum1=`cat trace | sed -e 's/^ *[^ ]*(-[0-9][0-9]*)/\1/' | md5sum`
-- Steve
sleep $SLEEP_TIME -csum2=`md5sum trace` +csum2=`cat trace | sed -e 's/^ *[^ ]*(-[0-9][0-9]*)/\1/' | md5sum` if [ "$csum1" != "$csum2" ]; then fail "Tracing file is still changing" -- 2.34.1
linux-kselftest-mirror@lists.linaro.org
-
Masami Hiramatsu -
Steven Rostedt -
Yipeng Zou