Skip to content

Commit 5aced16

Browse files
committed
fix(auditdb): align auditor EID locker semantics across backends
The auditor takes short-lived locks on the enrollment IDs a request touches, through a Locker chosen from configuration: memory for a single replica, postgres for a cluster. The two were not interchangeable, so the same auditor code was correct on one deployment and broken on the other. The Locker interface now documents the contract its implementations are held to — it had none, which is how they drifted — and locker/conformance_test.go exercises every expectation against both backends. The three findings in #2040: - AssertLocksHeld detects lost locks, not absent ones. An anchor holding nothing succeeds, so a request whose inputs and outputs yield no enrollment IDs can be appended under postgres too, as can an auditor that validates and appends without calling Audit (the dvp and nft views). - The memory locker keeps enrollment-ID semaphores and per-anchor bookkeeping in separate maps. One shared sync.Map, keyed by unconstrained strings of unrelated provenance, let an anchor equal to an enrollment ID return the other namespace's value type and panic on the assertion. - The auditor's retry no longer nests inside the locker's own waiting budget: ErrLockAcquireTimeout is final, so worst-case blocking for one audit is acquireDeadline rather than MaxRetries times it. The inner poll loop is exponential and jittered instead of a flat 100ms, which cuts round trips from hundreds to a few dozen and stops contending replicas retrying in lockstep. And the defects that aligning them surfaced: - A live anchor's EID set may shrink or stay the same, never grow. Deadlock freedom rests on taking shared IDs in one canonical order, and that order only covers the IDs of a single call, so an anchor that kept earlier locks while waiting for new ones held locks outside it: two anchors widening into each other's IDs waited on each other forever, and permanently, since the anchor's lock is held across the blocking acquire and so blocked the release that would have broken the cycle. Widening now fails with ErrLockSetWidened. - Postgres releases the leases a narrowing re-acquisition drops. Its upsert only inserted, and both AssertLocksHeld and the heartbeat require an exact row count per anchor, so each leftover row rejected the next write, killed the heartbeat, and then expired into another replica's hands. - unlockAnchor no longer decides eviction from an emptiness flag sampled before the anchor's lock was released, which let an anchor still holding permits be dropped and those permits be stranded for the process lifetime. - Each backend bounds its own waiting, so a caller that passes no deadline still gets an answer and a spent budget is reported as ErrLockAcquireTimeout. - Failure classification is based on whether an attempt actually lost a race for an ID, not on which context expired first. The underlying error is joined in, so a database outage is reported as itself; a caller's own cancellation on a free ID is not a conflict; a locker's own expired budget is retriable while the caller's context is live; and only ErrLockContention counts towards auditor_audit_lock_conflicts_total. - releaseAnchor detaches from the caller's context so a deferred release on an already-cancelled context still runs, and bounds itself so a stuck DELETE cannot outlive the deadline AcquireLocks promises. A failed re-acquisition no longer releases an anchor that already holds a live session. Fixes #2040 Signed-off-by: AkramBitar <akram@il.ibm.com>
1 parent 3552482 commit 5aced16

20 files changed

Lines changed: 2228 additions & 161 deletions

File tree

docs/configuration.md

Lines changed: 31 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -319,13 +319,30 @@ token:
319319
# "memory" – in-process mutex (default, single-replica only)
320320
# "postgres" – PostgreSQL lease-table (multi-replica)
321321
backend: memory
322+
# memory section is read only when backend == "memory".
323+
memory:
324+
# acquireDeadline bounds how long one acquisition waits for an EID held
325+
# by another anchor. Every backend bounds its own waiting so that a
326+
# caller which passes no deadline still gets an answer, and so that
327+
# spending the whole budget can be reported as such; auditor.lock does
328+
# not retry an acquisition that already exhausted it. Defaults to the
329+
# same 1m as the postgres backend, so switching backends does not
330+
# silently change how long an audit can block.
331+
acquireDeadline: 1m
322332
# postgres section is read only when backend == "postgres".
323333
postgres:
324334
# ttl is the lease duration for each EID lock row.
325335
ttl: 30s
326-
# acquireBackoff is the wait between retry attempts when a lock is contended.
336+
# acquireBackoff is the initial wait between retry attempts when a lock
337+
# is contended. Successive waits grow exponentially and are jittered,
338+
# so this is the floor rather than a fixed poll interval.
327339
acquireBackoff: 100ms
328-
# acquireDeadline is the total time allowed to acquire all EID locks.
340+
# acquireMaxBackoff caps that growth. Raised to acquireBackoff if set
341+
# below it.
342+
acquireMaxBackoff: 2s
343+
# acquireDeadline is the total time allowed to acquire all EID locks,
344+
# and the whole budget for waiting out contention: auditor.lock does
345+
# not retry an acquisition that already exhausted it.
329346
acquireDeadline: 1m
330347
# heartbeat is the interval at which held leases are renewed (~TTL/3).
331348
heartbeat: 10s
@@ -810,6 +827,14 @@ Default values:
810827
- **backoffMultiplier**: Factor by which the backoff delay increases after each retry (exponential growth)
811828
- **jitterFactor**: Randomization factor (0.0 to 1.0) added to backoff delays to prevent multiple auditors from retrying simultaneously (prevents thundering herd problem)
812829

830+
**Relationship to `auditor.locker`:** this retry covers failures that another attempt
831+
might survive, such as a transient database error. It deliberately does **not** retry
832+
an acquisition that failed with `ErrLockAcquireTimeout`, because that means the locker
833+
already spent its own `acquireDeadline` waiting out the contention — retrying would
834+
spend it again. Waiting under contention is configured once, in
835+
[`auditor.locker`](#optional-tokentmsauditorlocker), so `maxRetries` here does not
836+
multiply `acquireDeadline` there.
837+
813838
**Tuning Recommendations:**
814839

815840
1. **For High-Contention Environments:**
@@ -924,6 +949,7 @@ token:
924949
postgres:
925950
ttl: 30s
926951
acquireBackoff: 100ms
952+
acquireMaxBackoff: 2s
927953
acquireDeadline: 1m
928954
heartbeat: 10s
929955
owner:
@@ -933,8 +959,9 @@ Default values:
933959

934960
- backend: `memory` (in-process mutex, single-replica only)
935961
- postgres.ttl: 30s
936-
- postgres.acquireBackoff: 100ms
937-
- postgres.acquireDeadline: 1m
962+
- postgres.acquireBackoff: 100ms (initial wait; grows exponentially, jittered)
963+
- postgres.acquireMaxBackoff: 2s (cap on that growth; raised to `acquireBackoff` if set below it)
964+
- postgres.acquireDeadline: 1m (the whole budget for waiting out contention)
938965
- postgres.heartbeat: 10s
939966
- postgres.owner: empty, defaults to the FSC node ID (`config.Provider.ID()`). Required
940967
when `backend: postgres` — if both this value and `fsc.id` are empty or blank, the

docs/services/auditor.md

Lines changed: 40 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -83,6 +83,37 @@ When multiple auditor replicas share the same AuditDB (PostgreSQL), concurrent p
8383

8484
The locker is injected into `auditdb.StoreService` at startup. Before appending audit records, the store calls `AssertLocksHeld` to verify leases are still valid.
8585

86+
Both backends implement the same contract, defined on the `Locker` interface, because the backend is chosen from configuration — a behavioural difference between them would be a correctness difference between two deployments running the same code. The shared expectations are exercised against every backend by `locker/conformance_test.go`.
87+
88+
**`AssertLocksHeld` detects lost locks, not absent ones.** It fails only when a lease this replica held has since expired or been taken over. An anchor that holds nothing succeeds — whether because the request yielded no enrollment IDs, or because the caller never locked anything for it. The latter is a supported flow: an auditor may call `Validate` (which takes no locks) and then `Append`, as the dvp and nft sample views do.
89+
90+
**`AcquireLocks` is all-or-nothing, and never gives up ground.** A failed call holds none of the EIDs it had reached for, and leaves untouched whatever the anchor already held from an earlier successful call. Acquiring an *empty* set is a successful acquisition of nothing — it must not, and does not, release what the anchor is already holding.
91+
92+
**Re-acquiring a live anchor may shrink its EID set, never grow it.** A refresh keeps the EIDs still named and releases the ones dropped from the set; naming an EID the anchor does not already hold fails with `ErrLockSetWidened`. That restriction is what keeps the lockers deadlock-free. Deadlock freedom rests on every caller taking shared EIDs in one canonical order, and that order can only be imposed over the EIDs of a single call — an anchor that keeps earlier locks while waiting for new ones is holding locks outside it, so two anchors widening into each other's EIDs wait on each other indefinitely. `Audit` acquires once per anchor and releases when done, so no caller needs to widen.
93+
94+
**Each backend bounds its own waiting.** A caller that passes no deadline still gets an answer: the Postgres backend stops after `acquireDeadline`, and the in-memory backend after its own `acquireDeadline`. Without a budget of its own a backend could only ever stop when the caller's context did, and could never report `ErrLockAcquireTimeout` — the signal `auditor.Service` reads to tell "already waited in full" from "worth another attempt".
95+
96+
**Release always runs.** `ReleaseLocks` is idempotent, safe on an anchor that never acquired anything, and safe to `defer`. Its statement is deliberately detached from the caller's context, since the usual case is a deferred release on a context that is already cancelled and a skipped release would leave the EIDs locked against every replica until the lease TTL expired. It carries its own short internal deadline so a stuck release cannot outlive the call that issued it.
97+
98+
### Error classification
99+
100+
Callers act on the outcome of a failed acquisition, so both backends classify it the same way:
101+
102+
| Outcome | Sentinels | Meaning |
103+
|---------|-----------|---------|
104+
| Another anchor holds an EID and the waiting budget ran out | `ErrLockContention` + `ErrLockAcquireTimeout` | A real conflict, already waited out in full; retrying only adds delay |
105+
| Another anchor holds an EID, but a transient failure or a cancelled caller ended the wait | `ErrLockContention` | A real conflict, not yet waited out; a later attempt may succeed |
106+
| The caller cancelled or ran out of time while nothing held the EIDs | neither (plain context error) | Not a conflict, and not counted as one |
107+
| The backend's own waiting budget elapsed while nothing held the EIDs | neither (plain context error) | Not a conflict; worth retrying while the caller's context is still live |
108+
| The anchor asked for an EID it does not already hold | `ErrLockSetWidened` | A caller error, not a conflict: every attempt reproduces it |
109+
| The database failed | neither; the underlying error is preserved | An infrastructure fault, reported as itself rather than as contention |
110+
111+
The distinction is drawn from whether an attempt actually lost a race for an EID — not from which context expired first. `acquireDeadline` defaults to a minute, so a request-scoped caller context is almost always the shorter of the two, and keying off it would mean the Postgres backend hardly ever reported contention in production.
112+
113+
Only the two `ErrLockContention` rows count towards `auditor_audit_lock_conflicts_total`. The rows that are not conflicts are not counted as ones, so a graceful-shutdown cancellation or a database outage does not inflate the metric operators alert on for contention.
114+
115+
Whether another attempt is worth making is read from the caller's context rather than from the error, because the two rows carrying a plain context error are indistinguishable by the error alone: the caller having given up is final, whereas the backend's own budget elapsing is exactly the transient case `auditor.lock` exists to retry. See `isRetriableLockError`.
116+
86117
### Configuration
87118

88119
Configure under `token.tms.<name>.auditor.locker` (see [Configuration](../configuration.md#optional-tokentmsauditorlocker)):
@@ -96,8 +127,9 @@ token:
96127
backend: postgres # use "memory" (default) for single replica
97128
postgres:
98129
ttl: 30s
99-
acquireBackoff: 100ms
100-
acquireDeadline: 1m
130+
acquireBackoff: 100ms # initial wait; grows exponentially, jittered
131+
acquireMaxBackoff: 2s # cap on that growth
132+
acquireDeadline: 1m # whole budget for waiting out contention
101133
heartbeat: 10s
102134
owner: # required; defaults to the FSC node ID
103135
```
@@ -113,6 +145,12 @@ The Postgres backend creates an `eid_leases` table (prefixed per TMS persistence
113145

114146
**Lease ownership:** each row is keyed by EID and carries the holding replica (`owner`) plus the request it was taken for (`anchor`). An acquisition may only take over an existing row when the lease has expired, or when the row is the same replica's lease for the *same* anchor — a re-acquisition, which just refreshes the deadline. Two different anchors therefore never hold the same EID at once, including two concurrent audits on a single replica; the second one is contended and retried until `acquireDeadline`.
115147

148+
### Waiting under contention
149+
150+
`acquireDeadline` is the **entire** budget for waiting out a contended EID, and one layer does the waiting. Within it, the locker retries the atomic acquisition starting at `acquireBackoff`, doubling up to `acquireMaxBackoff`, with jitter on every sleep. The jitter matters as much as the growth: a fixed interval is identical on every replica, so contenders retry in lockstep and keep colliding, and at the defaults it also costs one round trip per interval for the whole deadline — hundreds per acquisition.
151+
152+
`auditor.Service` wraps `AcquireLocks` in its own retry (`token.tms.<name>.auditor.lock`) for transient failures, but it does **not** retry an error carrying `ErrLockAcquireTimeout`: the locker reporting one means it already spent `acquireDeadline`, so calling it again would spend that deadline afresh rather than improve the odds. Worst-case blocking for one audit is therefore about `acquireDeadline`, not `maxRetries × acquireDeadline`.
153+
116154
### Replica owner identity
117155

118156
Every lease row carries an `owner` column, and each replica scopes all of its lease

token/services/auditor/auditor.go

Lines changed: 47 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -178,7 +178,13 @@ func (a *Service) Audit(ctx context.Context, tx Transaction) (*token.InputStream
178178
// Acquire locks with retry and exponential backoff to prevent livelock
179179
logger.DebugfContext(ctx, "audit transaction [%s], acquire locks with retry", tx.ID())
180180
if err := a.acquireLocksWithRetry(ctx, string(request.Anchor), eids); err != nil {
181-
a.metrics.AuditLockConflicts.Add(1)
181+
// Only a genuine conflict counts towards the conflict metric. Counting every
182+
// failure meant a graceful-shutdown cancellation or a database outage — neither
183+
// of which involves a second holder — inflated the one signal operators are
184+
// told to alert on for contention.
185+
if errors.Is(err, auditdb.ErrLockContention) {
186+
a.metrics.AuditLockConflicts.Add(1)
187+
}
182188

183189
return nil, nil, err
184190
}
@@ -193,6 +199,13 @@ func (a *Service) Audit(ctx context.Context, tx Transaction) (*token.InputStream
193199
// acquireLocksWithRetry attempts to acquire locks with exponential backoff and randomized jitter
194200
// to prevent livelock conditions when multiple auditors compete for the same enrollment IDs.
195201
// This implements the mitigation strategy for deadlock/livelock prevention.
202+
//
203+
// The locker owns the waiting policy and bounds it itself, so this loop must not
204+
// re-run an attempt that already spent that budget: an error carrying
205+
// ErrLockAcquireTimeout is final here. Retrying it anyway multiplied the locker's
206+
// deadline by MaxRetries — worst case, ten minutes of blocking for a single audit
207+
// against the Postgres backend, on top of the round trips each of those attempts
208+
// spent polling. Context errors are final for the same reason: the caller is gone.
196209
func (a *Service) acquireLocksWithRetry(ctx context.Context, anchor string, eids []string) error {
197210
// Create a retry runner with jitter support
198211
retryRunner := utils.NewRetryRunnerWithJitter(
@@ -204,18 +217,47 @@ func (a *Service) acquireLocksWithRetry(ctx context.Context, anchor string, eids
204217
a.lockConfig.JitterFactor,
205218
)
206219

207-
// Use the retry runner to acquire locks
208-
err := retryRunner.RunWithContext(ctx, func() error {
209-
return a.auditDB.AcquireLocks(ctx, anchor, eids...)
210-
})
220+
// Use the retry runner to acquire locks, stopping early on errors that another
221+
// attempt cannot improve on.
222+
err := retryRunner.RunWithErrorsContext(ctx, func() (bool, error) {
223+
err := a.auditDB.AcquireLocks(ctx, anchor, eids...)
224+
if err == nil {
225+
return true, nil
226+
}
211227

228+
return !isRetriableLockError(ctx, err), err
229+
})
212230
if err != nil {
213231
return errors.WithMessagef(err, "failed to acquire locks for anchor [%s]", anchor)
214232
}
215233

216234
return nil
217235
}
218236

237+
// isRetriableLockError reports whether re-running AcquireLocks stands a chance of
238+
// a different outcome. Most failures do — a contended lock may be free by now, a
239+
// database blip may have passed — but three do not: ErrLockAcquireTimeout means
240+
// the locker already spent its whole waiting budget, so an identical attempt would
241+
// just spend it again; ErrLockSetWidened is a caller error that every attempt will
242+
// reproduce; and a caller whose own context is done is no longer waiting for an
243+
// answer.
244+
//
245+
// Whether the caller is gone is read from ctx, not from the error. The lockers
246+
// bound their own waiting, and a budget of their own that elapses with nothing
247+
// contending surfaces as a bare context.DeadlineExceeded — indistinguishable, by
248+
// the error alone, from the caller's deadline elapsing. Classifying it from the
249+
// error stopped the auditor after a single attempt at exactly the transient
250+
// database failures this retry exists to survive, while ctx was still perfectly
251+
// live.
252+
func isRetriableLockError(ctx context.Context, err error) bool {
253+
if ctx.Err() != nil {
254+
return false
255+
}
256+
257+
return !errors.Is(err, auditdb.ErrLockAcquireTimeout) &&
258+
!errors.Is(err, auditdb.ErrLockSetWidened)
259+
}
260+
219261
// Append adds the passed transaction to the auditor database, reusing the
220262
// audit record computed by Audit, when available.
221263
// It also releases the locks acquired by Audit.

0 commit comments

Comments
 (0)