Skip to content

Commit 988f5df

Browse files
authored
fix(tsp): say why an inbound frame was not claimed as a reply (#136)
The claim predicate added with the TSP inbound work returned `false` for every failure mode without recording any of them. On a shared socket that is right in principle — a frame from another peer is not this request's problem — but it made the one case that *is* a problem indistinguishable from silence: when the VTA's reply is declined, the request waits out its full timeout and reports `timed out awaiting reply frame`, with no record anywhere that a frame arrived at all, let alone why it was rejected. That is a regression in diagnosability against the code it replaced, which threw a typed error naming the sender mismatch or the parse failure. The predicate is the only thing in the path that knows; if it does not report, by construction nothing downstream can. It now records the reason for the most recent decline — unpack failure, sender mismatch, unparseable payload, or a `threadId` that does not thread to this request (naming both values, plus the reply's own type and id) — and attaches it to the error the caller sees when the wait ends. The frame is still declined in exactly the same cases; only the silence is removed. Signed-off-by: Glenn Gore <glenn.g@affinidi.com>
1 parent 4f4f5f5 commit 988f5df

1 file changed

Lines changed: 48 additions & 12 deletions

File tree

‎packages/core/src/vta/tsp-channel.ts‎

Lines changed: 48 additions & 12 deletions
Original file line numberDiff line numberDiff line change
@@ -196,6 +196,12 @@ export class TspChannel implements TrustTaskChannel {
196196
// *proven* to come from that VTA, and (c) threads to this request is our
197197
// reply. Anything else — most importantly an executor-initiated push
198198
// landing mid-request — is left for the next waiter or the inbox.
199+
// Why the last frame was declined, so a request that times out can say what
200+
// it saw instead of only that it waited. Declining silently is what turned
201+
// a correlation mismatch into a 30s hang with no reason anywhere — the
202+
// predicate has to report, because by design nothing downstream can.
203+
let lastDecline: string | undefined;
204+
199205
const claims: TspFrameClaim = async (bytes) => {
200206
let reply;
201207
try {
@@ -204,29 +210,59 @@ export class TspChannel implements TrustTaskChannel {
204210
senderEncryptionKey: this.vta.encryptionPublicKey,
205211
senderSigningKey: this.vta.signingPublicKey,
206212
});
207-
} catch {
208-
// Not unpackable under these keys, so not ours. Not an error: another
209-
// waiter's peer, or an inbound from someone else entirely.
213+
} catch (err) {
214+
// Not unpackable under these keys, so not ours. Expected on a shared
215+
// socket — another peer's frame — but recorded, because "nothing I can
216+
// read arrived" and "the VTA answered something I did not expect" are
217+
// very different problems and they look identical from the timeout.
218+
lastDecline = `unpack failed: ${(err as Error).message}`;
219+
return false;
220+
}
221+
if (reply.sender !== this.vta.vid) {
222+
lastDecline = `sealed by ${reply.sender}, not the VTA ${this.vta.vid}`;
210223
return false;
211224
}
212-
if (reply.sender !== this.vta.vid) return false;
213-
let doc: { type?: string; payload?: unknown; threadId?: unknown };
225+
let doc: { type?: string; id?: unknown; payload?: unknown; threadId?: unknown };
214226
try {
215227
doc = JSON.parse(fromUtf8.decode(reply.payload)) as typeof doc;
216-
} catch {
228+
} catch (err) {
229+
lastDecline = `payload not JSON: ${(err as Error).message}`;
217230
return false;
218231
}
219232
// `threadId` on a response is the request's `threadId` or, as here, its
220-
// `id` — the same `thid ?? id` rule DIDComm correlates on.
221-
if (doc.threadId !== envelope.id) return false;
233+
// `id` — the same `thid ?? id` rule DIDComm correlates on, and what the
234+
// framework's `respond_with` sets.
235+
if (doc.threadId !== envelope.id) {
236+
lastDecline =
237+
`threadId ${JSON.stringify(doc.threadId)} != request id ` +
238+
`${JSON.stringify(envelope.id)} (reply type ${JSON.stringify(doc.type)}, ` +
239+
`reply id ${JSON.stringify(doc.id)})`;
240+
return false;
241+
}
222242
claimedDoc = doc;
223243
return true;
224244
};
225245

226-
await this.transport.sendAndAwaitReply(packed.bytes, {
227-
timeoutMs: opts.timeoutMs ?? this.timeoutMs,
228-
claims,
229-
});
246+
try {
247+
await this.transport.sendAndAwaitReply(packed.bytes, {
248+
timeoutMs: opts.timeoutMs ?? this.timeoutMs,
249+
claims,
250+
});
251+
} catch (err) {
252+
// A timeout here almost always means a frame *did* arrive and was
253+
// declined. Say which, on the error the caller actually sees: without it
254+
// the only evidence is a silent 30s wait, and the difference between
255+
// "the VTA never answered" and "it answered something I did not
256+
// recognise" is the whole diagnosis.
257+
if (lastDecline) {
258+
throw new VtaClientError(
259+
(err as VtaClientError).code ?? "e.client.network",
260+
`${(err as Error).message} — last inbound frame declined: ${lastDecline}`,
261+
{ details: { lastDecline } },
262+
);
263+
}
264+
throw err;
265+
}
230266

231267
// `claims` returned true, so it parsed the document; the transport cannot
232268
// resolve without one having claimed. Defensive only.

0 commit comments

Comments
 (0)