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

[Tim.Bird]

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