diff --git a/docs/PHI.md b/docs/PHI.md index 275a4c48..974e20d8 100644 --- a/docs/PHI.md +++ b/docs/PHI.md @@ -908,7 +908,7 @@ with materially different PHI profiles, so they get their own rows; stream 4 is | **3. `messagefoundry.audit` off-box tee** (sub-stream of 1) | one JSON object per **committed** `audit_log` row: `event`/`ts`/`action`/`actor`/`channel_id`/`client`/`detail` | JSON | emitted after the row is durably committed and **outside** the store write lock; rides stream 1's handlers | shipping audit evidence to a SIEM so it survives a host compromise | inherits stream 1's | inherits stream 1's | `detail` is passed through the `safe_text` PHI chokepoint **before** it leaves the process; `client` is forwarded verbatim as a discrete field so a SIEM can index it. Best-effort: a logging failure is caught, never raised into the audit write. **Pinned to `INFO`** — it is emitted even at `[logging].level = WARNING` | | **4. Off-box syslog/SIEM forwarder** — the shared **transport** for 1–3 | a copy of every record from 1–3 | `forward_format`, default **JSON** (independent of the stdout format) | the operator's collector (`forward_host`/`_port`) | off-box evidence retention / SIEM correlation | **default-on when a collector is named.** Transport: `udp` (default) / `tcp` / **`tls`** (RFC 5425, CA-anchored, verified by default). `serve` gates the hop on the shared posture gradient before the handler is installed: verified TLS ungated; otherwise loopback / attested / synthetic ALLOW, non-enforcing PHI WARN, **enforcing PHI REFUSE (exit 2)** | the collector's, not the engine's | the identical three filters are installed on this handler, so the forwarded copy is PHI-redacted — but it still carries usernames, connection names, message ids, client addresses and the audit chain. That is the engine's own stated reason for gating the hop | | **5. `audit_log` table** (SQLite, Postgres, SQL Server) | who / what / **where-from** / when of auth + PHI *access* and admin actions — plus, when the opt-in `[security].audit_all_authorization_decisions` is on (**default `false`**; the internal field it desugars to is `audit_all_authz`, whose old `[diagnostics]` TOML spelling is **refused at load** — ADR 0118), an `authz` row for **every** authorization decision including successes, which multiplies this stream's volume — `actor`, `action`, `channel_id`, `client`, `detail`, `row_hash` | JSON `detail`; **tamper-evident hash chain** over `prev_hash` + the row (the `client` address is **inside** the chained payload — ADR 0150) | the store database | HIPAA §164.312(b) audit controls; incident response; `verify_audit_chain` integrity checks | `GET /audit` requires **`audit:read`**; `GET /audit/export` requires the separate **`audit:export`** and streams CSV with formula-injection neutralisation, recording its own `audit.export` row *before* streaming; `GET /me/security-events` is a per-user view of the same table | **`[retention].audit_days` is reserved and NOT enforced — keep-forever by design** (deleting rows would break the chain; HIPAA expects ~6 years) | `detail` is stored **in the clear** (it is not a cipher-covered column): its protection is that writers only ever store filter shapes, counts and ids — never bodies or credentials — plus the store ACL and the volume layer | -| **6. `message_events` table** | the per-message disposition timeline — the **complete** vocabulary is `received`, `routed`, `unrouted`, `filtered`, `transformed`, `delivered`, `failed`, `dead`, `error`, `replayed`, `resent`, `reingressed`, `passthrough`, `passthrough_dropped`, `cancelled`, `edit_resend`, `edit_resubmit`, `viewed`, `not_deployed` (CI asserts this list against the engine's own `MESSAGE_EVENT_KINDS`). `[diagnostics].message_events` can thin the set, but never below the compliance floor `viewed` / `dead` / `error` / `failed` / `not_deployed` | rows: `message_id`, `ts`, `event`, `destination`, `detail` | the store database | operator timeline on the message-detail view; the `viewed` row is the HIPAA PHI-access record | `GET /messages/{id}` under **`messages:view_raw`** + `require_phi_read`; the read itself writes a `viewed` event **and** a `message_view` audit row | no dedicated window — `purge_message_bodies` sets `message_events.detail` to `NULL` in the same transaction that blanks the body, so it inherits `[retention].messages_days` | `detail` is `safe_text()`-scrubbed **then** cipher-encrypted (AAD `("message_events","detail",message_id,ts,event)`). Verbosity gate `[diagnostics].message_events` = `all` (default) / `errors` / `off`, with a **compliance floor that can never be thinned**: `viewed`, `dead`, `error`, `failed`, `not_deployed` are retained at every level | +| **6. `message_events` table** | the per-message disposition timeline — the **complete** vocabulary is `received`, `routed`, `unrouted`, `filtered`, `transformed`, `delivered`, `failed`, `dead`, `error`, `replayed`, `resent`, `reingressed`, `passthrough`, `passthrough_dropped`, `cancelled`, `edit_resend`, `edit_resubmit`, `viewed`, `not_deployed`, and the ADR 0154 synchronous-reply pair `reply_returned` / `reply_timeout` (names, counts and `waited_ms` only — **never** a fragment of the partner's reply body) (CI asserts this list against the engine's own `MESSAGE_EVENT_KINDS`). `[diagnostics].message_events` can thin the set, but never below the compliance floor `viewed` / `dead` / `error` / `failed` / `not_deployed` / `reply_timeout` | rows: `message_id`, `ts`, `event`, `destination`, `detail` | the store database | operator timeline on the message-detail view; the `viewed` row is the HIPAA PHI-access record | `GET /messages/{id}` under **`messages:view_raw`** + `require_phi_read`; the read itself writes a `viewed` event **and** a `message_view` audit row | no dedicated window — `purge_message_bodies` sets `message_events.detail` to `NULL` in the same transaction that blanks the body, so it inherits `[retention].messages_days` | `detail` is `safe_text()`-scrubbed **then** cipher-encrypted (AAD `("message_events","detail",message_id,ts,event)`). Verbosity gate `[diagnostics].message_events` = `all` (default) / `errors` / `off`, with a **compliance floor that can never be thinned**: `viewed`, `dead`, `error`, `failed`, `not_deployed`, `reply_timeout` are retained at every level (`reply_timeout` is the one row that explains a "we called you and got a 504" complaint, so an instance that thinned its logs would lose exactly the record it is later asked for) | | **7. `connection_event` table — DEFAULT ON** (`[diagnostics].connection_events = true`) | transport/lifecycle events per connection: `established`, `closed` (reason `eof` or `idle_timeout` — no path produces any other), `idle_timeout`, `at_capacity`, `peer_not_allowlisted`, `frame_oversize`, `framing_error`, `peer_reset`, the inbound-HTTP intake-auth refusals `intake_auth_failed` / `auth_subject_denied` / `auth_rate_limited` (ADR 0154 D6 — peer address and mode only; **never** the credential, a prefix of it, or its length. Each of these also writes a tamper-evident audit-log row — the copy that survives an operator turning this diagnostics stream off), plus the runner's `connection_lost` / `connection_restored`. That is the whole vocabulary, asserted in CI against the literal emit call sites in `transports/` and the pipeline runner **and** cross-checked against the console's own filter tuple. The MLLP, raw-TCP and HTTP listeners emit these; the **DICOM inbound C-STORE SCP** and the **`ISA`/`IEA`-framed X12 inbound** emit none — the runner injects the sink onto **every** source (`wiring_runner.py`, over the base-class `on_connection_event` field), so both connectors *have* the wiring and simply never call it — so this stream covers those three listeners plus the runner's outbound-lane transitions — not literally every connection. An X12 feed's connects, allow-list refusals and at-capacity refusals are therefore **absent** from this stream | rows: `ts`, `connection`, `transport`, `direction`, `kind`, `peer_host`, `message_id` (correlation hint), `reason` | the store database, **all three backends** | Corepoint-style transport diagnostics — "did the sender connect, and why did it drop" | `GET /events` and `GET /connections/{name}/events` under **`monitoring:read`** (**not** a PHI permission) with per-channel RBAC — an out-of-scope `connection=` is 403'd *and* audited — server-clamped to ≤1000 rows | `[retention].connection_event_retention_hours` (its own **hours** window); 0 inherits `[retention].messages_days`; both 0 = keep forever. Plain age `DELETE` (metadata-only) | **`reason` is free text that can carry sensitive fragments.** Defended twice — `safe_exc()` at the source, `safe_text(reason)[:200]` at the store — then cipher-encrypted (AAD `("connection_event","reason",connection,ts,kind)`). Every other column is config metadata; the table is documented **metadata-only** — never a frame, body or HL7 field value. Writes are a pure side observer: a bounded in-memory queue drained by a background task outside any handoff transaction, so a flood can never block a listener or pin a message disposition | | **8. `alert_instance` table — default on wherever an `[alerts]` notifier exists** | resolvable operator alerts: `connection_stopped`, `queue_buildup`, `lane_stuck`, `message_stall`, `saturation`, `connection_error`, `content_match`, `storage_threshold`, `cert_expiry`, `secret_rotation`, `bootstrap_admin_expiring` (the UNCLAIMED first-run bootstrap admin nearing its auto-disable deadline — ASVS 6.4.5; its payload carries only the ISO deadline plus whole hours remaining, never the password or any secret), `integrity_drift`, `update_available`, `backup_failed`, `rcsi_off_degraded`, `leadership_acquired`, `dr_activated`, `gcm_invocations` (the per-key AES-GCM invocation bound crossing its 2^31 soft warn — ASVS 11.3.4; its payload carries a one-way `key_id` fingerprint plus counters, never key bytes) The three reachable **inverse** signals — `connection_restored`, `leadership_lost`, `dr_released` — are never rows here: `_record_state` routes an inverse through `_AUTO_RESOLVE` to `resolve_alert_instances_for`, never to `upsert_alert_instance`. (A fourth mapped key, `connection_started`, is emitted by no code path today.) | rows: `event_type`, `connection`, `severity`, `status`, `first_seen`, `last_seen`, `count`, `reason`, `acked_by`, `acked_at`, `resolved_at`, `suspended_until`, `escalation_tier` | the store database, **all three backends** | the operator alert list — acknowledge / resolve / suspend. Durable state is recorded **before** any suppression or throttle return, so a muted alert still leaves a record | `GET /alerts/active` under **`monitoring:diagnose`** (**not** a PHI permission) with the same per-channel scope; ack/resolve/suspend/**resume** are POSTs on the same tier, and the separate read-only `GET /alerts/rules` view sits on its own gate | shares the connection-event window; **only RESOLVED instances are DELETEd**, by `resolved_at` — an open or acknowledged condition is never aged out from under an operator | **`reason` is free text** taken from the event's `detail`/`reason`/`label`: `safe_text(reason)[:200]` then cipher-encrypted (AAD `("alert_instance","reason",event_type,connection)` — the de-dup grain, so one AAD covers both the INSERT and the re-fire UPDATE). `content_match` is **PHI-free by contract**: the sink method takes no value parameter, only the connection, an operator label and an optional rule id | | **9. `response` rows with `kind='ack_sent'` — DEFAULT ON** (`[diagnostics].response_sent = true`) | the ACK/NAK the engine returned to an inbound sender, under a sentinel destination `\x1fack:` | rows: `ack_code` (`AA`/`AE`/`AR`/`CA`/`CE`/`CR`), `ack_phase` (`decode`/`parse`/`strict`/`ingest`), `outcome`, `body`, `detail` | the store database | "what did we actually reply, and why" — the operator's answer to a sender disputing an ACK | `GET /messages/{id}/responses` under `messages:read` + `require_phi_read`; the `body` only for a caller who also holds `messages:view_raw`; every read writes a `response.read` audit row | `body`, `detail` and `resp_headers` are set to `NULL` in place by `purge_message_bodies` on the message-body window, on all three backends | **PHI fail-safe:** the ACK **body** is stored **only when the store cipher is active** — on a keyless store it is `NULL` rather than plaintext — and every NAK passes no body at all, so the offending field value is never persisted. The disposition metadata (`ack_code`/`ack_phase`/`outcome`) is non-PHI and always captured; `detail` is `safe_text`-scrubbed, 200-char bounded and encrypted | diff --git a/messagefoundry/api/metrics.py b/messagefoundry/api/metrics.py index bcffc140..de3c3ca0 100644 --- a/messagefoundry/api/metrics.py +++ b/messagefoundry/api/metrics.py @@ -37,6 +37,7 @@ ) from messagefoundry import __version__ +from messagefoundry.pipeline.sync_reply import SyncReplyMetrics from messagefoundry.store.pool_metrics import PoolStatus from messagefoundry.store.store import ( ClaimProcStatus, @@ -201,6 +202,10 @@ class _Snapshot: # is off — the gauges are then ABSENT rather than 0, so a scrape can tell "not requested" from # "requested and degraded" (a constant 0 on every SQLite fleet would be pure alert noise). claim_proc: ClaimProcStatus | None = None + # ADR 0154 D8: per-inbound synchronous-reply counters, read from the runner rather than the + # store — they are process-lifetime in-memory counts, not persisted aggregates. Empty on every + # instance with no reply_from inbound, so those scrapes are byte-identical. + sync_replies: dict[str, SyncReplyMetrics] = field(default_factory=dict) async def gather_snapshot(engine: Engine) -> _Snapshot: @@ -209,6 +214,10 @@ async def gather_snapshot(engine: Engine) -> _Snapshot: All ``await``s — and therefore all store I/O — live here; nothing downstream blocks. """ now = time.time() + # Engine.registry_runner is a public property; the counters live with the runner that owns the + # resolvers because api/metrics.py otherwise builds every family from engine.store alone. + runner = engine.registry_runner + sync_replies = runner.sync_reply_metrics() if runner is not None else {} cm = await engine.store.connection_metrics( since=engine.started_at or now, now=now, rate_window=_RATE_WINDOW ) @@ -225,6 +234,7 @@ async def gather_snapshot(engine: Engine) -> _Snapshot: committed_txns = int(getattr(engine.store, "committed_txns", 0)) body_copies = int(getattr(engine.store, "body_copies", 0)) return _Snapshot( + sync_replies=sync_replies, version=__version__, inbound=cm.inbound, destinations=cm.destinations, @@ -310,6 +320,37 @@ def collect(self) -> Iterable[Any]: received.add_metric([channel_id], float(im.read)) errored.add_metric([channel_id], float(im.errored)) yield received + + # ADR 0154 D8 — the synchronous-reply SLO series. Labelled `status`, NOT `outcome`: the label + # allowlist above is a PHI contract, and the outcome enum is a fixed non-PHI constant set, so + # it rides an existing label rather than widening a deliberately closed one. + # rate(timeout)/rate(total) IS the proxy API's error budget, which is why `degraded` is a + # distinct label value rather than folded into timeout. + if s.sync_replies: + replies = CounterMetricFamily( + "messagefoundry_http_sync_replies_total", + "Synchronous captured-downstream replies resolved, by outcome (process lifetime).", + labels=["connection", "status"], + ) + wait = GaugeMetricFamily( + "messagefoundry_http_sync_reply_wait_seconds", + "Mean time an HTTP turn blocked on a captured downstream reply (process lifetime). " + "Answers 'is this approaching reply_timeout?' before the pager does.", + labels=["connection"], + ) + waiters = GaugeMetricFamily( + "messagefoundry_http_sync_reply_waiters", + "HTTP turns currently blocked on a captured downstream reply.", + labels=["connection"], + ) + for connection, m in sorted(s.sync_replies.items()): + for status, count in sorted(m.totals.items()): + replies.add_metric([connection, status], float(count)) + wait.add_metric([connection], m.mean_wait_seconds) + waiters.add_metric([connection], float(m.live)) + yield replies + yield wait + yield waiters yield errored # --- outbound counters + gauges (per connection/destination) --------- diff --git a/messagefoundry/checks.py b/messagefoundry/checks.py index 73d14ba4..9cf71301 100644 --- a/messagefoundry/checks.py +++ b/messagefoundry/checks.py @@ -1303,6 +1303,10 @@ def _check_build( # hop raises here rather than shipping and only refusing at serve. posture=hop_posture_from_ai(settings.ai, enforcement=settings.security.enforcement), trust_anchor_policy=settings.tls.policy(), + # ADR 0154 D4: the EFFECTIVE ordering / max_attempts refusals need the resolved + # [delivery] defaults. Without them that arm is skipped rather than guessed, and the + # misconfiguration would surface only at serve rather than at commit/CI. + delivery=settings.delivery, ) except WiringError as exc: return CheckResult("build-check", ok=False, required=True, detail=str(exc)) diff --git a/messagefoundry/config/wiring.py b/messagefoundry/config/wiring.py index 58367d21..11a6496f 100644 --- a/messagefoundry/config/wiring.py +++ b/messagefoundry/config/wiring.py @@ -1104,6 +1104,16 @@ def Http( | None = 10, # FAILED intake-auth attempts per minute per peer (0/None disables) intake_auth_rate_limit_global: int | None = 60, # FAILED intake-auth attempts per minute across all peers + # --- Synchronous captured-downstream reply (ADR 0154 D4) — reply_from's presence is the switch --- + reply_from: str + | None = None, # names the outbound whose CAPTURED reply becomes this request's HTTP body + reply_timeout: float = 30.0, # seconds the HTTP turn may block waiting for that reply + reply_on_timeout: Literal["504", "202"] = "504", # what to answer when the wait expires + reply_content_type: str = "passthrough", # "passthrough" (echo the captured one) or a literal MIME + reply_on_empty: Literal[ + "204", "200" + ] = "204", # answer for a captured but deliberately empty reply + reply_write_timeout: float = 30.0, # seconds to drain the (partner-sized) response to the caller ) -> ConnectionSpec: """An **inbound HTTP/1.1 web-service listener** (ADR 0023) — a connector-owned bound socket that a partner ``POST``s a body to (REST / SOAP-body / FHIR / webhook). Source-only: it never delivers. The @@ -1146,7 +1156,34 @@ def Http( Health probes are **inside** the gate by default; ``intake_auth_health="allow"`` exempts ``GET``/ ``HEAD`` for a load-balancer check, at the cost of an unauthenticated "is MessageFoundry up, and - where" oracle on a PHI intake socket.""" + where" oracle on a PHI intake socket. + + **Synchronous captured-downstream reply (ADR 0154 D4).** Naming ``reply_from`` turns this inbound + from fire-and-forget into a **proxy**: the HTTP turn blocks until the named outbound's reply has + been captured and **committed**, then returns that reply as the response body. One knob, not two — + a separate ``sync_reply: bool`` would admit a half-configured state (mode on, no target) that + could only fail at runtime. + + The returned bytes always come from a **committed** ``response`` row, never from an in-flight + delivery, so a reply is returned only once it is durable and replayable. ``reply_timeout`` bounds + the block and ``reply_write_timeout`` bounds the drain of the (partner-sized) response back to the + caller, so a sync-reply turn has three independent clocks with ``receive_timeout`` still bounding + the read. A timeout answers ``reply_on_timeout`` and **leaves the message flowing** — the HTTP + status is never a second disposition channel, and the finalizer remains the only authority on + that. + + ``reply_content_type="passthrough"`` echoes the partner's own captured ``content-type``; a literal + MIME type pins it instead. ``reply_on_empty`` chooses how a deliberately empty partner reply is + answered — ``204`` is correct, ``200`` is the escape hatch for toolchains that mishandle a + bodyless response. + + **The reply body is PHI**: the partner's response, decrypted out of the store. It is returned to + the caller and *nowhere else* — never logged, and never placed in an exception, a + ``connection_event.reason`` or a ``message_events.detail``. + + An inbound **without** ``reply_from`` keeps the shipped ``202``-on-receipt behaviour byte for + byte; every knob above is inert without it, and setting one alone is refused rather than silently + ignored.""" settings: dict[str, Any] = { "port": port, "encoding": encoding, @@ -1167,11 +1204,139 @@ def Http( "intake_auth_health": intake_auth_health, "intake_auth_rate_limit": intake_auth_rate_limit, "intake_auth_rate_limit_global": intake_auth_rate_limit_global, + "reply_from": reply_from, + "reply_timeout": reply_timeout, + "reply_on_timeout": reply_on_timeout, + "reply_content_type": reply_content_type, + "reply_on_empty": reply_on_empty, + "reply_write_timeout": reply_write_timeout, } _validate_intake_auth(settings) + _validate_sync_reply(settings) return ConnectionSpec(ConnectorType.HTTP, settings) +#: The synchronous-reply knobs. Every one is inert without ``reply_from``, so setting any of them +#: alone is a configuration that silently does nothing — refused, for the same reason a credential +#: configured with ``intake_auth="none"`` is. +_SYNC_REPLY_KNOBS = ( + "reply_timeout", + "reply_on_timeout", + "reply_content_type", + "reply_on_empty", + "reply_write_timeout", +) + + +def _sync_reply_defaults() -> dict[str, Any]: + """The knobs' default values, read off :func:`Http`'s own signature. + + Derived rather than duplicated on purpose: a hand-copied table would go stale the first time a + default changed, and the failure would be silent — the "configured but never read" refusal below + would simply stop firing for that knob, which is the opposite of what a guard should do when it + drifts. Cheap: this runs once per ``Http()`` call, and only on the path that is already about to + raise or return.""" + params = inspect.signature(Http).parameters + return {name: params[name].default for name in _SYNC_REPLY_KNOBS} + + +def apply_sync_reply_capture_implication(registry: Registry) -> None: + """Make ``reply_from`` imply capturing the partner's ``content-type`` (ADR 0154 D4, owner ruling). + + **Resolves a contradiction in the ADR itself.** ``reply_content_type`` defaults to + ``"passthrough"``, and D4 then requires ``"content-type"`` to be in the named outbound's + ``capture_response_headers`` — which defaults to ``None`` on all three capable factories, and + ``normalize_header_allowlist(None)`` is the empty set. So the ADR's own headline shape, + ``Http(reply_from="X")`` + ``Rest(capture_response=True)``, would raise at ``check`` until the + operator *also* wrote ``capture_response_headers=["content-type"]``. Asking for a reply to be + echoed back verbatim **is** asking for its content type; requiring both is a papercut with no + decision behind it. + + Applied as an explicit, **idempotent** normalisation of the resolved graph rather than a hidden + runtime fallback, so the implied header appears in ``/metadata`` and ``graph --json`` like any + other captured header. An operator reading the outbound's configuration sees what is actually + captured — which is the point: an implication nobody can observe is indistinguishable from a bug. + + Only touches outbounds that are the ``reply_from`` target of an inbound using ``passthrough``, + and only those whose factory has the setting at all (it exists on 3 of the 8 outbound factories). + A capturing outbound with no allow-list is left alone and refused explicitly by + :func:`~messagefoundry.pipeline.wiring_runner.check_http_sync_reply`. + """ + targets: set[str] = set() + for ic in registry.inbound.values(): + if ic.spec.type is not ConnectorType.HTTP: + continue + reply_from = ic.spec.settings.get("reply_from") + if reply_from and ic.spec.settings.get("reply_content_type") == "passthrough": + targets.add(str(reply_from)) + + for name in sorted(targets): + oc = registry.outbound.get(name) + if oc is None or "capture_response_headers" not in oc.spec.settings: + continue # unknown target, or a factory with no allow-list — both refused elsewhere + current = oc.spec.settings.get("capture_response_headers") or [] + if any(str(h).strip().lower() == "content-type" for h in current): + continue # already asked for — idempotent + oc.spec.settings["capture_response_headers"] = [*current, "content-type"] + + +def _validate_sync_reply(settings: Mapping[str, Any]) -> None: + """Refuse a synchronous-reply configuration that cannot work, at **factory** time (ADR 0154 D4). + + Factory-local checks only — everything decidable from this one ``Http()`` call, with no store, no + posture and no registry, so it fires identically in ``messagefoundry check``, in dry-run, and + through the ``connections.toml`` desugar. + + The **cross-registry** half lives in ``build_check_registry``: that ``reply_from`` names a + deployed outbound, that the outbound captures responses, the ``passthrough`` content-type + requirement, and the effective ``ordering``/``max_attempts`` refusals. None of those are knowable + from here, and pretending otherwise would mean validating against a registry this function + cannot see. + """ + reply_from = settings["reply_from"] + if reply_from is not None and not str(reply_from).strip(): + raise WiringError("Http reply_from must name an outbound connection, not an empty string") + + if reply_from is None: + defaults = _sync_reply_defaults() + configured = [name for name in _SYNC_REPLY_KNOBS if settings[name] != defaults[name]] + if configured: + raise WiringError( + f"Http sets {', '.join(configured)} but no reply_from, so the synchronous-reply path " + "is off and none of them is ever read — name the outbound whose captured reply should " + "become the HTTP body, or remove the setting" + ) + return + + for name in ("reply_timeout", "reply_write_timeout"): + value = settings[name] + if not isinstance(value, int | float) or value <= 0: + raise WiringError( + f"Http {name} must be a positive number of seconds — got {value!r}. It bounds a " + "blocked HTTP turn; an unbounded or zero budget is not a timeout" + ) + + if settings["reply_on_timeout"] not in ("504", "202"): + raise WiringError( + f"Http reply_on_timeout must be '504' or '202' — got {settings['reply_on_timeout']!r}" + ) + if settings["reply_on_empty"] not in ("204", "200"): + raise WiringError( + f"Http reply_on_empty must be '204' or '200' — got {settings['reply_on_empty']!r}" + ) + + content_type = settings["reply_content_type"] + if not content_type or not str(content_type).strip(): + raise WiringError( + "Http reply_content_type must be 'passthrough' or a literal MIME type, not empty" + ) + if content_type != "passthrough" and "/" not in str(content_type): + raise WiringError( + f"Http reply_content_type must be 'passthrough' or a MIME type — got {content_type!r}, " + "which is neither (a MIME type contains a '/', e.g. 'application/json')" + ) + + #: The intake-auth modes that carry a shared-secret credential (as opposed to a client certificate). _INTAKE_KEY_MODES = ("api_key", "bearer") #: Qualified-namespace prefixes an ``intake_client_subjects`` entry may take, mirroring what diff --git a/messagefoundry/pipeline/reply_wait.py b/messagefoundry/pipeline/reply_wait.py new file mode 100644 index 00000000..03ea6d7d --- /dev/null +++ b/messagefoundry/pipeline/reply_wait.py @@ -0,0 +1,183 @@ +# SPDX-License-Identifier: AGPL-3.0-or-later +# Copyright (C) 2026 MessageFoundry Organization and contributors +"""In-process rendezvous for the synchronous captured-downstream reply (ADR 0154 D3). + +**Every signal here is a LATENCY HINT and never an answer.** A woken waiter re-reads the store and +decides from the committed row; nothing that arrives through this module is treated as data. That is +the property the whole design rests on, and it is what makes the module safe to be wrong: a hint that +never fires costs latency (the poll still finds the reply), and a hint that fires spuriously costs one +extra read. Neither can produce an incorrect HTTP response. + +Because of that, :meth:`ReplyRendezvous.signal` and :meth:`ReplyRendezvous.fail` are **deliberately +indistinguishable to the waiter**. They differ only in what the caller is reporting. If they resolved +the wait differently, the signal would have become data — the exact mistake this design exists to +avoid — so the asymmetry is in the names and the docs, not the behaviour. + +**Thread-affinity, and it is load-bearing.** ``asyncio.Event.set()`` is *not* thread-safe, and neither +is the ``call_soon`` that schedules a waiter's wakeup. Every method here must be called from the event +loop thread. The engine has real off-loop paths that look like tempting hook sites — the fused +route/transform bodies run in a ``ThreadPoolExecutor`` — and calling in from one usually *appears* to +work while intermittently dropping wakeups, which is the worst failure signature available: silent, +rare, and load-dependent. Hook the loop-side marshalling instead. +""" + +from __future__ import annotations + +import asyncio +from collections.abc import Iterator +from contextlib import contextmanager +from typing import Final + +__all__ = ["ReplyRendezvous", "ReplyWaiter", "RendezvousFull"] + +#: Default cap on simultaneously armed waiters. A backstop against a leak or a deliberate flood, not +#: a second refusal point for ordinary load — the listener's own ``max_connections`` bounds that, and +#: an arm refused here resolves to the ``degraded`` outcome rather than an error. +DEFAULT_MAX_WAITERS: Final = 512 + + +class RendezvousFull(RuntimeError): + """Raised by :meth:`ReplyRendezvous.arm` when the waiter cap is reached, or while draining. + + The caller maps this to the ``degraded`` outcome. It is deliberately not a timeout: a timeout + means "the partner did not answer in time", which would be a lie about the partner and would + corrupt the ``rate(timeout)/rate(total)`` SLO series that an operator pages on. + """ + + +class ReplyWaiter: + """One armed wait. Obtained from :meth:`ReplyRendezvous.arm`, never constructed directly.""" + + __slots__ = ("_event", "_drain_reason") + + def __init__(self) -> None: + self._event = asyncio.Event() + self._drain_reason: str | None = None + + @property + def drain_reason(self) -> str | None: + """The reason this waiter was drained (listener shutdown), or ``None``. + + The caller checks this after every :meth:`hint` and stops waiting when it is set — it is the + one condition that is *not* re-derived from the store, because it describes **us**, not the + message. + """ + return self._drain_reason + + async def hint(self, timeout: float) -> None: + """Sleep up to ``timeout`` seconds, returning early if a hint arrived. + + Returns nothing on purpose: there is no outcome to report. The caller always re-reads the + store afterwards, whether it woke early, timed out, or was drained. + + **The hint is consumed before returning.** An ``asyncio.Event`` stays set once set, so a + waiter that looped on an unconsumed Event would stop sleeping entirely and spin at full CPU + for the rest of ``reply_timeout`` — and it would do so precisely in the legitimate case that + drives repeated wakes: a message fanned out to several handlers, where every sibling's + progress wakes us and the store correctly says "keep waiting". + + A drained waiter returns immediately and never blocks again. + """ + if self._drain_reason is not None: + return + try: + await asyncio.wait_for(self._event.wait(), timeout) + except TimeoutError: + return + finally: + # Consume it even on the timeout path: a hint that landed in the race between wait_for + # expiring and this line would otherwise survive to skip the NEXT sleep for free. + self._event.clear() + + def _wake(self) -> None: + self._event.set() + + def _drain(self, reason: str) -> None: + self._drain_reason = reason + self._event.set() + + +class ReplyRendezvous: + """Wakes HTTP turns blocked on a captured downstream reply, keyed by ``(message_id, dest)``. + + Owned by the runner and injected into the resolver, so ``transports/`` never imports it. + """ + + __slots__ = ("_waiters", "_max_waiters", "_draining") + + def __init__(self, *, max_waiters: int = DEFAULT_MAX_WAITERS) -> None: + self._waiters: dict[tuple[str, str], set[ReplyWaiter]] = {} + self._max_waiters = max_waiters + self._draining: str | None = None + + @property + def waiters(self) -> int: + """Currently armed waiters. Tested to return to zero — see :meth:`arm`.""" + return sum(len(group) for group in self._waiters.values()) + + @contextmanager + def arm(self, message_id: str, destination_name: str) -> Iterator[ReplyWaiter]: + """Arm a waiter for the duration of the ``with`` block. + + **A context manager rather than an arm/disarm pair, structurally.** An entry that outlives its + turn — a missed disarm, a cancellation landing between arm and ``try``, an early return — + accumulates silently until :data:`DEFAULT_MAX_WAITERS`, after which *every* subsequent caller + resolves ``degraded`` while the store is perfectly healthy and no error appears anywhere. A + slow-motion listener outage with no signal is not a failure mode worth leaving to caller + discipline, so the release is not the caller's to forget. + + Raises :class:`RendezvousFull` when the cap is reached or the listener is draining. + """ + if self._draining is not None: + raise RendezvousFull(f"listener is draining ({self._draining})") + if self.waiters >= self._max_waiters: + raise RendezvousFull(f"reply rendezvous at capacity ({self._max_waiters} waiters)") + + key = (message_id, destination_name) + waiter = ReplyWaiter() + self._waiters.setdefault(key, set()).add(waiter) + try: + yield waiter + finally: + group = self._waiters.get(key) + if group is not None: + group.discard(waiter) + if not group: # drop the empty bucket so the dict tracks live keys, not history + del self._waiters[key] + + def signal(self, message_id: str, destination_name: str) -> None: + """Hint that a reply for this key **may** have committed. Never raises. + + Must be called only **after** the capturing transaction has returned normally. Signalling + from a ``finally``, or before the await, fires on a transaction that may have rolled back — + harmless here only because the waiter re-reads, but it wastes the wake and misleads anyone + reading the code into thinking the signal carries information. + """ + self._wake(message_id, destination_name) + + def fail(self, message_id: str, destination_name: str) -> None: + """Hint that this message **may** have reached a state where no reply will arrive. + + Behaviourally identical to :meth:`signal`, and that is deliberate — see the module docstring. + In particular a *sibling* handler's terminal outcome legitimately fires this while the awaited + destination is still perfectly healthy; the waiter re-reads, sees the message is still + flowing, and keeps waiting. Nothing here may shortcut that. + """ + self._wake(message_id, destination_name) + + def _wake(self, message_id: str, destination_name: str) -> None: + # An unknown key is the normal case, not an error: almost no message is being awaited, and + # every delivery calls this. Silence is the contract. + for waiter in self._waiters.get((message_id, destination_name), ()): + waiter._wake() + + def drain(self, reason: str) -> None: + """Wake every waiter for listener shutdown and refuse further arms. + + Called from ``stop()`` **before** client writers are closed, so each woken turn can still + write its ``503`` through a live socket. Idempotent. + """ + self._draining = reason + for group in list(self._waiters.values()): + for waiter in list(group): + waiter._drain(reason) diff --git a/messagefoundry/pipeline/sync_reply.py b/messagefoundry/pipeline/sync_reply.py new file mode 100644 index 00000000..1a135d02 --- /dev/null +++ b/messagefoundry/pipeline/sync_reply.py @@ -0,0 +1,321 @@ +# SPDX-License-Identifier: AGPL-3.0-or-later +# Copyright (C) 2026 MessageFoundry Organization and contributors +"""The synchronous-reply resolver (ADR 0154 D3) — the wait loop behind a ``reply_from`` HTTP turn. + +**The committed row is the sole authority.** Every in-process signal is a latency hint; this loop +decides only from what the store says. A hint that never fires costs latency, a hint that fires +spuriously costs one extra read, and neither can produce an incorrect response. That is what makes +the design correct under engine sharding, HA failover, every claim mode, and any race between the +capturing worker and this reader. + +Runner-owned, injected into the listener as a plain callable, so ``transports/`` keeps its +CI-enforced freedom from ``store/`` and ``pipeline/`` imports (AC-17) while still returning bytes that +came out of the store. +""" + +from __future__ import annotations + +import logging +import time +from typing import Final + +from messagefoundry.pipeline.reply_wait import RendezvousFull, ReplyRendezvous +from messagefoundry.store.base import QueueStore +from messagefoundry.store.store import OutboxStatus +from messagefoundry.transports.base import InboundReply, ReplyOutcome + +log = logging.getLogger(__name__) + +#: Fastest a single waiter may re-read. Deliberately not zero: the hint already collapses the common +#: case to ~one read, so a tighter floor buys latency nobody notices and costs pooled reads everyone +#: shares. +_POLL_FLOOR_SECONDS: Final = 0.025 +#: Slowest a waiter backs off to. Bounds worst-case added latency when hints are unavailable — the +#: engine-shard case, where the delivery signal fires in the process that owns the lane, not ours. +_POLL_CEILING_SECONDS: Final = 0.25 +#: Live-waiter count past which the floor is widened. On SQLite, reads share a FIXED pool of four +#: connections with the admin API, console, retention and alert sweeps, so N waiters spinning at the +#: floor is a self-inflicted denial of service against the very store they are waiting on. The period +#: therefore scales with load rather than being a constant an operator has to reason about. +_POLL_SCALE_AFTER_WAITERS: Final = 8 + +#: Terminal delivery states for the awaited destination's row: no reply can still arrive. +_TERMINAL_ROW_STATES: Final = frozenset({OutboxStatus.DEAD.value, OutboxStatus.CANCELLED.value}) + + +def poll_period(waiters: int) -> float: + """Seconds to wait before the next re-read, given the number of live waiters. + + Floored as an explicit function of load, which the ADR asserts is necessary without specifying + it. The alternative — a constant — is what turns 256 blocked callers into ~1,000 pooled reads a + second against a four-connection pool. + """ + if waiters <= _POLL_SCALE_AFTER_WAITERS: + return _POLL_FLOOR_SECONDS + scaled = _POLL_FLOOR_SECONDS * (waiters / _POLL_SCALE_AFTER_WAITERS) + return min(scaled, _POLL_CEILING_SECONDS) + + +#: Outcomes that count as "a reply came back", so they get a ``reply_returned`` row. ``rejected`` and +#: ``empty`` belong here: the partner answered, and the answer is what the caller was waiting for even +#: when it is negative or deliberately blank. +_RETURNED_OUTCOMES: Final = frozenset( + {ReplyOutcome.REPLY, ReplyOutcome.REJECTED, ReplyOutcome.EMPTY} +) + + +class SyncReplyMetrics: + """In-process counters for one inbound's sync-reply path (ADR 0154 D8). + + **Labelled ``status``, not ``outcome``.** ``api/metrics.py`` states a CLOSED label allowlist as a + PHI contract — ``connection``/``destination``/``status``/``version``/``le`` — and + ``tests/test_metrics_exporter.py`` asserts it. The outcome enum is a fixed, non-PHI constant set, + so reusing ``status`` is honest rather than a workaround, and it keeps a contract that was + deliberately closed from being widened for a label that adds no new information. + + Counters live here rather than in ``api/metrics.py`` because that module builds every family + per-scrape from ``engine.store`` alone and has no view of the runner — and ``transports/`` may not + import ``api/`` (AC-17). The runner owns these and exposes them; the exporter reads them. + """ + + __slots__ = ("connection", "totals", "wait_seconds_sum", "wait_count", "live") + + def __init__(self, connection: str) -> None: + self.connection = connection + #: Turns currently blocked on THIS inbound. Tracked per connection rather than read off the + #: rendezvous, because the rendezvous is shared by every inbound in the runner — publishing + #: its total under a ``{connection}`` label would attribute one listener's load to all of + #: them, which is worse than no gauge at all for the thing operators size capacity on. + self.live = 0 + #: ``{status: count}`` — the SLO series. ``rate(timeout)/rate(total)`` is the proxy API's + #: error budget, which is exactly why ``degraded`` is a distinct label rather than folded in. + self.totals: dict[str, int] = {} + self.wait_seconds_sum = 0.0 + self.wait_count = 0 + + def record(self, outcome: ReplyOutcome, waited_ms: int) -> None: + self.totals[outcome.value] = self.totals.get(outcome.value, 0) + 1 + self.wait_seconds_sum += waited_ms / 1000.0 + self.wait_count += 1 + + @property + def mean_wait_seconds(self) -> float: + """Mean blocked time. Answers *"is p99 approaching reply_timeout?"* before the pager does.""" + return self.wait_seconds_sum / self.wait_count if self.wait_count else 0.0 + + +class SyncReplyResolverImpl: + """Resolves one blocked HTTP turn into an :class:`InboundReply`. Never raises.""" + + __slots__ = ( + "_store", + "_rendezvous", + "_destination", + "_timeout", + "_content_type", + "_on_timeout", + "_metrics", + ) + + def __init__( + self, + store: QueueStore, + rendezvous: ReplyRendezvous, + *, + destination: str, + timeout: float, + content_type: str, + on_timeout: str = "504", + metrics: SyncReplyMetrics | None = None, + ) -> None: + self._store = store + self._rendezvous = rendezvous + self._destination = destination + self._timeout = timeout + self._content_type = content_type + self._on_timeout = on_timeout + self._metrics = metrics + + async def __call__(self, message_id: str) -> InboundReply: + if self._metrics is not None: + self._metrics.live += 1 + try: + reply = await self._resolve(message_id) + finally: + # try/finally, not a decrement after the await: a cancelled turn (client hung up, task + # torn down) must not leak a permanently-blocked waiter into the gauge an operator sizes + # capacity on. + if self._metrics is not None: + self._metrics.live -= 1 + await self._observe(message_id, reply) + return reply + + async def _observe(self, message_id: str, reply: InboundReply) -> None: + """Record the outcome (ADR 0154 D8/AC-18) — names, counts and timings only. + + **Fail-soft, and that is a decision rather than caution.** This runs after the wait has + already resolved, so a store hiccup here must not turn a perfectly good partner reply into a + ``500``: the caller's answer is already determined, and losing a diagnostic row is strictly + better than losing the reply it describes. + + **No fragment of the partner's body reaches ``detail``.** The structural rule is that + reply-derived bytes never leave the resolver's return value, so the only things interpolated + here are the destination name, the sequence number, the outcome enum and a duration — + every one of which is config metadata or a count. + """ + if self._metrics is not None: + self._metrics.record(reply.outcome, reply.waited_ms) + + if reply.outcome in _RETURNED_OUTCOMES: + event, detail = ( + "reply_returned", + f"dest={self._destination} seq={reply.response_seq} " + f"outcome={reply.outcome.value} waited_ms={reply.waited_ms}", + ) + elif reply.outcome is ReplyOutcome.TIMEOUT: + event, detail = ( + "reply_timeout", + f"dest={self._destination} waited_ms={reply.waited_ms} fallback={self._on_timeout}", + ) + else: + # Every other outcome already has its own disposition trail — a dead/cancelled row, an + # UNROUTED message, or (for degraded) the metric label. Minting a second record of the + # same fact would make the timeline read as two events where one thing happened. + return + + try: + await self._store.record_message_event( + message_id, event, destination=self._destination, detail=detail + ) + except Exception as exc: # noqa: BLE001 - observability must never fail the turn + log.warning( + "sync reply: could not record %s for %s: %s", + event, + message_id, + exc.__class__.__name__, + ) + + async def _resolve(self, message_id: str) -> InboundReply: + """Block until the awaited reply commits, the message goes terminal, or the budget expires. + + **Total by construction.** Every exit is an :class:`InboundReply`; nothing propagates. A + store error resolves ``degraded`` rather than raising, because a raise here would surface as + a ``500`` and lose the committed message's disposition from the operator's view — and because + ``degraded`` is deliberately distinct from ``timeout``, which means "the partner did not + answer" and drives an SLO an operator pages on. + """ + started = time.monotonic() + deadline = started + self._timeout + + def elapsed_ms() -> int: + return int((time.monotonic() - started) * 1000) + + try: + with self._rendezvous.arm(message_id, self._destination) as waiter: + while True: + try: + state = await self._store.reply_wait_state(message_id, self._destination) + except Exception as exc: # noqa: BLE001 - total by contract; see the docstring + # safe_exc is not used: this is our own error text, never reply-derived. + log.warning( + "sync reply: state read failed for %s/%s: %s", + message_id, + self._destination, + exc.__class__.__name__, + ) + return self._done(ReplyOutcome.DEGRADED, elapsed_ms()) + + if state.latest_response_seq is not None: + return await self._read_committed_reply( + message_id, state.latest_response_seq, elapsed_ms() + ) + + # Fail fast on a PROVEN-terminal delivery, but only on the row's own state — + # never on the ABSENCE of rows. A sibling handler still upstream leaves this + # empty (routed rows carry a NULL destination_name), and reading that as + # exclusion is the 502-for-a-message-we-then-delivered defect. + if any(s in _TERMINAL_ROW_STATES for s in state.row_states): + return self._done(ReplyOutcome.FAILED, elapsed_ms()) + + if state.message_is_terminal: + # Terminal with no reply and no dead row: nothing routed here at all. + return self._done(ReplyOutcome.NO_ROUTE, elapsed_ms()) + + remaining = deadline - time.monotonic() + if remaining <= 0: + return self._done(ReplyOutcome.TIMEOUT, elapsed_ms()) + + await waiter.hint(min(poll_period(self._rendezvous.waiters), remaining)) + if waiter.drain_reason is not None: + return self._done(ReplyOutcome.SHUTTING_DOWN, elapsed_ms()) + except RendezvousFull: + # Capacity or shutdown — OUR condition, not the partner's. Never a timeout. + return self._done(ReplyOutcome.DEGRADED, elapsed_ms()) + + async def _read_committed_reply( + self, message_id: str, seq: int, waited_ms: int + ) -> InboundReply: + """Fetch the committed reply once and map it onto the wire outcome.""" + try: + captured = [ + row + for row in await self._store.correlate_response(message_id) + if row.kind == "response" and row.destination_name == self._destination + ] + except Exception as exc: # noqa: BLE001 - total by contract + log.warning( + "sync reply: reply read failed for %s/%s: %s", + message_id, + self._destination, + exc.__class__.__name__, + ) + return self._done(ReplyOutcome.DEGRADED, waited_ms) + + if not captured: # raced with retention, or the seq belonged to a purged row + return self._done(ReplyOutcome.PURGED, waited_ms, response_seq=seq) + + # Highest seq wins: a replay appends seq=N+1 rather than overwriting, so the latest capture + # is the authoritative reply for this destination. + row = max(captured, key=lambda r: r.response_seq) + if row.body is None: + # The row exists but retention nulled the body in place. Distinct from "no reply". + return self._done(ReplyOutcome.PURGED, waited_ms, response_seq=row.response_seq) + + if row.outcome == "no_reply": + return self._done(ReplyOutcome.EMPTY, waited_ms, response_seq=row.response_seq) + + outcome = ReplyOutcome.REPLY if row.outcome == "accepted" else ReplyOutcome.REJECTED + return InboundReply( + outcome=outcome, + body=row.body, + content_type=self._resolve_content_type(row), + destination=self._destination, + response_seq=row.response_seq, + waited_ms=waited_ms, + ) + + def _resolve_content_type(self, row: object) -> str | None: + """The Content-Type to echo, or ``None`` to let the caller use its own default. + + ``passthrough`` reads the partner's own captured header — which ``reply_from`` implies + capturing, so it is normally present. It can still be absent when retention has nulled the + captured headers, and that must degrade to the caller's default rather than fail the turn: + the body is still perfectly good. + """ + if self._content_type != "passthrough": + return self._content_type + headers = getattr(row, "headers", None) or {} + for name, value in headers.items(): + if str(name).strip().lower() == "content-type": + return str(value) + return None + + def _done( + self, outcome: ReplyOutcome, waited_ms: int, *, response_seq: int | None = None + ) -> InboundReply: + return InboundReply( + outcome=outcome, + destination=self._destination, + response_seq=response_seq, + waited_ms=waited_ms, + ) diff --git a/messagefoundry/pipeline/wiring_runner.py b/messagefoundry/pipeline/wiring_runner.py index f6201319..46515da5 100644 --- a/messagefoundry/pipeline/wiring_runner.py +++ b/messagefoundry/pipeline/wiring_runner.py @@ -67,7 +67,7 @@ StallThreshold, ) from messagefoundry.config.run_context import RunContext, run_contexts -from messagefoundry.config.settings import EgressSettings, StoreBackend +from messagefoundry.config.settings import DeliverySettings, EgressSettings, StoreBackend from messagefoundry.config.tls_policy import ( HopPosture, TrustAnchorPolicy, @@ -81,6 +81,7 @@ PortConflictError, Registry, WiringError, + apply_sync_reply_capture_implication, bindings_overlap, inbound_binding_conflicts, resolve_env_settings, @@ -122,6 +123,7 @@ DeliveryPhaseTiming, delivery_phase_timing_enabled, ) +from messagefoundry.pipeline.reply_wait import ReplyRendezvous from messagefoundry.pipeline.sandbox import SandboxMode, SandboxPolicy, SandboxSession from messagefoundry.pipeline.saturation import SaturationDetector from messagefoundry.pipeline.sharding import owner_shard_of_destination @@ -130,6 +132,7 @@ LaneResultKind, StageDispatcher, ) +from messagefoundry.pipeline.sync_reply import SyncReplyMetrics, SyncReplyResolverImpl from messagefoundry.redaction import safe_exc, safe_text from messagefoundry.store import ( MessageStatus, @@ -148,7 +151,12 @@ build_destination, build_source, ) -from messagefoundry.transports.base import ConnectionEventSink, IntakeAuditSink, IntakeRateLimiter +from messagefoundry.transports.base import ( + ConnectionEventSink, + IntakeAuditSink, + IntakeRateLimiter, + SyncReplyResolver, +) from messagefoundry.transports.database import DatabaseLookupExecutor from messagefoundry.transports.fhir import FhirLookupExecutor from messagefoundry.transports.mllp import build_ack @@ -730,6 +738,13 @@ def __init__( ) -> None: self.registry = registry self.store = store + #: ADR 0154 D3. One rendezvous per runner: the waiter and the capturing worker are the same + #: process by construction (under HA the graph runs on the leader only), so process-local is + #: the right scope. It carries no information — every signal is a latency hint and the waiter + #: re-reads the store — so a shard that never sees a signal is merely slower, never wrong. + self._reply_rendezvous = ReplyRendezvous() + #: Per-inbound sync-reply counters, exposed via sync_reply_metrics() (ADR 0154 D8). + self._sync_reply_metrics: dict[str, SyncReplyMetrics] = {} # ADR 0087 (#197) opt-in Router/Handler subprocess isolation. None or mode=off → in-process, # byte-identical, zero overhead (no session ever constructed). mode=subprocess → one PERSISTENT # worker child per inbound, built lazily on first dispatch (off the loop, inside the worker @@ -1256,6 +1271,53 @@ async def _sink(action: str, client: str | None, detail: str | None) -> None: return _sink + def _make_sync_reply_resolver(self, ic: InboundConnection) -> SyncReplyResolver | None: + """The per-inbound synchronous-reply resolver (ADR 0154 D2/D3), or ``None``. + + ``None`` unless this inbound declares ``reply_from``, which is what keeps every other + connection on the shipped ``202`` path byte for byte (AC-8). + + Also re-runs the cross-registry validation **here**, where ``[delivery]`` is resolved. The + offline arm in ``build_check_registry`` skips the effective ``ordering``/``max_attempts`` + refusals whenever its caller could not supply those defaults, so this is the backstop that + makes them unconditional — a graph that would serialise every concurrent caller behind one + FIFO lane fails to start rather than degrading silently under load, and ADR 0031 isolates + that to this one connection. + """ + if ic.spec.type is not ConnectorType.HTTP or not ic.spec.settings.get("reply_from"): + return None + check_http_sync_reply( + ic, + self.registry, + delivery=DeliverySettings( + ordering=self._ordering_default, + # The runner resolves an outbound's retry as `oc.retry or self._delivery_defaults`, + # so the inherited max_attempts is that default policy's — not a separate scalar. + retry_max_attempts=self._delivery_defaults.max_attempts, + ), + ) + settings = ic.spec.settings + metrics = self._sync_reply_metrics.setdefault(ic.name, SyncReplyMetrics(ic.name)) + return SyncReplyResolverImpl( + self.store, + self._reply_rendezvous, + destination=str(settings["reply_from"]), + timeout=float(settings.get("reply_timeout") or 30.0), + content_type=str(settings.get("reply_content_type") or "passthrough"), + on_timeout=str(settings.get("reply_on_timeout") or "504"), + metrics=metrics, + ) + + def sync_reply_metrics(self) -> dict[str, SyncReplyMetrics]: + """Per-inbound synchronous-reply counters, keyed by connection name (ADR 0154 D8). + + The PUBLIC accessor the metrics exporter reads. api/metrics.py builds every family per scrape + from engine.store alone and has no view of the runner, while transports/ may not import api/ + (AC-17) — so the counters live with the runner that owns the resolvers, and the exporter pulls + them through here rather than reaching into a private attribute. + """ + return dict(self._sync_reply_metrics) + def _make_intake_rate_limiter(self, ic: InboundConnection) -> IntakeRateLimiter | None: """The per-inbound failed-attempt budget, or ``None`` when both arms are disabled.""" if not self._intake_auth_enabled(ic): @@ -2101,6 +2163,13 @@ async def _start_inbound_unsafe(self, name: str) -> None: # gains no auth/ edge either — pipeline/ owns both, which is the only layer allowed to. source.on_intake_audit = self._make_intake_audit_sink(ic) source.intake_rate_limiter = self._make_intake_rate_limiter(ic) + # ADR 0154 D2: the resolver that lets the listener return bytes out of the store while + # transports/ imports neither store/ nor pipeline/ (AC-17). None unless this inbound declares + # reply_from, so every other connection keeps the shipped 202 path byte for byte. + source.sync_reply = self._make_sync_reply_resolver(ic) + if source.sync_reply is not None: + # ADR 0154 D5/AC-10: stop() wakes blocked turns through this BEFORE closing writers. + source.reply_drain = self._reply_rendezvous.drain # Inject the process-in-place dedup ledger (#142): a store-backed adapter keyed to THIS inbound, so # a leave-in-place (after_read='leave') File/RemoteFile source records/skips files it has ingested # by a HASHED key. Every other source ignores it (byte-identical); transports/ stays store-agnostic @@ -4283,6 +4352,27 @@ async def _process_delivery_item( ) if self._delivery_phase_timing: self._delivery_phase_stats.record_mark_done(time.perf_counter_ns() - _done_t0) + # ADR 0154 D3 — the latency hint, and its POSITION is the correctness argument. + # + # Strictly after the await returned NORMALLY. Under SQLite group commit + # complete_with_response enrols in a shared batch whose future resolves post-commit, + # so a signal here is committed-authoritative; in a `finally`, or before the await, + # it would fire on a transaction that may have rolled back. + # + # It is only ever a hint — the woken turn re-reads the store — so both ways it can be + # "wrong" are harmless: it can fire for a vanished row that wrote nothing + # (complete_with_response returns normally in that case), and it can fail to fire at + # all when an engine shard other than the listener's owns this lane. The first costs + # one extra read; the second costs latency, never correctness. + # + # NOT placed beside the _wake_lane below, which is where the ADR says to put it: that + # call is nested under `if reingress_to is not None`, and a reply_from outbound never + # re-ingresses, so a hint there would be unreachable dead code. + # destination_name is NULL on ingress/routed rows and set on outbound ones, so it is + # non-None everywhere this path runs — but the type says otherwise, and a hint keyed + # on None would silently match nothing rather than fail, so the guard is explicit. + if item.destination_name is not None: + self._reply_rendezvous.signal(item.message_id, item.destination_name) if reingress_to is not None: # B12 (ADR 0061): CROSS-LANE — wake the loopback's RESPONSE lane # (reingress_to), NOT this delivery worker's own OUTBOUND lane. @@ -5877,6 +5967,7 @@ def build_check_registry( reserved_bindings: Sequence[tuple[str, str, int]] = (), posture: HopPosture | None = None, trust_anchor_policy: TrustAnchorPolicy | None = None, + delivery: DeliverySettings | None = None, ) -> None: """Construct (and discard) every **deployed** connector in ``registry`` + run the fail-closed connect/egress allowlists, so a bad connector spec or a non-allowlisted host fails as a @@ -5914,7 +6005,7 @@ def build_check_registry( # so it need not run inside the scope. with active_hop_posture(posture): _build_check_connectors( - registry, inbound_bind_host, env_values, egress, trust_anchor_policy + registry, inbound_bind_host, env_values, egress, trust_anchor_policy, delivery ) except WiringError: raise @@ -5928,6 +6019,7 @@ def _build_check_connectors( env_values: Mapping[str, Any], egress: EgressSettings, trust_anchor_policy: TrustAnchorPolicy | None = None, + delivery: DeliverySettings | None = None, ) -> None: """Construct-and-discard every DEPLOYED connector + run the connect/egress allowlists (the body of :func:`build_check_registry`, split out so the whole block runs inside the ``active_hop_posture`` @@ -5947,11 +6039,17 @@ def _build_check_connectors( nothing. The fail-loud guarantee is UNCHANGED for a deployed connection: a missing ``env()`` value on one still raises here, which is exactly the promote-time gate ("a graph whose env keys aren't defined for the target never goes live").""" + # ADR 0154 D4: normalise the graph BEFORE validating it, so the passthrough content-type rule + # below sees the implied header rather than refusing the ADR's own headline shape. Idempotent. + apply_sync_reply_capture_implication(registry) for ic in registry.inbound.values(): if not ic.deployed: continue source_cfg = _source_config(ic, inbound_bind_host, env_values) check_source_allowed(source_cfg, ic.name, egress) + # ADR 0154 D4's cross-registry arm: reply_from's target must exist, be deployed, capture + # responses, and resolve to a lane that can actually serve concurrent callers. + check_http_sync_reply(ic, registry, delivery=delivery) # ADR 0154 D7's parallel offline arm. The runner-side call in _start_inbound_unsafe does NOT # fire at `messagefoundry check`, so without this a config that refuses to start would pass # the commit/CI gate and only fail at serve. Same predicate, and posture-keyed the same way: @@ -6415,6 +6513,110 @@ def _has_effective_peer_control(settings: Mapping[str, Any]) -> bool: return True +def check_http_sync_reply( + ic: InboundConnection, + registry: Registry, + *, + delivery: DeliverySettings | None = None, +) -> None: + """Cross-registry refusals for a ``reply_from`` inbound (ADR 0154 D4). + + These are the facts one ``Http()`` call cannot know, because they are about the *other* + connection. Runs with no store, so it fires at ``messagefoundry check`` and in dry-run exactly as + at serve. + + The ``ordering``/``max_attempts`` pair is the subtle one, and both are refusals rather than + warnings because together they make the feature's headline use case unserviceable. ``ordering`` + resolves to **FIFO**, which drains one message at a time and blocks the head on failure — so N + concurrent HTTP callers do not get N concurrent downstream calls; they serialise behind a single + lane bounded by one partner round-trip, and one transiently-failing head message holds that lane + until an operator purges it, timing out **every** concurrent and subsequent caller. + ``max_attempts`` resolves to retry-forever, which is not merely incoherent with "the caller gave + up 30 seconds ago" — it is a total outage with a config-shaped cause. + + **Both are read as EFFECTIVE values, never declared ones.** ``OutboundConnection.ordering`` + defaults to ``None`` meaning *inherit*, and ``retry`` defaults to no ``RetryPolicy`` object at + all; resolution against ``[delivery]`` happens in the runner. A literal ``ordering == FIFO`` test + would therefore pass cleanly for the overwhelmingly common shape — the exact shape this refusal + exists to catch. When ``delivery`` is not supplied the caller could not resolve them either, so + that arm is **skipped rather than guessed**; the runner re-checks at start, where the resolved + values always exist. + """ + settings = ic.spec.settings + reply_from = settings.get("reply_from") + if not reply_from: + return + name, target = ic.name, str(reply_from) + + oc = registry.outbound.get(target) + if oc is None: + raise WiringError( + f"inbound connection {name!r}: reply_from names unknown outbound {target!r} — a " + "synchronous reply can only come from an outbound declared in this graph" + ) + if not oc.deployed: + raise WiringError( + f"inbound connection {name!r}: reply_from names {target!r}, which is declared " + "deployed=False — it will never run, so every HTTP turn could only time out" + ) + if not oc.spec.settings.get("capture_response"): + raise WiringError( + f"inbound connection {name!r}: reply_from names {target!r}, which does not set " + "capture_response=True — with no captured reply there is nothing to return, and every " + "call would block until reply_timeout" + ) + + # apply_sync_reply_capture_implication has already added content-type for any factory that HAS + # the allow-list. One that does not cannot echo a content type at all, so refuse here rather than + # let it surface as an AttributeError deep in the capture path. + if ( + settings.get("reply_content_type") == "passthrough" + and "capture_response_headers" not in oc.spec.settings + ): + raise WiringError( + f"inbound connection {name!r}: reply_content_type='passthrough' needs {target!r} to " + "capture the partner's content-type, but that connector has no " + "capture_response_headers setting — pin a literal MIME type on reply_content_type " + "instead" + ) + + if ic.ack_after is AckAfter.DELIVERED: + raise WiringError( + f"inbound connection {name!r}: reply_from cannot be combined with ack_after='delivered' " + "— the HTTP turn already blocks on the downstream reply, so deferring the receipt too " + "would mean waiting for the same delivery twice" + ) + + if delivery is None: + return # the caller could not resolve [delivery]; the runner re-checks at start + + if (oc.ordering or delivery.ordering) is OrderingMode.FIFO: + declared = oc.ordering.value if oc.ordering else "unset, inheriting [delivery].ordering" + raise WiringError( + f"inbound connection {name!r}: reply_from names {target!r}, whose EFFECTIVE ordering is " + f"FIFO (declared: {declared}). A FIFO lane drains one message at a time and blocks the " + "head on failure, so concurrent HTTP callers serialise behind a single partner " + "round-trip and one stuck message times out every caller — set ordering=UNORDERED on " + "that outbound" + ) + + effective_attempts = ( + oc.retry.max_attempts if oc.retry is not None else delivery.retry_max_attempts + ) + if effective_attempts is None: + declared = ( + "no retry policy, inheriting [delivery].retry_max_attempts" + if oc.retry is None + else "max_attempts=None" + ) + raise WiringError( + f"inbound connection {name!r}: reply_from names {target!r}, whose EFFECTIVE max_attempts " + f"is unset — retry forever (declared: {declared}). Retrying forever is incoherent with a " + "caller that gave up seconds ago; set a finite max_attempts so a failed delivery " + "dead-letters instead of holding the lane" + ) + + def check_http_intake_auth(source: Source, name: str, *, posture: HopPosture | None = None) -> None: """Peer-control gate (ADR 0154 D7): refuse an **off-loopback HTTP listener with no effective peer control** — no sufficiently narrow ``source_ip_allowlist``, no ``intake_auth``, and no diff --git a/messagefoundry/store/base.py b/messagefoundry/store/base.py index 6064f89c..b50fc1b1 100644 --- a/messagefoundry/store/base.py +++ b/messagefoundry/store/base.py @@ -60,6 +60,7 @@ OwnedLanes, ReingressOriginMissing, ReingressOutcome, + ReplyWaitState, ResendError, ResendKeyConflict, ResendOutcome, @@ -777,6 +778,19 @@ async def pending_depth( raise a ``queue_buildup`` alert when a lane stops draining. Cheap: a single COUNT + MIN.""" ... + async def reply_wait_state(self, message_id: str, destination_name: str) -> ReplyWaitState: + """Metadata-only state for one synchronous-reply wait tick (ADR 0154 D3): the message's own + status, the awaited destination's outbound row states, and the highest committed + ``response_seq`` for it. + + The inbound HTTP listener's sync-reply path polls this while a caller is blocked, so it must + stay cheap and must decrypt **nothing** — see :class:`ReplyWaitState`, which also documents + why the message status is returned alongside the rows rather than the rows being read alone. + Returning ``latest_response_seq`` rather than the body is what keeps a tick metadata-only: + the reply is fetched once, through :meth:`correlate_response`, after a row is proven + committed.""" + ... + async def reset_stale_inflight( self, now: float | None = None, @@ -1007,6 +1021,31 @@ async def outbox_payloads_for(self, message_id: str) -> Sequence[Row]: async def events_for(self, message_id: str) -> Sequence[Row]: ... # --- connection events (Corepoint-style transport/lifecycle log, #46) ----- + async def record_message_event( + self, + message_id: str, + event: str, + *, + destination: str | None = None, + detail: str | None = None, + now: float | None = None, + ) -> None: + """Append one ``message_events`` row with a caller-supplied kind (ADR 0154 D8). + + Lives on this protocol rather than :class:`AuditStore` because ``message_events`` is the + per-message **disposition timeline** — queue-domain, the sibling of + :meth:`record_connection_event` — not the tamper-evident ``audit_log``. That placement is also + what lets ``pipeline/`` reach it through the store it already holds, with no cast. + + Before this there was **no** public message-event writer: ``_event`` is private to each + backend and only ever called inside a store-owned transaction, so neither ``pipeline/`` nor + ``transports/`` could record a disposition event at all. + + ``event`` is validated against :data:`MESSAGE_EVENT_KINDS` at runtime — the static + literal-call-site guard in ``tests/test_phi_logging_inventory.py`` AST-walks for a *constant* + first argument and therefore cannot see a kind forwarded through here.""" + ... + async def record_connection_event( self, *, diff --git a/messagefoundry/store/postgres.py b/messagefoundry/store/postgres.py index 92b5c9bb..acc53a46 100644 --- a/messagefoundry/store/postgres.py +++ b/messagefoundry/store/postgres.py @@ -103,6 +103,7 @@ ) from messagefoundry.store.pool_metrics import AcquireWaitHistogram, PoolStatus from messagefoundry.store.store import ( + MESSAGE_EVENT_KINDS, NOT_DEPLOYED_EVENT, REINGRESS_TARGET_PREFIX, AlertInstance, @@ -123,6 +124,7 @@ OwnedLanes, ReingressOriginMissing, ReingressOutcome, + ReplyWaitState, ResendKeyConflict, ResendOutcome, ResendSourceAmbiguous, @@ -4244,6 +4246,34 @@ async def pending_depth( oldest = row["oldest"] if row is not None else None return count, (float(oldest) if oldest is not None else None) + async def reply_wait_state(self, message_id: str, destination_name: str) -> ReplyWaitState: + """Metadata-only state for one synchronous-reply wait tick (ADR 0154 D3). + + Three narrow indexed reads, decoding nothing — see :class:`ReplyWaitState` for why the + message's own status is returned alongside the destination's row states.""" + message_row = await self._fetchone("SELECT status FROM messages WHERE id=$1", message_id) + queue_rows = await self._fetchall( + "SELECT status FROM queue WHERE message_id=$1 AND stage=$2 AND destination_name=$3", + message_id, + Stage.OUTBOUND.value, + destination_name, + ) + # kind='response' excludes the ADR 0021 ack_sent row: the inbound ACK we returned must never + # be mistaken for the partner's reply. + response_row = await self._fetchone( + "SELECT MAX(response_seq) AS seq FROM response" + " WHERE message_id=$1 AND destination_name=$2 AND kind=$3", + message_id, + destination_name, + "response", + ) + seq = response_row["seq"] if response_row is not None else None + return ReplyWaitState( + message_status=(str(message_row["status"]) if message_row is not None else None), + row_states=tuple(str(r["status"]) for r in queue_rows), + latest_response_seq=(int(seq) if seq is not None else None), + ) + # --- recovery / replay --------------------------------------------------- async def reset_stale_inflight( @@ -5479,6 +5509,28 @@ async def record_view( async with self._timed_acquire() as conn, conn.transaction(): await self._event(conn, message_id, "viewed", None, actor or "", now) + async def record_message_event( + self, + message_id: str, + event: str, + *, + destination: str | None = None, + detail: str | None = None, + now: float | None = None, + ) -> None: + """Append one ``message_events`` row with a caller-supplied kind (ADR 0154 D8). + + See :meth:`MessageStore.record_message_event` — same contract, same runtime kind validation + (the static literal-call-site guard cannot see a forwarded variable), same verbosity gate.""" + if event not in MESSAGE_EVENT_KINDS: + raise ValueError( + f"unknown message_events kind {event!r} — add it to MESSAGE_EVENT_KINDS and to the " + "docs/PHI.md §7 row 6 vocabulary, which CI asserts against it" + ) + now = time.time() if now is None else now + async with self._timed_acquire() as conn, conn.transaction(): + await self._event(conn, message_id, event, destination, detail or "", now) + async def record_audit( self, action: str, diff --git a/messagefoundry/store/sqlserver.py b/messagefoundry/store/sqlserver.py index cded23d0..924d8b79 100644 --- a/messagefoundry/store/sqlserver.py +++ b/messagefoundry/store/sqlserver.py @@ -81,6 +81,7 @@ ) from messagefoundry.store.pool_metrics import AcquireWaitHistogram, ClaimPoolStatus, PoolStatus from messagefoundry.store.store import ( + MESSAGE_EVENT_KINDS, NOT_DEPLOYED_EVENT, REINGRESS_TARGET_PREFIX, AlertInstance, @@ -101,6 +102,7 @@ OwnedLanes, ReingressOriginMissing, ReingressOutcome, + ReplyWaitState, ResendKeyConflict, ResendOutcome, ResendSourceAmbiguous, @@ -7644,6 +7646,30 @@ async def pending_depth( oldest = row["m"] if row is not None else None return count, (float(oldest) if oldest is not None else None) + async def reply_wait_state(self, message_id: str, destination_name: str) -> ReplyWaitState: + """Metadata-only state for one synchronous-reply wait tick (ADR 0154 D3). + + Three narrow indexed reads, decoding nothing — see :class:`ReplyWaitState` for why the + message's own status is returned alongside the destination's row states.""" + message_row = await self._fetchone("SELECT status FROM messages WHERE id=?", (message_id,)) + queue_rows = await self._fetchall( + "SELECT status FROM queue WHERE message_id=? AND stage=? AND destination_name=?", + (message_id, Stage.OUTBOUND.value, destination_name), + ) + # kind='response' excludes the ADR 0021 ack_sent row: the inbound ACK we returned must never + # be mistaken for the partner's reply. + response_row = await self._fetchone( + "SELECT MAX(response_seq) AS seq FROM response" + " WHERE message_id=? AND destination_name=? AND kind=?", + (message_id, destination_name, "response"), + ) + seq = response_row["seq"] if response_row is not None else None + return ReplyWaitState( + message_status=(str(message_row["status"]) if message_row is not None else None), + row_states=tuple(str(r["status"]) for r in queue_rows), + latest_response_seq=(int(seq) if seq is not None else None), + ) + async def dead_letter_missing_destinations( self, valid_names: set[str], now: float | None = None ) -> int: @@ -8483,6 +8509,33 @@ async def record_view( await conn.rollback() raise + async def record_message_event( + self, + message_id: str, + event: str, + *, + destination: str | None = None, + detail: str | None = None, + now: float | None = None, + ) -> None: + """Append one ``message_events`` row with a caller-supplied kind (ADR 0154 D8). + + See :meth:`MessageStore.record_message_event` — same contract, same runtime kind validation + (the static literal-call-site guard cannot see a forwarded variable), same verbosity gate.""" + if event not in MESSAGE_EVENT_KINDS: + raise ValueError( + f"unknown message_events kind {event!r} — add it to MESSAGE_EVENT_KINDS and to the " + "docs/PHI.md §7 row 6 vocabulary, which CI asserts against it" + ) + now = time.time() if now is None else now + async with self._acquire() as conn, self._cursor(conn) as cur: + try: + await self._event(cur, message_id, event, destination, detail or "", now) + await self._commit(conn) + except Exception: + await conn.rollback() + raise + async def record_audit( self, action: str, diff --git a/messagefoundry/store/store.py b/messagefoundry/store/store.py index 67b86d58..30ff15c0 100644 --- a/messagefoundry/store/store.py +++ b/messagefoundry/store/store.py @@ -560,6 +560,53 @@ class CapturedResponse: headers: Mapping[str, str] = field(default_factory=dict) +@dataclass(frozen=True) +class ReplyWaitState: + """One metadata-only snapshot for a synchronous-reply wait tick (ADR 0154 D3). + + **Metadata only, by construction.** Nothing here is encrypted at rest, so a tick decrypts nothing + and reads no body. The reply itself is fetched exactly once, via :meth:`correlate_response`, and + only after :attr:`latest_response_seq` proves a row is committed. + + **The message's own status is the first field on purpose.** A routed row carries a NULL + ``destination_name`` (only ``handler_name`` is set), so a sibling handler's still-in-flight work + is *structurally invisible* to the destination-keyed query behind :attr:`row_states` — which + means an empty ``row_states`` does **not** mean "this message was excluded". Concluding that it + does is the defect ADR 0154 revision 1 shipped: a ``502`` returned for a message the engine then + delivered normally. Consult :attr:`message_is_terminal` before ever interpreting an empty list. + """ + + #: ``messages.status`` for the awaited message, or ``None`` when the row no longer exists. + message_status: str | None + #: ``queue.status`` for each **outbound** row of the awaited destination, in no guaranteed order. + #: Empty while a sibling handler is still upstream — see the class note. + row_states: tuple[str, ...] + #: Highest committed ``response_seq`` for this ``(message_id, destination_name)`` with + #: ``kind='response'``, or ``None`` when no reply has been captured. An ADR 0021 ``ack_sent`` row + #: is excluded, so the inbound ACK we returned can never be mistaken for the partner's reply. + latest_response_seq: int | None + + @property + def message_is_terminal(self) -> bool: + """Whether no reply can still arrive for this message. + + **Defined by EXCLUSION, never by enumeration**, and that is a correctness requirement rather + than a style preference. An enumerated terminal list + (``UNROUTED``/``FILTERED``/``NOT_DEPLOYED``/``ERROR``) silently omits **``PROCESSED``** — and + ``PROCESSED`` is exactly what the finalizer sets when a *sibling* handler delivered + successfully while the awaited destination's ``Send`` was declined, filtered out, or never + emitted by a code-first Handler. Enumerating therefore hangs that turn for the full + ``reply_timeout`` instead of failing fast, and a future :class:`MessageStatus` member would + inherit the same bug silently. Exclusion is total against the enum by construction. + + A vanished message row is terminal too: nothing can arrive for a message that is gone. + """ + return self.message_status is None or self.message_status not in ( + MessageStatus.RECEIVED.value, + MessageStatus.ROUTED.value, + ) + + @dataclass(frozen=True) class ConnectionEvent: """One metadata-only connection event (Corepoint-style transport/lifecycle log, #46), as returned @@ -948,15 +995,27 @@ def not_deployed_detail(destination: str) -> str: # be dropped); `dead`/`error`/`failed` are terminal failure dispositions an operator relies on; # `not_deployed` is the count-and-log record + NOT_DEPLOYED-disposition signal (see above). A blanket # "off" that dropped these would silently discard the compliance-critical trail. -_AUDIT_FLOOR_EVENTS = frozenset({"viewed", "dead", "error", "failed", NOT_DEPLOYED_EVENT}) +#: ``reply_timeout`` joins the floor (ADR 0154 D8): it is the one row that explains a customer +#: complaint — "we called you and got a 504" — and an instance that thinned its logs to "errors" or +#: "off" would lose exactly the record needed to answer that, on exactly the deployments most likely +#: to be asked. ``reply_returned`` is the routine happy-path counterpart and is deliberately NOT in +#: the floor: it is thinnable like ``delivered``. +_AUDIT_FLOOR_EVENTS = frozenset( + {"viewed", "dead", "error", "failed", NOT_DEPLOYED_EVENT, "reply_timeout"} +) #: The COMPLETE ``message_events.event`` vocabulary, shared by all three backends. #: #: Exported (not private) because ``docs/PHI.md`` §7 row 6 documents this list as the per-message -#: disposition timeline and ASVS 16.1.1 scores that inventory: the doc named 9 of these 19 while +#: disposition timeline and ASVS 16.1.1 scores that inventory: the doc once named 9 of these while #: reading as exhaustive. ``tests/test_phi_logging_inventory.py`` asserts the doc names every #: member and that the set matches the literal ``_event``/``_event_stmt`` call sites, so a new kind #: cannot ship undocumented. +#: +#: **The literal-call-site check cannot see a kind passed through** :meth:`MessageStore.record_message_event` +#: — it AST-walks for constant first arguments, and that method forwards a variable. So that method +#: validates its ``event`` against this set at runtime; the two guards together keep the vocabulary +#: closed from both directions. MESSAGE_EVENT_KINDS: Final[frozenset[str]] = frozenset( { "received", @@ -978,6 +1037,11 @@ def not_deployed_detail(destination: str) -> str: "edit_resubmit", "viewed", NOT_DEPLOYED_EVENT, + # ADR 0154 D8 — the synchronous-reply outcome pair. Names, counts and waited_ms only; never a + # fragment of the partner's reply body (that is the PHI class this design keeps structurally + # out of every log, event and exception). + "reply_returned", + "reply_timeout", } ) @@ -5782,6 +5846,40 @@ async def pending_depth( oldest = row["oldest"] if row is not None else None return count, (float(oldest) if oldest is not None else None) + async def reply_wait_state(self, message_id: str, destination_name: str) -> ReplyWaitState: + """Metadata-only state for one synchronous-reply wait tick (ADR 0154 D3). + + Deliberately **not** built on :meth:`outbox_for`. That is a ``SELECT *`` fed through + ``_decode_row``, so it decrypts ``last_error`` and pulls the payload ciphertext on **every + tick** — a cost a poll loop cannot carry, and PHI this path has no business touching. + Modelled on :meth:`pending_depth` instead: three narrow indexed reads sharing one pooled + connection, decoding nothing. + + See :class:`ReplyWaitState` for why the message's own status is returned alongside the row + states rather than the rows being trusted alone.""" + async with self._read() as db: + cur = await db.execute("SELECT status FROM messages WHERE id=?", (message_id,)) + message_row = await cur.fetchone() + cur = await db.execute( + "SELECT status FROM queue WHERE message_id=? AND stage=? AND destination_name=?", + (message_id, Stage.OUTBOUND.value, destination_name), + ) + queue_rows = await cur.fetchall() + # kind='response' excludes the ADR 0021 ack_sent row: the inbound ACK we returned must + # never be mistaken for the partner's reply. + cur = await db.execute( + "SELECT MAX(response_seq) AS seq FROM response" + " WHERE message_id=? AND destination_name=? AND kind=?", + (message_id, destination_name, "response"), + ) + response_row = await cur.fetchone() + seq = response_row["seq"] if response_row is not None else None + return ReplyWaitState( + message_status=(str(message_row["status"]) if message_row is not None else None), + row_states=tuple(str(r["status"]) for r in queue_rows), + latest_response_seq=(int(seq) if seq is not None else None), + ) + # --- recovery / replay --------------------------------------------------- async def reset_stale_inflight( @@ -7163,6 +7261,40 @@ async def record_view( await self._event(message_id, "viewed", None, actor or "", now) await self._commit() + async def record_message_event( + self, + message_id: str, + event: str, + *, + destination: str | None = None, + detail: str | None = None, + now: float | None = None, + ) -> None: + """Append one ``message_events`` row with a caller-supplied kind (ADR 0154 D8). + + ``_event`` is private to each backend and is only ever called inside a store-owned + transaction, so before this there was no way for ``pipeline/`` or ``transports/`` to record a + disposition event at all. This is the public writer; it applies the same ``#63`` verbosity + gate and the same ``safe_text`` scrub on ``detail`` as every internal call site. + + **``event`` is validated against** :data:`MESSAGE_EVENT_KINDS` **at runtime**, because the + static guard cannot cover this path: ``test_message_event_constant_matches_the_literal_emit_sites`` + AST-walks for a *constant* first argument, and this method forwards a variable. Without the + runtime check a typo'd or undeclared kind would write silently and pass CI. + + ``detail`` carries names, counts and timings only. On the sync-reply path in particular it + must never carry a fragment of the partner's reply — that rule is structural in the caller, + and ``safe_text`` here is defence in depth, not the control.""" + if event not in MESSAGE_EVENT_KINDS: + raise ValueError( + f"unknown message_events kind {event!r} — add it to MESSAGE_EVENT_KINDS and to the " + "docs/PHI.md §7 row 6 vocabulary, which CI asserts against it" + ) + now = time.time() if now is None else now + async with self._lock: + await self._event(message_id, event, destination, detail or "", now) + await self._commit() + async def record_audit( self, action: str, diff --git a/messagefoundry/transports/base.py b/messagefoundry/transports/base.py index 5f951ed9..979a00fa 100644 --- a/messagefoundry/transports/base.py +++ b/messagefoundry/transports/base.py @@ -18,6 +18,7 @@ import asyncio from collections.abc import Awaitable, Callable, Mapping from dataclasses import dataclass, field +from enum import Enum from typing import ClassVar, Protocol from messagefoundry.config.models import ConnectorType, ContentType, Destination, Source @@ -35,6 +36,9 @@ "ConnectionEventSink", "IntakeAuditSink", "IntakeRateLimiter", + "InboundReply", + "ReplyOutcome", + "SyncReplyResolver", "ProcessedFileLedger", "DeliveryError", "NegativeAckError", @@ -109,6 +113,84 @@ def note_success(self, peer: str) -> None: ... +class ReplyOutcome(str, Enum): # noqa: UP042 - matches MessageStatus/OutboxStatus house style + """How a synchronous-reply wait ended (ADR 0154 D5). One member per row of the outcome table. + + ``degraded`` is deliberately **not** folded into ``timeout``. The SLO series an operator pages on + is ``rate(timeout)/rate(total)`` — the proxy API's error budget — so counting our own store + errors or a rendezvous refusal as partner timeouts would silently corrupt the one number that is + supposed to mean "the partner is not answering". + """ + + REPLY = "reply" # the partner replied and we return it verbatim + EMPTY = "empty" # a successful round-trip with a deliberately empty payload + REJECTED = "rejected" # the partner replied negatively; the reply is still returned + FAILED = "failed" # the delivery row went dead/cancelled — no reply exists + PURGED = "purged" # the row exists but retention has already nulled the body + NO_ROUTE = "no_route" # nothing routed to the awaited destination + TIMEOUT = "timeout" # reply_timeout expired with the message still flowing + DEGRADED = "degraded" # OUR fault: a store read raised, or the rendezvous was full + SHUTTING_DOWN = "shutting_down" # the listener stopped mid-wait + + +@dataclass(frozen=True) +class InboundReply: + """The result of one synchronous-reply wait, handed to the listener by the injected resolver. + + **``body`` is PHI**, and the rule around it is structural rather than a redaction promise: + reply-derived bytes are never passed to an exception, a log call, a ``connection_event.reason`` or + a ``message_events.detail``. The listener may report only :attr:`outcome`, :attr:`destination`, + :attr:`response_seq` and :attr:`waited_ms`. That is deliberately stronger than routing it through + ``safe_text``, because ``safe_text`` is an **HL7-shaped** redactor — segment runs, ``| ^ ~ &`` + density, date and capitalised-name runs — while this payload class is JSON/SOAP-XML/FHIR. A + Salesforce error body is only *partially* scrubbed by it, so identifiers such as an MRN in a JSON + field pass straight through. Partial redaction is not a PHI control. + + :meth:`__repr__` is overridden to omit the body for the same reason: a frozen dataclass's default + repr would otherwise put the partner's reply into any log line, traceback or assertion message + that happens to interpolate the object — which is exactly the accident the structural rule + exists to prevent, and the kind that survives review because nothing looks wrong at the call site. + + ``body`` is ``str`` rather than ``bytes`` deliberately. Every capture path already decodes with + ``errors="replace"`` before the store (``rest.py``, ``fhir.py``, ``soap.py``), ``DeliveryResponse.body`` + is ``str``, and the ``response.body`` column is encrypted TEXT — so non-UTF-8 fidelity is destroyed + at capture and a ``bytes`` type here would be false precision, promising a faithfulness the + pipeline cannot deliver. + """ + + outcome: ReplyOutcome + #: The partner's reply text. Populated only for ``reply`` and ``rejected``; ``None`` otherwise. + body: str | None = None + #: The captured ``content-type`` when the inbound echoes it (``reply_content_type="passthrough"``). + content_type: str | None = None + #: The awaited outbound connection name — non-PHI, safe to log. + destination: str | None = None + #: ``response_seq`` of the row returned — non-PHI, safe to log. + response_seq: int | None = None + #: How long the turn blocked, in milliseconds — non-PHI, safe to log. + waited_ms: int = 0 + + def __repr__(self) -> str: # pragma: no cover - trivial, but load-bearing for PHI + return ( + f"InboundReply(outcome={self.outcome.value!r}, destination={self.destination!r}, " + f"response_seq={self.response_seq!r}, waited_ms={self.waited_ms!r}, " + f"body=<{0 if self.body is None else len(self.body)} chars redacted>)" + ) + + +#: Resolve the synchronous reply for an **already-committed** message (ADR 0154 D2/D3). +#: +#: The single argument is the ``message_id`` that ``enqueue_ingress`` returned, and that is how +#: ACK-on-receipt is enforced **structurally** rather than by convention: the id does not exist until +#: the body is durably committed to the ingress stage, so the listener cannot begin waiting before the +#: commit even if it wanted to. There is no shape of this call that observes an uncommitted message. +#: +#: Runner-owned, injected after build like every other seam here, so ``transports/`` keeps its +#: CI-enforced freedom from ``store/`` and ``pipeline/`` imports (AC-17) while still returning bytes +#: that came out of the store. +SyncReplyResolver = Callable[[str], Awaitable[InboundReply]] + + class ProcessedFileLedger(Protocol): """The store-backed **process-in-place dedup ledger** a leave-in-place (``after_read='leave'``) poll source uses (ADR 0129, BACKLOG #142). The runner injects an adapter closing over the store + the @@ -315,6 +397,24 @@ class SourceConnector(abc.ABC): #: sets ``intake_auth_rate_limit=None`` gets the same. intake_rate_limiter: IntakeRateLimiter | None = None + #: Optional synchronous-reply resolver (ADR 0154 D2), **injected by the runner after build** — + #: the sixth attribute on this seam, not the "fourth" the ADR calls it (``on_connection_event``, + #: ``content_type``, ``processed_ledger``, ``on_intake_audit`` and ``intake_rate_limiter`` + #: precede it). ``None`` (the default) means this inbound declares no ``reply_from``, so the + #: shipped ``202`` path is byte-identical — which is what AC-8 pins. + #: + #: This is the seam that lets the listener return bytes that came out of the store while + #: ``transports/`` keeps importing neither ``store/`` nor ``pipeline/`` (AC-17, CI-enforced). + sync_reply: SyncReplyResolver | None = None + + #: Optional drain hook for blocked synchronous-reply turns (ADR 0154 D5), **injected by the + #: runner after build**. ``stop()`` calls it **before** closing client writers, so a blocked turn + #: can still answer ``503`` + ``Retry-After`` through a live socket — a write issued after + #: ``close()`` is typically discarded with no exception at all, so the answer would simply + #: vanish. A plain callable rather than the rendezvous object, so ``transports/`` gains no + #: ``pipeline/`` import (AC-17). ``None`` on every inbound without ``reply_from``. + reply_drain: Callable[[str], None] | None = None + @abc.abstractmethod async def start( self, handler: InboundHandler, *, leader_gate: Callable[[], bool] | None = None diff --git a/messagefoundry/transports/http_listener.py b/messagefoundry/transports/http_listener.py index 71d64802..9245505f 100644 --- a/messagefoundry/transports/http_listener.py +++ b/messagefoundry/transports/http_listener.py @@ -45,6 +45,8 @@ from messagefoundry.redaction import safe_exc from messagefoundry.transports.base import ( InboundHandler, + InboundReply, + ReplyOutcome, SourceConnector, peer_ip_allowed, register_source, @@ -205,13 +207,18 @@ def build_response( call site.** This function joins the header block with ``\\r\\n``, so it *is* the chokepoint: a value carrying CR or LF is a header-injection primitive, and validating in the callers would mean each future consumer has to remember. Today every caller passes a literal, so this guards against - a future one — notably the captured-reply path, which echoes a partner's ``Content-Type``.""" + a future one — notably the captured-reply path, which echoes a partner's ``Content-Type``. + + **A ``204`` carries no entity headers.** RFC 9110 §15.3.5 forbids a body on a ``204``, and + ``Content-Length: 0`` beside it is at best noise and at worst a parser tripwire — some clients + treat an entity header on a bodyless status as a framing error. That matters here rather than + academically: ``reply_on_empty="204"`` is the default answer for a partner reply that is + deliberately empty, so this is ordinary traffic, not an edge case.""" payload = body.encode("utf-8") - headers = [ - _status_line(status), - _validated_header("Content-Type", content_type), - f"Content-Length: {len(payload)}", - ] + headers = [_status_line(status)] + if status != 204: + headers.append(_validated_header("Content-Type", content_type)) + headers.append(f"Content-Length: {len(payload)}") headers.extend(_validated_header(name, value) for name, value in (extra_headers or {}).items()) headers.extend(("Connection: close", "", "")) return "\r\n".join(headers).encode("ascii") + payload @@ -426,6 +433,14 @@ def __init__(self, config: Source) -> None: {str(x): str(x) for x in subjects} if subjects else {} ) self.intake_auth_health: str = str(s.get("intake_auth_health") or "require") + # Synchronous captured-downstream reply (ADR 0154 D4). reply_from's presence is the mode + # switch; absent, every path below is byte-identical to the shipped 202 slice (AC-8). + self.reply_from: str | None = s.get("reply_from") or None + self.reply_timeout: float = float(s.get("reply_timeout") or 30.0) + self.reply_on_timeout: str = str(s.get("reply_on_timeout") or "504") + self.reply_content_type: str = str(s.get("reply_content_type") or "passthrough") + self.reply_on_empty: str = str(s.get("reply_on_empty") or "204") + self.reply_write_timeout: float = float(s.get("reply_write_timeout") or 30.0) self._server: asyncio.Server | None = None self._handler: InboundHandler | None = None self._active = 0 @@ -455,6 +470,20 @@ async def stop(self) -> None: # Stop accepting NEW connections (this alone does not close established ones). if self._server is not None: self._server.close() + # ADR 0154 D5 — the PRE-CLOSE drain phase, and its position is the whole point (AC-10). + # + # Waking blocked waiters must happen BEFORE the writers below are closed. Revision 1 of the + # ADR promised both the 503 and the existing close-first ordering; those are mutually + # exclusive. A 503 written after close() lands on a dead transport, and post-close asyncio + # typically DISCARDS the write with no exception at all — so _write_safely's + # `except (TimeoutError, OSError)` never even sees it and the demoted caller gets a bare + # connection reset instead of the answer the HA argument depends on. + # + # Each woken turn resolves `shutting_down` and writes its own 503 + Retry-After through its + # still-open writer on the way out, inside the same bounded grace the teardown already has. + # No-op when nothing is armed, so a listener with no reply_from is byte-identical. + if self.reply_drain is not None: + self.reply_drain("shutting_down") # Close established clients BEFORE awaiting the server (server.wait_closed() hangs on py3.12.1+ # waiting for in-flight handlers of a peer holding its connection open). A request mid-handler # still finishes its commit (the body is durably stored before the 202, so at-least-once holds). @@ -777,12 +806,101 @@ async def _read_authenticated() -> HttpRequest: # (it becomes the message's ERROR/dead-letter + AlertSink). count-and-log holds: the body is # persisted before the response is written. message_id = await self._handler(request.body) + + if self.reply_from and self.sync_reply is not None: + return await self._respond_with_sync_reply(writer, message_id, peer_host=peer_host) + receipt = {"status": "accepted"} if message_id is not None: receipt["message_id"] = message_id await self._respond(writer, build_response(202, json.dumps(receipt))) return False + async def _respond_with_sync_reply( + self, writer: asyncio.StreamWriter, message_id: str | None, *, peer_host: str | None + ) -> bool: + """Block on the captured downstream reply and answer with it (ADR 0154 D5). + + Reached only when ``reply_from`` is set **and** the runner injected a resolver, so an inbound + without it never takes this path — that is what makes AC-8's "unchanged" true rather than + aspirational. + + **The HTTP status is never a second disposition channel.** Whatever is returned here, the + message stays committed and keeps flowing; its disposition is decided by the finalizer alone. + A ``504`` does not cancel a delivery, and a ``200`` does not complete one. + """ + if message_id is None: + # The handler declined AFTER recording the message with status ERROR — that write IS the + # count-and-log record, so nothing is dropped here. On the 202 path this answers + # "202 without a message_id", which is a lie to a proxy client; on the sync path a + # caller waiting for a reply deserves to be told the submission itself failed. + await self._respond(writer, build_response(422, '{"error":"message was not accepted"}')) + return True + + resolver = self.sync_reply + assert resolver is not None # guarded by the caller, as _handler is above + reply = await resolver(message_id) + status, body, extra = self._reply_to_wire(reply, message_id) + # No reply-derived bytes reach the log — only the outcome enum, the destination and timings. + logger.debug( + "sync reply %s: outcome=%s dest=%s seq=%s waited_ms=%s", + message_id, + reply.outcome.value, + reply.destination, + reply.response_seq, + reply.waited_ms, + ) + content_type = reply.content_type or "application/json" + try: + await self._respond( + writer, + build_response(status, body, content_type=content_type, extra_headers=extra), + ) + except ValueError: + # A partner Content-Type that fails the header guard must not take the turn down with + # it: the body is still good, so fall back to our own type rather than 500 the caller. + await self._respond(writer, build_response(status, body, extra_headers=extra)) + return False + + def _reply_to_wire( + self, reply: InboundReply, message_id: str + ) -> tuple[int, str, dict[str, str] | None]: + """Map one resolved outcome onto ``(status, body, extra_headers)`` — ADR 0154 D5's table. + + Every row of that table maps to exactly one outcome and every outcome to exactly one row. + Refusal and timeout bodies are **fixed, non-PHI JSON**; only ``reply`` and ``rejected`` carry + partner bytes, and those are exactly the two the caller asked to be proxied. + """ + outcome = reply.outcome + if outcome is ReplyOutcome.REPLY: + return 200, reply.body or "", None + if outcome is ReplyOutcome.REJECTED: + # The partner's own negative answer is the most useful thing we can return. + return 502, reply.body or "", None + if outcome is ReplyOutcome.EMPTY: + return (204, "", None) if self.reply_on_empty == "204" else (200, "", None) + if outcome is ReplyOutcome.TIMEOUT: + payload = json.dumps({"status": "timeout", "message_id": message_id}) + return (504 if self.reply_on_timeout == "504" else 202), payload, None + if outcome is ReplyOutcome.NO_ROUTE: + # Answered IMMEDIATELY with the timeout status rather than after the full budget: the + # message is already terminal, so waiting would burn the caller's patience for nothing. + payload = json.dumps({"status": "no_route", "message_id": message_id}) + return (504 if self.reply_on_timeout == "504" else 202), payload, None + if outcome is ReplyOutcome.SHUTTING_DOWN: + payload = json.dumps({"status": "shutting_down", "message_id": message_id}) + # Never a 504 on a demotion: the new leader is about to deliver this message, so claiming + # the partner timed out would be a lie about a message that is still in flight. + return 503, payload, {"Retry-After": "5"} + if outcome is ReplyOutcome.PURGED: + payload = json.dumps({"status": "reply_purged", "message_id": message_id}) + return 502, payload, None + if outcome is ReplyOutcome.DEGRADED: + payload = json.dumps({"status": "degraded", "message_id": message_id}) + return (504 if self.reply_on_timeout == "504" else 202), payload, None + payload = json.dumps({"status": "delivery_failed", "message_id": message_id}) + return 502, payload, None + async def _respond(self, writer: asyncio.StreamWriter, data: bytes) -> None: """Write the success-path response, bounding the drain. @@ -801,7 +919,23 @@ async def _respond(self, writer: asyncio.StreamWriter, data: bytes) -> None: (ACK-on-receipt), so a lost 202 costs the sender a retry, never a message. """ writer.write(data) - await asyncio.wait_for(writer.drain(), _CLIENT_SHUTDOWN_GRACE) + await asyncio.wait_for(writer.drain(), self._drain_budget()) + + def _drain_budget(self) -> float: + """Seconds allowed to drain a response to the caller. + + ``_CLIENT_SHUTDOWN_GRACE`` for the shipped ``202`` path, which writes a few dozen bytes and + was bounded by that constant in increment A. A ``reply_from`` inbound instead uses its own + ``reply_write_timeout``, because it now carries a **partner-sized** body to a possibly slow + reader and a receipt-sized budget would truncate a legitimate large reply. + + The two are not interchangeable in the other direction either: ``reply_write_timeout`` + defaults to 30 s against a 5 s shutdown grace, so ``stop()`` clamps this to its own + sub-budget rather than letting one drain outlive the entire teardown by 6x. + """ + if self.reply_from and self.reply_write_timeout: + return float(self.reply_write_timeout) + return _CLIENT_SHUTDOWN_GRACE async def _write_safely(self, writer: asyncio.StreamWriter, data: bytes) -> None: """Best-effort error/refuse response — never raise out of the refuse/close path (the socket may diff --git a/tests/test_inbound_http_source.py b/tests/test_inbound_http_source.py index 8fe1f367..0e00728c 100644 --- a/tests/test_inbound_http_source.py +++ b/tests/test_inbound_http_source.py @@ -756,3 +756,21 @@ async def test_body_flood_no_content_length_refused(store: MessageStore) -> None assert (await cur.fetchone())["n"] == 0 # oversize body refused before any ingress row finally: await asyncio.wait_for(src.stop(), timeout=8.0) + + +def test_a_204_carries_no_entity_headers() -> None: + # RFC 9110 §15.3.5 forbids a body on a 204, and Content-Length beside it is at best noise and at + # worst a parser tripwire. Ordinary traffic rather than an edge case: reply_on_empty="204" is the + # default answer for a partner reply that is deliberately empty. + out = build_response(204) + assert out.startswith(b"HTTP/1.1 204 No Content\r\n") + assert b"Content-Type" not in out + assert b"Content-Length" not in out + assert b"Connection: close\r\n" in out + assert out.endswith(b"\r\n\r\n") + + # extra_headers still ride a 204 — Retry-After and friends are not entity headers. + assert b"Retry-After: 5\r\n" in build_response(204, extra_headers={"Retry-After": "5"}) + + # ... and every other status is unchanged. + assert b"Content-Length: 0\r\n" in build_response(200) diff --git a/tests/test_inbound_http_sync_reply.py b/tests/test_inbound_http_sync_reply.py new file mode 100644 index 00000000..0ba6854b --- /dev/null +++ b/tests/test_inbound_http_sync_reply.py @@ -0,0 +1,267 @@ +# SPDX-License-Identifier: AGPL-3.0-or-later +# Copyright (C) 2026 MessageFoundry Organization and contributors +"""Synchronous captured-downstream reply on the inbound HTTP listener (ADR 0154 increment B). + +Starts with the **factory-local** half of D4: everything decidable from one ``Http()`` call with no +store, no posture and no registry, so it fires identically in ``messagefoundry check``, in dry-run, +and through the ``connections.toml`` desugar (which routes through this same factory). + +The cross-registry half — ``reply_from`` naming a deployed outbound, that outbound capturing +responses, the ``passthrough`` content-type requirement, and the effective ``ordering`` / +``max_attempts`` refusals — is not knowable here and is tested against ``build_check_registry``. +""" + +from __future__ import annotations + +import asyncio +import inspect +import json as _json +from typing import Any + +import pytest + +from messagefoundry.config.models import ConnectorType, Source +from messagefoundry.config.wiring import Http, WiringError +from messagefoundry.transports.base import InboundReply, ReplyOutcome +from messagefoundry.transports.http_listener import HttpSource + + +def test_valid_configurations_build() -> None: + Http(port=8080) # no reply_from: the shipped 202 path, byte-identical + Http(port=8080, reply_from="OB_PARTNER") + Http( + port=8080, + reply_from="OB_PARTNER", + reply_timeout=5.0, + reply_on_timeout="202", + reply_content_type="application/json", + reply_on_empty="200", + reply_write_timeout=10.0, + ) + + +def test_settings_are_carried_onto_the_spec() -> None: + spec = Http(port=8080, reply_from="OB_PARTNER", reply_timeout=7.5) + assert spec.settings["reply_from"] == "OB_PARTNER" + assert spec.settings["reply_timeout"] == 7.5 + assert spec.settings["reply_on_timeout"] == "504" # default + assert spec.settings["reply_content_type"] == "passthrough" # default + assert spec.settings["reply_on_empty"] == "204" # default + assert spec.settings["reply_write_timeout"] == 30.0 # default + + # An inbound with no reply_from still carries the key, so the listener reads one shape. + assert Http(port=8080).settings["reply_from"] is None + + +def test_knobs_without_reply_from_are_refused() -> None: + # Same defect class as a credential configured with intake_auth="none": every one of these is + # inert without reply_from, so the config would silently do nothing while reading as if it did. + with pytest.raises(WiringError, match="no reply_from"): + Http(port=8080, reply_timeout=5.0) + with pytest.raises(WiringError, match="no reply_from"): + Http(port=8080, reply_on_timeout="202") + with pytest.raises(WiringError, match="no reply_from"): + Http(port=8080, reply_content_type="application/json") + with pytest.raises(WiringError, match="no reply_from"): + Http(port=8080, reply_on_empty="200") + with pytest.raises(WiringError, match="no reply_from"): + Http(port=8080, reply_write_timeout=10.0) + + # ... and the message names the offending knob, so the fix is obvious from the error alone. + with pytest.raises(WiringError, match="reply_timeout"): + Http(port=8080, reply_timeout=5.0) + + +def test_the_default_table_is_derived_from_the_signature_not_copied() -> None: + # Drift guard on the guard. If the defaults were hand-copied, changing one in the signature would + # silently stop the "configured but never read" refusal from firing for that knob. + from messagefoundry.config.wiring import _SYNC_REPLY_KNOBS, _sync_reply_defaults + + params = inspect.signature(Http).parameters + assert _sync_reply_defaults() == {name: params[name].default for name in _SYNC_REPLY_KNOBS} + # And every knob named really is a parameter — a rename would otherwise leave a dead entry. + assert set(_SYNC_REPLY_KNOBS) <= set(params) + + +def test_an_empty_reply_from_is_refused() -> None: + # "" is falsy, so it would read as "no sync reply" while looking configured in the file. + with pytest.raises(WiringError, match="must name an outbound"): + Http(port=8080, reply_from="") + with pytest.raises(WiringError, match="must name an outbound"): + Http(port=8080, reply_from=" ") + + +@pytest.mark.parametrize("knob", ["reply_timeout", "reply_write_timeout"]) +@pytest.mark.parametrize("bad", [0, 0.0, -1, -0.5]) +def test_a_non_positive_budget_is_refused(knob: str, bad: float) -> None: + # Both bound a BLOCKED HTTP turn. Zero or negative is not "no timeout", it is a turn that cannot + # succeed — and an operator writing 0 almost certainly means "unbounded", which is worse. + with pytest.raises(WiringError, match="positive number of seconds"): + Http(port=8080, reply_from="OB_PARTNER", **{knob: bad}) + + +def test_the_status_choices_are_closed() -> None: + with pytest.raises(WiringError, match="reply_on_timeout"): + Http(port=8080, reply_from="OB_PARTNER", reply_on_timeout="500") # type: ignore[arg-type] + with pytest.raises(WiringError, match="reply_on_empty"): + Http(port=8080, reply_from="OB_PARTNER", reply_on_empty="204 No Content") # type: ignore[arg-type] + + +def test_reply_content_type_must_be_passthrough_or_a_mime_type() -> None: + with pytest.raises(WiringError, match="not empty"): + Http(port=8080, reply_from="OB_PARTNER", reply_content_type="") + with pytest.raises(WiringError, match="which is neither"): + Http(port=8080, reply_from="OB_PARTNER", reply_content_type="json") + # A real MIME type and the passthrough sentinel both pass. + Http(port=8080, reply_from="OB_PARTNER", reply_content_type="application/soap+xml") + Http(port=8080, reply_from="OB_PARTNER", reply_content_type="passthrough") + + +def test_sync_reply_and_intake_auth_compose() -> None: + # The two increments' surfaces are orthogonal and must not interfere. + from messagefoundry.config.wiring import env + + spec = Http( + port=8443, + intake_auth="api_key", + intake_api_key=env("acme_intake_key"), + reply_from="OB_PARTNER", + reply_timeout=15.0, + ) + assert spec.settings["intake_auth"] == "api_key" + assert spec.settings["reply_from"] == "OB_PARTNER" + + +# --- the wire: outcome -> HTTP (ADR 0154 D5) ----------------------------------------------------- +# +# Drives a real listener with an injected resolver, so these assert the actual bytes a caller sees. +# The resolver itself is unit-tested separately; here the subject is the mapping and the fact that an +# inbound WITHOUT reply_from still takes the shipped 202 path byte for byte (AC-8). + +REPLY_BODY = '{"partner":"ok","mrn":"100"}' + + +async def _serve(reply: InboundReply | None, **settings: Any) -> tuple[int, dict[str, str], bytes]: + """POST once to a listener wired with a resolver that returns ``reply``; return the raw answer.""" + base: dict[str, Any] = {"host": "127.0.0.1", "port": 0} + if reply is not None: + base["reply_from"] = "OB_PARTNER" + base.update(settings) + src = HttpSource(Source(type=ConnectorType.HTTP, settings=base)) + + async def handler(raw: bytes) -> str | None: + return None if settings.get("_decline") else "msg-1" + + if reply is not None: + + async def resolver(message_id: str) -> InboundReply: + return reply + + src.sync_reply = resolver + await src.start(handler) + try: + reader, writer = await asyncio.open_connection("127.0.0.1", src.sockport) + writer.write(b"POST /ingest HTTP/1.1\r\nHost: h\r\nContent-Length: 2\r\n\r\n{}") + await writer.drain() + data = await asyncio.wait_for(reader.read(-1), 5.0) + writer.close() + finally: + await src.stop() + head, _, body = data.partition(b"\r\n\r\n") + lines = head.decode("iso-8859-1").split("\r\n") + headers = {} + for line in lines[1:]: + k, sep, v = line.partition(":") + if sep: + headers[k.strip().lower()] = v.strip() + return int(lines[0].split(" ", 2)[1]), headers, body + + +async def test_an_inbound_without_reply_from_still_gets_the_202() -> None: + # AC-8, on the real socket: no reply_from means the shipped receipt path, untouched. + status, _, body = await _serve(None) + assert status == 202 + assert _json.loads(body)["status"] == "accepted" + + +async def test_a_captured_reply_is_returned_verbatim_with_its_content_type() -> None: + status, headers, body = await _serve( + InboundReply(ReplyOutcome.REPLY, body=REPLY_BODY, content_type="application/json") + ) + assert status == 200 + assert body.decode() == REPLY_BODY # verbatim — this is the whole feature + assert headers["content-type"] == "application/json" + + +async def test_a_rejected_reply_returns_the_partners_body_with_502() -> None: + status, _, body = await _serve( + InboundReply(ReplyOutcome.REJECTED, body="no", content_type="text/xml") + ) + assert status == 502 + assert body == b"no", "the partner's own answer is the useful thing to return" + + +async def test_an_empty_reply_is_204_with_no_entity_headers() -> None: + status, headers, body = await _serve(InboundReply(ReplyOutcome.EMPTY)) + assert status == 204 and body == b"" + assert "content-length" not in headers and "content-type" not in headers + + # ... and the escape hatch for toolchains that mishandle a bodyless 204. + status, _, _ = await _serve(InboundReply(ReplyOutcome.EMPTY), reply_on_empty="200") + assert status == 200 + + +async def test_a_timeout_answers_the_configured_status_and_names_the_message() -> None: + status, _, body = await _serve(InboundReply(ReplyOutcome.TIMEOUT, waited_ms=30000)) + assert status == 504 + payload = _json.loads(body) + assert payload["status"] == "timeout" + assert payload["message_id"] == "msg-1", "the caller needs the id to reconcile later" + + status, _, _ = await _serve(InboundReply(ReplyOutcome.TIMEOUT), reply_on_timeout="202") + assert status == 202 + + +async def test_a_shutdown_is_503_with_retry_after_never_504() -> None: + # Never a 504 on demotion: the new leader is about to deliver this message, so claiming the + # partner timed out would be a lie about a message still in flight. + status, headers, body = await _serve(InboundReply(ReplyOutcome.SHUTTING_DOWN)) + assert status == 503 + assert headers["retry-after"] == "5" + assert _json.loads(body)["status"] == "shutting_down" + + +async def test_the_refusal_bodies_are_fixed_non_phi_json() -> None: + for outcome, expected_status, tag in ( + (ReplyOutcome.FAILED, 502, "delivery_failed"), + (ReplyOutcome.PURGED, 502, "reply_purged"), + (ReplyOutcome.DEGRADED, 504, "degraded"), + (ReplyOutcome.NO_ROUTE, 504, "no_route"), + ): + status, _, body = await _serve(InboundReply(outcome)) + assert status == expected_status + payload = _json.loads(body) + assert payload["status"] == tag + assert payload["message_id"] == "msg-1" + assert "mrn" not in body.decode(), "a refusal body carried partner data" + + +async def test_a_declined_handler_is_422_on_the_sync_path() -> None: + # The shipped 202 path answers "202 without a message_id", which is a lie to a proxy client. A + # caller blocked on a reply deserves to be told the submission itself failed. Post-record, so + # count-and-log holds: the handler already wrote the message with status ERROR. + status, _, body = await _serve(InboundReply(ReplyOutcome.REPLY, body="x"), _decline=True) + assert status == 422 + assert "not accepted" in body.decode() + + +async def test_a_hostile_partner_content_type_cannot_take_the_turn_down() -> None: + # The header guard rejects CR/LF. The body is still good, so fall back to our own content type + # rather than 500 the caller — a partner controls this value. + status, headers, body = await _serve( + InboundReply(ReplyOutcome.REPLY, body=REPLY_BODY, content_type="text/plain\r\nX-Evil: 1") + ) + assert status == 200 + assert body.decode() == REPLY_BODY + assert "x-evil" not in headers, "a partner injected a header through Content-Type" + assert headers["content-type"] == "application/json" diff --git a/tests/test_phi_logging_inventory.py b/tests/test_phi_logging_inventory.py index cb73e7ae..b6eb3b69 100644 --- a/tests/test_phi_logging_inventory.py +++ b/tests/test_phi_logging_inventory.py @@ -291,6 +291,29 @@ def test_every_message_event_kind_is_named_in_row_6() -> None: ) +def test_every_audit_floor_event_is_named_as_such_in_row_6() -> None: + """The compliance FLOOR — the kinds that survive ``[diagnostics].message_events = "off"``. + + RULE: row 6 states the floor **twice** and both statements were maintained by hand, with nothing + checking either against ``_AUDIT_FLOOR_EVENTS``. A kind could join the floor in code and the doc + would keep promising a shorter list — the failure mode being an operator who thins their logs + believing they know what survives. Row 6 names the floor as the thing that "can never be + thinned", so ASVS 16.1.1 scores it. + + Mutation: add a member to ``_AUDIT_FLOOR_EVENTS`` without touching row 6. Red: named below. + """ + from messagefoundry.store.store import _AUDIT_FLOOR_EVENTS + + section = _section_7() + row = next(line for line in section.splitlines() if line.startswith("| **6. `message_events`")) + missing = sorted(kind for kind in _AUDIT_FLOOR_EVENTS if f"`{kind}`" not in row) + assert not missing, ( + f"docs/PHI.md §7 row 6 does not name these compliance-floor kinds: {missing}. Row 6 promises " + "the floor is retained at every verbosity level; a floor member absent from it makes that " + "promise incomplete. Note the row states the floor TWICE — update both." + ) + + def test_message_event_constant_matches_the_literal_emit_sites() -> None: """The constant is trustworthy only while it tracks the code that writes the rows.""" import ast diff --git a/tests/test_reply_hint_thread_affinity.py b/tests/test_reply_hint_thread_affinity.py new file mode 100644 index 00000000..7adf5794 --- /dev/null +++ b/tests/test_reply_hint_thread_affinity.py @@ -0,0 +1,106 @@ +# SPDX-License-Identifier: AGPL-3.0-or-later +# Copyright (C) 2026 MessageFoundry Organization and contributors +"""The reply rendezvous is only ever touched from the event loop thread (ADR 0154 D3). + +**Static, because the failure is not reliably reproducible.** ``asyncio.Event.set()`` is not +thread-safe, and neither is the ``call_soon`` that schedules a waiter's wakeup. Called from a worker +thread it *usually appears to work* and intermittently drops the wakeup — so the turn hangs to its +full ``reply_timeout`` instead of returning in milliseconds, under load, occasionally. A functional +test cannot be relied on to catch that. + +Worse, the tempting hook sites are exactly the unsafe ones. ``_run_fused_route`` and +``_run_fused_transform`` contain a disposition line that reads like the obvious place to signal from, +and both are dispatched onto a ``ThreadPoolExecutor``. They are also **SQL-Server-only** and gated +behind ``fuse_thread_hops``, which defaults off — so the normal PR leg would never execute them even +if a hint were added. This guard is what stands between that and a silent production defect. +""" + +from __future__ import annotations + +import ast +from pathlib import Path + +_RUNNER = Path(__file__).resolve().parents[1] / "messagefoundry" / "pipeline" / "wiring_runner.py" + +#: Function bodies that run OFF the event loop, in a ThreadPoolExecutor. +_OFF_LOOP_FUNCTIONS = ("_run_fused_route", "_run_fused_transform") + +#: Any reference to the rendezvous. Deliberately broad — the point is that the object must not be +#: reachable from these frames at all, not that one particular method is avoided. +_FORBIDDEN_NAMES = ("_reply_rendezvous", "ReplyRendezvous", "reply_rendezvous") + + +def _function_source(tree: ast.Module, name: str) -> ast.AST | None: + for node in ast.walk(tree): + if isinstance(node, ast.FunctionDef | ast.AsyncFunctionDef) and node.name == name: + return node + return None + + +def test_the_off_loop_functions_exist() -> None: + """Liveness receipt: a rename would otherwise turn this module into green over nothing.""" + tree = ast.parse(_RUNNER.read_text(encoding="utf-8")) + missing = [name for name in _OFF_LOOP_FUNCTIONS if _function_source(tree, name) is None] + assert not missing, ( + f"{missing} no longer exist in wiring_runner.py. If the fused route/transform bodies were " + "renamed or removed, update _OFF_LOOP_FUNCTIONS — do not delete this guard, the thread-safety " + "constraint outlives any particular function name." + ) + + +def test_no_rendezvous_reference_in_an_off_loop_function() -> None: + """The guard. Mutation: add ``self._reply_rendezvous.signal(...)`` to either body. Red: named.""" + tree = ast.parse(_RUNNER.read_text(encoding="utf-8")) + + violations: list[str] = [] + for func_name in _OFF_LOOP_FUNCTIONS: + func = _function_source(tree, func_name) + if func is None: + continue + for node in ast.walk(func): + name = ( + node.attr + if isinstance(node, ast.Attribute) + else node.id + if isinstance(node, ast.Name) + else None + ) + if name in _FORBIDDEN_NAMES: + violations.append(f"{func_name} references {name!r} at line {node.lineno}") + + assert not violations, ( + "the reply rendezvous is reachable from a function that runs OFF the event loop: " + f"{violations}. asyncio.Event.set() and call_soon are NOT thread-safe — this usually appears " + "to work and intermittently drops the wakeup, hanging the HTTP turn to its full " + "reply_timeout under load. Hook the loop-side marshalling instead (the _Fused*Result path)." + ) + + +def test_the_guard_catches_a_planted_violation() -> None: + """The guard must actually fire, or it is decoration (mirrors test_scanner_flags_a_planted_*).""" + planted = ast.parse( + "def _run_fused_route(self, item):\n" + " self._reply_rendezvous.signal(item.message_id, item.destination_name)\n" + " return None\n" + ) + func = _function_source(planted, "_run_fused_route") + assert func is not None + found = [ + n.attr + for n in ast.walk(func) + if isinstance(n, ast.Attribute) and n.attr in _FORBIDDEN_NAMES + ] + assert found == ["_reply_rendezvous"], "the walk would not have seen a real violation" + + +def test_the_loop_side_signal_is_present() -> None: + """The other half: the hint must exist SOMEWHERE, or the poll silently carries every turn. + + Not a style check — a missing hint costs a poll interval on every reply and would never fail a + functional test, since the loop is correct without it. + """ + source = _RUNNER.read_text(encoding="utf-8") + assert "self._reply_rendezvous.signal(" in source, ( + "no delivery-side reply hint found — every sync-reply turn would wait a full poll period " + "for a reply that had already committed" + ) diff --git a/tests/test_reply_rendezvous.py b/tests/test_reply_rendezvous.py new file mode 100644 index 00000000..b5c4882b --- /dev/null +++ b/tests/test_reply_rendezvous.py @@ -0,0 +1,193 @@ +# SPDX-License-Identifier: AGPL-3.0-or-later +# Copyright (C) 2026 MessageFoundry Organization and contributors +"""The in-process reply rendezvous (ADR 0154 D3) — the race matrix, tested where it is deterministic. + +The rendezvous carries no information: every signal is a latency hint and the woken turn re-reads the +store. So these tests are not about *what* a wake means — they are about the two properties whose +absence produces silent, load-dependent failure in production and nothing at all in a functional test: + +* **a hint is consumed, never sticky** — an ``asyncio.Event`` stays set once set, so a waiter looping + on an unconsumed one stops sleeping and spins at full CPU for the rest of ``reply_timeout``, + precisely in the legitimate multi-handler case that drives repeated wakes; and +* **an armed entry never outlives its turn** — a leak accumulates until the cap, after which *every* + caller resolves ``degraded`` with a perfectly healthy store and no error anywhere. +""" + +from __future__ import annotations + +import asyncio +import time + +import pytest + +from messagefoundry.pipeline.reply_wait import RendezvousFull, ReplyRendezvous + +KEY = ("m1", "OB_PARTNER") + + +async def test_a_hint_wakes_the_waiter_early() -> None: + rv = ReplyRendezvous() + with rv.arm(*KEY) as waiter: + rv.signal(*KEY) + started = time.monotonic() + await waiter.hint(5.0) + assert time.monotonic() - started < 0.5, "the hint did not wake the waiter" + + +async def test_a_hint_is_consumed_not_sticky() -> None: + # THE spin guard. One signal buys exactly one early wake; the next tick must sleep normally. + # Without the consume, every subsequent hint() would return instantly forever. + rv = ReplyRendezvous() + with rv.arm(*KEY) as waiter: + rv.fail(*KEY) + + started = time.monotonic() + await waiter.hint(5.0) + assert time.monotonic() - started < 0.5 # consumed the hint + + started = time.monotonic() + await waiter.hint(0.15) + elapsed = time.monotonic() - started + assert elapsed >= 0.10, ( + f"the second hint returned after {elapsed:.3f}s — the Event stayed set, so a waiter would " + "spin at full CPU for the rest of reply_timeout" + ) + + +async def test_repeated_hints_coalesce_rather_than_queue() -> None: + # A sibling handler firing repeatedly must not bank wakes that skip future sleeps for free. + rv = ReplyRendezvous() + with rv.arm(*KEY) as waiter: + for _ in range(50): + rv.fail(*KEY) + await waiter.hint(5.0) # consumes all 50 + + started = time.monotonic() + await waiter.hint(0.15) + elapsed = time.monotonic() - started + assert elapsed >= 0.10, f"banked wakes survived: second hint returned in {elapsed:.3f}s" + + +async def test_a_signal_before_any_arm_is_a_silent_no_op() -> None: + # The normal case, not an error: every delivery signals, almost none is awaited. + rv = ReplyRendezvous() + rv.signal(*KEY) + rv.fail("unknown", "OB_NOBODY") + assert rv.waiters == 0 + + # ... and it does not leave a latent wake for a later turn on the same key. + with rv.arm(*KEY) as waiter: + started = time.monotonic() + await waiter.hint(0.15) + assert time.monotonic() - started >= 0.10, "a pre-arm signal leaked into a later turn" + + +async def test_a_foreign_key_never_wakes_this_waiter() -> None: + rv = ReplyRendezvous() + with rv.arm(*KEY) as waiter: + rv.signal("m1", "OB_OTHER") # same message, different destination + rv.signal("m2", "OB_PARTNER") # same destination, different message + started = time.monotonic() + await waiter.hint(0.15) + assert time.monotonic() - started >= 0.10, "a foreign key woke the waiter" + + +@pytest.mark.parametrize("failure", ["normal", "timeout", "exception", "cancel"]) +async def test_the_entry_count_returns_to_zero(failure: str) -> None: + # The leak guard, across every exit path a turn can take. + rv = ReplyRendezvous() + + async def turn() -> None: + with rv.arm(*KEY) as waiter: + assert rv.waiters == 1 + if failure == "timeout": + await waiter.hint(0.02) + elif failure == "exception": + raise RuntimeError("handler blew up mid-wait") + elif failure == "cancel": + await waiter.hint(30.0) # cancelled from outside + + if failure == "exception": + with pytest.raises(RuntimeError): + await turn() + elif failure == "cancel": + task = asyncio.create_task(turn()) + await asyncio.sleep(0.05) + task.cancel() + with pytest.raises(asyncio.CancelledError): + await task + else: + await turn() + + assert rv.waiters == 0, f"an armed entry survived the {failure!r} path — this is the leak" + + +async def test_many_sequential_turns_leave_nothing_behind() -> None: + rv = ReplyRendezvous() + for i in range(200): + with rv.arm(f"m{i}", "OB_PARTNER") as waiter: + rv.signal(f"m{i}", "OB_PARTNER") + await waiter.hint(1.0) + assert rv.waiters == 0 + + +async def test_the_cap_refuses_rather_than_queues() -> None: + rv = ReplyRendezvous(max_waiters=2) + with rv.arm("m1", "OB") as _a, rv.arm("m2", "OB") as _b: + assert rv.waiters == 2 + with pytest.raises(RendezvousFull, match="at capacity"), rv.arm("m3", "OB"): + pass + # ... and the cap is a live count, not a high-water mark: capacity returns on release. + assert rv.waiters == 0 + with rv.arm("m4", "OB"): + assert rv.waiters == 1 + + +async def test_drain_wakes_everyone_and_names_the_reason() -> None: + rv = ReplyRendezvous() + with rv.arm("m1", "OB") as first, rv.arm("m2", "OB") as second: + assert first.drain_reason is None + rv.drain("shutting_down") + + started = time.monotonic() + await first.hint(5.0) + await second.hint(5.0) + assert time.monotonic() - started < 0.5, "drain did not wake a blocked waiter" + assert first.drain_reason == "shutting_down" + assert second.drain_reason == "shutting_down" + + # A drained waiter never blocks again — stop() must not be paced by the poll period. + started = time.monotonic() + await first.hint(5.0) + assert time.monotonic() - started < 0.5 + + +async def test_arming_during_drain_is_refused() -> None: + # A request arriving mid-shutdown must resolve degraded immediately rather than arm a waiter + # nothing will ever wake. + rv = ReplyRendezvous() + rv.drain("shutting_down") + with pytest.raises(RendezvousFull, match="draining"), rv.arm("m1", "OB"): + pass + + +async def test_drain_is_idempotent() -> None: + rv = ReplyRendezvous() + with rv.arm("m1", "OB") as waiter: + rv.drain("shutting_down") + rv.drain("shutting_down") + assert waiter.drain_reason == "shutting_down" + assert rv.waiters == 0 + + +async def test_two_waiters_on_one_key_are_both_woken() -> None: + # Not expected in production (one HTTP turn per committed message), but a collision must not + # silently drop one waiter — that would be a turn that hangs to full timeout for no reason. + rv = ReplyRendezvous() + with rv.arm(*KEY) as first, rv.arm(*KEY) as second: + assert rv.waiters == 2 + rv.signal(*KEY) + started = time.monotonic() + await first.hint(5.0) + await second.hint(5.0) + assert time.monotonic() - started < 0.5 diff --git a/tests/test_store_record_message_event.py b/tests/test_store_record_message_event.py new file mode 100644 index 00000000..6f53ee2c --- /dev/null +++ b/tests/test_store_record_message_event.py @@ -0,0 +1,110 @@ +# SPDX-License-Identifier: AGPL-3.0-or-later +# Copyright (C) 2026 MessageFoundry Organization and contributors +"""``record_message_event`` — the public message-event writer (ADR 0154 D8). + +``_event`` is private to each backend and only ever called inside a store-owned transaction, so +before this neither ``pipeline/`` nor ``transports/`` could record a disposition event at all. + +The load-bearing test here is ``test_an_unknown_kind_is_refused``. The shipped static guard +(``test_message_event_constant_matches_the_literal_emit_sites``) AST-walks the backends for a +*constant* first argument to ``_event``; this method forwards a **variable**, so that guard is blind +to every kind written through it and passes vacuously. The runtime check is what actually keeps the +vocabulary closed on this path. +""" + +from __future__ import annotations + +import sqlite3 +from pathlib import Path + +import pytest + +from messagefoundry.store.store import MessageStore + +ADT = "MSH|^~\\&|S|F|R|RF|20260101||ADT^A01|MSG1|P|2.5.1\rPID|1||100^^^H^MR||DOE^JANE\r" + + +def _events(db_path: Path) -> list[tuple]: + con = sqlite3.connect(db_path) + try: + return con.execute( + "SELECT event, destination, detail FROM message_events ORDER BY id" + ).fetchall() + finally: + con.close() + + +async def test_writes_a_row_with_the_given_kind(tmp_path: Path) -> None: + db = tmp_path / "ev.db" + store = await MessageStore.open(db) + try: + mid = await store.enqueue_message(channel_id="IB_HTTP", raw=ADT, deliveries=[]) + await store.record_message_event( + mid, "reply_returned", destination="OB_PARTNER", detail="seq=1 waited_ms=42" + ) + await store.record_message_event(mid, "reply_timeout", destination="OB_PARTNER") + finally: + await store.close() + + written = [row for row in _events(db) if row[0].startswith("reply_")] + assert written == [ + ("reply_returned", "OB_PARTNER", "seq=1 waited_ms=42"), + ("reply_timeout", "OB_PARTNER", None if written[1][2] is None else ""), + ] + + +async def test_an_unknown_kind_is_refused(tmp_path: Path) -> None: + # The guard the static AST check cannot provide for this path. + store = await MessageStore.open(tmp_path / "bad.db") + try: + mid = await store.enqueue_message(channel_id="IB_HTTP", raw=ADT, deliveries=[]) + with pytest.raises(ValueError, match="unknown message_events kind"): + await store.record_message_event(mid, "reply_retruned") # typo + with pytest.raises(ValueError, match="unknown message_events kind"): + await store.record_message_event(mid, "something_invented") + finally: + await store.close() + + +async def test_the_reply_kinds_are_declared(tmp_path: Path) -> None: + from messagefoundry.store.store import _AUDIT_FLOOR_EVENTS, MESSAGE_EVENT_KINDS + + assert {"reply_returned", "reply_timeout"} <= MESSAGE_EVENT_KINDS + # reply_timeout is compliance-floor: it is the row that explains a "we called you and got a 504" + # complaint, so it must survive an operator thinning message_events to "errors" or "off". + assert "reply_timeout" in _AUDIT_FLOOR_EVENTS + # reply_returned is the routine happy-path counterpart and is deliberately thinnable. + assert "reply_returned" not in _AUDIT_FLOOR_EVENTS + + +async def test_the_floor_kind_survives_verbosity_off(tmp_path: Path) -> None: + # The whole point of the floor. `off` drops the routine kind and keeps the diagnostic one. + db = tmp_path / "off.db" + store = await MessageStore.open(db, message_events="off") + try: + mid = await store.enqueue_message(channel_id="IB_HTTP", raw=ADT, deliveries=[]) + await store.record_message_event(mid, "reply_returned", destination="OB_PARTNER") + await store.record_message_event(mid, "reply_timeout", destination="OB_PARTNER") + finally: + await store.close() + + kinds = [row[0] for row in _events(db)] + assert "reply_timeout" in kinds, "the floor kind was thinned away — the floor is not holding" + assert "reply_returned" not in kinds, "a routine kind survived verbosity=off" + + +async def test_detail_is_scrubbed_at_the_store_boundary(tmp_path: Path) -> None: + # Defence in depth only. The real control is structural: reply-derived bytes never reach a + # detail argument in the first place. This asserts the store's own PHI chokepoint still applies + # to this new writer, so it is not a hole around safe_text. + db = tmp_path / "scrub.db" + store = await MessageStore.open(db) + try: + mid = await store.enqueue_message(channel_id="IB_HTTP", raw=ADT, deliveries=[]) + await store.record_message_event(mid, "reply_timeout", detail=ADT) + finally: + await store.close() + + detail = next(row[2] for row in _events(db) if row[0] == "reply_timeout") + assert detail is not None + assert "DOE^JANE" not in detail, "an HL7 field value reached message_events.detail unscrubbed" diff --git a/tests/test_store_reply_wait_state.py b/tests/test_store_reply_wait_state.py new file mode 100644 index 00000000..f8133a8a --- /dev/null +++ b/tests/test_store_reply_wait_state.py @@ -0,0 +1,153 @@ +# SPDX-License-Identifier: AGPL-3.0-or-later +# Copyright (C) 2026 MessageFoundry Organization and contributors +"""``reply_wait_state`` — the metadata-only poll read behind the ADR 0154 D3 sync-reply wait. + +Two properties carry this module, and both are correctness rather than convenience. + +**Terminality is defined by exclusion, never by enumeration.** An enumerated terminal set +(``UNROUTED``/``FILTERED``/``NOT_DEPLOYED``/``ERROR``) omits ``PROCESSED`` — which is exactly what the +finalizer sets when a *sibling* handler delivered while the awaited destination's ``Send`` was +declined, filtered out, or never emitted. The wait would then hang for the whole ``reply_timeout`` +instead of failing fast. ``test_terminality_covers_every_message_status`` iterates the enum so a new +member forces an explicit decision instead of silently inheriting that bug. + +**An empty row list is not evidence of exclusion.** Routed rows carry a NULL ``destination_name``, so +a sibling handler still upstream is structurally invisible to the destination-keyed query. Reading +"no rows" as "excluded" is the defect ADR 0154 revision 1 shipped: a ``502`` for a message the engine +then delivered normally. +""" + +from __future__ import annotations + +from pathlib import Path + +from messagefoundry.store.store import MessageStatus, MessageStore, ReplyWaitState + +ADT = "MSH|^~\\&|S|F|R|RF|20260101||ADT^A01|MSG1|P|2.5.1\rPID|1||100^^^H^MR||DOE^JANE\r" +REPLY = '{"status":"ok","id":"partner-1"}' + + +def test_terminality_covers_every_message_status() -> None: + # The load-bearing test. Exclusion must be TOTAL against the enum: every member is classified, + # and a member added later fails here rather than silently becoming "keep waiting" forever. + still_running = {MessageStatus.RECEIVED, MessageStatus.ROUTED} + for status in MessageStatus: + state = ReplyWaitState(message_status=status.value, row_states=(), latest_response_seq=None) + expected = status not in still_running + assert state.message_is_terminal is expected, ( + f"{status.value!r} classified wrongly — if this is a NEW MessageStatus member, decide " + "explicitly whether a reply can still arrive for it; do not let it default" + ) + + # Named explicitly so the intent survives a refactor of the loop above: PROCESSED is terminal, + # and it is the member an enumerated list forgets. + assert ReplyWaitState(MessageStatus.PROCESSED.value, (), None).message_is_terminal + assert not ReplyWaitState(MessageStatus.ROUTED.value, (), None).message_is_terminal + + +def test_a_vanished_message_is_terminal() -> None: + # Nothing can arrive for a message that is gone; the caller resolves it as degraded rather than + # blocking for the full timeout. + assert ReplyWaitState( + message_status=None, row_states=(), latest_response_seq=None + ).message_is_terminal + + +async def test_reports_status_rows_and_no_reply_before_capture(tmp_path: Path) -> None: + store = await MessageStore.open(tmp_path / "wait.db") + try: + mid = await store.enqueue_message( + channel_id="IB_HTTP", raw=ADT, deliveries=[("OB_PARTNER", ADT)] + ) + state = await store.reply_wait_state(mid, "OB_PARTNER") + + assert state.message_status is not None + assert not state.message_is_terminal # still flowing — the wait must continue + assert state.row_states # the awaited destination has a queued row + assert state.latest_response_seq is None # nothing captured yet + finally: + await store.close() + + +async def test_a_sibling_handlers_row_does_not_look_like_exclusion(tmp_path: Path) -> None: + # AC-6 in miniature, at the store layer. The awaited destination has NO row yet while a sibling + # is upstream, so row_states is empty — and that must NOT read as "excluded". + store = await MessageStore.open(tmp_path / "sibling.db") + try: + mid = await store.enqueue_message( + channel_id="IB_HTTP", raw=ADT, deliveries=[("OB_OTHER", ADT)] + ) + state = await store.reply_wait_state(mid, "OB_PARTNER") # a destination with no rows at all + + assert state.row_states == () + assert not state.message_is_terminal, ( + "an empty row list plus a non-terminal message must mean KEEP WAITING — reading it as " + "exclusion is the 502-for-a-delivered-message defect" + ) + finally: + await store.close() + + +async def test_latest_response_seq_appears_once_a_reply_commits(tmp_path: Path) -> None: + store = await MessageStore.open(tmp_path / "capture.db") + try: + mid = await store.enqueue_message( + channel_id="IB_HTTP", raw=ADT, deliveries=[("OB_PARTNER", ADT)] + ) + assert (await store.reply_wait_state(mid, "OB_PARTNER")).latest_response_seq is None + + items = await store.claim_ready(destination_name="OB_PARTNER") + assert items, "expected the queued outbound row to be claimable" + await store.complete_with_response(items[0].id, body=REPLY, outcome="accepted") + + state = await store.reply_wait_state(mid, "OB_PARTNER") + assert state.latest_response_seq == 1 + + # ... and the body is reachable exactly once, through the existing decrypting read. + captured = [r for r in await store.correlate_response(mid) if r.kind == "response"] + assert [c.body for c in captured] == [REPLY] + finally: + await store.close() + + +async def test_an_ack_sent_row_is_never_mistaken_for_the_partners_reply(tmp_path: Path) -> None: + # ADR 0021 ack_sent rows share the response table. The inbound ACK *we* returned must not satisfy + # a wait for the partner's reply — otherwise the listener echoes our own ACK back to the caller. + store = await MessageStore.open(tmp_path / "acksent.db") + try: + mid = await store.enqueue_message( + channel_id="IB_HTTP", raw=ADT, deliveries=[("OB_PARTNER", ADT)] + ) + await store.record_ack_sent( + message_id=mid, + inbound_name="IB_HTTP", + ack_body=None, + ack_code="AA", + ack_phase="ingest", + outcome="accepted", + ) + state = await store.reply_wait_state(mid, "OB_PARTNER") + assert state.latest_response_seq is None, "an ack_sent row satisfied a partner-reply wait" + finally: + await store.close() + + +async def test_the_read_decrypts_nothing(tmp_path: Path) -> None: + # The poll runs per tick while a caller is blocked, so it must stay metadata-only. Proven by + # construction: every field is a non-encrypted column, and an encrypted store returns the same + # values as a plaintext one for the same graph. + from messagefoundry.store.crypto import generate_key, make_cipher + + store = await MessageStore.open(tmp_path / "enc.db", cipher=make_cipher(generate_key())) + try: + mid = await store.enqueue_message( + channel_id="IB_HTTP", raw=ADT, deliveries=[("OB_PARTNER", ADT)] + ) + items = await store.claim_ready(destination_name="OB_PARTNER") + await store.complete_with_response(items[0].id, body=REPLY, outcome="accepted") + + state = await store.reply_wait_state(mid, "OB_PARTNER") + assert state.latest_response_seq == 1 # readable without touching the encrypted body + assert isinstance(state.message_status, str) + finally: + await store.close() diff --git a/tests/test_sync_reply_cross_registry.py b/tests/test_sync_reply_cross_registry.py new file mode 100644 index 00000000..a3605de0 --- /dev/null +++ b/tests/test_sync_reply_cross_registry.py @@ -0,0 +1,166 @@ +# SPDX-License-Identifier: AGPL-3.0-or-later +# Copyright (C) 2026 MessageFoundry Organization and contributors +"""Cross-registry validation for ``reply_from`` (ADR 0154 D4) — the facts one ``Http()`` call cannot +know, because they are about the *other* connection. + +The load-bearing pair is ``ordering`` / ``max_attempts``, and they are load-bearing precisely because +the naive test passes. ``OutboundConnection.ordering`` defaults to ``None`` meaning *inherit* and +``retry`` defaults to no policy object at all, so a literal ``ordering == FIFO`` check passes cleanly +for the overwhelmingly common shape — which is the exact shape the refusal exists to catch. These +tests therefore assert against the shape that declares **nothing**. +""" + +from __future__ import annotations + +import pytest + +from messagefoundry.config.models import ContentType, OrderingMode, RetryPolicy +from messagefoundry.config.settings import DeliverySettings +from messagefoundry.config.wiring import ( + Http, + Registry, + Rest, + WiringError, + apply_sync_reply_capture_implication, + build_inbound_connection, + build_outbound_connection, +) +from messagefoundry.pipeline.wiring_runner import check_http_sync_reply + +# The shape that makes the feature work: an unordered lane that dead-letters rather than retrying +# forever. Everything else in this module is a departure from it. +SERVICEABLE = DeliverySettings(ordering=OrderingMode.UNORDERED, retry_max_attempts=3) + + +def _graph( + *, + reply_from: str | None = "OB_PARTNER", + reply_content_type: str = "passthrough", + capture_response: bool = True, + capture_headers: list[str] | None = None, + deployed: bool = True, + ordering: OrderingMode | None = None, + retry: RetryPolicy | None = None, + outbound_name: str = "OB_PARTNER", +) -> tuple[Registry, object]: + reg = Registry() + ic = build_inbound_connection( + "IB_HTTP", + Http(port=0, reply_from=reply_from, reply_content_type=reply_content_type) + if reply_from + else Http(port=0), + router="r", + content_type=ContentType.JSON, + ) + reg.add_inbound(ic) + reg.add_outbound( + build_outbound_connection( + outbound_name, + Rest( + url="https://partner.example/ingest", + capture_response=capture_response, + capture_response_headers=capture_headers, + ), + deployed=deployed, + ordering=ordering, + retry=retry, + ) + ) + return reg, ic + + +def test_a_serviceable_graph_passes() -> None: + reg, ic = _graph(ordering=OrderingMode.UNORDERED, retry=RetryPolicy(max_attempts=3)) + apply_sync_reply_capture_implication(reg) + check_http_sync_reply(ic, reg, delivery=SERVICEABLE) + + +def test_an_inbound_without_reply_from_is_untouched() -> None: + reg, ic = _graph(reply_from=None) + check_http_sync_reply(ic, reg, delivery=DeliverySettings()) # the FIFO/forever default: fine + + +def test_an_unknown_or_undeployed_target_is_refused() -> None: + reg, ic = _graph(outbound_name="OB_SOMETHING_ELSE") + with pytest.raises(WiringError, match="unknown outbound"): + check_http_sync_reply(ic, reg, delivery=SERVICEABLE) + + reg, ic = _graph(deployed=False) + with pytest.raises(WiringError, match="deployed=False"): + check_http_sync_reply(ic, reg, delivery=SERVICEABLE) + + +def test_a_target_that_does_not_capture_is_refused() -> None: + # Without capture_response there is no reply to return, so every call would block to timeout. + reg, ic = _graph(capture_response=False) + with pytest.raises(WiringError, match="capture_response=True"): + check_http_sync_reply(ic, reg, delivery=SERVICEABLE) + + +def test_reply_from_implies_capturing_the_content_type() -> None: + # The ADR contradicts itself here: reply_content_type defaults to "passthrough", which D4 says + # requires content-type in capture_response_headers — a setting that defaults to None. So the + # ADR's own headline shape would refuse. The implication resolves it. + reg, ic = _graph(ordering=OrderingMode.UNORDERED, retry=RetryPolicy(max_attempts=3)) + assert not reg.outbound["OB_PARTNER"].spec.settings["capture_response_headers"] + + apply_sync_reply_capture_implication(reg) + + headers = reg.outbound["OB_PARTNER"].spec.settings["capture_response_headers"] + assert [h.lower() for h in headers] == ["content-type"] + check_http_sync_reply(ic, reg, delivery=SERVICEABLE) + + +def test_the_implication_is_idempotent_and_preserves_operator_headers() -> None: + reg, _ = _graph(capture_headers=["X-Request-Id", "Content-Type"]) + apply_sync_reply_capture_implication(reg) + apply_sync_reply_capture_implication(reg) + headers = reg.outbound["OB_PARTNER"].spec.settings["capture_response_headers"] + assert headers == ["X-Request-Id", "Content-Type"], "the operator's own list was disturbed" + + # Case-insensitively already present, so nothing is appended a second time. + reg, _ = _graph(capture_headers=["content-type"]) + apply_sync_reply_capture_implication(reg) + assert reg.outbound["OB_PARTNER"].spec.settings["capture_response_headers"] == ["content-type"] + + +def test_the_implication_leaves_a_literal_mime_type_alone() -> None: + # Only passthrough needs the partner's own content type; a pinned MIME type does not. + reg, _ = _graph(reply_content_type="application/json") + apply_sync_reply_capture_implication(reg) + assert not reg.outbound["OB_PARTNER"].spec.settings["capture_response_headers"] + + +def test_an_effective_fifo_lane_is_refused_even_when_nothing_is_declared() -> None: + # THE landmine. ordering is unset, so a literal `== FIFO` test passes — while the lane really + # does resolve to FIFO and serialises every concurrent caller behind one partner round-trip. + reg, ic = _graph(retry=RetryPolicy(max_attempts=3)) # ordering left unset + assert reg.outbound["OB_PARTNER"].ordering is None, "the test lost its own premise" + + with pytest.raises(WiringError, match="EFFECTIVE ordering is FIFO"): + check_http_sync_reply(ic, reg, delivery=DeliverySettings(retry_max_attempts=3)) + + # An explicit FIFO is refused too, and the message distinguishes the two cases. + reg, ic = _graph(ordering=OrderingMode.FIFO, retry=RetryPolicy(max_attempts=3)) + with pytest.raises(WiringError, match="declared: fifo"): + check_http_sync_reply(ic, reg, delivery=SERVICEABLE) + + +def test_effective_retry_forever_is_refused_even_when_nothing_is_declared() -> None: + # Same shape: no RetryPolicy object at all, so the declared value is None and the naive test + # passes, while the lane really does resolve to retry-forever. + reg, ic = _graph(ordering=OrderingMode.UNORDERED) # retry left unset + assert reg.outbound["OB_PARTNER"].retry is None, "the test lost its own premise" + + with pytest.raises(WiringError, match="EFFECTIVE max_attempts"): + check_http_sync_reply(ic, reg, delivery=DeliverySettings(ordering=OrderingMode.UNORDERED)) + + # ... and inheriting a FINITE global default is fine. + check_http_sync_reply(ic, reg, delivery=SERVICEABLE) + + +def test_the_effective_arm_is_skipped_rather_than_guessed_without_delivery() -> None: + # A caller that could not resolve [delivery] must not have the refusal guessed for it — the + # runner re-checks at start where the resolved values always exist. + reg, ic = _graph() # nothing declared: would be refused if delivery were known + check_http_sync_reply(ic, reg, delivery=None) diff --git a/tests/test_sync_reply_resolver.py b/tests/test_sync_reply_resolver.py new file mode 100644 index 00000000..16441a19 --- /dev/null +++ b/tests/test_sync_reply_resolver.py @@ -0,0 +1,452 @@ +# SPDX-License-Identifier: AGPL-3.0-or-later +# Copyright (C) 2026 MessageFoundry Organization and contributors +"""The synchronous-reply resolver (ADR 0154 D3) — the wait loop's outcome matrix. + +Driven through a store double so every branch is deterministic, including the ones a real store +reaches only under a race: a sibling handler still upstream, a body nulled by retention mid-wait, and +a read that raises. The resolver is **total** — every exit is an ``InboundReply`` — so "it raised" is +itself a failure these tests can catch. +""" + +from __future__ import annotations + +import asyncio +from dataclasses import dataclass +from typing import Any + +import pytest + +from messagefoundry.pipeline.reply_wait import ReplyRendezvous +from messagefoundry.pipeline.sync_reply import ( + SyncReplyMetrics, + SyncReplyResolverImpl, + poll_period, +) +from messagefoundry.store.store import MessageStatus, ReplyWaitState +from messagefoundry.transports.base import ReplyOutcome + +DEST = "OB_PARTNER" +BODY = '{"status":"accepted","mrn":"100"}' + + +@dataclass +class _Row: + kind: str = "response" + destination_name: str = DEST + response_seq: int = 1 + outcome: str = "accepted" + body: str | None = BODY + headers: dict[str, str] | None = None + + +class _Store: + """A store double: a scripted sequence of wait states, then a fixed set of captured rows.""" + + def __init__(self, states: list[Any], rows: list[_Row] | None = None) -> None: + self._states = list(states) + self._rows = rows or [] + self.state_reads = 0 + + async def reply_wait_state(self, message_id: str, destination_name: str) -> Any: + self.state_reads += 1 + state = self._states[0] if len(self._states) == 1 else self._states.pop(0) + if isinstance(state, Exception): + raise state + return state + + async def correlate_response(self, message_id: str) -> list[Any]: + if isinstance(self._rows, Exception): + raise self._rows + return list(self._rows) + + +def _flowing(**kw: Any) -> ReplyWaitState: + return ReplyWaitState( + message_status=kw.pop("status", MessageStatus.ROUTED.value), + row_states=kw.pop("row_states", ("pending",)), + latest_response_seq=kw.pop("seq", None), + ) + + +def _resolver(store: Any, **kw: Any) -> SyncReplyResolverImpl: + return SyncReplyResolverImpl( + store, + kw.pop("rendezvous", ReplyRendezvous()), + destination=DEST, + timeout=kw.pop("timeout", 2.0), + content_type=kw.pop("content_type", "passthrough"), + metrics=kw.pop("metrics", None), + ) + + +async def test_a_committed_accepted_reply_is_returned_verbatim() -> None: + store = _Store([_flowing(seq=1)], [_Row(headers={"Content-Type": "application/json"})]) + reply = await _resolver(store)("m1") + assert reply.outcome is ReplyOutcome.REPLY + assert reply.body == BODY + assert reply.content_type == "application/json" + assert reply.destination == DEST and reply.response_seq == 1 + + +async def test_a_rejected_reply_still_returns_the_partners_body() -> None: + # A partner is the answer the caller needs to see; swallowing it would be worse than a + # 502 with no detail. + store = _Store([_flowing(seq=1)], [_Row(outcome="rejected", body="nope")]) + reply = await _resolver(store)("m1") + assert reply.outcome is ReplyOutcome.REJECTED + assert reply.body == "nope" + + +async def test_an_empty_partner_reply_is_its_own_outcome() -> None: + store = _Store([_flowing(seq=1)], [_Row(outcome="no_reply", body="")]) + assert (await _resolver(store)("m1")).outcome is ReplyOutcome.EMPTY + + +async def test_a_purged_body_is_distinct_from_no_reply() -> None: + # Retention nulled the body in place. The row exists, so this is not "the partner said nothing". + store = _Store([_flowing(seq=1)], [_Row(body=None)]) + reply = await _resolver(store)("m1") + assert reply.outcome is ReplyOutcome.PURGED + assert reply.body is None + + +async def test_the_highest_seq_wins_and_ack_sent_is_ignored() -> None: + store = _Store( + [_flowing(seq=2)], + [ + _Row(response_seq=1, body="first"), + _Row(response_seq=2, body="second"), + _Row(kind="ack_sent", response_seq=99, body="OUR OWN ACK"), + _Row(destination_name="OB_OTHER", response_seq=98, body="someone else's reply"), + ], + ) + reply = await _resolver(store)("m1") + assert reply.body == "second", "a replay appends seq=N+1; the latest capture is authoritative" + + +async def test_a_dead_row_fails_fast_rather_than_waiting_out_the_budget() -> None: + store = _Store([_flowing(row_states=("dead",))]) + reply = await _resolver(store, timeout=30.0)("m1") + assert reply.outcome is ReplyOutcome.FAILED + assert reply.waited_ms < 5000, "it waited instead of failing fast on a proven-terminal row" + + +async def test_a_sibling_handler_upstream_does_not_look_like_exclusion() -> None: + # AC-6. The awaited destination has NO rows yet because a sibling is still upstream — routed rows + # carry a NULL destination_name. Reading that as "excluded" is the 502-for-a-delivered-message + # defect. The loop must keep waiting, then return the reply once it commits. + store = _Store( + [ + _flowing(row_states=()), # sibling upstream: no rows for us at all + _flowing(row_states=()), + _flowing(row_states=("pending",), seq=1), + ], + [_Row()], + ) + reply = await _resolver(store)("m1") + assert reply.outcome is ReplyOutcome.REPLY + assert store.state_reads >= 3 + + +async def test_a_terminal_message_with_no_reply_is_no_route() -> None: + store = _Store([_flowing(status=MessageStatus.UNROUTED.value, row_states=())]) + assert (await _resolver(store, timeout=30.0)("m1")).outcome is ReplyOutcome.NO_ROUTE + + +async def test_processed_is_terminal_too() -> None: + # The member an ENUMERATED terminal list forgets: a sibling handler delivered and the finalizer + # set PROCESSED while our destination's Send was never emitted. Enumeration would hang here for + # the full reply_timeout. + store = _Store([_flowing(status=MessageStatus.PROCESSED.value, row_states=())]) + reply = await _resolver(store, timeout=30.0)("m1") + assert reply.outcome is ReplyOutcome.NO_ROUTE + assert reply.waited_ms < 5000, "PROCESSED was not treated as terminal — it waited" + + +async def test_the_budget_expires_into_a_timeout() -> None: + store = _Store([_flowing()]) # never resolves + reply = await _resolver(store, timeout=0.2)("m1") + assert reply.outcome is ReplyOutcome.TIMEOUT + assert reply.waited_ms >= 150 + + +async def test_a_store_error_is_degraded_not_timeout() -> None: + # rate(timeout)/rate(total) is the proxy API's error budget. Counting OUR store failure as the + # partner failing to answer would silently corrupt the one number an operator pages on. + store = _Store([RuntimeError("db is gone")]) + reply = await _resolver(store)("m1") + assert reply.outcome is ReplyOutcome.DEGRADED + assert reply.body is None + + +async def test_a_full_rendezvous_is_degraded_not_timeout() -> None: + rv = ReplyRendezvous(max_waiters=1) + with rv.arm("other", DEST): + reply = await _resolver(_Store([_flowing()]), rendezvous=rv)("m1") + assert reply.outcome is ReplyOutcome.DEGRADED + + +async def test_a_drain_mid_wait_resolves_shutting_down() -> None: + rv = ReplyRendezvous() + store = _Store([_flowing()]) + resolver = _resolver(store, rendezvous=rv, timeout=30.0) + + task = asyncio.create_task(resolver("m1")) + await asyncio.sleep(0.1) + rv.drain("shutting_down") + reply = await asyncio.wait_for(task, 5.0) + + assert reply.outcome is ReplyOutcome.SHUTTING_DOWN + assert reply.waited_ms < 5000, "a drained waiter was still paced by the poll period" + + +async def test_a_literal_content_type_overrides_passthrough() -> None: + store = _Store([_flowing(seq=1)], [_Row(headers={"Content-Type": "text/plain"})]) + reply = await _resolver(store, content_type="application/json")("m1") + assert reply.content_type == "application/json" + + +async def test_passthrough_degrades_to_the_callers_default_when_headers_are_gone() -> None: + # Retention can null captured headers while leaving the body. The body is still good, so the + # turn must not fail — the caller falls back to its own default content type. + store = _Store([_flowing(seq=1)], [_Row(headers={})]) + assert (await _resolver(store)("m1")).content_type is None + + +async def test_the_rendezvous_entry_is_always_released() -> None: + rv = ReplyRendezvous() + for store in (_Store([_flowing(seq=1)], [_Row()]), _Store([RuntimeError("x")])): + await _resolver(store, rendezvous=rv, timeout=0.2)("m1") + assert rv.waiters == 0 + + +def test_the_poll_period_widens_with_load() -> None: + # On SQLite, reads share a FIXED pool of four with the admin API, console and sweeps, so a + # constant period turns 256 blocked callers into a self-inflicted denial of service. + assert poll_period(1) == poll_period(8) # light load: the floor + assert poll_period(64) > poll_period(8) # heavier: backs off + assert poll_period(10_000) <= 0.25 # ... but bounded, so latency stays predictable + + +# --- AC-18: observability ------------------------------------------------------------------------ + + +class _RecordingStore(_Store): + def __init__(self, *a: Any, **kw: Any) -> None: + super().__init__(*a, **kw) + self.events: list[tuple[str, str, str | None, str | None]] = [] + self.event_error: Exception | None = None + + async def record_message_event( + self, + message_id: str, + event: str, + *, + destination: str | None = None, + detail: str | None = None, + now: float | None = None, + ) -> None: + if self.event_error is not None: + raise self.event_error + self.events.append((message_id, event, destination, detail)) + + +async def test_a_returned_reply_records_reply_returned_without_any_body() -> None: + store = _RecordingStore([_flowing(seq=1)], [_Row()]) + metrics = SyncReplyMetrics("IB_HTTP") + await _resolver(store, metrics=metrics)("m1") + + assert len(store.events) == 1 + message_id, event, destination, detail = store.events[0] + assert (message_id, event, destination) == ("m1", "reply_returned", DEST) + assert "seq=1" in detail and "outcome=reply" in detail and "waited_ms=" in detail + # The PHI property: names, counts and timings only — never a fragment of the partner's body. + for leak in ("mrn", "100", BODY): + assert leak not in detail + + assert metrics.totals == {"reply": 1} + + +async def test_rejected_and_empty_also_count_as_a_reply_returned() -> None: + # The partner answered; a negative or deliberately blank answer is still the thing the caller + # was waiting for, so it belongs in the same row rather than looking like nothing happened. + for outcome, row in ( + ("rejected", _Row(outcome="rejected")), + ("no_reply", _Row(outcome="no_reply", body="")), + ): + store = _RecordingStore([_flowing(seq=1)], [row]) + await _resolver(store)("m1") + assert [e[1] for e in store.events] == ["reply_returned"], outcome + + +async def test_a_timeout_records_reply_timeout_with_its_fallback() -> None: + store = _RecordingStore([_flowing()]) + await _resolver(store, timeout=0.15)("m1") + + assert len(store.events) == 1 + _, event, destination, detail = store.events[0] + assert (event, destination) == ("reply_timeout", DEST) + assert "fallback=504" in detail, "an operator reading this needs to know what the caller got" + assert "waited_ms=" in detail + + +async def test_outcomes_with_their_own_disposition_trail_mint_no_second_row() -> None: + # A dead row, an UNROUTED message and a degraded read each already leave their own record. + # Duplicating them here would make the timeline read as two events where one thing happened. + for states in ( + _flowing(row_states=("dead",)), + _flowing(status=MessageStatus.UNROUTED.value, row_states=()), + ): + store = _RecordingStore([states]) + await _resolver(store, timeout=0.2)("m1") + assert store.events == [] + + store = _RecordingStore([RuntimeError("db gone")]) + await _resolver(store)("m1") + assert store.events == [] + + +async def test_observability_failure_never_costs_the_caller_their_reply() -> None: + # The wait has already resolved by this point, so losing a diagnostic row is strictly better + # than turning a perfectly good partner reply into a 500. + store = _RecordingStore([_flowing(seq=1)], [_Row()]) + store.event_error = RuntimeError("message_events write failed") + + reply = await _resolver(store)("m1") + assert reply.outcome is ReplyOutcome.REPLY + assert reply.body == BODY + + +async def test_the_metrics_separate_degraded_from_timeout() -> None: + # rate(timeout)/rate(total) IS the proxy API's error budget, so our own failures must not be + # counted as the partner failing to answer. + metrics = SyncReplyMetrics("IB_HTTP") + await _resolver(_RecordingStore([RuntimeError("x")]), metrics=metrics)("m1") + await _resolver(_RecordingStore([_flowing()]), metrics=metrics, timeout=0.1)("m2") + + assert metrics.totals == {"degraded": 1, "timeout": 1} + assert metrics.wait_count == 2 + assert metrics.mean_wait_seconds > 0 + + +def test_the_metric_labels_stay_inside_the_closed_allowlist() -> None: + # api/metrics.py states a CLOSED label allowlist as a PHI contract and a test asserts it. The + # outcome enum is a fixed non-PHI constant set, so it rides `status` rather than widening it. + from tests.test_metrics_exporter import ALLOWED_LABELS + + assert "status" in ALLOWED_LABELS + assert "outcome" not in ALLOWED_LABELS, "the allowlist was widened — re-check the PHI contract" + + +def test_the_three_series_reach_a_scrape_with_allowlisted_labels() -> None: + """AC-18's metric half, asserted on the exposition rather than on the counters. + + The counters incrementing proves nothing an operator can see; this proves the families are + actually emitted, named as the ADR specifies, and labelled inside the closed allowlist. + """ + from messagefoundry.api.metrics import _MetricsCollector, _Snapshot + + metrics = SyncReplyMetrics("IB_HTTP") + metrics.totals = {"reply": 7, "timeout": 2, "degraded": 1} + metrics.wait_seconds_sum, metrics.wait_count, metrics.live = 5.0, 10, 3 + + snapshot = _Snapshot( + version="test", + inbound={}, + destinations={}, + latency=[], + outbox_by_status={}, + in_pipeline=0, + now=0.0, + sync_replies={"IB_HTTP": metrics}, + ) + families = {f.name: f for f in _MetricsCollector(snapshot).collect()} + + # prometheus_client strips a `_total` suffix from Metric.name while the EXPOSED sample keeps it, + # so assert on the sample names — that is what a scrape actually shows. + exposed = {sample.name for f in families.values() for sample in f.samples} + assert "messagefoundry_http_sync_replies_total" in exposed + assert "messagefoundry_http_sync_reply_wait_seconds" in exposed + assert "messagefoundry_http_sync_reply_waiters" in exposed + + total = families["messagefoundry_http_sync_replies"] + by_status = {tuple(s.labels.values()): s.value for s in total.samples} + assert by_status[("IB_HTTP", "reply")] == 7.0 + # degraded is its OWN label value, never folded into timeout: rate(timeout)/rate(total) is the + # proxy API's error budget, so our failures must not read as the partner failing to answer. + assert by_status[("IB_HTTP", "timeout")] == 2.0 + assert by_status[("IB_HTTP", "degraded")] == 1.0 + + assert families["messagefoundry_http_sync_reply_wait_seconds"].samples[0].value == 0.5 + assert families["messagefoundry_http_sync_reply_waiters"].samples[0].value == 3.0 + + # The PHI contract: every label used stays inside the closed allowlist. + from tests.test_metrics_exporter import ALLOWED_LABELS + + for family in families.values(): + for sample in family.samples: + assert set(sample.labels) <= ALLOWED_LABELS, f"{family.name} widened the allowlist" + + +def test_an_instance_with_no_sync_reply_inbound_emits_nothing_new() -> None: + # Byte-identical scrape for every existing deployment — absent families rather than zeros, so a + # constant 0 on every fleet that never uses this cannot become alert noise. + from messagefoundry.api.metrics import _MetricsCollector, _Snapshot + + snapshot = _Snapshot( + version="test", + inbound={}, + destinations={}, + latency=[], + outbox_by_status={}, + in_pipeline=0, + now=0.0, + ) + names = {f.name for f in _MetricsCollector(snapshot).collect()} + assert not any(n.startswith("messagefoundry_http_sync_reply") for n in names) + + +async def test_a_cancelled_turn_does_not_leak_a_live_waiter() -> None: + # The gauge operators size capacity on. A client that hangs up mid-wait must not leave a + # permanently-blocked waiter behind in it. + metrics = SyncReplyMetrics("IB_HTTP") + resolver = _resolver(_Store([_flowing()]), metrics=metrics, timeout=30.0) + + task = asyncio.create_task(resolver("m1")) + await asyncio.sleep(0.1) + assert metrics.live == 1 + task.cancel() + with pytest.raises(asyncio.CancelledError): + await task + assert metrics.live == 0, "a cancelled turn leaked a live waiter into the gauge" + + +async def test_the_hint_collapses_the_wait_to_well_under_a_poll_period() -> None: + """C12's whole value: the reply is returned on the signal, not on the next scheduled read. + + Asserted as a READ COUNT rather than a wall-clock margin — a timing assertion here would be the + kind of load-sensitive test that fails on a slow runner for reasons unrelated to the code. + """ + rv = ReplyRendezvous() + store = _Store([_flowing(), _flowing(seq=1)], [_Row()]) + resolver = _resolver(store, rendezvous=rv, timeout=30.0) + + async def deliver_soon() -> None: + await asyncio.sleep(0.05) + store._states = [_flowing(seq=1)] # the capture commits... + rv.signal("m1", DEST) # ... and the hint fires, exactly as the delivery worker does + + await asyncio.gather(resolver("m1"), deliver_soon()) + + # Without the hint this would have taken ceil(0.05 / poll_period) reads and returned late; with + # it, the waiter wakes on the signal and re-reads once. + assert store.state_reads <= 3, f"the hint did not shorten the wait ({store.state_reads} reads)" + + +async def test_a_missing_hint_still_returns_the_reply_just_later() -> None: + # The property that makes the hint safe to be wrong, and safe to be absent: an engine shard that + # never sees the signal still resolves correctly off the poll. Latency, never correctness. + store = _Store([_flowing(), _flowing(), _flowing(seq=1)], [_Row()]) + reply = await _resolver(store, timeout=30.0)("m1") # no signal is ever fired + assert reply.outcome is ReplyOutcome.REPLY + assert reply.body == BODY diff --git a/tests/test_sync_reply_seam.py b/tests/test_sync_reply_seam.py new file mode 100644 index 00000000..437fb3b0 --- /dev/null +++ b/tests/test_sync_reply_seam.py @@ -0,0 +1,92 @@ +# SPDX-License-Identifier: AGPL-3.0-or-later +# Copyright (C) 2026 MessageFoundry Organization and contributors +"""The synchronous-reply injection seam (ADR 0154 D2) — the types, and the PHI property they carry. + +``InboundReply.body`` is the partner's reply: PHI, decrypted out of the store. The design rule is +structural — reply-derived bytes never reach an exception, a log call, a ``connection_event.reason`` +or a ``message_events.detail`` — and the redacting ``__repr__`` is what makes the *accidental* case +safe too. A frozen dataclass's default repr would put the body into any log line, traceback or +assertion message that interpolates the object, which is the kind of leak that survives review +because nothing looks wrong at the call site. +""" + +from __future__ import annotations + +from messagefoundry.transports.base import ( + InboundReply, + ReplyOutcome, + SourceConnector, +) + +# A JSON reply carrying an identifier. Chosen deliberately: safe_text is an HL7-shaped redactor, so +# it would NOT scrub this — which is exactly why the rule here is structural rather than a scrub. +PHI_BODY = '{"patient":{"mrn":"100","name":"DOE^JANE"},"status":"accepted"}' + + +def test_repr_never_contains_the_body() -> None: + reply = InboundReply( + outcome=ReplyOutcome.REPLY, + body=PHI_BODY, + content_type="application/json", + destination="OB_PARTNER", + response_seq=1, + waited_ms=42, + ) + text = repr(reply) + for leak in ("100", "DOE", "JANE", "mrn", PHI_BODY): + assert leak not in text, f"{leak!r} reached repr(InboundReply) — this is the PHI leak" + + # ... while everything an operator actually needs is still there. + assert "reply" in text and "OB_PARTNER" in text and "42" in text + assert "redacted" in text + + +def test_repr_survives_an_absent_body() -> None: + # The refusal outcomes carry no body; repr must not blow up mid-log. + assert "0 chars redacted" in repr(InboundReply(outcome=ReplyOutcome.TIMEOUT)) + + +def test_an_f_string_of_the_object_is_safe() -> None: + # The realistic accident: logger.warning("sync reply: %s", reply) or an f-string in an assert. + reply = InboundReply(outcome=ReplyOutcome.REJECTED, body=PHI_BODY, destination="OB_PARTNER") + assert "DOE" not in f"{reply}" + assert "DOE" not in str(reply) + assert "DOE" not in "{}".format(reply) # noqa: UP032 - the point is the format path + + +def test_degraded_is_a_distinct_outcome_from_timeout() -> None: + # The SLO series rate(timeout)/rate(total) IS the proxy API's error budget, so our own store + # errors and rendezvous refusals must never be counted as the partner failing to answer. + assert ReplyOutcome.DEGRADED is not ReplyOutcome.TIMEOUT + assert ReplyOutcome.DEGRADED.value == "degraded" + # Every D5 outcome-table row has exactly one member. + assert {o.value for o in ReplyOutcome} == { + "reply", + "empty", + "rejected", + "failed", + "purged", + "no_route", + "timeout", + "degraded", + "shutting_down", + } + + +def test_the_seam_defaults_to_absent_so_the_202_path_is_unchanged() -> None: + # AC-8: an inbound without reply_from must be byte-identical. The default is what guarantees it. + assert SourceConnector.sync_reply is None + + +def test_the_resolver_takes_only_a_committed_message_id() -> None: + # ACK-on-receipt, enforced structurally rather than by convention: the id does not exist until + # the body is durably committed to the ingress stage, so there is no shape of this call that + # observes an uncommitted message. + import inspect + + from messagefoundry.transports.base import SyncReplyResolver + + args = SyncReplyResolver.__args__ # Callable[[str], Awaitable[InboundReply]] + assert args[0] is str, f"the resolver takes {args[0]!r}, not a message_id" + assert len(args) == 2, "the resolver must take exactly one argument — the committed message_id" + assert inspect.isclass(str)