From fe9eeb847132dfce9d5f4a36a0f6492b19098f68 Mon Sep 17 00:00:00 2001 From: Marc Herbert Date: Mon, 6 Dec 2021 15:47:07 -0800 Subject: [PATCH 1/3] config.sh: remove KERNEL_CHECKPOINT and fix SOF_TEST_INTERVAL comments Pure comment changes, zero code change. Notably clarify that SOF_TEST_INTERVAL is not something that can be freely defined, it must reflect reality. Remove KERNEL_CHECKPOINT comment from config.sh because it's not something we want most users to mess with. Signed-off-by: Marc Herbert --- case-lib/config.sh | 19 +++++++++++-------- 1 file changed, 11 insertions(+), 8 deletions(-) diff --git a/case-lib/config.sh b/case-lib/config.sh index c07e9864..1479b0a5 100644 --- a/case-lib/config.sh +++ b/case-lib/config.sh @@ -19,11 +19,6 @@ declare -A TPLG_IGNORE_LST # shellcheck disable=SC2034 TPLG_IGNORE_LST['pcm']='HDA Digital' -# Will be set by the lib function, don't need to set -# Catches the last line of /var/log/kern.log, which will be used by -# sof-kernel-log-check. -# KERNEL_CHECKPOINT - # If not set will be automatically set by logging_ctl function # Test case log root # EXAMPLE: the log for test-case/check-ipc-flood.sh will be stored at @@ -63,7 +58,15 @@ SUDO_LEVEL=${SUDO_LEVEL:-} # # NO_BT_MODE=true -# Test interval between two test cases, the default value is 5 seconds -# in CI, which is controlled by sof-framework. In manual run, user can -# override the default value. +# SOF_TEST_INTERVAL informs sof-test of how long the external test +# runner waits between the end of one sof-test and the start of the next +# sof-test. sof-test uses this value to assign the corresponding kernel +# logs "no man's land" to the second test, which can be confusing (see +# for instance https://github.com/thesofproject/sof/issues/5032) but +# safer: it makes sure no kernel error escapes. +# See initial review in https://github.com/thesofproject/sof-test/pull/639 +# +# The default value must be 5s because 5s is the inter-test delay +# waited by the internal test runner used by sof/jenkins CI and that +# test runner does not define SOF_TEST_INTERVAL (internal bug 158) SOF_TEST_INTERVAL=${SOF_TEST_INTERVAL:-5} From ebf9babbaf1207973fb2baf66dca1fe173a046dd Mon Sep 17 00:00:00 2001 From: Marc Herbert Date: Mon, 6 Dec 2021 17:00:10 -0800 Subject: [PATCH 2/3] lib.sh: add 3 seconds to SOF_TEST_INTERVAL for our own delays SOF_TEST_INTERVAL is the "sleep" delay between the end of one sof-test and the start of the next one. However this does not account for our own delays collecting logs, which makes some bugs like https://github.com/thesofproject/sof/issues/5032 being caught semi-randomly. Err on the safe side and add 3 seconds for more determinism (this will of course never be completely deterministic). Signed-off-by: Marc Herbert --- case-lib/lib.sh | 9 ++++++--- 1 file changed, 6 insertions(+), 3 deletions(-) diff --git a/case-lib/lib.sh b/case-lib/lib.sh index 7c30b7ce..d7bc0075 100644 --- a/case-lib/lib.sh +++ b/case-lib/lib.sh @@ -42,9 +42,12 @@ fi setup_kernel_check_point() { - # Make the check point $SOF_TEST_INTERVAL second(s) earlier to avoid log loss. - # Note this may lead to an error caused by one test appear in the next one. - KERNEL_CHECKPOINT=$(($(date +%s) - SOF_TEST_INTERVAL)) + # Make the check point $SOF_TEST_INTERVAL second(s) earlier to avoid + # log loss. Note this may lead to an error caused by one test + # appear in the next one, see comments in config.sh. Add 3 extra + # second to account for our own, sof-test delays after PASS/FAIL + # decision: time spent collecting logs etc. + KERNEL_CHECKPOINT=$(($(date +%s) - SOF_TEST_INTERVAL - 3)) } # This function adds a fake error to dmesg (which is always saved by From f44b2286d0c9e2dd86c373a636c1524bf4901efe Mon Sep 17 00:00:00 2001 From: Marc Herbert Date: Mon, 6 Dec 2021 16:23:48 -0800 Subject: [PATCH 3/3] run-all-tests.sh: export SOF_TEST_INTERVAL It is necessary to inform sof-test otherwise some errors can be reported twice. Signed-off-by: Marc Herbert --- test-case/run-all-tests.sh | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/test-case/run-all-tests.sh b/test-case/run-all-tests.sh index 000ab3be..15aa9beb 100755 --- a/test-case/run-all-tests.sh +++ b/test-case/run-all-tests.sh @@ -95,7 +95,9 @@ main() while getopts "l:T:xh" OPTION; do case "$OPTION" in l) tests_length="$OPTARG" ;; - T) time_delay="$OPTARG" ;; + T) time_delay="$OPTARG" + export SOF_TEST_INTERVAL="$OPTARG" + ;; x) exit_first=true ;; *) usage; exit 1 ;; esac