| Message ID | 20230814025918.2726807-1-zouyipeng@huawei.com (mailing list archive) |
|---|---|
| State | Superseded |
| Headers | show |
| Series | selftests/ftrace: let traceonoff_triggers testcase without md5sum | expand |
On Mon, 14 Aug 2023 10:59:18 +0800 Yipeng Zou <zouyipeng@huawei.com> wrote: > 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 So the problem is the <..> being added? > > And we can see that the saved_cmdlines in kernel was changed. > > So Maybe there is no safe to use md5sum here to verify whether > the file whether it has changed. > > >From my point of view, we only need to verify traceoff event > is valid there. > > Maybe it is enough to check first that the tracing_on equals 0, > and then check that the total number of rows of trace does not > increase? > > Fixes: d87b29179aa0 ("selftests: ftrace: Use md5sum to take less time of checking logs") > Signed-off-by: Yipeng Zou <zouyipeng@huawei.com> > --- > .../test.d/ftrace/func_traceonoff_triggers.tc | 16 ++++------------ > 1 file changed, 4 insertions(+), 12 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..180c60605d7b 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 > @@ -77,25 +77,17 @@ if [ $cnt -ne 1 ]; then > fail "Did not find traceoff trigger" > fi > > -cnt=`cnt_trace` > -sleep $SLEEP_TIME > -cnt2=`cnt_trace` > - > -if [ $cnt -ne $cnt2 ]; then > - fail "Tracing is not stopped" > -fi > - > on=`cat tracing_on` > if [ $on != "0" ]; then > fail "Tracing is not off" > fi > > -csum1=`md5sum trace` What about just changing the above to: # Can not rely on names being around as they are only cached csum1=`cat trace | sed -e 's/^ *[^ ]*\(-[0-9][0-9]*\)/\1/' | md5sum` > +cnt=`cnt_trace` > sleep $SLEEP_TIME > -csum2=`md5sum trace` And this: csum2=`cat trace | sed -e 's/^ *[^ ]*\(-[0-9][0-9]*\)/\1/' | md5sum` That will strip off the names an leave just the -[PID]... part of the line? -- Steve > +cnt2=`cnt_trace` > > -if [ "$csum1" != "$csum2" ]; then > - fail "Tracing file is still changing" > +if [ $cnt -ne $cnt2 ]; then > + fail "Tracing is not stopped" > fi > > clear_trace
在 2023/8/17 4:20, Steven Rostedt 写道: > On Mon, 14 Aug 2023 10:59:18 +0800 > Yipeng Zou <zouyipeng@huawei.com> wrote: > >> 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 > So the problem is the <..> being added? > >> And we can see that the saved_cmdlines in kernel was changed. >> >> So Maybe there is no safe to use md5sum here to verify whether >> the file whether it has changed. >> >> >From my point of view, we only need to verify traceoff event >> is valid there. >> >> Maybe it is enough to check first that the tracing_on equals 0, >> and then check that the total number of rows of trace does not >> increase? >> >> Fixes: d87b29179aa0 ("selftests: ftrace: Use md5sum to take less time of checking logs") >> Signed-off-by: Yipeng Zou <zouyipeng@huawei.com> >> --- >> .../test.d/ftrace/func_traceonoff_triggers.tc | 16 ++++------------ >> 1 file changed, 4 insertions(+), 12 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..180c60605d7b 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 >> @@ -77,25 +77,17 @@ if [ $cnt -ne 1 ]; then >> fail "Did not find traceoff trigger" >> fi >> >> -cnt=`cnt_trace` >> -sleep $SLEEP_TIME >> -cnt2=`cnt_trace` >> - >> -if [ $cnt -ne $cnt2 ]; then >> - fail "Tracing is not stopped" >> -fi >> - >> on=`cat tracing_on` >> if [ $on != "0" ]; then >> fail "Tracing is not off" >> fi >> >> -csum1=`md5sum trace` > What about just changing the above to: > > # Can not rely on names being around as they are only cached > csum1=`cat trace | sed -e 's/^ *[^ ]*\(-[0-9][0-9]*\)/\1/' | md5sum` > >> +cnt=`cnt_trace` >> sleep $SLEEP_TIME >> -csum2=`md5sum trace` > And this: > > csum2=`cat trace | sed -e 's/^ *[^ ]*\(-[0-9][0-9]*\)/\1/' | md5sum` > > That will strip off the names an leave just the -[PID]... part of the line? > > -- Steve > > Hi Steve: Thanks for your suggests, this is indeed more effective. The problem was that <...> filed be filled with names, and it causes the md5 value changed. I will send v2 in that ways, thanks ! -- Yipeng >> +cnt2=`cnt_trace` >> >> -if [ "$csum1" != "$csum2" ]; then >> - fail "Tracing file is still changing" >> +if [ $cnt -ne $cnt2 ]; then >> + fail "Tracing is not stopped" >> fi >> >> clear_trace >
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..180c60605d7b 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 @@ -77,25 +77,17 @@ if [ $cnt -ne 1 ]; then fail "Did not find traceoff trigger" fi -cnt=`cnt_trace` -sleep $SLEEP_TIME -cnt2=`cnt_trace` - -if [ $cnt -ne $cnt2 ]; then - fail "Tracing is not stopped" -fi - on=`cat tracing_on` if [ $on != "0" ]; then fail "Tracing is not off" fi -csum1=`md5sum trace` +cnt=`cnt_trace` sleep $SLEEP_TIME -csum2=`md5sum trace` +cnt2=`cnt_trace` -if [ "$csum1" != "$csum2" ]; then - fail "Tracing file is still changing" +if [ $cnt -ne $cnt2 ]; then + fail "Tracing is not stopped" fi clear_trace
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 the saved_cmdlines in kernel was changed. So Maybe there is no safe to use md5sum here to verify whether the file whether it has changed. From my point of view, we only need to verify traceoff event is valid there. Maybe it is enough to check first that the tracing_on equals 0, and then check that the total number of rows of trace does not increase? Fixes: d87b29179aa0 ("selftests: ftrace: Use md5sum to take less time of checking logs") Signed-off-by: Yipeng Zou <zouyipeng@huawei.com> --- .../test.d/ftrace/func_traceonoff_triggers.tc | 16 ++++------------ 1 file changed, 4 insertions(+), 12 deletions(-)