diff --git a/docs/en/antalya/cas/architecture/mounts-and-leases.md b/docs/en/antalya/cas/architecture/mounts-and-leases.md index eb852b070da0..e8ef85af7a12 100644 --- a/docs/en/antalya/cas/architecture/mounts-and-leases.md +++ b/docs/en/antalya/cas/architecture/mounts-and-leases.md @@ -83,12 +83,14 @@ watermark — there is no separate watermark object. `MountLease` fields: `serve equals its immutable request. If the predecessor token is still current, another identical `PUT` may follow bounded backoff. A same-pair twin, GC-fenced body, successor, foreign holder, or absent body is never treated as this renewal. -- **Absolute deadline.** Renewal uses `CLOCK_BOOTTIME`, not `CLOCK_MONOTONIC`, so a VM resumed from - suspend correctly observes itself expired. Its absolute deadline is the minimum of the existing - request-operation budget and the last confirmed lease deadline minus the safety margin. The - controller checks that one attempt envelope still fits before each backend `PUT` or resolving - `GET`, after each interruptible backoff, and before accepting success. A retry, `GET`, response - timestamp, or wall-clock step never extends authority. +- **Lease deadline.** The lease is valid for `cas_mount_lease_ttl_ms` from the start of the last + confirmed renewal. It is measured on `CLOCK_BOOTTIME`, not `CLOCK_MONOTONIC`, so a VM resumed from + suspend correctly observes itself expired. The deadline decides about writes: none is admitted past + it, and none is admitted once the remaining lease cannot cover the requests it may send plus the + safety margin. The background renewal does not stop at the deadline. It retries timeouts, `5xx` + answers and connection errors about a second apart until the store answers. The renewals at startup, + after a remount and the direct renewal stay bounded: they stop at the last confirmed deadline minus + the safety margin. A retry, `GET`, response timestamp, or wall-clock step never extends authority. - **Cadence.** The runtime normally starts a logical renewal every `cas_mount_renew_period_ms` (default 10 s), with TTL `cas_mount_lease_ttl_ms` (default 30 s, TTL/3 renewal ratio). The next beat is anchored at the committed body's pre-I/O BOOTTIME start. A slow recovery therefore causes an immediate @@ -101,43 +103,79 @@ watermark — there is no separate watermark object. `MountLease` fields: `serve `2 × envelope + safety_margin` fits inside the remaining lease (a write and its settlement read), rejecting with `BAD_ARGUMENTS` at request-admission time rather than mid-flight. -**Losing the lease is neither read-only mode nor a process abort.** `MountLeaseRenewer` is a -synchronous durable-slot state machine. A committed result advances its token, sequence, confirmed -BOOTTIME deadline, and cadence anchor. Any admitted deterministic failure, confirmed conflict, or -ambiguity left at the deadline/attempt limit moves it to `RenewalTerminal`; it cannot mint another -body or publish a clean farewell. Owner cancellation before any request is the only -`NotAttempted` result and leaves clean release possible. Cancellation after a request was sent is -terminal because that request may still land. +**A transient renewal failure does not end the mount.** `MountLeaseRenewer` is a synchronous +durable-slot state machine. A committed result advances its token, sequence, confirmed BOOTTIME +deadline, and cadence anchor. The background renewal ends, and moves the renewer to `RenewalTerminal`, +only on one of these: + +- a definitive answer from the store: a confirmed foreign, successor or same-pair body, `gc_fenced`, an + absent object, or a request the store refuses on a clear attempt; +- a stop or a remount request; +- a deterministic local failure; +- a lifecycle other than `Live`; +- a lost fence. + +A terminal renewer cannot mint another body or publish a clean farewell. Owner cancellation before +any request is the only `NotAttempted` result and leaves clean release possible. Cancellation after a +request was sent is terminal because that request may still land. + +While retries continue past the lease deadline, the lease is *expired*. New durable writes are refused +with a transient `NETWORK_ERROR` that names the lease, reads are not gated, and the pool does not +remount. Writes are admitted again, under the same `writer_epoch`, when a renewal succeeds and leaves +enough lease for a write's reservation. A renewal that succeeds after its own deadline (its start plus +the TTL has already passed) leaves the lease expired, and the next renewal follows at once. +The log carries one `WARNING` when the lease expires, written at the first request of the renewal +after the expiry (a request that hangs delays it by up to one attempt timeout), and the restore +`WARNING` when a renewal restores it. +`system.cas_mounts` shows the expired period as `lifecycle = 'not_live'`, +`lifecycle_reason = 'lease_expired'` (see [`system.cas_mounts`](#mounts-table)); it shows +`lifecycle = 'live'` until the deadline passes, although with the defaults conditional writes stop +16 s earlier. The `CASMountLeaseExpired` event advances by one when a renewal restores an expired +lease, not when the lease expires. Failing renewals alone do not fence or remount the mount. A GC +leader on another member still fences a slot whose token has not changed for +`TTL + floor(TTL/20) + period`, and a definitive answer from the store that the slot holds something +else ends it; in both cases the server remounts under a new `writer_epoch`. After the renewer call returns, `CasMountRuntime` consumes the result. A terminal result trips the local fence (latches `lost`, bumps the fence generation, moves the in-process runtime to `TransientNotLive`) and latches one self-remount generation. A confirmed foreign/successor or same-pair conflict remains a typed fail-closed error; it is never adopted. A real fence still costs only an epoch: recovery reclaims with a fresh one, bounded at three whole-chain attempts. This is the -general CAS posture: doubt about the source fails closed, while transport ambiguity may retry only -inside authority already proved by the last confirmed lease. - -GC's own view of a dead server is symmetric and clock-skew-immune: a slot becomes fence-eligible -only after the leader observes the *same* renewal token hold stable, on its own monotonic clock, -for `TTL + floor(TTL/20) + period` — close to, but not identical to, the threshold a re-mounting -server uses to wait out a predecessor, which observes `TTL + floor(TTL/20) + max(1, -floor(period/2))`. Both thresholds are evaluated purely on the observer's own clock and its own -configured `TTL`/`period`; nothing about the writer's timing travels on the wire. The stamped -`expires_at_ms` never participates in either decision — it is a writer-stamped diagnostic used by -`system.cas_mounts` and by the non-authoritative decommission epoch-recovery precheck, never an -authorization; local fencing is derived instead from the confirmed request's pre-I/O `BOOTTIME` -anchor plus the TTL, and wall-clock `now` stays audit-only. +general CAS posture: doubt about the source fails closed. Fenced mutations and the bounded renewals +(startup, remount and direct) retry transport ambiguity only inside authority already proved by the last +confirmed lease. The background renewal may keep retrying after that lease has expired; write authority +stays bounded by the start of the renewal that last succeeded plus the TTL. + +GC's own view of a dead server is symmetric and clock-skew-immune: a slot becomes fence-eligible only +after the leader observes the *same* renewal token hold stable, on its own monotonic clock, for `TTL + +floor(TTL/20) + period` — close to, but not identical to, the threshold a re-mounting server uses to +wait out a predecessor, which observes `TTL + floor(TTL/20) + max(1, floor(period/2))`. GC starts +counting from a clock sample taken after the read that returned the token, so time the round spent on a +slow `LIST` or `GET` before that read is not credited as time spent watching. Both thresholds are +evaluated purely on the observer's own clock and its own configured `TTL`/`period`; nothing about the +writer's timing travels on the wire. The stamped `expires_at_ms` never participates in either decision — +it is a writer-stamped diagnostic used by `system.cas_mounts` and by the non-authoritative decommission +epoch-recovery precheck, never an authorization; local fencing is derived instead from the confirmed +request's pre-I/O `BOOTTIME` anchor plus the TTL, and wall-clock `now` stays audit-only. Every server sharing a pool must therefore run the identical `cas_mount_lease_ttl_ms` and -`cas_mount_renew_period_ms`: a member or GC leader configured with a shorter threshold than its -peers can fence out a healthy peer whose token-update gap merely exceeds that shorter threshold — -a peer renewing frequently stays live, one that missed a renewal does not. Change these values only -with every member of the pool stopped; a graceful restart removes only that member's own startup -observation and does not make mixed thresholds safe. With the defaults (TTL 30 s, period 10 s, -margin 2 s), `TTL − margin − period − 2 × envelope = 4 s` is the scheduling-lateness budget before -the first renewal attempt of a period can begin, where `envelope = attempt_timeout + 2 × cap` and -`cap` is `attempt_timeout` when the disk's `connect_timeout_ms` is `0`, else -`min(connect_timeout_ms, attempt_timeout)` (7 s with defaults). +`cas_mount_renew_period_ms`: a member or GC leader configured with a shorter threshold than its peers +can fence out a healthy peer whose token-update gap merely exceeds that shorter threshold — a peer +renewing frequently stays live, one that missed a renewal does not. Change these values only with every +member of the pool stopped; a graceful restart removes only that member's own startup observation and +does not make mixed thresholds safe. With the defaults (TTL 30 s, period 10 s, margin 2 s), the startup +check `period + 2 × envelope + margin < TTL` leaves `TTL − margin − period − 2 × envelope = 4 s` of +slack: a renewal that starts up to 4 s late still leaves time to admit a write before the next one. A +write is admitted only while the remaining lease exceeds the time its requests may still take plus the +margin. A conditional write reserves two envelopes on every attempt (the attempt and the read that +settles it; a ref-log append reserves the same). A removal that re-observes the key after a mismatch +reserves two plus its pause, and a retried sentinel probe reserves one plus its pause. With the defaults +a conditional write is refused once less than 16 s of the lease remains, a retried sentinel probe once +less than 9 s remains. Renewals start every 10 s, so the lease has 30 s left after one and 20 s just +before the next; if renewals keep failing, conditional writes stop 14 s after the last confirmed renewal +started, about 4 s after the next one was due. Here `envelope = attempt_timeout + 2 × cap` and `cap` is +`attempt_timeout` when the disk's `connect_timeout_ms` is `0`, else `min(connect_timeout_ms, +attempt_timeout)` (7 s with defaults). ## The two monotone counters {#counters} @@ -205,7 +243,7 @@ The in-process `PoolLifecycle` runtime, by contrast, is a literal enum (`CasMoun stateDiagram-v2 [*] --> Live: Pool constructed, fence unarmed Live --> Live: mountWritable arms the fence - Live --> TransientNotLive: renewal failure, tripMountLost, lost=true + Live --> TransientNotLive: terminal renewal result, tripMountLost, lost=true TransientNotLive --> Live: self-remount succeeds with a fresh epoch TransientNotLive --> TransientNotLive: probe inconclusive, retry with backoff TransientNotLive --> IdentityLost: pool meta and owner both authoritatively absent @@ -268,7 +306,11 @@ becomes `state = 'corrupt'`, never an exception). Shows every `server_root_id` i | `writer_epoch`, `renewal_sequence`, `started_at`, `expires_at`, `min_active_build_sequence`, `gc_fenced` | lease state (`DateTime64(3)` columns; the millisecond-integer field names live only in the internal `MountLease` struct and the on-disk body) | | `state` | one of `live`, `expired`, `terminated`, `fenced`, `corrupt` | | `is_leader`, `pending_reclaim`, `last_success_age_seconds`, `wedged_namespace_count` | GC health, process-local; **`NULL` on every peer row** — a process-local fact must never be stamped onto another server's row | -| `lifecycle`, `lifecycle_reason`, `lifecycle_detail`, `lifecycle_since` | the SQL surface for the in-process `PoolLifecycle` runtime above: `lifecycle` is one of `live`, `not_live`, `identity_lost`, `vanished`, `constructing`, `shutdown`; `lifecycle_reason` distinguishes `replaced` from `forgotten` for a `vanished` disk; `lifecycle_detail` carries the full diagnosis text; `lifecycle_since` is when the current non-live state began (`NULL` while live) | +| `lifecycle`, `lifecycle_reason`, `lifecycle_detail`, `lifecycle_since` | the SQL surface for the in-process `PoolLifecycle` runtime above: `lifecycle` is one of `live`, `not_live`, `identity_lost`, `vanished`, `constructing`, `shutdown`; `lifecycle_reason` distinguishes `replaced` from `forgotten` for a `vanished` disk, and is `lease_expired` for a `not_live` disk whose lease deadline has passed while renewals keep failing; `lifecycle_detail` carries the full diagnosis text (for `lease_expired`, the text of the last failed renewal request, empty if none failed); `lifecycle_since` is when the current non-live state began (for `lease_expired`, the passed deadline; `NULL` while live) | + +`lifecycle_reason = 'lease_expired'` reports this server's own confirmed lease deadline. The `state` +column is a different signal: it is derived from the body's wall-clock `expires_at` plus a skew +allowance. The two need not agree. The lifecycle snapshot is I/O-free and ungated, so a not-live, never-started, or vanished disk still produces a row instead of silently disappearing from the table. diff --git a/docs/en/antalya/cas/configuration.md b/docs/en/antalya/cas/configuration.md index 17b1e3482768..3e19b981fe2e 100644 --- a/docs/en/antalya/cas/configuration.md +++ b/docs/en/antalya/cas/configuration.md @@ -96,7 +96,7 @@ entirely before release. Treat this table as a snapshot of the current build, no | `cas_blob_hash` | `cityhash128` | Pool blob content-hash function (`cityhash128` \| `xxh3-128` \| `sha256`). Recorded in the pool at creation; a mismatching config is refused at mount | | `cas_blob_hash_allow_new` | `false` | Explicit opt-in to admit a new hash algorithm into an existing pool. One-way: once admitted, the pool carries both algorithms permanently | | `skip_access_check` | `false` | Skip the boot-time capability probe (start now, fix later). Only the preflight probe is skipped — the conditional-write correctness check still runs on every writable mount. **Not available on a writable generation-token (GCS) disk**, which refuses to mount with it: there, the probe battery is the only proof that a token-exact delete carries its generation precondition. Mount such a disk read-only if you need to defer the check | -| `cas_mount_lease_ttl_ms` | `30000` | Milliseconds for which a mount lease remains valid after a successful claim or renewal (≥ 1). Lower values shorten stale-mount recovery but reduce tolerance for object-storage and scheduling delays | +| `cas_mount_lease_ttl_ms` | `30000` | Milliseconds for which a mount lease remains valid after the start of a successful claim or renewal (≥ 1). Writes are never admitted past it, and stop earlier (see below). The background renewal keeps retrying after it until the store answers, so a failing or timing-out renewal does not by itself fence or remount the mount; GC on another pool member can still fence it after the observation threshold below, and a definitive answer from the store (`gc_fenced`, a foreign or successor body, an absent object) ends it. Lower values shorten stale-mount recovery but shorten the outage that writes ride out | | `cas_mount_renew_period_ms` | `10000` | Milliseconds between background mount-lease renewals (≥ 1). It must leave enough time for two attempt envelopes (a renewal write and its settlement read) and the lease safety margin before the TTL expires: `period + 2 × envelope + margin < TTL` | | `cas_gc_snapshot_generations_to_keep` | `3` | GC snapshot generations retained | | `cas_gc_shards` | `1` | Blob-hash-prefix reducer shards (≥ 1). Recorded in the pool at creation; a mismatching config is refused at mount | @@ -117,21 +117,33 @@ Startup reclaim and GC's fence-out both judge liveness by the mount slot's write on the observer's own `CLOCK_BOOTTIME`, using the observer's own threshold — nothing about a writer's timing travels on the wire. Startup observes `cas_mount_lease_ttl_ms + floor(cas_mount_lease_ttl_ms / 20) + max(1, floor(cas_mount_renew_period_ms / 2))`; GC observes `cas_mount_lease_ttl_ms + -floor(cas_mount_lease_ttl_ms / 20) + cas_mount_renew_period_ms`. A pool member or GC leader +floor(cas_mount_lease_ttl_ms / 20) + cas_mount_renew_period_ms`. GC counts the observation from a clock sample taken after the read that returned the token, not from the start of its round. A pool member or GC leader configured with a shorter threshold than its peers can therefore fence out a healthy peer whose token-update gap exceeds that shorter threshold — a peer renewing frequently stays live, one that missed a renewal does not. Change these values only with every member of the pool stopped: a graceful restart removes only that member's own startup observation and does not make mixed thresholds safe. -A shorter TTL reduces the tolerance for object-storage delays; a shorter renewal period increases it -(renewal starts earlier) at the cost of more background traffic. With the defaults, -`cas_mount_lease_ttl_ms − cas_lease_safety_margin_ms − cas_mount_renew_period_ms − 2 × envelope = -4000` ms is the scheduling-lateness budget before the first renewal attempt of a period can begin, -where `envelope = cas_attempt_timeout_ms + 2 × cap` (7000 ms with defaults) and `cap` is -`cas_attempt_timeout_ms` when the disk's `connect_timeout_ms` is `0`, else -`min(connect_timeout_ms, cas_attempt_timeout_ms)` (1000 ms with defaults); the renewal then keeps -retrying until `confirmed deadline − cas_lease_safety_margin_ms`. +A longer TTL lengthens the outage that writes ride out without a refusal. A shorter renewal period starts +each renewal earlier, so more of the TTL is left when one fails, at the cost of more background traffic. +With the defaults, `cas_mount_lease_ttl_ms − cas_lease_safety_margin_ms − cas_mount_renew_period_ms − +2 × envelope = 4000` ms is the slack the startup check leaves: a renewal that starts up to that late +still leaves time to admit a write before the next one. Here `envelope = cas_attempt_timeout_ms + 2 × cap` +(7000 ms with defaults) and `cap` is `cas_attempt_timeout_ms` when the disk's `connect_timeout_ms` is `0`, +else `min(connect_timeout_ms, cas_attempt_timeout_ms)` (1000 ms with defaults). The background renewal +retries, about a second apart, until the store answers. It does not stop at the lease deadline. + +A write is admitted only while the remaining lease exceeds the time its requests may still take plus +`cas_lease_safety_margin_ms`. A conditional write (create, replace, read-modify-write) reserves two +attempt envelopes on every attempt: the attempt and the read that settles it. A removal that re-observes +the key after a mismatch reserves two plus its pause, and a sentinel probe that is retried reserves one +plus its pause. With the defaults (envelope 7000 ms, margin 2000 ms) a conditional write is therefore +refused once less than 16000 ms of the lease remains, and a retried sentinel probe once less than 9000 +ms remains. The lease is renewed every `cas_mount_renew_period_ms` (10000 ms) from the start of the last +confirmed renewal, so it has 30000 ms left after a renewal and 20000 ms just before the next one. If +renewals keep failing, conditional writes are refused from 14000 ms after the last confirmed renewal +started, about 4000 ms after the next one was due. `system.cas_mounts` shows `lifecycle = 'live'` until +the deadline itself passes; from then it shows `lifecycle_reason = 'lease_expired'`. The `expires_at_ms` stamped into the mount object is a writer-stamped diagnostic used by `system.cas_mounts` and by the non-authoritative decommission epoch-recovery precheck; it never diff --git a/docs/en/antalya/cas/operations/debugging.md b/docs/en/antalya/cas/operations/debugging.md index d7c2efa9f668..7fbdaa5f6680 100644 --- a/docs/en/antalya/cas/operations/debugging.md +++ b/docs/en/antalya/cas/operations/debugging.md @@ -121,17 +121,18 @@ WHERE disk_name = 'cas' ORDER BY event_time_microseconds; ``` -A `watermark_renew` row now carries only two detail keys beyond the identifying ones: -`attempts_sent` (the number of physical HTTP attempts the whole logical renewal made) and -`classification`. There is no per-attempt `retrying` row any more — a renewal that recovers after -one or more physical attempts produces exactly one `recovered` row when it settles, not a `retrying` -row followed by a `recovered` one — and the older `unresolved_reason`, `deadline_source`, and -`stop_cause` keys are gone; everything they used to distinguish is now named directly by -`classification`. Interpret the sequence as follows: - -- `outcome = 'recovered'` means an in-budget renewal landed, in the same epoch. `classification` - says how: `committed_by_read` means an exact `GET` proved a landed request; `committed_after_retry` - means a later identical physical `PUT` completed and the response itself proved it. +A `watermark_renew` row carries `attempts_sent` (the number of physical HTTP attempts the whole logical +renewal made), `classification` and, on the renewal that restored an expired lease, `expired_ms`. A +renewal that recovers after one or more physical attempts produces exactly one `recovered` row when it +settles; there is no per-attempt row. `classification` names what happened. Interpret the sequence as +follows: + + +- `outcome = 'recovered'` means a renewal landed in the same epoch after a retry, an exact `GET`, or an + expired lease. `classification` says how: `committed_by_read` means an exact `GET` proved a landed + request; `committed_after_retry` means a later identical physical `PUT` completed and the response + itself proved it; `committed_after_expiry` means the renewal restored a lease that had expired (the + row also has `expired_ms`). When more than one applies, the first of those three in that order wins. - `outcome = 'failed'` carries the decisive `classification`: `external_lease_deadline` (the confirmed lease's own safety margin, not the request policy, ran out first — check object-store latency or `BOOTTIME` advancement before anything else), `request_deadline` (the ninety-second diff --git a/docs/en/antalya/cas/operations/monitoring.md b/docs/en/antalya/cas/operations/monitoring.md index 8bde03328575..8ee1610ece20 100644 --- a/docs/en/antalya/cas/operations/monitoring.md +++ b/docs/en/antalya/cas/operations/monitoring.md @@ -55,16 +55,17 @@ window and correlate them with the `server_root_id` in `system.cas_log`. | Metric | Counting dimension | Interpretation | |---|---|---| -| `CASMountRenewalAttempts` | One per physical conditional renewal `PUT` sent | Physical object-store load; one logical renewal can contribute several | +| `CASMountRenewalAttempts` | One per physical conditional renewal `PUT` sent | Physical object-store load; one logical renewal can contribute several. The background renewal counts each `PUT` as it is sent, so the counter advances during an outage while `PUT`s are being sent | | `CASMountRenewalRetries` | One per physical renewal `PUT` after the first in the same logical renewal | Positive growth shows in-period retry, not a later cadence beat | | `CASMountRenewalResolved` | One per logical renewal proved committed by an exact resolving `GET` | A response was ambiguous, but exact bytes and `write_attempt_id` proved the write | | `CASMountRenewalRecovered` | One per logical renewal committed after a retry or exact resolving `GET` | Recovered object-store blips that retained the existing mount incarnation | -| `CASMountRenewalDeadlineExceeded` | One per logical renewal stopped by the external lease-safety deadline | The last confirmed lease no longer left enough safe time; this is narrower than request-budget exhaustion | +| `CASMountRenewalDeadlineExceeded` | One per logical renewal stopped by the external lease-safety deadline | The last confirmed lease no longer left enough safe time; this is narrower than request-budget exhaustion. Only the bounded renewals (startup, remount and direct) can reach it; the background renewal does not | +| `CASMountLeaseExpired` | One per renewal that restored a lease that had expired | Moves at the restore, not when the lease expires. While it is expired, `system.cas_mounts` shows `lifecycle_reason = 'lease_expired'` and writes are refused; the `watermark_renew` row of the restoring renewal carries `expired_ms` | | `CASRemountAttempts` | One per invocation of the existing whole-chain remount attempt | Includes both successful and failed attempts | | `CASRemountSucceeded` | One per whole-chain attempt that restored `Live` under a fresh writer epoch | Must be a subset of `CASRemountAttempts` | | `CASRemountFailed` | One per whole-chain attempt that returned without restoring `Live` | Includes a named step exception or a step that returned transiently | -`CASMountLeaseLost` complements those eight counters. It increments exactly once per operational +`CASMountLeaseLost` complements those nine counters. It increments exactly once per operational `Live -> TransientNotLive` recovery generation: either the initiating external loss or the first ordinary terminal renewal consumer owns it. A parked terminal result and shutdown do not duplicate the count. @@ -77,24 +78,28 @@ FROM system.events WHERE event IN ( 'CASMountRenewalAttempts', 'CASMountRenewalRetries', 'CASMountRenewalResolved', 'CASMountRenewalRecovered', 'CASMountRenewalDeadlineExceeded', 'CASMountLeaseLost', - 'CASRemountAttempts', 'CASRemountSucceeded', 'CASRemountFailed') + 'CASMountLeaseExpired', 'CASRemountAttempts', 'CASRemountSucceeded', 'CASRemountFailed') SETTINGS system_events_show_zero_values = 1; ``` `system.cas_log` records only nontrivial logical renewals. A `watermark_renew` row has outcome -`recovered` or `failed` — there is no per-attempt `retrying` row; the terminal event is the whole -story — with detail keys `server_root_id`, `writer_epoch`, `seq`, a shortened `write_attempt_id`, -`attempts_sent`, `elapsed_ms`, `remaining_confirmed_budget_ms`, and `classification`. The older -`unresolved_reason`, `deadline_source`, and `stop_cause` keys no longer exist; `classification` -carries what they used to say between them (see [debugging](/antalya/cas/operations/debugging#trace-renewal-remount) -for the full value list). Ordinary first-attempt -success produces no row. Every `mount_remount` attempt produces one final row with outcome `ok` or +`recovered` or `failed`; it is the single terminal event of the logical renewal, with detail keys `server_root_id`, `writer_epoch`, `seq`, a shortened `write_attempt_id`, +`attempts_sent`, `elapsed_ms`, `remaining_confirmed_budget_ms`, and `classification`, plus +`expired_ms` on the renewal that restored an expired lease. `classification` carries the cause (see +[debugging](/antalya/cas/operations/debugging#trace-renewal-remount) for the full value list). +Ordinary first-attempt success produces no row. Every `mount_remount` attempt produces one final row with outcome `ok` or `failed` and details `attempt_no`, `step`, `server_root_id`, optional `writer_epoch`, and optional `error`. -Default-level text logging is bounded per logical operation: the first ambiguous transition may -emit one retry `WARNING`, followed by one recovery `INFO` or final fence `WARNING`; individual -physical retries remain `DEBUG`. Each whole-chain remount attempt emits one final default-level line +Default-level text logging is bounded per logical operation. A renewal logs nothing until it ends, +and nothing at all when it succeeds on its first request. A renewal that needed a retry, was settled +by a read, or restored an expired lease emits one recovery `INFO`; a terminal renewal emits one fence +`WARNING`. An expired lease emits one `WARNING` when it expires, written at the first request of the +renewal after the expiry (a request that hangs delays it by up to one attempt timeout), and a renewal +that restores it emits one `WARNING` with the expired duration and the last failed request. The live +state during the outage is the row in `system.cas_mounts`. +Individual physical retries are not logged. Each whole-chain remount attempt emits one final +default-level line with its attempt number and last/current step. Use the structured rows for correlation instead of counting backend-attempt log lines. diff --git a/docs/en/antalya/cas/operations/troubleshooting.md b/docs/en/antalya/cas/operations/troubleshooting.md index 1113ec1855dd..6d3631307f6f 100644 --- a/docs/en/antalya/cas/operations/troubleshooting.md +++ b/docs/en/antalya/cas/operations/troubleshooting.md @@ -16,7 +16,8 @@ tools. | Symptom | Diagnosis | Action | |---|---|---| -| A server keeps losing its mount lease and self-remounting | Check `system.cas_mounts` for the server's own `state`/`expires_at`, then correlate `watermark_renew` and `mount_remount` in `system.cas_log`; losing the lease trips a local fence and latches a remount generation | Read the failed renewal's `classification` before changing anything — it alone now says why (see [the decision flow](#mount-renewal-remount-flow)). Look for object-store latency consuming the confirmed lease or BOOTTIME advancement; see [the mount lease](/antalya/cas/architecture/mounts-and-leases#mount-lease) | +| A server keeps losing its mount lease and self-remounting | Check `system.cas_mounts` for the server's own `state`/`expires_at`, then correlate `watermark_renew` and `mount_remount` in `system.cas_log`; losing the lease trips a local fence and latches a remount generation | Read the failed renewal's `classification` before changing anything — it alone now says why (see [the decision flow](#mount-renewal-remount-flow)). Only the bounded renewals (startup, remount and direct) can exceed a lease deadline; the background renewal does not. For those, look for object-store latency consuming the confirmed lease or BOOTTIME advancement; see [the mount lease](/antalya/cas/architecture/mounts-and-leases#mount-lease) | +| Writes fail with a transient error that names the lease and recover on their own | `system.cas_mounts` shows `lifecycle = 'not_live'`, `lifecycle_reason = 'lease_expired'` for the disk; `lifecycle_detail` is the text of the last failed renewal request. While refusals have started but the deadline has not passed, the row still shows `lifecycle = 'live'` (with the defaults, for the last 16 s of the lease); `lease_expired` appears once the deadline passes. `CASMountLeaseExpired` in `system.events` counts the expiries that a restore ended, not those that ended in a remount or a shutdown, and the `watermark_renew` row that ended one carries `expired_ms` in `detail` | The server could not renew its lease for longer than `cas_mount_lease_ttl_ms`, so it refuses writes until a renewal succeeds and leaves enough lease for a write's reservation. A renewal that succeeds after its own deadline (its start plus `cas_mount_lease_ttl_ms` already past) does not, and the next renewal follows at once. Failing renewals alone do not fence or remount it: it keeps the same `writer_epoch` unless a GC leader on another member fences the slot (token unchanged for `cas_mount_lease_ttl_ms + floor(cas_mount_lease_ttl_ms / 20) + cas_mount_renew_period_ms`) or the store answers definitively that the slot holds something else, and then it remounts under a new `writer_epoch`. Fix the object-store path named in `lifecycle_detail` (reachability, throttling, credentials). `CASMountRenewalAttempts` and `CASMountRenewalRetries` advance when a `PUT` is sent. When one `PUT` is unclear and only the reads that settle it fail, they stand still and the failure shows in `lifecycle_detail`. If `CASMountLeaseLost` rises as well, follow [the decision flow](#mount-renewal-remount-flow) | | Writes slow down or stall under load, with no exception reaching the client | S3 `SlowDown`/`ServiceUnavailable`/`RequestTimeout`/`InternalError` (5xx) responses are not on the request engine's `isDefinitelyRefusedWrite` definite-failure list (only malformed-request, entity-too-large, and access-denied that no credential refresh can fix are), so they classify as ambiguous and are retried automatically. Confirm with `sum(ProfileEvents['CASConditionalWriteUnresolved'])` rising alongside `sum(ProfileEvents['CASConditionalWriteAttempts'])` over `system.query_log` for the affected window (or `ProfileEvent_CASConditionalWriteUnresolved` in `system.metric_log` for a cumulative view across queries), and check `system.blob_storage_log` for `disk_name = ''` rows with a nonzero `error_code` around the same window | Nothing to configure per-request: the request engine retries the same `(key, bytes)` with capped-exponential backoff (200ms initial, capped at 5s, full jitter) until the 90-second operation deadline — there is no separate attempts ceiling, only the deadline — and the mount-lease renewer keeps extending the fence across the disruption — this is the "blips, throttling, partial outages" case the write path is built to survive. Confirm the mount lease itself is still renewing (`system.cas_mounts.expires_at` moving forward, `last_success_age_seconds` not climbing) — if it is, this is expected and self-resolving. If `SlowDown` responses are sustained rather than transient, check the bucket's request-rate limits against the pool's actual PUT/GET rate (see [bucket requirements](/antalya/cas/bucket-requirements)) and consider lowering `cas_blob_upload_pool_size` to reduce concurrent upload traffic; a write only surfaces a client-visible `NETWORK_ERROR` if the 90-second deadline is exhausted before the store recovers, and that error is retried by the ordinary merge/insert backoff, not silently dropped | | `GC` never seems to reclaim space after tables are dropped | `SELECT * FROM system.cas_gc_log WHERE event_type='Finish' ORDER BY event_time DESC LIMIT 5` — check `outcome`; also `SELECT is_leader FROM system.cas_mounts` on this node | If `outcome != 'Success'`/`'Deferred'`, see [reading GC health](/antalya/cas/operations/monitoring#gc-health); if this node is not the leader (`is_leader = 0`), it never reclaims for this disk — check the peer holding leadership. Reclamation also needs at least two full rounds past condemnation by design (the grace period is rounds, not acks) — a single manual `SYSTEM CAS GC RUN` will not finish it | | A dangling-access exception or `CORRUPTED_DATA` on read | Run `clickhouse-disks cas-fsck --detail` and check `dangling` specifically — it is the one class that means data loss, distinct from `unreachable`/`awaiting-gc`, which are just waiting for graduation | A nonzero `dangling` count is a real incident: collect the `--detail` output (see [what to collect before filing a bug](/antalya/cas/operations/debugging#filing-a-bug)) before taking any destructive action | @@ -37,13 +38,24 @@ Start with the `watermark_renew` timeline described in look for) with `classification` of `committed_by_read` or `committed_after_retry`; `CASMountRenewalRecovered` rises while `CASMountLeaseLost` and all remount counters stay flat. No intervention is needed unless the rate is sustained; investigate backend throttling/latency before - the blips consume the lease budget. -2. **External lease-safety exhaustion.** The failed row has - `classification = 'external_lease_deadline'`; `CASMountRenewalDeadlineExceeded` and - `CASMountLeaseLost` rise. The runtime correctly refused to manufacture authority beyond the last - confirmed lease. Check object-store latency and BOOTTIME/suspend history, then follow the ensuing - remount. `classification = 'request_deadline'` is the sibling case: the ninety-second request - policy exhausted first rather than the lease's own safety margin. + the blips grow into an expired lease. +1a. **Expired lease.** `CASMountLeaseExpired` rises by one when a renewal restores a lease that had + expired; `CASMountLeaseLost` and the remount counters stay flat. The restoring `watermark_renew` row + has `outcome = 'recovered'` and `expired_ms` in `detail`: how long the lease was expired, from its + deadline to the restoring renewal. Its `classification` is `committed_after_expiry`, or + `committed_after_retry` or `committed_by_read` when one of those applies first. The server log has + a `WARNING` with the same duration and the last failure. While the outage lasts, the log carries one + `WARNING` when the lease expires, written at the first request of the renewal after the expiry (a + request that hangs delays it by up to one attempt timeout). The live state is the row in + `system.cas_mounts` (`lifecycle_reason = 'lease_expired'`); the event moves only at the restore. +2. **External lease-safety exhaustion.** Only the renewals at startup, after a remount and the direct + renewal are bounded by the lease; the background renewal is not, so this case means one of those ran + out of lease. The failed row has `classification = 'external_lease_deadline'`; + `CASMountRenewalDeadlineExceeded` and `CASMountLeaseLost` rise. The runtime correctly refused to + manufacture authority beyond the last confirmed lease. Check object-store latency and + BOOTTIME/suspend history, then follow the ensuing remount. `classification = 'request_deadline'` is + the sibling case: the ninety-second request policy exhausted first rather than the lease's own + safety margin. 3. **Cancellation.** `classification = 'cancelled'` after a sent request is terminal and suppresses a clean farewell because the request may still land. Cancellation before any request remains `Active` and emits no failed aggregate row; during graceful shutdown that is the expected @@ -62,7 +74,12 @@ Start with the `watermark_renew` timeline described in The current protocol retries the whole chain with bounded backoff; it does not preserve per-step progress. Repeated failure at the same step is the actionable signal. -The default-level log policy is intentionally bounded: one warning on the first transition to retry, -then one recovery info or terminal fence warning, plus one final line per whole-chain remount attempt. -Use `system.cas_log` and counter deltas to reconstruct the incident; `DEBUG` contains individual -physical retries when that extra transport detail is necessary. +The default-level log policy is intentionally bounded. The lease keeper logs nothing about a renewal +until the renewal ends. A renewal that succeeds on its first request logs nothing. A renewal that +needed a retry, was settled by a read, or restored an expired lease logs one recovery `INFO`; a +terminal renewal logs one fence `WARNING`. An expired lease logs one `WARNING` when it expires, at the +first request of the renewal after the expiry, and another with the expired time and the last failure +when a renewal restores it. Each whole-chain remount attempt logs one final line. +Individual physical retries are not logged. During an outage the live state is the row in +`system.cas_mounts`. Use `system.cas_log` and the counters to reconstruct the +incident: `CASMountRenewalAttempts` and `CASMountRenewalRetries` advance as `PUT`s are sent. diff --git a/docs/en/operations/system-tables/cas_mounts.md b/docs/en/operations/system-tables/cas_mounts.md index 5a9465db04af..e1565fe9cd4a 100644 --- a/docs/en/operations/system-tables/cas_mounts.md +++ b/docs/en/operations/system-tables/cas_mounts.md @@ -38,9 +38,11 @@ rows. - `last_success_age_seconds` ([Nullable(UInt64)](/sql-reference/data-types/nullable)) — Seconds since this disk's GC last led a round (`0` if it has never led or GC is not running here). - `wedged_namespace_count` ([Nullable(UInt64)](/sql-reference/data-types/nullable)) — Ref-append lanes currently wedged on this disk (an uncertain `PUT` exhausted its retry budget). - `lifecycle` ([String](/sql-reference/data-types/string)) — This server's content-addressed pool lifecycle for the disk (a non-gated snapshot, always populated so a not-live disk stays visible): one of `live`, `not_live`, `identity_lost`, `vanished`, `constructing` (never started), or `shutdown` (torn down). -- `lifecycle_reason` ([String](/sql-reference/data-types/string)) — The enum-clean sub-state word for a `vanished` disk: `replaced` or `forgotten`. Empty for every other lifecycle, so `lifecycle || '(' || lifecycle_reason || ')'` reads e.g. `vanished(forgotten)`. -- `lifecycle_detail` ([String](/sql-reference/data-types/string)) — The full typed reason text naming the actual cause when not live: the vanish diagnosis (a data root replaced by a foreign pool, or decommissioned by `SYSTEM CAS FORGET` at a given time) or the identity-loss message. Empty when live. -- `lifecycle_since` ([Nullable(DateTime)](/sql-reference/data-types/nullable)) — When this server entered the current non-live lifecycle state. `NULL` when live, or when the state has no backing pool to date from. +- `lifecycle_reason` ([String](/sql-reference/data-types/string)) — The enum-clean sub-state word: `replaced` or `forgotten` for a `vanished` disk, and `lease_expired` for a `not_live` disk whose own confirmed lease deadline has passed while renewals keep failing (writes are refused until a renewal succeeds and leaves enough lease for a write; a renewal that succeeds after its own deadline does not, and the next one follows at once; the writer epoch does not change). Empty for every other lifecycle, so `lifecycle || '(' || lifecycle_reason || ')'` reads e.g. `vanished(forgotten)`. +- `lifecycle_detail` ([String](/sql-reference/data-types/string)) — The full typed reason text naming the actual cause when not live: the vanish diagnosis (a data root replaced by a foreign pool, or decommissioned by `SYSTEM CAS FORGET` at a given time), the identity-loss message, or, for `lease_expired`, the text of the last failed renewal request (empty if no request failed). Empty when live. +- `lifecycle_since` ([Nullable(DateTime)](/sql-reference/data-types/nullable)) — When this server entered the current non-live lifecycle state; for `lease_expired`, the lease deadline that passed. `NULL` when live, or when the state has no backing pool to date from. + +`lifecycle_reason = 'lease_expired'` is about this server's own confirmed lease deadline; it differs from `state = 'expired'`, which is derived from the body's wall-clock `expires_at` plus a skew allowance. `lifecycle`/`lifecycle_reason`/`lifecycle_detail`/`lifecycle_since` are the SQL surface for diagnosing an identity-lost or forgotten disk without reading server logs — see the diff --git a/src/Common/ProfileEvents.cpp b/src/Common/ProfileEvents.cpp index a9986b5aa485..5cb260b8006c 100644 --- a/src/Common/ProfileEvents.cpp +++ b/src/Common/ProfileEvents.cpp @@ -958,6 +958,7 @@ The server successfully detected this situation and will download merged part fr M(CASMountRenewalRecovered, "Number of logical CAS mount-lease renewals that committed after a physical retry or exact resolving GET.", ValueType::Number) \ M(CASMountRenewalDeadlineExceeded, "Number of logical CAS mount-lease renewals stopped by the external lease-safety deadline. Growth means the last confirmed lease no longer had enough safe time for another physical attempt.", ValueType::Number) \ M(CASMountLeaseLost, "Counts exactly once per operational CAS mount-lease Live-to-TransientNotLive loss/recovery generation. The initiating external loss or the first ordinary terminal renewal consumer owns the increment, including external lease-safety deadline exhaustion; parked/classification/shutdown paths do not duplicate it.", ValueType::Number) \ + M(CASMountLeaseExpired, "Number of times a renewal restored a CAS mount lease that had expired. While the lease is expired this server refuses writes and system.cas_mounts shows lifecycle_reason = 'lease_expired'; the watermark_renew event of the restoring renewal carries expired_ms.", ValueType::Number) \ M(CASRemountAttempts, "Number of invocations of the CAS whole-chain remount attempt.", ValueType::Number) \ M(CASRemountSucceeded, "Number of CAS whole-chain remount attempts that restored Live under a fresh writer epoch.", ValueType::Number) \ M(CASRemountFailed, "Number of CAS whole-chain remount attempts that returned without restoring Live, including caught step exceptions.", ValueType::Number) \ diff --git a/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Backend/CasObjectStorageBackend.cpp b/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Backend/CasObjectStorageBackend.cpp index 0589929d2912..976866143026 100644 --- a/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Backend/CasObjectStorageBackend.cpp +++ b/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Backend/CasObjectStorageBackend.cpp @@ -309,8 +309,10 @@ static detail::ConditionalWriteOutcome finalizeConditionalWriteInstrumented(Writ std::expected ObjectStorageBackend::nativeConditionalPut( const String & key, const String & bytes, const WriteSettings & ws) { + /// Sized to the body rather than 1 MiB; `WriteBufferFromS3` grows it if needed. At least one byte, + /// because `WriteBuffer::write` requires a non-empty buffer even for an empty body. auto buf = object_storage->writeObject( - StoredObject(key), WriteMode::Rewrite, /*attributes=*/std::nullopt, DBMS_DEFAULT_BUFFER_SIZE, ws); + StoredObject(key), WriteMode::Rewrite, /*attributes=*/std::nullopt, std::max(1, bytes.size()), ws); buf->write(bytes.data(), bytes.size()); if (finalizeConditionalWriteInstrumented(*buf) == detail::ConditionalWriteOutcome::PreconditionLost) return std::unexpected(RawConflict{}); @@ -809,6 +811,9 @@ WriteSettings ObjectStorageBackend::conditionalWriteSettings(size_t attempt_no) if (native_token_type == Dialect::Generation) ws.s3_force_single_part_upload = true; ws.s3_check_objects_after_upload_override = false; + /// Upload on the calling thread: the caller waits for the write anyway, and a pool thread would run + /// outside the memory guard the mount-lease thread holds. + ws.s3_allow_parallel_part_upload = false; /// Exactly one attempt at the WriteBufferFromS3 layer too: makeSinglepartUpload/ /// completeMultipartUpload run their OWN retry loop above the S3 client, reissuing the identical /// (conditional!) request on NO_SUCH_KEY — a client-level override alone does not bound it. Plain diff --git a/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Backend/CasObjectStorageBackend.h b/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Backend/CasObjectStorageBackend.h index f9f51396efbb..91bc2c829284 100644 --- a/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Backend/CasObjectStorageBackend.h +++ b/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Backend/CasObjectStorageBackend.h @@ -196,9 +196,9 @@ class ObjectStorageBackend final : public Backend /// Settings for a Native COMPARE/CREATE write (create-if-absent, compare-and-set): mark the request /// conditional, make exactly one attempt at every retry layer, skip the racy post-upload - /// existence/size check, and force a single PUT on generation stores because GCS does not - /// enforce the condition on multipart completion. `attempt_no` is the engine's own 1-based - /// physical-attempt count (see `TransportAccess::attemptNo`), carried into + /// existence/size check, upload on the calling thread, and force a single PUT on generation stores + /// because GCS does not enforce the condition on multipart completion. `attempt_no` is the engine's + /// own 1-based physical-attempt count (see `TransportAccess::attemptNo`), carried into /// `object_storage_attempt_number` so the HTTP client sees a reissue as attempt >= 2. WriteSettings conditionalWriteSettings(size_t attempt_no) const; WriteSettings conditionalWriteSettingsForTest() const { return conditionalWriteSettings(/*attempt_no=*/1); } diff --git a/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Backend/CasRequests.cpp b/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Backend/CasRequests.cpp index 898c0c8c1504..28e406c278b0 100644 --- a/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Backend/CasRequests.cpp +++ b/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Backend/CasRequests.cpp @@ -6,6 +6,7 @@ #include #include #include +#include #include #include "config.h" @@ -865,22 +866,27 @@ std::optional CasOperation::gatedPause(uint64_t pause_ms, uint32_t return std::nullopt; } -std::optional CasOperation::pauseAndReissue(WriteState & state, const Retry::Bound & bound) +std::optional CasOperation::pauseAndReissue(WriteState & state, const Retry & policy, const Retry::Bound & bound) { - return gatedPause(Retry::backoff(++state.reissues), 2, state, bound, detail::recordReissue, /*should_sleep=*/true); + ++state.reissues; + const uint64_t pause_ms = reissuePause( + policy, state.attempt_started_ms, [reissues = state.reissues] { return Retry::backoff(reissues); }); + return gatedPause(pause_ms, 2, state, bound, detail::recordReissue, /*should_sleep=*/true); } -std::optional CasOperation::pauseForConflict(WriteState & state, const Retry::Bound & bound) +std::optional CasOperation::pauseForConflict(WriteState & state, const Retry & policy, const Retry::Bound & bound) { - return gatedPause(Retry::conflictBackoff(), 2, state, bound, detail::recordConflictPause, /*should_sleep=*/true); + const uint64_t pause_ms = reissuePause(policy, state.attempt_started_ms, Retry::conflictBackoff); + return gatedPause(pause_ms, 2, state, bound, detail::recordConflictPause, /*should_sleep=*/true); } /// A flat pause before reissuing an attempt whose failure text named a failed connection. static constexpr uint64_t kConnectHintPauseMs = 50; -std::optional CasOperation::pauseFlat(WriteState & state, const Retry::Bound & bound) +std::optional CasOperation::pauseFlat(WriteState & state, const Retry & policy, const Retry::Bound & bound) { - return gatedPause(kConnectHintPauseMs, 2, state, bound, detail::recordReissue, /*should_sleep=*/true); + const uint64_t pause_ms = reissuePause(policy, state.attempt_started_ms, [] { return kConnectHintPauseMs; }); + return gatedPause(pause_ms, 2, state, bound, detail::recordReissue, /*should_sleep=*/true); } std::optional CasOperation::reissueAtOnce(WriteState & state, const Retry::Bound & bound) @@ -888,6 +894,19 @@ std::optional CasOperation::reissueAtOnce(WriteState & state, const return gatedPause(0, 2, state, bound, detail::recordReissue, /*should_sleep=*/false); } +void CasOperation::notifyRequest(uint32_t attempt_no, const std::exception * failure) const noexcept +{ + if (!request_observer) + return; + try + { + request_observer(attempt_no, failure); + } + catch (...) // NOLINT(bugprone-empty-catch) + { + } +} + WriteResult CasOperation::writeLoop(const String & key, const String & bytes, const std::optional & expected, const Retry & policy, const Retry::Bound & bound, WriteState & state, ResolveWith resolve_refusal_with) @@ -915,9 +934,12 @@ WriteResult CasOperation::writeLoop(const String & key, const String & bytes, co if (!fits(reservation, bound)) return gaveUp(GaveUp::Why::Deadline, sourceFor(bound), state); + if (policy.attempt_spacing_ms) + state.attempt_started_ms = owner.now_ms(); detail::recordAttempt(); ++state.attempts_sent; state.sent_any = true; + notifyRequest(state.attempts_sent, nullptr); /// Disengaged means the attempt threw: its fate is unproven, and nothing may be read out of it. std::optional> outcome; @@ -944,6 +966,7 @@ WriteResult CasOperation::writeLoop(const String & key, const String & bytes, co } catch (const Exception & e) { + notifyRequest(state.attempts_sent, &e); if (isDeterministicLocalFailure(e.code())) throw; /// ONE refresh per call, only for the class a credential could explain, and only when a @@ -995,6 +1018,7 @@ WriteResult CasOperation::writeLoop(const String & key, const String & bytes, co } catch (const std::exception & e) { + notifyRequest(state.attempts_sent, &e); /// Only the transport can have landed anything, and every exception it raises is a /// `Poco::Exception`. A local fault -- a bad allocation, a logic error raised inside the /// attempt -- is not a store answer, and settling it by a read would bury the bug behind an @@ -1019,7 +1043,7 @@ WriteResult CasOperation::writeLoop(const String & key, const String & bytes, co /// inner write is unresolved either. Re-send it under the credentials the refresh installed. if (refresh_owns_reissue) { - if (auto given_up = pauseAndReissue(state, bound)) + if (auto given_up = pauseAndReissue(state, policy, bound)) return *given_up; continue; } @@ -1031,7 +1055,7 @@ WriteResult CasOperation::writeLoop(const String & key, const String & bytes, co /// the read below settles it. if (connect_hint && !policy.single_attempt) { - if (auto given_up = pauseFlat(state, bound)) + if (auto given_up = pauseFlat(state, policy, bound)) return *given_up; continue; } @@ -1044,9 +1068,14 @@ WriteResult CasOperation::writeLoop(const String & key, const String & bytes, co /// caller settles it with a HEAD; proving an ambiguous attempt landed needs the bytes, and there /// the body read is unavoidable. ProfileEvents::increment(ProfileEvents::CASRequestResolveRead); - const Resolved resolved = resolve_refusal_with == ResolveWith::Presence && !state.any_ambiguous - ? observePresence(key, policy, bound) - : observe(key, policy, bound); + resolve_read_put_no = state.attempts_sent; + Resolved resolved; + { + SCOPE_EXIT({ resolve_read_put_no = 0; }); + resolved = resolve_refusal_with == ResolveWith::Presence && !state.any_ambiguous + ? observePresence(key, policy, bound) + : observe(key, policy, bound); + } state.last_seen = resolved.seen; /// A bound refused the resolve, so say WHICH. Erasing it here is what let a lost fence be /// reported as an ordinary conflict and a lease refusal as a policy deadline. @@ -1087,7 +1116,7 @@ WriteResult CasOperation::writeLoop(const String & key, const String & bytes, co return *given_up; continue; } - if (auto given_up = pauseAndReissue(state, bound)) + if (auto given_up = pauseAndReissue(state, policy, bound)) return *given_up; } } @@ -1143,7 +1172,7 @@ WriteResult CasOperation::readModifyWrite(const String & key, const DecideOnObje /// A clean lost race is settled: the resolve read holds the fresh object and the next /// iteration decides on it. Only a conflict that settled a transport fault is paced by the /// growing schedule. - if (auto given_up = state.any_ambiguous ? pauseAndReissue(state, bound) : pauseForConflict(state, bound)) + if (auto given_up = state.any_ambiguous ? pauseAndReissue(state, policy, bound) : pauseForConflict(state, policy, bound)) return *given_up; /// Only when the resolve settled nothing is a fresh read owed; otherwise `current` already is @@ -1200,7 +1229,7 @@ WriteResult CasOperation::readModifyWriteOnPresence(const String & key, const De /// A clean lost race is settled: the resolve read holds the fresh object and the next /// iteration decides on it. Only a conflict that settled a transport fault is paced by the /// growing schedule. - if (auto given_up = state.any_ambiguous ? pauseAndReissue(state, bound) : pauseForConflict(state, bound)) + if (auto given_up = state.any_ambiguous ? pauseAndReissue(state, policy, bound) : pauseForConflict(state, policy, bound)) return *given_up; if (std::holds_alternative(state.last_seen)) diff --git a/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Backend/CasRequests.h b/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Backend/CasRequests.h index dd79f1a9db4b..432bd0a21419 100644 --- a/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Backend/CasRequests.h +++ b/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Backend/CasRequests.h @@ -260,6 +260,15 @@ class CasOperation /// The write lane for keys several writers of this pool share. CasHotKeys & hotKeys() const { return *owner.hot_keys; } + /// Told of the requests of this operation's writes, on the issuing thread: each `PUT` when it is + /// sent (null `failure`) and again if it throws, and each failed resolve read. `attempt_no` is the + /// count of `PUT`s sent so far. A refused precondition is an answer, not a failure, and is not + /// reported; nor is a read that succeeds, one the caller issued itself, or the read that + /// `readModifyWrite` and `readModifyWriteOnPresence` repeat after a resolve read that observed + /// nothing. What the observer throws is ignored. + using RequestObserver = std::function; + void setRequestObserver(RequestObserver observer) { request_observer = std::move(observer); } + /// `policy` with its window turned into an absolute deadline on this operation's clock, taken NOW. /// A hand-written loop freezes its policy once before it starts and passes the frozen value to /// every call it makes, so the loop ends when the window it was given ends -- rather than granting @@ -340,6 +349,8 @@ class CasOperation Observation last_seen = NotObserved{}; uint32_t reissues = 0; bool refresh_attempted = false; + /// When the latest attempt was sent; sampled only under `Retry::attempt_spacing_ms`. + uint64_t attempt_started_ms = 0; }; /// Why a read-class request stopped without an answer. Every give-up below throws the same @@ -358,7 +369,8 @@ class CasOperation std::optional stop; }; - /// One read-class request under the policy: admission, attempt, classification, jittered reissue. + /// One read-class request under the policy: admission, attempt, classification, then a jittered + /// reissue, or a spaced one under `Retry::attempt_spacing_ms`. /// Returns whatever `once` returns, or throws -- the read surface reports failure by exception. template auto readLoop(std::string_view verb, const String & subject, const Retry & policy, @@ -397,6 +409,9 @@ class CasOperation /// state the read never saw, which is how a lease refusal used to be reported as a policy deadline. WriteResult gaveUpAfterFailedObservation(std::optional stop, WriteState & state, const Retry::Bound & bound) const; + /// Calls `request_observer` if one is set. A report must not change a verdict, so whatever the + /// observer throws is swallowed here. + void notifyRequest(uint32_t attempt_no, const std::exception * failure) const noexcept; /// The shared shape behind every gated pause below: admission for `envelopes` attempt reservations /// plus `pause_ms`, the deadline check, the counter this pause records itself under, then the sleep /// -- called even with a zero `pause_ms` UNLESS `should_sleep` is false, which is reserved for the @@ -405,20 +420,31 @@ class CasOperation std::optional gatedPause(uint64_t pause_ms, uint32_t envelopes, WriteState & state, const Retry::Bound & bound, void (*record)(), bool should_sleep); /// Admission, then the jittered sleep. A value means the call ended during it; nullopt means the - /// caller may send another attempt. - std::optional pauseAndReissue(WriteState & state, const Retry::Bound & bound); + /// caller may send another attempt. This and the two siblings below sleep the spaced pause instead + /// under `Retry::attempt_spacing_ms`. + std::optional pauseAndReissue(WriteState & state, const Retry & policy, const Retry::Bound & bound); /// The sibling for a clean lost race: the same admission and the same reservation, a flat /// `Retry::conflictBackoff` sleep, and `state.reissues` untouched, so a transport fault that follows /// starts its own schedule at the beginning. - std::optional pauseForConflict(WriteState & state, const Retry::Bound & bound); + std::optional pauseForConflict(WriteState & state, const Retry & policy, const Retry::Bound & bound); /// The sibling for a failure text that named a failed connection. The same admission and the same /// reservation, a flat `kConnectHintPauseMs` sleep, and `state.reissues` untouched. - std::optional pauseFlat(WriteState & state, const Retry::Bound & bound); + std::optional pauseFlat(WriteState & state, const Retry & policy, const Retry::Bound & bound); /// The sibling for a first-attempt fuse timeout: the same admission and the same reservation, NO /// sleep at all, and `state.reissues` untouched -- the fuse is a connection-quality answer about a /// fresh connection, not a store fault, so nothing here is paced against it. std::optional reissueAtOnce(WriteState & state, const Retry::Bound & bound); + /// The pause before a reissue: `unspaced_ms()`, or under `Retry::attempt_spacing_ms` what is left of + /// a fresh draw since `request_started_ms`. `unspaced_ms` is not called when spacing applies. + template + uint64_t reissuePause(const Retry & policy, uint64_t request_started_ms, UnspacedPause && unspaced_ms) const + { + if (!policy.attempt_spacing_ms) + return unspaced_ms(); + return Retry::spacedPause(Retry::drawSpacing(*policy.attempt_spacing_ms), request_started_ms, owner.now_ms()); + } + /// `sleep_ms` plus `envelopes` attempt reservations, saturating. uint64_t reservedFor(uint64_t sleep_ms, uint32_t envelopes) const; /// Is there room to START something needing `needed_ms` before the bound? The guarantee is on the @@ -445,6 +471,10 @@ class CasOperation /// Written immediately before a read-class give-up throws, cleared and read only by the resolve /// read that swallows it. Every other caller lets the exception carry the verdict. std::optional last_read_stop; + RequestObserver request_observer; + /// The `PUT` count while a write's resolve read runs, 0 otherwise. A read failure is reported only + /// when it is set, so the caller's own reads stay silent. + uint32_t resolve_read_put_no = 0; }; template @@ -452,6 +482,7 @@ auto CasOperation::readLoop(std::string_view verb, const String & subject, const const Retry::Bound & bound, Fn && once) { bool refresh_attempted = false; + uint64_t attempt_started_ms = 0; /// Two counters, deliberately kept separate: `attempt_no` is the PHYSICAL attempt count handed to /// the transport (so a reissue is seen as attempt >= 2); `ordinary_reissues` is the /// exponential-backoff index. They advance together on an ordinary failure, but the first-attempt @@ -469,6 +500,8 @@ auto CasOperation::readLoop(std::string_view verb, const String & subject, const if (!fits(reservation, bound)) giveUpReadDeadline(verb, subject, bound, attempt_no - 1); + if (policy.attempt_spacing_ms) + attempt_started_ms = owner.now_ms(); detail::recordAttempt(); try { @@ -476,6 +509,8 @@ auto CasOperation::readLoop(std::string_view verb, const String & subject, const } catch (const std::exception & e) { + if (resolve_read_put_no != 0) + notifyRequest(resolve_read_put_no, &e); bool refreshed = false; if (refreshAndClassifyReadFault(e, refresh_attempted, refreshed)) throw; @@ -509,7 +544,9 @@ auto CasOperation::readLoop(std::string_view verb, const String & subject, const } } - const uint64_t pause_ms = Retry::backoff(++ordinary_reissues); + ++ordinary_reissues; + const uint64_t pause_ms = reissuePause( + policy, attempt_started_ms, [ordinary_reissues] { return Retry::backoff(ordinary_reissues); }); const uint64_t needed = reservedFor(pause_ms, 1); switch (gate(needed)) { diff --git a/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Backend/CasRetry.cpp b/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Backend/CasRetry.cpp index c7b4c27215b5..cfbfab930c56 100644 --- a/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Backend/CasRetry.cpp +++ b/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Backend/CasRetry.cpp @@ -17,6 +17,22 @@ uint64_t Retry::backoff(uint32_t attempt) return thread_local_rng() % (ceiling + 1); /// full jitter: uniform(0, ceiling) } +uint64_t Retry::spacedPause(uint64_t spacing_draw_ms, uint64_t request_started_ms, uint64_t now_ms) +{ + const uint64_t taken_ms = now_ms > request_started_ms ? now_ms - request_started_ms : 0; + return taken_ms >= spacing_draw_ms ? 0 : spacing_draw_ms - taken_ms; +} + +uint64_t Retry::drawSpacing(uint64_t attempt_spacing_ms_) +{ + const uint64_t spread = attempt_spacing_ms_ / 5; + const uint64_t low = attempt_spacing_ms_ - spread; + const uint64_t high = attempt_spacing_ms_ > std::numeric_limits::max() - spread + ? std::numeric_limits::max() + : attempt_spacing_ms_ + spread; + return low + thread_local_rng() % (high - low + 1); +} + Retry::Bound Retry::bind(uint64_t now_ms) const { const uint64_t own_deadline_ms = policy_deadline_ms diff --git a/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Backend/CasRetry.h b/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Backend/CasRetry.h index de235e8fd3fa..7534b0810962 100644 --- a/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Backend/CasRetry.h +++ b/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Backend/CasRetry.h @@ -1,5 +1,6 @@ #pragma once #include +#include #include namespace DB::Cas @@ -23,6 +24,10 @@ struct Retry /// iterations a fresh window. Empty for a single verb, which gets its window from where it is /// called. std::optional policy_deadline_ms = std::nullopt; + /// When set, a reissue in `CasOperation`'s write and read loops waits until this long (drawn in + /// [0.8, 1.2] of it) has passed since the failed request started, instead of the engine's backoff. + /// A request that took longer is reissued at once. The first-attempt fuse is reissued at once either way. + std::optional attempt_spacing_ms = std::nullopt; /// Full jitter: uniform(0, min(5000, 200 << (attempt-1))) milliseconds. `attempt` is 1-based; /// `attempt == 0` returns 0. @@ -54,6 +59,20 @@ struct Retry /// The standard policy, but at most one attempt is ever sent. static Retry once() { return {.window_ms = 90'000, .lease_deadline_ms = std::nullopt, .single_attempt = true}; } + /// No window and no lease bound: retried until a definitive answer, or until the fence or the + /// caller's liveness ends it. `bind` saturates, so the only horizon is the range of the clock. + static Retry untilDefinitive(uint64_t attempt_spacing_ms_) + { + return {.window_ms = std::numeric_limits::max(), .lease_deadline_ms = std::nullopt, + .single_attempt = false, .attempt_spacing_ms = attempt_spacing_ms_}; + } + + /// The pause before a retry under `attempt_spacing_ms`: `spacing_draw_ms` minus what the failed + /// request took, not below 0. A clock sample before the start counts as no time taken. + static uint64_t spacedPause(uint64_t spacing_draw_ms, uint64_t request_started_ms, uint64_t now_ms); + /// A uniform draw in [0.8, 1.2] of `attempt_spacing_ms_`, saturating at the top of the range. + static uint64_t drawSpacing(uint64_t attempt_spacing_ms_); + /// This policy, made single-attempt. A frozen loop policy keeps its absolute deadline through it, /// which is what lets a loop send an unrepeatable request under the same bound as the rest. Retry asSingleAttempt() const diff --git a/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/ContentAddressedMetadataStorage.cpp b/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/ContentAddressedMetadataStorage.cpp index b20d299df60c..24b7c95f0bc5 100644 --- a/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/ContentAddressedMetadataStorage.cpp +++ b/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/ContentAddressedMetadataStorage.cpp @@ -465,8 +465,8 @@ CasLifecycleSnapshot ContentAddressedMetadataStorage::lifecycleSnapshot() const } const Cas::Pool::LifecycleSnapshot ps = pool->lifecycleSnapshot(); - snap.lifecycle = casLifecycleToString(ps.lifecycle); - snap.reason = casLifecycleReasonWord(ps.lifecycle); + snap.lifecycle = ps.lease_expired ? "not_live" : casLifecycleToString(ps.lifecycle); + snap.reason = ps.lease_expired ? "lease_expired" : casLifecycleReasonWord(ps.lifecycle); snap.detail = ps.detail; snap.since = ps.since; return snap; diff --git a/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/ContentAddressedMetadataStorage.h b/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/ContentAddressedMetadataStorage.h index 5f0aadb2d7d4..be5d5299e504 100644 --- a/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/ContentAddressedMetadataStorage.h +++ b/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/ContentAddressedMetadataStorage.h @@ -94,14 +94,17 @@ enum class CasOpAdmission : uint8_t /// operator instead of silently missing from the table. /// - `lifecycle` — one of `live` / `not_live` / `identity_lost` / `vanished` (a live pool), or /// `constructing` / `shutdown` (no pool published). -/// - `reason` — the ENUM-CLEAN sub-state word: `replaced` / `forgotten` for a -/// `vanished` pool, empty otherwise. Kept a small closed vocabulary so a downstream +/// - `reason` — the ENUM-CLEAN sub-state word: `replaced` / `forgotten` for a `vanished` pool, +/// `lease_expired` for a `not_live` row whose lifecycle enum is still `Live` but +/// whose lease expired, empty otherwise. A small closed vocabulary, so a downstream /// `lifecycle || '(' || reason || ')'` yields e.g. exactly `vanished(forgotten)` — /// the [D5] free text lives in `detail`, never here. /// - `detail` — the full [D5] reason text naming the actual failure (the replaced -/// diagnosis, the timestamped `FORGET` message, or the identity-loss message); spec §1 -/// requires it appear verbatim in the snapshot. Empty while `live` and for a null pool. -/// - `since` — wall-clock second the current non-`live` state was entered; 0 while `live`/no pool. +/// diagnosis, the timestamped `FORGET` message, or the identity-loss message), verbatim. +/// For `lease_expired`, the text of the last failed renewal request. Empty while +/// `live` and for a null pool. +/// - `since` — wall-clock second the current non-`live` state was entered (for `lease_expired`, +/// the confirmed deadline that passed); 0 while `live`/no pool. /// - `pool_id` — last-known pool UUID (empty before the first `startup`); the disk stays /// introspectable under its identity even once the pool is gone. /// - `server_root_id` — this server's node-local root id owning the mount slot. diff --git a/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Gc/CasGc.cpp b/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Gc/CasGc.cpp index f871182c8edb..918c9b10177b 100644 --- a/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Gc/CasGc.cpp +++ b/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Gc/CasGc.cpp @@ -690,7 +690,7 @@ RoundReport Gc::runRegularRound(std::function on_lease_acquired, bool al /// PUT per newly-fenced mount. { GcPhaseTimer t(phase_sink, "heartbeat_floor"); - const HeartbeatFloor floor = computeHeartbeatFloor(op, layout, now_ms_fn(), mono_ms_fn(), + const HeartbeatFloor floor = computeHeartbeatFloor(op, layout, now_ms_fn(), mono_ms_fn, stable_threshold_ms, mount_obs); report.fence_outs = floor.fenced_now; if (floor.fenced_now > 0) @@ -4704,7 +4704,7 @@ RebuildReport Gc::rebuildBaseline(bool force) /// `mountObservationThresholdMs` -- see its doc comment (CasServerRoot.h). const uint64_t stable_threshold_ms = mountObservationThresholdMs( ttl_ms, static_cast(store->poolConfig().mount_renew_period.count())); - computeHeartbeatFloor(op, layout, now_ms_fn(), mono_ms_fn(), stable_threshold_ms, mount_obs); + computeHeartbeatFloor(op, layout, now_ms_fn(), mono_ms_fn, stable_threshold_ms, mount_obs); /// Retired-in-snapshot: the rebuilt seal's `condemned_summary` must be TOTAL over gc_shards so a /// subsequent regular round reads graduation/carry decisions zero-I/O off it (and its `carryParentRefs` diff --git a/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Pool/CasMountRuntime.cpp b/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Pool/CasMountRuntime.cpp index e3f52fd7957a..4fd2cefc8c9f 100644 --- a/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Pool/CasMountRuntime.cpp +++ b/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Pool/CasMountRuntime.cpp @@ -1,6 +1,7 @@ #include #include #include +#include #include #include #include @@ -24,6 +25,7 @@ namespace ProfileEvents extern const Event CASIdentityLost; extern const Event CASDataRootVanished; extern const Event CASMountLeaseLost; + extern const Event CASMountLeaseExpired; extern const Event CASMountRenewalAttempts; extern const Event CASMountRenewalRetries; extern const Event CASMountRenewalResolved; @@ -34,7 +36,7 @@ namespace ProfileEvents namespace DB::Cas { -void reportMountRenewCompletion(const MountRenewResult & result) noexcept; +void reportMountRenewCompletion(const MountRenewResult & result, std::optional expired_ms) noexcept; void configureMountRenewObservability( const String * server_root_id, const CasEventSink * event_sink, bool deferred) noexcept; @@ -54,6 +56,7 @@ CasMountRuntime::CasMountRuntime( BackendPtr backend_ptr_, CasRequests & mount_requests_, CasRequests & farewell_requests_, + CasRequests & lease_requests_, const Layout & layout_, MountConfig config_, String server_root_id_, @@ -63,6 +66,7 @@ CasMountRuntime::CasMountRuntime( : backend_ptr(std::move(backend_ptr_)) , mount_requests(mount_requests_) , farewell_requests(farewell_requests_) + , lease_requests(lease_requests_) , layout(layout_) , config(std::move(config_)) , server_root_id(std::move(server_root_id_)) @@ -119,6 +123,11 @@ void CasMountRuntime::tripFenceWithoutOperationalLoss() void CasMountRuntime::checkFenceOrThrow(uint64_t admitted_generation) const { + if (mayMutate() && fenceGeneration() == admitted_generation) + return; + const String subject = fmt::format("content-addressed pool '{}'", server_root_id); + if (const std::optional expired = leaseExpiredRefusal(admitted_generation)) + throwCasTransientUnavailable(subject, *expired); /// [D5]: tell only what is known here. A tripped fence (or a bumped generation) means this node no /// longer holds the mount incarnation the caller was admitted under -- but this same guard trips for a /// transient lease blip AND for a deliberate terminal decommission (FORGET) or a lost identity, and this @@ -126,13 +135,12 @@ void CasMountRuntime::checkFenceOrThrow(uint64_t admitted_generation) const /// would misdiagnose the terminal case); it names both possibilities and points at the authoritative /// lifecycle. The CLASS is the write plane's uniform transient one (its 32 sibling write-transient sites /// already mint it): under genuine ambiguity the refusal must be retried, never consumed as damage. - if (!mayMutate() || fenceGeneration() != admitted_generation) - throwCasTransientUnavailable( - fmt::format("content-addressed pool '{}'", server_root_id), - "mount fence tripped: the durable write is refused because this node no longer holds the mount " - "incarnation it was admitted under -- either a lease loss the disk auto-recovers from, or a " - "FORGET decommission / lost identity that does NOT recover; consult " - "system.cas_mounts for the disk's lifecycle before retrying"); + throwCasTransientUnavailable( + subject, + "mount fence tripped: the durable write is refused because this node no longer holds the mount " + "incarnation it was admitted under -- either a lease loss the disk auto-recovers from, or a " + "FORGET decommission / lost identity that does NOT recover; consult " + "system.cas_mounts for the disk's lifecycle before retrying"); } Fence::Admit CasMountRuntime::admit(uint64_t admitted_generation, uint64_t needed_ms) const @@ -162,6 +170,108 @@ bool CasMountRuntime::refAppendFenceOk() const return admit(fenceGeneration(), needed_ms) == Fence::Admit::Ok; } +std::optional CasMountRuntime::leaseExpiredAt(uint64_t now_boot_ms) const +{ + if (lifecycle() != PoolLifecycle::Live || mount_fence.lost.load(std::memory_order_acquire)) + return std::nullopt; + const uint64_t deadline = mount_fence.deadline_boot_ms.load(std::memory_order_acquire); + if (now_boot_ms < deadline) + return std::nullopt; + return std::min(deadline, lease_expired_at_boot_ms.load(std::memory_order_acquire)); +} + +std::optional CasMountRuntime::leaseExpiredSinceBootMs() const +{ + return leaseExpiredAt(bootMsNow()); +} + +std::optional CasMountRuntime::leaseExpiredRefusal(uint64_t admitted_generation) const +{ + if (fenceGeneration() != admitted_generation || !leaseExpiredSinceBootMs()) + return std::nullopt; + return String("the mount lease expired and no renewal has restored it yet; " + "writes resume when a renewal succeeds"); +} + +String CasMountRuntime::lastRenewFailure() const +{ + std::lock_guard lock(renew_failure_mutex); + return last_renew_failure; +} + +void CasMountRuntime::noteRenewRequest(const MountRenewRequestEvent & event) noexcept +{ + warnOnceIfLeaseExpired(event); + if (!event.failed) + { + ProfileEvents::incrementNoTrace(ProfileEvents::CASMountRenewalAttempts); + if (event.request_no > 1) + ProfileEvents::incrementNoTrace(ProfileEvents::CASMountRenewalRetries); + return; + } + try + { + std::lock_guard lock(renew_failure_mutex); + last_renew_failure = event.failure_text; + } + catch (...) // NOLINT(bugprone-empty-catch) + { + /// A lost diagnostic must not end the renewal. + } +} + +void CasMountRuntime::warnOnceIfLeaseExpired(const MountRenewRequestEvent & event) noexcept +{ + try + { + const uint64_t now = bootMsNow(); + const std::optional expired_at = leaseExpiredAt(now); + if (!expired_at || *expired_at == lease_expiry_warned_at_boot_ms.load(std::memory_order_relaxed)) + return; + lease_expiry_warned_at_boot_ms.store(*expired_at, std::memory_order_relaxed); + const String last_failure = event.failed ? event.failure_text : lastRenewFailure(); + LOG_WARNING(getLogger("CasPool"), + "CAS mount lease of '{}' expired {} ms ago and no renewal has restored it yet; " + "the renewal keeps retrying and writes are refused until it succeeds. Last failed request: {}", + server_root_id, now - *expired_at, last_failure.empty() ? "none" : last_failure); + } + catch (...) // NOLINT(bugprone-empty-catch) + { + /// A lost diagnostic must not end the renewal. + } +} + +std::optional CasMountRuntime::publishRenewedDeadline(uint64_t deadline_boot_ms) +{ + const uint64_t now = bootMsNow(); + const std::optional expired_at = leaseExpiredAt(now); + if (deadline_boot_ms <= now) + { + /// The carried instant goes first: a concurrent snapshot reads the deadline and this instant + /// separately, and must never see the new deadline without it. + lease_expired_at_boot_ms.store( + expired_at.value_or(std::numeric_limits::max()), std::memory_order_release); + setMountDeadline(deadline_boot_ms); + return std::nullopt; + } + setMountDeadline(deadline_boot_ms); + lease_expired_at_boot_ms.store(std::numeric_limits::max(), std::memory_order_release); + String ended_failure; + { + std::lock_guard lock(renew_failure_mutex); + ended_failure.swap(last_renew_failure); + } + if (!expired_at) + return std::nullopt; + const uint64_t expired_ms = now - *expired_at; + ProfileEvents::incrementNoTrace(ProfileEvents::CASMountLeaseExpired); + LOG_WARNING(getLogger("CasPool"), + "CAS mount lease of '{}' was expired for {} ms; a renewal restored it and writes resume. " + "Last failed renewal request: {}", + server_root_id, expired_ms, ended_failure); + return expired_ms; +} + void CasMountRuntime::setMountDeadline(uint64_t deadline_boot_ms) { mount_fence.deadline_boot_ms.store(deadline_boot_ms, std::memory_order_release); @@ -172,6 +282,7 @@ void CasMountRuntime::armMountFence(UInt128 server_uuid, uint64_t writer_epoch, mount_fence.server_uuid = server_uuid; mount_fence.writer_epoch = writer_epoch; mount_fence.deadline_boot_ms.store(deadline_boot_ms, std::memory_order_release); + lease_expired_at_boot_ms.store(std::numeric_limits::max(), std::memory_order_release); /// A fresh lease incarnation is a fresh generation too: a durable-effect caller admitted under the /// PRIOR incarnation must re-check and abort rather than ride this re-arm through (rev.7 [C2]). fence_generation.fetch_add(1, std::memory_order_acq_rel); @@ -201,8 +312,7 @@ void CasMountRuntime::renewWatermarkOnce() (void)renewRenewerOnce( std::move(call), RenewalDriverState::DirectCall, - /*propagate_failure=*/true, - /*worker_call=*/false); + /*propagate_failure=*/true); } uint64_t CasMountRuntime::allocateBuildSeq() @@ -367,7 +477,7 @@ void CasMountRuntime::installRenewer( const std::function & now_ms) { auto replacement = std::make_unique( - mount_requests, farewell_requests, layout, server_root_id, our_uuid, writer_epoch, + mount_requests, farewell_requests, lease_requests, layout, server_root_id, our_uuid, writer_epoch, config.mount_lease_ttl_ms, now_ms, [this] { return minActive(); }, [this](CasEvent e) { emitEvent(std::move(e)); }, @@ -425,9 +535,17 @@ MountRenewOperationEnvironment CasMountRuntime::renewalEnvironment(bool worker_c .boot_ms = [this] { return bootMsNow(); }, .live = [this, worker_call] { - return config.renewal_live_for_test ? config.renewal_live_for_test() : renewalLive(worker_call); + return renewalLive(worker_call) && (!config.renewal_live_for_test || config.renewal_live_for_test()); }, .cancelled = [this] { return renewalCancelled(); }, + /// Only the worker keeps renewing past the lease; startup, remount and direct renewals stay + /// bounded by it. + .policy = worker_call ? MountRenewPolicy::UntilDefinitive : MountRenewPolicy::LeaseBound, + /// The worker counts its requests as they are sent, so an outage shows while it lasts. + .on_request = worker_call + ? std::function( + [this](const MountRenewRequestEvent & event) { noteRenewRequest(event); }) + : nullptr, }; } @@ -463,9 +581,9 @@ void CasMountRuntime::consumeRenewResult( { /// Driver ownership has already been restored by `DriverLease::finish`; this is the single logical /// consumption boundary and it runs without `driver_mutex` or renewer access. - /// The physical counters come off the result rather than off a per-attempt callback, so they count - /// the same on every ending: a renewal that gave up still sent what it sent. - if (result.attempts_sent > 0) + /// The worker's renewal counts its requests as they are sent (`noteRenewRequest`). Every other + /// renewal counts them here, from its result. + if (active_state != RenewalDriverState::WorkerCall && result.attempts_sent > 0) { ProfileEvents::incrementNoTrace(ProfileEvents::CASMountRenewalAttempts, result.attempts_sent); ProfileEvents::incrementNoTrace(ProfileEvents::CASMountRenewalRetries, result.attempts_sent - 1); @@ -482,16 +600,16 @@ void CasMountRuntime::consumeRenewResult( if (result.outcome == MountRenewOutcome::Committed) { const uint64_t ttl_ms = static_cast(config.mount_lease_ttl_ms.count()); - setMountDeadline( + const std::optional expired_ms = publishRenewedDeadline( result.attempt_start_boot_ms > std::numeric_limits::max() - ttl_ms ? std::numeric_limits::max() : result.attempt_start_boot_ms + ttl_ms); - reportMountRenewCompletion(result); + reportMountRenewCompletion(result, expired_ms); return; } if (result.outcome == MountRenewOutcome::NotAttempted) { - reportMountRenewCompletion(result); + reportMountRenewCompletion(result, std::nullopt); return; } @@ -510,9 +628,8 @@ void CasMountRuntime::consumeRenewResult( { } - reportMountRenewCompletion(result); + reportMountRenewCompletion(result, std::nullopt); - (void)active_state; (void)returned_state; if (propagate_failure) @@ -522,9 +639,9 @@ void CasMountRuntime::consumeRenewResult( uint64_t CasMountRuntime::renewRenewerOnce( AdmittedRenewerCall call, RenewalDriverState active, - bool propagate_failure, - bool worker_call) + bool propagate_failure) { + const bool worker_call = active == RenewalDriverState::WorkerCall; /// Configuration is pointer/POD-only. A parked redo retains its completed observation for the /// whole-chain finalizer to deliver after `remount_mutex` is released. configureMountRenewObservability( @@ -552,8 +669,7 @@ uint64_t CasMountRuntime::renewRenewerForStartupOnce() return renewRenewerOnce( std::move(call), RenewalDriverState::StartupCall, - /*propagate_failure=*/true, - /*worker_call=*/false); + /*propagate_failure=*/true); } uint64_t CasMountRuntime::renewRenewerForRemountOnce() @@ -562,8 +678,7 @@ uint64_t CasMountRuntime::renewRenewerForRemountOnce() return renewRenewerOnce( std::move(call), RenewalDriverState::RemountCall, - /*propagate_failure=*/true, - /*worker_call=*/false); + /*propagate_failure=*/true); } void CasMountRuntime::renewerReset() @@ -643,6 +758,9 @@ void CasMountRuntime::startBackgroundWorkers(std::chrono::milliseconds period) void CasMountRuntime::renewalLoop() { setThreadName(ThreadName::CAS_LEASE_RENEWER); + /// The tracker still counts this thread's allocations but never throws on it: a renewal failed by a + /// memory limit costs the mount, and an exception outside the request ends this thread. + LockMemoryExceptionInThread memory_exception_lock(VariableContext::Global); { std::unique_lock lock(driver_mutex); driver_cv.wait(lock, [this] { return worker_loops_released; }); @@ -711,8 +829,7 @@ void CasMountRuntime::renewalLoop() (void)renewRenewerOnce( std::move(call), RenewalDriverState::WorkerCall, - /*propagate_failure=*/false, - /*worker_call=*/true); + /*propagate_failure=*/false); } catch (...) { diff --git a/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Pool/CasMountRuntime.h b/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Pool/CasMountRuntime.h index 7f3ff1d76f36..91d717ee6018 100644 --- a/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Pool/CasMountRuntime.h +++ b/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Pool/CasMountRuntime.h @@ -16,6 +16,7 @@ #include #include #include +#include #include namespace DB::Cas @@ -105,8 +106,8 @@ struct MountConfig std::function terminal_publication_driver_lock_acquired_hook_for_test = {}; /// Deterministic failure injection at the vanished-reason preparation boundary. std::function vanished_reason_prepare_hook_for_test = {}; - /// Test-only override of the renewal's liveness predicate, for exact pre/post-send gate - /// interleavings. FALSE ends the renewal exactly as a lost fence does. + /// Test-only extra liveness condition, for exact pre/post-send gate interleavings. It is ANDed with + /// the ordinary predicate, so a stop still ends the renewal. FALSE ends it exactly as a lost fence does. std::function renewal_live_for_test = {}; }; @@ -146,10 +147,12 @@ class CasMountRuntime public: CasMountRuntime( BackendPtr backend_ptr_, - /// The two planes the `MountLeaseRenewer` runs on: renewals under the mount fence, the farewell - /// on an open one. Owned by `Pool` and outliving this runtime. + /// The planes the `MountLeaseRenewer` runs on: a bounded renewal under the mount fence, the + /// claim and the farewell on an open one, and the worker's renewal on `lease_requests_`, which + /// has no lease budget and whose sleep a stop wakes. Owned by `Pool` and outliving this runtime. CasRequests & mount_requests_, CasRequests & farewell_requests_, + CasRequests & lease_requests_, const Layout & layout_, MountConfig config_, String server_root_id_, @@ -309,6 +312,25 @@ class CasMountRuntime /// it cannot plausibly finish before the fence expires. bool refAppendFenceOk() const; + /// ---- lease expiry ---- + /// The instant this server's confirmed lease expired, on the fence clock, while it stays expired: + /// the lifecycle is `Live`, the fence is not lost and `bootMsNow` has reached the deadline. A + /// renewal that commits with a start more than a TTL ago does not end the expiry, so the first expired + /// deadline is kept until a renewal restores the lease. Empty otherwise. + std::optional leaseExpiredSinceBootMs() const; + /// Text of the last failed request of the worker's renewal; empty when no request failed since the + /// last renewal that left the lease unexpired. + String lastRenewFailure() const; + /// The condition text for a request admitted under `admitted_generation` that is refused only + /// because the lease expired; empty when the refusal has any other cause or there is none. + std::optional leaseExpiredRefusal(uint64_t admitted_generation) const; + /// Counts each `PUT` of the worker's renewal as it is sent and keeps the text of every failed + /// `PUT` or resolve read. Runs on the renewing thread. + void noteRenewRequest(const MountRenewRequestEvent & event) noexcept; + + /// Writes one `WARNING` per lease expiry, at the first request event after it. Lease thread only. + void warnOnceIfLeaseExpired(const MountRenewRequestEvent & event) noexcept; + /// TRUE once the pool has reached — or is being driven toward — a state on which the self-remount /// worker must stop: a published terminal `Vanished` intent (`vanished_intent` — set early by /// FORGET, or by a natural `enterVanished`, and already subsuming every settled `Vanished*` state since @@ -322,10 +344,11 @@ class CasMountRuntime || lifecycle() == PoolLifecycle::IdentityLost; } - /// The inter-attempt sleep the mount plane runs on. A plain sleep would hold a parked or stopping - /// renewal for the whole capped backoff; this one wakes on the same stop signal the workers watch. - /// It shortens a stop, not a fence loss: the fence cannot see a stop request, so a woken operation - /// still reissues unless its own liveness predicate refuses. + /// The inter-attempt sleep the mount plane runs on. A plain sleep would hold a stopping renewal + /// for the whole capped backoff; this one wakes on the same stop signal the workers watch. + /// A park or a remount request does not wake it: the wait runs out, at most one spacing draw for + /// the background renewal. It shortens a stop, not a fence loss: the fence cannot see a stop request, + /// so a woken operation still reissues unless its own liveness predicate refuses. void sleepInterruptibly(uint64_t ms); /// The mount fence's admission verdict, as `Fence::admit` expects it: may a request admitted under @@ -434,9 +457,14 @@ class CasMountRuntime uint64_t renewRenewerOnce( AdmittedRenewerCall call, RenewalDriverState active, - bool propagate_failure, - bool worker_call); + bool propagate_failure); MountRenewOperationEnvironment renewalEnvironment(bool worker_call); + std::optional leaseExpiredAt(uint64_t now_boot_ms) const; + /// Publishes a committed renewal's deadline. A deadline in the future ends the current run of + /// trouble: it clears the failure text and, when the lease was expired, counts and logs the + /// restore. Returns how long the lease had been expired when this deadline restores it; empty + /// when it was not expired or is still expired. + std::optional publishRenewedDeadline(uint64_t deadline_boot_ms); void consumeRenewResult( const MountRenewResult & result, RenewalDriverState active_state, @@ -445,8 +473,9 @@ class CasMountRuntime void renewalLoop(); void remountLoop(); ThreadFromGlobalPool makeWorker(std::function body); - /// The renewal's liveness: facts the mount fence cannot see -- a shutdown request, a parked or - /// park-requested driver, a pool that left `Live`. FALSE ends the renewal. + /// The renewal's liveness: a shutdown request and, for the worker, a parked or park-requested + /// driver, a pool that left `Live`, or a lost fence -- the worker's plane has no fence of its own. + /// FALSE ends the renewal. bool renewalLive(bool worker_call) const; /// Whether this node has already been asked to stop. Sampled ONCE, before the write, so a refusal /// caused by the stop cannot be mistaken for one that preceded it. @@ -458,6 +487,7 @@ class CasMountRuntime BackendPtr backend_ptr; CasRequests & mount_requests; CasRequests & farewell_requests; + CasRequests & lease_requests; const Layout & layout; MountConfig config; String server_root_id; @@ -520,6 +550,14 @@ class CasMountRuntime /// `fenceGeneration`/`checkFenceOrThrow`. std::atomic fence_generation{0}; std::function arm_mount_fence_interposition_hook_for_test; + /// The first expired deadline of an expiry that a renewal committed past did not end. `UINT64_MAX` + /// when there is none. Written by the renewal consumer and by `armMountFence`. + std::atomic lease_expired_at_boot_ms{std::numeric_limits::max()}; + mutable std::mutex renew_failure_mutex; + String last_renew_failure; + /// The expiry instant `warnOnceIfLeaseExpired` last wrote a line for. A renewal that commits past + /// its own deadline keeps the instant, so the same expiry is not reported twice. + std::atomic lease_expiry_warned_at_boot_ms{std::numeric_limits::max()}; /// The pool lifecycle condition (rev.7 §1). Starts `Live`. Non-terminal transitions /// (`noteLeaseLost`/`noteRemounted`) are lock-free compare-exchanges guarded by their exact diff --git a/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Pool/CasPool.cpp b/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Pool/CasPool.cpp index 8ea206618492..e527e9803d82 100644 --- a/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Pool/CasPool.cpp +++ b/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Pool/CasPool.cpp @@ -77,6 +77,16 @@ namespace std::atomic remount_attempt_sequence{0}; +/// The wall-clock second of a past `CLOCK_BOOTTIME` instant: wall now minus how long ago it was on the +/// boot clock. Both clocks are this server's own, sampled at one moment. +time_t wallSecondOfPastBootInstant(uint64_t past_boot_ms, uint64_t now_boot_ms) +{ + const int64_t wall_now_ms = std::chrono::duration_cast( + std::chrono::system_clock::now().time_since_epoch()).count(); + const uint64_t ago_ms = now_boot_ms > past_boot_ms ? now_boot_ms - past_boot_ms : 0; + return static_cast((wall_now_ms - static_cast(ago_ms)) / 1000); +} + /// Validate every writable factory's lease/request/cadence relationship before it can publish /// owner, epoch, mount, or probe authority. Decommission forces background renewal before calling /// this helper, so it is held to the same cadence window as an ordinary production mount. @@ -173,8 +183,8 @@ Pool::Pool(BackendPtr backend_, PoolConfig config_, PoolMeta meta_) , meta(std::move(meta_)) , hot_keys(config.hot_key_cache_bytes) /// The mount plane's fence reaches `mount_runtime`, declared far below: the closures capture - /// `this` and run only after construction, exactly like `ref_ledger`'s callbacks. All three planes - /// take the fence's own clock, so a policy bound to a mount-lease deadline and the fence that + /// `this` and run only after construction, exactly like `ref_ledger`'s callbacks. Every plane + /// takes the fence's own clock, so a policy bound to a mount-lease deadline and the fence that /// enforces it are read from the same source. , mount_requests(pool_backend, Fence{ [this] { return mount_runtime.fenceGeneration(); }, @@ -187,7 +197,7 @@ Pool::Pool(BackendPtr backend_, PoolConfig config_, PoolMeta meta_) /// The open plane's fence is the pool's teardown flag: generation 0 forever, exactly like /// `Fence::open`, but `admit` refuses once `beginTeardown` ran. A GC round, an FSCK or a probe in /// flight is then refused at its next request instead of running to completion under a disk that - /// is being torn down. The ref ledger and the farewell live on the other two planes, so + /// is being torn down. The ref ledger and the farewell live on other planes, so /// teardown's own I/O never meets this fence. A write already proven durable is admitted ONCE /// MORE (`postCommit`), so an armed teardown can turn a landed `gc/state` into a give-up rather /// than a commit. That is safe and not merely tolerable: the round is one-pass, so the next round @@ -201,6 +211,9 @@ Pool::Pool(BackendPtr backend_, PoolConfig config_, PoolMeta meta_) config.boot_ms_fn, config.retry_sleep_fn ? config.retry_sleep_fn : openPlaneSleepFn(), &hot_keys) + , lease_requests(pool_backend, Fence::open(), config.boot_ms_fn, + config.retry_sleep_fn ? config.retry_sleep_fn : mountPlaneSleepFn(), + &hot_keys) /// Seed the monotone admitted-algo cache from the pool state `createOrValidate` already /// established (fresh create, steady-state member, or a just-completed admission union) -- /// register-before-first-write means this Pool's own `writeAlgo()` is ALWAYS a @@ -242,13 +255,13 @@ Pool::Pool(BackendPtr backend_, PoolConfig config_, PoolMeta meta_) [this] (const RootNamespace & ns) { cancelInflightBuildsForNamespace(ns); }, config.recovery_pre_first_request_hook_for_test) /// Mount / write-fence / build-watermark / self-remount runtime. Injected with - /// backend/layout + the mount and farewell planes + the `MountConfig` slice + `server_root_id` + the event-sink reference + the pool + /// backend/layout + the mount, farewell and lease planes + the `MountConfig` slice + `server_root_id` + the event-sink reference + the pool /// `cas_request_budget` + the `remount_attempt` callback (== `Pool::tryRemountOnce`, whose claim/ /// recovery ORCHESTRATION stays on Pool). The callback captures `this`; it is invoked only at runtime /// (post-construction). Declared/constructed AFTER `ref_ledger`, preserving the original member order /// verbatim (mount destroyed first, ledger last; both orders proven safe -- see the header note). , mount_runtime( - pool_backend, mount_requests, farewell_requests, + pool_backend, mount_requests, farewell_requests, lease_requests, pool_layout, config.mountConfig(), config.server_root_id, event_sink_, config.cas_request_budget, [this] { return tryRemountOnce(); }) @@ -377,6 +390,14 @@ Pool::LifecycleSnapshot Pool::lifecycleSnapshot() const snap.lifecycle = mount_runtime.lifecycle(); snap.detail = lifecycleReasonDetail(snap.lifecycle); snap.since = mount_runtime.lifecycleSinceWallS(); + if (snap.lifecycle != PoolLifecycle::Live) + return snap; + const std::optional expired_at = mount_runtime.leaseExpiredSinceBootMs(); + if (!expired_at) + return snap; + snap.lease_expired = true; + snap.detail = mount_runtime.lastRenewFailure(); + snap.since = wallSecondOfPastBootInstant(*expired_at, mount_runtime.bootMsNow()); return snap; } @@ -1946,14 +1967,15 @@ std::vector Pool::listMirroredChildren(const String & prefix) void Pool::setCasRetrySleepForTest(std::function sleep_fn) { - /// All three planes, not just the ledger's: a test that replaces the retry sleep must not be left - /// with a real one on the plane the site under test happens to use. + /// Every plane, not just the ledger's: a test that replaces the retry sleep must not be left with + /// a real one on the plane the site under test happens to use. farewell_requests.setSleepFnForTest(sleep_fn); ref_ledger.setCasRetrySleepForTest(sleep_fn); - /// `CasRequests` falls back to the engine's plain sleep for an empty argument -- which is neither - /// the mount plane's nor the open plane's default. Re-install both, so clearing the seam cannot - /// leave a parked renewal held for a whole capped backoff, or the open plane deaf to a teardown. + /// `CasRequests` falls back to the engine's plain sleep for an empty argument -- which is none of + /// the mount, lease or open plane's defaults. Re-install them, so clearing the seam cannot leave a + /// stopping renewal held for a whole wait, or the open plane deaf to a teardown. gc_requests.setSleepFnForTest(sleep_fn ? sleep_fn : openPlaneSleepFn()); + lease_requests.setSleepFnForTest(sleep_fn ? sleep_fn : mountPlaneSleepFn()); mount_requests.setSleepFnForTest(sleep_fn ? std::move(sleep_fn) : mountPlaneSleepFn()); } @@ -1961,6 +1983,7 @@ void Pool::setCasRequestNowFnForTest(std::function now_fn) { mount_requests.setNowFnForTest(now_fn); farewell_requests.setNowFnForTest(now_fn); + lease_requests.setNowFnForTest(now_fn); gc_requests.setNowFnForTest(std::move(now_fn)); } diff --git a/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Pool/CasPool.h b/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Pool/CasPool.h index c566a9164f1a..c1dd8de03781 100644 --- a/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Pool/CasPool.h +++ b/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Pool/CasPool.h @@ -256,10 +256,10 @@ struct PoolConfig /// boot clock (`Pool::bootMs`); injected by tests to drive the fence deadline deterministically. std::function boot_ms_fn = {}; - /// The inter-attempt sleep for the mount, farewell and GC request planes (`mount_requests`, + /// The inter-attempt sleep for the request planes (`mount_requests`, `lease_requests`, /// `farewell_requests`, `gc_requests`), installed at their CONSTRUCTION -- before this `Pool` has /// claimed or read anything. Empty = each plane's own production default (an interruptible real - /// sleep for the mount and GC planes, `CasRequests`'s own real sleep for the farewell plane). A test + /// sleep for the mount, lease and GC planes, `CasRequests`'s own real sleep for the farewell plane). A test /// that also freezes `boot_ms_fn` must supply a matching sleep here: a retry loop bound to a clock /// that only moves when this function is called would otherwise retry forever against a REAL sleep /// that never calls it, because the deadline it measures against never appears to elapse. @@ -531,18 +531,21 @@ class Pool : public std::enable_shared_from_this /// truth-absent on removes/enumeration — is `checkOpAdmitted`; this covers only the terminal states. void throwIfLifecycleTerminal() const; - /// A non-gated, I/O-free lifecycle snapshot for `system.cas_mounts` (spec §7, - /// Factory class). Reads only the runtime's atomics — NO backend op — so it is truthful in EVERY - /// state, including the terminal ones the store()-class surface refuses. `detail` is the same [D5] - /// reason text `throwIfLifecycleTerminal` throws (empty while `Live`/`TransientNotLive`), which spec §1 - /// requires appear verbatim in the snapshot; `since` is the wall-clock second the current non-`Live` - /// state was entered (0 while `Live`). The metadata-storage layer maps `lifecycle` to the operator - /// vocabulary and derives the enum-clean sub-state word separately (see `CasLifecycleSnapshot`). + /// A non-gated, I/O-free lifecycle snapshot for `system.cas_mounts`. Reads only the runtime's + /// atomics, no backend op, so it is truthful in every state, including the terminal ones the + /// store()-class surface refuses. `detail` is the same reason text `throwIfLifecycleTerminal` throws + /// (empty while `Live`/`TransientNotLive` unless `lease_expired`), verbatim; `since` is the + /// wall-clock second the current non-`Live` state was entered (0 while `Live` unless `lease_expired`). + /// The metadata-storage layer maps `lifecycle` to the operator vocabulary and derives the enum-clean + /// sub-state word separately (see `CasLifecycleSnapshot`). struct LifecycleSnapshot { PoolLifecycle lifecycle = PoolLifecycle::Live; String detail; time_t since = 0; + /// The lifecycle is `Live` but this server's lease expired and no renewal has restored it yet. + /// `detail` is then the last failed renewal request and `since` the expired deadline. + bool lease_expired = false; }; LifecycleSnapshot lifecycleSnapshot() const; @@ -754,7 +757,7 @@ class Pool : public std::enable_shared_from_this const PoolMeta & poolMeta() const { return meta; } const Layout & layout() const { return pool_layout; } - /// ---- the three request planes ---- + /// ---- request planes ---- /// The mount plane: the durable writes whose right to land IS this node's mount lease. An /// operation admitted here is refused the moment the fence trips, is re-armed under a fresh lease /// incarnation, or runs out of room before the lease expires. @@ -1072,10 +1075,10 @@ class Pool : public std::enable_shared_from_this ref_ledger.setSnapshotBeforeCkptCasHookForTest(std::move(hook)); } - /// Test-only: replace the inter-attempt backoff sleep (e.g. with a clock-advancing no-op) on all - /// three request planes and on ref-table recovery, for tests that drive a persistent write fault to + /// Test-only: replace the inter-attempt backoff sleep (e.g. with a clock-advancing no-op) on every + /// request plane and on ref-table recovery, for tests that drive a persistent write fault to /// exhaustion through a fully wired Pool/disk and must not serve the production sleeps for real. - /// Call before driving traffic. On the three request planes an empty function restores each plane's + /// Call before driving traffic. On the request planes an empty function restores each plane's /// own default, the mount plane's interruptible sleep included. /// /// It does NOT bound a reissue the engine refuses to start: the engine's inter-attempt backoff is @@ -1084,7 +1087,7 @@ class Pool : public std::enable_shared_from_this /// clock, not the sleep. void setCasRetrySleepForTest(std::function sleep_fn); - /// Test-only: replace the request engine's clock on all three planes. A test driving a PERSISTENT + /// Test-only: replace the request engine's clock on every plane. A test driving a PERSISTENT /// transient fault must run the retry window on a clock it advances; the sleep seam alone cannot /// bound it, because a read the engine keeps reissuing is bounded by the policy deadline and the /// deadline is read from this clock. @@ -1172,9 +1175,9 @@ class Pool : public std::enable_shared_from_this return std::forward(mutation)(); } - /// The mount plane's inter-attempt sleep: interruptible, so a parked or stopping renewal is not - /// held for a whole capped backoff. Named rather than inlined because the test seam has to be able - /// to put it back. + /// The mount plane's inter-attempt sleep: woken only by a stop of the workers, so a stopping renewal + /// is not held for a whole capped backoff. A park or a remount request does not wake it; the wait + /// runs out. Named rather than inlined because the test seam has to be able to put it back. std::function mountPlaneSleepFn() { return [this](uint64_t ms) { mount_runtime.sleepInterruptibly(ms); }; @@ -1198,17 +1201,20 @@ class Pool : public std::enable_shared_from_this PoolConfig config; PoolMeta meta; - /// The pool's write lane for keys several of its writers share, declared before the three planes + /// The pool's write lane for keys several of its writers share, declared before the planes /// that carry a pointer to it, so it outlives every operation they admit. `mutable` for the same /// reason the planes are. mutable CasHotKeys hot_keys; - /// The three planes' engines, declared before every component that is handed one and after the + /// The planes' engines, declared before every component that is handed one and after the /// config they take their clock from. `mutable` because issuing a request is not a change to the /// pool: a `const` observer still has to read the store. mutable CasRequests mount_requests; mutable CasRequests farewell_requests; mutable CasRequests gc_requests; + /// The worker renewal's plane: no lease budget, because the renewal keeps trying after the lease + /// expired; a stop, a park or a terminal lifecycle ends it through its liveness. + mutable CasRequests lease_requests; std::shared_ptr detached_work = std::make_shared(); diff --git a/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Pool/CasServerRoot.cpp b/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Pool/CasServerRoot.cpp index 10de8e758b3c..a0ef5b43b888 100644 --- a/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Pool/CasServerRoot.cpp +++ b/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Pool/CasServerRoot.cpp @@ -8,6 +8,7 @@ #include #include #include +#include #include #include #include @@ -45,7 +46,7 @@ namespace ErrorCodes namespace DB::Cas { -void reportMountRenewCompletion(const MountRenewResult & result) noexcept; +void reportMountRenewCompletion(const MountRenewResult & result, std::optional expired_ms) noexcept; void configureMountRenewObservability( const String * server_root_id, const CasEventSink * event_sink, bool deferred) noexcept; void deliverDeferredMountRenewObservability(uint64_t remount_attempt_no) noexcept; @@ -131,6 +132,8 @@ struct MountRenewObservabilityContext MountRenewTerminalClassification terminal_classification = MountRenewTerminalClassification::Unclassified; uint32_t attempts_sent = 0; bool resolved_by_read = false; + /// How long the lease had been expired when this renewal restored it; empty unless it did. + std::optional expired_ms = std::nullopt; }; static_assert(std::is_trivially_copyable_v); @@ -293,9 +296,12 @@ void emitMountRenewEvent( CasEvent event; event.type = CasEventType::WatermarkRenew; event.outcome = String{outcome}; - event.reason = outcome == "recovered" - ? "CAS mount renewal recovered before its confirmed lease-safety deadline" - : "CAS mount renewal ended without retained authority and fenced the mount"; + if (outcome != "recovered") + event.reason = "CAS mount renewal ended without retained authority and fenced the mount"; + else if (context.expired_ms) + event.reason = "CAS mount renewal restored a lease that had expired"; + else + event.reason = "CAS mount renewal committed after a retry or a resolving read"; event.detail = { {"server_root_id", *context.server_root_id}, {"writer_epoch", std::to_string(context.writer_epoch)}, @@ -308,6 +314,8 @@ void emitMountRenewEvent( }; if (remount_attempt_no != 0) event.detail["remount_attempt_no"] = std::to_string(remount_attempt_no); + if (context.expired_ms) + event.detail["expired_ms"] = std::to_string(*context.expired_ms); (*context.event_sink)(std::move(event)); } catch (...) @@ -344,30 +352,15 @@ void deliverMountRenewObservability( const uint64_t now_boot_ms = defaultBootMs(); const String write_attempt_id = u128ToHex(context.write_attempt_id).substr(0, 12); - for (uint32_t attempt_no = 2; attempt_no <= context.attempts_sent; ++attempt_no) - { - try - { - LOG_DEBUG( - getLogger("CasMountLeaseRenewer"), - "CAS mount renewal '{}' physical retry attempt {} (writer_epoch={}, seq={})", - *context.server_root_id, - attempt_no, - context.writer_epoch, - context.seq); - } - catch (...) - { - } - } - const bool recovered = context.outcome == MountRenewOutcome::Committed - && (context.attempts_sent > 1 || context.resolved_by_read); + && (context.attempts_sent > 1 || context.resolved_by_read || context.expired_ms.has_value()); if (recovered) { - const std::string_view classification = context.resolved_by_read - ? "committed_by_read" - : "committed_after_retry"; + std::string_view classification = "committed_after_expiry"; + if (context.resolved_by_read) + classification = "committed_by_read"; + else if (context.attempts_sent > 1) + classification = "committed_after_retry"; emitMountRenewEvent( context, write_attempt_id, @@ -463,7 +456,7 @@ void configureMountRenewObservability( }; } -void reportMountRenewCompletion(const MountRenewResult & result) noexcept +void reportMountRenewCompletion(const MountRenewResult & result, std::optional expired_ms) noexcept { if (mount_renew_observability.suppressed_depth != 0) { @@ -477,6 +470,7 @@ void reportMountRenewCompletion(const MountRenewResult & result) noexcept context->outcome = result.outcome; context->attempts_sent = std::max(context->attempts_sent, result.attempts_sent); context->resolved_by_read = result.resolved_by_read; + context->expired_ms = expired_ms; if (context->deferred) return; @@ -932,6 +926,16 @@ String mountDoubleStartMessage(const String & srid, const std::optional= first_seen_mono_ms && sample_before_read_ms - first_seen_mono_ms >= threshold_ms; +} + uint64_t mountObservationThresholdMs(uint64_t ttl_ms, uint64_t cadence_ms) { return ttl_ms + ttl_ms / 20 + cadence_ms; @@ -957,15 +961,15 @@ MountClaimResult claimMountAwaitingExpiry( /// threshold, which passes the full renewal period into the same shared helper. const uint64_t threshold_ms = mountObservationThresholdMs(ttl_ms, poll); - std::optional observed; - uint64_t observed_since = 0; + std::optional watch; size_t restarts = 0; while (true) { - const bool threshold_met = observed && mono_ms_fn() - observed_since >= threshold_ms; + const bool threshold_met = watch && watch->stableFor(threshold_ms, mono_ms_fn()); MountClaimResult r = claimMount(op, l, srid, our_uuid, our_epoch, now_ms_fn(), ttl_ms, - threshold_met ? observed : std::nullopt, sink, /*unsafe_reclaim_authorization=*/{}); + threshold_met ? std::optional(watch->token) : std::nullopt, sink, + /*unsafe_reclaim_authorization=*/{}); if (r.kind != MountClaimResult::LiveDoubleStart) return r; @@ -997,14 +1001,13 @@ MountClaimResult claimMountAwaitingExpiry( r.body = decodeMountLease(got->bytes); } - if (!observed || *observed != *current_etag) + if (!watch || watch->token != *current_etag) { - if (observed && ++restarts > kMaxObservationRestarts) + if (watch && ++restarts > kMaxObservationRestarts) /// The incarnation kept changing across bounded restarts — the holder is genuinely alive /// (actively renewing), not a dead predecessor. Report it rather than waiting forever. return r; - observed = *current_etag; - observed_since = mono_ms_fn(); + watch = TokenWatch::sighted(*current_etag, mono_ms_fn()); if (on_wait_start && r.body) on_wait_start(*r.body, threshold_ms); LOG_INFO(getLogger("CasMountLease"), @@ -1018,10 +1021,12 @@ MountClaimResult claimMountAwaitingExpiry( } HeartbeatFloor computeHeartbeatFloor(CasOperation & op, const Layout & l, uint64_t now_ms, - uint64_t mono_now_ms, uint64_t stable_threshold_ms, + const std::function & mono_ms_fn, uint64_t stable_threshold_ms, MountObservationMap & obs) { HeartbeatFloor floor; + /// Taken before any read, so it may confirm that a token held, but never date a sighting. + const uint64_t round_start_ms = mono_ms_fn(); /// `obs` is keyed by every srid this leader has EVER observed, but a /// srid removed from the LIST entirely (its `/mount` key gone -- e.g. `SYSTEM CAS @@ -1082,13 +1087,12 @@ HeartbeatFloor computeHeartbeatFloor(CasOperation & op, const Layout & l, uint64 /// raced against our own fence-out attempt) — (re)starts the observation window and /// counts as `live` this call. const auto it = obs.find(srid); - const bool stable = it != obs.end() && it->second.etag == observed->etag - && mono_now_ms - it->second.first_seen_mono_ms >= stable_threshold_ms; - - if (!stable) + const bool watched = it != obs.end() && it->second.token == observed->etag; + if (!watched || !it->second.stableFor(stable_threshold_ms, round_start_ms)) { - if (it == obs.end() || it->second.etag != observed->etag) - obs.insert_or_assign(srid, MountIncarnationObservation{observed->etag, mono_now_ms}); + /// A sample from before this read would count the walk to the slot as time watched. + if (!watched) + obs.insert_or_assign(srid, TokenWatch::sighted(observed->etag, mono_ms_fn())); ++floor.live; return std::nullopt; } @@ -1305,8 +1309,23 @@ constexpr uint64_t kFarewellBudgetMs = 10'000; /// "admission-time arithmetic needs room to actually run, not just to pass at t=0". constexpr uint64_t kFarewellSlackMs = 2'000; +namespace +{ +/// The text of a failed request as an operator should read it: a `DB::Exception`'s message, a Poco +/// exception's display text (its `what` is only the class name), any other exception's `what`. +String describeRequestFailure(const std::exception & failure) +{ + if (const auto * db_failure = dynamic_cast(&failure)) + return db_failure->message(); + if (const auto * poco_failure = dynamic_cast(&failure)) + return poco_failure->displayText(); + return failure.what(); +} +} + MountLeaseRenewer::MountLeaseRenewer( - CasRequests & mount_requests_, CasRequests & open_requests_, const Layout & layout_, + CasRequests & mount_requests_, CasRequests & open_requests_, CasRequests & worker_requests_, + const Layout & layout_, const String & srid_, UInt128 server_uuid_, uint64_t writer_epoch_, std::chrono::milliseconds ttl_, std::function now_ms_fn_, std::function min_active_build_sequence_fn_, @@ -1315,6 +1334,7 @@ MountLeaseRenewer::MountLeaseRenewer( std::function boot_ms_fn_) : mount_requests(mount_requests_) , open_requests(open_requests_) + , worker_requests(worker_requests_) , key(layout_.mountKey(srid_)) , srid(srid_) , server_uuid(server_uuid_) @@ -1560,7 +1580,8 @@ MountRenewResult MountLeaseRenewer::terminalResult(MountRenewResult result) MountRenewResult MountLeaseRenewer::renew(const MountRenewOperationEnvironment & environment) { - return renewOn(mount_requests, environment); + return renewOn( + environment.policy == MountRenewPolicy::UntilDefinitive ? worker_requests : mount_requests, environment); } MountRenewResult MountLeaseRenewer::renewForRemount(const MountRenewOperationEnvironment & environment) @@ -1609,11 +1630,22 @@ MountRenewResult MountLeaseRenewer::renewOn( result.attempt_start_boot_ms = attempt_start_boot_ms; CasOperation op = plane.admit(environment.live); + if (environment.on_request) + op.setRequestObserver([&on_request = environment.on_request](uint32_t attempt_no, const std::exception * failure) + { + on_request(MountRenewRequestEvent{ + .request_no = attempt_no, + .failed = failure != nullptr, + .failure_text = failure ? describeRequestFailure(*failure) : String{}, + }); + }); + const Retry policy = environment.policy == MountRenewPolicy::UntilDefinitive + ? Retry::untilDefinitive(kMountRenewRetrySpacingMs) + : Retry::untilLeaseSafe(confirmed_deadline_boot_ms, static_cast(lease_safety_margin.count())); std::optional written; try { - written = op.replace(key, body, precondition(), - Retry::untilLeaseSafe(confirmed_deadline_boot_ms, static_cast(lease_safety_margin.count()))); + written = op.replace(key, body, precondition(), policy); } catch (...) { @@ -1748,8 +1780,8 @@ void MountLeaseRenewer::terminate(CasOperation & op) : doubled_reservation_ms + kFarewellSlackMs; const uint64_t farewell_window_ms = std::max(kFarewellBudgetMs, two_envelope_reservation_plus_slack_ms); /// The derived window alone is not enough: mount-control activity must also never run past the - /// point this node's own fence may already be gone (the same rule `renew` enforces via - /// `Retry::untilLeaseSafe` above). The precondition on this write already stops it from clobbering + /// point this node's own fence may already be gone (the rule a bounded renewal enforces with + /// `Retry::untilLeaseSafe`). The precondition on this write already stops it from clobbering /// a successor if it DOES land late, but a shutdown holding the process open to retry a write past /// its own lease-safe deadline serves no one -- the successor's own reclaim does not wait for it. /// `confirmed_deadline_boot_ms` is set at `start()` and kept current by every successful `renew`, diff --git a/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Pool/CasServerRoot.h b/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Pool/CasServerRoot.h index 1c1fd8928f97..448ec650493c 100644 --- a/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Pool/CasServerRoot.h +++ b/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Pool/CasServerRoot.h @@ -61,6 +61,25 @@ struct MountRenewResult std::exception_ptr failure; }; +/// How far a renewal may retry. +enum class MountRenewPolicy : uint8_t +{ + LeaseBound, /// startup, remount and direct renewals: `Retry::untilLeaseSafe` + UntilDefinitive, /// the background worker: `Retry::untilDefinitive(kMountRenewRetrySpacingMs)` +}; + +/// The spacing of an `UntilDefinitive` renewal's retries. +inline constexpr uint64_t kMountRenewRetrySpacingMs = 1000; + +/// One physical request of a renewal, reported as it happens: a `PUT` sent (`failed` false), a `PUT` +/// that failed, or a failed read that settles a `PUT` (both `failed` true). +struct MountRenewRequestEvent +{ + uint32_t request_no = 0; /// 1-based count of `PUT`s sent by this renewal + bool failed = false; + String failure_text; /// empty unless `failed` +}; + struct MountRenewOperationEnvironment { std::function boot_ms; @@ -71,6 +90,10 @@ struct MountRenewOperationEnvironment /// `NotAttempted` rather than terminal only when this node had already been asked to stop -- /// sampling it afterwards would read a flag that the refusal itself may have set. std::function cancelled; + MountRenewPolicy policy = MountRenewPolicy::LeaseBound; + /// Called on the renewing thread for each `PUT` sent, each failed `PUT` and each failed resolve read. + /// May be empty. What it throws is ignored. + std::function on_request; }; /// Validate a `server_root_id` — the explicit, configured identity of the content-addressed layout @@ -344,21 +367,25 @@ MountClaimResult claimMountAwaitingExpiry( const std::function & on_wait_start = {}, const CasEventSink & sink = {}); -/// One `server_root_id`'s cross-round incarnation-stability observation, -/// owned by the GC leader instance (`Cas::Gc::mount_obs`) and threaded through consecutive -/// `computeHeartbeatFloor` calls — one GC round is one observation tick. Mirrors -/// `claimMountAwaitingExpiry`'s observation loop, but at heartbeat-gate granularity rather than a -/// tight poll loop. -struct MountIncarnationObservation +/// One observed token and the instant it was first seen, on the observer's own monotonic clock. +struct TokenWatch { - Etag etag; + Etag token; uint64_t first_seen_mono_ms = 0; + + /// `sample_after_read_ms` is a clock sample taken after the read that returned `token_`. An earlier + /// sample would count the time the read took as time watched. + static TokenWatch sighted(Etag token_, uint64_t sample_after_read_ms); + + /// True when the token has been watched for at least `threshold_ms`. `sample_before_read_ms` is a + /// clock sample taken before the read that confirmed the token; false when it precedes the sighting. + bool stableFor(uint64_t threshold_ms, uint64_t sample_before_read_ms) const; }; /// Keyed by `server_root_id`. In-memory only: a fresh leader (after a steal, or a process restart) /// starts with an empty map, which only delays fencing an already-dead mount by one extra round while /// it (re)establishes the observation — safe (never fences early), never unsafe. -using MountObservationMap = std::map; +using MountObservationMap = std::map; /// GC heartbeat gate (GC round protocol step 1). Run by the GC leader at the top of a round: LIST /// `gc/server-roots/` (O(servers), single-digit counts), GET each mount body, and classify + fence out @@ -371,8 +398,7 @@ using MountObservationMap = std::map; /// terminated marker; /// - otherwise, observation-based liveness (the same /// principle `claimMountAwaitingExpiry` uses for a mount's OWN reopen, applied here to the GC's -/// fence-out): `obs` remembers, per srid, the incarnation last seen and the leader's OWN -/// monotonic clock reading (`mono_now_ms`) at the moment it first saw it. A body whose +/// fence-out): `obs` holds, per srid, a `TokenWatch` of the incarnation last seen. A body whose /// CURRENT incarnation differs from (or is absent from) `obs` is (re)started fresh — counted `live`, /// never fenced this call, regardless of what its stamped `expires_at_ms` claims (a bare /// wall-clock stamp is never trusted — see `claimMount`'s "certificate of death" doc). Only once @@ -386,8 +412,9 @@ using MountObservationMap = std::map; /// /// `now_ms` is WALL clock, used only for the audit/diagnostic log line — it never participates in the /// fence decision (mirrors `claimMountAwaitingExpiry`'s `now_ms_fn` vs `mono_ms_fn` split). -/// `mono_now_ms` is the OBSERVATION clock: the caller's OWN monotonic reading, never compared against -/// any other node's clock. `obs` is owned by the caller and threaded across consecutive calls (one GC +/// `mono_ms_fn` is the OBSERVATION clock: the caller's OWN monotonic clock, never compared against +/// any other node's clock. It is sampled once at entry for the stability test and again after the read +/// for every sighting. `obs` is owned by the caller and threaded across consecutive calls (one GC /// leader instance, `Cas::Gc::mount_obs`) — a fresh leader starts with an empty map (safe: delays /// fencing one round, never fences early). /// @@ -407,7 +434,7 @@ struct HeartbeatFloor }; HeartbeatFloor computeHeartbeatFloor(CasOperation & op, const Layout & l, uint64_t now_ms, - uint64_t mono_now_ms, uint64_t stable_threshold_ms, + const std::function & mono_ms_fn, uint64_t stable_threshold_ms, MountObservationMap & obs); /// One `gc/server-roots//mount` slot whose holder is not provably finished with the prefix. @@ -522,17 +549,20 @@ bool isCreatorFenceTerminal(CasOperation & op, const Layout & layout, const Stri /// - foreign uuid → fail closed; /// - absent → `create`; expired-our-uuid (any epoch) → `replace` reclaim. /// -/// PLANES. Only the RENEWAL is admitted under the mount fence, because only a renewal writes under -/// authority the fence is tracking. The claim and the farewell are admitted off it: a self-remount -/// claims with the fence already latched lost, so a claim gated on the fence could never reclaim, and -/// a farewell refused because the fence has run down would leave the slot looking live until GC -/// fences it out. Neither is unguarded: a claim's safety is its own conditional write, and a caller -/// that has shutdown facts hands them over as a `Liveness`. +/// PLANES. A bounded renewal is admitted under the mount fence, because it writes under the authority +/// the fence tracks. The worker's renewal (`UntilDefinitive`) runs on a plane with no lease budget: it +/// keeps trying after the lease expired, and a stop, a park or a terminal lifecycle reaches it through +/// its liveness. The claim and the farewell are admitted off the fence: a self-remount claims with the +/// fence already latched lost, so a claim gated on the fence could never reclaim, and a farewell +/// refused because the fence has run down would leave the slot looking live until GC fences it out. +/// Neither is unguarded: a claim's safety is its own conditional write, and a caller that has shutdown +/// facts hands them over as a `Liveness`. class MountLeaseRenewer { public: MountLeaseRenewer( - CasRequests & mount_requests_, CasRequests & open_requests_, const Layout & layout_, + CasRequests & mount_requests_, CasRequests & open_requests_, CasRequests & worker_requests_, + const Layout & layout_, const String & srid_, UInt128 server_uuid_, uint64_t writer_epoch_, std::chrono::milliseconds ttl_, std::function now_ms_fn_, std::function min_active_build_sequence_fn_, @@ -545,7 +575,9 @@ class MountLeaseRenewer /// Adopt the already-claimed mount. Returns the exact pre-I/O BOOTTIME anchor. `liveness` carries /// the caller's shutdown terms; the mount fence is deliberately not consulted here. uint64_t start(Liveness liveness = {}); - /// The steady-state renewal, admitted under the mount fence. + /// The steady-state renewal. `LeaseBound` runs under the mount fence with `Retry::untilLeaseSafe`; + /// `UntilDefinitive` runs on the worker plane with `Retry::untilDefinitive(kMountRenewRetrySpacingMs)` + /// and ends on a definitive answer, a deterministic local failure, or when `environment.live` refuses. MountRenewResult renew(const MountRenewOperationEnvironment & environment); /// The remount's re-anchor, which is bootstrap control rather than steady state: a remount renews /// BEFORE it arms the fence for the new incarnation, so the fence is still latched lost and an @@ -573,6 +605,8 @@ class MountLeaseRenewer CasRequests & mount_requests; CasRequests & open_requests; + /// The plane of an `UntilDefinitive` renewal: no lease budget, and a sleep a stop wakes. + CasRequests & worker_requests; String key; String srid; diff --git a/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Tools/CasDecommission.cpp b/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Tools/CasDecommission.cpp index eef2ba04d9bf..6c8659d92881 100644 --- a/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Tools/CasDecommission.cpp +++ b/src/Disks/DiskObjectStorage/MetadataStorages/ContentAddressed/Tools/CasDecommission.cpp @@ -173,7 +173,7 @@ DecommissionReport decommissionPoolMember(BackendPtr backend, PoolConfig config, if (drain_now_fn && drain_sleep_fn) { /// Re-affirms the same values `config` above already installed on `mount_requests`/ - /// `farewell_requests`/`gc_requests` at construction, and additionally wires `ref_ledger`'s own + /// `lease_requests`/`farewell_requests`/`gc_requests` at construction, and additionally wires `ref_ledger`'s own /// retry sleep, which has no construction-time seam of its own. `sweepNamespace` below issues /// its deletes on `admin`'s own GC plane. admin->setCasRequestNowFnForTest(drain_now_fn); diff --git a/src/Disks/tests/gtest_cas_event_log.cpp b/src/Disks/tests/gtest_cas_event_log.cpp index e55f775ef4f8..49fd515323d3 100644 --- a/src/Disks/tests/gtest_cas_event_log.cpp +++ b/src/Disks/tests/gtest_cas_event_log.cpp @@ -29,7 +29,7 @@ namespace DB::Cas { void configureMountRenewObservability( const String * server_root_id, const CasEventSink * event_sink, bool deferred) noexcept; -void reportMountRenewCompletion(const MountRenewResult & result) noexcept; +void reportMountRenewCompletion(const MountRenewResult & result, std::optional expired_ms) noexcept; } namespace @@ -345,7 +345,7 @@ TEST(CASEvent, DeepReentrancyPreservesDeterministicPhysicalAttemptTruth) { configureMountRenewObservability(&server_root_ids[index], &sinks[index], /*deferred=*/false); MountRenewResult result = renewers[index]->renew(MountRenewOperationEnvironment{}); - reportMountRenewCompletion(result); + reportMountRenewCompletion(result, std::nullopt); return result; }; @@ -371,6 +371,7 @@ TEST(CASEvent, DeepReentrancyPreservesDeterministicPhysicalAttemptTruth) planes[index] = std::make_unique( backends[index], Fence::open(), [&] { return boot_ms; }, [&](uint64_t ms) { boot_ms += ms; }); renewers[index] = std::make_unique( + *planes[index], *planes[index], *planes[index], *layouts[index], diff --git a/src/Disks/tests/gtest_cas_gc_ack_floor.cpp b/src/Disks/tests/gtest_cas_gc_ack_floor.cpp index ea63268a8fe3..d0fff5bcff6b 100644 --- a/src/Disks/tests/gtest_cas_gc_ack_floor.cpp +++ b/src/Disks/tests/gtest_cas_gc_ack_floor.cpp @@ -933,7 +933,7 @@ void runExpiredMountFenceOutScenario(const PoolConfig & config) // never changes again. const String srid2 = "stale-server"; CasRequests renewer_requests = openRequestsForTest(backend); - MountLeaseRenewer srid2_renewer(renewer_requests, renewer_requests, layout, srid2, DB::UInt128(0x2222), + MountLeaseRenewer srid2_renewer(renewer_requests, renewer_requests, renewer_requests, layout, srid2, DB::UInt128(0x2222), /*writer_epoch=*/1, std::chrono::milliseconds(100), [] { return 1000u; }, [] { return 0u; }, {}, std::chrono::milliseconds(0), [] { return 0u; }); @@ -1061,7 +1061,7 @@ TEST(CASGCAckFloor, DefaultMonoClockTracksPoolsInjectedBootClockNotWallClock) // A stale mount, exactly as `ExpiredMountFencedOutAndExcluded`: one claim, never renewed again. const String srid2 = "stale-server"; CasRequests renewer_requests = openRequestsForTest(backend); - MountLeaseRenewer srid2_renewer(renewer_requests, renewer_requests, layout, srid2, DB::UInt128(0x2222), + MountLeaseRenewer srid2_renewer(renewer_requests, renewer_requests, renewer_requests, layout, srid2, DB::UInt128(0x2222), /*writer_epoch=*/1, std::chrono::milliseconds(100), [] { return 1000u; }, [fake_boot] diff --git a/src/Disks/tests/gtest_cas_heartbeat.cpp b/src/Disks/tests/gtest_cas_heartbeat.cpp index c39935d7ca7f..b4fd8d7c1570 100644 --- a/src/Disks/tests/gtest_cas_heartbeat.cpp +++ b/src/Disks/tests/gtest_cas_heartbeat.cpp @@ -12,7 +12,9 @@ #include #include +#include #include +#include #include #include #include @@ -21,6 +23,8 @@ namespace DB::ErrorCodes { extern const int NETWORK_ERROR; extern const int ABORTED; + extern const int CORRUPTED_DATA; + extern const int FILE_DOESNT_EXIST; } using namespace DB::Cas; @@ -34,23 +38,24 @@ using namespace DB::Cas; namespace { -/// The two request planes this file's renewers run on. Both are open-fence -- the exclusivity these -/// tests exercise is the mount protocol's own, not a fence's -- on the same injected boot clock the -/// renewer's lease deadline is expressed on, so the two never disagree about how much budget is left. +/// The request planes this file's renewers run on. All are open-fence -- the exclusivity these tests +/// exercise is the mount protocol's own, not a fence's -- on the same injected boot clock the renewer's +/// lease deadline is expressed on, so they never disagree about how much budget is left. /// `sleep_step_ms`, when set, makes one inter-attempt pause jump the clock past the lease bound: that /// is how a test asks for exactly one physical attempt without a per-call attempt cap. It depends on /// the engine checking the bound, sleeping, then checking again -- a reissue that slept first would /// send a second attempt. `tests::OperationForTest` covers a fixture needing one operation, but -/// neither the two planes a renewer takes nor this clock, which is why this stays local. +/// neither the planes a renewer takes nor this clock, which is why this stays local. class Ops { public: Ops(std::shared_ptr backend, uint64_t * boot_ms, uint64_t sleep_step_ms = 0) : mount(openRequestsForTest(backend)) - , farewell(openRequestsForTest(std::move(backend))) + , farewell(openRequestsForTest(backend)) + , lease(openRequestsForTest(std::move(backend))) , op(mount.admit()) { - for (CasRequests * requests : {&mount, &farewell}) + for (CasRequests * requests : {&mount, &farewell, &lease}) { requests->setNowFnForTest([boot_ms] { return *boot_ms; }); requests->setSleepFnForTest( @@ -63,6 +68,7 @@ class Ops CasRequests mount; CasRequests farewell; + CasRequests lease; CasOperation op; }; @@ -96,6 +102,8 @@ class RenewalScriptBackend : public InMemoryBackend ReturnThenCancel, ThrowBeforeThenLandAfterResolve, ThrowConnectHint, + ThrowFirstAttemptFuse, + ThrowStoreRefusal, }; struct Attempt @@ -109,6 +117,17 @@ class RenewalScriptBackend : public InMemoryBackend std::vector attempts; std::function cancel_after_write; uint64_t read_calls = 0; + /// Consulted when `actions` is empty: TRUE fails the guarded write with `outage_action`. + std::function outage; + Action outage_action = Action::ThrowBefore; + /// Scripted answers for reads of a mount slot: `ThrowBefore` and `ThrowFirstAttemptFuse` fail the + /// read, `Delegate` serves it. Consulted before `read_outage`. + std::deque read_actions; + /// TRUE fails a read of a mount slot with a transport timeout. + std::function read_outage; + /// Called on every scripted write and on every read of a mount slot, before it is answered. + std::function on_attempt; + std::function on_read; /// Only a GUARDED write of a mount slot is scripted; the fixture's own seeding and every other /// key reach the store untouched. @@ -120,9 +139,18 @@ class RenewalScriptBackend : public InMemoryBackend return InMemoryBackend::write(key, bytes, expected_value, access); attempts.push_back({key, bytes, expected_value}); - const Action action = actions.empty() ? Action::Delegate : actions.front(); + if (on_attempt) + on_attempt(); + Action action = Action::Delegate; if (!actions.empty()) + { + action = actions.front(); actions.pop_front(); + } + else if (outage && outage()) + { + action = outage_action; + } if (action == Action::ThrowConnectHint) { @@ -133,6 +161,16 @@ class RenewalScriptBackend : public InMemoryBackend throw Poco::TimeoutException("connect timed out"); #endif } + if (action == Action::ThrowFirstAttemptFuse) + throwFirstAttemptFuse(); + if (action == Action::ThrowStoreRefusal) + { +#if USE_AWS_S3 + throw DB::S3Exception("the store answered MalformedXML", Aws::S3::S3Errors::UNKNOWN, "MalformedXML"); +#else + throw DB::Exception(DB::ErrorCodes::ABORTED, "a store refusal needs USE_AWS_S3"); +#endif + } if (action == Action::ThrowBefore || action == Action::ThrowBeforeThenLandAfterResolve) { @@ -156,6 +194,24 @@ class RenewalScriptBackend : public InMemoryBackend std::optional read(const String & key, TransportAccess & access) override { ++read_calls; + if (key.ends_with("/mount")) + { + if (on_read) + on_read(); + if (!read_actions.empty()) + { + const Action action = read_actions.front(); + read_actions.pop_front(); + if (action == Action::ThrowFirstAttemptFuse) + throwFirstAttemptFuse(); + if (action == Action::ThrowBefore) + throw Poco::TimeoutException("injected renewal read failure"); + } + else if (read_outage && read_outage()) + { + throw Poco::TimeoutException("injected renewal read outage"); + } + } std::optional result = InMemoryBackend::read(key, access); if (pending && pending->key == key) { @@ -169,6 +225,16 @@ class RenewalScriptBackend : public InMemoryBackend } private: + /// The adaptive first-attempt timeout the engine reissues at once. + [[noreturn]] static void throwFirstAttemptFuse() + { +#if USE_AWS_S3 + throw DB::S3Exception("Timeout", Aws::S3::S3Errors::NETWORK_CONNECTION); +#else + throw Poco::TimeoutException("first-attempt fuse"); +#endif + } + std::optional pending; }; @@ -181,6 +247,8 @@ MountRenewOperationEnvironment renewalEnvironment( .boot_ms = [&boot_ms] { return boot_ms; }, .live = live, .cancelled = cancelled, + .policy = MountRenewPolicy::LeaseBound, + .on_request = {}, }; } @@ -225,7 +293,7 @@ TEST(CASHeartbeat, AnchorCarriesFloor) Ops ops(backend, &boot_ms); seedOwnClaim(ops.op, layout, srid, uuid, /*epoch=*/9, now_ms, /*ttl_ms=*/100); - MountLeaseRenewer renewer(ops.mount, ops.farewell, layout, srid, uuid, /*writer_epoch=*/9, + MountLeaseRenewer renewer(ops.mount, ops.farewell, ops.lease, layout, srid, uuid, /*writer_epoch=*/9, std::chrono::milliseconds(100), [&] { return now_ms; }, [&] { return min_active_build_sequence_now; }, {}, std::chrono::milliseconds(0), [&] { return boot_ms; }); @@ -251,7 +319,7 @@ TEST(CASHeartbeat, RenewRereadsCallbackAndBumpsSeq) Ops ops(backend, &boot_ms); seedOwnClaim(ops.op, layout, srid, uuid, /*epoch=*/9, now_ms, /*ttl_ms=*/100); - MountLeaseRenewer renewer(ops.mount, ops.farewell, layout, srid, uuid, /*writer_epoch=*/9, + MountLeaseRenewer renewer(ops.mount, ops.farewell, ops.lease, layout, srid, uuid, /*writer_epoch=*/9, std::chrono::milliseconds(100), [&] { return now_ms; }, [&] { return min_active_build_sequence_now; }, {}, std::chrono::milliseconds(0), [&] { return boot_ms; }); @@ -279,7 +347,7 @@ TEST(CASHeartbeat, StopStampsExpiredAndFarewellSentinel) Ops ops(backend, &boot_ms); seedOwnClaim(ops.op, layout, srid, uuid, /*epoch=*/9, now_ms, /*ttl_ms=*/100); - MountLeaseRenewer renewer(ops.mount, ops.farewell, layout, srid, uuid, /*writer_epoch=*/9, + MountLeaseRenewer renewer(ops.mount, ops.farewell, ops.lease, layout, srid, uuid, /*writer_epoch=*/9, std::chrono::milliseconds(100), [&] { return now_ms; }, [] { return uint64_t{5}; }, {}, std::chrono::milliseconds(0), [&] { return boot_ms; }); @@ -335,7 +403,7 @@ TEST(CASHeartbeat, FarewellIsAdmittedUnderTheDefaultBudget) Ops ops(backend, &boot_ms); seedOwnClaim(ops.op, layout, srid, uuid, /*epoch=*/9, now_ms, /*ttl_ms=*/30000); - MountLeaseRenewer renewer(ops.mount, ops.farewell, layout, srid, uuid, /*writer_epoch=*/9, + MountLeaseRenewer renewer(ops.mount, ops.farewell, ops.lease, layout, srid, uuid, /*writer_epoch=*/9, std::chrono::milliseconds(30000), [&] { return now_ms; }, [] { return uint64_t{5}; }, {}, std::chrono::milliseconds(2000), [&] { return boot_ms; }); @@ -368,7 +436,7 @@ TEST(CASHeartbeat, FarewellIsAdmittedUnderADifferentEnvelope) Ops ops(backend, &boot_ms); seedOwnClaim(ops.op, layout, srid, uuid, /*epoch=*/9, now_ms, /*ttl_ms=*/40000); - MountLeaseRenewer renewer(ops.mount, ops.farewell, layout, srid, uuid, /*writer_epoch=*/9, + MountLeaseRenewer renewer(ops.mount, ops.farewell, ops.lease, layout, srid, uuid, /*writer_epoch=*/9, std::chrono::milliseconds(40000), [&] { return now_ms; }, [] { return uint64_t{5}; }, {}, std::chrono::milliseconds(2000), [&] { return boot_ms; }); @@ -402,7 +470,7 @@ TEST(CASHeartbeat, FarewellIsRefusedWhenTheLeaseExpiresBeforeItsDerivedWindow) Ops ops(backend, &boot_ms); seedOwnClaim(ops.op, layout, srid, uuid, /*epoch=*/9, now_ms, /*ttl_ms=*/5000); - MountLeaseRenewer renewer(ops.mount, ops.farewell, layout, srid, uuid, /*writer_epoch=*/9, + MountLeaseRenewer renewer(ops.mount, ops.farewell, ops.lease, layout, srid, uuid, /*writer_epoch=*/9, std::chrono::milliseconds(5000), [&] { return now_ms; }, [] { return uint64_t{5}; }, {}, std::chrono::milliseconds(2000), [&] { return boot_ms; }); @@ -448,7 +516,7 @@ TEST(CASHeartbeat, ForeignIncarnationDuringFarewellLeavesTheSuccessorUntouchedAn Ops ops(backend, &boot_ms); seedOwnClaim(ops.op, layout, srid, uuid, /*epoch=*/9, now_ms, /*ttl_ms=*/100); - MountLeaseRenewer renewer(ops.mount, ops.farewell, layout, srid, uuid, /*writer_epoch=*/9, + MountLeaseRenewer renewer(ops.mount, ops.farewell, ops.lease, layout, srid, uuid, /*writer_epoch=*/9, std::chrono::milliseconds(100), [&] { return now_ms; }, [] { return uint64_t{5}; }, {}, std::chrono::milliseconds(0), [&] { return boot_ms; }); @@ -505,7 +573,7 @@ TEST(CASHeartbeat, SameEpochUnfencedTouchIsUncertainNotFatal) Ops ops(backend, &boot_ms); seedOwnClaim(ops.op, layout, srid, uuid, /*epoch=*/9, now_ms, /*ttl_ms=*/100); - MountLeaseRenewer renewer(ops.mount, ops.farewell, layout, srid, uuid, /*writer_epoch=*/9, + MountLeaseRenewer renewer(ops.mount, ops.farewell, ops.lease, layout, srid, uuid, /*writer_epoch=*/9, std::chrono::milliseconds(100), [&] { return now_ms; }, [] { return uint64_t{5}; }, {}, std::chrono::milliseconds(0), [&] { return boot_ms; }); @@ -552,7 +620,7 @@ TEST(CASHeartbeat, SupersededTouchIsFailClosedNotFatal) Ops ops(backend, &boot_ms); seedOwnClaim(ops.op, layout, srid, uuid, /*epoch=*/9, now_ms, /*ttl_ms=*/100); - MountLeaseRenewer renewer(ops.mount, ops.farewell, layout, srid, uuid, /*writer_epoch=*/9, + MountLeaseRenewer renewer(ops.mount, ops.farewell, ops.lease, layout, srid, uuid, /*writer_epoch=*/9, std::chrono::milliseconds(100), [&] { return now_ms; }, [] { return uint64_t{5}; }, {}, std::chrono::milliseconds(0), [&] { return boot_ms; }); @@ -606,7 +674,7 @@ TEST(CASHeartbeat, ForeignUuidTouchFailsClosedWithoutAborting) Ops ops(backend, &boot_ms); seedOwnClaim(ops.op, layout, srid, uuid, /*epoch=*/9, now_ms, /*ttl_ms=*/100); - MountLeaseRenewer renewer(ops.mount, ops.farewell, layout, srid, uuid, /*writer_epoch=*/9, + MountLeaseRenewer renewer(ops.mount, ops.farewell, ops.lease, layout, srid, uuid, /*writer_epoch=*/9, std::chrono::milliseconds(100), [&] { return now_ms; }, [] { return uint64_t{5}; }, {}, std::chrono::milliseconds(0), [&] { return boot_ms; }); @@ -694,7 +762,7 @@ TEST(CASMountAudit, RenewerAdoptEmitsClaimAndTerminateEmitsRelease) std::vector seen; CasEventSink sink = [&](const CasEvent & e) { seen.push_back(e); }; - MountLeaseRenewer renewer(ops.mount, ops.farewell, layout, srid, uuid, /*writer_epoch=*/9, + MountLeaseRenewer renewer(ops.mount, ops.farewell, ops.lease, layout, srid, uuid, /*writer_epoch=*/9, std::chrono::milliseconds(100), [&] { return now_ms; }, [] { return uint64_t{5}; }, sink, std::chrono::milliseconds(0), [&] { return boot_ms; }); @@ -732,7 +800,7 @@ TEST(CASMountAudit, RenewerForeignConflictRefusesAndNamesHolder) ASSERT_EQ(claimMount(ops.op, layout, srid, uuid_x, /*our_epoch=*/1, now_ms, /*ttl_ms=*/100).kind, MountClaimResult::Claimed); - MountLeaseRenewer renewer(ops.mount, ops.farewell, layout, srid, uuid_y, /*writer_epoch=*/1, + MountLeaseRenewer renewer(ops.mount, ops.farewell, ops.lease, layout, srid, uuid_y, /*writer_epoch=*/1, std::chrono::milliseconds(100), [&] { return now_ms; }, [] { return uint64_t{5}; }, {}, std::chrono::milliseconds(2000), [&] { return boot_ms; }); @@ -774,7 +842,7 @@ TEST(CASMountAudit, RenewerAdoptRefusesFencedSelfWithTypedError) std::vector seen; CasEventSink sink = [&](const CasEvent & e) { seen.push_back(e); }; /// A renewer for the SAME (uuid, epoch) tries to adopt the now-fenced slot. - MountLeaseRenewer renewer(ops.mount, ops.farewell, layout, srid, uuid, /*writer_epoch=*/9, + MountLeaseRenewer renewer(ops.mount, ops.farewell, ops.lease, layout, srid, uuid, /*writer_epoch=*/9, std::chrono::milliseconds(100), [&] { return now_ms; }, [] { return uint64_t{5}; }, sink, std::chrono::milliseconds(2000), [&] { return boot_ms; }); @@ -814,7 +882,7 @@ TEST(CASHeartbeat, RenewOverFencedOwnSlotIsClassifiedNotForeign) std::vector seen; CasEventSink sink = [&](const CasEvent & e) { seen.push_back(e); }; - MountLeaseRenewer renewer(ops.mount, ops.farewell, layout, srid, uuid, /*writer_epoch=*/9, + MountLeaseRenewer renewer(ops.mount, ops.farewell, ops.lease, layout, srid, uuid, /*writer_epoch=*/9, std::chrono::milliseconds(100), [&] { return now_ms; }, [] { return uint64_t{5}; }, sink, std::chrono::milliseconds(0), [&] { return boot_ms; }); @@ -869,7 +937,7 @@ TEST(CASHeartbeat, RenewerStateAllowsOnlyActiveReleaseOrTerminal) Ops ops(backend, &boot_ms); seedOwnClaim(ops.op, layout, "released", uuid, 9, wall_ms, 1000); MountLeaseRenewer renewer( - ops.mount, ops.farewell, layout, "released", uuid, 9, std::chrono::milliseconds(1000), + ops.mount, ops.farewell, ops.lease, layout, "released", uuid, 9, std::chrono::milliseconds(1000), [&] { return wall_ms; }, [] { return uint64_t{7}; }, {}, std::chrono::milliseconds(20), [&] { return boot_ms; }); EXPECT_EQ(renewer.state(), MountLeaseRenewerState::New); @@ -894,7 +962,7 @@ TEST(CASHeartbeat, RenewerStateAllowsOnlyActiveReleaseOrTerminal) Ops ops(backend, &boot_ms, /*sleep_step_ms=*/10'000); seedOwnClaim(ops.op, layout, "terminal", uuid, 9, wall_ms, 1000); MountLeaseRenewer renewer( - ops.mount, ops.farewell, layout, "terminal", uuid, 9, std::chrono::milliseconds(1000), + ops.mount, ops.farewell, ops.lease, layout, "terminal", uuid, 9, std::chrono::milliseconds(1000), [&] { return wall_ms; }, [] { return uint64_t{7}; }, {}, std::chrono::milliseconds(20), [&] { return boot_ms; }); renewer.start(); @@ -922,7 +990,7 @@ TEST(CASHeartbeat, RenewalRetriesOneImmutableBodyAndAdoptsLostResponse) Ops ops(backend, &boot_ms); seedOwnClaim(ops.op, layout, srid, uuid, 9, wall_ms, 1000); MountLeaseRenewer renewer( - ops.mount, ops.farewell, layout, srid, uuid, 9, std::chrono::milliseconds(1000), + ops.mount, ops.farewell, ops.lease, layout, srid, uuid, 9, std::chrono::milliseconds(1000), [&] { return wall_ms; }, [] { return uint64_t{7}; }, {}, std::chrono::milliseconds(20), [&] { return boot_ms; }); renewer.start(); @@ -960,7 +1028,7 @@ TEST(CASHeartbeat, RenewalOverConnectFailuresRecoversWithoutASettleRead) Ops ops(backend, &boot_ms); seedOwnClaim(ops.op, layout, srid, uuid, 9, wall_ms, 30000); MountLeaseRenewer renewer( - ops.mount, ops.farewell, layout, srid, uuid, 9, std::chrono::milliseconds(30000), + ops.mount, ops.farewell, ops.lease, layout, srid, uuid, 9, std::chrono::milliseconds(30000), [&] { return wall_ms; }, [] { return uint64_t{7}; }, {}, std::chrono::milliseconds(2000), [&] { return boot_ms; }); renewer.start(); @@ -991,7 +1059,7 @@ TEST(CASHeartbeat, DeadlineBeforeSendTerminalizesWithTypedFailure) Ops ops(backend, &boot_ms); seedOwnClaim(ops.op, layout, "test", UInt128{1}, 9, wall_ms, 100); MountLeaseRenewer renewer( - ops.mount, ops.farewell, layout, "test", UInt128{1}, 9, std::chrono::milliseconds(100), + ops.mount, ops.farewell, ops.lease, layout, "test", UInt128{1}, 9, std::chrono::milliseconds(100), [&] { return wall_ms; }, [] { return uint64_t{0}; }, {}, std::chrono::milliseconds(20), [&] { return boot_ms; }); renewer.start(); @@ -1019,7 +1087,7 @@ TEST(CASHeartbeat, CancellationBeforeSendIsNotAttemptedAndAllowsRelease) Ops ops(backend, &boot_ms); seedOwnClaim(ops.op, layout, "test", UInt128{1}, 9, wall_ms, 1000); MountLeaseRenewer renewer( - ops.mount, ops.farewell, layout, "test", UInt128{1}, 9, std::chrono::milliseconds(1000), + ops.mount, ops.farewell, ops.lease, layout, "test", UInt128{1}, 9, std::chrono::milliseconds(1000), [&] { return wall_ms; }, [] { return uint64_t{0}; }, {}, std::chrono::milliseconds(20), [&] { return boot_ms; }); renewer.start(); @@ -1045,7 +1113,7 @@ TEST(CASHeartbeat, CancellationAfterSendIsTerminalAndForbidsRelease) Ops ops(backend, &boot_ms); seedOwnClaim(ops.op, layout, "test", UInt128{1}, 9, wall_ms, 1000); MountLeaseRenewer renewer( - ops.mount, ops.farewell, layout, "test", UInt128{1}, 9, std::chrono::milliseconds(1000), + ops.mount, ops.farewell, ops.lease, layout, "test", UInt128{1}, 9, std::chrono::milliseconds(1000), [&] { return wall_ms; }, [] { return uint64_t{0}; }, {}, std::chrono::milliseconds(20), [&] { return boot_ms; }); renewer.start(); @@ -1074,7 +1142,7 @@ TEST(CASHeartbeat, SlowResolvedSuccessKeepsAttemptStartAnchor) Ops ops(backend, &boot_ms); seedOwnClaim(ops.op, layout, "test", UInt128{1}, 9, wall_ms, 1000); MountLeaseRenewer renewer( - ops.mount, ops.farewell, layout, "test", UInt128{1}, 9, std::chrono::milliseconds(1000), + ops.mount, ops.farewell, ops.lease, layout, "test", UInt128{1}, 9, std::chrono::milliseconds(1000), [&] { return wall_ms; }, [] { return uint64_t{0}; }, {}, std::chrono::milliseconds(20), [&] { return boot_ms; }); renewer.start(); @@ -1099,7 +1167,7 @@ TEST(CASHeartbeat, SamePairTwinAndForeignOrSuccessorStayTerminal) Ops ops(backend, &boot_ms); seedOwnClaim(ops.op, layout, "test", uuid, 9, wall_ms, 1000); MountLeaseRenewer renewer( - ops.mount, ops.farewell, layout, "test", uuid, 9, std::chrono::milliseconds(1000), + ops.mount, ops.farewell, ops.lease, layout, "test", uuid, 9, std::chrono::milliseconds(1000), [&] { return wall_ms; }, [] { return uint64_t{0}; }, {}, std::chrono::milliseconds(20), [&] { return boot_ms; }); renewer.start(); @@ -1133,7 +1201,7 @@ TEST(CASHeartbeat, ExpectedPredecessorThenLateLandingIsAdoptedExactly) Ops ops(backend, &boot_ms); seedOwnClaim(ops.op, layout, "test", UInt128{1}, 9, wall_ms, 1000); MountLeaseRenewer renewer( - ops.mount, ops.farewell, layout, "test", UInt128{1}, 9, std::chrono::milliseconds(1000), + ops.mount, ops.farewell, ops.lease, layout, "test", UInt128{1}, 9, std::chrono::milliseconds(1000), [&] { return wall_ms; }, [] { return uint64_t{0}; }, {}, std::chrono::milliseconds(20), [&] { return boot_ms; }); renewer.start(); @@ -1162,7 +1230,7 @@ TEST(CASHeartbeat, GcFenceAndVanishedMountStayTerminal) Ops ops(backend, &boot_ms); seedOwnClaim(ops.op, layout, "test", UInt128{1}, 9, wall_ms, 1000); MountLeaseRenewer renewer( - ops.mount, ops.farewell, layout, "test", UInt128{1}, 9, std::chrono::milliseconds(1000), + ops.mount, ops.farewell, ops.lease, layout, "test", UInt128{1}, 9, std::chrono::milliseconds(1000), [&] { return wall_ms; }, [] { return uint64_t{0}; }, {}, std::chrono::milliseconds(20), [&] { return boot_ms; }); renewer.start(); @@ -1198,7 +1266,7 @@ TEST(CASHeartbeat, LateDeliveryAfterTerminalCannotRearmOrOverwriteSuccessor) Ops ops(backend, &boot_ms, /*sleep_step_ms=*/10'000); seedOwnClaim(ops.op, layout, "before-reclaim", UInt128{1}, 9, wall_ms, 1000); MountLeaseRenewer renewer( - ops.mount, ops.farewell, layout, "before-reclaim", UInt128{1}, 9, std::chrono::milliseconds(1000), + ops.mount, ops.farewell, ops.lease, layout, "before-reclaim", UInt128{1}, 9, std::chrono::milliseconds(1000), [&] { return wall_ms; }, [] { return uint64_t{0}; }, CasEventSink{}, std::chrono::milliseconds(20), [&] { return boot_ms; }); renewer.start(); @@ -1220,7 +1288,7 @@ TEST(CASHeartbeat, LateDeliveryAfterTerminalCannotRearmOrOverwriteSuccessor) Ops ops(backend, &boot_ms, /*sleep_step_ms=*/10'000); seedOwnClaim(ops.op, layout, "after-successor", UInt128{1}, 9, wall_ms, 1000); MountLeaseRenewer renewer( - ops.mount, ops.farewell, layout, "after-successor", UInt128{1}, 9, std::chrono::milliseconds(1000), + ops.mount, ops.farewell, ops.lease, layout, "after-successor", UInt128{1}, 9, std::chrono::milliseconds(1000), [&] { return wall_ms; }, [] { return uint64_t{0}; }, {}, std::chrono::milliseconds(20), [&] { return boot_ms; }); renewer.start(); @@ -1246,7 +1314,7 @@ TEST(CASHeartbeat, LateDeliveryAfterTerminalCannotRearmOrOverwriteSuccessor) ASSERT_EQ(claimMount(ops.op, layout, "after-successor", UInt128{1}, 10, wall_ms, 1000).kind, MountClaimResult::Claimed); MountLeaseRenewer successor( - ops.mount, ops.farewell, layout, "after-successor", UInt128{1}, 10, std::chrono::milliseconds(1000), + ops.mount, ops.farewell, ops.lease, layout, "after-successor", UInt128{1}, 10, std::chrono::milliseconds(1000), [&] { return wall_ms; }, [] { return uint64_t{0}; }, {}, std::chrono::milliseconds(20), [&] { return boot_ms; }); successor.start(); @@ -1268,7 +1336,7 @@ TEST(CASHeartbeat, WallClockStepsAndBootSuspendCannotExtendAuthority) Ops ops(backend, &boot_ms); seedOwnClaim(ops.op, layout, "test", UInt128{1}, 9, wall_ms, 1000); MountLeaseRenewer renewer( - ops.mount, ops.farewell, layout, "test", UInt128{1}, 9, std::chrono::milliseconds(1000), + ops.mount, ops.farewell, ops.lease, layout, "test", UInt128{1}, 9, std::chrono::milliseconds(1000), [&] { return wall_ms; }, [] { return uint64_t{0}; }, {}, std::chrono::milliseconds(20), [&] { return boot_ms; }); renewer.start(); @@ -1334,7 +1402,7 @@ TEST(CASHeartbeat, RenewalStopsBeforeTheCutoffWhenEveryAttemptConsumesTheEnvelop Layout layout("pool"); Ops ops(backend, &boot_ms); seedOwnClaim(ops.op, layout, "test", UInt128{0x1234}, 9, wall_ms, 1000); - MountLeaseRenewer renewer(ops.mount, ops.farewell, layout, "test", UInt128{0x1234}, 9, std::chrono::milliseconds(1000), + MountLeaseRenewer renewer(ops.mount, ops.farewell, ops.lease, layout, "test", UInt128{0x1234}, 9, std::chrono::milliseconds(1000), [&] { return wall_ms; }, [] { return uint64_t{7}; }, {}, std::chrono::milliseconds(100), [&] { return boot_ms; }); renewer.start(); @@ -1345,3 +1413,585 @@ TEST(CASHeartbeat, RenewalStopsBeforeTheCutoffWhenEveryAttemptConsumesTheEnvelop EXPECT_EQ(result.outcome, MountRenewOutcome::Terminal); EXPECT_LE(boot_ms, cutoff) << "the last attempt started inside the cutoff and the engine did not start one that could not finish"; } + +namespace +{ +/// The production shape at test scale: a 30 s lease, renewed one 10 s period after its anchor, with a +/// 2 s safety margin and the 7 s attempt envelope a bounded renewal reserves twice before each +/// request. That leaves a bounded renewal about 4 s of retries; an `UntilDefinitive` one has no bound. +class UnboundedRenewalFixture +{ +public: + static constexpr uint64_t ttl_ms = 30'000; + static constexpr uint64_t period_ms = 10'000; + static constexpr uint64_t margin_ms = 2'000; + /// Far above the longest legitimate renewal (one request per second for a few lease lengths). + static constexpr size_t max_requests = 500; + + UnboundedRenewalFixture() + { + backend->setAttemptTimeoutMs(7'000); + ops = std::make_unique(backend, &boot_ms); + seedOwnClaim(ops->op, layout, "test", UInt128{1}, 9, wall_ms, ttl_ms); + renewer = std::make_unique( + ops->mount, ops->farewell, ops->lease, layout, "test", UInt128{1}, 9, std::chrono::milliseconds(ttl_ms), + [this] { return wall_ms; }, [] { return uint64_t{0}; }, + [this](CasEvent event) { events.push_back(std::move(event)); }, + std::chrono::milliseconds(margin_ms), [this] { return boot_ms; }); + anchor = renewer->start(); + backend->attempts.clear(); + backend->read_calls = 0; + events.clear(); + boot_ms = anchor + period_ms; + renewal_start = boot_ms; + } + + UnboundedRenewalFixture(const UnboundedRenewalFixture &) = delete; + UnboundedRenewalFixture & operator=(const UnboundedRenewalFixture &) = delete; + + MountRenewResult renew( + MountRenewPolicy policy, + const std::function & live = {}, + const std::function & cancelled = {}, + std::function on_request = {}) + { + /// The test clock moves only through the sleep seam, so a regression that zeroes every pause would + /// loop forever; the request count bounds the renewal and the check below fails it instead. + const auto bounded_live = [this, live] + { + if (backend->attempts.size() + backend->read_calls >= max_requests) + { + request_bound_hit = true; + return false; + } + return !live || live(); + }; + MountRenewOperationEnvironment environment = renewalEnvironment(boot_ms, bounded_live, cancelled); + environment.policy = policy; + environment.on_request = std::move(on_request); + MountRenewResult result = renewer->renew(environment); + EXPECT_FALSE(request_bound_hit) << "the renewal sent " << max_requests + << " requests without the clock reaching the end of the outage: the spaced pauses are not advancing it"; + return result; + } + + /// The `branch` of every `MountConflict` event, in order. + std::vector conflictBranches() const + { + std::vector branches; + for (const CasEvent & event : events) + if (event.type == CasEventType::MountConflict) + branches.push_back(event.detail.at("branch")); + return branches; + } + + String mountKey() const { return layout.mountKey("test"); } + + std::shared_ptr backend = std::make_shared(); + Layout layout{"pool"}; + uint64_t wall_ms = 1000; + uint64_t boot_ms = 100; + std::vector events; + std::unique_ptr ops; + std::unique_ptr renewer; + uint64_t anchor = 0; + uint64_t renewal_start = 0; + bool request_bound_hit = false; +}; + +/// A request start (`P`) or a resolve read (`R`), with the boot clock when it was issued. +using RequestLog = std::vector>; + +bool inSpacing(uint64_t gap_ms) +{ + return gap_ms >= kMountRenewRetrySpacingMs * 8 / 10 && gap_ms <= kMountRenewRetrySpacingMs * 12 / 10; +} +} + +/// An outage longer than the cutoff a bounded renewal reserves for is retried to its end. +TEST(CASHeartbeat, RenewalOutlivesTheReservationCutoff) +{ + UnboundedRenewalFixture f; + f.backend->outage = [&] { return f.boot_ms < f.renewal_start + 8'000; }; + + const MountRenewResult result = f.renew(MountRenewPolicy::UntilDefinitive); + + ASSERT_EQ(result.outcome, MountRenewOutcome::Committed); + EXPECT_EQ(f.renewer->state(), MountLeaseRenewerState::Active); + /// One request per spacing interval of 800 to 1200 ms until the outage ends, then the one that lands. + EXPECT_GE(f.backend->attempts.size(), 8u); + EXPECT_LE(f.backend->attempts.size(), 11u); + EXPECT_EQ(static_cast(result.attempts_sent), f.backend->attempts.size()); +} + +TEST(CASHeartbeat, RenewalSendsOneTupleOnEveryAttempt) +{ + UnboundedRenewalFixture f; + f.backend->outage = [&] { return f.boot_ms < f.renewal_start + 8'000; }; + + const MountRenewResult result = f.renew(MountRenewPolicy::UntilDefinitive); + + ASSERT_EQ(result.outcome, MountRenewOutcome::Committed); + const auto & attempts = f.backend->attempts; + ASSERT_GT(attempts.size(), 1u); + const UInt128 attempt_id = decodeMountLease(attempts.front().bytes).write_attempt_id; + for (const auto & attempt : attempts) + { + EXPECT_EQ(attempt.key, attempts.front().key); + EXPECT_EQ(attempt.bytes, attempts.front().bytes); + EXPECT_EQ(attempt.expected, attempts.front().expected); + EXPECT_EQ(decodeMountLease(attempt.bytes).write_attempt_id, attempt_id); + } + EXPECT_EQ(f.ops->op.read(f.mountKey(), Retry::standard())->bytes, attempts.front().bytes) + << "the body that landed is the one every attempt carried"; +} + +TEST(CASHeartbeat, RenewalSucceedsPastTheDeadlineWithItsFirstStart) +{ + UnboundedRenewalFixture f; + f.backend->outage = [&] { return f.boot_ms < f.anchor + UnboundedRenewalFixture::ttl_ms + 15'000; }; + + const MountRenewResult result = f.renew(MountRenewPolicy::UntilDefinitive); + + ASSERT_EQ(result.outcome, MountRenewOutcome::Committed); + EXPECT_EQ(result.attempt_start_boot_ms, f.renewal_start); + EXPECT_EQ(f.renewer->lastCommittedAttemptStartBootMs(), f.renewal_start); + EXPECT_LT(result.attempt_start_boot_ms + UnboundedRenewalFixture::ttl_ms, f.boot_ms) + << "the lease this success confirms is already over"; +} + +TEST(CASHeartbeat, LandedAttemptIsAdoptedAfterALongOutage) +{ + UnboundedRenewalFixture f; + f.backend->actions = {RenewalScriptBackend::Action::LandThenThrow}; + f.backend->read_outage = [&] { return f.boot_ms < f.anchor + UnboundedRenewalFixture::ttl_ms + 15'000; }; + std::vector reported; + + const MountRenewResult result = f.renew( + MountRenewPolicy::UntilDefinitive, {}, {}, [&](const MountRenewRequestEvent & event) { reported.push_back(event); }); + const uint64_t reads = f.backend->read_calls; + + ASSERT_EQ(result.outcome, MountRenewOutcome::Committed); + EXPECT_TRUE(result.resolved_by_read); + EXPECT_EQ(result.attempts_sent, 1u); + EXPECT_GT(f.boot_ms, f.anchor + UnboundedRenewalFixture::ttl_ms) << "the adopting read came after the deadline"; + EXPECT_TRUE(f.conflictBranches().empty()) << "an adopted attempt is not a conflict such as same_epoch_state_uncertain"; + EXPECT_EQ(decodeMountLease(f.ops->op.read(f.mountKey(), Retry::standard())->bytes).write_attempt_id, + decodeMountLease(f.backend->attempts.front().bytes).write_attempt_id); + + /// The one PUT sent, its failure, then one failed event per failed read; the last read succeeded. + ASSERT_GE(reads, 2u); + ASSERT_EQ(reported.size(), 2 + (reads - 1)); + EXPECT_FALSE(reported[0].failed); + EXPECT_TRUE(reported[1].failed); + EXPECT_NE(reported[1].failure_text.find("injected renewal response loss after commit"), String::npos) + << reported[1].failure_text; + for (size_t i = 2; i < reported.size(); ++i) + { + EXPECT_EQ(reported[i].request_no, 1u) << i; + EXPECT_TRUE(reported[i].failed) << i << ": no request but the first PUT was sent"; + EXPECT_NE(reported[i].failure_text.find("injected renewal read outage"), String::npos) + << i << ": " << reported[i].failure_text; + } +} + +/// Each definitive answer, met by a request sent past the deadline, ends the renewal with today's +/// classification. +TEST(CASHeartbeat, DefinitiveAnswersStayTerminalPastTheDeadline) +{ + enum class Answer : uint8_t { GcFenced, Foreign, NewerOwnEpoch, OwnEpochOtherBytes, Absent, StoreRefusal, LocalFailure }; + const auto run = [](Answer answer) + { + UnboundedRenewalFixture f; + const String key = f.mountKey(); + const auto replace_slot = [&](const std::function & change) + { + const auto got = f.ops->op.read(key, Retry::standard()); + ASSERT_TRUE(got.has_value()); + MountLease lease = decodeMountLease(got->bytes); + change(lease); + ++lease.seq; + mustCommit(f.ops->op.replace(key, encodeMountLease(lease), got->etag, Retry::standard()), "changed slot"); + }; + switch (answer) + { + case Answer::GcFenced: + replace_slot([](MountLease & lease) { lease.gc_fenced = true; }); + break; + case Answer::Foreign: + replace_slot([](MountLease & lease) { lease.server_uuid = UInt128{2}; }); + break; + case Answer::NewerOwnEpoch: + replace_slot([](MountLease & lease) { lease.writer_epoch = 10; }); + break; + case Answer::OwnEpochOtherBytes: + replace_slot([](MountLease & lease) { lease.write_attempt_id = UInt128{0xAAAA}; }); + break; + case Answer::Absent: + { + const auto got = f.ops->op.read(key, Retry::standard()); + ASSERT_TRUE(got.has_value()); + ASSERT_EQ(f.ops->op.remove(key, got->etag, Retry::standard()), Removal::Removed); + break; + } + case Answer::StoreRefusal: +#if USE_AWS_S3 + f.backend->failNextWriteWith(key, std::make_exception_ptr(DB::S3Exception( + "the store answered MalformedXML", Aws::S3::S3Errors::UNKNOWN, "MalformedXML"))); +#endif + break; + case Answer::LocalFailure: + f.backend->failNextWriteWith(key, std::make_exception_ptr(DB::Exception( + DB::ErrorCodes::CORRUPTED_DATA, "injected deterministic local failure"))); + break; + } + f.backend->attempts.clear(); + f.events.clear(); + /// Past the lease: a bounded renewal would send nothing here. + f.boot_ms = f.anchor + UnboundedRenewalFixture::ttl_ms + 1'000; + /// A definitive answer that was retried would never end this renewal; the bound makes it fail instead. + const uint64_t live_until = f.boot_ms + 600'000; + + const MountRenewResult result = f.renew(MountRenewPolicy::UntilDefinitive, [&] { return f.boot_ms < live_until; }); + + const DB::Exception failure = terminalException(result); + EXPECT_EQ(f.renewer->state(), MountLeaseRenewerState::RenewalTerminal); + EXPECT_EQ(f.backend->attempts.size(), 1u) << "the answer came to a request sent past the deadline"; + const std::vector branches = f.conflictBranches(); + switch (answer) + { + case Answer::GcFenced: + EXPECT_EQ(branches, std::vector{"fenced_by_gc"}); + break; + case Answer::Foreign: + EXPECT_EQ(branches, std::vector{"foreign_writer"}); + break; + case Answer::NewerOwnEpoch: + EXPECT_EQ(branches, std::vector{"superseded"}); + break; + case Answer::OwnEpochOtherBytes: + EXPECT_EQ(branches, std::vector{"same_epoch_state_uncertain"}); + break; + case Answer::Absent: + EXPECT_EQ(branches, std::vector{"vanished"}); + EXPECT_EQ(failure.code(), DB::ErrorCodes::FILE_DOESNT_EXIST) << failure.message(); + break; + case Answer::StoreRefusal: + EXPECT_TRUE(branches.empty()); + EXPECT_NE(failure.message().find("the store refused the renewal"), String::npos) << failure.message(); + break; + case Answer::LocalFailure: + EXPECT_TRUE(branches.empty()); + EXPECT_EQ(failure.code(), DB::ErrorCodes::CORRUPTED_DATA) << failure.message(); + EXPECT_NE(failure.message().find("injected deterministic local failure"), String::npos); + break; + } + }; + for (Answer answer : {Answer::GcFenced, Answer::Foreign, Answer::NewerOwnEpoch, Answer::OwnEpochOtherBytes, + Answer::Absent, Answer::StoreRefusal, Answer::LocalFailure}) + { +#if !USE_AWS_S3 + if (answer == Answer::StoreRefusal) + continue; +#endif + SCOPED_TRACE(static_cast(answer)); + run(answer); + } +} + +/// The cut-off node's story: renewals fail past the deadline, GC on a healthy node fences the slot, +/// and the first request that reaches the store reads the fence. +TEST(CASHeartbeat, AFenceSeenAfterALongOutageEndsTheRenewal) +{ + UnboundedRenewalFixture f; + const uint64_t fenced_at = f.anchor + UnboundedRenewalFixture::ttl_ms + 15'000; + bool fenced = false; + f.backend->outage = [&] { return !fenced; }; + f.ops->lease.setSleepFnForTest([&](uint64_t ms) + { + f.boot_ms += ms; + if (fenced || f.boot_ms < fenced_at) + return; + fenced = true; + const auto got = f.ops->op.read(f.mountKey(), Retry::standard()); + ASSERT_TRUE(got.has_value()); + MountLease lease = decodeMountLease(got->bytes); + lease.gc_fenced = true; + ++lease.seq; + mustCommit(f.ops->op.replace(f.mountKey(), encodeMountLease(lease), got->etag, Retry::standard()), "fence-out"); + }); + + /// A fence that was retried would never end this renewal; the bound makes it fail instead. + const MountRenewResult result = f.renew( + MountRenewPolicy::UntilDefinitive, [&] { return f.boot_ms < f.renewal_start + 600'000; }); + + const DB::Exception failure = terminalException(result); + EXPECT_NE(failure.message().find("fenced by GC"), String::npos) << failure.message(); + EXPECT_EQ(f.conflictBranches(), std::vector{"fenced_by_gc"}); + EXPECT_GE(f.boot_ms, fenced_at); +} + +#if USE_AWS_S3 +/// After an unclear attempt the engine cannot tell whether that attempt will still land, so a refusal +/// is not an answer about the slot: the renewal keeps retrying at the spacing until a stop ends it. +TEST(CASHeartbeat, ARefusalAfterAnUnclearAttemptIsRetriedUntilStopped) +{ + UnboundedRenewalFixture f; + f.backend->actions = {RenewalScriptBackend::Action::ThrowBefore}; + f.backend->outage = [] { return true; }; + f.backend->outage_action = RenewalScriptBackend::Action::ThrowStoreRefusal; + std::vector sent_at; + f.backend->on_attempt = [&] { sent_at.push_back(f.boot_ms); }; + bool stopped = false; + f.ops->lease.setSleepFnForTest([&](uint64_t ms) + { + f.boot_ms += ms; + if (f.boot_ms >= f.renewal_start + 30'000) + stopped = true; + }); + std::vector reported; + + const MountRenewResult result = f.renew( + MountRenewPolicy::UntilDefinitive, /*live=*/[&] { return !stopped; }, /*cancelled=*/[&] { return stopped; }, + [&](const MountRenewRequestEvent & event) { reported.push_back(event); }); + + const DB::Exception failure = terminalException(result); + EXPECT_EQ(failure.code(), DB::ErrorCodes::NETWORK_ERROR) << failure.message(); + EXPECT_EQ(f.renewer->state(), MountLeaseRenewerState::RenewalTerminal); + EXPECT_TRUE(f.conflictBranches().empty()) << "the read kept showing our own unchanged body"; + + /// One PUT per spacing interval over the 30 s the store kept refusing. + ASSERT_GE(sent_at.size(), 2u); + for (size_t i = 1; i < sent_at.size(); ++i) + EXPECT_TRUE(inSpacing(sent_at[i] - sent_at[i - 1])) << i << ": " << sent_at[i] - sent_at[i - 1]; + EXPECT_GE(sent_at.size(), 30'000 / (kMountRenewRetrySpacingMs * 12 / 10)); + EXPECT_LE(sent_at.size(), 30'000 / (kMountRenewRetrySpacingMs * 8 / 10) + 1); + + /// Every refusal was reported as a failed request. + size_t refusals = 0; + for (const MountRenewRequestEvent & event : reported) + if (event.failed && event.failure_text.find("MalformedXML") != String::npos) + ++refusals; + EXPECT_EQ(refusals, sent_at.size() - 1) << "every PUT after the unclear first one was refused"; +} +#endif + +TEST(CASHeartbeat, RenewalSpacesRetries) +{ +#if USE_AWS_S3 + { + SCOPED_TRACE("fast connect failures"); + UnboundedRenewalFixture f; + RequestLog log; + f.backend->on_attempt = [&] { log.emplace_back('P', f.boot_ms); }; + f.backend->on_read = [&] { log.emplace_back('R', f.boot_ms); }; + f.backend->actions = {RenewalScriptBackend::Action::ThrowFirstAttemptFuse}; + f.backend->outage = [&] { return f.boot_ms < f.renewal_start + 30'500; }; + f.backend->outage_action = RenewalScriptBackend::Action::ThrowConnectHint; + + ASSERT_EQ(f.renew(MountRenewPolicy::UntilDefinitive).outcome, MountRenewOutcome::Committed); + + ASSERT_GE(log.size(), 4u); + /// The fuse: its settling read and its reissue follow at once. + EXPECT_EQ(log[0], std::make_pair('P', f.renewal_start)); + EXPECT_EQ(log[1], std::make_pair('R', f.renewal_start)); + EXPECT_EQ(log[2], std::make_pair('P', f.renewal_start)); + /// A connect failure is reissued without a read, one spacing interval after it started. + for (size_t i = 3; i < log.size(); ++i) + { + EXPECT_EQ(log[i].first, 'P') << i; + EXPECT_TRUE(inSpacing(log[i].second - log[i - 1].second)) << i << ": " << log[i].second - log[i - 1].second; + } + EXPECT_GE(log.back().second, f.renewal_start + 30'000) << "still renewing after 30 s"; + } +#endif + { + SCOPED_TRACE("unclear PUT with a failing read"); + UnboundedRenewalFixture f; + RequestLog log; + f.backend->on_attempt = [&] { log.emplace_back('P', f.boot_ms); }; + f.backend->on_read = [&] { log.emplace_back('R', f.boot_ms); }; + f.backend->read_actions = {RenewalScriptBackend::Action::ThrowBefore, RenewalScriptBackend::Action::ThrowBefore}; + f.backend->outage = [&] { return f.boot_ms < f.renewal_start + 30'500; }; + + ASSERT_EQ(f.renew(MountRenewPolicy::UntilDefinitive).outcome, MountRenewOutcome::Committed); + + ASSERT_GE(log.size(), 6u); + const uint64_t t0 = f.renewal_start; + EXPECT_EQ(log[0], std::make_pair('P', t0)); + EXPECT_EQ(log[1], std::make_pair('R', t0)) << "the read that settles an unclear PUT is sent at once"; + EXPECT_EQ(log[2].first, 'R'); + EXPECT_TRUE(inSpacing(log[2].second - log[1].second)) << log[2].second - log[1].second; + EXPECT_EQ(log[3].first, 'R'); + EXPECT_TRUE(inSpacing(log[3].second - log[2].second)) << log[3].second - log[2].second; + EXPECT_EQ(log[4], std::make_pair('P', log[3].second)) + << "more than one interval has passed since the PUT started, so it is retried at once"; + uint64_t previous_put = log[4].second; + for (size_t i = 5; i < log.size(); ++i) + { + if (log[i].first == 'R') + { + EXPECT_EQ(log[i].second, log[i - 1].second) << i; + continue; + } + EXPECT_TRUE(inSpacing(log[i].second - previous_put)) << i << ": " << log[i].second - previous_put; + previous_put = log[i].second; + } + EXPECT_GE(previous_put, t0 + 30'000) << "still renewing after 30 s"; + } +#if USE_AWS_S3 + { + SCOPED_TRACE("first-attempt fuse of the read"); + UnboundedRenewalFixture f; + RequestLog log; + f.backend->on_attempt = [&] { log.emplace_back('P', f.boot_ms); }; + f.backend->on_read = [&] { log.emplace_back('R', f.boot_ms); }; + f.backend->actions = {RenewalScriptBackend::Action::ThrowBefore}; + f.backend->read_actions = {RenewalScriptBackend::Action::ThrowFirstAttemptFuse}; + + ASSERT_EQ(f.renew(MountRenewPolicy::UntilDefinitive).outcome, MountRenewOutcome::Committed); + + ASSERT_EQ(log.size(), 4u); + EXPECT_EQ(log[1], std::make_pair('R', f.renewal_start)); + EXPECT_EQ(log[2], std::make_pair('R', f.renewal_start)) << "a fused read is reissued at once"; + EXPECT_EQ(log[3].first, 'P'); + EXPECT_TRUE(inSpacing(log[3].second - log[0].second)) << log[3].second - log[0].second; + } +#endif + { + SCOPED_TRACE("slow requests"); + UnboundedRenewalFixture f; + RequestLog log; + bool failing = false; + f.backend->on_attempt = [&] + { + log.emplace_back('P', f.boot_ms); + failing = f.boot_ms < f.renewal_start + 30'500; + if (failing) + f.boot_ms += 5'000; + }; + f.backend->on_read = [&] { log.emplace_back('R', f.boot_ms); }; + f.backend->outage = [&] { return failing; }; + + ASSERT_EQ(f.renew(MountRenewPolicy::UntilDefinitive).outcome, MountRenewOutcome::Committed); + + ASSERT_GE(log.size(), 3u); + std::optional previous_put; + for (size_t i = 0; i < log.size(); ++i) + { + if (log[i].first == 'R') + { + EXPECT_EQ(log[i].second, log[i - 1].second + 5'000) << i; + continue; + } + if (previous_put) + EXPECT_EQ(log[i].second, *previous_put + 5'000) << i << ": a 5 s request is retried with no wait"; + previous_put = log[i].second; + } + EXPECT_GE(*previous_put, f.renewal_start + 30'000) << "still renewing after 30 s"; + } +} + +TEST(CASHeartbeat, StopDuringARetryWaitEndsTheRenewal) +{ + { + SCOPED_TRACE("a stop during the wait"); + UnboundedRenewalFixture f; + bool stopped = false; + std::vector waits; + f.backend->outage = [] { return true; }; + /// The stop wakes the wait, so the clock does not move. + f.ops->lease.setSleepFnForTest([&](uint64_t ms) + { + waits.push_back(ms); + stopped = true; + }); + + const MountRenewResult result = f.renew( + MountRenewPolicy::UntilDefinitive, /*live=*/[&] { return !stopped; }, /*cancelled=*/[&] { return stopped; }); + + const DB::Exception failure = terminalException(result); + EXPECT_EQ(failure.code(), DB::ErrorCodes::NETWORK_ERROR) << failure.message(); + ASSERT_EQ(waits.size(), 1u); + EXPECT_TRUE(inSpacing(waits[0])) << waits[0]; + EXPECT_EQ(f.backend->attempts.size(), 1u) << "nothing is sent after the stop"; + EXPECT_EQ(f.renewer->state(), MountLeaseRenewerState::RenewalTerminal); + EXPECT_FALSE(f.renewer->canRelease()); + } + { + SCOPED_TRACE("a stop after the renewal began, before its first send"); + UnboundedRenewalFixture f; + + const MountRenewResult result = f.renew( + MountRenewPolicy::UntilDefinitive, /*live=*/[] { return false; }, /*cancelled=*/[] { return false; }); + + (void)terminalException(result); + EXPECT_TRUE(f.backend->attempts.empty()); + EXPECT_FALSE(f.renewer->canRelease()); + } +} + +TEST(CASHeartbeat, RenewalReportsEachRequestAsItHappens) +{ + UnboundedRenewalFixture f; + f.backend->actions = {RenewalScriptBackend::Action::ThrowBefore, RenewalScriptBackend::Action::ThrowBefore}; + std::vector reported; + + const MountRenewResult result = f.renew( + MountRenewPolicy::UntilDefinitive, {}, {}, [&](const MountRenewRequestEvent & event) { reported.push_back(event); }); + + ASSERT_EQ(result.outcome, MountRenewOutcome::Committed); + const std::vector> expected{{1, false}, {1, true}, {2, false}, {2, true}, {3, false}}; + ASSERT_EQ(reported.size(), expected.size()); + for (size_t i = 0; i < expected.size(); ++i) + { + EXPECT_EQ(reported[i].request_no, expected[i].first) << i; + EXPECT_EQ(reported[i].failed, expected[i].second) << i; + if (reported[i].failed) + EXPECT_NE(reported[i].failure_text.find("injected renewal response uncertainty"), String::npos) + << reported[i].failure_text; + else + EXPECT_TRUE(reported[i].failure_text.empty()) << i; + } +} + +TEST(CASHeartbeat, AThrowingRequestReportChangesNoOutcome) +{ + UnboundedRenewalFixture f; + f.backend->actions = {RenewalScriptBackend::Action::ThrowBefore, RenewalScriptBackend::Action::ThrowBefore}; + + const MountRenewResult result = f.renew( + MountRenewPolicy::UntilDefinitive, {}, {}, + [](const MountRenewRequestEvent &) { throw std::runtime_error("injected report failure"); }); + + ASSERT_EQ(result.outcome, MountRenewOutcome::Committed); + EXPECT_EQ(result.attempts_sent, 3u); + EXPECT_EQ(f.renewer->state(), MountLeaseRenewerState::Active); +} + +/// The startup, remount and direct renewals keep their lease bound. +TEST(CASHeartbeat, BoundedPathsStillStopAtTheLeaseDeadline) +{ + for (const bool remount : {false, true}) + { + SCOPED_TRACE(remount ? "renewForRemount" : "renew"); + UnboundedRenewalFixture f; + std::vector sent_at; + f.backend->on_attempt = [&] { sent_at.push_back(f.boot_ms); }; + /// Longer than any lease, so only the bound can end the renewal. + f.backend->outage = [&] { return f.boot_ms < f.renewal_start + 60'000; }; + MountRenewOperationEnvironment environment = renewalEnvironment(f.boot_ms); + environment.policy = MountRenewPolicy::LeaseBound; + + const MountRenewResult result = remount ? f.renewer->renewForRemount(environment) : f.renewer->renew(environment); + + const DB::Exception failure = terminalException(result); + EXPECT_NE(failure.message().find("external_lease_deadline"), String::npos) << failure.message(); + ASSERT_TRUE(result.deadline_source.has_value()); + EXPECT_EQ(*result.deadline_source, GaveUp::Source::Lease); + ASSERT_FALSE(sent_at.empty()); + const uint64_t lease_safe = f.anchor + UnboundedRenewalFixture::ttl_ms - UnboundedRenewalFixture::margin_ms; + for (uint64_t at : sent_at) + EXPECT_LT(at, lease_safe) << "no request starts past the lease-safe bound"; + } +} diff --git a/src/Disks/tests/gtest_cas_lifecycle_snapshot.cpp b/src/Disks/tests/gtest_cas_lifecycle_snapshot.cpp index ea504c894641..e9b9499eca8b 100644 --- a/src/Disks/tests/gtest_cas_lifecycle_snapshot.cpp +++ b/src/Disks/tests/gtest_cas_lifecycle_snapshot.cpp @@ -7,6 +7,7 @@ #include #include +#include #include #include #include @@ -235,3 +236,35 @@ TEST(CASLifecycleSnapshot, NaturalIdentityLostMatchesThrowDetail) << "snapshot detail and the typed error must not drift\n detail: " << snap.detail << "\n thrown: " << thrown; } + +/// An expired lease, while the lifecycle enum stays `Live`: `not_live` / `lease_expired`, `since` is the +/// deadline as wall time, and a deadline back in the future returns the row to `live`. +TEST(CASLifecycleSnapshot, ExpiredLeaseIsNotLiveUntilRestored) +{ + auto storage = openSnapshotStorage(); + commitOnePart(*storage); + auto pool = storage->store(); + const auto wall_now_s = [] + { + return static_cast(std::chrono::duration_cast( + std::chrono::system_clock::now().time_since_epoch()).count()); + }; + + const int64_t before_s = wall_now_s(); + pool->setMountDeadline(pool->bootMsNow() - 5'000); + const CasLifecycleSnapshot expired = storage->lifecycleSnapshot(); + const int64_t after_s = wall_now_s(); + + EXPECT_EQ(expired.lifecycle, "not_live"); + EXPECT_EQ(expired.reason, "lease_expired"); + EXPECT_GE(static_cast(expired.since), before_s - 6) << "the deadline passed about 5 s ago"; + EXPECT_LE(static_cast(expired.since), after_s - 4); + EXPECT_TRUE(expired.detail.empty()) << "no renewal request failed, so there is no failure text: " << expired.detail; + EXPECT_EQ(pool->lifecycle(), PoolLifecycle::Live) << "the lifecycle enum is not touched"; + + pool->setMountDeadline(pool->bootMsNow() + 60'000); + const CasLifecycleSnapshot restored = storage->lifecycleSnapshot(); + EXPECT_EQ(restored.lifecycle, "live"); + EXPECT_TRUE(restored.reason.empty()) << restored.reason; + EXPECT_EQ(restored.since, 0); +} diff --git a/src/Disks/tests/gtest_cas_mount.cpp b/src/Disks/tests/gtest_cas_mount.cpp index a9472994237f..d94868ed661b 100644 --- a/src/Disks/tests/gtest_cas_mount.cpp +++ b/src/Disks/tests/gtest_cas_mount.cpp @@ -59,13 +59,13 @@ void renewOrThrow(MountLeaseRenewer & renewer) ASSERT_EQ(result.outcome, MountRenewOutcome::Committed); } -/// The two request planes a renewer in this file runs on, plus one operation for the protocol calls -/// driven directly. Both planes are open-fence: these fixtures hold no mount lease, so nothing here -/// should be refused by a fence it does not have. The clock and the sleep are ALWAYS injected -- a -/// fixture that drives a lease deadline passes its own so a slow machine cannot run the bound out -/// mid-test, and one that does not still must not sleep for real when a fault sends the engine round -/// again. `tests::OperationForTest` covers the one-operation case but neither the two planes nor the -/// clock, which is why this stays local. +/// The request planes a renewer in this file runs on, plus one operation for the protocol calls driven +/// directly. All planes are open-fence: these fixtures hold no mount lease, so nothing here should be +/// refused by a fence it does not have. The clock and the sleep are ALWAYS injected -- a fixture that +/// drives a lease deadline passes its own so a slow machine cannot run the bound out mid-test, and one +/// that does not still must not sleep for real when a fault sends the engine round again. +/// `tests::OperationForTest` covers the one-operation case but neither the planes nor the clock, which +/// is why this stays local. class Ops { public: @@ -73,11 +73,12 @@ class Ops Ops(std::shared_ptr backend, uint64_t * boot_ms) : mount(openRequestsForTest(backend)) - , farewell(openRequestsForTest(std::move(backend))) + , farewell(openRequestsForTest(backend)) + , lease(openRequestsForTest(std::move(backend))) , op(mount.admit()) { uint64_t * clock = boot_ms ? boot_ms : &own_clock; - for (CasRequests * requests : {&mount, &farewell}) + for (CasRequests * requests : {&mount, &farewell, &lease}) { requests->setNowFnForTest([clock] { return *clock; }); requests->setSleepFnForTest([clock](uint64_t ms) { *clock += ms; }); @@ -89,6 +90,7 @@ class Ops CasRequests mount; CasRequests farewell; + CasRequests lease; CasOperation op; private: @@ -360,7 +362,10 @@ TEST(CASMountAudit, RenewalDefaultLogsAreBounded) ScopedRenewalLogCapture capture("debug"); backend->throw_before_next_overwrite = true; EXPECT_NO_THROW(store->renewWatermarkOnce()); - EXPECT_EQ(countRenewalLogText(capture.captured(), "physical retry attempt 2"), 1u); + const String output = capture.captured(); + EXPECT_GE(countRenewalLogText(output, "recovered"), 1u) << "the capture sees the renewal at all: " << output; + EXPECT_EQ(countRenewalLogText(output, "physical retry attempt"), 0u) + << "requests are counted by the attempt counters, not replayed as log lines when the renewal ends: " << output; } { @@ -723,7 +728,7 @@ TEST(CASMountLease, AbsentClaimThenRenewBumpsSeq) Ops ops(b, &boot); auto r = claimMount(ops.op, l, "r", UInt128(1), /*epoch*/ 7, now, /*ttl*/ 100); EXPECT_EQ(r.kind, MountClaimResult::Claimed); - MountLeaseRenewer k(ops.mount, ops.farewell, l, "r", UInt128(1), 7, std::chrono::milliseconds(100), + MountLeaseRenewer k(ops.mount, ops.farewell, ops.lease, l, "r", UInt128(1), 7, std::chrono::milliseconds(100), [&] { return now; }, [] { return uint64_t{0}; }, {}, std::chrono::milliseconds(0), [&] { return boot; }); k.start(); @@ -743,7 +748,7 @@ TEST(CASMountLease, HolderBodiesMintFreshAttemptIdsAndFenceCopiesIt) const String key = layout.mountKey("r"); const MountLease claimed = decodeMountLease(ops.op.read(key, Retry::standard())->bytes); - MountLeaseRenewer renewer(ops.mount, ops.farewell, layout, "r", UInt128{1}, 7, std::chrono::milliseconds(100), + MountLeaseRenewer renewer(ops.mount, ops.farewell, ops.lease, layout, "r", UInt128{1}, 7, std::chrono::milliseconds(100), [&] { return now; }, [] { return uint64_t{0}; }, {}, std::chrono::milliseconds(0), [&] { return boot; }); renewer.start(); @@ -799,7 +804,7 @@ TEST(CASMountLease, VanishedBackingStoreStopsRenewalWithoutLogicalError) uint64_t boot = 0; Ops ops(b, &boot); ASSERT_EQ(claimMount(ops.op, l, "r", UInt128(1), /*epoch*/ 7, now, /*ttl*/ 100).kind, MountClaimResult::Claimed); - MountLeaseRenewer k(ops.mount, ops.farewell, l, "r", UInt128(1), 7, std::chrono::milliseconds(100), + MountLeaseRenewer k(ops.mount, ops.farewell, ops.lease, l, "r", UInt128(1), 7, std::chrono::milliseconds(100), [&] { return now; }, [] { return uint64_t{0}; }, {}, std::chrono::milliseconds(0), [&] { return boot; }); k.start(); @@ -842,7 +847,7 @@ TEST(CASMountLease, TerminateAfterVanishedBackingStoreIsNoOpRelease) uint64_t now = 1000; Ops ops(b); ASSERT_EQ(claimMount(ops.op, l, "r", UInt128(1), /*epoch*/ 7, now, /*ttl*/ 100).kind, MountClaimResult::Claimed); - MountLeaseRenewer k(ops.mount, ops.farewell, l, "r", UInt128(1), 7, std::chrono::milliseconds(100), + MountLeaseRenewer k(ops.mount, ops.farewell, ops.lease, l, "r", UInt128(1), 7, std::chrono::milliseconds(100), [&] { return now; }, [] { return uint64_t{0}; }); k.start(); @@ -1154,7 +1159,7 @@ TEST(CASMountLease, RenewerStartAdoptsOurOwnClaimNotDoubleStart) Ops ops(b); // The normal flow: claimMount writes the live mount under (uuid=1, epoch=7), THEN renewer.start(). ASSERT_EQ(claimMount(ops.op, l, "r", UInt128(1), /*epoch*/ 7, now, /*ttl*/ 100).kind, MountClaimResult::Claimed); - MountLeaseRenewer k(ops.mount, ops.farewell, l, "r", UInt128(1), /*epoch*/ 7, std::chrono::milliseconds(100), + MountLeaseRenewer k(ops.mount, ops.farewell, ops.lease, l, "r", UInt128(1), /*epoch*/ 7, std::chrono::milliseconds(100), [&] { return now; }, [] { return uint64_t{0}; }); EXPECT_NO_THROW(k.start()); // adopts our own live (uuid=1,epoch=7) mount — NOT a double-start EXPECT_EQ(decodeMountLease(ops.op.read(l.mountKey("r"), Retry::standard())->bytes).writer_epoch, 7u); @@ -1501,7 +1506,7 @@ namespace /// Rev.6 §token-stability observation removed the wall clock from the fence DECISION; `kNowMs` below /// is threaded through only as `computeHeartbeatFloor`'s audit-only `now_ms`. constexpr uint64_t kNowMs = 1'000'000; -/// The fence-out threshold measured on the LEADER's OWN monotonic clock (`mono_now_ms`), independent +/// The fence-out threshold measured on the LEADER's OWN monotonic clock (`mono_ms_fn`), independent /// of any lease's stamped `expires_at_ms`. constexpr uint64_t kStableThresholdMs = 10'000; @@ -1539,6 +1544,168 @@ void renewMount(CasOperation & op, const Layout & l, const String & srid) mustCommit(op.replace(l.mountKey(srid), encodeMountLease(m), got->etag, Retry::standard()), "renewed mount " + srid); } + +/// An observer clock that does not move during a call: a sighting and the round start read the same value. +std::function frozenClock(uint64_t ms) +{ + return [ms] { return ms; }; +} + +/// Moves the observer clock on every read of a mount slot, so a round spends time between its first +/// clock sample and the read it decides on. With `renew_before_next_fence` set, the holder renews once +/// just before the next guarded write of a mount slot lands, so a fence-out is refused and decided +/// again on the holder's new token. +class SightingClockBackend : public InMemoryBackend +{ +public: + explicit SightingClockBackend(uint64_t & mono_) : mono(mono_) {} + + uint64_t read_cost_ms = 0; + bool renew_before_next_fence = false; + + std::optional read(const String & key, TransportAccess & access) override + { + if (key.ends_with("/mount")) + mono += read_cost_ms; + return InMemoryBackend::read(key, access); + } + + std::expected write(const String & key, const String & bytes, + const std::optional & expected_value, + TransportAccess & access) override + { + if (renew_before_next_fence && expected_value && key.ends_with("/mount")) + { + renew_before_next_fence = false; + const auto got = InMemoryBackend::read(key, access); + MountLease m = decodeMountLease(got->bytes); + m.seq += 1; + EXPECT_TRUE(InMemoryBackend::write(key, encodeMountLease(m), got->value, access).has_value()); + } + return InMemoryBackend::write(key, bytes, expected_value, access); + } + +private: + uint64_t & mono; +}; + +constexpr uint64_t kWalkMs = 4'000; + +void firstDecisionCountsFromAfterTheRead() +{ + uint64_t mono = 0; + auto b = std::make_shared(mono); + Layout l("p"); + Ops ops(b); + seedMount(ops.op, l, "s1", /*expires*/ 10, /*fenced*/ false, /*min_active_build_sequence*/ 0); + const auto clock = [&mono] { return mono; }; + MountObservationMap obs; + + /// The round starts at 0 and reaches the slot at `kWalkMs`. + b->read_cost_ms = kWalkMs; + ASSERT_EQ(computeHeartbeatFloor(ops.op, l, kNowMs, clock, kStableThresholdMs, obs).fenced_now, 0u); + ASSERT_TRUE(obs.contains("s1")); + EXPECT_EQ(obs.at("s1").first_seen_mono_ms, kWalkMs); + + /// One threshold after the first round started, less than one after its read. + b->read_cost_ms = 0; + mono = kStableThresholdMs; + const HeartbeatFloor early = computeHeartbeatFloor(ops.op, l, kNowMs, clock, kStableThresholdMs, obs); + ASSERT_EQ(early.fenced_now, 0u) << "fenced a token watched for less than the threshold"; + EXPECT_EQ(early.live, 1u); + + mono = kWalkMs + kStableThresholdMs; + EXPECT_EQ(computeHeartbeatFloor(ops.op, l, kNowMs, clock, kStableThresholdMs, obs).fenced_now, 1u); +} + +void reDecisionCountsFromAfterItsRead() +{ + uint64_t mono = 0; + auto b = std::make_shared(mono); + Layout l("p"); + Ops ops(b); + seedMount(ops.op, l, "s1", /*expires*/ 10, /*fenced*/ false, /*min_active_build_sequence*/ 0); + const auto clock = [&mono] { return mono; }; + MountObservationMap obs; + + computeHeartbeatFloor(ops.op, l, kNowMs, clock, kStableThresholdMs, obs); + ASSERT_TRUE(obs.contains("s1")); + const Etag first = obs.at("s1").token; + + /// Stable at this round's start, so it tries the fence-out. The holder renews first, the write is + /// refused, and the round decides again on the new token after reading it. + mono = kStableThresholdMs; + b->read_cost_ms = kWalkMs; + b->renew_before_next_fence = true; + const HeartbeatFloor refused = computeHeartbeatFloor(ops.op, l, kNowMs, clock, kStableThresholdMs, obs); + ASSERT_FALSE(b->renew_before_next_fence) << "the round never attempted the fence-out"; + ASSERT_EQ(refused.fenced_now, 0u); + ASSERT_EQ(refused.live, 1u); + ASSERT_NE(obs.at("s1").token, first); + + /// Nothing reads after the re-decision, so the clock still holds the value of its last read. + const uint64_t reread_at = mono; + ASSERT_GT(reread_at, kStableThresholdMs); + EXPECT_EQ(obs.at("s1").first_seen_mono_ms, reread_at); + + /// One threshold after that round started, less than one after its re-read. + b->read_cost_ms = 0; + mono = kStableThresholdMs + kStableThresholdMs; + ASSERT_EQ(computeHeartbeatFloor(ops.op, l, kNowMs, clock, kStableThresholdMs, obs).fenced_now, 0u) + << "fenced the renewed token before it was watched for the threshold"; + + mono = reread_at + kStableThresholdMs; + EXPECT_EQ(computeHeartbeatFloor(ops.op, l, kNowMs, clock, kStableThresholdMs, obs).fenced_now, 1u); +} + +void slowWalkDoesNotMoveTheStabilitySample() +{ + uint64_t mono = 0; + auto b = std::make_shared(mono); + Layout l("p"); + Ops ops(b); + seedMount(ops.op, l, "s1", /*expires*/ 10, /*fenced*/ false, /*min_active_build_sequence*/ 0); + const auto clock = [&mono] { return mono; }; + MountObservationMap obs; + + computeHeartbeatFloor(ops.op, l, kNowMs, clock, kStableThresholdMs, obs); + ASSERT_EQ(obs.at("s1").first_seen_mono_ms, 0u); + + /// The round starts one millisecond short of the threshold; its walk passes the threshold many times. + mono = kStableThresholdMs - 1; + b->read_cost_ms = 10 * kStableThresholdMs; + const HeartbeatFloor slow = computeHeartbeatFloor(ops.op, l, kNowMs, clock, kStableThresholdMs, obs); + EXPECT_EQ(slow.fenced_now, 0u); + EXPECT_EQ(slow.live, 1u); + EXPECT_EQ(obs.at("s1").first_seen_mono_ms, 0u) << "an unchanged token keeps its first sighting"; +} +} + +TEST(CASTokenWatch, CountsFromAfterTheRead) +{ + auto b = std::make_shared(); + Ops ops(b); + const Etag t1 = std::get(ops.op.create("k", "v1", Retry::standard())).etag; + const Etag t2 = std::get(ops.op.replace("k", "v2", t1, Retry::standard())).etag; + constexpr uint64_t threshold_ms = 10'000; + + /// The read that returned `t1` ended at 5000: the watch counts from there. + const TokenWatch watch = TokenWatch::sighted(t1, /*sample_after_read_ms=*/ 5'000); + EXPECT_EQ(watch.token, t1); + EXPECT_EQ(watch.first_seen_mono_ms, 5'000u); + + EXPECT_FALSE(watch.stableFor(threshold_ms, 14'999)); + EXPECT_TRUE(watch.stableFor(threshold_ms, 15'000)); + + /// A sample older than the sighting proves nothing about how long the token held. + EXPECT_FALSE(watch.stableFor(threshold_ms, 4'000)); + EXPECT_FALSE(watch.stableFor(0, 4'000)); + + /// A changed token is a new watch, counted from its own read. + const TokenWatch renewed = TokenWatch::sighted(t2, 15'000); + EXPECT_NE(renewed.token, watch.token); + EXPECT_FALSE(renewed.stableFor(threshold_ms, 15'000)); + EXPECT_TRUE(renewed.stableFor(threshold_ms, 25'000)); } TEST(CASHeartbeatFloor, FirstSightNeverFencesEvenIfStampLooksExpired) @@ -1552,7 +1719,7 @@ TEST(CASHeartbeatFloor, FirstSightNeverFencesEvenIfStampLooksExpired) seedMount(ops.op, l, "s1", /*expires*/ 10, /*fenced*/ false, /*min_active_build_sequence*/ 0); MountObservationMap obs; - const HeartbeatFloor floor = computeHeartbeatFloor(ops.op, l, /*now_ms*/ kNowMs, /*mono_now_ms*/ 0, + const HeartbeatFloor floor = computeHeartbeatFloor(ops.op, l, /*now_ms*/ kNowMs, frozenClock(0), kStableThresholdMs, obs); EXPECT_EQ(floor.fenced_now, 0u); @@ -1569,14 +1736,14 @@ TEST(CASHeartbeatFloor, StableIncarnationPastThresholdIsFenced) seedMount(ops.op, l, "s1", /*expires*/ 10, /*fenced*/ false, /*min_active_build_sequence*/ 0); MountObservationMap obs; - const HeartbeatFloor floor_before = computeHeartbeatFloor(ops.op, l, kNowMs, /*mono*/ 0, kStableThresholdMs, obs); + const HeartbeatFloor floor_before = computeHeartbeatFloor(ops.op, l, kNowMs, frozenClock(0), kStableThresholdMs, obs); EXPECT_EQ(floor_before.fenced_now, 0u); const MountLease before = decodeMountLease(ops.op.read(l.mountKey("s1"), Retry::standard())->bytes); /// No renewal in between: the SAME incarnation, observed since mono 0, is now stable for the full /// threshold on the leader's own clock. - const HeartbeatFloor floor2 = computeHeartbeatFloor(ops.op, l, kNowMs, /*mono*/ kStableThresholdMs, + const HeartbeatFloor floor2 = computeHeartbeatFloor(ops.op, l, kNowMs, frozenClock(kStableThresholdMs), kStableThresholdMs, obs); EXPECT_EQ(floor2.fenced_now, 1u); @@ -1594,20 +1761,20 @@ TEST(CASHeartbeatFloor, RenewalBetweenRoundsRestartsObservation) seedMount(ops.op, l, "s1", /*expires*/ 10, /*fenced*/ false, /*min_active_build_sequence*/ 0); MountObservationMap obs; - computeHeartbeatFloor(ops.op, l, kNowMs, /*mono*/ 0, kStableThresholdMs, obs); + computeHeartbeatFloor(ops.op, l, kNowMs, frozenClock(0), kStableThresholdMs, obs); ASSERT_TRUE(obs.contains("s1")); - const Etag first_etag = obs.at("s1").etag; + const Etag first_etag = obs.at("s1").token; renewMount(ops.op, l, "s1"); const Etag renewed_etag = currentEtag(ops.op, l.mountKey("s1")); EXPECT_NE(renewed_etag, first_etag); - const HeartbeatFloor floor2 = computeHeartbeatFloor(ops.op, l, kNowMs, /*mono*/ kStableThresholdMs, + const HeartbeatFloor floor2 = computeHeartbeatFloor(ops.op, l, kNowMs, frozenClock(kStableThresholdMs), kStableThresholdMs, obs); EXPECT_EQ(floor2.fenced_now, 0u); ASSERT_TRUE(obs.contains("s1")); - EXPECT_EQ(obs.at("s1").etag, renewed_etag); + EXPECT_EQ(obs.at("s1").token, renewed_etag); EXPECT_EQ(obs.at("s1").first_seen_mono_ms, kStableThresholdMs); } @@ -1625,7 +1792,7 @@ TEST(CASHeartbeatFloor, UnseenSridPrunedFromObservationMap) seedMount(ops.op, l, "s2", /*expires*/ 10, /*fenced*/ false, /*min_active_build_sequence*/ 0); MountObservationMap obs; - computeHeartbeatFloor(ops.op, l, kNowMs, /*mono*/ 0, kStableThresholdMs, obs); + computeHeartbeatFloor(ops.op, l, kNowMs, frozenClock(0), kStableThresholdMs, obs); ASSERT_TRUE(obs.contains("s1")); ASSERT_TRUE(obs.contains("s2")); @@ -1637,7 +1804,7 @@ TEST(CASHeartbeatFloor, UnseenSridPrunedFromObservationMap) renewMount(ops.op, l, "s1"); ASSERT_EQ(ops.op.removeCurrent(l.mountKey("s2"), Retry::standard()), Removal::Removed); - computeHeartbeatFloor(ops.op, l, kNowMs, /*mono*/ kStableThresholdMs, kStableThresholdMs, obs); + computeHeartbeatFloor(ops.op, l, kNowMs, frozenClock(kStableThresholdMs), kStableThresholdMs, obs); EXPECT_TRUE(obs.contains("s1")); EXPECT_FALSE(obs.contains("s2")) << "a srid removed from the LIST entirely must be pruned from obs, not linger forever"; @@ -1664,7 +1831,7 @@ TEST(CASHeartbeatFloor, ClassifiesAndFencesOut) MountObservationMap obs; /// Round 1 (mono 0): first sight of every non-terminal mount — nothing is fence-eligible yet. - const HeartbeatFloor floor_before = computeHeartbeatFloor(ops.op, l, kNowMs, /*mono*/ 0, kStableThresholdMs, obs); + const HeartbeatFloor floor_before = computeHeartbeatFloor(ops.op, l, kNowMs, frozenClock(0), kStableThresholdMs, obs); EXPECT_EQ(floor_before.live, 3u); // s1, s2, s3: observation just started EXPECT_EQ(floor_before.terminated, 1u); // s5 EXPECT_EQ(floor_before.fenced_now, 0u); @@ -1681,7 +1848,7 @@ TEST(CASHeartbeatFloor, ClassifiesAndFencesOut) /// Round 2 (mono == threshold): s1/s2's renewed incarnations restart their observation (still /// live); s3's original incarnation has now held stable for the full threshold -> fenced. - const HeartbeatFloor floor2 = computeHeartbeatFloor(ops.op, l, kNowMs, /*mono*/ kStableThresholdMs, + const HeartbeatFloor floor2 = computeHeartbeatFloor(ops.op, l, kNowMs, frozenClock(kStableThresholdMs), kStableThresholdMs, obs); EXPECT_EQ(floor2.live, 2u); // s1, s2: renewed, observation restarted @@ -1759,14 +1926,14 @@ TEST(CASHeartbeatFloor, FenceOutLosesTheIncarnationRaceAndReclassifiesLive) MountObservationMap obs; /// Round 1: first sight, observation starts — never reaches the fence-out path (the race /// decorator stays armed for round 2). - const HeartbeatFloor floor_before = computeHeartbeatFloor(ops.op, l, kNowMs, /*mono*/ 0, kStableThresholdMs, obs); + const HeartbeatFloor floor_before = computeHeartbeatFloor(ops.op, l, kNowMs, frozenClock(0), kStableThresholdMs, obs); EXPECT_EQ(floor_before.fenced_now, 0u); /// Round 2: the incarnation has been stable past threshold, so the function attempts the /// fence-out. The decorator renews concurrently under the real incarnation, the write is refused, /// and the re-decision reclassifies the slot as live (observation restarted on the new /// incarnation) — never fenced. - const HeartbeatFloor floor2 = computeHeartbeatFloor(ops.op, l, kNowMs, /*mono*/ kStableThresholdMs, + const HeartbeatFloor floor2 = computeHeartbeatFloor(ops.op, l, kNowMs, frozenClock(kStableThresholdMs), kStableThresholdMs, obs); EXPECT_EQ(floor2.fenced_now, 0u); @@ -1777,6 +1944,22 @@ TEST(CASHeartbeatFloor, FenceOutLosesTheIncarnationRaceAndReclassifiesLive) EXPECT_FALSE(decodeMountLease(after->bytes).gc_fenced); } +TEST(CASHeartbeat, GcCountsASightingFromAfterItsRead) +{ + { + SCOPED_TRACE("first decision"); + firstDecisionCountsFromAfterTheRead(); + } + { + SCOPED_TRACE("re-decision after a refused fence-out"); + reDecisionCountsFromAfterItsRead(); + } + { + SCOPED_TRACE("slow walk"); + slowWalkDoesNotMoveTheStabilitySample(); + } +} + TEST(CASHeartbeatFloor, EmptyPrefixYieldsNoLiveMounts) { auto b = std::make_shared(); @@ -1784,7 +1967,7 @@ TEST(CASHeartbeatFloor, EmptyPrefixYieldsNoLiveMounts) Ops ops(b); MountObservationMap obs; - const HeartbeatFloor floor = computeHeartbeatFloor(ops.op, l, kNowMs, /*mono*/ 0, kStableThresholdMs, obs); + const HeartbeatFloor floor = computeHeartbeatFloor(ops.op, l, kNowMs, frozenClock(0), kStableThresholdMs, obs); EXPECT_EQ(floor.live, 0u); EXPECT_EQ(floor.terminated, 0u); @@ -1938,7 +2121,7 @@ TEST(CASMountObservation, RenewalDuringObservationRestartsIt) /// wrote (no seq bump, per the ADOPT RULE), then a synchronous renewal mints a new incarnation /// mid-observation. uint64_t renewer_wall = 500; - MountLeaseRenewer renewer(ops.mount, ops.farewell, l, "r", UInt128(1), 7, std::chrono::milliseconds(500), + MountLeaseRenewer renewer(ops.mount, ops.farewell, ops.lease, l, "r", UInt128(1), 7, std::chrono::milliseconds(500), [&] { return renewer_wall; }, [] { return uint64_t{0}; }, {}, std::chrono::milliseconds(0), [&] { return renewer_boot; }); renewer.start(); @@ -2127,7 +2310,7 @@ TEST(CASMountLease, ClaimAdoptIsTwoRequests) /// The absent-slot mint. backend->reads = backend->heads = backend->writes = 0; - MountLeaseRenewer minting(ops.mount, ops.farewell, l, "fresh", UInt128(1), 7, + MountLeaseRenewer minting(ops.mount, ops.farewell, ops.lease, l, "fresh", UInt128(1), 7, std::chrono::milliseconds(100), [&] { return now; }, [] { return uint64_t{0}; }); minting.start(); EXPECT_EQ(backend->reads, 1u); @@ -2138,7 +2321,7 @@ TEST(CASMountLease, ClaimAdoptIsTwoRequests) ASSERT_EQ(claimMount(ops.op, l, "adopted", UInt128(1), /*epoch*/ 7, now, /*ttl*/ 100).kind, MountClaimResult::Claimed); backend->reads = backend->heads = backend->writes = 0; - MountLeaseRenewer adopting(ops.mount, ops.farewell, l, "adopted", UInt128(1), 7, + MountLeaseRenewer adopting(ops.mount, ops.farewell, ops.lease, l, "adopted", UInt128(1), 7, std::chrono::milliseconds(100), [&] { return now; }, [] { return uint64_t{0}; }); adopting.start(); EXPECT_EQ(backend->reads, 1u); @@ -2177,10 +2360,10 @@ TEST(CASMountLease, FarewellRunsOnAnOpenFenceAfterTheMountFenceIsLost) ASSERT_EQ(claimMount(seed, l, "renewing", UInt128(1), 7, now, /*ttl*/ 1000).kind, MountClaimResult::Claimed); ASSERT_EQ(claimMount(seed, l, "departing", UInt128(1), 7, now, /*ttl*/ 1000).kind, MountClaimResult::Claimed); - MountLeaseRenewer renewing(mount_requests, open_requests, l, "renewing", UInt128(1), 7, + MountLeaseRenewer renewing(mount_requests, open_requests, open_requests, l, "renewing", UInt128(1), 7, std::chrono::milliseconds(1000), [&] { return now; }, [] { return uint64_t{0}; }, {}, std::chrono::milliseconds(0), [&] { return boot; }); - MountLeaseRenewer departing(mount_requests, open_requests, l, "departing", UInt128(1), 7, + MountLeaseRenewer departing(mount_requests, open_requests, open_requests, l, "departing", UInt128(1), 7, std::chrono::milliseconds(1000), [&] { return now; }, [] { return uint64_t{0}; }, {}, std::chrono::milliseconds(0), [&] { return boot; }); renewing.start(); @@ -2218,7 +2401,7 @@ TEST(CASMountLease, ClaimIsNotAdmittedUnderTheMountFence) open_requests.setNowFnForTest([&boot] { return boot; }); open_requests.setSleepFnForTest([&boot](uint64_t ms) { boot += ms; }); - MountLeaseRenewer renewer(mount_requests, open_requests, l, "r", UInt128(1), 7, + MountLeaseRenewer renewer(mount_requests, open_requests, open_requests, l, "r", UInt128(1), 7, std::chrono::milliseconds(1000), [&] { return now; }, [] { return uint64_t{0}; }, {}, std::chrono::milliseconds(0), [&] { return boot; }); EXPECT_NO_THROW(renewer.start()); @@ -2278,7 +2461,7 @@ TEST(CASMountLease, RemountRenewalIsAdmittedOffTheMountFence) open_requests.setNowFnForTest([&boot] { return boot; }); open_requests.setSleepFnForTest([&boot](uint64_t ms) { boot += ms; }); - MountLeaseRenewer renewer(mount_requests, open_requests, l, "r", UInt128(1), 7, + MountLeaseRenewer renewer(mount_requests, open_requests, open_requests, l, "r", UInt128(1), 7, std::chrono::milliseconds(1000), [&] { return now; }, [] { return uint64_t{0}; }, {}, std::chrono::milliseconds(0), [&] { return boot; }); renewer.start(); diff --git a/src/Disks/tests/gtest_cas_mount_claim_conflicts.cpp b/src/Disks/tests/gtest_cas_mount_claim_conflicts.cpp index 6eb8f9c9b7b8..f7c974073a49 100644 --- a/src/Disks/tests/gtest_cas_mount_claim_conflicts.cpp +++ b/src/Disks/tests/gtest_cas_mount_claim_conflicts.cpp @@ -15,7 +15,7 @@ using DB::Cas::tests::OperationForTest; namespace { -/// One renewer for the mount slot of server-root "r", under (uuid=1, epoch=7) unless overridden. Both +/// One renewer for the mount slot of server-root "r", under (uuid=1, epoch=7) unless overridden. All /// of its planes are the same open-fence one: what these tests exercise is the mount protocol's own /// exclusivity, not a fence's, and no test here renews, which is the only caller of the mount plane. MountLeaseRenewer makeRenewer( @@ -25,6 +25,7 @@ MountLeaseRenewer makeRenewer( uint64_t epoch = 7) { return MountLeaseRenewer( + requests, requests, requests, Layout("p"), diff --git a/src/Disks/tests/gtest_cas_mount_runtime.cpp b/src/Disks/tests/gtest_cas_mount_runtime.cpp index 0294fa178a35..7a2ccbbd8830 100644 --- a/src/Disks/tests/gtest_cas_mount_runtime.cpp +++ b/src/Disks/tests/gtest_cas_mount_runtime.cpp @@ -4,10 +4,17 @@ #include #include #include +#include +#include #include #include +namespace DB::ErrorCodes +{ +extern const int NETWORK_ERROR; +} + using namespace DB::Cas; namespace @@ -26,8 +33,9 @@ class RuntimeFixture [this](uint64_t g, uint64_t needed) { return runtime.admit(g, needed); }, [this](uint64_t g) { runtime.checkFenceOrThrow(g); }}) , farewell(backend, Fence::open()) + , lease(backend, Fence::open()) , runtime( - backend, mount, farewell, layout, + backend, mount, farewell, lease, layout, MountConfig{.boot_ms_fn = [this] { return boot_ms; }}, "test", sink, CasRequestBudget{.attempt_timeout_ms = attempt_timeout_ms, @@ -47,6 +55,7 @@ class RuntimeFixture CasEventSink sink; CasRequests mount; CasRequests farewell; + CasRequests lease; CasMountRuntime runtime; }; @@ -62,6 +71,22 @@ const char * admitName(Fence::Admit verdict) return "unknown"; } +/// The message of the refusal `refuse` throws; a failure when it does not throw the transient class. +String refusalText(const std::function & refuse) +{ + try + { + refuse(); + } + catch (const DB::Exception & e) + { + EXPECT_EQ(e.code(), DB::ErrorCodes::NETWORK_ERROR) << e.message(); + return e.message(); + } + ADD_FAILURE() << "the fence check did not refuse"; + return {}; +} + constexpr DB::UInt128 kUuid{7}; } @@ -174,3 +199,54 @@ TEST(CASMountRuntime, RefAppendFenceOkIsAdmitAtTwoEnvelopesWithANonzeroCap) EXPECT_FALSE(f->refAppendFenceOk()); EXPECT_STREQ(admitName(f->admit(f->fenceGeneration(), 400)), "NoBudget"); } + +/// An expiry is this server's own confirmed deadline passing while nothing else is wrong. A lost fence or +/// a lifecycle that left `Live` is a different state and reports as itself. +TEST(CASMountRuntime, LeaseExpiredOnlyWhileLiveAndNotLost) +{ + RuntimeFixture f(/*lease_safety_margin_ms=*/0); + f.boot_ms = 1'000; + EXPECT_FALSE(f->leaseExpiredSinceBootMs().has_value()) << "an unarmed fence has no deadline to pass"; + + f->armMountFence(kUuid, 1, /*deadline_boot_ms=*/1'100); + f.boot_ms = 1'099; + EXPECT_FALSE(f->leaseExpiredSinceBootMs().has_value()); + f.boot_ms = 1'100; + ASSERT_TRUE(f->leaseExpiredSinceBootMs().has_value()) << "the deadline instant is already past, as `admit` reads it"; + EXPECT_EQ(*f->leaseExpiredSinceBootMs(), 1'100u); + EXPECT_TRUE(f->lastRenewFailure().empty()) << "no renewal request has failed"; + + f->setLifecycleForTest(PoolLifecycle::IdentityLost); + EXPECT_FALSE(f->leaseExpiredSinceBootMs().has_value()) << "only a `Live` pool reports an expiry"; + f->setLifecycleForTest(PoolLifecycle::Live); + ASSERT_TRUE(f->leaseExpiredSinceBootMs().has_value()); + + f->tripMountLost(); + EXPECT_FALSE(f->leaseExpiredSinceBootMs().has_value()) << "a lost fence is a lease loss, not an expiry"; +} + +/// Only a refusal caused by the expiry itself names it: an operator can wait for a renewal then, and for +/// nothing else. +TEST(CASMountRuntime, ExpiredLeaseRefusalSaysWritesResume) +{ + RuntimeFixture f(/*lease_safety_margin_ms=*/0); + f.boot_ms = 1'000; + f->armMountFence(kUuid, 1, /*deadline_boot_ms=*/1'100); + const uint64_t generation = f->fenceGeneration(); + f.boot_ms = 1'100; + + const String expired = refusalText([&] { f->checkFenceOrThrow(generation); }); + EXPECT_NE(expired.find("lease expired"), String::npos) << expired; + EXPECT_NE(expired.find("writes resume when a renewal succeeds"), String::npos) << expired; + + /// A re-arm moves the generation while the lease stays expired: the caller's incarnation is gone. + f->armMountFence(kUuid, 1, /*deadline_boot_ms=*/1'100); + const String moved = refusalText([&] { f->checkFenceOrThrow(generation); }); + EXPECT_EQ(moved.find("lease expired"), String::npos) << moved; + EXPECT_NE(moved.find("mount fence tripped"), String::npos) << moved; + + f->tripMountLost(); + const String lost = refusalText([&] { f->checkFenceOrThrow(f->fenceGeneration()); }); + EXPECT_EQ(lost.find("lease expired"), String::npos) << lost; + EXPECT_NE(lost.find("mount fence tripped"), String::npos) << lost; +} diff --git a/src/Disks/tests/gtest_cas_pool.cpp b/src/Disks/tests/gtest_cas_pool.cpp index 452511f5f761..528f6653c7ad 100644 --- a/src/Disks/tests/gtest_cas_pool.cpp +++ b/src/Disks/tests/gtest_cas_pool.cpp @@ -10,6 +10,10 @@ #include #include #include +#include +#include +#include +#include #include #include #include @@ -37,6 +41,7 @@ extern const int UNKNOWN_FORMAT_VERSION; extern const int FILE_DOESNT_EXIST; extern const int UNKNOWN_EXCEPTION; extern const int NETWORK_ERROR; +extern const int MEMORY_LIMIT_EXCEEDED; } namespace ProfileEvents @@ -48,6 +53,9 @@ extern const Event CASMountReleaseSkippedForeignOccupant; extern const Event CASRemountAttempts; extern const Event CASRemountSucceeded; extern const Event CASRemountFailed; +extern const Event CASMountLeaseExpired; +extern const Event CASMountRenewalAttempts; +extern const Event CASMountRenewalRetries; } using namespace DB::Cas; @@ -2004,6 +2012,7 @@ class RuntimeRenewBackend final : public DB::Cas::tests::CountingBackend LandThenThrow, BlockThenDelegate, BlockThenThrow, + ThrowMemoryLimitExceeded, }; Fault fault = Fault::None; @@ -2014,6 +2023,12 @@ class RuntimeRenewBackend final : public DB::Cas::tests::CountingBackend /// rather than reissued has to move the injected clock here -- from inside the attempt, which is the /// only point between admission and the resolve read a test can reach. std::function before_throw; + /// While it answers TRUE, every conditional write throws a transport timeout, before `fault` is + /// consulted. Read on the renewing thread; set it before the workers start. + std::function outage; + /// Runs on every write `outage` fails, before it throws. + std::function on_outage_write; + std::atomic outage_writes{0}; /// The fault sits on the WRITE PRIMITIVE, and only on a CONDITIONAL one: a lease renewal is a /// replace, so a create on the same key must not consume the one-shot fault. @@ -2022,6 +2037,13 @@ class RuntimeRenewBackend final : public DB::Cas::tests::CountingBackend { if (!expected_value) return DB::Cas::tests::CountingBackend::write(key, bytes, expected_value, access); + if (outage && outage()) + { + outage_writes.fetch_add(1, std::memory_order_relaxed); + if (on_outage_write) + on_outage_write(); + throw Poco::TimeoutException("injected runtime renewal outage"); + } const Fault current = std::exchange(fault, Fault::None); if (current == Fault::BlockThenDelegate || current == Fault::BlockThenThrow) { @@ -2029,6 +2051,8 @@ class RuntimeRenewBackend final : public DB::Cas::tests::CountingBackend throw DB::Exception(DB::ErrorCodes::CORRUPTED_DATA, "runtime renewal barrier is absent"); barrier->arriveAndWait(); } + if (current == Fault::ThrowMemoryLimitExceeded) + throw DB::Exception(DB::ErrorCodes::MEMORY_LIMIT_EXCEEDED, "injected memory limit exceeded on the renewal request"); if (current == Fault::ThrowBefore || current == Fault::BlockThenThrow) { if (before_throw) @@ -2047,7 +2071,7 @@ class RuntimeRenewBackend final : public DB::Cas::tests::CountingBackend CasRequestBudget runtimeRenewBudget(); -/// A directly-constructed `CasMountRuntime` plus the two request planes it needs. `Pool` builds those +/// A directly-constructed `CasMountRuntime` plus the request planes it needs. `Pool` builds those /// from its own members; a test has no `Pool`, so the mount plane's fence reaches the runtime through /// this holder -- the closures run only once the runtime is issuing requests, well after construction. class RuntimeUnderTest @@ -2060,7 +2084,8 @@ class RuntimeUnderTest [this](uint64_t g, uint64_t needed) { return runtime.admit(g, needed); }, [this](uint64_t g) { runtime.checkFenceOrThrow(g); }}) , farewell(backend, DB::Cas::Fence::open()) - , runtime(backend, mount, farewell, std::forward(args)...) + , lease(backend, DB::Cas::Fence::open()) + , runtime(backend, mount, farewell, lease, std::forward(args)...) { /// What the request engine reserves per attempt is the BACKEND's attempt timeout, not the /// budget field alone; every construction of this holder pairs the two via `runtimeRenewBudget`, @@ -2072,6 +2097,9 @@ class RuntimeUnderTest /// deadline against real boottime, finds it long past, and refuses every request unsent. mount.setNowFnForTest([this] { return runtime.bootMsNow(); }); farewell.setNowFnForTest([this] { return runtime.bootMsNow(); }); + lease.setNowFnForTest([this] { return runtime.bootMsNow(); }); + /// As `Pool` wires it: a stop wakes the worker renewal's wait. + lease.setSleepFnForTest([this](uint64_t ms) { runtime.sleepInterruptibly(ms); }); } /// The workers are joined HERE, not only by the tests that assert on teardown: `CasMountRuntime` @@ -2091,9 +2119,19 @@ class RuntimeUnderTest CasMountRuntime & operator*() { return runtime; } + /// The retry wait of the mount and lease planes: the worker's renewal runs on the lease plane, the + /// other bounded ones on the mount plane. A remount renewal runs on the farewell plane, which this + /// does not reach. Call before the workers start. + void setRetrySleepForTest(const std::function & sleep_fn) + { + mount.setSleepFnForTest(sleep_fn); + lease.setSleepFnForTest(sleep_fn); + } + private: DB::Cas::CasRequests mount; DB::Cas::CasRequests farewell; + DB::Cas::CasRequests lease; CasMountRuntime runtime; }; @@ -3568,6 +3606,143 @@ TEST(CASPoolRemount, TeardownJoinsBothWorkersBeforeRelease) std::numeric_limits::max()); } +namespace +{ + +/// Above the 4 MiB a thread batches before it reaches the tracker, below the 16 MiB at which an +/// allocation over an ignored limit also sends a trace. +constexpr Int64 kOverLimitAllocationBytes = 8 * 1024 * 1024; + +struct OverLimitAllocation +{ + /// What the tracker threw; empty when it did not throw. + String failure; + /// How much the calling thread's tracker grew by the allocation. + Int64 counted = 0; +}; + +/// One accounted allocation made while the global tracker is over its hard limit. The limit is restored +/// before this returns, whatever the allocation did. The growth is read from the calling thread's own +/// tracker, so an allocation or free on another thread cannot disturb it. +OverLimitAllocation allocateOverTheGlobalLimit() +{ + DB::CurrentThread::flushUntrackedMemory(); + const Int64 saved_limit = total_memory_tracker.getHardLimit(); + SCOPE_EXIT({ total_memory_tracker.setHardLimit(saved_limit); }); + total_memory_tracker.setHardLimit(1); + + OverLimitAllocation result; + MemoryTracker * thread_tracker = DB::CurrentThread::getMemoryTracker(); + if (!thread_tracker) + { + result.failure = "the calling thread has no memory tracker"; + return result; + } + const Int64 before = thread_tracker->get(); + try + { + std::ignore = CurrentMemoryTracker::alloc(kOverLimitAllocationBytes); + } + catch (...) + { + result.failure = DB::getCurrentExceptionMessage(/*with_stacktrace=*/false); + return result; + } + result.counted = thread_tracker->get() - before; + std::ignore = CurrentMemoryTracker::free(kOverLimitAllocationBytes); + return result; +} + +} + +/// With the global tracker over its limit, an allocation on the lease thread before the request and +/// another while the result is consumed do not throw and are still counted; a memory-limit exception +/// raised inside the request is retried, does not trip the fence, and the thread goes on renewing. +TEST(CASMountRuntime, MemoryLimitDoesNotEndTheLeaseThread) +{ + auto backend = std::make_shared(); + const Layout layout("runtime-memory-limit"); + uint64_t wall_ms = 1000; + uint64_t boot_ms = 100; + const UInt128 uuid{1}; + ASSERT_EQ(claimMount(*DB::Cas::tests::OperationForTest(backend), layout, "test", uuid, 1, wall_ms, 1000).kind, MountClaimResult::Claimed); + const Int64 hard_limit_before = total_memory_tracker.getHardLimit(); + + std::atomic admissions{0}; + OverLimitAllocation before_request; + DB::Cas::tests::ManualBarrier second_admission; + + std::optional while_consumed; + String outcome; + String attempts_sent; + String classification; + DB::Cas::tests::ManualBarrier reported; + CasEventSink sink = [&](CasEvent event) + { + if (event.type != CasEventType::WatermarkRenew || while_consumed) + return; + while_consumed = allocateOverTheGlobalLimit(); + outcome = event.outcome; + attempts_sent = event.detail["attempts_sent"]; + classification = event.detail["classification"]; + reported.arriveAndWait(); + }; + + RuntimeUnderTest runtime_holder( + backend, layout, + MountConfig{ + .mount_lease_ttl_ms = std::chrono::milliseconds(1000), + .background_watermark = true, + .boot_ms_fn = [&] { return boot_ms; }, + .renewal_admitted_hook_for_test = [&] + { + const uint32_t admission = ++admissions; + if (admission == 1) + before_request = allocateOverTheGlobalLimit(); + else if (admission == 2) + second_admission.arriveAndWait(); + }}, + "test", sink, runtimeRenewBudget(), [] { return false; }); + /// Declared after the runtime so it runs first: a failed expectation must not leave the lease thread + /// parked on a barrier while the runtime's destructor joins it. + SCOPE_EXIT({ + reported.release(); + second_admission.release(); + }); + CasMountRuntime & runtime = *runtime_holder; + runtime.installRenewer(uuid, 1, [&] { return wall_ms; }); + const uint64_t anchor = runtime.startRenewer(); + runtime.armMountFence(uuid, 1, anchor + 1000); + const uint64_t leases_lost_before = ProfileEvents::global_counters[ProfileEvents::CASMountLeaseLost].load(); + + backend->fault = RuntimeRenewBackend::Fault::ThrowMemoryLimitExceeded; + runtime.startBackgroundWorkers(std::chrono::milliseconds(0)); + + reported.waitUntilArrived(); + const String reported_outcome = outcome; + reported.release(); + ASSERT_EQ(reported_outcome, "recovered") << "a memory-limit exception inside the request must be retried"; + EXPECT_EQ(attempts_sent, "2"); + EXPECT_EQ(classification, "committed_after_retry"); + + /// The worker is admitted for its next renewal: the thread outlived the injected failure. + second_admission.waitUntilArrived(); + EXPECT_TRUE(runtime.mayMutate()); + EXPECT_EQ(runtime.lifecycle(), PoolLifecycle::Live); + EXPECT_EQ(ProfileEvents::global_counters[ProfileEvents::CASMountLeaseLost].load(), leases_lost_before); + + EXPECT_EQ(before_request.failure, "") << "the allocation before the request threw"; + EXPECT_GE(before_request.counted, kOverLimitAllocationBytes); + ASSERT_TRUE(while_consumed.has_value()); + EXPECT_EQ(while_consumed->failure, "") << "the allocation while the result was consumed threw"; + EXPECT_GE(while_consumed->counted, kOverLimitAllocationBytes); + EXPECT_EQ(total_memory_tracker.getHardLimit(), hard_limit_before); + + second_admission.release(); + runtime.stopBackgroundWorkers(); + runtime.finishTeardown(false); +} + TEST(CASPoolRemount, NaturalTerminalTransitionMakesBothPersistentWorkersSelfExit) { for (PoolLifecycle terminal : {PoolLifecycle::IdentityLost, PoolLifecycle::VanishedReplaced}) @@ -3932,12 +4107,8 @@ TEST(CASPoolRemount, TerminalDepositionDoesNotTouchRenewerAfterReplacement) runtime.installRenewer(uuid, 1, [&] { return wall_ms; }); const uint64_t anchor = runtime.startRenewer(); runtime.armMountFence(uuid, 1, anchor + 1000); - backend->fault = RuntimeRenewBackend::Fault::ThrowBefore; - /// Expire the lease from inside the attempt. The fault alone no longer ends a renewal: the engine - /// settles the ambiguity by reading and then reissues, and the reissue commits. With the clock past - /// the deadline the renewal was admitted under, neither the settling read nor the reissue is - /// admitted, so the renewal ends terminal -- which is what this test deposits. - backend->before_throw = [&, deadline = anchor + 1000] { boot_ms = deadline; }; + /// A definitive answer ends the worker's renewal; a transient fault would only be retried. + fenceOutMount(*backend, layout.mountKey("test")); runtime.startBackgroundWorkers(std::chrono::milliseconds(0)); terminal_deposited.waitUntilArrived(); EXPECT_TRUE(replaced.load(std::memory_order_acquire)); @@ -4022,11 +4193,9 @@ TEST(CASPoolRemount, ImmediatePostRemountRenewalFailureIsNotDropped) runtime_ptr->armMountFence(uuid, 2, fresh_anchor + 10'000); runtime_ptr->noteRemounted(); boot_ms = 2'000; - backend->fault = RuntimeRenewBackend::Fault::ThrowBefore; - /// Expire the fresh lease from inside the attempt, so the ambiguity can be neither - /// settled by a read nor reissued: otherwise the engine reissues and the renewal - /// commits, and there is no dropped failure to catch up on. - backend->before_throw = [&, deadline = fresh_anchor + 10'000] { boot_ms = deadline; }; + /// A definitive answer for the fresh incarnation's first worker renewal; a transient + /// fault would only be retried. + fenceOutMount(*backend, layout.mountKey("test")); first.arriveAndWait(); return true; } @@ -4454,10 +4623,8 @@ TEST(CASPool, DeterministicWorkerFailureFencesWithoutWaitingForCadence) runtime.installRenewer(uuid, 1, [&] { return wall_ms; }); const uint64_t anchor = runtime.startRenewer(); runtime.armMountFence(uuid, 1, anchor + 1000); - backend->fault = RuntimeRenewBackend::Fault::ThrowBefore; - /// Expire the lease from inside the attempt, so the ambiguity can be neither settled by a read nor - /// reissued: without that the engine reissues and the renewal commits, and this worker never fences. - backend->before_throw = [&, deadline = anchor + 1000] { boot_ms = deadline; }; + /// A definitive answer ends the worker's renewal; a transient fault would only be retried. + fenceOutMount(*backend, layout.mountKey("test")); runtime.startBackgroundWorkers(std::chrono::milliseconds(0)); remount_entered.waitUntilArrived(); EXPECT_FALSE(runtime.mayMutate()); @@ -4467,6 +4634,278 @@ TEST(CASPool, DeterministicWorkerFailureFencesWithoutWaitingForCadence) runtime.finishTeardown(false); } +/// A remount request ends a worker renewal that is retrying past its lease, inside the wait or the +/// request it is in: no request and no wait starts after it. +TEST(CASMountRuntime, ParkEndsAnUnboundedRenewal) +{ + enum class ParkDuring : uint8_t { Wait, Request }; + const auto run = [](ParkDuring park_during) + { + const Layout layout(park_during == ParkDuring::Wait ? "unbounded-park-in-wait" : "unbounded-park-in-request"); + const UInt128 uuid{1}; + uint64_t wall_ms = 1000; + std::atomic boot_ms{100}; + std::atomic past_the_lease{std::numeric_limits::max()}; + std::atomic held{false}; + std::atomic waits{0}; + std::atomic writes_at_remount{0}; + std::atomic waits_at_remount{0}; + DB::Cas::tests::ManualBarrier holding; + DB::Cas::tests::ManualBarrier remount_entered; + const auto hold_once_past_the_lease = [&] + { + if (boot_ms.load() >= past_the_lease.load() && !held.exchange(true)) + holding.arriveAndWait(); + }; + /// Declared after the locals its hooks capture. + auto backend = std::make_shared(); + ASSERT_EQ(claimMount(*DB::Cas::tests::OperationForTest(backend), layout, "test", uuid, 1, wall_ms, 1000).kind, + MountClaimResult::Claimed); + CasEventSink sink; + RuntimeUnderTest runtime_holder( + backend, layout, + MountConfig{.mount_lease_ttl_ms = std::chrono::milliseconds(1000), .background_watermark = true, + .boot_ms_fn = [&] { return boot_ms.load(); }}, + "test", sink, runtimeRenewBudget(), [&] + { + writes_at_remount = backend->outage_writes.load(); + waits_at_remount = waits.load(); + remount_entered.arriveAndWait(); + return false; + }); + CasMountRuntime & runtime = *runtime_holder; + runtime.installRenewer(uuid, 1, [&] { return wall_ms; }); + const uint64_t anchor = runtime.startRenewer(); + runtime.armMountFence(uuid, 1, anchor + 1000); + /// Five lease lengths on: a renewal bounded by its lease ended long before. + past_the_lease = anchor + 5'000; + runtime_holder.setRetrySleepForTest([&](uint64_t ms) + { + ++waits; + boot_ms += ms; + if (park_during == ParkDuring::Wait) + hold_once_past_the_lease(); + }); + if (park_during == ParkDuring::Request) + backend->on_outage_write = hold_once_past_the_lease; + backend->outage = [] { return true; }; + runtime.startBackgroundWorkers(std::chrono::milliseconds(0)); + + holding.waitUntilArrived(); + const uint64_t writes_at_park = backend->outage_writes.load(); + const uint64_t waits_at_park = waits.load(); + runtime.scheduleRemount(); + EXPECT_EQ(runtime.renewalDriverStateForTest(), RenewalDriverState::ParkRequested); + holding.release(); + remount_entered.waitUntilArrived(); + EXPECT_EQ(runtime.renewalDriverStateForTest(), RenewalDriverState::Parked); + EXPECT_EQ(writes_at_remount.load(), writes_at_park) << "no request starts after the park"; + EXPECT_EQ(waits_at_remount.load(), waits_at_park) << "no wait starts after the park"; + remount_entered.release(); + runtime.stopBackgroundWorkers(); + runtime.finishTeardown(false); + }; + run(ParkDuring::Wait); + run(ParkDuring::Request); +} + +/// FORGET while the worker's renewal retries past its lease: the intent then the trip, in the order +/// `Pool::forgetDisk` uses, end the renewal inside the wait it is in, both workers exit, and no remount +/// generation is raised. +TEST(CASMountRuntime, ForgetEndsAnUnboundedRenewal) +{ + auto backend = std::make_shared(); + const Layout layout("unbounded-forget"); + const UInt128 uuid{1}; + uint64_t wall_ms = 1000; + std::atomic boot_ms{100}; + std::atomic past_the_lease{std::numeric_limits::max()}; + std::atomic held{false}; + std::atomic waits{0}; + DB::Cas::tests::ManualBarrier holding; + WorkerExitLatch exits; + RuntimeWorkerFactory factory = [&](std::function worker_body) + { + return ThreadFromGlobalPool([&, body = std::move(worker_body)] + { + body(); + exits.recordExit(); + }); + }; + ASSERT_EQ(claimMount(*DB::Cas::tests::OperationForTest(backend), layout, "test", uuid, 1, wall_ms, 1000).kind, + MountClaimResult::Claimed); + CasEventSink sink; + RuntimeUnderTest runtime_holder( + backend, layout, + MountConfig{.mount_lease_ttl_ms = std::chrono::milliseconds(1000), .background_watermark = true, + .boot_ms_fn = [&] { return boot_ms.load(); }, .worker_factory = factory}, + "test", sink, runtimeRenewBudget(), [] { return false; }); + CasMountRuntime & runtime = *runtime_holder; + runtime.installRenewer(uuid, 1, [&] { return wall_ms; }); + const uint64_t anchor = runtime.startRenewer(); + runtime.armMountFence(uuid, 1, anchor + 1000); + past_the_lease = anchor + 5'000; + runtime_holder.setRetrySleepForTest([&](uint64_t ms) + { + ++waits; + boot_ms += ms; + if (boot_ms.load() >= past_the_lease.load() && !held.exchange(true)) + holding.arriveAndWait(); + }); + backend->outage = [] { return true; }; + runtime.startBackgroundWorkers(std::chrono::milliseconds(0)); + + holding.waitUntilArrived(); + const uint64_t writes_at_forget = backend->outage_writes.load(); + const uint64_t waits_at_forget = waits.load(); + const uint64_t generation_at_forget = runtime.remountRequestedGenerationForTest(); + runtime.publishVanishedIntent(); + runtime.tripMountLost(); + holding.release(); + + const bool both_exited = exits.waitForAtLeast(2); + EXPECT_TRUE(both_exited) << "the worker loops must exit on the published intent"; + EXPECT_EQ(backend->outage_writes.load(), writes_at_forget) << "no request starts after FORGET"; + EXPECT_EQ(waits.load(), waits_at_forget) << "no wait starts after FORGET"; + EXPECT_EQ(runtime.remountRequestedGenerationForTest(), generation_at_forget); + EXPECT_FALSE(runtime.mayMutate()); + runtime.stopBackgroundWorkers(); + runtime.finishTeardown(false); +} + +TEST(CASMountRuntime, StopWakesTheRetryWaitOfAnUnboundedRenewal) +{ + auto backend = std::make_shared(); + const Layout layout("unbounded-stop-in-wait"); + const UInt128 uuid{1}; + uint64_t wall_ms = 1000; + const uint64_t boot_ms = 100; + std::promise wait_entered; + std::future wait_requested = wait_entered.get_future(); + std::atomic first_wait{true}; + std::atomic first_wait_slept_ms{-1}; + /// The first wait is held far longer than any scheduling delay of the test thread, so only a stop can + /// end it before the expectation below; a stop that failed to wake it fails after this long. + constexpr uint64_t held_wait_ms = 30'000; + ASSERT_EQ(claimMount(*DB::Cas::tests::OperationForTest(backend), layout, "test", uuid, 1, wall_ms, 1000).kind, + MountClaimResult::Claimed); + CasEventSink sink; + RuntimeUnderTest runtime_holder( + backend, layout, + MountConfig{.mount_lease_ttl_ms = std::chrono::milliseconds(1000), .background_watermark = true, + .boot_ms_fn = [&] { return boot_ms; }}, + "test", sink, runtimeRenewBudget(), [] { return false; }); + CasMountRuntime & runtime = *runtime_holder; + runtime.installRenewer(uuid, 1, [&] { return wall_ms; }); + const uint64_t anchor = runtime.startRenewer(); + runtime.armMountFence(uuid, 1, anchor + 1000); + runtime_holder.setRetrySleepForTest([&](uint64_t ms) + { + const bool first = first_wait.exchange(false); + if (first) + wait_entered.set_value(ms); + const auto started = std::chrono::steady_clock::now(); + runtime.sleepInterruptibly(first ? held_wait_ms : ms); + if (first) + first_wait_slept_ms = std::chrono::duration_cast( + std::chrono::steady_clock::now() - started).count(); + }); + backend->outage = [] { return true; }; + runtime.startBackgroundWorkers(std::chrono::milliseconds(0)); + + ASSERT_EQ(wait_requested.wait_for(std::chrono::seconds(20)), std::future_status::ready); + const uint64_t requested_ms = wait_requested.get(); + runtime.stopBackgroundWorkers(); + + EXPECT_GE(requested_ms, kMountRenewRetrySpacingMs * 8 / 10); + EXPECT_LE(requested_ms, kMountRenewRetrySpacingMs * 12 / 10); + ASSERT_GE(first_wait_slept_ms.load(), 0); + EXPECT_LT(static_cast(first_wait_slept_ms.load()), held_wait_ms / 2) + << "the stop woke the wait instead of letting it run out"; + EXPECT_EQ(backend->outage_writes.load(), 1u) << "nothing is sent after the stop"; + runtime.finishTeardown(false); +} + +/// A success whose lease is already over is followed by the next renewal with no cadence wait. +TEST(CASMountRuntime, AStaleSuccessIsFollowedAtOnceByTheNextRenewal) +{ + const Layout layout("unbounded-stale-success"); + const UInt128 uuid{1}; + uint64_t wall_ms = 1000; + std::atomic boot_ms{100}; + std::atomic outage_until{0}; + std::vector commit_boot_ms; + std::vector may_mutate_at_commit; + DB::Cas::tests::ManualBarrier second_commit; + CasMountRuntime * runtime_ptr = nullptr; + /// Far above the longest legitimate outage here (one request per second for three lease lengths). + constexpr uint64_t max_outage_requests = 500; + std::atomic request_bound_hit{false}; + /// Declared after the locals its hooks capture. + auto backend = std::make_shared(); + ASSERT_EQ(claimMount(*DB::Cas::tests::OperationForTest(backend), layout, "test", uuid, 1, wall_ms, 1000).kind, + MountClaimResult::Claimed); + CasEventSink sink; + RuntimeUnderTest runtime_holder( + backend, layout, + MountConfig{.mount_lease_ttl_ms = std::chrono::milliseconds(1000), .background_watermark = true, + .boot_ms_fn = [&] { return boot_ms.load(); }, + /// The test clock moves only through the sleep seam, so a regression that zeroes the + /// pauses would retry forever; the request count ends the renewal instead. + .renewal_live_for_test = [&] + { + if (backend->outage_writes.load() < max_outage_requests) + return true; + request_bound_hit = true; + return false; + }}, + "test", sink, runtimeRenewBudget(), [] { return false; }); + CasMountRuntime & runtime = *runtime_holder; + runtime_ptr = &runtime; + runtime.installRenewer(uuid, 1, [&] { return wall_ms; }); + const uint64_t anchor = runtime.startRenewer(); + runtime.armMountFence(uuid, 1, anchor + 1000); + runtime_holder.setRetrySleepForTest([&](uint64_t ms) { boot_ms += ms; }); + /// The first renewal starts one period after the anchor and fails for three lease lengths. + boot_ms = anchor + 500; + outage_until = anchor + 3'500; + backend->outage = [&] { return boot_ms.load() < outage_until.load(); }; + backend->after_commit = [&] + { + commit_boot_ms.push_back(boot_ms.load()); + may_mutate_at_commit.push_back(runtime_ptr->mayMutate()); + if (commit_boot_ms.size() == 2) + second_commit.arriveAndWait(); + }; + runtime.startBackgroundWorkers(std::chrono::milliseconds(500)); + + bool arrived = true; + try + { + second_commit.waitUntilArrived(); + } + catch (const DB::Exception &) + { + arrived = false; + } + if (!arrived) + { + runtime.stopBackgroundWorkers(); + runtime.finishTeardown(false); + FAIL() << "the second renewal never committed; request bound hit: " << request_bound_hit.load(); + } + EXPECT_FALSE(request_bound_hit.load()) + << "the first renewal sent " << max_outage_requests << " requests without the clock reaching the end of the outage"; + ASSERT_EQ(commit_boot_ms.size(), 2u); + EXPECT_GE(commit_boot_ms[0], anchor + 3'500) << "the first renewal outlived its own lease"; + EXPECT_EQ(commit_boot_ms[1], commit_boot_ms[0]) + << "no time passed: a cadence wait on this frozen clock would never have ended"; + EXPECT_FALSE(may_mutate_at_commit[1]) << "the stale success left the lease expired"; + second_commit.release(); + runtime.stopBackgroundWorkers(); + runtime.finishTeardown(false); +} + TEST(CASPool, RenewWatermarkOnceRefreshesFenceAndDepositsOneFailure) { auto backend = std::make_shared(); @@ -4732,3 +5171,836 @@ TEST(CASPool, ConcurrentNamespaceCreationsNeverRaceEachOtherOnTheCatalog) << "the next hold starts from what the resolve read saw"; EXPECT_EQ(backend->writeCount(key) - writes_mid, 3u) << "one refused, two landed"; } + +namespace +{ + +/// Fails the guarded mount `PUT`s that `on_put` says to fail, with a timeout raised before the store +/// applied anything, and the reads of the mount slot that `on_read` says to fail. Both run on the +/// renewing thread with the 1-based number of the request of their kind. +class ExpiryScriptBackend final : public DB::Cas::tests::CountingBackend +{ +public: + std::function on_put; + std::function on_read; + + std::optional read(const String & key, DB::Cas::TransportAccess & access) override + { + if (on_read && key.ends_with("/mount") && on_read(++reads)) + throw Poco::TimeoutException("injected resolve read timeout"); + return DB::Cas::tests::CountingBackend::read(key, access); + } + + std::expected write(const String & key, const String & bytes, + const std::optional & expected_value, DB::Cas::TransportAccess & access) override + { + if (on_put && expected_value && key.ends_with("/mount") && on_put(++puts)) + throw Poco::TimeoutException("injected renewal timeout before the store applied it"); + return DB::Cas::tests::CountingBackend::write(key, bytes, expected_value, access); + } + +private: + uint32_t puts = 0; + uint32_t reads = 0; +}; + +constexpr uint64_t kExpiryTtlMs = 30'000; +constexpr uint64_t kExpiryPeriodMs = 10'000; +constexpr uint64_t kExpiryClaimBootMs = 100'000; +constexpr uint64_t kExpiryDeadlineBootMs = kExpiryClaimBootMs + kExpiryTtlMs; +constexpr uint64_t kExpiryFirstStartBootMs = kExpiryClaimBootMs + kExpiryPeriodMs; +/// Longer than the largest retry-spacing draw, so a failed request is retried at once. +constexpr uint64_t kExpiryFailedPutMs = 1'300; +/// Enough failures to carry the first renewal past its own start + TTL. +constexpr uint32_t kExpiryFailedPuts = 24; +constexpr uint64_t kExpiryRestoreBootMs = kExpiryFirstStartBootMs + kExpiryFailedPuts * kExpiryFailedPutMs; +/// A request sent while the lease is expired and the first renewal still retries. +constexpr uint32_t kExpiryObservedPut = 20; +static_assert(kExpiryFirstStartBootMs + (kExpiryObservedPut - 1) * kExpiryFailedPutMs > kExpiryDeadlineBootMs); +static_assert(kExpiryRestoreBootMs > kExpiryFirstStartBootMs + kExpiryTtlMs); + +const char * expiryAdmitName(Fence::Admit verdict) +{ + switch (verdict) + { + case Fence::Admit::Ok: return "Ok"; + case Fence::Admit::LostOrRearmed: return "LostOrRearmed"; + case Fence::Admit::NoBudget: return "NoBudget"; + } + return "unknown"; +} + +uint64_t eventCount(ProfileEvents::Event event) +{ + return ProfileEvents::global_counters[event].load(); +} + +struct ExpiryObservation +{ + uint64_t generation_before = 0; + uint64_t attempts_before = 0; + uint64_t retries_before = 0; + uint64_t lease_expired_before = 0; + uint64_t lease_lost_before = 0; + + /// Inside `PUT` number `kExpiryObservedPut`. + Fence::Admit admit_during = Fence::Admit::Ok; + bool may_mutate_during = true; + PoolLifecycle lifecycle_during = PoolLifecycle::TransientNotLive; + std::optional expired_since_during; + String last_failure_during; + uint64_t attempts_during = 0; + uint64_t retries_during = 0; + + /// At the loop pass after the renewal that committed with a start more than a TTL ago. + Fence::Admit admit_after_stale = Fence::Admit::Ok; + std::optional expired_since_after_stale; + String last_failure_after_stale; + uint64_t lease_expired_after_stale = 0; + uint64_t boot_ms_after_stale = 0; + uint64_t boot_ms_at_next_admission = 0; + + /// At the loop pass after the restoring renewal. + Fence::Admit admit_after_restore = Fence::Admit::LostOrRearmed; + std::optional expired_since_after_restore; + String last_failure_after_restore; + PoolLifecycle lifecycle_after_restore = PoolLifecycle::TransientNotLive; + uint64_t generation_after_restore = 0; + uint64_t lease_expired_after_restore = 0; + uint64_t lease_lost_after_restore = 0; + uint64_t attempts_after_restore = 0; + uint64_t retries_after_restore = 0; + + uint64_t writer_epoch_on_store = 0; + uint32_t remount_calls = 0; + std::vector events; + String log; +}; + +void runExpiryScenario(const String & layout_prefix, ExpiryObservation & seen) +{ + /// Everything the hooks capture is declared before the backend and the runtime that store them. + const Layout layout(layout_prefix); + const UInt128 uuid{1}; + uint64_t wall_ms = 1000; + std::atomic boot_ms{kExpiryClaimBootMs}; + std::atomic remount_calls{0}; + uint32_t loop_passes = 0; + DB::Cas::tests::ManualBarrier third_pass; + CasMountRuntime * runtime_ptr = nullptr; + auto events = std::make_shared(); + CasEventSink sink = [events](CasEvent event) { events->push(std::move(event)); }; + ScopedRemountLogCapture log_capture; + auto backend = std::make_shared(); + + ASSERT_EQ(claimMount(*DB::Cas::tests::OperationForTest(backend), layout, "test", uuid, 1, wall_ms, kExpiryTtlMs).kind, + MountClaimResult::Claimed); + + const auto observe_after_stale = [&] + { + CasMountRuntime & runtime = *runtime_ptr; + seen.admit_after_stale = runtime.admit(seen.generation_before, 0); + seen.expired_since_after_stale = runtime.leaseExpiredSinceBootMs(); + seen.last_failure_after_stale = runtime.lastRenewFailure(); + seen.lease_expired_after_stale = eventCount(ProfileEvents::CASMountLeaseExpired) - seen.lease_expired_before; + seen.boot_ms_after_stale = boot_ms.load(); + }; + const auto observe_after_restore = [&] + { + CasMountRuntime & runtime = *runtime_ptr; + seen.admit_after_restore = runtime.admit(seen.generation_before, 0); + seen.expired_since_after_restore = runtime.leaseExpiredSinceBootMs(); + seen.last_failure_after_restore = runtime.lastRenewFailure(); + seen.lifecycle_after_restore = runtime.lifecycle(); + seen.generation_after_restore = runtime.fenceGeneration(); + seen.lease_expired_after_restore = eventCount(ProfileEvents::CASMountLeaseExpired) - seen.lease_expired_before; + seen.lease_lost_after_restore = eventCount(ProfileEvents::CASMountLeaseLost) - seen.lease_lost_before; + seen.attempts_after_restore = eventCount(ProfileEvents::CASMountRenewalAttempts) - seen.attempts_before; + seen.retries_after_restore = eventCount(ProfileEvents::CASMountRenewalRetries) - seen.retries_before; + }; + + RuntimeUnderTest runtime_holder( + backend, layout, + MountConfig{ + .mount_lease_ttl_ms = std::chrono::milliseconds(kExpiryTtlMs), + .background_watermark = true, + .boot_ms_fn = [&] { return boot_ms.load(); }, + .renewal_before_driver_lock_hook_for_test = [&] + { + ++loop_passes; + if (loop_passes == 1) + { + boot_ms.store(kExpiryFirstStartBootMs); + } + else if (loop_passes == 2) + { + observe_after_stale(); + } + else if (loop_passes == 3) + { + observe_after_restore(); + third_pass.arriveAndWait(); + } + }, + .renewal_admitted_hook_for_test = [&] + { + if (loop_passes == 2) + seen.boot_ms_at_next_admission = boot_ms.load(); + }}, + "test", sink, runtimeRenewBudget(), [&] + { + ++remount_calls; + return false; + }); + CasMountRuntime & runtime = *runtime_holder; + runtime_ptr = &runtime; + runtime.installRenewer(uuid, 1, [&] { return wall_ms; }); + const uint64_t anchor = runtime.startRenewer(); + ASSERT_EQ(anchor, kExpiryClaimBootMs); + runtime.armMountFence(uuid, 1, anchor + kExpiryTtlMs); + + seen.generation_before = runtime.fenceGeneration(); + seen.attempts_before = eventCount(ProfileEvents::CASMountRenewalAttempts); + seen.retries_before = eventCount(ProfileEvents::CASMountRenewalRetries); + seen.lease_expired_before = eventCount(ProfileEvents::CASMountLeaseExpired); + seen.lease_lost_before = eventCount(ProfileEvents::CASMountLeaseLost); + + backend->on_put = [&](uint32_t put_no) + { + if (put_no == kExpiryObservedPut) + { + CasMountRuntime & renewing = *runtime_ptr; + seen.admit_during = renewing.admit(seen.generation_before, 0); + seen.may_mutate_during = renewing.mayMutate(); + seen.lifecycle_during = renewing.lifecycle(); + seen.expired_since_during = renewing.leaseExpiredSinceBootMs(); + seen.last_failure_during = renewing.lastRenewFailure(); + seen.attempts_during = eventCount(ProfileEvents::CASMountRenewalAttempts) - seen.attempts_before; + seen.retries_during = eventCount(ProfileEvents::CASMountRenewalRetries) - seen.retries_before; + } + if (put_no > kExpiryFailedPuts) + return false; + boot_ms.fetch_add(kExpiryFailedPutMs); + return true; + }; + + runtime.startBackgroundWorkers(std::chrono::milliseconds(kExpiryPeriodMs)); + third_pass.waitUntilArrived(); + + seen.writer_epoch_on_store = decodeMountLease(readObj(*backend, layout.mountKey("test"))->bytes).writer_epoch; + seen.remount_calls = remount_calls.load(); + seen.events = events->snapshot(); + seen.log = log_capture.captured(); + + third_pass.release(); + runtime.stopBackgroundWorkers(); + runtime.finishTeardown(false); +} + +/// One renewal whose first `PUT` is unclear and whose resolve reads then fail long enough for the lease +/// to expire; the 19th read finds the slot unchanged and the reissued `PUT` lands. +constexpr uint32_t kReadOutageFailedReads = 18; +constexpr uint32_t kReadOutageObservedRead = 17; +static_assert(kExpiryFirstStartBootMs + (kReadOutageObservedRead - 1) * kExpiryFailedPutMs > kExpiryDeadlineBootMs); + +struct ReadOutageObservation +{ + uint64_t attempts_before = 0; + uint64_t retries_before = 0; + /// Inside read number `kReadOutageObservedRead`. + std::optional expired_since_during; + String last_failure_during; + uint64_t attempts_during = 0; + uint64_t retries_during = 0; + /// At the loop pass after the renewal. + uint64_t attempts_after = 0; + uint64_t retries_after = 0; +}; + +void runReadOutageScenario(const String & layout_prefix, ReadOutageObservation & seen) +{ + const Layout layout(layout_prefix); + const UInt128 uuid{1}; + uint64_t wall_ms = 1000; + std::atomic boot_ms{kExpiryClaimBootMs}; + uint32_t loop_passes = 0; + DB::Cas::tests::ManualBarrier second_pass; + CasMountRuntime * runtime_ptr = nullptr; + CasEventSink sink; + auto backend = std::make_shared(); + + ASSERT_EQ(claimMount(*DB::Cas::tests::OperationForTest(backend), layout, "test", uuid, 1, wall_ms, kExpiryTtlMs).kind, + MountClaimResult::Claimed); + + RuntimeUnderTest runtime_holder( + backend, layout, + MountConfig{ + .mount_lease_ttl_ms = std::chrono::milliseconds(kExpiryTtlMs), + .background_watermark = true, + .boot_ms_fn = [&] { return boot_ms.load(); }, + .renewal_before_driver_lock_hook_for_test = [&] + { + ++loop_passes; + if (loop_passes == 1) + { + boot_ms.store(kExpiryFirstStartBootMs); + } + else if (loop_passes == 2) + { + seen.attempts_after = eventCount(ProfileEvents::CASMountRenewalAttempts) - seen.attempts_before; + seen.retries_after = eventCount(ProfileEvents::CASMountRenewalRetries) - seen.retries_before; + second_pass.arriveAndWait(); + } + }}, + "test", sink, runtimeRenewBudget(), [] { return false; }); + CasMountRuntime & runtime = *runtime_holder; + runtime_ptr = &runtime; + runtime.installRenewer(uuid, 1, [&] { return wall_ms; }); + const uint64_t anchor = runtime.startRenewer(); + runtime.armMountFence(uuid, 1, anchor + kExpiryTtlMs); + + seen.attempts_before = eventCount(ProfileEvents::CASMountRenewalAttempts); + seen.retries_before = eventCount(ProfileEvents::CASMountRenewalRetries); + backend->on_put = [](uint32_t put_no) { return put_no == 1; }; + backend->on_read = [&](uint32_t read_no) + { + if (read_no == kReadOutageObservedRead) + { + seen.expired_since_during = runtime_ptr->leaseExpiredSinceBootMs(); + seen.last_failure_during = runtime_ptr->lastRenewFailure(); + seen.attempts_during = eventCount(ProfileEvents::CASMountRenewalAttempts) - seen.attempts_before; + seen.retries_during = eventCount(ProfileEvents::CASMountRenewalRetries) - seen.retries_before; + } + if (read_no > kReadOutageFailedReads) + return false; + boot_ms.fetch_add(kExpiryFailedPutMs); + return true; + }; + + runtime.startBackgroundWorkers(std::chrono::milliseconds(kExpiryPeriodMs)); + second_pass.waitUntilArrived(); + second_pass.release(); + runtime.stopBackgroundWorkers(); + runtime.finishTeardown(false); +} + +std::vector renewEventsOf(const std::vector & events) +{ + std::vector renewals; + for (const CasEvent & event : events) + if (event.type == CasEventType::WatermarkRenew) + renewals.push_back(event); + return renewals; +} + +} + +/// An expiry refuses writes without touching the fence, a renewal that commits with a start more than a +/// TTL ago restores nothing and is followed at once, and the next one restores writes under the same +/// epoch and generation. Runs the real worker loop. +TEST(CASMountRuntime, ExpiryRefusesWritesAndResumesUnderTheSameEpoch) +{ + ExpiryObservation seen; + ASSERT_NO_FATAL_FAILURE(runExpiryScenario("runtime-expiry-resume", seen)); + + EXPECT_STREQ(expiryAdmitName(seen.admit_during), "NoBudget") << "refused, and not because the fence is lost"; + EXPECT_FALSE(seen.may_mutate_during); + EXPECT_EQ(seen.lifecycle_during, PoolLifecycle::Live); + + EXPECT_STREQ(expiryAdmitName(seen.admit_after_stale), "NoBudget") + << "a renewal whose start + TTL is already past restores nothing"; + /// The clock moves only when the test moves it, so a renewal admitted at all after the stale success + /// was admitted without a cadence wait; a wait would have left loop pass 3 unreached. + EXPECT_EQ(seen.boot_ms_at_next_admission, seen.boot_ms_after_stale); + + EXPECT_STREQ(expiryAdmitName(seen.admit_after_restore), "Ok"); + EXPECT_EQ(seen.lifecycle_after_restore, PoolLifecycle::Live); + EXPECT_EQ(seen.generation_after_restore, seen.generation_before) << "an expiry is not a re-arm"; + EXPECT_EQ(seen.lease_lost_after_restore, 0u); + EXPECT_EQ(seen.writer_epoch_on_store, 1u) << "the same epoch holds the slot"; + EXPECT_EQ(seen.remount_calls, 0u); +} + +/// What an operator sees: the expiry and its last failure while it lasts, the attempt counters moving +/// during the outage, and one counter, event field and warning when a renewal restores the lease. +TEST(CASMountRuntime, ExpiryIsReported) +{ + ExpiryObservation seen; + ASSERT_NO_FATAL_FAILURE(runExpiryScenario("runtime-expiry-report", seen)); + + ASSERT_TRUE(seen.expired_since_during.has_value()); + EXPECT_EQ(*seen.expired_since_during, kExpiryDeadlineBootMs); + EXPECT_NE(seen.last_failure_during.find("injected renewal timeout"), String::npos) << seen.last_failure_during; + /// The request being sent is counted before it reaches the store. + EXPECT_EQ(seen.attempts_during, kExpiryObservedPut) << "attempts advance as requests are sent"; + EXPECT_EQ(seen.retries_during, kExpiryObservedPut - 1); + + ASSERT_TRUE(seen.expired_since_after_stale.has_value()); + EXPECT_EQ(*seen.expired_since_after_stale, kExpiryDeadlineBootMs) + << "a renewal committed past its own start + TTL keeps the expiry and when it began"; + EXPECT_EQ(seen.lease_expired_after_stale, 0u) << "that renewal is not a restore"; + EXPECT_NE(seen.last_failure_after_stale.find("injected renewal timeout"), String::npos) + << "the lease is still expired, so its failures still explain it: " << seen.last_failure_after_stale; + + EXPECT_FALSE(seen.expired_since_after_restore.has_value()); + EXPECT_TRUE(seen.last_failure_after_restore.empty()) + << "a restore ends the outage the text described: " << seen.last_failure_after_restore; + EXPECT_EQ(seen.lease_expired_after_restore, 1u); + /// 25 requests by the first renewal and one by the second, each counted once. + EXPECT_EQ(seen.attempts_after_restore, kExpiryFailedPuts + 2); + EXPECT_EQ(seen.retries_after_restore, kExpiryFailedPuts); + + const std::vector renewals = renewEventsOf(seen.events); + ASSERT_EQ(renewals.size(), 2u) << "the retried renewal and the restoring one"; + EXPECT_FALSE(renewals[0].detail.contains("expired_ms")) << "the first renewal left the lease expired"; + EXPECT_EQ(renewals[0].detail.at("classification"), "committed_after_retry"); + EXPECT_EQ(renewals[1].outcome, "recovered"); + EXPECT_EQ(renewals[1].detail.at("classification"), "committed_after_expiry"); + ASSERT_TRUE(renewals[1].detail.contains("expired_ms")); + EXPECT_EQ(renewals[1].detail.at("expired_ms"), std::to_string(kExpiryRestoreBootMs - kExpiryDeadlineBootMs)); + + EXPECT_NE(seen.log.find(fmt::format("expired for {} ms", kExpiryRestoreBootMs - kExpiryDeadlineBootMs)), String::npos) + << seen.log; + EXPECT_NE(seen.log.find("injected renewal timeout"), String::npos) << "the warning names the last failure: " << seen.log; + + /// An unclear `PUT` whose resolve reads then fail: the reads are what the operator needs to see, + /// and they are not requests of the renewal. + ReadOutageObservation reads; + ASSERT_NO_FATAL_FAILURE(runReadOutageScenario("runtime-expiry-read-outage", reads)); + ASSERT_TRUE(reads.expired_since_during.has_value()) << "the read outage outlasted the lease, so the row shows this text"; + EXPECT_NE(reads.last_failure_during.find("injected resolve read timeout"), String::npos) + << "lifecycle_detail carries the last failed read: " << reads.last_failure_during; + EXPECT_EQ(reads.attempts_during, 1u) << "failed reads do not advance the attempt counter"; + EXPECT_EQ(reads.retries_during, 0u); + EXPECT_EQ(reads.attempts_after, 2u) << "the unclear PUT and its reissue"; + EXPECT_EQ(reads.retries_after, 1u); +} + +namespace +{ + +const String kExpiryWarningPrefix = "CAS mount lease of 'test' expired "; +const String kRestoreWarningText = "was expired for"; + +size_t countText(const String & haystack, const String & needle) +{ + size_t count = 0; + for (size_t at = haystack.find(needle); at != String::npos; at = haystack.find(needle, at + needle.size())) + ++count; + return count; +} + +/// What the lease thread sees while it runs `runExpiryLogScenario`. Declared by the test before the +/// runtime that stores the hooks capturing it. +struct ExpiryLogRig +{ + ScopedRemountLogCapture log; + std::atomic boot_ms{kExpiryClaimBootMs}; + CasMountRuntime * runtime = nullptr; + uint64_t generation = 0; + + /// Return true to fail the guarded mount `PUT` with that 1-based number. + std::function on_put; + std::function on_pass; + + size_t expiryWarnings() const { return countText(log.captured(), kExpiryWarningPrefix); } + + /// Per `PUT`, as the lease thread enters it. + std::vector expiry_at_put; + std::vector boot_at_put; + /// Per loop pass, before the renewal of that pass. + std::vector expiry_at_pass; + std::vector restore_at_pass; + uint32_t refused_writes = 0; + bool overran = false; + String final_log; +}; + +constexpr uint32_t kExpiryLogMaxPasses = 8; + +/// Runs the real worker loop until pass `stop_pass`, which is the loop pass before the renewal after +/// the one whose result the test wants to see. +void runExpiryLogScenario(const String & layout_prefix, ExpiryLogRig & rig, uint32_t stop_pass) +{ + const Layout layout(layout_prefix); + const UInt128 uuid{1}; + uint64_t wall_ms = 1000; + uint32_t loop_passes = 0; + DB::Cas::tests::ManualBarrier stop; + CasEventSink sink; + auto backend = std::make_shared(); + + ASSERT_EQ(claimMount(*DB::Cas::tests::OperationForTest(backend), layout, "test", uuid, 1, wall_ms, kExpiryTtlMs).kind, + MountClaimResult::Claimed); + + RuntimeUnderTest runtime_holder( + backend, layout, + MountConfig{ + .mount_lease_ttl_ms = std::chrono::milliseconds(kExpiryTtlMs), + .background_watermark = true, + .boot_ms_fn = [&] { return rig.boot_ms.load(); }, + .renewal_before_driver_lock_hook_for_test = [&] + { + ++loop_passes; + if (loop_passes == 1) + rig.boot_ms.store(kExpiryFirstStartBootMs); + const String text = rig.log.captured(); + rig.expiry_at_pass.push_back(countText(text, kExpiryWarningPrefix)); + rig.restore_at_pass.push_back(countText(text, kRestoreWarningText)); + if (rig.on_pass) + rig.on_pass(rig, loop_passes); + if (loop_passes >= stop_pass || loop_passes >= kExpiryLogMaxPasses) + { + rig.overran = loop_passes > stop_pass; + stop.arriveAndWait(); + } + }}, + "test", sink, runtimeRenewBudget(), [] { return false; }); + CasMountRuntime & runtime = *runtime_holder; + rig.runtime = &runtime; + runtime.installRenewer(uuid, 1, [&] { return wall_ms; }); + const uint64_t anchor = runtime.startRenewer(); + runtime.armMountFence(uuid, 1, anchor + kExpiryTtlMs); + rig.generation = runtime.fenceGeneration(); + + backend->on_put = [&](uint32_t put_no) + { + rig.expiry_at_put.push_back(rig.expiryWarnings()); + rig.boot_at_put.push_back(rig.boot_ms.load()); + if (!rig.on_put || !rig.on_put(rig, put_no)) + return false; + rig.boot_ms.fetch_add(kExpiryFailedPutMs); + return true; + }; + + runtime.startBackgroundWorkers(std::chrono::milliseconds(kExpiryPeriodMs)); + stop.waitUntilArrived(); + rig.final_log = rig.log.captured(); + + stop.release(); + runtime.stopBackgroundWorkers(); + runtime.finishTeardown(false); +} + +} + +/// The log carries one `WARNING` per expiry, written at the first request after it: not for an +/// outage the lease outlives, not per retry or per refused write, not when a renewal commits after its +/// own deadline, and again for a second expiry. +TEST(CASMountRuntime, ExpiryIsLoggedOncePerExpiry) +{ + { + ExpiryLogRig rig; + constexpr uint32_t kShortOutagePuts = 5; + static_assert(kExpiryFirstStartBootMs + kShortOutagePuts * kExpiryFailedPutMs < kExpiryDeadlineBootMs); + rig.on_put = [](ExpiryLogRig &, uint32_t put_no) { return put_no <= kShortOutagePuts; }; + ASSERT_NO_FATAL_FAILURE(runExpiryLogScenario("runtime-expiry-log-short", rig, 2)); + EXPECT_FALSE(rig.overran); + EXPECT_EQ(rig.expiry_at_put.size(), kShortOutagePuts + 1u) << "the outage ran as scripted"; + EXPECT_EQ(countText(rig.final_log, kExpiryWarningPrefix), 0u) << rig.final_log; + EXPECT_EQ(countText(rig.final_log, kRestoreWarningText), 0u) << rig.final_log; + } + + ExpiryLogRig rig; + uint64_t second_outage_floor_boot_ms = 0; + rig.on_put = [&](ExpiryLogRig & r, uint32_t put_no) + { + if (put_no == kExpiryObservedPut) + { + for (int i = 0; i < 3; ++i) + { + try + { + r.runtime->checkFenceOrThrow(r.generation); + } + catch (const DB::Exception &) + { + ++r.refused_writes; + } + } + } + if (put_no <= kExpiryFailedPuts) + return true; + if (second_outage_floor_boot_ms == 0) + return false; + return r.boot_ms.load() <= second_outage_floor_boot_ms; + }; + rig.on_pass = [&](ExpiryLogRig & r, uint32_t pass) + { + /// The restoring renewal has committed. The next one starts a period later and fails until + /// the lease that was just restored has run out. + if (pass == 3) + { + second_outage_floor_boot_ms = r.boot_ms.load() + kExpiryTtlMs; + r.boot_ms.fetch_add(kExpiryPeriodMs); + } + }; + ASSERT_NO_FATAL_FAILURE(runExpiryLogScenario("runtime-expiry-log-twice", rig, 4)); + ASSERT_FALSE(rig.overran) << "the worker ran more passes than scripted"; + ASSERT_GT(rig.expiry_at_put.size(), kExpiryFailedPuts + 1u); + + /// Outage past the deadline: a request that sees the lease expired has already written the line. + for (uint32_t put_no = 1; put_no <= kExpiryFailedPuts + 1; ++put_no) + { + const size_t expected = rig.boot_at_put[put_no - 1] >= kExpiryDeadlineBootMs ? 1 : 0; + EXPECT_EQ(rig.expiry_at_put[put_no - 1], expected) << "at PUT " << put_no << " (boot " << rig.boot_at_put[put_no - 1] << ")"; + } + EXPECT_EQ(rig.refused_writes, 3u); + + /// Pass 2 follows the renewal that committed after its own deadline: the lease is still expired. + ASSERT_GE(rig.expiry_at_pass.size(), 4u); + EXPECT_EQ(rig.expiry_at_pass[1], 1u) << "a renewal that commits past its own deadline does not warn again"; + EXPECT_EQ(rig.restore_at_pass[1], 0u); + /// Pass 3 follows the restoring renewal. + EXPECT_EQ(rig.expiry_at_pass[2], 1u); + EXPECT_EQ(rig.restore_at_pass[2], 1u); + /// Pass 4 follows the renewal that restored a second expiry. + EXPECT_EQ(rig.expiry_at_pass[3], 2u) << "a lease that expires again warns again"; + EXPECT_EQ(rig.restore_at_pass[3], 2u); + + EXPECT_EQ(countText(rig.final_log, kExpiryWarningPrefix), 2u) << rig.final_log; + + /// The first line names the server root, the injected failure and a positive elapsed time. + const size_t first = rig.final_log.find(kExpiryWarningPrefix); + ASSERT_NE(first, String::npos) << rig.final_log; + const String line = rig.final_log.substr(first, rig.final_log.find('\n', first) - first); + EXPECT_NE(line.find("injected renewal timeout"), String::npos) << line; + const uint64_t elapsed_ms = std::stoull(line.substr(kExpiryWarningPrefix.size())); + EXPECT_GT(elapsed_ms, 0u) << line; + EXPECT_LE(elapsed_ms, kExpiryFailedPutMs) << "written at the first request after the expiry: " << line; +} + +/// The failure text explains the current run of trouble only. A renewal that fails once and then commits +/// with a deadline in the future ends that run; a later expiry in which no request fails shows no text. +TEST(CASMountRuntime, ASuccessEndsTheFailureTextOfItsRun) +{ + /// Everything the hooks capture is declared before the backend and the runtime that store them. + const Layout layout("runtime-expiry-failure-text"); + const UInt128 uuid{1}; + uint64_t wall_ms = 1000; + std::atomic boot_ms{kExpiryClaimBootMs}; + uint32_t loop_passes = 0; + DB::Cas::tests::ManualBarrier third_pass; + CasMountRuntime * runtime_ptr = nullptr; + String failure_after_success = "unobserved"; + std::optional expired_since_after_stall; + String failure_after_stall = "unobserved"; + /// The second renewal's `PUT` lands, but only after the lease it was meant to extend ran out. + constexpr uint64_t second_start_boot_ms = kExpiryFirstStartBootMs + 15'000; + constexpr uint64_t stall_ms = 2 * kExpiryTtlMs; + CasEventSink sink; + auto backend = std::make_shared(); + + ASSERT_EQ(claimMount(*DB::Cas::tests::OperationForTest(backend), layout, "test", uuid, 1, wall_ms, kExpiryTtlMs).kind, + MountClaimResult::Claimed); + + RuntimeUnderTest runtime_holder( + backend, layout, + MountConfig{ + .mount_lease_ttl_ms = std::chrono::milliseconds(kExpiryTtlMs), + .background_watermark = true, + .boot_ms_fn = [&] { return boot_ms.load(); }, + .renewal_before_driver_lock_hook_for_test = [&] + { + ++loop_passes; + if (loop_passes == 1) + { + boot_ms.store(kExpiryFirstStartBootMs); + } + else if (loop_passes == 2) + { + failure_after_success = runtime_ptr->lastRenewFailure(); + boot_ms.store(second_start_boot_ms); + } + else if (loop_passes == 3) + { + expired_since_after_stall = runtime_ptr->leaseExpiredSinceBootMs(); + failure_after_stall = runtime_ptr->lastRenewFailure(); + third_pass.arriveAndWait(); + } + }}, + "test", sink, runtimeRenewBudget(), [] { return false; }); + CasMountRuntime & runtime = *runtime_holder; + runtime_ptr = &runtime; + runtime.installRenewer(uuid, 1, [&] { return wall_ms; }); + const uint64_t anchor = runtime.startRenewer(); + runtime.armMountFence(uuid, 1, anchor + kExpiryTtlMs); + + backend->on_put = [&](uint32_t put_no) + { + if (put_no == 1) + { + boot_ms.fetch_add(kExpiryFailedPutMs); + return true; + } + if (put_no == 3) + boot_ms.fetch_add(stall_ms); + return false; + }; + + runtime.startBackgroundWorkers(std::chrono::milliseconds(kExpiryPeriodMs)); + third_pass.waitUntilArrived(); + third_pass.release(); + runtime.stopBackgroundWorkers(); + runtime.finishTeardown(false); + + EXPECT_TRUE(failure_after_success.empty()) + << "a commit with a deadline in the future ends the run of trouble: " << failure_after_success; + ASSERT_TRUE(expired_since_after_stall.has_value()) << "the stalled renewal committed past its own start + TTL"; + EXPECT_TRUE(failure_after_stall.empty()) + << "no request of this expiry failed, so lifecycle_detail is empty: " << failure_after_stall; +} + +/// Two expiries in a row, each ended by a restoring renewal, count 2: a stale success counts nothing, +/// and writes refused while the lease is expired do not count either. +TEST(CASMountRuntime, EachRestoredExpiryIsCountedOnce) +{ + const Layout layout("runtime-expiry-twice"); + const UInt128 uuid{1}; + uint64_t wall_ms = 1000; + std::atomic boot_ms{kExpiryClaimBootMs}; + uint32_t loop_passes = 0; + uint64_t generation = 0; + DB::Cas::tests::ManualBarrier last_pass; + CasMountRuntime * runtime_ptr = nullptr; + const uint64_t expired_before = eventCount(ProfileEvents::CASMountLeaseExpired); + std::vector counted_at_pass; + std::vector refused_while_expired; + std::vector counted_after_refusals; + CasEventSink sink; + auto backend = std::make_shared(); + + ASSERT_EQ(claimMount(*DB::Cas::tests::OperationForTest(backend), layout, "test", uuid, 1, wall_ms, kExpiryTtlMs).kind, + MountClaimResult::Claimed); + + RuntimeUnderTest runtime_holder( + backend, layout, + MountConfig{ + .mount_lease_ttl_ms = std::chrono::milliseconds(kExpiryTtlMs), + .background_watermark = true, + .boot_ms_fn = [&] { return boot_ms.load(); }, + .renewal_before_driver_lock_hook_for_test = [&] + { + ++loop_passes; + if (loop_passes == 1) + { + boot_ms.store(kExpiryFirstStartBootMs); + return; + } + counted_at_pass.push_back(eventCount(ProfileEvents::CASMountLeaseExpired) - expired_before); + if (loop_passes == 3) + boot_ms.fetch_add(kExpiryPeriodMs); + else if (loop_passes == 5) + last_pass.arriveAndWait(); + }}, + "test", sink, runtimeRenewBudget(), [] { return false; }); + CasMountRuntime & runtime = *runtime_holder; + runtime_ptr = &runtime; + runtime.installRenewer(uuid, 1, [&] { return wall_ms; }); + const uint64_t anchor = runtime.startRenewer(); + runtime.armMountFence(uuid, 1, anchor + kExpiryTtlMs); + generation = runtime.fenceGeneration(); + + /// Renewal 1 fails 24 times and then lands stale (put 25); renewal 2 restores (put 26). Renewal 3 + /// does the same over puts 27 to 52. Puts `kExpiryObservedPut` and 48 are sent while the lease is expired. + const auto refuse_while_expired = [&] + { + uint32_t refused = 0; + for (int i = 0; i < 3; ++i) + { + try + { + runtime_ptr->checkFenceOrThrow(generation); + } + catch (const DB::Exception &) + { + ++refused; + } + } + refused_while_expired.push_back(refused); + counted_after_refusals.push_back(eventCount(ProfileEvents::CASMountLeaseExpired) - expired_before); + }; + backend->on_put = [&](uint32_t put_no) + { + if (put_no == kExpiryObservedPut || put_no == 48) + refuse_while_expired(); + const bool failing = put_no <= kExpiryFailedPuts + || (put_no > kExpiryFailedPuts + 2 && put_no <= 2 * kExpiryFailedPuts + 2); + if (failing) + boot_ms.fetch_add(kExpiryFailedPutMs); + return failing; + }; + + runtime.startBackgroundWorkers(std::chrono::milliseconds(kExpiryPeriodMs)); + last_pass.waitUntilArrived(); + last_pass.release(); + runtime.stopBackgroundWorkers(); + runtime.finishTeardown(false); + + /// Passes 2 to 5: after the first stale success, the first restore, the second stale success and the + /// second restore. + EXPECT_EQ(counted_at_pass, (std::vector{0, 1, 1, 2})); + EXPECT_EQ(refused_while_expired, (std::vector{3, 3})) << "the lease was expired for both batches of refusals"; + EXPECT_EQ(counted_after_refusals, (std::vector{0, 1})) << "a refused write is not a restore"; +} + +/// An expiry that ends because GC fenced the mount out is a loss, not a restore: nothing is counted. +TEST(CASMountRuntime, AnExpiryEndedByAFenceIsNotCountedAsARestore) +{ + const Layout layout("runtime-expiry-fenced"); + const UInt128 uuid{1}; + uint64_t wall_ms = 1000; + std::atomic boot_ms{kExpiryClaimBootMs}; + uint32_t loop_passes = 0; + DB::Cas::tests::ManualBarrier remount_entered; + const uint64_t expired_before = eventCount(ProfileEvents::CASMountLeaseExpired); + CasEventSink sink; + auto backend = std::make_shared(); + + ASSERT_EQ(claimMount(*DB::Cas::tests::OperationForTest(backend), layout, "test", uuid, 1, wall_ms, kExpiryTtlMs).kind, + MountClaimResult::Claimed); + + RuntimeUnderTest runtime_holder( + backend, layout, + MountConfig{ + .mount_lease_ttl_ms = std::chrono::milliseconds(kExpiryTtlMs), + .background_watermark = true, + .boot_ms_fn = [&] { return boot_ms.load(); }, + .renewal_before_driver_lock_hook_for_test = [&] + { + ++loop_passes; + if (loop_passes == 1) + boot_ms.store(kExpiryFirstStartBootMs); + else if (loop_passes == 2) + fenceOutMount(*backend, layout.mountKey("test")); + }}, + "test", sink, runtimeRenewBudget(), [&] + { + remount_entered.arriveAndWait(); + return false; + }); + CasMountRuntime & runtime = *runtime_holder; + runtime.installRenewer(uuid, 1, [&] { return wall_ms; }); + const uint64_t anchor = runtime.startRenewer(); + runtime.armMountFence(uuid, 1, anchor + kExpiryTtlMs); + /// The first renewal lands stale, so the lease is still expired when GC fences the slot out; the + /// next renewal meets the fence. + backend->on_put = [&](uint32_t put_no) + { + const bool failing = put_no <= kExpiryFailedPuts; + if (failing) + boot_ms.fetch_add(kExpiryFailedPutMs); + return failing; + }; + + runtime.startBackgroundWorkers(std::chrono::milliseconds(kExpiryPeriodMs)); + remount_entered.waitUntilArrived(); + + EXPECT_EQ(runtime.lifecycle(), PoolLifecycle::TransientNotLive); + EXPECT_FALSE(runtime.leaseExpiredSinceBootMs().has_value()) << "a fenced mount is not an expired one"; + EXPECT_EQ(eventCount(ProfileEvents::CASMountLeaseExpired) - expired_before, 0u); + + remount_entered.release(); + runtime.stopBackgroundWorkers(); + runtime.finishTeardown(false); +} diff --git a/src/Disks/tests/gtest_cas_requests.cpp b/src/Disks/tests/gtest_cas_requests.cpp index 81086f27f433..26011ea2bd11 100644 --- a/src/Disks/tests/gtest_cas_requests.cpp +++ b/src/Disks/tests/gtest_cas_requests.cpp @@ -34,6 +34,7 @@ #include +#include #include #include #include @@ -579,6 +580,58 @@ TEST(CASRetry, BindSaturatesAndLeavesAnEqualLeaseOffTheLeaseSource) EXPECT_TRUE(lease.lease_bound); } +TEST(CASRetrySpacing, SpacedPauseWaitsOutTheRestOfTheDraw) +{ + EXPECT_EQ(Retry::spacedPause(1'000, 5'000, 5'000), 1'000u); /// failed at once + EXPECT_EQ(Retry::spacedPause(1'000, 5'000, 5'300), 700u); + EXPECT_EQ(Retry::spacedPause(1'000, 5'000, 6'000), 0u); /// took exactly the draw + EXPECT_EQ(Retry::spacedPause(1'000, 5'000, 10'000), 0u); /// took longer: retried at once + /// A sample before the start counts as no time taken, so the wait is never shortened by it. + EXPECT_EQ(Retry::spacedPause(1'000, 5'000, 4'000), 1'000u); +} + +TEST(CASRetrySpacing, DrawIsWithinAFifthOfTheSpacing) +{ + bool low = false; + bool high = false; + for (int i = 0; i < 2'000; ++i) + { + const uint64_t draw = Retry::drawSpacing(1'000); + ASSERT_GE(draw, 800u); + ASSERT_LE(draw, 1'200u); + low = low || draw < 850; + high = high || draw > 1'150; + } + /// The bounds alone cannot tell a draw from a constant, so both ends must be reached. + EXPECT_TRUE(low); + EXPECT_TRUE(high); + EXPECT_EQ(Retry::drawSpacing(0), 0u); + constexpr uint64_t largest = std::numeric_limits::max(); + EXPECT_GE(Retry::drawSpacing(largest), largest - largest / 5) << "the top of the range must not wrap"; +} + +TEST(CASRetrySpacing, UntilDefinitiveHasNoWindowNoLeaseAndASpacing) +{ + constexpr uint64_t largest = std::numeric_limits::max(); + const Retry policy = Retry::untilDefinitive(1'000); + EXPECT_EQ(policy.window_ms, largest); + EXPECT_FALSE(policy.lease_deadline_ms.has_value()); + EXPECT_FALSE(policy.single_attempt); + EXPECT_FALSE(policy.policy_deadline_ms.has_value()); + EXPECT_EQ(policy.attempt_spacing_ms, std::optional(1'000)); + for (const uint64_t now : {uint64_t{0}, uint64_t{1}, uint64_t{1'000'000}, largest - 1, largest}) + { + const Retry::Bound bound = policy.bind(now); + EXPECT_EQ(bound.deadline_ms, largest) << "now " << now; + EXPECT_FALSE(bound.lease_bound) << "now " << now; + } + /// Every other policy keeps the engine's own backoff. + EXPECT_FALSE(Retry::standard().attempt_spacing_ms.has_value()); + EXPECT_FALSE(Retry::within(1'000).attempt_spacing_ms.has_value()); + EXPECT_FALSE(Retry::once().attempt_spacing_ms.has_value()); + EXPECT_FALSE(Retry::untilLeaseSafe(2'000'000, 2'000).attempt_spacing_ms.has_value()); +} + TEST(CASRequests, CreateThenReplaceThenRemove) { FakeClock clock; @@ -692,6 +745,134 @@ TEST(CASRequests, AmbiguousCreateThatNeverLandedIsReissued) EXPECT_EQ(clock.sleeps.size(), 1u); } +/// The observer hears of each physical write attempt when it is sent, and of each one that throws. +TEST(CASRequests, RequestObserverSeesEachPutAndEachFailure) +{ + FakeClock clock; + auto backend = std::make_shared(); + backend->injectAmbiguousWrite("k"); + auto requests = makeRequests(backend, clock); + auto op = requests.admit(); + std::vector> seen; + op.setRequestObserver([&](uint32_t attempt_no, const std::exception * failure) + { + seen.emplace_back(attempt_no, failure != nullptr); + }); + + WriteResult result = op.create("k", "v", Retry::standard()); + + ASSERT_TRUE(std::holds_alternative(result)); + const std::vector> expected{{1, false}, {1, true}, {2, false}}; + EXPECT_EQ(seen, expected); +} + +/// A deterministic local failure is reported before it propagates unchanged. +TEST(CASRequests, RequestObserverSeesADeterministicFailureBeforeItPropagates) +{ + FakeClock clock; + auto backend = std::make_shared(); + backend->failNextWriteWith("k", std::make_exception_ptr(DB::Exception( + DB::ErrorCodes::CORRUPTED_DATA, "injected deterministic failure"))); + auto requests = makeRequests(backend, clock); + auto op = requests.admit(); + std::vector> seen; + op.setRequestObserver([&](uint32_t attempt_no, const std::exception * failure) + { + const auto * db_failure = dynamic_cast(failure); + seen.emplace_back(attempt_no, failure == nullptr ? 0 : (db_failure ? db_failure->code() : -1)); + }); + + expectThrowsCode(DB::ErrorCodes::CORRUPTED_DATA, [&] { (void)op.create("k", "v", Retry::standard()); }); + + const std::vector> expected{{1, 0}, {1, DB::ErrorCodes::CORRUPTED_DATA}}; + EXPECT_EQ(seen, expected); +} + +/// A refused precondition is the store's answer, not a failed request. +TEST(CASRequests, RequestObserverIsNotToldOfARefusedPrecondition) +{ + FakeClock clock; + auto backend = std::make_shared(); + backend->refuseNextWrite("k"); + auto requests = makeRequests(backend, clock); + auto op = requests.admit(); + std::vector> seen; + op.setRequestObserver([&](uint32_t attempt_no, const std::exception * failure) + { + seen.emplace_back(attempt_no, failure != nullptr); + }); + + WriteResult result = op.create("k", "v", Retry::standard()); + + EXPECT_TRUE(std::holds_alternative(result)); + const std::vector> expected{{1, false}}; + EXPECT_EQ(seen, expected); +} + +/// Each failed resolve read is reported with the count of `PUT`s sent so far; the read that succeeds is not. +TEST(CASRequests, RequestObserverSeesEachFailedResolveRead) +{ + FakeClock clock; + auto backend = std::make_shared(); + backend->injectAmbiguousWrite("k"); + backend->failNextReadWith("k", std::make_exception_ptr(Poco::TimeoutException("injected read failure"))); + backend->failNextReadWith("k", std::make_exception_ptr(Poco::TimeoutException("injected read failure"))); + auto requests = makeRequests(backend, clock); + auto op = requests.admit(); + std::vector> seen; + op.setRequestObserver([&](uint32_t attempt_no, const std::exception * failure) + { + seen.emplace_back(attempt_no, failure != nullptr); + }); + + WriteResult result = op.create("k", "v", Retry::standard()); + + ASSERT_TRUE(std::holds_alternative(result)); + /// PUT 1 sent, PUT 1 failed, two failed reads, PUT 2 sent. + const std::vector> expected{{1, false}, {1, true}, {1, true}, {1, true}, {2, false}}; + EXPECT_EQ(seen, expected); +} + +/// A read the caller issues itself is not a resolve read and is not reported. +TEST(CASRequests, RequestObserverIsNotToldOfACallersOwnRead) +{ + FakeClock clock; + auto backend = std::make_shared(); + backend->failNextReadWith("k", std::make_exception_ptr(Poco::TimeoutException("injected read failure"))); + auto requests = makeRequests(backend, clock); + auto op = requests.admit(); + uint32_t calls = 0; + op.setRequestObserver([&](uint32_t, const std::exception *) { ++calls; }); + + EXPECT_FALSE(op.read("k", Retry::standard()).has_value()); + + EXPECT_EQ(calls, 0u); +} + +/// An observer that throws on every call changes neither the verdict nor the requests sent. +TEST(CASRequests, ThrowingRequestObserverChangesNothing) +{ + FakeClock clock; + auto backend = std::make_shared(); + backend->injectAmbiguousWrite("k"); + auto requests = makeRequests(backend, clock); + auto op = requests.admit(); + uint32_t calls = 0; + op.setRequestObserver([&](uint32_t, const std::exception *) + { + ++calls; + throw std::runtime_error("injected observer failure"); + }); + + WriteResult result = op.create("k", "v", Retry::standard()); + + const auto * committed = std::get_if(&result); + ASSERT_NE(committed, nullptr); + EXPECT_EQ(committed->attempts_sent, 2u); + EXPECT_EQ(backend->getTotal(), 1u); + EXPECT_EQ(calls, 3u); +} + /// The engine's own attempt number reaches the transport through `TransportAccess::attemptNo()`, for /// every primitive -- write, read (the resolve read is its own call, with its own attempt count) and /// list. @@ -2947,6 +3128,407 @@ TEST(CASRequestsFuse, ReadRefreshedCredentialTextDoesNotDoubleCountTheFuse) EXPECT_EQ(ProfileEvents::global_counters[ProfileEvents::CASRequestFirstAttemptFuse].load() - fuses_before, 0u); } +namespace +{ + +/// A store whose requests each take `duration_ms` of the injected clock and fail as `fault` says. +/// Every request is logged with the instant it started. +class TimedFaultBackend : public InMemoryBackend +{ +public: + enum class Verb : uint8_t { Put, Get }; + struct Sent + { + Verb verb; + uint64_t started_ms; + }; + /// The exception the request fails with, or null to serve it. `nth` counts requests of `verb` from 1. + using Fault = std::function; + + explicit TimedFaultBackend(FakeClock & clock_) : clock(clock_) {} + + std::optional read(const String & key, DB::Cas::TransportAccess & access) override + { + begin(Verb::Get); + return InMemoryBackend::read(key, access); + } + + std::expected write(const String & key, const String & bytes, + const std::optional & expected_value, + DB::Cas::TransportAccess & access) override + { + begin(Verb::Put); + return InMemoryBackend::write(key, bytes, expected_value, access); + } + + std::vector startsOf(Verb verb) const + { + std::vector starts; + for (const Sent & request : sent) + if (request.verb == verb) + starts.push_back(request.started_ms); + return starts; + } + + Fault fault; + uint64_t duration_ms = 0; + std::vector sent; + +private: + void begin(Verb verb) + { + const uint64_t started = clock.now.load(); + const size_t nth = 1 + static_cast(std::count_if(sent.begin(), sent.end(), + [&](const Sent & request) { return request.verb == verb; })); + sent.push_back({verb, started}); + clock.now.fetch_add(duration_ms); + if (auto error = fault ? fault(verb, nth, started) : nullptr) + std::rethrow_exception(error); + } + + FakeClock & clock; +}; + +using Verb = TimedFaultBackend::Verb; + +/// A transport failure that is neither a connect-failure hint nor a first-attempt fuse. +std::exception_ptr ordinaryFault() +{ + return std::make_exception_ptr(DB::S3Exception( + "Poco::Exception. Code: 1000, e.code() = 104, Connection reset by peer", Aws::S3::S3Errors::NETWORK_CONNECTION)); +} + +constexpr uint64_t kSpacingMs = 1'000; + +/// Creates `k` and forgets the requests that did it. +Etag seedK(TimedFaultBackend & backend, CasOperation & op) +{ + const Etag seen = *orThrow(op.create("k", "v1", Retry::standard()), "seed"); + backend.sent.clear(); + return seen; +} + +} + +/// A `bind` whose deadline wrapped at the top of the clock would refuse the first request; the only +/// legitimate refusal is a request whose two envelopes no longer fit before the clock ends. +TEST(CASRequestsSpacing, UntilDefinitiveRefusesNothingBeforeTheEndOfTheClock) +{ + constexpr uint64_t largest = std::numeric_limits::max(); + FakeClock clock; + clock.now = largest - 20'000; + auto backend = std::make_shared(clock); + backend->fault = [](Verb verb, size_t, uint64_t) -> std::exception_ptr + { + return verb == Verb::Put ? connectHint() : nullptr; + }; + auto requests = makeRequests(backend, clock); + requests.setAttemptReservationForTest(7'000); + auto op = requests.admit(); + + const WriteResult result = op.create("k", "v", Retry::untilDefinitive(kSpacingMs)); + + const auto * gave_up = std::get_if(&result); + ASSERT_NE(gave_up, nullptr); + EXPECT_EQ(gave_up->why, GaveUp::Why::Deadline); + EXPECT_EQ(gave_up->deadline_source, GaveUp::Source::Policy); + EXPECT_TRUE(gave_up->sent_any); + const auto puts = backend->startsOf(Verb::Put); + ASSERT_GE(puts.size(), 2u); + EXPECT_EQ(puts.front(), largest - 20'000); + EXPECT_LE(puts.back(), largest - 14'000) << "every PUT was admitted with room for its two envelopes"; +} + +/// A hinted PUT is reissued without a read, every reissue starts one draw +/// after the previous one started, and the call is still retrying after 30 s. +TEST(CASRequestsSpacing, FastConnectFailuresAreSpacedFromTheirStart) +{ + FakeClock clock; + auto backend = std::make_shared(clock); + auto requests = makeRequests(backend, clock); + auto op = requests.admit(); + const Etag seen = seedK(*backend, op); + const uint64_t t0 = clock.now; + backend->fault = [t0](Verb verb, size_t nth, uint64_t started) -> std::exception_ptr + { + if (verb != Verb::Put) + return nullptr; + if (nth == 1) + return fuseTimeout(); + return started < t0 + 30'000 ? connectHint() : nullptr; + }; + + const WriteResult result = op.replace("k", "v2", seen, Retry::untilDefinitive(kSpacingMs)); + + const auto * committed = std::get_if(&result); + ASSERT_NE(committed, nullptr); + const auto puts = backend->startsOf(Verb::Put); + ASSERT_GE(puts.size(), 3u); + EXPECT_EQ(committed->attempts_sent, puts.size()); + EXPECT_GE(puts.back(), t0 + 30'000) << "the call must still be retrying after 30 s"; + /// The fuse: its settle read and its reissue both follow at once. + EXPECT_EQ(backend->sent[1].verb, Verb::Get); + EXPECT_EQ(backend->sent[1].started_ms, t0); + EXPECT_EQ(puts[1], t0); + EXPECT_EQ(backend->startsOf(Verb::Get).size(), 1u) << "a hinted PUT is reissued without a read"; + uint64_t min_gap = std::numeric_limits::max(); + uint64_t max_gap = 0; + for (size_t i = 2; i < puts.size(); ++i) + { + min_gap = std::min(min_gap, puts[i] - puts[i - 1]); + max_gap = std::max(max_gap, puts[i] - puts[i - 1]); + } + EXPECT_GE(min_gap, 800u); + EXPECT_LE(max_gap, 1'200u); + EXPECT_EQ(clock.sleeps.size(), puts.size() - 2) << "one sleep per hinted reissue, none for the fuse"; +} + +/// The read after an unclear PUT is sent at once, the read's own fuse is +/// reissued at once, and the retries of the read and of the PUT are spaced. +TEST(CASRequestsSpacing, TheResolveReadFollowsAtOnceAndItsRetriesAreSpaced) +{ + FakeClock clock; + auto backend = std::make_shared(clock); + auto requests = makeRequests(backend, clock); + auto op = requests.admit(); + const Etag seen = seedK(*backend, op); + const uint64_t t0 = clock.now; + backend->fault = [t0](Verb verb, size_t nth, uint64_t started) -> std::exception_ptr + { + if (verb == Verb::Put) + return started < t0 + 30'000 ? ordinaryFault() : nullptr; + /// Every resolve read: a fuse, an ordinary failure, then the answer. + switch (nth % 3) + { + case 1: return fuseTimeout(); + case 2: return ordinaryFault(); + default: return nullptr; + } + }; + + const WriteResult result = op.replace("k", "v2", seen, Retry::untilDefinitive(kSpacingMs)); + + ASSERT_TRUE(std::holds_alternative(result)); + const auto & sent = backend->sent; + const auto puts = backend->startsOf(Verb::Put); + ASSERT_GE(puts.size(), 2u); + EXPECT_GE(puts.back(), t0 + 30'000) << "the call must still be retrying after 30 s"; + ASSERT_EQ(sent.size(), puts.size() + 3 * (puts.size() - 1)) << "three reads per failed PUT"; + bool at_once = true; + uint64_t min_spaced = std::numeric_limits::max(); + uint64_t max_spaced = 0; + for (size_t p = 0; p + 1 < puts.size(); ++p) + { + const size_t i = 4 * p; /// this PUT, then its three reads, then the next PUT + ASSERT_EQ(sent[i].verb, Verb::Put); + ASSERT_EQ(sent[i + 1].verb, Verb::Get); + ASSERT_EQ(sent[i + 2].verb, Verb::Get); + ASSERT_EQ(sent[i + 3].verb, Verb::Get); + at_once = at_once && sent[i + 1].started_ms == sent[i].started_ms + && sent[i + 2].started_ms == sent[i + 1].started_ms; + for (const uint64_t gap : {sent[i + 3].started_ms - sent[i + 2].started_ms, sent[i + 4].started_ms - sent[i].started_ms}) + { + min_spaced = std::min(min_spaced, gap); + max_spaced = std::max(max_spaced, gap); + } + } + EXPECT_TRUE(at_once) << "the read follows its PUT at once, and the read's fuse is reissued at once"; + EXPECT_GE(min_spaced, 800u); + EXPECT_LE(max_spaced, 1'200u); +} + +/// A request that takes 5 s on the injected clock is followed by the next one +/// with no wait, for the read and for the PUT; the PUT's own fuse reissue does not sleep at all. +TEST(CASRequestsSpacing, ARequestThatTookLongerThanTheSpacingIsRetriedAtOnce) +{ + FakeClock clock; + auto backend = std::make_shared(clock); + auto requests = makeRequests(backend, clock); + auto op = requests.admit(); + const Etag seen = seedK(*backend, op); + backend->duration_ms = 5'000; + const uint64_t t0 = clock.now; + backend->fault = [t0](Verb verb, size_t nth, uint64_t started) -> std::exception_ptr + { + if (verb == Verb::Put) + { + if (nth == 1) + return fuseTimeout(); + return started < t0 + 60'000 ? ordinaryFault() : nullptr; + } + return nth % 2 == 1 ? ordinaryFault() : nullptr; + }; + + const WriteResult result = op.replace("k", "v2", seen, Retry::untilDefinitive(kSpacingMs)); + + ASSERT_TRUE(std::holds_alternative(result)); + const auto & sent = backend->sent; + bool back_to_back = true; + for (size_t i = 1; i < sent.size(); ++i) + back_to_back = back_to_back && sent[i].started_ms == sent[i - 1].started_ms + 5'000; + EXPECT_TRUE(back_to_back) << "every request starts when the previous one ends"; + EXPECT_EQ(backend->startsOf(Verb::Put), + (std::vector{t0, t0 + 15'000, t0 + 30'000, t0 + 45'000, t0 + 60'000})); + /// Four read retries and three PUT reissues, each a zero-length sleep; the fuse reissue none. + EXPECT_EQ(clock.sleeps, std::vector(7, 0)); +} + +/// The worst case for request rate: every PUT is unclear and every resolve read hits its fuse and then +/// a failure before it answers. The fuse and the read after a PUT are immediate, so the bound comes from +/// the spacing alone: at most two PUT periods of 4 requests start in any second. +TEST(CASRequestsSpacing, AnUnclearPutWithAFailingReadStaysUnderEightRequestsPerSecond) +{ + FakeClock clock; + auto backend = std::make_shared(clock); + auto requests = makeRequests(backend, clock); + auto op = requests.admit(); + const Etag seen = seedK(*backend, op); + const uint64_t t0 = clock.now; + constexpr uint64_t outage_ms = 60'000; + backend->fault = [t0](Verb verb, size_t nth, uint64_t started) -> std::exception_ptr + { + if (verb == Verb::Put) + return started < t0 + outage_ms ? fuseTimeout() : nullptr; /// a fuse on attempt 1, an ordinary timeout after + switch (nth % 3) + { + case 1: return fuseTimeout(); + case 2: return ordinaryFault(); + default: return nullptr; + } + }; + + const WriteResult result = op.replace("k", "v2", seen, Retry::untilDefinitive(kSpacingMs)); + + ASSERT_TRUE(std::holds_alternative(result)); + const auto & sent = backend->sent; + ASSERT_FALSE(sent.empty()); + EXPECT_GE(sent.back().started_ms, t0 + outage_ms); + std::vector per_second((sent.back().started_ms - t0) / 1'000 + 1, 0); + for (const auto & request : sent) + ++per_second[(request.started_ms - t0) / 1'000]; + EXPECT_LE(*std::max_element(per_second.begin(), per_second.end()), 8u); + EXPECT_LE(sent.size(), 4 * (outage_ms / 800 + 2)) << "at most 4 requests per 800 ms period"; +} + +TEST(CASRequestsSpacing, ACredentialRefreshReissueIsSpaced) +{ + FakeClock clock; + auto backend = std::make_shared(); + backend->setRefreshCredentialsResult(true); + backend->failNextWriteWith("k", s3Error(Aws::S3::S3Errors::INVALID_CLIENT_TOKEN_ID, "ExpiredToken")); + auto requests = makeRequests(backend, clock); + auto op = requests.admit(); + + const WriteResult result = op.create("k", "v", Retry::untilDefinitive(kSpacingMs)); + + const auto * committed = std::get_if(&result); + ASSERT_NE(committed, nullptr); + EXPECT_EQ(committed->attempts_sent, 2u); + EXPECT_EQ(backend->getTotal(), 0u) << "the credential answer owes no read"; + EXPECT_EQ(backend->refreshCredentialsCalls(), 1u); + ASSERT_EQ(clock.sleeps.size(), 1u); + EXPECT_GE(clock.sleeps[0], 800u); + EXPECT_LE(clock.sleeps[0], 1'200u); +} + +/// A spaced policy has no window, so the spacing is the only bound on a conflict loop's rate too. +TEST(CASRequestsSpacing, CleanConflictPausesAreSpacedUnderASpacedPolicy) +{ + FakeClock clock; + auto backend = std::make_shared(); + auto requests = makeRequests(backend, clock); + auto op = requests.admit(); + (void)orThrow(op.create("k", "v", Retry::standard()), "seed"); + constexpr int K = 3; + RaceMaker races(backend, clock, "k", K, /*ambiguous=*/false); + + const WriteResult result = op.readModifyWrite("k", appendX(), Retry::untilDefinitive(kSpacingMs)); + + ASSERT_TRUE(std::holds_alternative(result)); + ASSERT_EQ(clock.sleeps.size(), static_cast(K)); + for (const uint64_t pause : clock.sleeps) + { + EXPECT_GE(pause, 800u); + EXPECT_LE(pause, 1'200u); + } +} + +TEST(CASRequestsSpacing, PresenceOnlyConflictPausesAreSpacedUnderASpacedPolicy) +{ + FakeClock clock; + auto backend = std::make_shared(); + auto requests = makeRequests(backend, clock); + auto op = requests.admit(); + (void)orThrow(op.create("k", "v", Retry::standard()), "seed"); + constexpr int K = 3; + RaceMaker races(backend, clock, "k", K, /*ambiguous=*/false); + + const WriteResult result = op.readModifyWriteOnPresence("k", + [](const std::optional &) -> std::optional { return String("w"); }, Retry::untilDefinitive(kSpacingMs)); + + ASSERT_TRUE(std::holds_alternative(result)); + ASSERT_EQ(clock.sleeps.size(), static_cast(K)); + for (const uint64_t pause : clock.sleeps) + { + EXPECT_GE(pause, 800u); + EXPECT_LE(pause, 1'200u); + } +} + +TEST(CASRequestsSpacing, ARetriedReadCalledDirectlyIsSpaced) +{ + FakeClock clock; + auto backend = std::make_shared(); + auto requests = makeRequests(backend, clock); + auto op = requests.admit(); + (void)orThrow(op.create("k", "v", Retry::standard()), "seed"); + backend->failNextReadWith("k", std::make_exception_ptr(Poco::TimeoutException("injected read failure"))); + backend->failNextReadWith("k", std::make_exception_ptr(Poco::TimeoutException("injected read failure"))); + + const auto object = op.read("k", Retry::untilDefinitive(kSpacingMs)); + + ASSERT_TRUE(object.has_value()); + ASSERT_EQ(clock.sleeps.size(), 2u); + for (const uint64_t pause : clock.sleeps) + { + EXPECT_GE(pause, 800u); + EXPECT_LE(pause, 1'200u); + } +} + +/// Spacing must not leak into a policy without it: per failed PUT, the read's `backoff(1)` and then the +/// PUT's growing `backoff(n)`. +TEST(CASRequestsSpacing, AnUnspacedPolicyKeepsTheGrowingBackoff) +{ + FakeClock clock; + auto backend = std::make_shared(clock); + auto requests = makeRequests(backend, clock); + auto op = requests.admit(); + const Etag seen = seedK(*backend, op); + backend->fault = [](Verb verb, size_t nth, uint64_t) -> std::exception_ptr + { + if (verb == Verb::Put) + return nth <= 3 ? ordinaryFault() : nullptr; + return nth % 2 == 1 ? ordinaryFault() : nullptr; + }; + + const WriteResult result = op.replace("k", "v2", seen, Retry::standard()); + + const auto * committed = std::get_if(&result); + ASSERT_NE(committed, nullptr); + EXPECT_EQ(committed->attempts_sent, 4u); + const std::vector ceilings{200, 200, 200, 400, 200, 800}; + ASSERT_EQ(clock.sleeps.size(), ceilings.size()); + uint64_t total = 0; + for (size_t i = 0; i < ceilings.size(); ++i) + { + EXPECT_LE(clock.sleeps[i], ceilings[i]) << "sleep " << i; + total += clock.sleeps[i]; + } + /// Six full-jitter draws that are all zero have a probability below 1e-13; a zero-wait leak does not. + EXPECT_GT(total, 0u); +} + #endif TEST(CASRequestBudget, EnvelopeIsValidatedNotTheBareAttempt) diff --git a/src/Disks/tests/gtest_cas_s3_single_attempt_client.cpp b/src/Disks/tests/gtest_cas_s3_single_attempt_client.cpp index 30ee3192bc54..27aa62612f2f 100644 --- a/src/Disks/tests/gtest_cas_s3_single_attempt_client.cpp +++ b/src/Disks/tests/gtest_cas_s3_single_attempt_client.cpp @@ -14,18 +14,24 @@ #include #include #include +#include +#include +#include #include #include #include #include #include +#include #include #include #include #include #include #include +#include +#include #include @@ -49,6 +55,11 @@ /// The single-attempt client clone must cap its connect timeout at the value the mount froze at open, /// never at the disk's (possibly wider, possibly reloaded, possibly unbounded) own connect timeout. +namespace ProfileEvents +{ +extern const Event S3PutObject; +} + namespace { @@ -196,7 +207,8 @@ class DelayedResponseServer /// succeeds. No SDK-level retry (`RetryStrategy{.max_retries = 0}`, /// `s3_slow_all_threads_after_retryable_error = false`): a retry would blur "the single-attempt clone /// made exactly one request" into "the SDK also tried again". -std::shared_ptr makeDispatchStorageForTest(const std::string & endpoint, long base_request_timeout_ms) +template +std::shared_ptr makeDispatchStorageForTest(const std::string & endpoint, long base_request_timeout_ms) { DB::RemoteHostFilter remote_host_filter; DB::S3::PocoHTTPClientConfiguration cfg = DB::S3::ClientFactory::instance().createClientConfiguration( @@ -228,7 +240,7 @@ std::shared_ptr makeDispatchStorageForTest(const std::strin cfg.http_keep_alive_timeout = 0; auto client = DB::S3::ClientFactory::instance().create( cfg, clientSettingsForTest(), "ACCESS_KEY_ID", "SECRET_ACCESS_KEY", "", {}, {}, DB::S3::CredentialsConfiguration{}); - return std::make_shared( + return std::make_shared( std::move(client), std::make_unique(), DB::S3::URI(endpoint + "/test-bucket/"), DB::S3Capabilities{}, DB::ObjectStorageKeyGeneratorPtr{}, "disk"); @@ -239,6 +251,43 @@ DB::ContextPtr contextForTest() return getContext().context; } +/// A genuine `S3ObjectStorage` that remembers the buffer size each `writeObject` was opened with. +class BufferSizeRecordingS3ObjectStorage final : public DB::S3ObjectStorage +{ +public: + using DB::S3ObjectStorage::S3ObjectStorage; + + std::unique_ptr writeObject( + const DB::StoredObject & object, + DB::WriteMode mode, + std::optional attributes, + size_t buf_size, + const DB::WriteSettings & write_settings) override + { + opened_buffer_sizes.push_back(buf_size); + return DB::S3ObjectStorage::writeObject(object, mode, attributes, buf_size, write_settings); + } + + std::vector opened_buffer_sizes; +}; + +/// A server that accepts every `PUT` with a fixed `ETag`. +void acceptPut(Poco::Net::HTTPServerResponse & response) +{ + response.set("ETag", "\"put-etag\""); + response.setContentLength(0); + response.setStatus(Poco::Net::HTTPResponse::HTTP_OK); + response.send(); +} + +/// A writable Native backend as `openPoolView` builds one: conditional writes are single-attempt. +std::shared_ptr conditionalBackendForTest(DB::ObjectStoragePtr storage) +{ + return std::make_shared( + std::move(storage), DB::Cas::ObjectStorageBackend::Mode::Native, + /*single_attempt_control_plane_=*/true, /*attempt_timeout_ms_=*/5000, /*connect_timeout_cap_ms_=*/5000); +} + } /// Test 6c of the spec: the clone's connect cap is the MIN of the base client's own connect timeout @@ -728,4 +777,65 @@ TEST(CASEnvelopeWiring, FreezeConnectTimeoutCapReachesTheBackendOverProductionDi } } +/// A conditional `PUT` is sent by the thread that asked for it, not by the remote-FS writer pool, so a +/// memory guard the caller holds covers it. `WriteBufferFromS3` counts `S3PutObject` on the thread that +/// calls `PutObject`, and a pool thread has counters of its own. +TEST(CASBackend, ConditionalPutRunsOnTheCallingThread) +{ + (void)contextForTest(); + + DelayedResponseServer server(std::chrono::milliseconds(0), acceptPut); + auto backend = conditionalBackendForTest(makeDispatchStorageForTest(server.getUrl(), 10000)); + EXPECT_FALSE(backend->conditionalWriteSettingsForTest().s3_allow_parallel_part_upload); + + DB::Cas::CasRequests requests(DB::Cas::BackendPtr(backend), DB::Cas::Fence::open()); + bool committed = false; + uint64_t puts_on_calling_thread = 0; + std::exception_ptr failure; + ThreadFromGlobalPool caller([&] + { + try + { + const uint64_t before = DB::CurrentThread::getProfileEvents()[ProfileEvents::S3PutObject].load(); + auto op = requests.admit(); + committed = std::holds_alternative(op.create("put-key", "body", DB::Cas::Retry::once())); + puts_on_calling_thread = DB::CurrentThread::getProfileEvents()[ProfileEvents::S3PutObject].load() - before; + } + catch (...) + { + failure = std::current_exception(); + } + }); + caller.join(); + if (failure) + std::rethrow_exception(failure); + + EXPECT_TRUE(committed); + EXPECT_EQ(server.requestsSeen(), 1u); + EXPECT_EQ(puts_on_calling_thread, 1u) << "the conditional PUT was sent by another thread"; +} + +/// A conditional `PUT` opens its buffer at the body size instead of 1 MiB, and an empty body at one +/// byte, which is what `WriteBuffer::write` needs to accept zero bytes. +TEST(CASBackend, ConditionalPutBufferStartsAtTheBodySize) +{ + (void)contextForTest(); + + DelayedResponseServer server(std::chrono::milliseconds(0), acceptPut); + auto storage = makeDispatchStorageForTest(server.getUrl(), 10000); + auto backend = conditionalBackendForTest(storage); + DB::Cas::CasRequests requests(DB::Cas::BackendPtr(backend), DB::Cas::Fence::open()); + + const std::string body(37, 'b'); + { + auto op = requests.admit(); + EXPECT_TRUE(std::holds_alternative(op.create("small-key", body, DB::Cas::Retry::once()))); + } + { + auto op = requests.admit(); + EXPECT_TRUE(std::holds_alternative(op.create("empty-key", "", DB::Cas::Retry::once()))); + } + EXPECT_EQ(storage->opened_buffer_sizes, (std::vector{body.size(), 1})); +} + #endif diff --git a/src/Storages/System/StorageSystemContentAddressedMounts.cpp b/src/Storages/System/StorageSystemContentAddressedMounts.cpp index ba8b8670cc10..fb4311833d68 100644 --- a/src/Storages/System/StorageSystemContentAddressedMounts.cpp +++ b/src/Storages/System/StorageSystemContentAddressedMounts.cpp @@ -54,9 +54,9 @@ StorageSystemContentAddressedMounts::StorageSystemContentAddressedMounts(const S {"last_success_age_seconds", std::make_shared(std::make_shared()), "Seconds since this disk's GC last led a round (0 if it never led). NULL on rows describing other servers' mounts."}, {"wedged_namespace_count", std::make_shared(std::make_shared()), "Ref-append lanes currently wedged on this disk. NULL on rows describing other servers' mounts."}, {"lifecycle", std::make_shared(), "This server's content-addressed pool lifecycle for the disk (non-gated snapshot, always populated so a not-live disk stays visible): live, not_live, identity_lost, vanished, constructing (never started) or shutdown (torn down)."}, - {"lifecycle_reason", std::make_shared(), "The enum-clean sub-state word for a vanished disk: replaced or forgotten. Empty for every other lifecycle (so lifecycle || '(' || lifecycle_reason || ')' reads e.g. vanished(forgotten))."}, - {"lifecycle_detail", std::make_shared(), "The full typed reason text naming the actual cause when not live: the vanish diagnosis (data root replaced by a foreign pool / decommissioned by SYSTEM CAS FORGET at