From f9022b056b1d3226cd5c5914f6c8fdf8ebd767ec Mon Sep 17 00:00:00 2001 From: Gilles Peskine Date: Tue, 19 Oct 2021 16:25:10 +0200 Subject: [PATCH 1/5] Move some code of run_test into auxiliary functions No behavior change. Signed-off-by: Gilles Peskine --- tests/ssl-opt.sh | 237 +++++++++++++++++++++++++++-------------------- 1 file changed, 134 insertions(+), 103 deletions(-) diff --git a/tests/ssl-opt.sh b/tests/ssl-opt.sh index 724d62791..ce687f74f 100755 --- a/tests/ssl-opt.sh +++ b/tests/ssl-opt.sh @@ -723,68 +723,12 @@ find_in_both() { fi } -# Usage: run_test name [-p proxy_cmd] srv_cmd cli_cmd cli_exit [option [...]] -# Options: -s pattern pattern that must be present in server output -# -c pattern pattern that must be present in client output -# -u pattern lines after pattern must be unique in client output -# -f call shell function on client output -# -S pattern pattern that must be absent in server output -# -C pattern pattern that must be absent in client output -# -U pattern lines after pattern must be unique in server output -# -F call shell function on server output -# -g call shell function on server and client output -run_test() { - NAME="$1" - shift 1 - - if is_excluded "$NAME"; then - SKIP_NEXT="NO" - # There was no request to run the test, so don't record its outcome. - return - fi - - print_name "$NAME" - - # Do we only run numbered tests? - if [ -n "$RUN_TEST_NUMBER" ]; then - case ",$RUN_TEST_NUMBER," in - *",$TESTS,"*) :;; - *) SKIP_NEXT="YES";; - esac - fi - - # does this test use a proxy? - if [ "X$1" = "X-p" ]; then - PXY_CMD="$2" - shift 2 - else - PXY_CMD="" - fi - - # get commands and client output - SRV_CMD="$1" - CLI_CMD="$2" - CLI_EXPECT="$3" - shift 3 - - # Check if test uses files - case "$SRV_CMD $CLI_CMD" in - *data_files/*) - requires_config_enabled MBEDTLS_FS_IO;; - esac - - # If the client or serve requires a ciphersuite, check that it's enabled. - maybe_requires_ciphersuite_enabled "$SRV_CMD" "$@" - maybe_requires_ciphersuite_enabled "$CLI_CMD" "$@" - - # should we skip? - if [ "X$SKIP_NEXT" = "XYES" ]; then - SKIP_NEXT="NO" - record_outcome "SKIP" - SKIPS=$(( $SKIPS + 1 )) - return - fi - +# Analyze the commands that will be used in a test. +# +# Analyze and possibly instrument $PXY_CMD, $CLI_CMD, $SRV_CMD to pass +# extra arguments or go through wrappers. +# Set $DTLS (0=TLS, 1=DTLS). +analyze_test_commands() { # update DTLS variable detect_dtls "$SRV_CMD" @@ -838,48 +782,21 @@ run_test() { CLI_CMD="valgrind --leak-check=full $CLI_CMD" fi fi +} - TIMES_LEFT=2 - while [ $TIMES_LEFT -gt 0 ]; do - TIMES_LEFT=$(( $TIMES_LEFT - 1 )) - - # run the commands - if [ -n "$PXY_CMD" ]; then - printf "# %s\n%s\n" "$NAME" "$PXY_CMD" > $PXY_OUT - $PXY_CMD >> $PXY_OUT 2>&1 & - PXY_PID=$! - wait_proxy_start "$PXY_PORT" "$PXY_PID" - fi - - check_osrv_dtls - printf '# %s\n%s\n' "$NAME" "$SRV_CMD" > $SRV_OUT - provide_input | $SRV_CMD >> $SRV_OUT 2>&1 & - SRV_PID=$! - wait_server_start "$SRV_PORT" "$SRV_PID" - - printf '# %s\n%s\n' "$NAME" "$CLI_CMD" > $CLI_OUT - eval "$CLI_CMD" >> $CLI_OUT 2>&1 & - wait_client_done - - sleep 0.05 - - # terminate the server (and the proxy) - kill $SRV_PID - wait $SRV_PID - SRV_RET=$? - - if [ -n "$PXY_CMD" ]; then - kill $PXY_PID >/dev/null 2>&1 - wait $PXY_PID - fi - - # retry only on timeouts - if grep '===CLIENT_TIMEOUT===' $CLI_OUT >/dev/null; then - printf "RETRY " - else - TIMES_LEFT=0 - fi - done +# Check for failure conditions after a test case. +# +# Inputs from run_test: +# * positional parameters: test options (see run_test documentation) +# * $CLI_EXIT: client return code +# * $CLI_EXPECT: expected client return code +# * $SRV_RET: server return code +# * $CLI_OUT, $SRV_OUT, $PXY_OUT: files containing client/server/proxy logs +# +# Outputs: +# * $pass: set to 1 if no failures are detected, 0 otherwise +check_test_failure() { + pass=0 # check if the client and server went at least to the handshake stage # (useful to avoid tests with only negative assertions and non-zero @@ -1009,6 +926,120 @@ run_test() { fi # if we're here, everything is ok + pass=1 +} + +# Usage: run_test name [-p proxy_cmd] srv_cmd cli_cmd cli_exit [option [...]] +# Options: -s pattern pattern that must be present in server output +# -c pattern pattern that must be present in client output +# -u pattern lines after pattern must be unique in client output +# -f call shell function on client output +# -S pattern pattern that must be absent in server output +# -C pattern pattern that must be absent in client output +# -U pattern lines after pattern must be unique in server output +# -F call shell function on server output +# -g call shell function on server and client output +run_test() { + NAME="$1" + shift 1 + + if is_excluded "$NAME"; then + SKIP_NEXT="NO" + # There was no request to run the test, so don't record its outcome. + return + fi + + print_name "$NAME" + + # Do we only run numbered tests? + if [ -n "$RUN_TEST_NUMBER" ]; then + case ",$RUN_TEST_NUMBER," in + *",$TESTS,"*) :;; + *) SKIP_NEXT="YES";; + esac + fi + + # does this test use a proxy? + if [ "X$1" = "X-p" ]; then + PXY_CMD="$2" + shift 2 + else + PXY_CMD="" + fi + + # get commands and client output + SRV_CMD="$1" + CLI_CMD="$2" + CLI_EXPECT="$3" + shift 3 + + # Check if test uses files + case "$SRV_CMD $CLI_CMD" in + *data_files/*) + requires_config_enabled MBEDTLS_FS_IO;; + esac + + # If the client or serve requires a ciphersuite, check that it's enabled. + maybe_requires_ciphersuite_enabled "$SRV_CMD" "$@" + maybe_requires_ciphersuite_enabled "$CLI_CMD" "$@" + + # should we skip? + if [ "X$SKIP_NEXT" = "XYES" ]; then + SKIP_NEXT="NO" + record_outcome "SKIP" + SKIPS=$(( $SKIPS + 1 )) + return + fi + + analyze_test_commands "$@" + + TIMES_LEFT=2 + while [ $TIMES_LEFT -gt 0 ]; do + TIMES_LEFT=$(( $TIMES_LEFT - 1 )) + + # run the commands + if [ -n "$PXY_CMD" ]; then + printf "# %s\n%s\n" "$NAME" "$PXY_CMD" > $PXY_OUT + $PXY_CMD >> $PXY_OUT 2>&1 & + PXY_PID=$! + wait_proxy_start "$PXY_PORT" "$PXY_PID" + fi + + check_osrv_dtls + printf '# %s\n%s\n' "$NAME" "$SRV_CMD" > $SRV_OUT + provide_input | $SRV_CMD >> $SRV_OUT 2>&1 & + SRV_PID=$! + wait_server_start "$SRV_PORT" "$SRV_PID" + + printf '# %s\n%s\n' "$NAME" "$CLI_CMD" > $CLI_OUT + eval "$CLI_CMD" >> $CLI_OUT 2>&1 & + wait_client_done + + sleep 0.05 + + # terminate the server (and the proxy) + kill $SRV_PID + wait $SRV_PID + SRV_RET=$? + + if [ -n "$PXY_CMD" ]; then + kill $PXY_PID >/dev/null 2>&1 + wait $PXY_PID + fi + + # retry only on timeouts + if grep '===CLIENT_TIMEOUT===' $CLI_OUT >/dev/null; then + printf "RETRY " + else + TIMES_LEFT=0 + fi + done + + check_test_failure "$@" + if [ "$pass" -eq 0 ]; then + return + fi + record_outcome "PASS" if [ "$PRESERVE_LOGS" -gt 0 ]; then mv $SRV_OUT o-srv-${TESTS}.log From 5d8e702ab85ac316a4c9e08fe2fd22cc43f71278 Mon Sep 17 00:00:00 2001 From: Gilles Peskine Date: Tue, 19 Oct 2021 16:35:35 +0200 Subject: [PATCH 2/5] Move the core loop of run_test into an auxiliary function No behavior change. Signed-off-by: Gilles Peskine --- tests/ssl-opt.sh | 73 +++++++++++++++++++++++++++++------------------- 1 file changed, 44 insertions(+), 29 deletions(-) diff --git a/tests/ssl-opt.sh b/tests/ssl-opt.sh index ce687f74f..b9d69fcea 100755 --- a/tests/ssl-opt.sh +++ b/tests/ssl-opt.sh @@ -929,6 +929,49 @@ check_test_failure() { pass=1 } +# Run the current test case: start the server and if applicable the proxy, run +# the client, wait for all processes to finish or time out. +# +# Inputs: +# * $NAME: test case name +# * $CLI_CMD, $SRV_CMD, $PXY_CMD: commands to run +# * $CLI_OUT, $SRV_OUT, $PXY_OUT: files to contain client/server/proxy logs +# +# Outputs: +# * $CLI_EXIT: client return code +# * $SRV_RET: server return code +do_run_test_once() { + # run the commands + if [ -n "$PXY_CMD" ]; then + printf "# %s\n%s\n" "$NAME" "$PXY_CMD" > $PXY_OUT + $PXY_CMD >> $PXY_OUT 2>&1 & + PXY_PID=$! + wait_proxy_start "$PXY_PORT" "$PXY_PID" + fi + + check_osrv_dtls + printf '# %s\n%s\n' "$NAME" "$SRV_CMD" > $SRV_OUT + provide_input | $SRV_CMD >> $SRV_OUT 2>&1 & + SRV_PID=$! + wait_server_start "$SRV_PORT" "$SRV_PID" + + printf '# %s\n%s\n' "$NAME" "$CLI_CMD" > $CLI_OUT + eval "$CLI_CMD" >> $CLI_OUT 2>&1 & + wait_client_done + + sleep 0.05 + + # terminate the server (and the proxy) + kill $SRV_PID + wait $SRV_PID + SRV_RET=$? + + if [ -n "$PXY_CMD" ]; then + kill $PXY_PID >/dev/null 2>&1 + wait $PXY_PID + fi +} + # Usage: run_test name [-p proxy_cmd] srv_cmd cli_cmd cli_exit [option [...]] # Options: -s pattern pattern that must be present in server output # -c pattern pattern that must be present in client output @@ -997,35 +1040,7 @@ run_test() { while [ $TIMES_LEFT -gt 0 ]; do TIMES_LEFT=$(( $TIMES_LEFT - 1 )) - # run the commands - if [ -n "$PXY_CMD" ]; then - printf "# %s\n%s\n" "$NAME" "$PXY_CMD" > $PXY_OUT - $PXY_CMD >> $PXY_OUT 2>&1 & - PXY_PID=$! - wait_proxy_start "$PXY_PORT" "$PXY_PID" - fi - - check_osrv_dtls - printf '# %s\n%s\n' "$NAME" "$SRV_CMD" > $SRV_OUT - provide_input | $SRV_CMD >> $SRV_OUT 2>&1 & - SRV_PID=$! - wait_server_start "$SRV_PORT" "$SRV_PID" - - printf '# %s\n%s\n' "$NAME" "$CLI_CMD" > $CLI_OUT - eval "$CLI_CMD" >> $CLI_OUT 2>&1 & - wait_client_done - - sleep 0.05 - - # terminate the server (and the proxy) - kill $SRV_PID - wait $SRV_PID - SRV_RET=$? - - if [ -n "$PXY_CMD" ]; then - kill $PXY_PID >/dev/null 2>&1 - wait $PXY_PID - fi + do_run_test_once # retry only on timeouts if grep '===CLIENT_TIMEOUT===' $CLI_OUT >/dev/null; then From a28fd41ed12d0062adc9dfa43ac476804f914a86 Mon Sep 17 00:00:00 2001 From: Gilles Peskine Date: Tue, 19 Oct 2021 17:23:25 +0200 Subject: [PATCH 3/5] Move retry logic into check_test_failure This will allow having other retry conditions, in particular based on run_test options. Signed-off-by: Gilles Peskine --- tests/ssl-opt.sh | 32 ++++++++++++++++++-------------- 1 file changed, 18 insertions(+), 14 deletions(-) diff --git a/tests/ssl-opt.sh b/tests/ssl-opt.sh index b9d69fcea..c93154b5f 100755 --- a/tests/ssl-opt.sh +++ b/tests/ssl-opt.sh @@ -792,11 +792,19 @@ analyze_test_commands() { # * $CLI_EXPECT: expected client return code # * $SRV_RET: server return code # * $CLI_OUT, $SRV_OUT, $PXY_OUT: files containing client/server/proxy logs +# * $TIMES_LEFT: if nonzero, a RETRY outcome is allowed # # Outputs: -# * $pass: set to 1 if no failures are detected, 0 otherwise +# * $outcome: one of PASS/RETRY/FAIL check_test_failure() { - pass=0 + outcome=FAIL + + if [ $TIMES_LEFT -gt 0 ] && + grep '===CLIENT_TIMEOUT===' $CLI_OUT >/dev/null + then + outcome=RETRY + return + fi # check if the client and server went at least to the handshake stage # (useful to avoid tests with only negative assertions and non-zero @@ -926,7 +934,7 @@ check_test_failure() { fi # if we're here, everything is ok - pass=1 + outcome=PASS } # Run the current test case: start the server and if applicable the proxy, run @@ -1042,19 +1050,15 @@ run_test() { do_run_test_once - # retry only on timeouts - if grep '===CLIENT_TIMEOUT===' $CLI_OUT >/dev/null; then - printf "RETRY " - else - TIMES_LEFT=0 - fi + check_test_failure "$@" + case $outcome in + PASS) break;; + RETRY) printf "RETRY ";; + FAIL) return;; + esac done - check_test_failure "$@" - if [ "$pass" -eq 0 ]; then - return - fi - + # If we get this far, the test case passed. record_outcome "PASS" if [ "$PRESERVE_LOGS" -gt 0 ]; then mv $SRV_OUT o-srv-${TESTS}.log From 2d3c9f898b3d350b1e5d1a596039d74e0c6f735b Mon Sep 17 00:00:00 2001 From: Gilles Peskine Date: Tue, 19 Oct 2021 18:00:10 +0200 Subject: [PATCH 4/5] Retry if a test case fails because of an unexpected resend Palliative for https://github.com/ARMmbed/mbedtls/issues/3377. If a test case fails due to an unexpected resend, allow retrying, like in the case of a client timeout. Signed-off-by: Gilles Peskine --- tests/ssl-opt.sh | 18 +++++++++++++----- 1 file changed, 13 insertions(+), 5 deletions(-) diff --git a/tests/ssl-opt.sh b/tests/ssl-opt.sh index c93154b5f..25a33db93 100755 --- a/tests/ssl-opt.sh +++ b/tests/ssl-opt.sh @@ -795,14 +795,14 @@ analyze_test_commands() { # * $TIMES_LEFT: if nonzero, a RETRY outcome is allowed # # Outputs: -# * $outcome: one of PASS/RETRY/FAIL +# * $outcome: one of PASS/RETRY*/FAIL check_test_failure() { outcome=FAIL if [ $TIMES_LEFT -gt 0 ] && grep '===CLIENT_TIMEOUT===' $CLI_OUT >/dev/null then - outcome=RETRY + outcome="RETRY(client-timeout)" return fi @@ -863,14 +863,22 @@ check_test_failure() { "-S") if grep -v '^==' $SRV_OUT | grep -v 'Serious error when reading debug info' | grep "$2" >/dev/null; then - fail "pattern '$2' MUST NOT be present in the Server output" + if [ "$2" = "resend" ] && [ $TIMES_LEFT -gt 0 ]; then + outcome="RETRY(resend)" + else + fail "pattern '$2' MUST NOT be present in the Server output" + fi return fi ;; "-C") if grep -v '^==' $CLI_OUT | grep -v 'Serious error when reading debug info' | grep "$2" >/dev/null; then - fail "pattern '$2' MUST NOT be present in the Client output" + if [ "$2" = "resend" ] && [ $TIMES_LEFT -gt 0 ]; then + outcome="RETRY(resend)" + else + fail "pattern '$2' MUST NOT be present in the Client output" + fi return fi ;; @@ -1053,7 +1061,7 @@ run_test() { check_test_failure "$@" case $outcome in PASS) break;; - RETRY) printf "RETRY ";; + RETRY*) printf "$outcome ";; FAIL) return;; esac done From aa1d6ad9d266d5ee4bb76b0c2bb60a6b47341ffe Mon Sep 17 00:00:00 2001 From: Gilles Peskine Date: Wed, 20 Oct 2021 14:17:02 +0200 Subject: [PATCH 5/5] Move is-it-resend logic into a function Improve the code structure in case we want to add other similar conditions later. Document better what we're doing, and document why we're doing it. Signed-off-by: Gilles Peskine --- tests/ssl-opt.sh | 34 ++++++++++++++++++++++++++++------ 1 file changed, 28 insertions(+), 6 deletions(-) diff --git a/tests/ssl-opt.sh b/tests/ssl-opt.sh index 25a33db93..fec9776fd 100755 --- a/tests/ssl-opt.sh +++ b/tests/ssl-opt.sh @@ -485,6 +485,32 @@ record_outcome() { fi } +# True if the presence of the given pattern in a log definitely indicates +# that the test has failed. False if the presence is inconclusive. +# +# Inputs: +# * $1: pattern found in the logs +# * $TIMES_LEFT: >0 if retrying is an option +# +# Outputs: +# * $outcome: set to a retry reason if the pattern is inconclusive, +# unchanged otherwise. +# * Return value: 1 if the pattern is inconclusive, +# 0 if the failure is definitive. +log_pattern_presence_is_conclusive() { + # If we've run out of attempts, then don't retry no matter what. + if [ $TIMES_LEFT -eq 0 ]; then + return 0 + fi + case $1 in + "resend") + # An undesired resend may have been caused by the OS dropping or + # delaying a packet at an inopportune time. + outcome="RETRY(resend)" + return 1;; + esac +} + # fail fail() { record_outcome "FAIL" "$1" @@ -863,9 +889,7 @@ check_test_failure() { "-S") if grep -v '^==' $SRV_OUT | grep -v 'Serious error when reading debug info' | grep "$2" >/dev/null; then - if [ "$2" = "resend" ] && [ $TIMES_LEFT -gt 0 ]; then - outcome="RETRY(resend)" - else + if log_pattern_presence_is_conclusive "$2"; then fail "pattern '$2' MUST NOT be present in the Server output" fi return @@ -874,9 +898,7 @@ check_test_failure() { "-C") if grep -v '^==' $CLI_OUT | grep -v 'Serious error when reading debug info' | grep "$2" >/dev/null; then - if [ "$2" = "resend" ] && [ $TIMES_LEFT -gt 0 ]; then - outcome="RETRY(resend)" - else + if log_pattern_presence_is_conclusive "$2"; then fail "pattern '$2' MUST NOT be present in the Client output" fi return