Parallel cache restore with a hybrid start mode, and a fast /status refresh

README.md

@@ -186,7 +186,12 @@ instance only answers requests once its cache is fully warm; port 80 stays
 closed meanwhile, so give the orchestrator's health check enough time (on
 Rancher, raise the service's *initializing timeout* or rely on the load
 balancer's check) and keep a second instance serving. A restore of ~1 TB /
-millions of files takes hours. With `CACHE_RESTORE_MODE=background` NGINX
+millions of files takes hours (at ~90 files/s per worker; see
+`CACHE_RESTORE_JOBS`). `CACHE_RESTORE_MODE=hybrid` bounds the wait: NGINX
+starts as soon as the newest `CACHE_RESTORE_BLOCKING_MAX_BYTES` (default
+2 GB) have landed and the remainder continues in the background, so the
+health-check window stays valid however large the archive grows. With
+`CACHE_RESTORE_MODE=background` NGINX
 starts immediately and the copy runs alongside it: NGINX serves a cache file
 that appears on disk after it has started (verified against 1.26), and
 requests whose entry has not landed yet are ordinary misses. Either way,
@@ -228,7 +233,8 @@ Variables (all optional):
 
 - `CACHE_ARCHIVE_DIR` (`/cache`), `CACHE_LOCAL_DIR` (`/var/cache/nginx`): the two roots; both hold an `owlery/` tree.
 - `CACHE_RESTORE`: `auto` (default; skip if `.restored` exists), `always`, `off`.
-- `CACHE_RESTORE_MODE`: `blocking` (default; restore, then start NGINX) or `background` (start NGINX, restore alongside).
+- `CACHE_RESTORE_MODE`: `blocking` (default; restore everything, then start NGINX), `hybrid` (start NGINX once the newest `CACHE_RESTORE_BLOCKING_MAX_BYTES`, default `2g`, have landed; the rest continues in the background) or `background` (start NGINX immediately).
+- `CACHE_RESTORE_JOBS`: concurrent rsync workers for the restore (default `8`). Copy time is per-file NFS latency, not bandwidth (~90 files/s per worker measured), so workers scale almost linearly. The archive listing is also walked in parallel, one `find` per top-level directory.
 - `CACHE_RESTORE_BWLIMIT`, `CACHE_BACKUP_BWLIMIT`: rsync `--bwlimit` in KiB/s (default unlimited).
 - `CACHE_RESTORE_MAX_BYTES`: stop the restore after this many bytes of the newest entries (default: whole archive).
 - `CACHE_RESTORE_BATCH`, `CACHE_BACKUP_BATCH`: entries per rsync invocation (default 5000).

cache-backup.sh

@@ -55,6 +55,7 @@ bytes_done=0
 finish() {
     cache_write_state "$STATE_FILE" "$1" "$files_done" "$bytes_done" "$started" "$(date +%s)" "$2"
     cache_log "backup: $1 -- $2"
+    cache_signal_status_refresh
 }
 
 if [ ! -d "$CACHE_ARCHIVE_DIR" ]; then
@@ -96,6 +97,7 @@ fi
 
 cache_log "backup: $total_files entries ($total_bytes bytes) changed since last backup; waiting for archive lock"
 cache_write_state "$STATE_FILE" waiting 0 0 "$started" "" "waiting for lock ($total_files files pending)"
+cache_signal_status_refresh
 
 if ! cache_lock_acquire "$CACHE_BACKUP_LOCK_WAIT"; then
     finish skipped "another instance held the archive lock for more than ${CACHE_BACKUP_LOCK_WAIT} min; will retry next run"
@@ -104,6 +106,7 @@ fi
 trap 'cache_lock_release; rm -rf "$work"' EXIT
 
 cache_write_state "$STATE_FILE" running 0 0 "$started" "" "0/$total_files files"
+cache_signal_status_refresh
 mkdir -p "$DST"
 # Batch files in listing order (awk rather than split: BusyBox builds differ
 # in whether split is present, and this keeps the newest-first order).
@@ -126,6 +129,7 @@ for batch in "$work"/batch.*; do
     bytes_done=$(( bytes_done + $(awk '{ s += $1 } END { print s + 0 }' "$batch") ))
     rm -f "$batch" "$batch.paths"
     cache_write_state "$STATE_FILE" running "$files_done" "$bytes_done" "$started" "" "$files_done/$total_files files"
+    cache_signal_status_refresh
 done
 
 cp -p "$new_marker" "$MARKER"

cache-lib.sh

@@ -23,11 +23,44 @@ CACHE_MODIFY_WINDOW="${CACHE_MODIFY_WINDOW:-2}"
 # backups. flock(2) is unreliable on NFS; mkdir(2) is atomic there.
 CACHE_LOCK_DIR="${CACHE_LOCK_DIR:-$CACHE_ARCHIVE_DIR/.owl-cache-backup.lock}"
 CACHE_LOCK_STALE_MINUTES="${CACHE_LOCK_STALE_MINUTES:-360}"
+# /status is a snapshot health-monitor.sh writes on its own poll cycle
+# (default every 5s), so a restore/backup that finishes between polls can sit
+# "stale" in /status for up to that long -- harmless for a real multi-hour
+# restore, but on a small or empty archive the whole run can complete inside
+# one poll gap, which is what made a CI startup check race against it.
+#
+# cache_signal_status_refresh drops a flag file that health-monitor.sh checks
+# on a short tick (see its main loop) so a state change is reflected within
+# about a second instead of waiting for the next full poll. A first version
+# of this used `kill -USR1` at a pid health-monitor.sh recorded, woken by a
+# `trap ... USR1`; that does not work; in ash/dash a pending trap is not run
+# until the current `sleep` returns on its own, so the signal sat queued for
+# the rest of the poll interval anyway -- no better than doing nothing. A
+# plain file check on a 1s tick has no such gotcha, and, unlike the signal
+# (which needs sender and receiver to share a UID), works regardless of which
+# user creates it: nginx (cache-restore.sh/cache-backup.sh, after su-exec) can
+# always write into CACHE_STATE_DIR, since docker-entrypoint.sh chowns it to
+# nginx before either script ever runs.
+CACHE_STATUS_DIRTY_FILE="${CACHE_STATUS_DIRTY_FILE:-$CACHE_STATE_DIR/.status-dirty}"
+cache_signal_status_refresh() {
+    mkdir -p "$CACHE_STATE_DIR" 2>/dev/null || true
+    : > "$CACHE_STATUS_DIRTY_FILE" 2>/dev/null || true
+    return 0
+}
 
 cache_log() {
     printf '%s %s\n' "$(date -u +"%Y-%m-%dT%H:%M:%SZ")" "$*"
 }
 
+# "2g", "500m", "10k", "123" -> bytes. Anything unparseable -> 0.
+cache_parse_size() {
+    printf '%s' "${1:-0}" | awk '{
+        v = tolower($0); n = v + 0
+        if (v ~ /k$/) n *= 1024; else if (v ~ /m$/) n *= 1048576
+        else if (v ~ /g$/) n *= 1073741824; else if (v ~ /t$/) n *= 1099511627776
+        printf "%.0f", n }'
+}
+
 cache_json_escape() {
     printf '%s' "$1" | sed 's/\\/\\\\/g; s/"/\\"/g'
 }

cache-restore.sh

@@ -29,6 +29,15 @@
 #   CACHE_RESTORE_BWLIMIT    rsync --bwlimit in KiB/s; 0 = unlimited (default)
 #   CACHE_RESTORE_BATCH      files per rsync invocation (default 5000)
 #   CACHE_RESTORE_MAX_BYTES  stop after this many bytes (0 = whole archive)
+#   CACHE_RESTORE_JOBS       concurrent rsync workers (default 8). Copy time is
+#                            dominated by per-file NFS round trips, so workers
+#                            overlap almost perfectly.
+#   CACHE_RESTORE_BLOCKING_MAX_BYTES
+#                            the READY file is written once this many bytes
+#                            of the newest entries have landed (0 = only when
+#                            everything has). docker-entrypoint.sh waits for
+#                            that file before starting nginx in blocking and
+#                            hybrid modes. Accepts k/m/g/t suffixes.
 #   CACHE_RESTORE_DELAY      seconds to wait before starting (default 0)
 #
 # Usage: cache-restore.sh            # honours CACHE_RESTORE
@@ -51,20 +60,36 @@ CACHE_LIB="${CACHE_LIB:-/usr/local/bin/cache-lib.sh}"
 CACHE_RESTORE="${CACHE_RESTORE:-auto}"
 CACHE_RESTORE_BWLIMIT="${CACHE_RESTORE_BWLIMIT:-0}"
 CACHE_RESTORE_BATCH="${CACHE_RESTORE_BATCH:-5000}"
-CACHE_RESTORE_MAX_BYTES="${CACHE_RESTORE_MAX_BYTES:-0}"
+CACHE_RESTORE_MAX_BYTES="$(cache_parse_size "${CACHE_RESTORE_MAX_BYTES:-0}")"
+CACHE_RESTORE_JOBS="${CACHE_RESTORE_JOBS:-8}"
+CACHE_RESTORE_BLOCKING_MAX_BYTES="$(cache_parse_size "${CACHE_RESTORE_BLOCKING_MAX_BYTES:-0}")"
 CACHE_RESTORE_DELAY="${CACHE_RESTORE_DELAY:-0}"
+case "$CACHE_RESTORE_JOBS" in ''|*[!0-9]*|0) CACHE_RESTORE_JOBS=1 ;; esac
 
 STATE_FILE="$CACHE_STATE_DIR/cache-restore.json"
+# Written when the blocking portion has landed; the entrypoint waits for it.
+READY_FILE="$CACHE_STATE_DIR/cache-restore.ready"
 MARKER="$CACHE_LOCAL_DIR/.restored"
 SRC="$CACHE_ARCHIVE_DIR/$CACHE_SUBDIR"
 DST="$CACHE_LOCAL_DIR/$CACHE_SUBDIR"
 
 [ "${1:-}" = "--force" ] && CACHE_RESTORE=always
 
 started="$(date +%s)"
+mkdir -p "$CACHE_STATE_DIR"
+rm -f "$READY_FILE"
+mark_ready() {
+    [ -f "$READY_FILE" ] && return
+    printf '%s %s\n' "$(date -u +"%Y-%m-%dT%H:%M:%SZ")" "$1" > "$READY_FILE"
+    cache_log "restore: ready -- $1"
+    cache_signal_status_refresh
+}
 finish() {
     cache_write_state "$STATE_FILE" "$1" "${files_done:-0}" "${bytes_done:-0}" "$started" "$(date +%s)" "$2"
     cache_log "restore: $1 -- $2"
+    cache_signal_status_refresh
+    # Whatever happened, never leave the entrypoint waiting.
+    mark_ready "$1: $2"
 }
 
 case "$(printf '%s' "$CACHE_RESTORE" | tr '[:upper:]' '[:lower:]')" in
@@ -95,14 +120,28 @@ trap 'rm -rf "$work"' EXIT
 files_done=0
 bytes_done=0
 cache_write_state "$STATE_FILE" listing 0 0 "$started" "" "walking archive $SRC"
+cache_signal_status_refresh
 cache_log "restore: listing $SRC (this walks the whole archive once)"
 
 # One walk of the archive: "<mtime> <size> <relative path>", newest first.
 # find -printf needs GNU findutils (installed in the image); BusyBox find
 # has no -printf and would need one stat(2) per file on top of the walk.
-find "$SRC" -type f -printf '%T@ %s %P\n' 2>/dev/null \
+# The walk is NFS-latency bound, so the sixteen levels=1 top directories are
+# walked concurrently (files at the root, if any, in a seventeenth).
+mkdir -p "$work/list"
+i=0
+for top in "$SRC"/*/; do
+    [ -d "$top" ] || continue
+    rel="${top#"$SRC"/}"; rel="${rel%/}"
+    ( cd "$SRC" && find "$rel" -type f -printf '%T@ %s %p\n' ) > "$work/list/$i" 2>/dev/null &
+    i=$(( i + 1 ))
+done
+( cd "$SRC" && find . -maxdepth 1 -type f -printf '%T@ %s %P\n' ) > "$work/list/root" 2>/dev/null &
+wait
+cat "$work/list"/* \
     | awk '{ path=$3; for (i=4; i<=NF; i++) path=path " " $i; print $1, $2, path }' \
     | sort -k1,1nr > "$work/all.lst"
+rm -rf "$work/list"
 
 # Keep only real cache entries and apply the optional byte bound.
 awk -v max="$CACHE_RESTORE_MAX_BYTES" '
@@ -116,6 +155,7 @@ total_files="$(wc -l < "$work/entries.lst" | tr -d ' ')"
 total_bytes="$(awk '{ s += $1 } END { print s + 0 }' "$work/entries.lst")"
 cache_log "restore: $total_files entries ($total_bytes bytes) to consider, newest first, batches of $CACHE_RESTORE_BATCH"
 cache_write_state "$STATE_FILE" running 0 0 "$started" "" "0/$total_files files"
+cache_signal_status_refresh
 
 if [ "$total_files" -eq 0 ]; then
     finish "done" "archive is empty"; printf '%s\n' "$(date -u +"%Y-%m-%dT%H:%M:%SZ") 0 files" > "$MARKER"; exit 0
@@ -131,32 +171,78 @@ awk -v n="$CACHE_RESTORE_BATCH" -v dir="$work" '{
 
 # rsync partials go here, outside the tree nginx's cache loader walks.
 TMPDIR_RSYNC="$CACHE_LOCAL_DIR/.rsync-tmp"
-retry=""
-for batch in "$work"/batch.*; do
-    [ -f "$batch" ] || continue
-    cut -d' ' -f2- "$batch" > "$batch.paths"
-    n="$(wc -l < "$batch" | tr -d ' ')"
-    if ! cache_rsync_batch "$SRC" "$DST" "$batch.paths" "$CACHE_RESTORE_BWLIMIT" "$TMPDIR_RSYNC"; then
-        # Entries evicted from the archive between listing and copy show up as
-        # vanished files (rsync exit 24); anything else is worth surfacing but
-        # must not abandon the remaining batches. Failed batches get one more
-        # pass at the end (--update makes the repeat cheap).
-        cache_log "restore: rsync reported errors on batch $(basename "$batch"); will retry once"
-        retry="$retry $batch.paths"
-    else
-        rm -f "$batch.paths"
+
+# Where in the newest-first list the blocking portion ends: the first batch
+# index whose cumulative bytes exceed CACHE_RESTORE_BLOCKING_MAX_BYTES.
+# 0 means "all of it" (ready only when the whole restore is complete).
+ready_after_batch=-1
+if [ "$CACHE_RESTORE_BLOCKING_MAX_BYTES" -gt 0 ]; then
+    ready_after_batch="$(awk -v n="$CACHE_RESTORE_BATCH" -v max="$CACHE_RESTORE_BLOCKING_MAX_BYTES" '
+        { total += $1; if (total >= max) { print int((NR - 1) / n); exit } }
+        END { if (total < max) print int((NR - 1) / n) }' "$work/entries.lst")"
+fi
+
+# Worker w takes batches w, w+J, w+2J, ... so every worker starts near the
+# top of the newest-first list. Each appends "<files> <bytes>" per finished
+# batch to its progress file and lists failed batches for the retry pass.
+worker() {
+    w="$1"; k=0
+    for batch in "$work"/batch.*; do
+        case "$batch" in *.paths|*.failed) continue ;; esac
+        [ -f "$batch" ] || continue
+        if [ $(( k % CACHE_RESTORE_JOBS )) -eq "$w" ]; then
+            cut -d' ' -f2- "$batch" > "$batch.paths"
+            n="$(wc -l < "$batch" | tr -d ' ')"
+            b="$(awk '{ s += $1 } END { print s + 0 }' "$batch")"
+            if cache_rsync_batch "$SRC" "$DST" "$batch.paths" "$CACHE_RESTORE_BWLIMIT" "$TMPDIR_RSYNC"; then
+                rm -f "$batch.paths"
+            else
+                # Vanished files (exit 24, archive evicted between listing and
+                # copy) or anything else: retried once at the end.
+                cache_log "restore: rsync reported errors on batch $(basename "$batch"); will retry once"
+                printf '%s\n' "$batch.paths" >> "$work/failed.$w"
+            fi
+            printf '%s %s %s\n' "$n" "$b" "$k" >> "$work/progress.$w"
+        fi
+        k=$(( k + 1 ))
+    done
+    : > "$work/worker.$w.done"
+}
+
+w=0
+while [ "$w" -lt "$CACHE_RESTORE_JOBS" ]; do
+    worker "$w" &
+    w=$(( w + 1 ))
+done
+
+# Monitor: fold progress files into /status until every worker is done.
+update_progress() {
+    set -- $(cat "$work"/progress.* 2>/dev/null | awk '{ f += $1; b += $2 } END { print f + 0, b + 0 }')
+    files_done="$1"; bytes_done="$2"
+    cache_write_state "$STATE_FILE" running "$files_done" "$bytes_done" "$started" "" "$files_done/$total_files files, $CACHE_RESTORE_JOBS workers"
+    cache_signal_status_refresh
+    if [ "$ready_after_batch" -ge 0 ] && [ ! -f "$READY_FILE" ]; then
+        # Ready once every batch up to ready_after_batch has been processed.
+        done_upto="$(cat "$work"/progress.* 2>/dev/null | awk -v want="$ready_after_batch" '
+            $3 <= want { c++ } END { print c + 0 }')"
+        if [ "$done_upto" -ge $(( ready_after_batch + 1 )) ]; then
+            mark_ready "newest $bytes_done bytes ($files_done files) landed; remaining $(( total_files - files_done )) continue in the background"
+        fi
     fi
-    files_done=$(( files_done + n ))
-    # Bytes are accounted from the listing, not from rsync, so this is the
-    # size of the entries considered so far (already-current files included).
-    bytes_done=$(( bytes_done + $(awk '{ s += $1 } END { print s + 0 }' "$batch") ))
-    rm -f "$batch"
-    cache_write_state "$STATE_FILE" running "$files_done" "$bytes_done" "$started" "" "$files_done/$total_files files"
+}
+# Poll every second: cheap (one small state-file write), and a tiny restore
+# should not take longer than its workers do.
+while [ "$(ls "$work"/worker.*.done 2>/dev/null | wc -l | tr -d ' ')" -lt "$CACHE_RESTORE_JOBS" ]; do
+    sleep 1
+    update_progress
 done
+wait
+update_progress
 
 failed=0
-for paths in $retry; do
+for paths in $(cat "$work"/failed.* 2>/dev/null); do
     cache_write_state "$STATE_FILE" running "$files_done" "$bytes_done" "$started" "" "retrying $(basename "$paths" .paths)"
+    cache_signal_status_refresh
     if ! cache_rsync_batch "$SRC" "$DST" "$paths" "$CACHE_RESTORE_BWLIMIT" "$TMPDIR_RSYNC"; then
         failed=$(( failed + 1 ))
         cache_log "restore: batch $(basename "$paths" .paths) still reported errors on retry"

docker-entrypoint.sh

@@ -121,21 +121,35 @@ chown nginx:nginx /var/run/nginx "$CACHE_LOCAL_DIR" "$CACHE_LOCAL_DIR/owlery" 2>
 
 /usr/local/bin/health-monitor.sh &
 
-# CACHE_RESTORE_MODE=blocking (default): copy the archive into the local
-# cache BEFORE nginx starts, so the instance only answers once it is fully
-# warm. Nothing listens on port 80 meanwhile, so the orchestrator's health
-# check must allow for the restore time (Rancher: raise the service's
-# "initializing timeout", or rely on the load balancer's check instead).
-# CACHE_RESTORE_MODE=background: start nginx immediately and warm the cache
-# concurrently; nginx serves whatever has landed and treats the rest as
-# ordinary misses. Use this when there is no redundant instance to cover.
+# CACHE_RESTORE_MODE decides when nginx starts relative to the restore:
+#   blocking   (default) wait until the whole archive has been copied, so the
+#              instance only answers once fully warm. Port 80 stays closed
+#              meanwhile, so the orchestrator's health check must allow for
+#              the restore time (Rancher: raise the service's "initializing
+#              timeout"); keep a second instance serving.
+#   hybrid     wait only until the newest CACHE_RESTORE_BLOCKING_MAX_BYTES
+#              (default 2g) have landed, then start nginx while the rest of the
+#              restore continues in the background. Bounded start time
+#              whatever the archive size.
+#   background start nginx immediately; nginx serves whatever has landed and
+#              treats the rest as ordinary misses.
 export CACHE_RESTORE_MODE="${CACHE_RESTORE_MODE:-blocking}"
+READY_FILE="${CACHE_STATE_DIR:-/var/run/nginx}/cache-restore.ready"
+rm -f "$READY_FILE"
 case "$(printf '%s' "$CACHE_RESTORE_MODE" | tr '[:upper:]' '[:lower:]')" in
     background|async)
         echo "Cache restore runs in the background (CACHE_RESTORE_MODE=$CACHE_RESTORE_MODE)"
         /usr/local/bin/cache-restore.sh &
         ;;
+    hybrid)
+        export CACHE_RESTORE_BLOCKING_MAX_BYTES="${CACHE_RESTORE_BLOCKING_MAX_BYTES:-2g}"
+        echo "Cache restore: nginx starts once the newest $CACHE_RESTORE_BLOCKING_MAX_BYTES have landed (CACHE_RESTORE_MODE=hybrid); the rest continues in the background"
+        /usr/local/bin/cache-restore.sh &
+        restore_pid=$!
+        while [ ! -f "$READY_FILE" ] && kill -0 "$restore_pid" 2>/dev/null; do sleep 2; done
+        ;;
     *)
+        export CACHE_RESTORE_BLOCKING_MAX_BYTES=0
         echo "Cache restore runs before nginx starts (CACHE_RESTORE_MODE=$CACHE_RESTORE_MODE); port 80 stays closed until it finishes"
         /usr/local/bin/cache-restore.sh || echo "cache-restore.sh exited with status $?; starting nginx anyway"
         ;;

health-monitor.sh

@@ -57,6 +57,8 @@ last_health_log_epoch=0
 
 CACHE_RESTORE_STATE=${CACHE_RESTORE_STATE:-$STATUS_DIR/cache-restore.json}
 CACHE_BACKUP_STATE=${CACHE_BACKUP_STATE:-$STATUS_DIR/cache-backup.json}
+# Matches cache-lib.sh's CACHE_STATUS_DIRTY_FILE default (same directory).
+STATUS_DIRTY_FILE=${STATUS_DIRTY_FILE:-$STATUS_DIR/.status-dirty}
 
 # Embed a state file written by cache-restore.sh / cache-backup.sh, or null
 # when that job has not run in this container yet.
@@ -418,5 +420,17 @@ while true; do
     update_upstream_health
     update_connection_stats
     write_status_file
-    sleep "$STATUS_POLL_INTERVAL"
+    # Sleep in 1s ticks rather than one `sleep $STATUS_POLL_INTERVAL` call, so
+    # cache_signal_status_refresh's flag file (cache-lib.sh) is picked up
+    # within about a second of cache-restore.sh/cache-backup.sh changing
+    # state, instead of only at the next full poll.
+    waited=0
+    while [ "$waited" -lt "$STATUS_POLL_INTERVAL" ]; do
+        if [ -f "$STATUS_DIRTY_FILE" ]; then
+            rm -f "$STATUS_DIRTY_FILE"
+            break
+        fi
+        sleep 1
+        waited=$(( waited + 1 ))
+    done
 done