Merge pull request #8065 from edsantiago/flake_tweaks

Tests: Fix common flakes, and improve apiv2 test log

2 files changed, 26 insertions, 15 deletions

diff --git a/test/apiv2/01-basic.at b/test/apiv2/01-basic.at
index 9d4b04edb..f550d5fc3 100644
--- a/test/apiv2/01-basic.at
+++ b/test/apiv2/01-basic.at
@@ -59,7 +59,10 @@ t GET info 200                \
   .DefaultRuntime~.*$runtime  \
   .MemTotal~[0-9]\\+
 
-# Timing: make sure server stays responsive
+# Timing: make sure server stays responsive.
+# Because /info may need to check storage, it may be slow the first time.
+# Let's invoke it once to prime caches, then run ten queries in a timed loop.
+t GET info 200
 t0=$SECONDS
 for i in $(seq 1 10); do
     # FIXME: someday: refactor t(), separate out the 'curl' logic so we
@@ -70,7 +73,8 @@ t1=$SECONDS
 delta_t=$((t1 - t2))
 
 # Desired number of seconds in which we expect to run.
-want=7
+# FIXME: 10 seconds is a lot! PR #8076 opened to investigate why.
+want=10
 if [ $delta_t -le $want ]; then
     _show_ok 1 "Time for ten /info requests ($delta_t seconds) <= ${want}s"
 else
diff --git a/test/apiv2/test-apiv2 b/test/apiv2/test-apiv2
index 78325eb24..c8ca9df3f 100755
--- a/test/apiv2/test-apiv2
+++ b/test/apiv2/test-apiv2
@@ -179,7 +179,7 @@ function t() {
     # POST requests require an extra params arg
     if [[ $method = "POST" ]]; then
         curl_args="-d $(jsonify $1)"
-        testname="$testname [$1]"
+        testname="$testname [$curl_args]"
         shift
     fi
 
@@ -204,21 +204,30 @@ function t() {
     echo "-------------------------------------------------------------" >>$LOG
     echo "\$ $testname"                                                  >>$LOG
     rm -f $WORKDIR/curl.*
-    curl -s -X $method ${curl_args}                   \
-         -H 'Content-type: application/json'          \
-         --dump-header $WORKDIR/curl.headers.out       \
-         -o $WORKDIR/curl.result.out "$url"
-
-    if [[ $? -eq 7 ]]; then
-        echo "FATAL: curl failure on $url - cannot continue" >&2
+    # -s = silent, but --write-out 'format' gives us important response data
+    response=$(curl -s -X $method ${curl_args}                   \
+                    -H 'Content-type: application/json'          \
+                    --dump-header $WORKDIR/curl.headers.out       \
+                    --write-out '%{http_code}^%{content_type}^%{time_total}' \
+                    -o $WORKDIR/curl.result.out "$url")
+
+    # Any error from curl is instant bad news, from which we can't recover
+    rc=$?
+    if [[ $rc -ne 0 ]]; then
+        echo "FATAL: curl failure ($rc) on $url - cannot continue" >&2
         exit 1
     fi
 
-    cat $WORKDIR/curl.headers.out >>$LOG 2>/dev/null || true
+    # Show returned headers (without trailing ^M or empty lines) in log file.
+    # Sometimes -- I can't remember why! -- we don't get headers.
+    if [[ -e $WORKDIR/curl.headers.out ]]; then
+        tr -d '\015' < $WORKDIR/curl.headers.out | egrep '.' >>$LOG
+    fi
 
-    # Log results, if text. If JSON, filter through jq for readability.
-    content_type=$(sed -ne 's/^Content-Type:[ ]\+//pi' <$WORKDIR/curl.headers.out)
+    IFS='^' read actual_code content_type time_total <<<"$response"
+    printf "X-Response-Time: ${time_total}s\n\n" >>$LOG
 
+    # Log results, if text. If JSON, filter through jq for readability.
     if [[ $content_type =~ /octet ]]; then
         output="[$(file --brief $WORKDIR/curl.result.out)]"
         echo "$output" >>$LOG
@@ -233,10 +242,8 @@ function t() {
     fi
 
     # Test return code
-    actual_code=$(head -n1 $WORKDIR/curl.headers.out | awk '/^HTTP/ { print $2}')
     is "$actual_code" "$expected_code" "$testname : status"
 
-
     # Special case: 204/304, by definition, MUST NOT return content (rfc2616)
     if [[ $expected_code = 204 || $expected_code = 304 ]]; then
         if [ -n "$*" ]; then