RE: [PATCH] selftests/kselftest/runner.sh: Add 45 second timeout per test

[<Tim.Bird@sony.com>]

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