CAS: single-attempt lease renewal trips the mount fence under intermittent store timeouts; recovery takes ~15 min while the data plane rides its retries

[filimonov]

Type of problem

Bug report — availability. A retry-policy asymmetry: the two operations that keep a CAS mount alive (lease renewal, remount claim) are the only S3 operations with no retries at all, so an intermittent-timeout episode that the data plane shrugs off takes the whole disk down for ~15 minutes.

Describe the situation

Found while triaging Stateless tests (amd_binary, cas s3 storage, parallel) on PR #2159 (job 96307284077): 35 test failures, of which 27 fall inside one 14.5-minute window where every durable write on the shared CAS disk was refused with mount fence tripped (3,736 refusals), and the remaining 8 are the same retry-later class scattered earlier in the run.

The trigger and the asymmetry are both visible in the server debug log. Requests to the store intermittently exceeded the 5 s attempt timeout for ~20 minutes (06:40–07:00, server TZ; client-side evidence — the store's own log runs at ERROR-only and cannot locate whether the latency was the store process or CI host contention). The data plane rode straight through it:

06:50:08 AWSClient: Failed to make request to: http://localhost:11121/... Timeout
06:50:08 S3ClientRetryStrategy: Attempt 1/501 failed with retryable error: ... Timeout
06:50:09 S3ClientRetryStrategy: Attempt 2/501 succeeded with response code 200

The mount-lease renewal could not: it is a single conditional PUT with a 5 s attempt timeout, fired once per 10 s renew period, with no in-period retry — a failed renewal continues straight into the next full wait_for(period) (CasServerRoot.cpp, backgroundLoop). With mount_lease_ttl_ms=30000 that gives at most 3 consecutive coin flips against a timeouty store; at 06:55:33 the third one lost and the fence tripped. From that moment renewal is over by design (startBackground: "we never silently re-arm renewal after it has failed") — the only way back is a full remount.

The remount is the second half of the asymmetry. It is a long chain of sequential store operations — sentinel probe, slot read, a ~36.5 s token-stability observation window (ttl + ttl/20 + poll), a claim PUT that is also deliberately single-attempt (ObjectStorageRetryProfile::SingleAttempt), quiesce, ledger recovery — where any one timeout fails the whole attempt, followed by 1→30 s exponential backoff. Staying Live costs one successful PUT per 10 s; getting back to Live costs an unbroken run of ~15+ successes plus a stable 36.5 s window. Under an intermittent-timeout episode the first is likely to fail eventually and the second is unlikely to succeed soon: the fence stayed tripped 06:55:33 → 07:10:00, and the first sign of a completed remount is at 07:11:39.

A possible self-reinforcing loop makes it worse (same family as the fixed STID-3982 renewal self-race, unprovable from these logs): a claim PUT aborted by the client timeout can still land server-side, moving the slot token — which resets the token-stability window the next attempt needs.

Consequences inside the window, all fail-closed but total:

• every durable write refused instantly (mount fence tripped, 3,736×), 163 retry budget exhausted operation failures, CREATE TABLEs failing at namespace birth (the mount incarnation moved while birthing its catalog entry);
• system-log tables live on the same disk, so their flushes fail too, and one ref table's snapshot publisher spun on refusing snapshot publication while the append lane is not Ready — 125,952 Warning lines in 16 minutes (no backoff/rate limit on that loop);
• none of the cause is observable at default log level: no log line for the fence trip itself, none for renewal failures at the moment they matter, none per remount attempt. The window's cause had to be reconstructed from debug-level S3ClientRetryStrategy lines and the RustFS-side disconnect log.

(For scale: the RustFS log's 9,775 "errors" are mostly a red herring — ~700 of them match client-side logged failures; the rest are ClickHouse's silent-by-design mid-body aborts — cancelled queries, LIMIT, abandoned prefetches — which RustFS reports as Erasure decode failed ... downstream_closed.)

How to reproduce the behavior

• Version: 26.6.2.20000.altinityantalya, PR [experimental] CAS (Content-addressed storage) over shared object storage for antalya-26.6 #2159 at 3ba1ac283f6 (amd release)
• Observed in CI; any CAS pool whose store intermittently exceeds the 5 s attempt timeout for ≳30 s reproduces the trip. Deterministic local repro shape: run inserts against a CAS disk behind a fault proxy (utils/ca-soak/docker-compose-s3faultproxy.yml) injecting ~50% per-request delays >5 s for one minute — data-plane writes survive on retries, the lease trips, and the disk refuses everything for on the order of the observation window × failed attempts.

Expected behavior

The lease renewal should survive any store episode the data plane survives: if Attempt 2/501 succeeded is the norm around it, one lost single-shot PUT per 10 s must not be able to escalate into a full-disk outage. When a trip does happen, recovery should not require an unbroken multi-operation success chain under the same degraded conditions, and both the trip and every remount attempt should be observable at default log level.

Actual behavior

See above: trip after 3 unretried single-shot failures; ~15 minutes of full-disk write refusal; cause invisible at default log level; 126k warning spam from one publisher loop.

Suggested fix (in value order)

1. In-period renewal retries: on a failed renewal PUT, retry within the current period while now + margin < confirmed_deadline instead of sleeping the full period. The Attempt 2 succeeded pattern in this incident says this alone would have prevented the trip.
2. Per-step retries in the remount chain (probe, slot read, observation polls, claim) with the same budget discipline as data-plane ops — keeping the claim PUT itself conditional/exclusive, but not one-shot; plus a look at whether an own ambiguous landed claim resets the next attempt's observation window.
3. Observability: log the fence trip (with reason: renewal deadline vs FORGET vs identity) and each remount attempt's step outcome at default level; ProfileEvents for renewals failed/retried and remount attempts.
4. Rate-limit the snapshot-publication refusal loop (125,952 warnings / 16 min on one table).

Additional context

• Job: https://github.com/Altinity/ClickHouse/actions/runs/32320205125/job/96307284077 (artifacts: clickhouse-server.log.zst for the S3ClientRetryStrategy / budget evidence, clickhouse-server.err.log.zst for the refusal window, rustfs.log)
• RustFS in this CI env logs at ERROR only (its whole log is two client-disconnect error classes), so it can neither corroborate nor locate the latency; raising its log level / capturing request-latency stats belongs to the observability ask.
• Related: CAS: object-store connections exhaust the container's ephemeral ports, fencing out the mount lease #2243 — the same lease fragility reached from a different trigger (local port exhaustion); fix directions 1–3 there and here are the same work.
• The renewal single-attempt profile itself is intentional for conditional-write correctness (an ambiguous PUT must not be blindly re-fired with the same token); the ask is not to remove that property but to add a classified retry (re-read → re-CAS) inside the period, which the renewal path already knows how to do on the PreconditionFailed arm.