diff --git a/archreview/plans/R3-05-acl-hot-path-expiry-plan.md b/archreview/plans/R3-05-acl-hot-path-expiry-plan.md index d917512f..89f6ddf0 100644 --- a/archreview/plans/R3-05-acl-hot-path-expiry-plan.md +++ b/archreview/plans/R3-05-acl-hot-path-expiry-plan.md @@ -910,3 +910,91 @@ Gate rows deleted (`NodeAcl` row, the `expiry-probe` key, nothing else had been recreated **without** the override (`Security__Acl__Enabled` absent from both env lists, i.e. default `false`), parity `b344565cad3d` ×6 re-asserted, readiness back, final deploy `1c666be3…` Sealed, anonymous read of `HR100` answers a value again. Rig left UP on the master image with `DisableLogin=true`. + +## S18 hard-deadline follow-up (2026-08-20) + +The gate's S18 finding is **fixed on `fix/r3-05-s18-hard-deadline`** (branched off master `9242630c`), plus the +compose recipe defect the same leg exposed. Not yet live re-gated — the paused-SQL leg has to be re-run. + +### What was wrong + +`BoundedApiKeyStore.BoundAsync` bounded the inner store with a +`CancellationTokenSource(TimeSpan, TimeProvider)` linked into the call. **That bounds the call only if the +callee chooses to observe the token**, and `Microsoft.Data.SqlClient` does not while a connect or login is +in flight on a black-holed socket. So the deadline never returned control: the gate's keyed activation ran +**42.9 s** against a 2000 ms bound, the *"did not answer within 2000 ms"* Warning was emitted only at +unpause, and because the whole thing sits inside the SDK's synchronous `SessionManager`-lock-holding +impersonation callback, an unrelated already-open subscription stalled **57 s** behind it. The T3 TTL cache +cannot help: a miss is exactly what the outage produces. + +### Red before green — the observation, not just the claim + +Every pre-existing deadline test drives `GatedApiKeyStore`, whose waits take the token +(`Task.Delay(Timeout.Infinite, ct)`, `gate.WaitAsync(ct)`). A cooperative `CancelAfter` unblocks those, so +**all 15 of them passed against the defective build** — the suite could not see the gate's failure at all. +The new fake, `UncooperativeApiKeyStore`, ignores `ct` entirely and completes only when the test releases +it, modelling SqlClient. Against the unmodified `BoundedApiKeyStore` the three new tests fail — with a +test-side `WaitAsync(2 s)`, so the red is a **failure, not a hang**: + +``` +Failed! - Failed: 3, Passed: 15, Skipped: 0, Total: 18 + An_uncancellable_store_is_abandoned_at_the_deadline [FAIL] + An_abandoned_lookup_that_completes_later_is_not_cached [FAIL] + An_abandoned_lookup_that_faults_later_is_observed_and_swallowed [FAIL] +Shouldly.ShouldAssertException : … should throw System.OperationCanceledException but threw System.TimeoutException +``` + +`TimeoutException` rather than `OperationCanceledException` **is** the finding, restated as an assertion: +with a 200 ms bound the decorator had still not returned 2 s later. + +### The fix + +`BoundAsync` now races the inner call against `Task.Delay(timeout, _time, …)` — the injected clock, so the +deadline stays on the same `TimeProvider` as the authorizer and the revalidation timer — with +`Task.WhenAny`: + +- **Inner wins** ⇒ stop the delay timer, dispose, `await inner` (faults and a genuine *caller* cancellation + propagate exactly as before). +- **Delay wins** ⇒ cancel the linked token anyway (a *cooperative* inner store should still stop), hand the + abandoned task to `ObserveAbandoned`, meter `outcome=timeout`, log the (now honest) Warning, and throw + `OperationCanceledException` — the same exception the authenticator's catch-all already maps to the + standard opaque denial. **Fail-closed, unchanged: nothing here can admit.** +- `ObserveAbandoned` attaches a continuation that disposes the CTS, **touches `finished.Exception`** (the + observation itself, so a late SqlClient fault can never become an `UnobservedTaskException`), and logs at + Debug. Debug rather than Warning because the timeout is already reported at Warning — a ConfigDb outage + should not produce two lines per activation for one event. +- **An abandoned answer is never cached.** It was taken before the deadline and would be served after it, + so a key revoked or expired in the meantime could be admitted from a lookup nobody was still waiting for. + `Store(...)` is simply unreachable on the timeout path; the test asserts it by call count (a cached late + answer would make the next lookup a hit and leave `Calls` at 1). +- `StoreTimeoutMs ≤ 0` still short-circuits to the unbounded call, byte-for-byte — the documented rollback. + +Files: `src/Server/ZB.MOM.WW.OtOpcUa.Host/OpcUa/BoundedApiKeyStore.cs`, +`tests/Server/ZB.MOM.WW.OtOpcUa.Host.Tests/OpcUa/BoundedApiKeyStoreTests.cs`, `docs/security.md` +§"Bounding the key store". Host.Tests **137/137 green** (was 134; +3). + +### Recipe defect fixed: `OTOPCUA_ACL_ENABLED` never reached the centrals + +The gate's own correction note, actioned. `Security__Acl__Enabled: "${OTOPCUA_ACL_ENABLED:-false}"` was +wired to **site-a-1 / site-a-2 only**, so +`OTOPCUA_ACL_ENABLED=true docker compose up -d central-1 central-2` was a silent no-op — on the one node +kind that carries `BoundedApiKeyStore` at all (only a fused admin+driver node wraps `ConfigDbApiKeyStore`). +The key is now on **central-1 and central-2** too, same env var, **same default-`false`**, so today's rig +behaviour is unchanged and the plan's step 1 does what it says. site-b stays hardcoded OFF as the A/B +control. + +### Live re-gate — still owed + +Re-run **step 8's paused-SQL leg only** (setup steps 2-4 unchanged, and step 1 now needs no scratch +override). Expected, versus what the gate saw: + +| Observation | Gate (defective) | Expected now | +|---|---|---| +| Keyed `read` connect with SQL paused | 42.9 s, client `BadRequestTimeout` | denies in ≈ `StoreTimeoutMs` (2 s) | +| *"did not answer within 2000 ms"* Warning | at unpause, ~40 s late | at the deadline, while SQL is still paused | +| Already-open subscription on the same node | 57 s gap | no gap beyond the ~2 s of the activation | +| `apikey_store_bounded{outcome="timeout"}` | 1, ~40 s late | 1, promptly | +| Falsification control (pause with **no** activation) | streamed clean | must still stream clean | + +⚠️ The Debug abandonment line is not visible at the rig's default log level — it is not part of the gate's +pass criteria; the Warning and the restored subscription are. diff --git a/docker-dev/docker-compose.yml b/docker-dev/docker-compose.yml index 5ea2f7bf..e1d5542f 100644 --- a/docker-dev/docker-compose.yml +++ b/docker-dev/docker-compose.yml @@ -403,6 +403,13 @@ services: Security__Ldap__ServiceAccountPassword: "serviceaccount123" Security__DeployApiKey: "docker-dev-deploy-key" Security__Auth__DisableLogin: "${OTOPCUA_DISABLE_LOGIN:-true}" + # #520 stage 6 — node ACL enforcement, the dark switch. Default OFF, exactly as in production. + # The centrals read the SAME env override as the site-a pair, so an ACL live gate can enable it + # where BoundedApiKeyStore actually lives (only a fused admin+driver node wraps ConfigDbApiKeyStore): + # OTOPCUA_ACL_ENABLED=true docker compose -f docker-dev/docker-compose.yml up -d central-1 central-2 + # Added 2026-08-20: the R3-05 gate found this key wired only to site-a-1/2, so that command was a + # silent no-op on the centrals and the gate needed a scratch compose override to proceed. + Security__Acl__Enabled: "${OTOPCUA_ACL_ENABLED:-false}" # Map the shared-GLAuth data-plane groups (ReadOnly/WriteOperate/...) to data-plane role # strings the OPC UA session ACL gates read. The DB LdapGroupRoleMapping is AdminRole-typed # (AdminUI roles); this free-form GroupToRole baseline is the path for data-plane roles. @@ -529,6 +536,10 @@ services: Security__Ldap__ServiceAccountPassword: "serviceaccount123" Security__DeployApiKey: "docker-dev-deploy-key" Security__Auth__DisableLogin: "${OTOPCUA_DISABLE_LOGIN:-true}" + # Node ACL enforcement, the dark switch — same env override and same default-OFF as central-1. + # Both centrals must carry it: `up -d central-1 central-2` recreates both, and a pair split across + # two enforcement postures is not a rig anyone can reason about. + Security__Acl__Enabled: "${OTOPCUA_ACL_ENABLED:-false}" # Data-plane group→role baseline (see central-1). Security__Ldap__GroupToRole__ReadOnly: "ReadOnly" Security__Ldap__GroupToRole__WriteOperate: "WriteOperate" diff --git a/docs/security.md b/docs/security.md index aef95689..cb9f8147 100644 --- a/docs/security.md +++ b/docs/security.md @@ -214,6 +214,21 @@ with two `Security:ApiKeys` knobs: | `StoreTimeoutMs` | `2000` | Hard per-call deadline on the store. Exceeding it **denies** the activation. `≤ 0` disables the deadline (the pre-R3-05 unbounded behaviour — do not do this on an admin node). | | `StoreCacheSeconds` | `5` | TTL of a read-through cache in front of the store, so a burst of activations costs one round trip. `0` disables it (a read per activation). | +- ⚠️ **The deadline is a HARD race, not a cooperative token — and the difference was a live-gate + failure.** It was originally a `CancellationTokenSource(TimeSpan, TimeProvider)` linked into the inner + call, which bounds the call only if the callee chooses to observe the token. + `Microsoft.Data.SqlClient` does not, while a connect or login is in flight on a black-holed socket: the + 2026-08-20 R3-05 gate paused the SQL container and watched a keyed activation hang **42.9 s** past its + 2000 ms bound (the Warning below fired only at unpause), stalling an unrelated already-open + subscription **57 s** behind the `SessionManager` lock. `BoundedApiKeyStore` now races the inner call + against a `Task.Delay` on the injected clock and returns control the moment the delay wins. +- **An abandoned lookup runs on, and its answer is discarded.** Nothing can cancel a SqlClient call that + is not listening, so the query may still complete (or fault) in the background long after the + activation was denied. Its result is **never** cached — it was taken before the deadline and would be + served after it, so a key revoked or expired in the meantime could be admitted from a lookup nobody + was still waiting for. The token is still cancelled, so a *cooperative* inner store does stop, and the + abandoned task's outcome is observed and logged at Debug (*"an abandoned key store lookup finished / + faulted after its deadline; discarded"*) so it can never surface as an `UnobservedTaskException`. - **A timeout denies; it never admits.** The deadline surfaces as an `OperationCanceledException` into `ApiKeyOpcUaUserAuthenticator`'s existing catch-all, which returns the same opaque denial as a bad credential. There is no second denial path to get wrong, and the decorator can only ever return what diff --git a/src/Server/ZB.MOM.WW.OtOpcUa.Host/OpcUa/BoundedApiKeyStore.cs b/src/Server/ZB.MOM.WW.OtOpcUa.Host/OpcUa/BoundedApiKeyStore.cs index bc63006e..4da11850 100644 --- a/src/Server/ZB.MOM.WW.OtOpcUa.Host/OpcUa/BoundedApiKeyStore.cs +++ b/src/Server/ZB.MOM.WW.OtOpcUa.Host/OpcUa/BoundedApiKeyStore.cs @@ -27,10 +27,12 @@ namespace ZB.MOM.WW.OtOpcUa.Host.OpcUa; /// decorator can only return what the inner store returned, or throw. /// /// -/// ⚠️ Faults and timeouts are NEVER cached. Caching a deny would be fail-closed and is -/// still wrong: it would extend a ConfigDb outage past the outage, denying valid keys for a -/// further TTL after the database came back. Only a COMPLETED lookup — a hit or an authoritative -/// miss — is stored. +/// ⚠️ Faults and timeouts are NEVER cached, and neither is the late answer of a lookup the +/// deadline abandoned. Caching a deny would be fail-closed and is still wrong: it would extend a +/// ConfigDb outage past the outage, denying valid keys for a further TTL after the database came +/// back. Caching an abandoned answer would be worse than that — it was taken before the deadline +/// and served after it. Only a lookup that completed BEFORE its deadline — a hit or an +/// authoritative miss — is stored. /// /// public sealed class BoundedApiKeyStore : IApiKeyStore @@ -202,11 +204,33 @@ public sealed class BoundedApiKeyStore : IApiKeyStore /// sees in production is always uncancellable. /// /// - /// ⚠️ It re-throws rather than returning . null means + /// ⚠️ The deadline is a HARD race, not a cooperative token — and that distinction was a live + /// gate failure, not a theoretical one. This used to be a + /// CancellationTokenSource(TimeSpan, TimeProvider) linked into the inner call, which + /// bounds the call only if the callee chooses to observe the token. + /// Microsoft.Data.SqlClient does not, while a connect or login is in flight on a + /// black-holed socket: the 2026-08-20 R3-05 gate paused the SQL container and watched a keyed + /// activation hang 42.9 s past its 2000 ms bound (the Warning below fired only at + /// unpause), stalling an unrelated already-open subscription for 57 s behind the + /// SessionManager lock — the exact hazard the bound exists to prevent. So the inner call + /// is now raced against a + /// on the injected clock and abandoned when the delay wins. + /// + /// + /// ⚠️ An abandoned lookup's answer is DISCARDED, never cached. It was taken before the + /// deadline and would be served after it, so a key revoked or expired in the meantime could be + /// admitted from a lookup nobody was still waiting for. The token is still cancelled — a + /// cooperative inner store should stop — and the abandoned task's outcome is observed by + /// so it can never surface as an + /// UnobservedTaskException. + /// + /// + /// ⚠️ It throws rather than returning . null means /// "no such usable key", which the authenticator logs as denied — no enabled, unexpired key /// with id X. A timeout is not that, and an operator reading that line during a ConfigDb /// outage would go hunting for a key problem that does not exist. The distinct Warning below is - /// the honest signal; the denial itself is unchanged either way. + /// the honest signal; the denial itself is unchanged either way — the authenticator's catch-all + /// turns any throw into the same opaque denial. /// /// private async Task BoundAsync(Func> call, CancellationToken ct) @@ -214,27 +238,78 @@ public sealed class BoundedApiKeyStore : IApiKeyStore var timeoutMs = _options.Value.StoreTimeoutMs; if (timeoutMs <= 0) return await call(ct).ConfigureAwait(false); - // The deadline runs on the INJECTED clock (the TimeProvider ctor overload), not on a plain - // CancelAfter, so it is the same TimeProvider the authorizer and the revalidation timer read. // Linked with the caller's token so a genuine caller cancellation is still honoured — and so the - // catch below can tell the two apart. - using var deadline = new CancellationTokenSource(TimeSpan.FromMilliseconds(timeoutMs), _time); - using var cts = CancellationTokenSource.CreateLinkedTokenSource(ct, deadline.Token); - + // winner check below can tell the two apart. NOT linked to the deadline: the deadline is the race, + // and this token is only the courtesy signal to an inner store that happens to be cooperative. + var innerCts = CancellationTokenSource.CreateLinkedTokenSource(ct); + Task inner; try { - return await call(cts.Token).ConfigureAwait(false); + inner = call(innerCts.Token); } - catch (OperationCanceledException) when (!ct.IsCancellationRequested) + catch { - OtOpcUaTelemetry.ApiKeyStoreBounded.Add( - 1, new KeyValuePair("outcome", "timeout")); - _log.LogWarning( - "ApiKeyStore: the key store did not answer within {TimeoutMs} ms — denying this activation. " - + "Every OPC UA session activation on this server is serialized behind this call; " - + "check ConfigDb health.", - timeoutMs); + innerCts.Dispose(); throw; } + + // The delay runs on the INJECTED clock, so it is the same TimeProvider the authorizer and the + // revalidation timer read. Its own CTS exists only to stop the timer when the inner call wins. + using var delayCts = new CancellationTokenSource(); + var deadline = Task.Delay(TimeSpan.FromMilliseconds(timeoutMs), _time, delayCts.Token); + + if (await Task.WhenAny(inner, deadline).ConfigureAwait(false) == inner) + { + delayCts.Cancel(); + innerCts.Dispose(); + return await inner.ConfigureAwait(false); + } + + innerCts.Cancel(); + ObserveAbandoned(inner, innerCts); + + OtOpcUaTelemetry.ApiKeyStoreBounded.Add( + 1, new KeyValuePair("outcome", "timeout")); + _log.LogWarning( + "ApiKeyStore: the key store did not answer within {TimeoutMs} ms — denying this activation. " + + "The lookup is abandoned and its result, if it ever arrives, is discarded. Every OPC UA " + + "session activation on this server is serialized behind this call; check ConfigDb health.", + timeoutMs); + throw new OperationCanceledException( + $"The API key store did not answer within {timeoutMs} ms; the lookup was abandoned."); } + + /// + /// Watches an abandoned inner lookup to its end so its outcome is observed and its resources are + /// released, and discards whatever it produced. + /// + /// The abandoned call's result type. + /// The lookup the deadline gave up on. + /// The cancellation source that call was handed; disposed once it finishes. + /// + /// Nobody awaits , so without this its fault would be unobserved. + /// Debug rather than Warning: the timeout has already been reported at Warning, and a ConfigDb + /// outage would otherwise produce two lines per activation for one event. + /// + private void ObserveAbandoned(Task abandoned, CancellationTokenSource cts) => + _ = abandoned.ContinueWith( + finished => + { + cts.Dispose(); + var error = finished.Exception; // The observation itself — do not remove. + if (error is not null) + { + _log.LogDebug( + error, + "ApiKeyStore: an abandoned key store lookup faulted after its deadline; discarded."); + } + else + { + _log.LogDebug( + "ApiKeyStore: an abandoned key store lookup finished after its deadline; discarded."); + } + }, + CancellationToken.None, + TaskContinuationOptions.ExecuteSynchronously, + TaskScheduler.Default); } diff --git a/tests/Server/ZB.MOM.WW.OtOpcUa.Host.Tests/OpcUa/BoundedApiKeyStoreTests.cs b/tests/Server/ZB.MOM.WW.OtOpcUa.Host.Tests/OpcUa/BoundedApiKeyStoreTests.cs index 9a4357dc..e8081db1 100644 --- a/tests/Server/ZB.MOM.WW.OtOpcUa.Host.Tests/OpcUa/BoundedApiKeyStoreTests.cs +++ b/tests/Server/ZB.MOM.WW.OtOpcUa.Host.Tests/OpcUa/BoundedApiKeyStoreTests.cs @@ -1,4 +1,6 @@ +using System.Diagnostics; using System.Diagnostics.Metrics; +using Microsoft.Extensions.Logging; using Microsoft.Extensions.Logging.Abstractions; using Microsoft.Extensions.Options; using Shouldly; @@ -101,6 +103,110 @@ public sealed class BoundedApiKeyStoreTests result.Error.ShouldBe(ApiKeyOpcUaUserAuthenticator.DenyMessage); } + // ---------- the deadline is HARD, not cooperative (S18 live-gate follow-up, 2026-08-20) ---------- + + /// + /// An inner store that ignores its cancellation token is abandoned at the deadline anyway: + /// control returns to the activation inside the bound, not when the store eventually answers. + /// + /// + /// + /// ⚠️ This is the live-gate failure, and every other deadline case in this class misses + /// it. They drive , whose waits take the token, so a + /// cooperative CancelAfter is enough to unblock them. Real + /// Microsoft.Data.SqlClient is not cooperative while a connect or login is in flight on + /// a black-holed socket: the 2026-08-20 gate paused the SQL container and watched a keyed + /// activation hang 42.9 s past a 2000 ms bound (the Warning fired only at unpause), with + /// an unrelated open subscription stalled 57 s behind the SessionManager lock. + /// + /// + /// The wall-clock assertion is what makes this test about the bound rather than about the + /// exception type: a cooperative implementation does not throw late here, it does not return + /// at all, so the test-side WaitAsync is the red. + /// + /// + [Fact] + public async Task An_uncancellable_store_is_abandoned_at_the_deadline() + { + var (_, inner) = SetUpUncooperative(); + var sut = Bounded(inner, timeoutMs: 200, cacheSeconds: 5); + + var started = Stopwatch.StartNew(); + await Should.ThrowAsync( + () => sut.FindAsync(inner.KeyId, DateTime.UtcNow, default) + .WaitAsync(TimeSpan.FromSeconds(2))); + started.Stop(); + + started.Elapsed.ShouldBeLessThan( + TimeSpan.FromSeconds(2), + "the deadline must return control on its own, not wait for the store to answer"); + + // The abandoned lookup is released only now — the assertions above already hold without it. + inner.Release(); + } + + /// + /// A lookup abandoned at the deadline must never land in the cache when it completes later — the + /// next activation re-reads the store. + /// + /// + /// Caching it would be worse than caching a timeout: the answer was taken before the deadline and + /// is served after it, so a key revoked or expired in the meantime would be admitted from a + /// lookup nobody was still waiting for. The call count is the assertion — a build that stored the + /// late result would serve the second call from the cache and leave Calls at 1. + /// + [Fact] + public async Task An_abandoned_lookup_that_completes_later_is_not_cached() + { + var (_, inner) = SetUpUncooperative(); + var sut = Bounded(inner, timeoutMs: 200, cacheSeconds: 60); + + await Should.ThrowAsync( + () => sut.FindAsync(inner.KeyId, DateTime.UtcNow, default) + .WaitAsync(TimeSpan.FromSeconds(2))); + + // The abandoned inner task now completes, with a perfectly valid key, into nobody's hands. + inner.Release(); + await inner.Completed.WaitAsync(TimeSpan.FromSeconds(2)); + + // Well inside the 60 s TTL: a cached late answer would make this a hit. + (await sut.FindAsync(inner.KeyId, DateTime.UtcNow, default).WaitAsync(TimeSpan.FromSeconds(2))) + .ShouldNotBeNull("the store answers immediately once released"); + inner.Calls.ShouldBe(2, "the abandoned lookup must not have populated the cache"); + } + + /// + /// An abandoned lookup that later faults has its exception observed and swallowed, so it + /// can never surface as an UnobservedTaskException on the finalizer thread. + /// + /// + /// Nobody awaits the abandoned task, so without an explicit continuation its fault is unobserved — + /// which on some host configurations escalates. The Debug line is the observable proof the + /// continuation ran; asserting the absence of a finalizer-thread event instead would depend on GC + /// timing and prove nothing on a green run. + /// + [Fact] + public async Task An_abandoned_lookup_that_faults_later_is_observed_and_swallowed() + { + var (_, inner) = SetUpUncooperative(); + var log = new CapturingLogger(); + var sut = Bounded(inner, timeoutMs: 200, cacheSeconds: 0, log: log); + + await Should.ThrowAsync( + () => sut.FindAsync(inner.KeyId, DateTime.UtcNow, default) + .WaitAsync(TimeSpan.FromSeconds(2))); + + inner.ReleaseWithFault(new InvalidOperationException("SqlClient gave up")); + await inner.Completed.WaitAsync(TimeSpan.FromSeconds(2)); + + // The continuation is a separate task from the one just awaited; give it a moment to run. + var deadline = Stopwatch.StartNew(); + while (log.Lines.Count == 0 && deadline.Elapsed < TimeSpan.FromSeconds(2)) + await Task.Delay(10); + + log.Lines.ShouldContain(line => line.Contains("abandoned", StringComparison.OrdinalIgnoreCase)); + } + /// /// A non-positive StoreTimeoutMs disables the deadline, restoring the unbounded behaviour /// byte-for-byte — the documented rollback. @@ -367,7 +473,11 @@ public sealed class BoundedApiKeyStoreTests // ---------- helpers ---------- private static BoundedApiKeyStore Bounded( - IApiKeyStore inner, int timeoutMs, int cacheSeconds, TimeProvider? clock = null) => new( + IApiKeyStore inner, + int timeoutMs, + int cacheSeconds, + TimeProvider? clock = null, + ILogger? log = null) => new( inner, Options.Create(new ApiKeyOptions { @@ -376,7 +486,7 @@ public sealed class BoundedApiKeyStoreTests StoreTimeoutMs = timeoutMs, StoreCacheSeconds = cacheSeconds, }), - NullLogger.Instance, + log ?? NullLogger.Instance, clock ?? TimeProvider.System); private static ApiKeyOpcUaUserAuthenticator Auth(IApiKeyStore store) => new( @@ -400,6 +510,22 @@ public sealed class BoundedApiKeyStoreTests return (presented, new GatedApiKeyStore(key)); } + /// Builds the same key in front of an inner store that does NOT honour cancellation. + /// The presented credential and the uncooperative store. + private static (string Presented, UncooperativeApiKeyStore Store) SetUpUncooperative() + { + var (presented, apiKeyId, hash) = ApiKeySecret.Generate(Pepper); + return (presented, new UncooperativeApiKeyStore(new ApiKey + { + ApiKeyId = apiKeyId, + Name = "test key", + SecretHash = hash, + Principal = Principal, + Enabled = true, + CreatedUtc = DateTime.UtcNow, + })); + } + /// /// An inner store whose answer can be withheld — a hang the EF in-memory provider cannot /// represent — and whose calls are counted. @@ -456,6 +582,104 @@ public sealed class BoundedApiKeyStoreTests } } + /// + /// An inner store that ignores its cancellation token entirely — the shape real + /// Microsoft.Data.SqlClient takes on a black-holed connection, and the one every other fake + /// in this class cannot represent. + /// + /// + /// passes the token into every wait, so a cooperative deadline + /// unblocks it and a cooperative implementation looks correct. This one only ever completes when + /// the test releases it, so the deadline has to be a real race to return at all. + /// + private sealed class UncooperativeApiKeyStore(ApiKey key) : IApiKeyStore + { + private readonly TaskCompletionSource _gate = + new(TaskCreationOptions.RunContinuationsAsynchronously); + private readonly TaskCompletionSource _completed = + new(TaskCreationOptions.RunContinuationsAsynchronously); + private int _calls; + + /// The id of the key this store holds. + public string KeyId => key.ApiKeyId; + + /// How many calls reached this store (i.e. were not served from the cache). + public int Calls => _calls; + + /// Completes once an in-flight inner call has run to completion or fault. + public Task Completed => _completed.Task; + + /// Lets the in-flight (and every subsequent) call answer normally. + public void Release() => _gate.TrySetResult(); + + /// Lets the in-flight call fail, the way SqlClient eventually gives up on its own. + /// The fault to surface from the abandoned inner task. + public void ReleaseWithFault(Exception error) => _gate.TrySetException(error); + + public async Task FindAsync(string apiKeyId, DateTime utcNow, CancellationToken ct) + { + Interlocked.Increment(ref _calls); + try + { + // ⚠️ ct is deliberately NOT passed — that is the whole point of this fake. + await _gate.Task.ConfigureAwait(false); + } + finally + { + _completed.TrySetResult(); + } + + return string.Equals(apiKeyId, key.ApiKeyId, StringComparison.Ordinal) + ? new ApiKeyLookup(key, []) + : null; + } + + public async Task> FindGrantsAsync(string principal, CancellationToken ct) + { + Interlocked.Increment(ref _calls); + try + { + await _gate.Task.ConfigureAwait(false); + } + finally + { + _completed.TrySetResult(); + } + + return []; + } + } + + /// Collects rendered log messages so a "logged and swallowed" claim can be asserted. + private sealed class CapturingLogger : ILogger + { + private readonly List _lines = []; + private readonly Lock _gate = new(); + + /// Every line rendered so far. + public IReadOnlyList Lines + { + get { lock (_gate) return [.. _lines]; } + } + + /// + public IDisposable? BeginScope(TState state) where TState : notnull => null; + + /// + public bool IsEnabled(LogLevel logLevel) => true; + + /// + public void Log( + LogLevel logLevel, + EventId eventId, + TState state, + Exception? exception, + Func formatter) + { + lock (_gate) _lines.Add(formatter(state, exception)); + } + } + /// Collects otopcua.opcua.apikey_store.bounded measurements by their outcome tag. /// /// ⚠️ Filtered by instrument name only, which is normally the metrics-test leak (a listener sees