Baike.dev
Log in
Back to tool/Back to issues
#2992·typesense

Async-reference (JOIN) replay can permanently wedge a follower's apply pipeline (reference_q) — follower stuck at HTTP 503 while the leader stays healthy

Author: alangmartiniCreated Jul 20, 2026Updated Sep 8, 2026
Labelsbug

Bug Description

In a multi-node (HA) cluster, a follower can receive every committed Raft entry yet permanently stall in the application / indexing path while replaying writes that use an async reference (async_reference: true, i.e. a JOIN field).

The follower's committed_index matches the leader, but its known_applied_index stops advancing, its write queue (queued_writes, backed by reference_q) stays populated and never drains, and /health returns HTTP 503 — while the leader stays HTTP 200, fully applied, with an empty queue.

The single active batched-indexer thread on the follower spins in the async-reference sequencing loop at src/batched_indexer.cpp:366-367, repeatedly scanning the pending request map, so known_applied_index never moves and the follower does not recover on its own. It leaves the read pool indefinitely.

Reproduction Steps

The script below is fully self-contained (Docker + curl). It starts a 3-node cluster, creates a parent collection and three child collections that reference it with async_reference: true, seeds the parent, pauses one follower during an interleaved parent/child write burst, then resumes that follower so it replays the committed reference writes.

Run it with Docker running (no arguments needed):

bash
./reproduce.sh

It prints BUG REPRODUCED and exits 0 only when, at a single observation point: the leader is LEADER / fully applied / HTTP 200, the unconstrained follower is HTTP 200, and the target follower has the leader's full committed index but is HTTP 503 with a populated write queue, at least 1000 entries of apply lag, a known_applied_index that has been flat for at least 15 seconds, and — when GDB is available inside the container — the live batched-indexer thread captured at src/batched_indexer.cpp:366 or :367.

Reproducer script (reproduce.sh)
bash
#!/usr/bin/env bash
# Issue: Async reference replay can wedge a follower in reference_q
# Typesense Version: 31.0.rc10
# Description: A follower replays related collection writes through reference_q,
# accumulates pending write batches, and returns HTTP 503 while the leader is healthy.

set -euo pipefail

# Keep Docker paths literal when this script runs in Git Bash on Windows.
export MSYS_NO_PATHCONV=1

TYPESENSE_API_KEY=xyz
IMAGE=${IMAGE:-typesense/typesense:31.0.rc10}
TARGET_CPUS=${TARGET_CPUS:-0.30}
CAPTURE_STACK=${CAPTURE_STACK:-1}
WRITE_WORKERS=${WRITE_WORKERS:-64}
WRITES_PER_WORKER=${WRITES_PER_WORKER:-500}
WORKLOAD_BATCH=${WORKLOAD_BATCH:-50}
MIN_QUEUED_WRITES=${MIN_QUEUED_WRITES:-100}
MIN_REFERENCE_Q=${MIN_REFERENCE_Q:-50}
MIN_APPLY_GAP=${MIN_APPLY_GAP:-1000}
PLATEAU_SECONDS=${PLATEAU_SECONDS:-15}
MAX_OBSERVE_SECONDS=${MAX_OBSERVE_SECONDS:-180}

SCRIPT_DIR=$(cd "$(dirname "$0")" && pwd)
RUN_DIR="${SCRIPT_DIR}/.run"
ARTIFACT_DIR="${SCRIPT_DIR}/artifacts"
RUN_ID=$(date -u +%Y%m%dT%H%M%SZ)
EVIDENCE_FILE="${ARTIFACT_DIR}/trial-${RUN_ID}.log"
STACK_FILE="${ARTIFACT_DIR}/gdb-${RUN_ID}.txt"

NETWORK=typesense-refq-repro-net
NODE1=typesense-refq-repro-n1
NODE2=typesense-refq-repro-n2
NODE3=typesense-refq-repro-n3
PORT1=19108
PORT2=19118
PORT3=19128
IP1=172.30.31.11
IP2=172.30.31.12
IP3=172.30.31.13
TYPESENSE_HOST="http://localhost:${PORT2}"
LEADER_NODE=''
LEADER_PORT=''
TARGET_NODE=''
TARGET_PORT=''
FAST_NODE=''
FAST_PORT=''

mkdir -p "$ARTIFACT_DIR"
: > "$EVIDENCE_FILE"

log() {
  printf '%s\n' "$*" | tee -a "$EVIDENCE_FILE"
}

cleanup() {
  set +e
  for node in "$NODE1" "$NODE2" "$NODE3"; do
    docker unpause "$node" >/dev/null 2>&1 || true
  done

  for node in "$NODE1" "$NODE2" "$NODE3"; do
    log "=== ${node} relevant logs ==="
    docker logs "$node" 2>&1 \
      | grep -E 'Term:|reference_q.size|lagging entries|queued writes' \
      | tail -80 \
      | tee -a "$EVIDENCE_FILE" >/dev/null || true
  done

  docker rm -f "$NODE1" "$NODE2" "$NODE3" >/dev/null 2>&1 || true
  docker network rm "$NETWORK" >/dev/null 2>&1 || true

  case "$RUN_DIR" in
    "$SCRIPT_DIR"/.run) rm -rf "$RUN_DIR" ;;
    *) log "Refusing to remove unexpected run directory: ${RUN_DIR}" ;;
  esac
}
trap cleanup EXIT

for command_name in docker curl awk grep sed; do
  command -v "$command_name" >/dev/null 2>&1 || {
    log "Missing required command: ${command_name}"
    exit 1
  }
done

docker info >/dev/null 2>&1 || {
  log "Docker is not available"
  exit 1
}

docker rm -f "$NODE1" "$NODE2" "$NODE3" >/dev/null 2>&1 || true
docker network rm "$NETWORK" >/dev/null 2>&1 || true

case "$RUN_DIR" in
  "$SCRIPT_DIR"/.run) rm -rf "$RUN_DIR" ;;
  *) log "Refusing to reset unexpected run directory: ${RUN_DIR}"; exit 1 ;;
esac

mkdir -p "$RUN_DIR/n1" "$RUN_DIR/n2" "$RUN_DIR/n3"
printf '%s\n' \
  "${IP1}:8107:8108,${IP2}:8107:8108,${IP3}:8107:8108" \
  > "$RUN_DIR/nodes"

docker network create \
  --subnet 172.30.31.0/24 \
  "$NETWORK" >/dev/null

start_node() {
  local name=$1
  local ip=$2
  local port=$3
  local cpus=$4
  local data_dir=$5

  docker run -d \
    --name "$name" \
    --network "$NETWORK" \
    --ip "$ip" \
    --cpus "$cpus" \
    --memory 3g \
    --cap-add SYS_PTRACE \
    --security-opt seccomp=unconfined \
    -p "${port}:8108" \
    -v "$RUN_DIR/nodes:/nodes:ro" \
    -v "${data_dir}:/data" \
    "$IMAGE" \
    --data-dir /data \
    --api-key="$TYPESENSE_API_KEY" \
    --api-port 8108 \
    --peering-port 8107 \
    --peering-address "$ip" \
    --nodes /nodes \
    --reset-peers-on-error \
    --thread-pool-size 16 \
    --snapshot-interval-seconds 3600 \
    --healthy-read-lag 1000 \
    --healthy-write-lag 500 >/dev/null
}

wait_for_api() {
  local port=$1
  local attempts=${2:-120}
  local attempt

  for attempt in $(seq 1 "$attempts"); do
    if curl -sS --connect-timeout 1 --max-time 2 \
      "http://localhost:${port}/debug" \
      -H "X-TYPESENSE-API-KEY: ${TYPESENSE_API_KEY}" \
      | grep -q '"state"'; then
      return 0
    fi
    sleep 1
  done

  return 1
}

json_number() {
  local key=$1
  sed -n "s/.*\"${key}\":\([0-9][0-9]*\).*/\1/p"
}

status_json() {
  local port=$1
  curl -sS --connect-timeout 1 --max-time 3 \
    "http://localhost:${port}/status" \
    -H "X-TYPESENSE-API-KEY: ${TYPESENSE_API_KEY}" 2>/dev/null
}

select_roles() {
  local attempt

  for attempt in $(seq 1 60); do
    local status1
    local status2
    local status3
    local leader_count=0

    status1=$(status_json "$PORT1")
    status2=$(status_json "$PORT2")
    status3=$(status_json "$PORT3")

    printf '%s' "$status1" | grep -q '"state":"LEADER"' && leader_count=$((leader_count + 1))
    printf '%s' "$status2" | grep -q '"state":"LEADER"' && leader_count=$((leader_count + 1))
    printf '%s' "$status3" | grep -q '"state":"LEADER"' && leader_count=$((leader_count + 1))

    if [ "$leader_count" -eq 1 ]; then
      if printf '%s' "$status1" | grep -q '"state":"LEADER"'; then
        LEADER_NODE=$NODE1
        LEADER_PORT=$PORT1
        TARGET_NODE=$NODE2
        TARGET_PORT=$PORT2
        FAST_NODE=$NODE3
        FAST_PORT=$PORT3
      elif printf '%s' "$status2" | grep -q '"state":"LEADER"'; then
        LEADER_NODE=$NODE2
        LEADER_PORT=$PORT2
        TARGET_NODE=$NODE1
        TARGET_PORT=$PORT1
        FAST_NODE=$NODE3
        FAST_PORT=$PORT3
      else
        LEADER_NODE=$NODE3
        LEADER_PORT=$PORT3
        TARGET_NODE=$NODE1
        TARGET_PORT=$PORT1
        FAST_NODE=$NODE2
        FAST_PORT=$PORT2
      fi

      TYPESENSE_HOST="http://localhost:${LEADER_PORT}"
      return 0
    fi

    sleep 1
  done

  return 1
}

install_stack_capture() {
  if [ "$CAPTURE_STACK" != "1" ]; then
    return 0
  fi

  log "Installing GDB in the target container for a read only stack capture"
  docker exec "$TARGET_NODE" sh -c \
    'apt-get update >/dev/null && DEBIAN_FRONTEND=noninteractive apt-get install -y gdb >/dev/null'
}

capture_reference_stack() {
  if [ "$CAPTURE_STACK" != "1" ]; then
    return 1
  fi

  docker update --cpus 2 "$TARGET_NODE" >/dev/null
  docker exec "$TARGET_NODE" gdb -q -batch \
    -ex 'set pagination off' \
    -ex 'set print thread-events off' \
    -ex 'thread apply all bt 10' \
    -p 1 > "$STACK_FILE" 2>&1 || true
  docker update --cpus "$TARGET_CPUS" "$TARGET_NODE" >/dev/null

  if grep -E -q 'batched_indexer\.cpp:(366|367)' "$STACK_FILE"; then
    return 0
  fi

  return 1
}

health_code() {
  local port=$1
  curl -sS -o /dev/null -w '%{http_code}' \
    --connect-timeout 1 --max-time 3 \
    "http://localhost:${port}/health" 2>/dev/null || printf '000'
}

wait_for_collection() {
  local port=$1
  local collection=$2
  local max_wait=${3:-120}
  local count=0

  while [ "$count" -lt "$max_wait" ]; do
    if curl -sS -o /dev/null -w '%{http_code}' \
      --connect-timeout 1 --max-time 3 \
      "http://localhost:${port}/collections/${collection}" \
      -H "X-TYPESENSE-API-KEY: ${TYPESENSE_API_KEY}" 2>/dev/null \
      | grep -q '200'; then
      return 0
    fi
    sleep 1
    count=$((count + 1))
  done

  return 1
}

wait_until_caught_up() {
  local port=$1
  local max_wait=${2:-180}
  local count=0

  while [ "$count" -lt "$max_wait" ]; do
    local status
    local committed
    local known
    local applying
    local queued

    status=$(status_json "$port")
    committed=$(printf '%s' "$status" | json_number committed_index)
    known=$(printf '%s' "$status" | json_number known_applied_index)
    applying=$(printf '%s' "$status" | json_number applying_index)
    queued=$(printf '%s' "$status" | json_number queued_writes)

    if [ -n "$committed" ] && [ "$committed" = "$known" ] \
      && [ "${applying:-1}" = "0" ] && [ "${queued:-1}" = "0" ] \
      && [ "$(health_code "$port")" = "200" ]; then
      return 0
    fi

    sleep 1
    count=$((count + 1))
  done

  return 1
}

create_collection() {
  local payload=$1
  curl -sS --fail \
    -X POST "${TYPESENSE_HOST}/collections" \
    -H "X-TYPESENSE-API-KEY: ${TYPESENSE_API_KEY}" \
    -H 'Content-Type: application/json' \
    -d "$payload" >/dev/null
}

log "Image: ${IMAGE}"
log "Starting all three nodes"
start_node "$NODE2" "$IP2" "$PORT2" 8 "$RUN_DIR/n2"
sleep 2
start_node "$NODE3" "$IP3" "$PORT3" 8 "$RUN_DIR/n3"
start_node "$NODE1" "$IP1" "$PORT1" 8 "$RUN_DIR/n1"
wait_for_api "$PORT2"
wait_for_api "$PORT3"
wait_for_api "$PORT1"

select_roles || {
  log "Node 1 status: $(status_json "$PORT1")"
  log "Node 2 status: $(status_json "$PORT2")"
  log "Node 3 status: $(status_json "$PORT3")"
  log "Could not select exactly one leader"
  exit 1
}

log "Selected roles: leader=${LEADER_NODE}, target=${TARGET_NODE}, fast_follower=${FAST_NODE}"
install_stack_capture
docker update --cpus "$TARGET_CPUS" "$TARGET_NODE" >/dev/null

log "Creating one parent and three async reference collections"
create_collection '{
  "name": "products",
  "fields": [
    {"name": "sku", "type": "string"},
    {"name": "price", "type": "int32"}
  ]
}'
for port in "$PORT1" "$PORT2" "$PORT3"; do
  wait_for_collection "$port" products
done

for collection in link_a link_b link_c; do
  create_collection "{
    \"name\": \"${collection}\",
    \"fields\": [
      {
        \"name\": \"sku\",
        \"type\": \"string\",
        \"reference\": \"products.sku\",
        \"async_reference\": true
      },
      {\"name\": \"quantity\", \"type\": \"int32\"}
    ]
  }"
  for port in "$PORT1" "$PORT2" "$PORT3"; do
    wait_for_collection "$port" "$collection"
  done
done

log "Seeding 100 parent documents"
awk 'BEGIN {
  for (i = 0; i < 100; i++) {
    printf "{\"id\":\"product-%d\",\"sku\":\"sku-%d\",\"price\":%d}\\n", i, i, i
  }
}' | curl -sS --fail \
  -X POST "${TYPESENSE_HOST}/collections/products/documents/import?action=upsert" \
  -H "X-TYPESENSE-API-KEY: ${TYPESENSE_API_KEY}" \
  -H 'Content-Type: text/plain' \
  --data-binary @- >/dev/null

for port in "$PORT1" "$PORT2" "$PORT3"; do
  wait_until_caught_up "$port"
done

log "Pausing the target follower before the related collection write burst"
docker pause "$TARGET_NODE" >/dev/null

write_worker() {
  local worker=$1
  local sent=0

  while [ "$sent" -lt "$WRITES_PER_WORKER" ]; do
    local remaining=$((WRITES_PER_WORKER - sent))
    local this_batch=$WORKLOAD_BATCH
    local request_number
    local args=(--fail-early)
    local first=1

    if [ "$remaining" -lt "$this_batch" ]; then
      this_batch=$remaining
    fi

    for request_number in $(seq 1 "$this_batch"); do
      local sequence=$((worker * WRITES_PER_WORKER + sent + request_number))
      local sku=$((sequence % 100))
      local collection
      local body

      case $((sequence % 4)) in
        0)
          collection=products
          body="{\"id\":\"product-${sku}\",\"sku\":\"sku-${sku}\",\"price\":${sequence}}"
          ;;
        1)
          collection=link_a
          body="{\"id\":\"a-${worker}-${sequence}\",\"sku\":\"sku-${sku}\",\"quantity\":${sequence}}"
          ;;
        2)
          collection=link_b
          body="{\"id\":\"b-${worker}-${sequence}\",\"sku\":\"sku-${sku}\",\"quantity\":${sequence}}"
          ;;
        *)
          collection=link_c
          body="{\"id\":\"c-${worker}-${sequence}\",\"sku\":\"sku-${sku}\",\"quantity\":${sequence}}"
          ;;
      esac

      if [ "$first" -eq 0 ]; then
        args+=(--next)
      fi
      first=0
      args+=(
        -sS --fail -o /dev/null --connect-timeout 2 --max-time 30
        -X POST
        "${TYPESENSE_HOST}/collections/${collection}/documents?action=upsert"
        -H "X-TYPESENSE-API-KEY: ${TYPESENSE_API_KEY}"
        -H 'Content-Type: application/json'
        -d "$body"
      )
    done

    curl "${args[@]}"
    sent=$((sent + this_batch))
  done
}

log "Sending $((WRITE_WORKERS * WRITES_PER_WORKER)) related writes to the leader"
worker_pids=()
for worker in $(seq 1 "$WRITE_WORKERS"); do
  write_worker "$worker" &
  worker_pids+=("$!")
done

for worker_pid in "${worker_pids[@]}"; do
  wait "$worker_pid"
done

log "The burst is committed. Waiting for the leader and fast follower to drain"
wait_until_caught_up "$LEADER_PORT"
wait_until_caught_up "$FAST_PORT"

leader_before=$(status_json "$LEADER_PORT")
fast_before=$(status_json "$FAST_PORT")
log "Leader before replay: ${leader_before} health=$(health_code "$LEADER_PORT")"
log "Fast follower before replay: ${fast_before} health=$(health_code "$FAST_PORT")"

log "Resuming the target follower so it replays the committed reference writes"
docker unpause "$TARGET_NODE" >/dev/null

observe_start=$(date +%s)
plateau_known=''
plateau_start=0
reference_stack=0
stack_attempts=0

while true; do
  now=$(date +%s)
  elapsed=$((now - observe_start))
  target_status=$(status_json "$TARGET_PORT")
  leader_status=$(status_json "$LEADER_PORT")
  fast_status=$(status_json "$FAST_PORT")

  target_health=$(health_code "$TARGET_PORT")
  leader_health=$(health_code "$LEADER_PORT")
  fast_health=$(health_code "$FAST_PORT")

  target_last=$(printf '%s' "$target_status" | json_number last_index)
  target_committed=$(printf '%s' "$target_status" | json_number committed_index)
  target_known=$(printf '%s' "$target_status" | json_number known_applied_index)
  target_applying=$(printf '%s' "$target_status" | json_number applying_index)
  target_queued=$(printf '%s' "$target_status" | json_number queued_writes)
  leader_committed=$(printf '%s' "$leader_status" | json_number committed_index)
  leader_known=$(printf '%s' "$leader_status" | json_number known_applied_index)
  leader_queued=$(printf '%s' "$leader_status" | json_number queued_writes)

  current_index=${target_applying:-0}
  if [ "$current_index" = "0" ]; then
    current_index=${target_known:-0}
  fi
  apply_gap=0
  if [ -n "$target_last" ] && [ -n "$current_index" ]; then
    apply_gap=$((target_last - current_index))
  fi

  latest_gc=$(docker logs "$TARGET_NODE" 2>&1 | grep 'reference_q.size' | tail -1 || true)
  reference_q=$(printf '%s' "$latest_gc" \
    | sed -n 's/.*reference_q.size: \([0-9][0-9]*\).*/\1/p')
  reference_q=${reference_q:-0}

  if [ -n "$target_known" ] && [ "$target_known" = "$plateau_known" ]; then
    plateau_age=$((now - plateau_start))
  else
    plateau_known=$target_known
    plateau_start=$now
    plateau_age=0
  fi

  if [ "$stack_attempts" -lt 3 ] \
    && [ "$leader_health" = "200" ] \
    && [ "$target_health" = "503" ] \
    && [ -n "$target_committed" ] \
    && [ "$target_committed" = "$leader_committed" ] \
    && [ "${target_queued:-0}" -ge "$MIN_QUEUED_WRITES" ] \
    && [ "$apply_gap" -ge "$MIN_APPLY_GAP" ] \
    && [ "$plateau_age" -ge "$PLATEAU_SECONDS" ]; then
    stack_attempts=$((stack_attempts + 1))
    if capture_reference_stack; then
      reference_stack=1
      log "Captured the reference sequence thread stack in ${STACK_FILE}"
    else
      log "GDB attempt ${stack_attempts} did not find source line 366 or 367"
    fi
  fi

  log "sample=${elapsed}s leader_health=${leader_health} leader_queue=${leader_queued:-na} leader_commit=${leader_committed:-na} fast_health=${fast_health} target_health=${target_health} target_queue=${target_queued:-na} target_commit=${target_committed:-na} target_gap=${apply_gap} target_known=${target_known:-na} target_applying=${target_applying:-na} reference_q=${reference_q} reference_stack=${reference_stack} plateau=${plateau_age}s"

  if printf '%s' "$leader_status" | grep -q '"state":"LEADER"' \
    && [ "$leader_health" = "200" ] \
    && [ "${leader_queued:-999999}" -le 10 ] \
    && [ -n "$leader_committed" ] \
    && [ "$leader_committed" = "$leader_known" ] \
    && [ "$fast_health" = "200" ] \
    && [ "$target_health" = "503" ] \
    && [ -n "$target_committed" ] \
    && [ "$target_committed" = "$leader_committed" ] \
    && [ "${target_queued:-0}" -ge "$MIN_QUEUED_WRITES" ] \
    && [ "$apply_gap" -ge "$MIN_APPLY_GAP" ] \
    && { [ "$reference_q" -ge "$MIN_REFERENCE_Q" ] || [ "$reference_stack" -eq 1 ]; } \
    && [ "$plateau_age" -ge "$PLATEAU_SECONDS" ]; then
    log "Strict predicate satisfied"
    log "Leader: ${leader_status} health=${leader_health}"
    log "Target follower: ${target_status} health=${target_health}"
    if [ -n "$latest_gc" ]; then
      log "Target follower GC: ${latest_gc}"
    fi
    if [ "$reference_stack" -eq 1 ]; then
      log "Target follower stack: $(grep -E 'batched_indexer\.cpp:(366|367)' "$STACK_FILE" | head -1)"
    fi
    log "BUG REPRODUCED"
    exit 0
  fi

  if [ "$elapsed" -ge "$MAX_OBSERVE_SECONDS" ]; then
    log "Strict predicate was not satisfied within ${MAX_OBSERVE_SECONDS} seconds"
    exit 1
  fi

  sleep 3
done

Expected vs Actual

Expected behavior

A follower whose Raft log is current with the leader should be able to apply the committed async-reference writes and rejoin the read pool. Either write admission on the leader should account for follower application lag, or the follower catch-up path should not be able to stall indefinitely on the async-reference sequencing queue.

Actual behavior

The follower's apply pipeline stalls and never recovers. Reproduced on two consecutive clean runs:

trial-20260718T230312Z
leader:  committed=32006  known_applied=32006  queued_writes=0    health=200
target:  committed=32006  known_applied=1031   applying=2823  queued_writes=217  health=503
stack:   src/batched_indexer.cpp:367

trial-20260718T230645Z
leader:  committed=32006  known_applied=32006  queued_writes=0    health=200
target:  committed=32006  known_applied=1031   applying=2431  queued_writes=222  health=503
stack:   src/batched_indexer.cpp:366

The follower holds the leader's full committed index (committed=32006) but known_applied_index is frozen at 1031, and queued_writes stays populated instead of draining. The one live batched-indexer thread is scanning the pending request map inside the async-reference loop:

Follower batched-indexer thread (GDB — thread apply all bt)
Thread 101 (LWP 139) "typesense-serve":
#0  std::_Rb_tree<unsigned long, ..., BatchedIndexer::req_res_t

Source: typesense/typesense

View original on GitHubView discussion on GitHub