Received-SPF: pass (google.com: best guess record for domain of linux-kernel-owner@vger.kernel.org designates 209.132.180.67 as permitted sender) client-ip=209.132.180.67;
Received-SPF: Pass (protection.outlook.com: domain of sony.com designates
 160.33.194.230 as permitted sender) receiver=protection.outlook.com;
 client-ip=160.33.194.230; helo=usculsndmail03v.am.sony.com;
From:   <Tim.Bird@sony.com>
To:     <keescook@chromium.org>, <shuah@kernel.org>
CC:     <anders.roxell@linaro.org>, <alexandre.belloni@bootlin.com>,
        <linux-kernel@vger.kernel.org>, <linux-kselftest@vger.kernel.org>
Subject: RE: [PATCH] selftests/kselftest/runner.sh: Add 45 second timeout
 per test
Thread-Topic: [PATCH] selftests/kselftest/runner.sh: Add 45 second timeout
 per test
Thread-Index: AQHVbxUXsNEjsnpJkUeVTYYfiT5hwaczb7LQ
Date:   Thu, 19 Sep 2019 20:41:42 +0000
Message-ID: <ECADFF3FD767C149AD96A924E7EA6EAF977BA636@USCULXMSG01.am.sony.com>
References: <201909191102.97FA56072@keescook>
In-Reply-To: <201909191102.97FA56072@keescook>
Accept-Language: en-US
Content-Language: en-US
Content-Type: text/plain; charset="us-ascii"
Content-Transfer-Encoding: quoted-printable
MIME-Version: 1.0
X-MS-Exchange-CrossTenant-OriginalArrivalTime: 19 Sep 2019 20:41:47.9602
 (UTC)
X-MS-Exchange-CrossTenant-Network-Message-Id: bd409794-57be-4668-3c91-08d73d41cac8
X-MS-Exchange-CrossTenant-Id: 66c65d8a-9158-4521-a2d8-664963db48e4
X-MS-Exchange-CrossTenant-OriginalAttributedTenantConnectingIp: TenantId=66c65d8a-9158-4521-a2d8-664963db48e4;Ip=[160.33.194.230];Helo=[usculsndmail03v.am.sony.com]
X-MS-Exchange-CrossTenant-FromEntityHeader: HybridOnPrem
X-MS-Exchange-Transport-CrossTenantHeadersStamped: DM5PR13MB1179
Sender: linux-kernel-owner@vger.kernel.org
Precedence: bulk
List-ID: <linux-kernel.vger.kernel.org>
X-Mailing-List: linux-kernel@vger.kernel.org


> -----Original Message-----
> From: Kees Cook
>=20
> 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.
>=20
> 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 interpret=
ation
that would be beneficial for both CI systems (using them to control test in=
vocations 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:=20
https://lists.yoctoproject.org/pipermail/automated-testing/2019-August/0004=
71.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 conceptual=
ly
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 unive=
rsally
used by all CI runners I'm aware of to indicate the test timeout value.  Bu=
t
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.

>=20
> Additionally, this splits the reporting for timeouts into a specific
> "TIMEOUT" not-ok (and adds exit code reporting in the remaining case).
>=20
> 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
>=20
> 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=3D4
> +export timeout_rc=3D124
what are the units here?  I presume seconds?

>  export logfile=3D/dev/stdout
>  export per_test_logging=3D
>=20
> +# Defaults for "settings" file fields:
> +# "timeout" how many seconds to let each test run before failing.
> +export kselftest_default_timeout=3D45
> +
>  # 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
>  }
>=20
> +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=3D"$1"
> @@ -32,6 +47,18 @@ run_one()
>=20
>  	BASENAME_TEST=3D$(basename $TEST)
>=20
> +	# Reset any "settings"-file variables.
> +	export kselftest_timeout=3D"$kselftest_default_timeout"
> +	# Load per-test-directory kselftest "settings" file.
> +	settings=3D"$BASE_DIR/$DIR/settings"
> +	if [ -r "$settings" ] ; then
> +		while read line ; do
> +			field=3D$(echo "$line" | cut -d=3D -f1)
> +			value=3D$(echo "$line" | cut -d=3D -f2-)
> +			eval "kselftest_$field"=3D"$value"
> +		done < "$settings"
> +	fi
> +
>  	TEST_HDR_MSG=3D"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=3D$?;	\
> +		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 i=
n 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=3D$rc"
Is this also something new to kselftest's TAP output that should be documen=
ted?

>  		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=3D90

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