`restore -f` stops making progress permanently and logs nothing when it cannot bridge a gap

0.5.17

git clone https://gist.github.com/bitfliq/8b3c982599a7af5fc1b48420d37a7c86.git repro && cd repro && docker compose run --rm repro

services:
  minio:
    image: minio/minio:latest
    command: server /data
    environment:
      MINIO_ROOT_USER: minioadmin
      MINIO_ROOT_PASSWORD: minioadmin
    healthcheck:
      test: ["CMD", "mc", "ready", "local"]
      interval: 3s
      timeout: 3s
      retries: 20

  createbucket:
    image: minio/mc:latest
    depends_on:
      minio: {condition: service_healthy}
    entrypoint: >
      /bin/sh -c "mc alias set local http://minio:9000 minioadmin minioadmin &&
                  mc mb --ignore-existing local/repro"

  repro:
    build:
      context: .
      args:
        LITESTREAM_VERSION: ${LITESTREAM_VERSION:-0.5.17}
    depends_on:
      createbucket: {condition: service_completed_successfully}
    environment:
      AWS_ACCESS_KEY_ID: minioadmin
      AWS_SECRET_ACCESS_KEY: minioadmin

FROM debian:bookworm-slim
ARG LITESTREAM_VERSION=0.5.17
# Populated automatically by BuildKit (amd64 / arm64), so the reproduction runs
# on an Apple Silicon laptop as well as an x86_64 server.
ARG TARGETARCH
RUN apt-get update && apt-get install -y --no-install-recommends \
      ca-certificates curl sqlite3 python3 && rm -rf /var/lib/apt/lists/*
RUN set -eu; \
    case "${TARGETARCH:-amd64}" in \
      amd64) LS_ARCH=x86_64 ;; \
      arm64) LS_ARCH=arm64  ;; \
      *) echo "unsupported TARGETARCH: ${TARGETARCH}" >&2; exit 1 ;; \
    esac; \
    curl -fsSL -o /tmp/ls.deb \
      "https://github.com/benbjohnson/litestream/releases/download/v${LITESTREAM_VERSION}/litestream-${LITESTREAM_VERSION}-linux-${LS_ARCH}.deb"; \
    dpkg -i /tmp/ls.deb; rm /tmp/ls.deb
RUN set -eu; \
    curl -fsSL -o /usr/local/bin/mc \
      "https://dl.min.io/client/mc/release/linux-${TARGETARCH:-amd64}/mc"; \
    chmod +x /usr/local/bin/mc
COPY litestream.yml /etc/litestream.yml
COPY repro.sh /repro.sh
RUN chmod +x /repro.sh
ENTRYPOINT ["/repro.sh"]

# Intervals compressed so the scenario completes in ~3 minutes.
# Defaults (L1 30s / L9 24h / l0-retention 5m) behave the same, just slower.
levels:
  - interval: 45s
  - interval: 5m
  - interval: 1h

snapshot:
  # Snapshots must track the frontier, as they do on any long-running database.
  # With only a txid-1 snapshot the follower instead hits the documented
  # "saved TXID is ahead of latest snapshot" refusal, which is a different path.
  interval: 20s
  retention: 24h

l0-retention: 300s
l0-retention-check-interval: 5s

dbs:
  - path: /data/primary/db.sqlite
    replicas:
      - type: s3
        bucket: repro
        path: db
        endpoint: http://minio:9000
        region: us-east-1
        force-path-style: true
        sync-interval: 1s

#!/usr/bin/env bash
# Follow mode stops making progress, forever, without logging anything.
#
# Setup: one L0 object is removed from the replica, standing in for an upload
# that never landed. Everything after that is Litestream's own behaviour.
#
# Expected: the follower reports that it cannot proceed (some error, or a
#   recovery), the way `restore` does.
# Observed: the follower logs nothing after "entering follow mode", never
#   advances, survives restart -- while `litestream restore` from the SAME
#   replica at the SAME moment restores the database completely.
set -uo pipefail
DB=/data/primary/db.sqlite
mkdir -p /data/primary /data/follower /data/control
log(){ printf '\n=== %s\n' "$*"; }
fail(){ printf '\nPRECONDITION FAILED: %s\n' "$*"; exit 2; }

# Defaults target the bundled MinIO; override to point at any S3-compatible store.
S3_ENDPOINT="${S3_ENDPOINT:-http://minio:9000}"
S3_BUCKET="${S3_BUCKET:-repro}"
S3_PREFIX="${S3_PREFIX:-db}"
mc alias set L "$S3_ENDPOINT" "${AWS_ACCESS_KEY_ID}" "${AWS_SECRET_ACCESS_KEY}" >/dev/null
# Start from an empty replica. Without this, a re-run writes a fresh database
# (txid 1..N) into a bucket that still holds the previous run's objects, and the
# leftovers look exactly like naturally-occurring holes.
mc rm --recursive --force "L/$S3_BUCKET/$S3_PREFIX" >/dev/null 2>&1 || true
# TXIDs are 16-hex in the object names; print them as decimal to avoid confusion.
lvl(){ mc ls --recursive "L/$S3_BUCKET" 2>/dev/null | awk '{print $NF}' | grep "^$S3_PREFIX/$1/" \
       | sed -E 's|.*/([0-9a-f]{16})-([0-9a-f]{16})\.ltx|\1 \2|' \
       | python3 -c 'import sys
for line in sys.stdin:
    a,b=line.split()
    print(f"{int(a,16)}-{int(b,16)}")'; }

litestream version
sqlite3 "$DB" "pragma journal_mode=WAL; create table t(id integer primary key, v text);" >/dev/null

litestream replicate > /tmp/primary.log 2>&1 &
sleep 3
for i in $(seq 1 12); do sqlite3 "$DB" "insert into t(v) values('a$i');" >/dev/null; sleep 0.6; done
sleep 3

log "replica contents"
echo "L0: $(lvl 0000 | tr '\n' ' ')"
echo "L1: $(lvl 0001 | tr '\n' ' ')"

# Assert L0 is contiguous BEFORE we remove anything, so the hole we demonstrate
# is unambiguously the one we made.
N0=$(lvl 0000 | wc -l)
(( N0 >= 8 )) || fail "expected >=8 L0 objects before removal, saw $N0 (listing broken or nothing replicated)"
GAPS=$(lvl 0000 | awk -F- 'NR>1 && $1 != prev+1 {print prev"->"$1} {prev=$2}')
[[ -n "$GAPS" ]] && fail "L0 already has gaps before removal: $GAPS"
echo "L0 is contiguous before removal: OK ($N0 objects)"

# Choose a victim that L1 has NOT already absorbed. If L1 already covers the TXID,
# removing its L0 is a no-op: fillFollowGap bridges via L1 and the follower correctly
# catches up. That is a useful positive control but it is not the scenario under test,
# and picking blindly makes the reproduction flaky.
MAXL1=$(lvl 0001 | awk -F- '{print $2}' | sort -n | tail -1); MAXL1=${MAXL1:-0}
echo "highest TXID already compacted into L1: $MAXL1"

VICTIM=""; VLO=0
while read -r key; do
  hex=$(sed -E 's|.*/([0-9a-f]{16})-[0-9a-f]{16}\.ltx|\1|' <<<"$key")
  lo=$((16#$hex))
  if (( lo > MAXL1 + 1 )); then VICTIM="$key"; VLO=$lo; break; fi
done < <(mc ls --recursive "L/$S3_BUCKET" | awk '{print $NF}' | grep "^$S3_PREFIX/0000/" | sort)

[[ -n "$VICTIM" ]] || fail "no L0 object above the L1 watermark ($MAXL1) available to remove"
PARK=$(( VLO - 1 ))
echo "victim TXID $VLO is above the L1 watermark; follower will park at $PARK"

if [[ "${NEGATIVE_CONTROL:-0}" == "1" ]]; then
  log "NEGATIVE CONTROL: removing nothing. The follower must catch up."
else
  log "removing ONE L0 object (simulating an upload that never landed): $VICTIM"
  mc rm "L/$S3_BUCKET/$VICTIM" >/dev/null
fi

for i in $(seq 13 24); do sqlite3 "$DB" "insert into t(v) values('b$i');" >/dev/null; sleep 0.6; done

log "waiting for L1 compaction to run (45s interval)"
sleep 60
echo "L1 is now: $(lvl 0001 | tr '\n' ' ')      <-- frozen; see the errors below"
grep -m2 'compaction failed' /tmp/primary.log

COVER=""
for L in 0000 0001 0002 0003; do
  c=$(lvl "$L" | awk -F- -v n="$VLO" -v lab="$L" '$1<=n && n<=$2 {print lab" "$1"-"$2}')
  [[ -n "$c" ]] && COVER="$COVER $c"
done
if [[ "${NEGATIVE_CONTROL:-0}" == "1" ]]; then
  echo "negative control: TXID $VLO coverage is:${COVER:- none}"
else
  [[ -z "$COVER" ]] || fail "TXID $VLO is still covered by:$COVER -- no hole exists, nothing to test"
  echo "no incremental coverage for TXID $VLO: confirmed"
fi

log "park a follower just below the removed txid, then follow"
# restore to an exact txid, then write the sidecar exactly as litestream does
# (fmt.Fprintln => 16 hex digits + newline), so `restore -f` resumes from there
# precisely as it would after a process restart.
PARKHEX=$(printf '%016x' "$PARK")
litestream restore -txid "$PARKHEX" -o /data/follower/db.sqlite "$DB" >/dev/null 2>&1
printf '%s\n' "$PARKHEX" > /data/follower/db.sqlite-txid
# LOG_LEVEL is read in the shared config path (cmd/litestream/main.go), so it
# applies to `restore` as well -- `restore` has no -log-level flag of its own.
LOG_LEVEL=trace litestream restore -f -follow-interval 1s -o /data/follower/db.sqlite "$DB" \
  > /tmp/follower.log 2>&1 &
FPID=$!
for s in 15 30 45 60; do
  sleep 15
  printf '  t+%-3s txid=%s rows=%s alive=%s\n' "${s}s" \
    "$(tr -d '\n' < /data/follower/db.sqlite-txid)" \
    "$(sqlite3 "file:/data/follower/db.sqlite?mode=ro" 'select count(*) from t;')" \
    "$(kill -0 $FPID 2>/dev/null && echo yes || echo no)"
done
kill $FPID 2>/dev/null; wait $FPID 2>/dev/null

log "follower log, in full (LOG_LEVEL=trace)"
cat /tmp/follower.log
echo "error/warning lines: $(grep -ciE 'error|warn' /tmp/follower.log)"

log "control: plain restore from the SAME replica"
litestream restore -o /data/control/db.sqlite "$DB" 2>&1 | tail -2
echo "rows restored: $(sqlite3 "file:/data/control/db.sqlite?mode=ro" 'select count(*) from t;')"
echo "rows in primary: $(sqlite3 "file:$DB?mode=ro" 'select count(*) from t;')"
echo "highest txid in replica: $( { lvl 0000; lvl 0001; lvl 0009; } | awk -F- '{print $2}' | sort -n | tail -1)"

levels:
  - interval: 45s
  - interval: 5m
  - interval: 1h
snapshot:
  interval: 20s        # must track the frontier; see note below
  retention: 24h
l0-retention: 300s
l0-retention-check-interval: 5s
dbs:
  - path: /data/primary/db.sqlite
    replicas:
      - type: s3
        bucket: repro
        path: db
        endpoint: http://minio:9000
        region: us-east-1
        force-path-style: true
        sync-interval: 1s

=== park a follower just below the removed txid, then follow
  t+15s txid=0000000000000004 rows=4 alive=yes
  t+30s txid=0000000000000004 rows=4 alive=yes
  t+45s txid=0000000000000004 rows=4 alive=yes
  t+60s txid=0000000000000004 rows=4 alive=yes

=== follower log, in full
time=2026-08-31T04:08:46.335Z level=INFO msg="resuming follow mode from crash recovery" db=db.sqlite replica=s3 txid=0000000000000004 output=/data/follower/db.sqlite
time=2026-08-31T04:08:46.335Z level=INFO msg="entering follow mode" db=db.sqlite replica=s3 output=/data/follower/db.sqlite txid=0000000000000004 interval=1s
time=2026-08-31T04:09:46.331Z level=INFO msg="follow mode stopped" db=db.sqlite replica=s3
error/warning lines: 0

for level := 1; level < SnapshotLevel; level++ {

"cannot resume follow mode: saved TXID %s is behind the earliest snapshot (min TXID %s); replica history has been pruned -- delete %s and %s-txid to re-restore"

[0000000000000001-0000000000000001.ltx 0000000000000001-0000000000000002.ltx
 0000000000000001-0000000000000011.ltx 0000000000000001-0000000000000012.ltx]