test(secrets): live gate 4/4 — check 4 re-run and PASSES on 0.4.1

Second pass on the 0.4.1 image, from a clean start with zero denial warnings on
central-a. Both auth negatives are still refused with a byte-identical
Unauthenticated status and detail - 0.4.1 changed what the server writes down,
not what a caller sees - and the no-bearer call now produces a WRN in the same
second it is refused, with the cause attributed. No interval has to elapse for
the first denial to be visible, which is the whole point: a follower with a
mis-rotated token is refused on every sweep, and central now says so immediately.

The rate limit was proven to DEFER rather than drop, not assumed to. The
wrong-bearer call one second later fell inside the 60 s window and produced no
line of its own; the window was waited out and one further wrong-bearer call
issued, whose summary reported TWO wrong-credential denials - the deferred one
plus the new one. Summing the two lines gives exactly the three negatives issued,
correctly attributed by cause. N is a per-window delta, so a reader must sum the
lines rather than quote the last one; that is recorded as a follow-up because it
is the kind of thing an alert gets wrong.

Log hygiene re-run fleet-wide and widened: all eight nodes' docker logs and every
on-disk Serilog file were grepped for the dev token, the dev KEK, all three secret
plaintexts AND both wrong tokens the negatives presented. Zero hits everywhere.
The presented-credential check is deliberate - echoing a rejected credential back
into a log is its own leak and a free oracle, and the new warning counts denials
by cause without carrying any credential material.

Checks 2 and 3 were not repeated: 0.4.1 touches the hub's denial logging and
nothing else - no wire change, no store change, no sweep change. Convergence was
re-smoked instead so the new image is not merely assumed to replicate: a fresh
secret reached both followers in 17 s, byte-identical and decrypt-verified on
both, and the first pass's live secret and tombstone survived the image swap
unchanged on all three nodes.

The first-pass FAIL evidence is kept intact rather than overwritten. The fix only
means anything against the failure it answers, and a gate doc that shows only the
green run cannot be audited.

Residuals stand as recorded: the hub client dials a single endpoint with no
failover, and the central pair does not converge with itself - central-b answered
an authenticated GetManifest with an empty manifest for the whole run. Those are
one question, not two.

4/4. Merging.

Claude-Session: https://claude.ai/code/session_014WNM4vjoVksyyBraTXSZE1
This commit is contained in:
Joseph Doherty
2026-08-07 08:51:39 -04:00
parent 6d38e89be0
commit f6c3f7c593
@@ -1,8 +1,14 @@
# Secrets gRPC hub — live gate on the docker cluster
**Result: 3 of 4 checks PASS. Check 4 FAILS one clause of its stated criterion.**
**NOT MERGED** — the gate's merge condition is 4/4. Run 2026-08-07 on the local 8-node
docker cluster.
**Result: PASS — 4/4 checks.** Run 2026-08-07 on the local 8-node docker cluster.
Run in two passes. The **first pass** (image `2958aa2c2bbb`, secrets libs **0.4.0**) passed
checks 13 and failed one clause of check 4: denials were recorded at Information, not
Warning. That was a property of the library, not of this branch, so it was fixed at the
library and shipped as **0.4.1** (`scadaproj` main `c86cead`). The **second pass** (image
`f866208c89e8`, secrets libs **0.4.1**) re-ran check 4 in full and re-smoked convergence to
prove the new image still converges. Both passes are recorded below, first-pass evidence
kept intact — the fix is only meaningful against the failure it answers.
## Purpose
@@ -23,14 +29,19 @@ sites talk to central, not to central's DB.
## Rig state
| Fact | First pass | Second pass |
|---|---|---|
| Repo / branch | `ScadaBridge` @ `feat/secrets-grpc-hub` | same |
| Git SHA gated | `fc784b413713b1643a21d573e55c00bcc05bd8ee` (`fc784b41`) | `6d38e89be0b39a2224559dd50922751ccd8df2ed` (`6d38e89b`) |
| Image | `scadabridge:latest` = `2958aa2c2bbb`, built 11:39 UTC | `scadabridge:latest` = `f866208c89e8`, built 12:41 UTC |
| `ZB.MOM.WW.ScadaBridge.Host.dll` | `09cf76dc550d32fe…` — byte-identical on all 8 nodes | `bc8f17e7b5d6982c…` — byte-identical on all 8 nodes |
| Secrets libs | `ZB.MOM.WW.Secrets*` **0.4.0** | `ZB.MOM.WW.Secrets*` **0.4.1** |
| Working tree at build | only `docker/docker-compose.yml` modified (rig config, not in the image) + untracked `.claude/` | clean but for untracked `.claude/` |
Common to both passes:
| Fact | Value |
|---|---|
| Repo / branch | `ScadaBridge` @ `feat/secrets-grpc-hub` |
| Git SHA gated | `fc784b413713b1643a21d573e55c00bcc05bd8ee` (`fc784b41`) |
| Image | `scadabridge:latest` = `2958aa2c2bbb`, built 2026-08-07 11:39 UTC |
| `ZB.MOM.WW.ScadaBridge.Host.dll` | `09cf76dc550d32fe…`**byte-identical on all 8 nodes** |
| Secrets libs | `ZB.MOM.WW.Secrets*` **0.4.0** (`Directory.Packages.props`) |
| Working tree at build | only `docker/docker-compose.yml` modified (rig config, not in the image) + untracked `.claude/` |
| Hub enabled on | `central-a`, `central-b` (host) and `site-a-a`, `site-a-b` (followers) |
| Hub NOT enabled on | `site-b-a`, `site-b-b`, `site-c-a`, `site-c-b` — no `Secrets__*` env, no store file, no hub/sweep log line (verified) |
| Sweep interval | `00:00:30` — the **product default**, deliberately not shortened, so the timings below are real |
@@ -78,12 +89,14 @@ network, against the committed `secrets_hub.proto`.
## Results
| # | Check | Result | Timing |
|---|---|---|---|
| 1 | Convergence — central write reaches both site-a nodes, byte-identical, decrypt-verified | **PASS** | **5 s** (budget 30 s + margin) |
| 2 | Cold-boot offline — site pair boots and serves last-known-good with central down; convergence resumes | **PASS** | resumed in **14 s** / **43 s** |
| 3 | Tombstone — delete propagates, survives a pair restart | **PASS** | **≤ 9 s** |
| 4 | Auth negatives + log hygiene | **FAIL** (1 clause of 3) | — |
| # | Check | Pass | Result | Timing |
|---|---|---|---|---|
| 1 | Convergence — central write reaches both site-a nodes, byte-identical, decrypt-verified | 1st (0.4.0) | **PASS** | **5 s** (budget 30 s + margin) |
| 2 | Cold-boot offline — site pair boots and serves last-known-good with central down; convergence resumes | 1st (0.4.0) | **PASS** | resumed in **14 s** / **43 s** |
| 3 | Tombstone — delete propagates, survives a pair restart | 1st (0.4.0) | **PASS** | **≤ 9 s** |
| 4 | Auth negatives + log hygiene | 1st (0.4.0) | ~~FAIL~~ (1 clause of 3) | — |
| 4 | Auth negatives + log hygiene — **re-run in full** | 2nd (0.4.1) | **PASS** | denial warned immediately |
| — | Convergence re-smoke on the 0.4.1 image | 2nd (0.4.1) | **PASS** | **17 s** |
Baseline before seeding: all four stores empty.
@@ -178,7 +191,9 @@ opportunity to re-pull the row. Re-checked at 11:57:05Z (75 s / 2+ sweeps later)
`secret get``{"error":"not-found"}` on both.
- `hub-gate-smoke-2` survived on both and **decrypted to the correct plaintext** on both.
### Check 4 — auth negatives + log hygiene · FAIL (one clause)
### Check 4, first pass (0.4.0) — auth negatives + log hygiene · FAIL (one clause)
Kept for the record; superseded by the second pass below.
Three calls to `SecretsHub/GetManifest` on `scadabridge-central-a:8083` at 11:57:3132Z:
@@ -234,18 +249,108 @@ does fire), but central shows nothing above INF.
**Not patched in ScadaBridge.** A host-side interceptor could log the denial, but that would
(a) contradict a decision the library documents and reasons about explicitly, in the
consumer rather than at the layer that owns it, and (b) put an unbounded log write on an
unauthenticated endpoint. Both are worse than the gap. The correct fix is a rate-limited
warning in `SecretsHubAuthInterceptor`, or an explicit decision that Information is right
and this criterion should be relaxed. That call is not this gate's to make — see
[Follow-ups](#follow-ups).
unauthenticated endpoint. Both are worse than the gap. It was fixed at the layer that owns
it instead — see the second pass.
### Check 4, second pass (0.4.1) — auth negatives + log hygiene · PASS
Re-run in full on the 0.4.1 image (`f866208c89e8`, branch `6d38e89b`), from a clean start:
zero `The gRPC secrets hub denied` lines on `central-a` before the first negative.
**Denial semantics — unchanged, as intended.** Three calls to `SecretsHub/GetManifest` on
`scadabridge-central-a:8083`:
| Call | Time | Result |
|---|---|---|
| **no** `authorization` header | 12:46:09Z | `Code: Unauthenticated` / `Message: Unauthenticated.` |
| **wrong** bearer | 12:46:10Z | `Code: Unauthenticated` / `Message: Unauthenticated.` |
| correct bearer (positive control) | 12:46:10Z | `200`, manifest returned |
| **wrong** bearer, next window | 12:47:38Z | `Code: Unauthenticated` / `Message: Unauthenticated.` |
Byte-identical code and detail on every refusal, and the positive control proves the route
is live. The wire contract did not move: 0.4.1 changed only what the server writes down.
**The warning now fires, and fires on the first denial.** No interval had to elapse — the
no-bearer call at 12:46:09Z produced a `WRN` in the same second it was refused:
```
central-a [12:46:10 WRN] The gRPC secrets hub denied 1 call(s) since the previous such warning
(missing or malformed credential: 1; wrong credential: 0; hub token unconfigured: 0).
Denials are summarised at most once every 60s.
```
**Rate limiting defers, it does not drop.** The wrong-bearer call one second later fell
inside that 60 s window, so it produced no line of its own. Rather than assume it was
counted, the window was waited out and one further wrong-bearer call issued at 12:47:38Z:
```
central-a [12:47:38 WRN] The gRPC secrets hub denied 2 call(s) since the previous such warning
(missing or malformed credential: 0; wrong credential: 2; hub token unconfigured: 0).
```
The second summary reports **two** wrong-credential denials — the deferred 12:46:10Z one plus
the 12:47:38Z one. Summing across lines gives 1 missing + 2 wrong = **3**, exactly the three
negatives issued, with the causes correctly attributed. `N` is a per-window delta, so a
reader must sum the lines rather than quote the last one. Nothing was lost to the rate limit,
which is the only property that matters for the failure this fix exists to make visible: a
follower with a mis-rotated token is refused on every sweep, and central now says so at
`WRN` within a second of the first attempt.
**Log hygiene — zero hits, fleet-wide.** All **8** nodes' `docker logs` *and* every on-disk
Serilog file under `docker/*/logs/` were grepped for the dev bearer token, the dev KEK, all
three secret plaintexts, **and both wrong tokens presented by the negatives** — the last of
those deliberately, because echoing a rejected credential back into a log is its own leak and
a free oracle:
```
central-a token=0 kek=0 p1=0 p2=0 p3=0 wrong1=0 wrong2=0
central-b token=0 kek=0 p1=0 p2=0 p3=0 wrong1=0 wrong2=0
site-a-a token=0 kek=0 p1=0 p2=0 p3=0 wrong1=0 wrong2=0
site-a-b token=0 kek=0 p1=0 p2=0 p3=0 wrong1=0 wrong2=0
site-b-a / site-b-b / site-c-a / site-c-b all zero
on-disk log files: 0 files matched, for each of the 7 search strings
```
The new warning counts denials and names their cause; it carries no credential material,
presented or configured. The token still appears only where it legitimately may: the
committed rig config and the resulting container environment.
### Convergence re-smoke on the 0.4.1 image · PASS
Checks 2 and 3 were not repeated — 0.4.1 touches only the hub's denial logging. Convergence
was re-smoked to prove the new image still replicates end to end:
`hub-gate-smoke-3` seeded on `central-a` at 12:47:54Z:
```
central-node-a hub-gate-smoke-3 rev=0 del=0 cipher_sha256=fc3cee5431cab8f3a7df303c kek=7451bcbc1f1f updated=2026-08-07T12:47:54.3769041+00:00
site-a-node-a hub-gate-smoke-3 rev=0 del=0 cipher_sha256=fc3cee5431cab8f3a7df303c kek=7451bcbc1f1f updated=2026-08-07T12:47:54.3769041+00:00
site-a-node-b hub-gate-smoke-3 rev=0 del=0 cipher_sha256=fc3cee5431cab8f3a7df303c kek=7451bcbc1f1f updated=2026-08-07T12:47:54.3769041+00:00
site-a-a [12:48:11 INF] Secret hub sync converged: pulled 1 row(s) from the central hub.
site-a-b [12:48:11 INF] Secret hub sync converged: pulled 1 row(s) from the central hub.
```
**17 s**, both followers, byte-identical ciphertext and `updated_utc`, **decrypt-verified on
both**. The first pass's `hub-gate-smoke-2` and the `hub-gate-smoke-1` tombstone survived the
image swap unchanged on all three nodes.
## Defects found
**None in product code.** One defect in the *gate method*, caught and corrected before any
result was recorded:
**None in ScadaBridge product code.** One library defect, found by this gate and fixed
forward; one defect in the *gate method*, caught before any result was recorded.
**Host-side seeding of a bind-mounted SQLite store is not coherent with the running
container** (Docker Desktop for macOS). The first attempt at check 1 seeded central-a's
**Library: the hub logged denials only at Information** (`ZB.MOM.WW.Secrets.Replicator.Grpc`
0.4.0). Found by check 4's first pass; detailed above. Fixed at the library and shipped as
**0.4.1** (`scadaproj` main `c86cead`): `SecretsHubAuthInterceptor` now emits a rate-limited
`Warning` per denial window, broken down by cause, with the first denial after startup or a
quiet window warning immediately. Wire behaviour is byte-identical — the refusal is still one
uniform `Unauthenticated` with one detail. ScadaBridge took the bump in `6d38e89b` (all five
`ZB.MOM.WW.Secrets*` pins moved together; build 0 warnings, secrets wiring + hub-mapping pins
31/31), and check 4 was re-run in full against it.
**Gate method: host-side seeding of a bind-mounted SQLite store is not coherent with the
running container** (Docker Desktop for macOS). The first attempt at check 1 seeded central-a's
store with the CLI running natively on the host. The row was visible to the host and to a
fresh helper container, but the **running node never saw it**: four consecutive sweeps
returned an empty manifest, no `GetSecrets` was ever issued, and a `wal_checkpoint(TRUNCATE)`
@@ -314,15 +419,21 @@ mode is a convincing false negative: it looks exactly like "the hub is broken".
additionally needs a real KEK supplied out of band and a real token — never committed, and
never a `${secret:}` reference.
7. **Checks 2 and 3 ran on 0.4.0 only.** 0.4.1 changes what the hub writes to its own log on
a denied call and nothing else — no wire change, no store change, no sweep change — so
re-running the outage and tombstone drills would have re-proven code the bump did not
touch. Convergence *was* re-smoked on the 0.4.1 image (17 s, decrypt-verified on both
followers), and the first pass's live secret and tombstone survived the image swap
unchanged, so the 0.4.1 image is not merely assumed to replicate.
## Follow-ups
- **File against `ZB.MOM.WW.Secrets.Replicator.Grpc`:** decide whether a denied hub call
should emit a rate-limited `Warning` on the server. Today it emits nothing from the gate
itself, so a mis-rotated follower token is visible at central only at Information level.
This is the sole reason this gate is not 4/4.
- **File against ScadaBridge:** endpoint failover for the hub client, and/or a documented
answer for how the central pair's own stores converge (residual 2). Both are the same
underlying question — "which central node is authoritative for secrets".
- **Reading the new denial warning:** `N` is a **per-window delta**, not a running total.
Summing across lines gives the true count; quoting the last line understates it. Worth
knowing before anyone builds an alert on the `The gRPC secrets hub denied` anchor.
## Conclusion
@@ -330,10 +441,15 @@ The pull-only gRPC secrets hub **works, and works the way the branch says it doe
convergence is one sweep tick, ciphertext is relayed verbatim so last-writer-wins ordering
survives the hop, a site node boots and serves its full last-known-good store with the entire
central pair stopped, convergence resumes unaided when central returns, tombstones propagate
and do not resurrect across a pair restart, the auth gate refuses uniformly, and no token,
KEK or plaintext reaches any log on any of the eight nodes.
and do not resurrect across a pair restart, the auth gate refuses uniformly and now *says so*
at `WRN` within a second of the first attempt, and no token, KEK or plaintext — including the
rejected credentials the negatives presented — reaches any log on any of the eight nodes.
One clause of check 4 is not met — denials are recorded at Information, not Warning — and
that clause is a property of the library, not of this branch. The gate's merge condition is
4/4, so **this branch is not merged by this gate**. Resolving the logging question (fix the
library, or relax the criterion) is the only thing standing between this result and a merge.
The one clause that failed on the first pass was a library property, not a branch one. It was
fixed where it belonged, ScadaBridge took the bump, and check 4 was re-run in full rather than
argued around. **4/4 — merged to `main`.**
**Unchanged by this gate:** `Secrets:Replication:Enabled` remains **default-false in the
product**, with `Mode` defaulting to `SqlServer`. It is enabled on this docker rig only, on
four of eight nodes, with a dev KEK and a dev token. Production enablement additionally
requires a real KEK supplied out of band, a real hub token, and an answer to residual 2.