#2150·garnet

`--fail-on-recovery-error true` still serves an incomplete AOF tail when no HybridLog checkpoint is readable

Author: nixxczCreated Sep 17, 2026Updated Sep 17, 2026

Describe the bug

Garnet can start serving an incomplete database when no HybridLog checkpoint is readable, even with:

--recover
--fail-on-recovery-error true

A minimal standalone reproduction:

  1. writes 200 keys;
  2. takes a successful checkpoint;
  3. writes five more keys as an AOF-only tail;
  4. explicitly commits the AOF;
  5. shuts down gracefully;
  6. makes the sole HybridLog checkpoint metadata unreadable while Garnet is stopped;
  7. restarts over the same persistent directory.

On restart, Garnet:

  • logs Skipping unreadable HybridLog checkpoint;
  • throws TsavoriteNoHybridLogException internally;
  • handles that exception as though this were a fresh start;
  • recovers and replays only the retained AOF tail;
  • announces Ready to accept connections;
  • serves 5 keys instead of the 205 durably written keys.

The recovery failure is logged, so this is not silent in the logging sense. The problem is fail-open startup: the node serves incomplete state despite the option whose documented behavior is:

Server bootup should fail if errors happen during bootup of AOF and checkpointing

See --fail-on-recovery-error.

This is not a request to recover deliberately corrupted metadata. The expected behavior is to refuse to serve when the remaining checkpoint/AOF history cannot reconstruct the database.

Steps to reproduce the bug

Requires Bash and Docker. The script preserves complete pre-injection and pre-boot data-directory copies under the printed temporary directory.

bash
#!/usr/bin/env bash
set -euo pipefail

suffix="$$"
network="garnet-recovery-failopen-${suffix}"
node="garnet-recovery-failopen-${suffix}"
root="$(mktemp -d)"
data="$root/data"
image="ghcr.io/microsoft/garnet:2.1.8"
client_image="redis:7-alpine"

mkdir -p \
  "$data" \
  "$root/pre-injection" \
  "$root/pre-boot" \
  "$root/post-boot"
chmod 0777 \
  "$root" \
  "$data" \
  "$root/pre-injection" \
  "$root/pre-boot" \
  "$root/post-boot"

cleanup() {
  docker rm -f "$node" >/dev/null 2>&1 || true
  docker network rm "$network" >/dev/null 2>&1 || true
  echo "Captured data remains at: $root"
}
trap cleanup EXIT

docker network create "$network" >/dev/null

start_node() {
  docker run -d \
    --name "$node" \
    --network "$network" \
    --network-alias garnet \
    -v "$data:/data" \
    "$image" \
    --aof \
    --recover \
    --fail-on-recovery-error true \
    --logger-level Trace \
    --bind 0.0.0.0 \
    --port 6379 \
    --checkpointdir /data/checkpoints \
    --index 64m >/dev/null
}

wait_ready() {
  for attempt in $(seq 1 30); do
    if [ "$(docker run --rm --network "$network" "$client_image" \
        redis-cli -h garnet PING 2>/dev/null || true)" = PONG ]; then
      return 0
    fi
    sleep 1
  done
  return 1
}

start_node
wait_ready

docker run --rm --network "$network" "$client_image" sh -ec '
  i=1
  while [ "$i" -le 200 ]; do
    redis-cli -h garnet SET "base:$i" "value:$i" >/dev/null
    i=$((i + 1))
  done

  redis-cli -h garnet SAVE >/dev/null

  i=201
  while [ "$i" -le 205 ]; do
    redis-cli -h garnet SET "tail:$i" "value:$i" >/dev/null
    i=$((i + 1))
  done

  printf "before_stop_dbsize="
  redis-cli -h garnet DBSIZE

  printf "commitaof="
  redis-cli -h garnet COMMITAOF
'

docker stop -t 30 "$node" >/dev/null
docker rm "$node" >/dev/null

# Preserve the complete untouched directory, then change only the sole
# HybridLog checkpoint metadata file.
docker run --rm -v "$root:/work" "$client_image" sh -ec '
  cp -a /work/data/. /work/pre-injection/

  metadata=$(find \
    /work/data/checkpoints/Store/checkpoints/cpr-checkpoints \
    -name info.dat.0)

  count=$(printf "%s\n" "$metadata" | grep -c .)
  [ "$count" -eq 1 ]

  size=$(stat -c %s "$metadata")
  prefix=$(od -An -tu4 -N4 "$metadata" | tr -d " ")

  echo "metadata=$metadata size=$size prefix=$prefix"
  [ "$size" -gt 0 ]
  [ "$prefix" -gt 0 ]

  dd \
    if=/dev/zero \
    of="$metadata" \
    bs="$size" \
    count=1 \
    conv=notrunc \
    status=none

  cp -a /work/data/. /work/pre-boot/
'

start_node

if wait_ready; then
  echo "restart_result=READY"

  docker run --rm --network "$network" "$client_image" sh -ec '
    printf "after_restart_dbsize="
    redis-cli -h garnet DBSIZE

    printf "base_1="
    redis-cli -h garnet GET base:1

    printf "tail_201="
    redis-cli -h garnet GET tail:201
  '
else
  echo "restart_result=REFUSED"
fi

docker logs "$node" >"$root/restart.log" 2>&1

docker run --rm -v "$root:/work" "$client_image" sh -ec '
  cp -a /work/data/. /work/post-boot/
'

echo "recovery markers:"
grep -E \
  'FailOnRecoveryError|Skipping unreadable HybridLog|No Hybrid Log found|Recovered AOF|replayed records|Ready to accept connections' \
  "$root/restart.log" || true

Observed output:

before_stop_dbsize=205
commitaof=AOF file committed

metadata=.../cpr-checkpoints/4f140e6f-.../info.dat.0 size=512 prefix=268

restart_result=READY
after_restart_dbsize=5
base_1=
tail_201=value:201

Relevant boot log:

"FailOnRecoveryError": true

Skipping unreadable HybridLog checkpoint: 4f140e6f-...
Tsavorite.core.TsavoriteException: Invalid metadata length 0 in
cpr-checkpoints/4f140e6f-.../info.dat; the metadata file is truncated or corrupt

No Hybrid Log found for recovery; storeVersion = 0;
Tsavorite.core.TsavoriteNoHybridLogException:
Unable to find valid HybridLog token

Recovered AOF: begin address = 21628, tail address = 22212, DB ID: 0
Total number of replayed records 5
* Ready to accept connections

The checkpoint contains the first 200 keys. The AOF begins at address 21628 because the successful checkpoint advanced/truncated its recoverable prefix. Only the five post-checkpoint records remain reconstructive without that checkpoint.

The test modifies only cpr-checkpoints/<token>/info.dat.0. A recursive comparison of the complete pre-injection and pre-boot snapshots reported exactly that one differing file.

Controls

Untouched checkpoint

Booting a copy of the complete pre-injection directory with the same command recovers correctly:

Recovered store to version 1
Recovered AOF: begin address = 21628, tail address = 22212, DB ID: 0
Total number of replayed records 5
DBSIZE=205
base:1=value:1
tail:201=value:201

This uses the same AOF addresses as the injected run. The difference is whether the checkpoint is readable.

Complete AOF without any checkpoint

A separate control writes 200 keys, never takes a checkpoint, commits the AOF, and restarts with the same recovery options:

No Hybrid Log found for recovery; storeVersion = 0
Recovered AOF: begin address = 64, tail address = 21628
Total number of replayed records 200
DBSIZE=200

Thus a fresh/AOF-only start can remain supported. It differs observably from the unsafe case:

  • no checkpoint metadata exists;
  • the AOF starts at the first valid address, 64;
  • the full dataset is replayable.

Expected behavior

With --fail-on-recovery-error true, Garnet should refuse to serve when:

  • checkpoint tokens exist but none can be read; and
  • the retained AOF does not start at the first valid address and therefore cannot reconstruct the missing checkpointed prefix.

The server should report the recovery failure clearly and preserve the checkpoint artifacts for diagnosis.

A fresh directory, or an AOF-only database whose complete log begins at address 64, should still be allowed to start.

Possible regression coverage:

  1. Empty first start with recovery enabled: starts successfully.
  2. No checkpoint plus a complete AOF: replays the complete AOF successfully.
  3. Valid checkpoint plus truncated AOF tail: recovers checkpoint and tail.
  4. Unreadable sole checkpoint plus truncated AOF tail and FailOnRecoveryError=true: refuses to serve.
  5. The same cluster-mode case: refuses to serve without purging the unreadable checkpoint artifacts.

Release version

Reproduced against both:

  • Garnet v2.1.8: ghcr.io/microsoft/garnet@sha256:20d9f41b02bcdf8aae1ad734fb7e31ef98b06efffdfa487eeea49687bdd3ff55
  • Garnet v2.1.7: ghcr.io/microsoft/garnet@sha256:19bc507a8d84da467951a5db16b3e9976358f0b0f22029f38d4edae26769e072

The relevant behavior is unchanged on current main at 277ea6c.

IDE

Not applicable; reproduced with the official Docker images and RESP commands.

OS version

Reproduced with the official Linux/arm64 containers using Docker Engine 29.7.2 on macOS 26.6.2 arm64.

Additional context

Why FailOnRecoveryError is bypassed

FindRecoveryInfo throws TsavoriteNoHybridLogException after the checkpoint scan finds no valid HybridLog token.

SingleDatabaseManager.RecoverCheckpointAsync catches that exception separately and always continues:

csharp
catch (TsavoriteNoHybridLogException ex)
{
    // No hybrid log being found is not the same as an error in recovery. e.g. fresh start
    Logger?.LogInformation(
        ex,
        "No Hybrid Log found for recovery; storeVersion = {storeVersion};",
        storeVersion);
}

Only the following general catch (Exception) consults FailOnRecoveryError.

That assumption is valid for a genuinely fresh start but not when checkpoint tokens were found and rejected as unreadable. It is also not safe when the recovered AOF begins after address 64.

AOF replay then starts at the retained log's current BeginAddress. No exception occurs while replaying the valid tail, so the AOF-side FailOnRecoveryError check is never reached.

Cluster-mode amplification

The standalone reproducer above preserves the unreadable checkpoint directories.

In cluster mode the same data-loss outcome reproduces, and an additional destructive behavior occurs. CheckpointStore.GetLatestCheckpointEntryFromDisk returns a non-null entry with:

storeVersion: -1
storeHlogToken: 00000000-0000-0000-0000-000000000000
storeIndexToken: 00000000-0000-0000-0000-000000000000

PurgeAllCheckpointsExceptEntry then treats the default tokens as the selected checkpoint and deletes every HybridLog and index token. The observed trace was:

[PurgeAllCheckpointsExceptEntry] ... storeVersion: -1
storeHlogToken: 00000000-...
storeIndexToken: 00000000-...
Deleting log token <actual token>
Deleting index token <actual token>

The node subsequently starts with only the AOF tail. Purging should not run from an invalid/default recovery selection, particularly before recovery success is known.

Duplicate search

I searched open and closed Garnet issues and pull requests for FailOnRecoveryError, TsavoriteNoHybridLogException, PurgeAllCheckpointsExceptEntry, unreadable/corrupt checkpoint metadata, incomplete/empty recovery, fail-open recovery, and AOF BeginAddress. I found no matching report.

Nearest results, but not duplicates:

  • #2076 reported a pre-listen hang when no valid HybridLog token was found. It did not demonstrate a successfully committed checkpoint plus truncated AOF, incomplete state being served, or FailOnRecoveryError=true being bypassed. Its fix in PR #2093 is already present in both affected releases.
  • PR #2145 explicitly leaves the TsavoriteNoHybridLogException catch unchanged to support a never-checkpointed fresh start. This report demonstrates a distinguishable non-fresh case: an unreadable checkpoint token exists and the AOF begins after address 64.
  • #2149 reports transient false metadata-read failures caused by concurrent reads. This reproduction permanently changes the metadata while Garnet is stopped. It demonstrates the unsafe recovery response to having no readable checkpoint; it does not claim that #2149 caused the persisted metadata state.