Skip to content

fix(audit): two authorization refusals that reached no audit row now reach one (BACKLOG #1197) - #921

Merged
wshallwshall merged 5 commits into
mainfrom
claude/mgr-1197
Sep 8, 2026
Merged

fix(audit): two authorization refusals that reached no audit row now reach one (BACKLOG #1197)#921
wshallwshall merged 5 commits into
mainfrom
claude/mgr-1197

Conversation

@wshallwshall

Copy link
Copy Markdown
Collaborator

Builds the two DENIAL audits named in BACKLOG #1197's proposed-work list. This PR does not close
#1197 and does not claim to.
That item's closing act is a scorecard re-score in the vault, which no
build performs; its banner is untouched and it stays open.

Re-measurement, which is a named deliverable and not an aside

Both defects were re-verified at HEAD by execution before anything was written, each arm carrying
a positive control that had to fire in the same run.

Arm Result Control in the same run
console authorize_ui_ws, MFA-pending session 0 audit rows engine authorize_ws wrote auth.mfa_denied for the same session, same store, same counter
require_service_cert, refused authorization 0 audit rows (only log.warning) require()'s bearer-plane denial wrote auth.permission_denied for the same principal

Two further controls guard the console arm: mfa_satisfied asserted False and the identity asserted
to resolve, so the gate demonstrably reached the MFA branch rather than returning at an earlier one
and reporting a tidy, meaningless zero. Both defects stood. Neither was already fixed.

What shipped

  • authorize_ui_ws calls audit_mfa_denied before returning the empty pair. That refusal sits ABOVE
    the permission loop, so the denial call inside the loop cannot reach it, and the header-path
    fallback never sees a browser handshake (header-only token; the Origin check refuses every browser
    Origin on the shipped empty allowlist).
  • require_service_cert's dependency calls audit_permission_denied beside its existing log line.

Both rows carry the PATH and never the full URL, which is the no-payload limb the item calls
load-bearing. Behaviour is otherwise unchanged: the console still returns (None, None) and still
falls through; the cert gate still raises the same 403.

What I deliberately left

The GRANT side, on the item's own evidence. A grant row is per-request and the audit chain has no
drain ([retention].audit_days reserved and unenforced, [retention].max_db_mb ships at 0), so part
(a) measured that a first deployment would already accumulate 172,800 rows a day per polling JSON-API
client. Console grant parity across the gate applications is the flood and stays gated on the drain
and on a ruling. The cert plane's grant is left with it rather than taken as a cheap exception.

No ADR. The identical prior slice (the console WebSocket permission-denial audit, 2026-09-03)
shipped without one, and the governing decisions already exist -- ADR 0118 section 5 for the audit
verbosity posture, ADR 0083 for the cert-identity plane. The scope reasoning lives in the code
comments and in the item body. Flagging it here so the choice is reviewable rather than silent.

No docs/SECURITY.md edit. Its two service-cert claims stay true after this change (the route
body still writes service_cert_auth). Editing that table risks tripping an unrelated drift guard for
no correctness gain.

Three corrections to the row, made in the same PR

  1. The drafted replacement residual names authorize_ui_ws's silent MFA return as uncovered. It is
    repaired here and must not be carried into a re-score -- the exact failure that same paragraph
    warns about. Part (b)'s argument that rested on it is noted as historical; its conclusion is
    unaffected.
  2. The proposed-work line anchors the cert work at api/security.py:434-444, which is the
    docstring of require_service_cert, not the denial. Re-anchored by symbol.
  3. "its grant path, which records nothing in any configuration" is right about the GATE and
    incomplete about the surface: GET /service/identity writes its own service_cert_auth row in
    the route body
    . What is genuinely absent is any record of the authorization DECISION, and any
    record at all for a future route built on the same factory.

One instrument bug the drive run caught, mine

My new test helper was named _cert_request, shadowing an existing module-level _cert_request
in the same file that stashes the cert on scope['transport'] rather than scope['state']. Two
pre-existing cert-expiry tests silently rebound to the wrong one and failed. Renamed
_shim_cert_request, with the reason in its docstring. _svc_app now also clears
must_change_password: the cert plane never consults it, but require() refuses a must-change
identity ABOVE its permission loop, which would have made the positive control record nothing and
report a false zero.

Checks I ran

Interpreter for every command below, printed from sys.executable:
C:\Users\Scott\Code\MessageFoundry\.claude\worktrees\manager-277cbb-b1197\.venv\Scripts\python.exe
(this worktree's own venv -- never bare python, never the primary checkout's venv).

Check Result
ruff check . passed
ruff format --check . 1256 files already formatted
mypy messagefoundry messagefoundry_webconsole --exclude 'messagefoundry/tray/' (CI's own invocation) no issues, 284 source files
full web console suite, packaging/messagefoundry-webconsole/tests 427 collected, 424 passed, 3 skipped
tests/test_api_tls.py 81 passed
test_auth_hardening + test_mfa_access_gate + test_docs_security_pathways + test_security_doc_drift + test_audit_offbox_tee + the above 204 passed
-k "route_map or gate_of or authz or permission_grant or backlog" over tests/ 187 passed, 4 skipped
scripts/docs/backlog_status_check.py OK, 670 items, each declaring exactly one status
pre-commit at commit time all hooks passed (ledger gate, SPDX, leak guard, bandit included)

Drive test: with both source changes reverted,
test_ws_cookie_auth_mfa_pending_refusal_is_audited and test_service_cert_authz_denial_is_audited
fail and everything else in both files passes; restored, all pass. The two quiet-side guards
(test_ws_cookie_auth_mfa_satisfied_writes_no_mfa_row,
test_service_cert_grant_writes_no_authorization_row) pass in BOTH states by design -- they exist so
a later grant mirror cannot arrive unnoticed.

Checks I skipped, and legs somebody must read after I exit

  • The full tests/ suite. Ran the targeted selections above instead. Under fleet contention a
    local full suite may not finish inside one turn.
  • Every hosted-runner-only leg, which a Builder never sees: windows-service-smoke (NSSM), the
    SQL Server and Postgres store legs, the load leg, and the ide leg. The SQL Server and Postgres
    legs are the ones worth a look -- my change adds audit-row writes on two paths, and local pytest
    silently skips both backends.
  • The --platform win32 mypy pass; I ran the default-platform one.

Mode detected: not ultracode -- no system-reminder in my own context said otherwise, which is
the whole test.

I did not merge, did not enqueue, did not arm auto-merge, and added no label.

…reach one (BACKLOG #1197)

ASVS 16.3.2's base limb requires failed authorization attempts to be
logged. Two gates refused silently. Both are DENIAL audits, which are
rare by construction; the grant side is untouched and stays gated.

RE-MEASURED AT HEAD FIRST, each arm with a control that must fire,
because three of three dispatched builders on 2026-09-03 found their
item's stated defect already fixed or mis-measured.

  The console's authorize_ui_ws wrote ZERO rows for an MFA-pending
  session while the engine's header-path authorize_ws wrote
  auth.mfa_denied for the SAME session, on the same store, through the
  same counter, in the same run. That contrast is the control: a zero
  is otherwise a fact about the instrument, not about the gate.

  require_service_cert wrote ZERO rows on a refused authorization while
  emitting its log.warning, against the same shape of control --
  require()'s bearer-plane denial wrote auth.permission_denied for the
  same principal in the same run.

WHAT SHIPPED. authorize_ui_ws calls audit_mfa_denied before returning
the empty pair. That refusal sits ABOVE the permission loop, so the
denial call inside the loop cannot reach it, and the header-path
fallback never sees a browser handshake -- token read is header-only
and the Origin check refuses every browser Origin on the shipped empty
allowlist. require_service_cert's dependency calls
audit_permission_denied beside its existing log line. Both rows carry
the PATH, never the full URL: the query string is where an operator's
search terms live. Behaviour is otherwise unchanged.

THE GRANT SIDE IS DELIBERATELY NOT BUILT, on this item's own evidence.
A grant row is per-request and the chain has no drain -- audit_days is
reserved and unenforced, max_db_mb ships at 0 -- so #1197's part (a)
measured that a first deployment would already accumulate 172,800 rows
a day per polling JSON-API client. Console grant parity across the gate
applications is the flood and stays gated on the drain and on a ruling;
the cert plane's grant is left with it rather than taken as a cheap
exception.

FOUR TESTS, AND THE DENIAL PAIR WAS DRIVEN. Reverting both source
changes reds exactly test_ws_cookie_auth_mfa_pending_refusal_is_audited
and test_service_cert_authz_denial_is_audited, with the rest of both
files green. The console test asserts detail equals exactly
{"path": "/ws/stats"}, so widening to the full URL goes red, and it
asserts a permission the actor does NOT hold while requiring no
auth.permission_denied row -- an ordering guard, because refusing below
the permission loop would tell an unverified caller whether it holds
the permission. The two quiet-side tests pass in BOTH states by design:
they are the guards that a later grant mirror cannot arrive unnoticed.

ONE INSTRUMENT BUG CAUGHT BY THE DRIVE RUN, mine. The new helper was
named _cert_request, shadowing an existing module-level _cert_request
that stashes the cert on scope['transport'] rather than scope['state'].
Two pre-existing cert-expiry tests silently rebound to the wrong one
and failed. Renamed _shim_cert_request, with the reason in its
docstring. _svc_app now clears must_change_password too: the cert plane
never consults it, but require() refuses a must-change identity ABOVE
its permission loop, which would have made the positive control record
nothing and report a false zero.

THREE CORRECTIONS TO THE ROW, all in the item body.
  The drafted replacement residual names authorize_ui_ws's silent
  return as uncovered. It is repaired here and must not be carried into
  a re-score -- the exact failure that same paragraph warns about.
  The proposed-work line anchors the cert work at security.py:434-444,
  which is the DOCSTRING, not the denial. Anchored by symbol instead.
  "its grant path, which records nothing in any configuration" is right
  about the GATE and incomplete about the surface: GET /service/identity
  writes its own service_cert_auth row in the ROUTE BODY. What is
  absent is any record of the authorization DECISION, and any record at
  all for a future route on the same factory.

THE ITEM STAYS OPEN AND ITS BANNER IS UNTOUCHED. Closing-act is a
scorecard re-score in the vault, which no build performs.
@github-actions github-actions Bot added the ci-red A required check went red. Attribute it before retrying. label Sep 6, 2026
@wshallwshall

Copy link
Copy Markdown
Collaborator Author

Lander: this red is not staleness, and it should not be rebased over.

I refreshed this branch onto current main (744a7a43) at 12:33 CT and re-ran everything. test (ubuntu-latest, py3.14), test (windows-2022, py3.14) and test (windows-2025, py3.14) fail after the rebase, on the same three legs they failed on before it. A failure that survives a rebase onto a main 30 commits newer is the pull request's own.

For contrast, from the same sample taken at the same moment: PR 907's reds cleared entirely on the identical treatment (0 failed), and PR 934's moved from the sql server 2022 leg to the sql server 2025 leg, which reads as a flaky matrix leg rather than a defect. This one did neither.

I am not diagnosing the failure -- that needs whoever holds the change. Recording it so the red is attributed rather than sitting in a queue of sixteen that all look alike from the outside.

This PR adds `await auth.audit_mfa_denied(identity, websocket.url.path)` in
messagefoundry_webconsole/_auth.py, so the console now reaches an AuthService member it did not
before. The seam snapshot enumerates exactly that surface, so the contract genuinely moved and the
derived digest went stale, reddening all three `test (..., py3.14)` legs.

Regenerated with the sanctioned writer rather than by hand:

    python scripts/webconsole_seam_snapshot.py --write

which rewrote ENGINE_UI_SEAM in messagefoundry/api/_ui_seam.py and refreshed
tests/golden/webconsole_seam.snapshot. The console side is not written by that script, and its own
output tells you to set it in the same commit, so SUPPORTED_ENGINE_SEAMS in
messagefoundry_webconsole/__init__.py is set to the same value by hand:
266cbfd342b22819 -> 8121b1068d584081.

The gate stays blocking and nothing is silenced. tests/test_webconsole_seam_snapshot.py: 8 passed.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
@github-actions github-actions Bot added the unread Green and mergeable, but not marked read. Read it, then add: reviewed label Sep 7, 2026
@github-actions

github-actions Bot commented Sep 7, 2026

Copy link
Copy Markdown

@wshallwshall

This pull request is green and nobody has marked it read.

Every check that has reported is passing and the reviewed label is absent, so
a reviewer has read this is the only thing between it and a merge. Nothing else reports that, which is
why this comment exists (BACKLOG #1413).

To clear it, IN THIS ORDER:

  1. If the branch is behind main, update it FIRST: gh pr update-branch --repo MEFORORG/MessageFoundry 921.
    That push fires synchronize, and synchronize REMOVES the reviewed label. Labelling
    before updating throws the label away and costs a round trip.
  2. Read the diff.
  3. gh pr edit 921 --repo MEFORORG/MessageFoundry --add-label reviewed

DO NOT TRIAGE THIS FROM mergeStateStatus. It returns one value with precedence, so BEHIND,
DIRTY and UNSTABLE each mask the missing check -- the requirement is invisible until you act on
something else. This check never reads that field; see scripts/ci/check_unread_prs.py.

A seat can find every pull request in this state in one call: gh pr list --label unread.

Adding reviewed withdraws unread: the label event re-evaluates this pull request,
and so does the next completion of a watched workflow. Those are the two edges that clear it, so a
change neither of them reports -- converting to a draft, say -- can leave the label standing until one
of them next happens.

The reviewed label is a PROCESS gate. It records that a step happened. It does not
establish that an independent party looked, and nothing here should be read as saying it does.

@github-actions github-actions Bot added unread Green and mergeable, but not marked read. Read it, then add: reviewed and removed unread Green and mergeable, but not marked read. Read it, then add: reviewed labels Sep 7, 2026
@github-actions

github-actions Bot commented Sep 8, 2026

Copy link
Copy Markdown

@wshallwshall

This pull request is green and nobody has marked it read.

Every check that has reported is passing and the reviewed label is absent, so
a reviewer has read this is the only thing between it and a merge. Nothing else reports that, which is
why this comment exists (BACKLOG #1413).

To clear it, IN THIS ORDER:

  1. If the branch is behind main, update it FIRST: gh pr update-branch --repo MEFORORG/MessageFoundry 921.
    That push fires synchronize, and synchronize REMOVES the reviewed label. Labelling
    before updating throws the label away and costs a round trip.
  2. Read the diff.
  3. gh pr edit 921 --repo MEFORORG/MessageFoundry --add-label reviewed

DO NOT TRIAGE THIS FROM mergeStateStatus. It returns one value with precedence, so BEHIND,
DIRTY and UNSTABLE each mask the missing check -- the requirement is invisible until you act on
something else. This check never reads that field; see scripts/ci/check_unread_prs.py.

A seat can find every pull request in this state in one call: gh pr list --label unread.

Adding reviewed withdraws unread: the label event re-evaluates this pull request,
and so does the next completion of a watched workflow. Those are the two edges that clear it, so a
change neither of them reports -- converting to a draft, say -- can leave the label standing until one
of them next happens.

The reviewed label is a PROCESS gate. It records that a step happened. It does not
establish that an independent party looked, and nothing here should be read as saying it does.

@wshallwshall
wshallwshall added this pull request to the merge queue Sep 8, 2026
@wshallwshall
wshallwshall removed this pull request from the merge queue due to a manual request Sep 8, 2026
@github-actions github-actions Bot removed the unread Green and mergeable, but not marked read. Read it, then add: reviewed label Sep 8, 2026
@wshallwshall
wshallwshall added this pull request to the merge queue Sep 8, 2026
@github-actions github-actions Bot added the unread Green and mergeable, but not marked read. Read it, then add: reviewed label Sep 8, 2026
@github-actions

github-actions Bot commented Sep 8, 2026

Copy link
Copy Markdown

@wshallwshall

This pull request is green and nobody has marked it read.

Every check that has reported is passing and the reviewed label is absent, so
a reviewer has read this is the only thing between it and a merge. Nothing else reports that, which is
why this comment exists (BACKLOG #1413).

To clear it, IN THIS ORDER:

  1. If the branch is behind main, update it FIRST: gh pr update-branch --repo MEFORORG/MessageFoundry 921.
    That push fires synchronize, and synchronize REMOVES the reviewed label. Labelling
    before updating throws the label away and costs a round trip.
  2. Read the diff.
  3. gh pr edit 921 --repo MEFORORG/MessageFoundry --add-label reviewed

DO NOT TRIAGE THIS FROM mergeStateStatus. It returns one value with precedence, so BEHIND,
DIRTY and UNSTABLE each mask the missing check -- the requirement is invisible until you act on
something else. This check never reads that field; see scripts/ci/check_unread_prs.py.

A seat can find every pull request in this state in one call: gh pr list --label unread.

Adding reviewed withdraws unread: the label event re-evaluates this pull request,
and so does the next completion of a watched workflow. Those are the two edges that clear it, so a
change neither of them reports -- converting to a draft, say -- can leave the label standing until one
of them next happens.

The reviewed label is a PROCESS gate. It records that a step happened. It does not
establish that an independent party looked, and nothing here should be read as saying it does.

Merged via the queue into main with commit 6b21050 Sep 8, 2026
43 checks passed
@wshallwshall
wshallwshall deleted the claude/mgr-1197 branch September 8, 2026 07:19
@github-actions github-actions Bot removed the unread Green and mergeable, but not marked read. Read it, then add: reviewed label Sep 8, 2026
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

ci-red A required check went red. Attribute it before retrying.

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant