#2149·garnet

`DeviceLogCommitCheckpointManager` shares I/O completions across concurrent reads, causing valid checkpoints to be skipped

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

Describe the bug

Concurrent checkpoint-metadata reads are not isolated in DeviceLogCommitCheckpointManager. Two concurrent INFO ALL requests can cause Garnet to:

  • log Skipping unreadable index checkpoint;
  • report Invalid metadata length 0;
  • return disk_checkpoint_entry:(empty) from one or both requests;

even though the checkpoint metadata file is valid and a serial read immediately before and after the concurrent requests returns the same checkpoint successfully.

This reproduces on a single fresh node after one checkpoint. It does not require replication, restart, failover, checkpoint transfer, concurrent writes, multiple checkpoints, or damaged files.

The apparent cause is that every metadata operation shares the same instance-wide SemaphoreSlim and metadataIoErrorCode.

ReadInto:

  1. clears its leased buffer;
  2. starts an asynchronous read;
  3. waits on the shared semaphore;
  4. copies and returns its buffer.

Every operation uses the same IOCallback, which releases that shared semaphore without identifying which operation completed.

With reads A and B in flight, A's completion can satisfy B's wait. B then copies its own still-zeroed buffer and returns it to the pool while B's I/O remains outstanding. The first four bytes therefore appear to be zero, and GetIndexCheckpointMetadata rejects the valid token as truncated or corrupt.

The shared metadataIoErrorCode has the same ownership problem: one operation can reset or observe another operation's result.

WriteInto uses the same semaphore, error field, callback and buffer-lifetime pattern. The reproducer below demonstrates the concurrent-read failure only; it does not claim that the on-disk metadata was corrupted.

Steps to reproduce the bug

Requires Bash and Docker. The official Garnet 2.1.7 and Redis CLI images are sufficient.

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

suffix="$$"
network="garnet-metadata-read-${suffix}"
node="garnet-metadata-read-${suffix}"
data="$(mktemp -d)"
image="ghcr.io/microsoft/garnet:2.1.7"
client_image="redis:7-alpine"

cleanup() {
  docker rm -f "$node" >/dev/null 2>&1 || true
  docker network rm "$network" >/dev/null 2>&1 || true
  rm -rf "$data"
}
trap cleanup EXIT

chmod 0777 "$data"
docker network create "$network" >/dev/null

docker run -d \
  --name "$node" \
  --network "$network" \
  --network-alias garnet \
  -v "$data:/data" \
  "$image" \
  --cluster \
  --aof \
  --bind 0.0.0.0 \
  --port 6379 \
  --checkpointdir /data/checkpoints \
  --index 64m >/dev/null

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

docker run --rm --network "$network" "$client_image" \
  redis-cli -h garnet CLUSTER ADDSLOTSRANGE 0 16383 >/dev/null
docker run --rm --network "$network" "$client_image" \
  redis-cli -h garnet SET test-key test-value >/dev/null
docker run --rm --network "$network" "$client_image" \
  redis-cli -h garnet SAVE >/dev/null

echo "serial read before concurrent requests:"
docker run --rm --network "$network" "$client_image" sh -ec \
  'redis-cli -h garnet INFO ALL | sed -n "/# CheckpointInfo/,/^$/p"'

echo "two concurrent INFO ALL workers:"
docker run --rm --network "$network" "$client_image" sh -ec '
  probe() {
    misses=0
    i=0
    while [ "$i" -lt 1000 ]; do
      response=$(redis-cli -h garnet INFO ALL)
      if printf "%s\n" "$response" |
          grep -q "disk_checkpoint_entry:(empty)"; then
        misses=$((misses + 1))
      fi
      i=$((i + 1))
    done
    echo "worker observed $misses empty disk checkpoint entries"
  }

  probe & probe & wait
'

echo "metadata length prefix after concurrent requests:"
docker run --rm -v "$data:/data:ro" "$client_image" sh -ec '
  find /data/checkpoints \
    -path "*/index-checkpoints/*/info.dat.0" \
    -exec sh -c '\''
      printf "%s: " "$1"
      od -An -tu4 -N4 "$1" | tr -d " "
    '\'' sh {} \;
'

echo "serial read after concurrent requests:"
docker run --rm --network "$network" "$client_image" sh -ec \
  'redis-cli -h garnet INFO ALL | sed -n "/# CheckpointInfo/,/^$/p"'

echo "first warnings:"
docker logs "$node" 2>&1 |
  grep -m 3 "Skipping unreadable index checkpoint" || true

Observed on one run:

serial read before concurrent requests:
# CheckpointInfo
memory_checkpoint_entry:storeVersion=2,...,storeIndexToken=52e1d0f1-...
disk_checkpoint_entry:storeVersion=2,...,storeIndexToken=52e1d0f1-...

two concurrent INFO ALL workers:
worker observed 145 empty disk checkpoint entries
worker observed 162 empty disk checkpoint entries

metadata length prefix after concurrent requests:
/data/checkpoints/Store/checkpoints/index-checkpoints/52e1d0f1-.../info.dat.0: 91

serial read after concurrent requests:
# CheckpointInfo
memory_checkpoint_entry:storeVersion=2,...,storeIndexToken=52e1d0f1-...
disk_checkpoint_entry:storeVersion=2,...,storeIndexToken=52e1d0f1-...

The counts vary, but the warning reproduced on both fresh runs attempted with two clients.

The server log contains:

warn: TsavoriteKV [main][0] Skipping unreadable index checkpoint:
52e1d0f1-...
Tsavorite.core.TsavoriteException: Invalid metadata length 0 in
index-checkpoints/52e1d0f1-.../info.dat; the metadata file is truncated or corrupt
   at Tsavorite.core.DeviceLogCommitCheckpointManager.ThrowIfInvalidMetadataSize(...)
   at Tsavorite.core.DeviceLogCommitCheckpointManager.GetIndexCheckpointMetadata(...)
   at Tsavorite.core.IndexRecoveryInfo.Recover(...)
   at Tsavorite.core.TsavoriteKV`2.GetClosestIndexCheckpointInfo(...)

The physical file still has a nonzero length prefix (91 in this run), and serial reads before and after the failure recover it successfully. The “truncated or corrupt” diagnosis is therefore false in this reproducer.

Expected behavior

Each metadata operation must wait for its own I/O completion and retain its buffer until that specific operation completes.

Concurrent INFO ALL requests should:

  • return the same valid disk_checkpoint_entry;
  • not log Skipping unreadable index checkpoint;
  • not classify a valid metadata file as having length zero.

The completion signal, error code and buffer lease should be operation-specific, or access to the entire metadata I/O sequence should be serialized.

Because reads and writes currently share this machinery, regression coverage should include:

  1. two concurrent metadata reads whose completions are deliberately reordered;
  2. a metadata read concurrent with a metadata write;
  3. verification that no buffer is returned before its associated callback;
  4. verification that one operation cannot consume another operation's error.

Release version

Garnet v2.1.7, official image:

ghcr.io/microsoft/garnet@sha256:19bc507a8d84da467951a5db16b3e9976358f0b0f22029f38d4edae26769e072

The relevant DeviceLogCommitCheckpointManager code is unchanged on current main at commit 277ea6c.

IDE

Not applicable; reproduced with Docker and RESP commands only.

OS version

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

Additional context

INFO ALL populates its checkpoint section by scanning checkpoint metadata on disk through PopulateCheckpointInfo. The index scan catches the failed read and skips the token, explaining the transient disk_checkpoint_entry:(empty) result.

I searched open and closed Garnet issues and pull requests for the exact warning, Invalid metadata length 0, disk_checkpoint_entry:(empty), DeviceLogCommitCheckpointManager, its semaphore, concurrent INFO ALL, checkpoint metadata races, and close paraphrases. I found no matching report.

Nearest results, but not duplicates:

  • #2142 is a persistent checkpoint-cleanup defect: DeleteOutdatedCheckpoints deletes HybridLog metadata and then attempts to parse it. This issue needs only one intact index checkpoint and concurrent readers.
  • #2076 / PR #2093 address ignored metadata I/O errors and recovery hangs. Version 2.1.7 already contains that work. It clears read buffers and validates zero lengths, but does not associate a completion or error field with the operation that owns it.
  • #2134 concerns a 2 GiB hash-index short write on Linux. This reproducer uses a 64 MiB index and never overlaps a checkpoint write.
  • PR #2145 concerns failed checkpoints being reported as successful and aborted-checkpoint cleanup. It does not change metadata read synchronization.