Skip to content

feat(inbound): log every message that arrives, and on which inbox - #105

Merged
stormer78 merged 1 commit into
mainfrom
feat/log-inbound-messages
Aug 4, 2026
Merged

feat(inbound): log every message that arrives, and on which inbox#105
stormer78 merged 1 commit into
mainfrom
feat/log-inbound-messages

Conversation

@stormer78

Copy link
Copy Markdown
Contributor

Two inboxes run in parallel — the worker (authenticated as the VTA DID) and the approver (a distinct did:key) — and the mediator routes inbound by the authenticating DID. Nothing logged an arrival on either.

So a message delivered to the wrong inbox and a message never sent at all produced identical console output: none.

Why

Chasing a live "the approver is never prompted" report came down to proving a negative inside the extension while the sender's logs insisted it had pushed correctly. The console could not distinguish "nothing arrived" from "arrived and was mishandled", and that ambiguity took several rounds of cross-service log comparison to resolve.

What changed

type, id, from and to are logged at the top of onInboundMessage, before anything can drop the message, tagged with which inbox received it.

to is the field that earns its place: a task-consent/request/0.1 is addressed to the approver DID, so one landing on the worker inbox is a routing bug — and was previously indistinguishable from a message that never existed.

Logging only. No behaviour change.

Follow-up, deliberately not in this PR

The plugin never queries the mediator queue: it enables live delivery via the library and sees only what arrives while connected. There is no status-request / delivery-request path, so a backlog queued before connect is never fetched.

Draining it properly is larger than it first appears. Per mediator-transport.js, live delivery pushes bare inner JWEs as raw text frames — the mediator "does NOT re-wrap it in a forward". A delivery-request instead replies with a pickup/3.0/delivery envelope carrying attachments, a shape the transport never unwraps. So it needs: the resolved mediator endpoint surfaced on MediatorConnection, requestStatus/requestDelivery on MediatorClient, attachment unwrapping, then feed-through to onInboundMessage and ack via messages-received.

The ordering there is load-bearing and is why this is not being rushed: pending.ts documents that a task-consent/request lost between delivery and durable storage is unrecoverable — the challenge and payloadDigest are gone, and the executor waits for a decision that can never arrive. Ack-before-store loses messages silently.

Expiry for that drain has to be read from the payload, not the transport: neither DIDComm (expires_time deliberately unset) nor TSP (no expiry field at all) carries one here, so task-consent/request/0.1's own expiresAt is the only source. An expired request should be acked and dropped without prompting — showing a code for a request the executor has already forgotten would fail as no_pending and train the operator to approve whatever appears.

Two inboxes run in parallel -- the worker (authenticated as the VTA DID)
and the approver (a distinct did:key) -- and the mediator routes inbound
by the authenticating DID. Nothing logged an arrival on either, so a
message delivered to the wrong inbox and a message never sent at all
produced identical console output: none.

That ambiguity cost real time. Chasing "the approver is never prompted"
came down to proving a negative in the extension while the sender
insisted it had pushed correctly; the console could not distinguish
"nothing arrived" from "arrived and was mishandled".

Log type, id, from and to at the top of the handler, before anything can
drop the message, tagged with which inbox received it. `to` is the field
that matters: a task-consent/request is addressed to the approver DID, so
seeing one land on the worker inbox is a routing bug rather than a
missing message -- previously indistinguishable.

Logging only; no behaviour change.

Signed-off-by: Glenn Gore <glenn.g@affinidi.com>
@stormer78
stormer78 merged commit 8a82a4d into main Aug 4, 2026
3 checks passed
@stormer78
stormer78 deleted the feat/log-inbound-messages branch August 4, 2026 08:52
stormer78 added a commit that referenced this pull request Aug 7, 2026
)

parseTaskConsentRequest returned "not-a-task-consent-request" for two
completely different situations: a message not addressed to this handler,
and a genuine consent request whose payload is unusable.

dispatchInbound keys on that reason to decide whether to stay quiet:

    if (consent.reason !== "not-a-task-consent-request") { warn; return; }
    // Anything else is ignored.   <- silent

So a malformed consent request was discarded in total silence -- no
prompt, no log -- and handleInbound's finally then cleared its pending
record. The result is indistinguishable from a message that never
arrived, which is how it presented: arrival logged by #105, then nothing
at all, and a pending-approval badge (#110) that counted zero because the
record was already gone.

Malformed payloads now return "malformed-payload", so the existing warn
path reports them with their detail. The silent reason keeps its single
honest meaning: not addressed to this handler.

The test that pinned the old shared reason now pins the distinction and
the detail, with the reasoning recorded -- it was asserting the exact
behaviour that hid this.

Signed-off-by: Glenn Gore <glenn.g@affinidi.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant