| Message ID | 201909191102.97FA56072@keescook (mailing list archive) |
|---|---|
| State | Mainlined |
| Commit | 852c8cbf34d3b3130a05c38064dd98614f97d3a8 |
| Headers | show |
| Series | selftests/kselftest/runner.sh: Add 45 second timeout per test | expand |
On 19/09/2019 11:06:44-0700, Kees Cook wrote: > Commit a745f7af3cbd ("selftests/harness: Add 30 second timeout per > test") solves the problem of kselftest_harness.h-using binary tests > possibly hanging forever. However, scripts and other binaries can still > hang forever. This adds a global timeout to each test script run. > > To make this configurable (e.g. as needed in the "rtc" test case), > include a new per-test-directory "settings" file (similar to "config") > that can contain kselftest-specific settings. The first recognized field > is "timeout". > Seems good to me. I was also wondering whether this is actually reasonable to have tests running for so long. I wanted to discuss that at LPC but I missed the session. > Additionally, this splits the reporting for timeouts into a specific > "TIMEOUT" not-ok (and adds exit code reporting in the remaining case). > > Signed-off-by: Kees Cook <keescook@chromium.org> > --- > tools/testing/selftests/kselftest/runner.sh | 36 +++++++++++++++++++-- > tools/testing/selftests/rtc/settings | 1 + > 2 files changed, 34 insertions(+), 3 deletions(-) > create mode 100644 tools/testing/selftests/rtc/settings > > diff --git a/tools/testing/selftests/kselftest/runner.sh b/tools/testing/selftests/kselftest/runner.sh > index 00c9020bdda8..84de7bc74f2c 100644 > --- a/tools/testing/selftests/kselftest/runner.sh > +++ b/tools/testing/selftests/kselftest/runner.sh > @@ -3,9 +3,14 @@ > # > # Runs a set of tests in a given subdirectory. > export skip_rc=4 > +export timeout_rc=124 > export logfile=/dev/stdout > export per_test_logging= > > +# Defaults for "settings" file fields: > +# "timeout" how many seconds to let each test run before failing. > +export kselftest_default_timeout=45 > + > # There isn't a shell-agnostic way to find the path of a sourced file, > # so we must rely on BASE_DIR being set to find other tools. > if [ -z "$BASE_DIR" ]; then > @@ -24,6 +29,16 @@ tap_prefix() > fi > } > > +tap_timeout() > +{ > + # Make sure tests will time out if utility is available. > + if [ -x /usr/bin/timeout ] ; then > + /usr/bin/timeout "$kselftest_timeout" "$1" > + else > + "$1" > + fi > +} > + > run_one() > { > DIR="$1" > @@ -32,6 +47,18 @@ run_one() > > BASENAME_TEST=$(basename $TEST) > > + # Reset any "settings"-file variables. > + export kselftest_timeout="$kselftest_default_timeout" > + # Load per-test-directory kselftest "settings" file. > + settings="$BASE_DIR/$DIR/settings" > + if [ -r "$settings" ] ; then > + while read line ; do > + field=$(echo "$line" | cut -d= -f1) > + value=$(echo "$line" | cut -d= -f2-) > + eval "kselftest_$field"="$value" > + done < "$settings" > + fi > + > TEST_HDR_MSG="selftests: $DIR: $BASENAME_TEST" > echo "# $TEST_HDR_MSG" > if [ ! -x "$TEST" ]; then > @@ -44,14 +71,17 @@ run_one() > echo "not ok $test_num $TEST_HDR_MSG" > else > cd `dirname $TEST` > /dev/null > - (((((./$BASENAME_TEST 2>&1; echo $? >&3) | > + ((((( tap_timeout ./$BASENAME_TEST 2>&1; echo $? >&3) | > tap_prefix >&4) 3>&1) | > (read xs; exit $xs)) 4>>"$logfile" && > echo "ok $test_num $TEST_HDR_MSG") || > - (if [ $? -eq $skip_rc ]; then \ > + (rc=$?; \ > + if [ $rc -eq $skip_rc ]; then \ > echo "not ok $test_num $TEST_HDR_MSG # SKIP" > + elif [ $rc -eq $timeout_rc ]; then \ > + echo "not ok $test_num $TEST_HDR_MSG # TIMEOUT" > else > - echo "not ok $test_num $TEST_HDR_MSG" > + echo "not ok $test_num $TEST_HDR_MSG # exit=$rc" > fi) > cd - >/dev/null > fi > diff --git a/tools/testing/selftests/rtc/settings b/tools/testing/selftests/rtc/settings > new file mode 100644 > index 000000000000..ba4d85f74cd6 > --- /dev/null > +++ b/tools/testing/selftests/rtc/settings > @@ -0,0 +1 @@ > +timeout=90 > -- > 2.17.1 > > > -- > Kees Cook
On 9/19/19 12:55 PM, Alexandre Belloni wrote: > On 19/09/2019 11:06:44-0700, Kees Cook wrote: >> Commit a745f7af3cbd ("selftests/harness: Add 30 second timeout per >> test") solves the problem of kselftest_harness.h-using binary tests >> possibly hanging forever. However, scripts and other binaries can still >> hang forever. This adds a global timeout to each test script run. >> Timeout is good, but really tests should not hang. So we have to somehow indicate that the test needs to be fixed. This timeout is a band-aid and not real solution for the problem. This arbitrary value doesn't take into account that the test(s) in that particular directory (TARGET) could be running normally and working through all the tests. We need some way to differentiate the two cases. >> To make this configurable (e.g. as needed in the "rtc" test case), >> include a new per-test-directory "settings" file (similar to "config") >> that can contain kselftest-specific settings. The first recognized field >> is "timeout". >> > > Seems good to me. I was also wondering whether this is actually > reasonable to have tests running for so long. I wanted to discuss that > at LPC but I missed the session. > There is the individual test times and overall kselftest run time. We have lots of tests now and it does take long. >> Additionally, this splits the reporting for timeouts into a specific >> "TIMEOUT" not-ok (and adds exit code reporting in the remaining case). >> >> Signed-off-by: Kees Cook <keescook@chromium.org> >> --- >> tools/testing/selftests/kselftest/runner.sh | 36 +++++++++++++++++++-- >> tools/testing/selftests/rtc/settings | 1 + >> 2 files changed, 34 insertions(+), 3 deletions(-) >> create mode 100644 tools/testing/selftests/rtc/settings >> >> diff --git a/tools/testing/selftests/kselftest/runner.sh b/tools/testing/selftests/kselftest/runner.sh >> index 00c9020bdda8..84de7bc74f2c 100644 >> --- a/tools/testing/selftests/kselftest/runner.sh >> +++ b/tools/testing/selftests/kselftest/runner.sh >> @@ -3,9 +3,14 @@ >> # >> # Runs a set of tests in a given subdirectory. >> export skip_rc=4 >> +export timeout_rc=124 >> export logfile=/dev/stdout >> export per_test_logging= >> >> +# Defaults for "settings" file fields: >> +# "timeout" how many seconds to let each test run before failing. >> +export kselftest_default_timeout=45 >> + >> # There isn't a shell-agnostic way to find the path of a sourced file, >> # so we must rely on BASE_DIR being set to find other tools. >> if [ -z "$BASE_DIR" ]; then >> @@ -24,6 +29,16 @@ tap_prefix() >> fi >> } >> >> +tap_timeout() >> +{ >> + # Make sure tests will time out if utility is available. >> + if [ -x /usr/bin/timeout ] ; then >> + /usr/bin/timeout "$kselftest_timeout" "$1" >> + else >> + "$1" >> + fi >> +} >> + >> run_one() >> { >> DIR="$1" >> @@ -32,6 +47,18 @@ run_one() >> >> BASENAME_TEST=$(basename $TEST) >> >> + # Reset any "settings"-file variables. >> + export kselftest_timeout="$kselftest_default_timeout" >> + # Load per-test-directory kselftest "settings" file. >> + settings="$BASE_DIR/$DIR/settings" >> + if [ -r "$settings" ] ; then >> + while read line ; do >> + field=$(echo "$line" | cut -d= -f1) >> + value=$(echo "$line" | cut -d= -f2-) >> + eval "kselftest_$field"="$value" >> + done < "$settings" >> + fi >> + >> TEST_HDR_MSG="selftests: $DIR: $BASENAME_TEST" >> echo "# $TEST_HDR_MSG" >> if [ ! -x "$TEST" ]; then >> @@ -44,14 +71,17 @@ run_one() >> echo "not ok $test_num $TEST_HDR_MSG" >> else >> cd `dirname $TEST` > /dev/null >> - (((((./$BASENAME_TEST 2>&1; echo $? >&3) | >> + ((((( tap_timeout ./$BASENAME_TEST 2>&1; echo $? >&3) | >> tap_prefix >&4) 3>&1) | >> (read xs; exit $xs)) 4>>"$logfile" && >> echo "ok $test_num $TEST_HDR_MSG") || >> - (if [ $? -eq $skip_rc ]; then \ >> + (rc=$?; \ >> + if [ $rc -eq $skip_rc ]; then \ >> echo "not ok $test_num $TEST_HDR_MSG # SKIP" >> + elif [ $rc -eq $timeout_rc ]; then \ >> + echo "not ok $test_num $TEST_HDR_MSG # TIMEOUT" >> else >> - echo "not ok $test_num $TEST_HDR_MSG" >> + echo "not ok $test_num $TEST_HDR_MSG # exit=$rc" >> fi) >> cd - >/dev/null >> fi >> diff --git a/tools/testing/selftests/rtc/settings b/tools/testing/selftests/rtc/settings >> new file mode 100644 >> index 000000000000..ba4d85f74cd6 >> --- /dev/null >> +++ b/tools/testing/selftests/rtc/settings >> @@ -0,0 +1 @@ >> +timeout=90 >> -- >> 2.17.1 >> >> >> -- >> Kees Cook > thanks, -- Shuah
> -----Original Message----- > From: Kees Cook > > Commit a745f7af3cbd ("selftests/harness: Add 30 second timeout per > test") solves the problem of kselftest_harness.h-using binary tests > possibly hanging forever. However, scripts and other binaries can still > hang forever. This adds a global timeout to each test script run. > > To make this configurable (e.g. as needed in the "rtc" test case), > include a new per-test-directory "settings" file (similar to "config") > that can contain kselftest-specific settings. The first recognized field > is "timeout". OK - this is quite interesting. I have had on my to-do list an action item to propose the creation of a file (or a standard kerneldoc string) to hold CI-related meta-data (of which timeout is one example). What other meta-data did you have in mind? I would like (that Fuego, and probably other CI systems would like) to have access to data like test dependencies, descriptions, and results interpretation that would be beneficial for both CI systems (using them to control test invocations and scheduling), as well as users who are trying to interpret and handle the test results. So this concept is a very welcome addition to kselftest. LTP is in the process of adopting a new system for expressing and handling their test meta-data. See the discussion at: https://lists.yoctoproject.org/pipermail/automated-testing/2019-August/000471.html and the prototype implementation at: https://github.com/metan-ucw/ltp/tree/master/docparse I realize that that system is coupled pretty tightly to LTP, but conceptually some of the same type of information would be valuable for kselftest tests. One example of a specific field that would be handy is 'need_root'. It would be nice to avoid proliferation of such meta-data schemas (that is field names), so maybe we can have a discussion about this before adopting something? Just FYI, I'm OK with the name 'timeout'. I think that's pretty much universally used by all CI runners I'm aware of to indicate the test timeout value. But before adopting other fields it would be good to start comparing notes and not invent a bunch of new field names for concepts that are already in other systems. > > Additionally, this splits the reporting for timeouts into a specific > "TIMEOUT" not-ok (and adds exit code reporting in the remaining case). > > Signed-off-by: Kees Cook <keescook@chromium.org> > --- > tools/testing/selftests/kselftest/runner.sh | 36 +++++++++++++++++++-- > tools/testing/selftests/rtc/settings | 1 + > 2 files changed, 34 insertions(+), 3 deletions(-) > create mode 100644 tools/testing/selftests/rtc/settings > > diff --git a/tools/testing/selftests/kselftest/runner.sh > b/tools/testing/selftests/kselftest/runner.sh > index 00c9020bdda8..84de7bc74f2c 100644 > --- a/tools/testing/selftests/kselftest/runner.sh > +++ b/tools/testing/selftests/kselftest/runner.sh > @@ -3,9 +3,14 @@ > # > # Runs a set of tests in a given subdirectory. > export skip_rc=4 > +export timeout_rc=124 what are the units here? I presume seconds? > export logfile=/dev/stdout > export per_test_logging= > > +# Defaults for "settings" file fields: > +# "timeout" how many seconds to let each test run before failing. > +export kselftest_default_timeout=45 > + > # There isn't a shell-agnostic way to find the path of a sourced file, > # so we must rely on BASE_DIR being set to find other tools. > if [ -z "$BASE_DIR" ]; then > @@ -24,6 +29,16 @@ tap_prefix() > fi > } > > +tap_timeout() > +{ > + # Make sure tests will time out if utility is available. > + if [ -x /usr/bin/timeout ] ; then > + /usr/bin/timeout "$kselftest_timeout" "$1" > + else > + "$1" > + fi > +} > + > run_one() > { > DIR="$1" > @@ -32,6 +47,18 @@ run_one() > > BASENAME_TEST=$(basename $TEST) > > + # Reset any "settings"-file variables. > + export kselftest_timeout="$kselftest_default_timeout" > + # Load per-test-directory kselftest "settings" file. > + settings="$BASE_DIR/$DIR/settings" > + if [ -r "$settings" ] ; then > + while read line ; do > + field=$(echo "$line" | cut -d= -f1) > + value=$(echo "$line" | cut -d= -f2-) > + eval "kselftest_$field"="$value" > + done < "$settings" > + fi > + > TEST_HDR_MSG="selftests: $DIR: $BASENAME_TEST" > echo "# $TEST_HDR_MSG" > if [ ! -x "$TEST" ]; then > @@ -44,14 +71,17 @@ run_one() > echo "not ok $test_num $TEST_HDR_MSG" > else > cd `dirname $TEST` > /dev/null > - (((((./$BASENAME_TEST 2>&1; echo $? >&3) | > + ((((( tap_timeout ./$BASENAME_TEST 2>&1; echo $? >&3) | > tap_prefix >&4) 3>&1) | > (read xs; exit $xs)) 4>>"$logfile" && > echo "ok $test_num $TEST_HDR_MSG") || > - (if [ $? -eq $skip_rc ]; then \ > + (rc=$?; \ > + if [ $rc -eq $skip_rc ]; then \ > echo "not ok $test_num $TEST_HDR_MSG # SKIP" > + elif [ $rc -eq $timeout_rc ]; then \ > + echo "not ok $test_num $TEST_HDR_MSG # > TIMEOUT" This is an extension to the TAP protocol (well, not strictly, since it is in a comment), but it should be documented. I took an action item at the CKI hackfest to rigorously document the details of how kselftest has extended (or augmented) TAP. For example our indentation mechanism for sub-tests. You and I talked about this a bit at Plumbers, but I'd like to follow up and add something to Documentation/dev-tools/kselftest.rst so users and CI systems can know how to appropriately parse and manage kselftest TAP output. I'll start a separate thread on that when I get to documenting it, but this would definitely be an addition to that documentation. > else > - echo "not ok $test_num $TEST_HDR_MSG" > + echo "not ok $test_num $TEST_HDR_MSG # > exit=$rc" Is this also something new to kselftest's TAP output that should be documented? > fi) > cd - >/dev/null > fi > diff --git a/tools/testing/selftests/rtc/settings > b/tools/testing/selftests/rtc/settings > new file mode 100644 > index 000000000000..ba4d85f74cd6 > --- /dev/null > +++ b/tools/testing/selftests/rtc/settings > @@ -0,0 +1 @@ > +timeout=90 This is introducing a schema for meta-data naming, and a first field name. I have no problem with this one, but it might be worth comparing it with names expected by various kselftest-calling CI systems. I'll try to work on this shortly and report back any issues. Thanks for this. I think this points us in an interesting new direction. -- Tim
> -----Original Message----- > From: shuah > > On 9/19/19 12:55 PM, Alexandre Belloni wrote: > > On 19/09/2019 11:06:44-0700, Kees Cook wrote: > >> Commit a745f7af3cbd ("selftests/harness: Add 30 second timeout per > >> test") solves the problem of kselftest_harness.h-using binary tests > >> possibly hanging forever. However, scripts and other binaries can still > >> hang forever. This adds a global timeout to each test script run. > >> > > Timeout is good, but really tests should not hang. So we have to somehow > indicate that the test needs to be fixed. Well, a test hanging is something that might indicate either a failing in the test, or the detection of an actual problem. > > This timeout is a band-aid and not real solution for the problem. This > arbitrary value doesn't take into account that the test(s) in that > particular directory (TARGET) could be running normally and working > through all the tests. Yes. Also, having a single timeout value doesn't reflect the need to test on different hardware with potentially huge differences in CPU speed (or other resource performance differences). Since kselftest has a policy of having each test run quickly, this is somewhat mitigated. But still, some embedded boards are running magnitudes slower than your "average" enterprise Linux machine. Finding a timeout that can handle all hardware cases is difficult. -- Tim > > We need some way to differentiate the two cases. Agreed. > > >> To make this configurable (e.g. as needed in the "rtc" test case), > >> include a new per-test-directory "settings" file (similar to "config") > >> that can contain kselftest-specific settings. The first recognized field > >> is "timeout". > >> > > > > Seems good to me. I was also wondering whether this is actually > > reasonable to have tests running for so long. I wanted to discuss that > > at LPC but I missed the session. > > > > There is the individual test times and overall kselftest run time. We > have lots of tests now and it does take long. > > >> Additionally, this splits the reporting for timeouts into a specific > >> "TIMEOUT" not-ok (and adds exit code reporting in the remaining case). > >> > >> Signed-off-by: Kees Cook <keescook@chromium.org> > >> --- > >> tools/testing/selftests/kselftest/runner.sh | 36 > +++++++++++++++++++-- > >> tools/testing/selftests/rtc/settings | 1 + > >> 2 files changed, 34 insertions(+), 3 deletions(-) > >> create mode 100644 tools/testing/selftests/rtc/settings > >> > >> diff --git a/tools/testing/selftests/kselftest/runner.sh > b/tools/testing/selftests/kselftest/runner.sh > >> index 00c9020bdda8..84de7bc74f2c 100644 > >> --- a/tools/testing/selftests/kselftest/runner.sh > >> +++ b/tools/testing/selftests/kselftest/runner.sh > >> @@ -3,9 +3,14 @@ > >> # > >> # Runs a set of tests in a given subdirectory. > >> export skip_rc=4 > >> +export timeout_rc=124 > >> export logfile=/dev/stdout > >> export per_test_logging= > >> > >> +# Defaults for "settings" file fields: > >> +# "timeout" how many seconds to let each test run before failing. > >> +export kselftest_default_timeout=45 > >> + > >> # There isn't a shell-agnostic way to find the path of a sourced file, > >> # so we must rely on BASE_DIR being set to find other tools. > >> if [ -z "$BASE_DIR" ]; then > >> @@ -24,6 +29,16 @@ tap_prefix() > >> fi > >> } > >> > >> +tap_timeout() > >> +{ > >> + # Make sure tests will time out if utility is available. > >> + if [ -x /usr/bin/timeout ] ; then > >> + /usr/bin/timeout "$kselftest_timeout" "$1" > >> + else > >> + "$1" > >> + fi > >> +} > >> + > >> run_one() > >> { > >> DIR="$1" > >> @@ -32,6 +47,18 @@ run_one() > >> > >> BASENAME_TEST=$(basename $TEST) > >> > >> + # Reset any "settings"-file variables. > >> + export kselftest_timeout="$kselftest_default_timeout" > >> + # Load per-test-directory kselftest "settings" file. > >> + settings="$BASE_DIR/$DIR/settings" > >> + if [ -r "$settings" ] ; then > >> + while read line ; do > >> + field=$(echo "$line" | cut -d= -f1) > >> + value=$(echo "$line" | cut -d= -f2-) > >> + eval "kselftest_$field"="$value" > >> + done < "$settings" > >> + fi > >> + > >> TEST_HDR_MSG="selftests: $DIR: $BASENAME_TEST" > >> echo "# $TEST_HDR_MSG" > >> if [ ! -x "$TEST" ]; then > >> @@ -44,14 +71,17 @@ run_one() > >> echo "not ok $test_num $TEST_HDR_MSG" > >> else > >> cd `dirname $TEST` > /dev/null > >> - (((((./$BASENAME_TEST 2>&1; echo $? >&3) | > >> + ((((( tap_timeout ./$BASENAME_TEST 2>&1; echo $? >&3) | > >> tap_prefix >&4) 3>&1) | > >> (read xs; exit $xs)) 4>>"$logfile" && > >> echo "ok $test_num $TEST_HDR_MSG") || > >> - (if [ $? -eq $skip_rc ]; then \ > >> + (rc=$?; \ > >> + if [ $rc -eq $skip_rc ]; then \ > >> echo "not ok $test_num $TEST_HDR_MSG # SKIP" > >> + elif [ $rc -eq $timeout_rc ]; then \ > >> + echo "not ok $test_num $TEST_HDR_MSG # > TIMEOUT" > >> else > >> - echo "not ok $test_num $TEST_HDR_MSG" > >> + echo "not ok $test_num $TEST_HDR_MSG # > exit=$rc" > >> fi) > >> cd - >/dev/null > >> fi > >> diff --git a/tools/testing/selftests/rtc/settings > b/tools/testing/selftests/rtc/settings > >> new file mode 100644 > >> index 000000000000..ba4d85f74cd6 > >> --- /dev/null > >> +++ b/tools/testing/selftests/rtc/settings > >> @@ -0,0 +1 @@ > >> +timeout=90 > >> -- > >> 2.17.1 > >> > >> > >> -- > >> Kees Cook > > > > thanks, > -- Shuah
> -----Original Message----- > From Tim.Bird@sony.com > > > -----Original Message----- > > From: Kees Cook > > > > Commit a745f7af3cbd ("selftests/harness: Add 30 second timeout per > > test") solves the problem of kselftest_harness.h-using binary tests > > possibly hanging forever. However, scripts and other binaries can still > > hang forever. This adds a global timeout to each test script run. > > > > To make this configurable (e.g. as needed in the "rtc" test case), > > include a new per-test-directory "settings" file (similar to "config") > > that can contain kselftest-specific settings. The first recognized field > > is "timeout". > > OK - this is quite interesting. I have had on my to-do list an action > item to propose the creation of a file (or a standard kerneldoc string) > to hold CI-related meta-data (of which timeout is one example). > > What other meta-data did you have in mind? > > I would like (that Fuego, and probably other CI systems would like) to have > access to data like test dependencies, descriptions, and results > interpretation > that would be beneficial for both CI systems (using them to control test > invocations and scheduling), as > well as users who are trying to interpret and handle the test results. > So this concept is a very welcome addition to kselftest. > > LTP is in the process of adopting a new system for expressing and handling > their test meta-data. > See the discussion at: > https://lists.yoctoproject.org/pipermail/automated-testing/2019- > August/000471.html > and the prototype implementation at: > https://github.com/metan-ucw/ltp/tree/master/docparse > > I realize that that system is coupled pretty tightly to LTP, but conceptually > some of the same type of information would be valuable for kselftest tests. > One example of a specific field that would be handy is 'need_root'. > > It would be nice to avoid proliferation of such meta-data schemas (that is > field names), so maybe we can have a discussion about this before adopting > something? > > Just FYI, I'm OK with the name 'timeout'. I think that's pretty much > universally > used by all CI runners I'm aware of to indicate the test timeout value. But > before adopting other fields it would be good to start comparing notes > and not invent a bunch of new field names for concepts that are already in > other systems. > > > > > Additionally, this splits the reporting for timeouts into a specific > > "TIMEOUT" not-ok (and adds exit code reporting in the remaining case). > > > > Signed-off-by: Kees Cook <keescook@chromium.org> > > --- > > tools/testing/selftests/kselftest/runner.sh | 36 +++++++++++++++++++-- > > tools/testing/selftests/rtc/settings | 1 + > > 2 files changed, 34 insertions(+), 3 deletions(-) > > create mode 100644 tools/testing/selftests/rtc/settings > > > > diff --git a/tools/testing/selftests/kselftest/runner.sh > > b/tools/testing/selftests/kselftest/runner.sh > > index 00c9020bdda8..84de7bc74f2c 100644 > > --- a/tools/testing/selftests/kselftest/runner.sh > > +++ b/tools/testing/selftests/kselftest/runner.sh > > @@ -3,9 +3,14 @@ > > # > > # Runs a set of tests in a given subdirectory. > > export skip_rc=4 > > +export timeout_rc=124 > what are the units here? I presume seconds? Nevermind. I misread this. This is the return code from the 'timeout' program, right? -- Tim
On Thu, Sep 19, 2019 at 08:49:14PM +0000, Tim.Bird@sony.com wrote: > > > +export timeout_rc=124 > > what are the units here? I presume seconds? > > Nevermind. I misread this. This is the return code from the 'timeout' program, right? Correct -- given the skip_rc usage, it felt weird to hard-code it in the if/else statements. As for the "45" I chose, that was just to be "more than 30" which was the per-sub-test for tests built using kselftest_harness.h.
On Thu, Sep 19, 2019 at 08:41:42PM +0000, Tim.Bird@sony.com wrote: > > -----Original Message----- > > From: Kees Cook > > > > Commit a745f7af3cbd ("selftests/harness: Add 30 second timeout per > > test") solves the problem of kselftest_harness.h-using binary tests > > possibly hanging forever. However, scripts and other binaries can still > > hang forever. This adds a global timeout to each test script run. > > > > To make this configurable (e.g. as needed in the "rtc" test case), > > include a new per-test-directory "settings" file (similar to "config") > > that can contain kselftest-specific settings. The first recognized field > > is "timeout". > > OK - this is quite interesting. I have had on my to-do list an action > item to propose the creation of a file (or a standard kerneldoc string) > to hold CI-related meta-data (of which timeout is one example). FWIW, I opt for a "per directory settings" file here because per-test seemed like overkill. > What other meta-data did you have in mind? I figured in the future it could hold details about expected environmental states (user, namespace, rlimits, etc). For example, I'd like to indicate that the seccomp tests should be run twice both as root and as a regular user. > I would like (that Fuego, and probably other CI systems would like) to have > access to data like test dependencies, descriptions, and results interpretation > that would be beneficial for both CI systems (using them to control test invocations and scheduling), as > well as users who are trying to interpret and handle the test results. > So this concept is a very welcome addition to kselftest. I think this stuff may still be very per-test specific, but regardless, having it in a single place makes it easy to scrape. :) > LTP is in the process of adopting a new system for expressing and handling their test meta-data. > See the discussion at: > https://lists.yoctoproject.org/pipermail/automated-testing/2019-August/000471.html > and the prototype implementation at: > https://github.com/metan-ucw/ltp/tree/master/docparse This looks like similar framework details: _how_ to run a test in a given environment. > One example of a specific field that would be handy is 'need_root'. I think describing (possibly multiple) expected environments would be more useful, but perhaps just user alone would be a nice start. > It would be nice to avoid proliferation of such meta-data schemas (that is > field names), so maybe we can have a discussion about this before adopting > something? > > Just FYI, I'm OK with the name 'timeout'. I think that's pretty much universally > used by all CI runners I'm aware of to indicate the test timeout value. But > before adopting other fields it would be good to start comparing notes > and not invent a bunch of new field names for concepts that are already in > other systems. Yeah, I figure "timeout" could stand and other things would need more infrastructure. > > + if [ $rc -eq $skip_rc ]; then \ > > echo "not ok $test_num $TEST_HDR_MSG # SKIP" > > + elif [ $rc -eq $timeout_rc ]; then \ > > + echo "not ok $test_num $TEST_HDR_MSG # TIMEOUT" > This is an extension to the TAP protocol (well, not strictly, since it is in a comment), > but it should be documented. Right -- this is a "weird" corner of TAP-14. It says there can be "#" with everything after it semantically ignored, but that "# SKIP" is special. I think clarification of the spec here would be to have the format be: not ok name name name # DETAIL ignored ignored ignored Where the meaningful DETAIL words could be SKIP, TIMEOUT, FAIL. > I took an action item at the CKI hackfest to rigorously document the > details of how kselftest has extended (or augmented) TAP. For example > our indentation mechanism for sub-tests. You and I talked about this > a bit at Plumbers, but I'd like to follow up and add something > to Documentation/dev-tools/kselftest.rst so users and CI systems > can know how to appropriately parse and manage kselftest TAP output. > > I'll start a separate thread on that when I get to documenting it, > but this would definitely be an addition to that documentation. > > > else > > - echo "not ok $test_num $TEST_HDR_MSG" > > + echo "not ok $test_num $TEST_HDR_MSG # > > exit=$rc" > Is this also something new to kselftest's TAP output that should be documented? Right, if we made more the "SKIP" meaningful and required a specific detail here, this could just be "... # FAIL exit=$rc" unless we _wanted_ to make the exit code be parsed. Then maybe "... # EXIT=$rc" ? > > > fi) > > cd - >/dev/null > > fi > > diff --git a/tools/testing/selftests/rtc/settings > > b/tools/testing/selftests/rtc/settings > > new file mode 100644 > > index 000000000000..ba4d85f74cd6 > > --- /dev/null > > +++ b/tools/testing/selftests/rtc/settings > > @@ -0,0 +1 @@ > > +timeout=90 > > This is introducing a schema for meta-data naming, and a first field name. > I have no problem with this one, but it might be worth comparing it with > names expected by various kselftest-calling CI systems. I'll try to work > on this shortly and report back any issues. > > Thanks for this. I think this points us in an interesting new direction. Cool; I'm glad you like it! I really do want to get timeouts nailed down since Shuah mentioned that was a pain point. While I solved it for seccomp via the kselftest_harness.h timeout, there have been other cases of stalls that aren't handled by that change.
On Thu, Sep 19, 2019 at 02:09:37PM -0600, shuah wrote: > On 9/19/19 12:55 PM, Alexandre Belloni wrote: > > On 19/09/2019 11:06:44-0700, Kees Cook wrote: > > > Commit a745f7af3cbd ("selftests/harness: Add 30 second timeout per > > > test") solves the problem of kselftest_harness.h-using binary tests > > > possibly hanging forever. However, scripts and other binaries can still > > > hang forever. This adds a global timeout to each test script run. > > > > > Timeout is good, but really tests should not hang. So we have to somehow > indicate that the test needs to be fixed. Totally agreed, which is why I changed the reporting to call out a "TIMEOUT" instead of just having it enter the general failure noise. > This timeout is a band-aid and not real solution for the problem. This > arbitrary value doesn't take into account that the test(s) in that > particular directory (TARGET) could be running normally and working > through all the tests. Even something that looks like it's making progress may still be hung or won't finish in a reasonable amount of time. > We need some way to differentiate the two cases. I don't think it's unreasonable to declare that no test should take longer than some default amount of time that can be tweaked via a "settings" file. It gives the framework the option of easily removing tests that take "too long", etc. If the "timeout=..." value was made mandatory for each test directory, then the framework could actually filter based on expected worst-case run time. > > > To make this configurable (e.g. as needed in the "rtc" test case), > > > include a new per-test-directory "settings" file (similar to "config") > > > that can contain kselftest-specific settings. The first recognized field > > > is "timeout". > > > > > > > Seems good to me. I was also wondering whether this is actually > > reasonable to have tests running for so long. I wanted to discuss that > > at LPC but I missed the session. > > > > There is the individual test times and overall kselftest run time. We > have lots of tests now and it does take long. This patch seeks to implement a "timeout for a single test from kselftest's perspective". Some "individual" tests have many subtests (e.g. anything built with kselftest_harness.h) giving us the whole subtest issue. I think my solution here is a good middle ground: we specify the max run time for each executed test binary/script. It's not clear to me if a v2 is needed? Is this patch fine as-is? Thanks!
On 9/19/19 3:17 PM, Kees Cook wrote: > On Thu, Sep 19, 2019 at 02:09:37PM -0600, shuah wrote: >> On 9/19/19 12:55 PM, Alexandre Belloni wrote: >>> On 19/09/2019 11:06:44-0700, Kees Cook wrote: >>>> Commit a745f7af3cbd ("selftests/harness: Add 30 second timeout per >>>> test") solves the problem of kselftest_harness.h-using binary tests >>>> possibly hanging forever. However, scripts and other binaries can still >>>> hang forever. This adds a global timeout to each test script run. >>>> >> >> Timeout is good, but really tests should not hang. So we have to somehow >> indicate that the test needs to be fixed. > > Totally agreed, which is why I changed the reporting to call out a > "TIMEOUT" instead of just having it enter the general failure noise. > >> This timeout is a band-aid and not real solution for the problem. This >> arbitrary value doesn't take into account that the test(s) in that >> particular directory (TARGET) could be running normally and working >> through all the tests. > > Even something that looks like it's making progress may still be hung or > won't finish in a reasonable amount of time. > >> We need some way to differentiate the two cases. > > I don't think it's unreasonable to declare that no test should take > longer than some default amount of time that can be tweaked via a > "settings" file. It gives the framework the option of easily removing > tests that take "too long", etc. If the "timeout=..." value was made > mandatory for each test directory, then the framework could actually > filter based on expected worst-case run time. > >>>> To make this configurable (e.g. as needed in the "rtc" test case), >>>> include a new per-test-directory "settings" file (similar to "config") >>>> that can contain kselftest-specific settings. The first recognized field >>>> is "timeout". >>>> >>> >>> Seems good to me. I was also wondering whether this is actually >>> reasonable to have tests running for so long. I wanted to discuss that >>> at LPC but I missed the session. >>> >> >> There is the individual test times and overall kselftest run time. We >> have lots of tests now and it does take long. > > This patch seeks to implement a "timeout for a single test from > kselftest's perspective". Some "individual" tests have many subtests > (e.g. anything built with kselftest_harness.h) giving us the whole > subtest issue. I think my solution here is a good middle ground: we > specify the max run time for each executed test binary/script. > > It's not clear to me if a v2 is needed? Is this patch fine as-is? > > Thanks! > v1 is good. I will pull this in for testing. I do like the way it is done. thanks, -- Shuah
diff --git a/tools/testing/selftests/kselftest/runner.sh b/tools/testing/selftests/kselftest/runner.sh index 00c9020bdda8..84de7bc74f2c 100644 --- a/tools/testing/selftests/kselftest/runner.sh +++ b/tools/testing/selftests/kselftest/runner.sh @@ -3,9 +3,14 @@ # # Runs a set of tests in a given subdirectory. export skip_rc=4 +export timeout_rc=124 export logfile=/dev/stdout export per_test_logging= +# Defaults for "settings" file fields: +# "timeout" how many seconds to let each test run before failing. +export kselftest_default_timeout=45 + # There isn't a shell-agnostic way to find the path of a sourced file, # so we must rely on BASE_DIR being set to find other tools. if [ -z "$BASE_DIR" ]; then @@ -24,6 +29,16 @@ tap_prefix() fi } +tap_timeout() +{ + # Make sure tests will time out if utility is available. + if [ -x /usr/bin/timeout ] ; then + /usr/bin/timeout "$kselftest_timeout" "$1" + else + "$1" + fi +} + run_one() { DIR="$1" @@ -32,6 +47,18 @@ run_one() BASENAME_TEST=$(basename $TEST) + # Reset any "settings"-file variables. + export kselftest_timeout="$kselftest_default_timeout" + # Load per-test-directory kselftest "settings" file. + settings="$BASE_DIR/$DIR/settings" + if [ -r "$settings" ] ; then + while read line ; do + field=$(echo "$line" | cut -d= -f1) + value=$(echo "$line" | cut -d= -f2-) + eval "kselftest_$field"="$value" + done < "$settings" + fi + TEST_HDR_MSG="selftests: $DIR: $BASENAME_TEST" echo "# $TEST_HDR_MSG" if [ ! -x "$TEST" ]; then @@ -44,14 +71,17 @@ run_one() echo "not ok $test_num $TEST_HDR_MSG" else cd `dirname $TEST` > /dev/null - (((((./$BASENAME_TEST 2>&1; echo $? >&3) | + ((((( tap_timeout ./$BASENAME_TEST 2>&1; echo $? >&3) | tap_prefix >&4) 3>&1) | (read xs; exit $xs)) 4>>"$logfile" && echo "ok $test_num $TEST_HDR_MSG") || - (if [ $? -eq $skip_rc ]; then \ + (rc=$?; \ + if [ $rc -eq $skip_rc ]; then \ echo "not ok $test_num $TEST_HDR_MSG # SKIP" + elif [ $rc -eq $timeout_rc ]; then \ + echo "not ok $test_num $TEST_HDR_MSG # TIMEOUT" else - echo "not ok $test_num $TEST_HDR_MSG" + echo "not ok $test_num $TEST_HDR_MSG # exit=$rc" fi) cd - >/dev/null fi diff --git a/tools/testing/selftests/rtc/settings b/tools/testing/selftests/rtc/settings new file mode 100644 index 000000000000..ba4d85f74cd6 --- /dev/null +++ b/tools/testing/selftests/rtc/settings @@ -0,0 +1 @@ +timeout=90
Commit a745f7af3cbd ("selftests/harness: Add 30 second timeout per test") solves the problem of kselftest_harness.h-using binary tests possibly hanging forever. However, scripts and other binaries can still hang forever. This adds a global timeout to each test script run. To make this configurable (e.g. as needed in the "rtc" test case), include a new per-test-directory "settings" file (similar to "config") that can contain kselftest-specific settings. The first recognized field is "timeout". Additionally, this splits the reporting for timeouts into a specific "TIMEOUT" not-ok (and adds exit code reporting in the remaining case). Signed-off-by: Kees Cook <keescook@chromium.org> --- tools/testing/selftests/kselftest/runner.sh | 36 +++++++++++++++++++-- tools/testing/selftests/rtc/settings | 1 + 2 files changed, 34 insertions(+), 3 deletions(-) create mode 100644 tools/testing/selftests/rtc/settings