Read an INFO reply the way Redis writes it, and print the log when it fails

.github/workflows/tests.yml

@@ -19,8 +19,8 @@ permissions:
 
 jobs:
   tests:
-    # COVERAGE.md: the conf script at 100 percent (36/36), the first boot
-    # hook at 100 (31/31) and its library at 100 (56/56), 65 bats tests. The
+    # COVERAGE.md: the conf script at 100 percent (39/39), the first boot
+    # hook at 100 (31/31) and its library at 100 (56/56), 67 bats tests. The
     # threshold is the measured number and is only ever raised (decision
     # 0006). This job produces the check
     # "tests / coverage", the required status on main; the job id is part of

COVERAGE.md

@@ -12,20 +12,20 @@ repository does not carry a boot test of its own.
 | --- | --- | --- | --- |
 | overlay/usr/lib/inithooks/lib/redis.sh | tests/redis.bats (20 tests) | 100 percent (56/56) under kcov | every function and every branch |
 | overlay/usr/lib/inithooks/firstboot.d/35redispass | tests/hook.bats (18 tests) | 100 percent (31/31) under kcov | every path, including the four failures that matter |
-| conf | tests/conf.bats (15 tests) | 100 percent (36/36) under kcov | the include appended once and last, the fragments, the running server on both families, and every refusal |
+| conf | tests/conf.bats (17 tests) | 100 percent (39/39) under kcov | the include appended once and last, the fragments, the running server on both families, every refusal, the CRLF an INFO reply really carries, and the server log a failure prints |
 | overlay/etc/redis/redis.conf.d/\* | tests/conf.bats (2 tests) | not executable | asserted as content: two literal bind addresses and no name, the default account restricted to `+info`, the administrative account published `off`, and no `requirepass` anywhere |
 | overlay/usr/lib/inithooks/bin/redispass.py | none | 0 | dialog wrapper, only reached with a terminal attached |
 
-Total over the three measured shell files: **100 percent (123/123)**,
-65 bats tests over four files (conf, hook, library, unit shape).
+Total over the three measured shell files: **100 percent (126/126)**,
+67 bats tests over four files (conf, hook, library, unit shape).
 `tests/coverage.sh` fails below `COVERAGE_THRESHOLD`, which the workflow sets
 to 100, the measured number. It is only ever raised (decision 0006).
 
     $ COVERAGE_THRESHOLD=100 tests/coverage.sh
     kcov line coverage (threshold 100 percent):
      100.00  56/56  redis.sh
      100.00  31/31  35redispass
-     100.00  36/36  conf
+     100.00  39/39  conf
 
 ## What the tests are really about
 
@@ -47,12 +47,19 @@ require it absent, and the file's mode is asserted to be 0640. The upstream
 appliance wrote `requirepass` into a file the package ships world readable,
 which is the defect this replaces.
 
-Under all three, one Redis behaviour that every check is shaped around:
+Under all three, two Redis behaviours that every check is shaped around.
+
 **redis-cli exits 0 when the server answers with an error.** One test drives
 the hook with a wrong password through a stub that exits 0 and prints
 `WRONGPASS`, and requires the hook to fail anyway. A check written on `$?`
 would have passed.
 
+**Redis speaks CRLF.** Every line of an `INFO` reply ends `\r\n`, and
+redis-cli prints the reply as it came, so a grep anchored with `$` never
+matches a whole line. The first build of this component died there. Every
+`INFO` stub in `tests/conf.bats` answers in CRLF now, so the whole file
+covers it, and one test says so by name.
+
 ## What is not measured, and what would change that
 
 `overlay/usr/lib/inithooks/bin/redispass.py` is a Dialog wrapper, reached

changelog

@@ -1,3 +1,32 @@
+unit-redis-1.0.1 (1) keel; urgency=low
+
+  * Read an INFO reply the way Redis writes it. Redis speaks CRLF: every
+    line of an INFO reply ends "\r\n" and redis-cli prints the reply as it
+    came, so "tcp_port:6379" is really "tcp_port:6379\r" and the conf
+    script's check, anchored with a dollar, never matched it. The first
+    build of this component died there, with a server that was up and
+    listening on both families and a message that said no Redis answered.
+    Measured in the chroot of that build:
+
+        redis-cli INFO server | grep tcp_port | od -c
+        t c p _ p o r t : 6 3 7 9 \r \n
+
+    The reply now goes through tr before it is read, in one function both
+    checks call, and the stub in tests/conf.bats answers in CRLF so every
+    test in that file covers it.
+
+  * A failure prints the server's own log. The check removes the directory
+    it runs the server in, so the log that explains a failure went with it
+    and the build that failed could not be diagnosed from its own output.
+    The fatal path now prints the last twenty lines first.
+
+  * The message that failure prints says which address reported nothing and
+    how long the wait was, as two separate facts. The old one read "no Redis
+    answered INFO on [127.0.0.1]:6379 after 30 tries" for a check that had
+    made one attempt, because the tries belong to the wait on [::1].
+
+ -- Keel Linux maintainers <admin@keellinux.org>  Mon, 28 Sep 2026 01:45:00 +0000
+
 unit-redis-1.0.0 (1) keel; urgency=low
 
   * The Redis component, as a fab unit (decision 0010): a plan, an overlay

conf

@@ -44,9 +44,37 @@ REDIS_TRIES="${REDIS_TRIES:-30}"
 
 fatal() {
     echo "FATAL [unit-redis conf]: $*" >&2
+    # The server's own log, when there is one, because the check below
+    # removes the directory it is in and a build that failed for want of a
+    # log is a build nobody can diagnose. The first build of this component
+    # failed exactly that way.
+    if [ -s "$REDIS_CHECK_DIR/redis.log" ]; then
+        echo "FATAL [unit-redis conf]: the last lines of the server's own log:" >&2
+        tail -n 20 "$REDIS_CHECK_DIR/redis.log" >&2
+    fi
     exit 1
 }
 
+# redis_port_line HOST: the tcp_port line the server at HOST reports, with
+# the carriage returns taken out, and nothing when it reports none.
+#
+# The tr is the whole point of this function. Redis speaks CRLF: every line
+# of an INFO reply ends "\r\n", and redis-cli prints the reply as it came,
+# so "tcp_port:6379" is really "tcp_port:6379\r" and a grep anchored with a
+# dollar never matches it. The first build of this component failed there,
+# with a server that was up and listening on both families and a check that
+# said no Redis answered. Measured in the chroot of that build:
+#
+#     redis-cli INFO server | grep tcp_port | od -c
+#     t c p _ p o r t : 6 3 7 9 \r \n
+#
+# Anything that reads an INFO reply has to do this, or match a prefix and
+# never a whole line.
+redis_port_line() {
+    redis-cli -h "$1" -p "$REDIS_PORT" INFO server 2>/dev/null \
+        | tr -d '\r' | grep -x "tcp_port:$REDIS_PORT"
+}
+
 # 1. The fragments. They come from the overlay, which fab applied before
 #    this script ran, so their absence means the overlay did not arrive.
 [ -d "$REDIS_CONF_D" ] || fatal "$REDIS_CONF_D is not in the tree: the component overlay did not arrive"
@@ -94,9 +122,7 @@ trap stop_server EXIT INT TERM
 
 attempt=1
 while [ "$attempt" -le "$REDIS_TRIES" ]; do
-    if redis-cli -h ::1 -p "$REDIS_PORT" INFO server 2>/dev/null | grep -q '^redis_version:'; then
-        break
-    fi
+    redis_port_line ::1 > /dev/null && break
     attempt=$((attempt + 1))
     sleep 1
 done
@@ -109,9 +135,9 @@ done
 # after 20-keel-acl.conf, and because it is exactly what `keel inspect` runs
 # to read this machine's database.server.role.
 for host in $REDIS_CHECK_HOSTS; do
-    redis-cli -h "$host" -p "$REDIS_PORT" INFO server 2>/dev/null \
-        | grep -q "^tcp_port:$REDIS_PORT\$" \
-        || fatal "no Redis answered INFO on [$host]:$REDIS_PORT after $REDIS_TRIES tries"
+    redis_port_line "$host" > /dev/null \
+        || fatal "no Redis reported tcp_port:$REDIS_PORT on [$host]:$REDIS_PORT," \
+            "after $REDIS_TRIES tries on [::1]"
 done
 
 # And the other half of 20-keel-acl.conf: a client with no secret is refused

tests/conf.bats

@@ -43,9 +43,14 @@ while [ $# -gt 0 ]; do
 done
 if [ -n "$pidfile" ]; then sleep 60 & echo $! > "$pidfile"; echo "started-pid $!" >> "$CALLS"; fi
 exit 0'
+    # The stub answers the way a real server does, which here means CRLF:
+    # every line of an INFO reply ends "\r\n" and redis-cli prints the
+    # reply as it came. The first build of this component failed because
+    # the check was anchored with a dollar and the stub of the day was not
+    # faithful about it, so this is the shape every INFO stub below has.
     stub redis-cli 'echo "redis-cli $*" >> "$CALLS"
 case " $* " in
-  *" INFO server "*|*" INFO server") printf "redis_version:8.0.2\ntcp_port:6379\n" ;;
+  *" INFO server "*|*" INFO server") printf "# Server\r\nredis_version:8.0.2\r\ntcp_port:6379\r\n" ;;
   *" GET "*) echo "NOPERM User default has no permissions to run the '"'"'get'"'"' command" ;;
 esac
 exit 0'
@@ -134,20 +139,57 @@ run_conf() {
     export REDIS_TRIES=2
     run_conf
     [ "$status" -eq 1 ]
-    [[ "$output" == *"no Redis answered INFO on [::1]:6379 after 2 tries"* ]]
+    [[ "$output" == *"no Redis reported tcp_port:6379 on [::1]:6379"* ]]
+    [[ "$output" == *"after 2 tries on [::1]"* ]]
 }
 
 @test "a server on one family only fails, which is the trap this exists for" {
     stub redis-cli 'echo "redis-cli $*" >> "$CALLS"
 case " $* " in
-  *" -h ::1 "*" INFO server"*) printf "redis_version:8.0.2\ntcp_port:6379\n" ;;
+  *" -h ::1 "*" INFO server"*) printf "# Server\r\ntcp_port:6379\r\n" ;;
   *" -h 127.0.0.1 "*) exit 1 ;;
 esac
 exit 0'
     export REDIS_TRIES=1
     run_conf
     [ "$status" -eq 1 ]
-    [[ "$output" == *"no Redis answered INFO on [127.0.0.1]:6379"* ]]
+    [[ "$output" == *"no Redis reported tcp_port:6379 on [127.0.0.1]:6379"* ]]
+}
+
+@test "an INFO reply in CRLF is read, which a dollar anchor would not have" {
+    # The defect the first build of this component died on. redis-cli
+    # prints the reply as it came and Redis speaks CRLF, so the line is
+    # "tcp_port:6379\r"; a check anchored with a dollar never matched it,
+    # and the message said no Redis answered while the server was up and
+    # listening on both families. Measured in the chroot of that build with
+    # od -c. The stub above is CRLF for the same reason, so every test in
+    # this file covers it; this one says so by name.
+    run bash -c 'printf "# Server\r\ntcp_port:6379\r\n" | grep -q "^tcp_port:6379$"'
+    [ "$status" -ne 0 ]
+    run bash -c 'printf "# Server\r\ntcp_port:6379\r\n" | tr -d "\r" | grep -qx "tcp_port:6379"'
+    [ "$status" -eq 0 ]
+    run_conf
+    [ "$status" -eq 0 ]
+}
+
+@test "a failure carries the server's own log, which the check then removes" {
+    stub redis-server 'echo "redis-server $*" >> "$CALLS"
+pidfile=""; logfile=""
+while [ $# -gt 0 ]; do
+    if [ "$1" = --pidfile ]; then pidfile=$2; fi
+    if [ "$1" = --logfile ]; then logfile=$2; fi
+    shift
+done
+[ -n "$logfile" ] && echo "1:M Ready to accept connections tcp" > "$logfile"
+if [ -n "$pidfile" ]; then sleep 60 & echo $! > "$pidfile"; echo "started-pid $!" >> "$CALLS"; fi
+exit 0'
+    stub redis-cli 'exit 1'
+    export REDIS_TRIES=1
+    run_conf
+    [ "$status" -eq 1 ]
+    [[ "$output" == *"the last lines of the server's own log"* ]]
+    [[ "$output" == *"Ready to accept connections tcp"* ]]
+    [ ! -e "$REDIS_CHECK_DIR" ]
 }
 
 @test "redis-server refusing the file fails the build" {
@@ -160,7 +202,7 @@ exit 0'
 @test "a server that hands a key to a client with no secret fails the build" {
     stub redis-cli 'echo "redis-cli $*" >> "$CALLS"
 case " $* " in
-  *" INFO server"*) printf "redis_version:8.0.2\ntcp_port:6379\n" ;;
+  *" INFO server"*) printf "# Server\r\ntcp_port:6379\r\n" ;;
   *" GET "*) echo "(nil)" ;;
 esac
 exit 0'

version

@@ -1 +1 @@
-1.0.0
+1.0.1