test: make sd-journal-gatewayd tests even more debug-able

Unfortunately bfd30e8af6 is not enough and the test fails, that still
occasionally occur, don't provide enough information to see what's
wrong. Let's rework the test a little to improve this, namely:

  - redirect curl's output into a temporary file instead of piping it
    directly into the "check" expression; that way we can simply dump
    the temporary file when the test fails, providing potentially
    crucial information. We don't want to always dump everything to
    stdout, as some of the tests request an entire system journal (note
    that shell redirection instead of `curl -o file` is used
    intentionally, so the output file is always nuked first)
  - by dropping the pipes in curl commands we can re-enable pipefail
  - also, split some very long commands to multiple lines to (slightly)
    improve readability

Follow-up for bfd30e8af64a0d39ad110258dca69be919f6df34.

diff --git a/test/units/testsuite-04.journal-gatewayd.sh b/test/units/testsuite-04.journal-gatewayd.sh
index 4bd3c79a4de22b42505e3f02315ad59d670d168a..9c7a3d05bb3dc197be220b152e8c0e0f3014575a 100755 (executable)
--- a/test/units/testsuite-04.journal-gatewayd.sh
+++ b/test/units/testsuite-04.journal-gatewayd.sh
@@ -1,13 +1,28 @@
 #!/usr/bin/env bash
 # SPDX-License-Identifier: LGPL-2.1-or-later
 set -eux
-# pipefail is disabled intentionally, as `curl | grep -q` is very SIGPIPE happy
+set -o pipefail
 
 if [[ ! -x /usr/lib/systemd/systemd-journal-gatewayd ]]; then
     echo "Built without systemd-journal-gatewayd support, skipping the test"
     exit 0
 fi
 
+LOG_FILE="$(mktemp)"
+
+at_exit() {
+    if [[ $? -ne 0 ]]; then
+        # The $LOG_FILE is potentially huge (as it might be a full copy of the current journal), so let's
+        # dump it at debug level under a specific syslog tag, so it's clearly separated from the actual test
+        # journal; things get very confusing otherwise.
+        systemd-cat -t log-file-dump -p debug cat "$LOG_FILE"
+    fi
+
+    rm -f "$LOG_FILE"
+}
+
+trap at_exit EXIT
+
 TEST_MESSAGE="-= This is a test message $RANDOM =-"
 TEST_TAG="$(systemd-id128 new)"
 
@@ -27,38 +42,56 @@ systemctl start systemd-journal-gatewayd.socket
 
 # /browse
 # We should get redirected to /browse by default
-curl -LSfs http://localhost:19531 | grep -F "<title>Journal</title>" >/dev/null
-curl -LSfs http://localhost:19531/browse | grep -F "<title>Journal</title>" >/dev/null
+curl -LSfs http://localhost:19531 >"$LOG_FILE"
+grep -qF "<title>Journal</title>" "$LOG_FILE"
+curl -LSfs http://localhost:19531/browse >"$LOG_FILE"
+grep -qF "<title>Journal</title>" "$LOG_FILE"
 (! curl -LSfs http://localhost:19531/foo/bar/baz)
 (! curl -LSfs http://localhost:19531/foo/../../../bar/../baz)
 
 # /entries
 # Accept: text/plain should be the default
-curl -LSfs http://localhost:19531/entries | \
-    grep -E " $TEST_TAG\[[0-9]+\]: $TEST_MESSAGE" >/dev/null
-curl -LSfs --header "Accept: text/plain" http://localhost:19531/entries | \
-    grep -E " $TEST_TAG\[[0-9]+\]: $TEST_MESSAGE" >/dev/null
-curl -LSfs --header "Accept: application/json" http://localhost:19531/entries | \
-    jq -se ".[] | select(.MESSAGE == \"$TEST_MESSAGE\")"
-curl -LSfs --header "Accept: application/json" http://localhost:19531/entries?boot | \
-    jq -se ".[] | select(.MESSAGE == \"$TEST_MESSAGE\")"
-curl -LSfs --header "Accept: application/json" http://localhost:19531/entries?SYSLOG_IDENTIFIER="$TEST_TAG" | \
-    jq -se "length == 1 and select(.[].MESSAGE == \"$TEST_MESSAGE\")"
+curl -LSfs http://localhost:19531/entries >"$LOG_FILE"
+grep -qE " $TEST_TAG\[[0-9]+\]: $TEST_MESSAGE" "$LOG_FILE"
+curl -LSfs --header "Accept: text/plain" http://localhost:19531/entries >"$LOG_FILE"
+grep -qE " $TEST_TAG\[[0-9]+\]: $TEST_MESSAGE" "$LOG_FILE"
+curl -LSfs --header "Accept: application/json" http://localhost:19531/entries >"$LOG_FILE"
+jq -se ".[] | select(.MESSAGE == \"$TEST_MESSAGE\")" "$LOG_FILE"
+curl -LSfs --header "Accept: application/json" http://localhost:19531/entries?boot >"$LOG_FILE"
+jq -se ".[] | select(.MESSAGE == \"$TEST_MESSAGE\")" "$LOG_FILE"
+curl -LSfs --header "Accept: application/json" http://localhost:19531/entries?SYSLOG_IDENTIFIER="$TEST_TAG" >"$LOG_FILE"
+jq -se "length == 1 and select(.[].MESSAGE == \"$TEST_MESSAGE\")" "$LOG_FILE"
 # Show 10 entries starting from $BOOT_CURSOR, skip the first 5
-curl -LSfs --header "Accept: application/json" --header "Range: entries=$BOOT_CURSOR:5:10" http://localhost:19531/entries | \
-    jq -se "length == 10"
+curl -LSfs \
+     --header "Accept: application/json" \
+     --header "Range: entries=$BOOT_CURSOR:5:10" \
+     http://localhost:19531/entries >"$LOG_FILE"
+jq -se "length == 10" "$LOG_FILE"
 # Check if the specified cursor refers to an existing entry and return just that entry
-curl -LSfs --header "Accept: application/json" --header "Range: entries=$TEST_CURSOR" http://localhost:19531/entries?discrete | \
-    jq -se "length == 1 and select(.[].MESSAGE == \"$TEST_MESSAGE\")"
+curl -LSfs \
+     --header "Accept: application/json" \
+     --header "Range: entries=$TEST_CURSOR" \
+     http://localhost:19531/entries?discrete >"$LOG_FILE"
+jq -se "length == 1 and select(.[].MESSAGE == \"$TEST_MESSAGE\")" "$LOG_FILE"
 # Check entry is present (resp. absent) when filtering by timestamp
-curl -LSfs --header "Range: realtime=$BEFORE_TIMESTAMP:" http://localhost:19531/entries?SYSLOG_IDENTIFIER="$TEST_TAG" | \
-    grep -E " $TEST_TAG\[[0-9]+\]: $TEST_MESSAGE" >/dev/null
-curl -LSfs --header "Range: realtime=:$AFTER_TIMESTAMP" http://localhost:19531/entries?SYSLOG_IDENTIFIER="$TEST_TAG" | \
-    grep -E " $TEST_TAG\[[0-9]+\]: $TEST_MESSAGE" >/dev/null
-curl -LSfs --header "Accept: application/json" --header "Range: realtime=:$BEFORE_TIMESTAMP" http://localhost:19531/entries?SYSLOG_IDENTIFIER="$TEST_TAG" | \
-    jq -se "length == 0"
-curl -LSfs --header "Accept: application/json" --header "Range: realtime=$AFTER_TIMESTAMP:" http://localhost:19531/entries?SYSLOG_IDENTIFIER="$TEST_TAG" | \
-    jq -se "length == 0"
+curl -LSfs \
+     --header "Range: realtime=$BEFORE_TIMESTAMP:" \
+     http://localhost:19531/entries?SYSLOG_IDENTIFIER="$TEST_TAG" >"$LOG_FILE"
+grep -qE " $TEST_TAG\[[0-9]+\]: $TEST_MESSAGE" "$LOG_FILE"
+curl -LSfs \
+     --header "Range: realtime=:$AFTER_TIMESTAMP" \
+     http://localhost:19531/entries?SYSLOG_IDENTIFIER="$TEST_TAG" >"$LOG_FILE"
+grep -qE " $TEST_TAG\[[0-9]+\]: $TEST_MESSAGE" "$LOG_FILE"
+curl -LSfs \
+     --header "Accept: application/json" \
+     --header "Range: realtime=:$BEFORE_TIMESTAMP" \
+     http://localhost:19531/entries?SYSLOG_IDENTIFIER="$TEST_TAG" >"$LOG_FILE"
+jq -se "length == 0" "$LOG_FILE"
+curl -LSfs \
+     --header "Accept: application/json" \
+     --header "Range: realtime=$AFTER_TIMESTAMP:" \
+     http://localhost:19531/entries?SYSLOG_IDENTIFIER="$TEST_TAG" >"$LOG_FILE"
+jq -se "length == 0" "$LOG_FILE"
 # Check positive and negative skip when filtering by timestamp
 echo "-= This is a second test message =-" | systemd-cat -t "$TEST_TAG"
 journalctl --sync
@@ -67,19 +100,25 @@ echo "-= This is a third test message =-" | systemd-cat -t "$TEST_TAG"
 journalctl --sync
 sleep 1
 END_TIMESTAMP="$(date +%s)"
-curl -LSfs --header "Accept: application/json" --header "Range: realtime=$BEFORE_TIMESTAMP::1:1" http://localhost:19531/entries?SYSLOG_IDENTIFIER="$TEST_TAG" | \
-    jq -se "length == 1 and select(.[].__CURSOR == \"$TEST2_CURSOR\")"
-curl -LSfs --header "Accept: application/json" --header "Range: realtime=$END_TIMESTAMP::-1:1" http://localhost:19531/entries?SYSLOG_IDENTIFIER="$TEST_TAG" | \
-    jq -se "length == 1 and select(.[].__CURSOR == \"$TEST2_CURSOR\")"
+curl -LSfs \
+     --header "Accept: application/json" \
+     --header "Range: realtime=$BEFORE_TIMESTAMP::1:1" \
+     http://localhost:19531/entries?SYSLOG_IDENTIFIER="$TEST_TAG" >"$LOG_FILE"
+jq -se "length == 1 and select(.[].__CURSOR == \"$TEST2_CURSOR\")" "$LOG_FILE"
+curl -LSfs \
+     --header "Accept: application/json" \
+     --header "Range: realtime=$END_TIMESTAMP::-1:1" \
+     http://localhost:19531/entries?SYSLOG_IDENTIFIER="$TEST_TAG" >"$LOG_FILE"
+jq -se "length == 1 and select(.[].__CURSOR == \"$TEST2_CURSOR\")" "$LOG_FILE"
 
 # No idea how to properly parse this (jq won't cut it), so let's at least do some sanity checks that every
 # line is either empty or begins with data:
-curl -LSfs --header "Accept: text/event-stream" http://localhost:19531/entries | \
-    awk '!/^(data: \{.+\}|)$/ { exit 1; }'
+curl -LSfs --header "Accept: text/event-stream" http://localhost:19531/entries >"$LOG_FILE"
+awk '!/^(data: \{.+\}|)$/ { exit 1; }' "$LOG_FILE"
 # Same thing as journalctl --output=export
 mkdir /tmp/remote-journal
-curl -LSfs --header "Accept: application/vnd.fdo.journal" http://localhost:19531/entries | \
-    /usr/lib/systemd/systemd-journal-remote --output=/tmp/remote-journal/system.journal --split-mode=none -
+curl -LSfs --header "Accept: application/vnd.fdo.journal" http://localhost:19531/entries >"$LOG_FILE"
+/usr/lib/systemd/systemd-journal-remote --output=/tmp/remote-journal/system.journal --split-mode=none "$LOG_FILE"
 journalctl --directory=/tmp/remote-journal -t "$TEST_TAG" --grep "$TEST_MESSAGE"
 rm -rf /tmp/remote-journal/*
 # Let's do the same thing again, but let systemd-journal-remote spawn curl itself
@@ -90,10 +129,12 @@ journalctl --directory=/tmp/remote-journal -t "$TEST_TAG" --grep "$TEST_MESSAGE"
 rm -rf /tmp/remote-journal
 
 # /machine
-curl -LSfs http://localhost:19531/machine | jq
+curl -LSfs http://localhost:19531/machine >"$LOG_FILE"
+jq . "$LOG_FILE"
 
 # /fields
-curl -LSfs http://localhost:19531/fields/MESSAGE | grep -E -- "$TEST_MESSAGE" >/dev/null
+curl -LSfs http://localhost:19531/fields/MESSAGE >"$LOG_FILE"
+grep -qE -- "$TEST_MESSAGE" "$LOG_FILE"
 curl -LSfs http://localhost:19531/fields/_TRANSPORT
 (! curl -LSfs http://localhost:19531/fields)
 (! curl -LSfs http://localhost:19531/fields/foo-bar-baz)
@@ -133,12 +174,14 @@ GATEWAYD_PID=$!
 sleep 1
 
 # Do a limited set of tests, since the underlying code should be the same past the HTTPS transport
-curl -LSfsk https://localhost:19531 | grep -F "<title>Journal</title>" >/dev/null
-curl -LSfsk https://localhost:19531/entries | \
-    grep -E " $TEST_TAG\[[0-9]+\]: $TEST_MESSAGE" >/dev/null
-curl -LSfsk --header "Accept: application/json" https://localhost:19531/entries | \
-    jq -se ".[] | select(.MESSAGE == \"$TEST_MESSAGE\")"
-curl -LSfsk https://localhost:19531/machine | jq
+curl -LSfsk https://localhost:19531 >"$LOG_FILE"
+grep -qF "<title>Journal</title>" "$LOG_FILE"
+curl -LSfsk https://localhost:19531/entries >"$LOG_FILE"
+grep -qE " $TEST_TAG\[[0-9]+\]: $TEST_MESSAGE" "$LOG_FILE"
+curl -LSfsk --header "Accept: application/json" https://localhost:19531/entries >"$LOG_FILE"
+jq -se ".[] | select(.MESSAGE == \"$TEST_MESSAGE\")" "$LOG_FILE"
+curl -LSfsk https://localhost:19531/machine >"$LOG_FILE"
+jq . "$LOG_FILE"
 curl -LSfsk https://localhost:19531/fields/_TRANSPORT
 
 kill "$GATEWAYD_PID"
@@ -154,19 +197,21 @@ systemd-run --unit="test-gatewayd.service" --socket-property="ListenStream=19531
 # See: https://github.com/systemd/systemd/issues/9858
 OUT="$(mktemp)"
 for _ in {0..4}; do
-    curl --fail-with-body -d "please process this🐱 $RANDOM" -L http://localhost:19531/upload | tee "$OUT"
+    (! curl --fail-with-body -d "please process this🐱 $RANDOM" -L http://localhost:19531/upload | tee "$OUT")
     (! grep '[^[:print:]]' "$OUT")
 done
-curl --fail-with-body --upload-file "$GATEWAYD_FILE" -L http://localhost:19531/upload | tee "$OUT"
+(! curl --fail-with-body --upload-file "$GATEWAYD_FILE" -L http://localhost:19531/upload | tee "$OUT")
 (! grep '[^[:print:]]' "$OUT")
 rm -rf "$OUT"
 
-curl -LSfs http://localhost:19531/browse | grep -F "<title>Journal</title>" >/dev/null
+curl -LSfs http://localhost:19531/browse >"$LOG_FILE"
+grep -qF "<title>Journal</title>" "$LOG_FILE"
 # Nuke the file behind the /browse endpoint
 mv /usr/share/systemd/gatewayd/browse.html /usr/share/systemd/gatewayd/browse.html.bak
 (! curl --fail-with-body -L http://localhost:19531/browse)
 mv /usr/share/systemd/gatewayd/browse.html.bak /usr/share/systemd/gatewayd/browse.html
-curl -LSfs http://localhost:19531/browse | grep -F "<title>Journal</title>" >/dev/null
+curl -LSfs http://localhost:19531/browse >"$LOG_FILE"
+grep -qF "<title>Journal</title>" "$LOG_FILE"
 
 # Nuke the journal file
 mv "$GATEWAYD_FILE" "$GATEWAYD_FILE.bak"