Tests: Fix common flakes, and improve apiv2 test log

- apiv2 - the 'ten /info requests' test is flaking often,
  taking ~8 seconds (our limit is 7, up from 5 a few weeks
  ago). Brent suggested that the first /info call might be
  expensive, because it needs to access storage. So, let's
  prime it by running one /info outside the timing loop.
  And, because even that continues to fail, bump it up
  to 10 seconds and file #8076 to track the slowdown.

- toolbox test - WaitForReady() has timed out, even on one
  occasion causing a run failure because it failed 3 times.
  Solution: bump up timeout from 2s to 5s. Not really great,
  but CI systems are underpowered, and it's not unreasonable
  that 2s might be too low.

- sdnotify test - add a 'podman wait' between stop & rm.
  This may prevent a "cannot rm container as it is running"
  race condition.

While working on this, Brent and I noticed a few ways that
test-apiv2 logging can be improved:

- test name: when request is POST, display the jsonified
  parameters, not the original input ones. This should
  make it much easier to reproduce failures.

- use curl's "--write-out" option to capture http code,
  content type, and request time. We were getting the
  first two via grep from logged headers; this is cleaner.
  And there was no other way to get timing. We now include
  the timing as X-Response-Time in the log file.

- abort on *any* curl error, not just 7 (cannot connect).
  Any error at all from curl is bad news.

Signed-off-by: Ed Santiago <santiago@redhat.com>

1 files changed, 6 insertions, 2 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