Mouth: fetch failures log fixed words only; pin deadline signal, redacted clause, pre-PUT abort; receipt names the resolved event

The fetch-error and file-receipt-not-proven lines are gone: a failure folds into the one fetch line as cause=Class/status, never a message.

Co-Authored-By: Claude Sonnet 5.5 <noreply@anthropic.com>

tests/persona-matrix-mouth-fetch.test.mjs

@@ -577,3 +577,71 @@ test("images.put has exactly two call sites in the mouth and the fetch's comes a
   assert.ok(!/media\/download/.test(source), "no media GET outside fetchImage");
   assert.equal([...source.matchAll(/\/state\/(m\.|uk\.)|event_type=/g)].length, 0);
 });
+
+test("the receipt names the event the GET resolved: reference and content.event_id both carry the returned id, in a thread file and a plain one", async () => {
+  const answered = { type: "m.room.message", event_id: "$resolved", room_id: ROOM, sender: OTHER };
+  const plain = synapse({ events: { [FILE]: { ...answered, content: plainFile(undefined)[FILE].content } } });
+  assert.equal((await mouthOn(plain).ask({ room: ROOM })).receipt, "Posted");
+  const [event] = plain.receipts();
+  assert.equal(event.content["m.relates_to"].event_id, "$resolved");
+  assert.equal(event.content[docs.fileReceivedType].event_id, "$resolved");
+  const threaded = synapse({ events: { [FILE]: { ...answered, content: fileContent() } } });
+  await mouthOn(threaded).ask({ room: ROOM });
+  assert.equal(threaded.receipts()[0].content[docs.fileReceivedType].event_id, "$resolved");
+  const bad = synapse({ events: { [FILE]: { ...answered, event_id: "$a/../b", content: fileContent() } } });
+  assert.equal((await mouthOn(bad).ask({ room: ROOM })).outcome, "NoAttachment");
+  assert.equal(bad.receipts().length, 0);
+});
+
+test("a failure leaves the log as fixed words: a transport error holding a URL, an mxc and a sender-chosen 200-byte album root reaches no line", async () => {
+  const root = `$${"r".repeat(199)}`;
+  const taint = `http://hs.test/_matrix/client/v3/joined_rooms mxc://gamecult.org/abc ${root} Bearer ${TOKEN}`;
+  for (const [pattern, expectFetch] of [[/GET \/rooms\/[^/]+\/relations\//, "Stored"], [/GET \/rooms\/[^/]+\/state$/, "FetchFailed"], [/PUT \/rooms\/[^/]+\/send\//, "Stored"]]) {
+    const s = synapse({ events: { [FILE]: { type: "m.room.message", event_id: FILE, room_id: ROOM, sender: OTHER, content: fileContent({ "m.relates_to": { rel_type: "m.thread", event_id: root } }) } } });
+    const real = s.fetch;
+    s.fetch = async (url, init = {}) => {
+      if (pattern.test(`${init.method ?? "GET"} ${decodeURIComponent(new URL(url).pathname).replace(/^\/_matrix\/client\/v[13]/, "")}`)) throw new Error(`fetch failed ${taint}`);
+      return real(url, init);
+    };
+    const m = mouthOn(s);
+    assert.equal((await m.ask({ room: ROOM })).outcome, expectFetch, String(pattern));
+    assert.equal(m.fetchLines().length, 1, "still one fetch line");
+    for (const line of m.logs) {
+      for (const bit of ["http", "mxc", root, "r".repeat(40), TOKEN, "unreachable"]) assert.ok(!line.includes(bit), `${bit} in: ${line.slice(0, 120)}`);
+    }
+    assert.match(m.fetchLines()[0], / cause=Error\/-$/);
+  }
+  const status = synapse();
+  status.failing = { "/relations/": 500 };
+  const m = mouthOn(status);
+  await m.ask();
+  assert.match(m.fetchLines()[0], /receipt=failed cause=Error\/500$/);
+});
+
+test("the deadline aborts the in-flight media GET: the room gate is free again at once, not after the media timeout", async () => {
+  const s = synapse({ holds: [{ match: /media\/download/ }] });
+  const gate = createRoomGate();
+  const m = mouthOn(s, { gate, deadline: 100 });
+  assert.equal((await m.ask({ room: ROOM })).outcome, "FetchFailed");
+  const freed = await Promise.race([gate.run(ROOM, async () => "free"), new Promise(r => setTimeout(() => r("held"), 300))]);
+  assert.equal(freed, "free");
+  assert.equal(m.puts.length, 0);
+});
+
+test("a redacted receipt does not count as hers even when its content is intact", async () => {
+  const s = synapse();
+  s.relations.set(`${ROOT}|m.thread`, [[{ type: docs.fileReceivedType, sender: ME, unsigned: { redacted_because: {} }, content: { [docs.fileReceivedType]: { event_id: FILE } } }]]);
+  assert.equal((await mouthOn(s).ask({ room: ROOM })).receipt, "Posted");
+  assert.equal(s.receipts().length, 1);
+});
+
+test("a deadline that passes while the brake is re-read before the receipt PUT sends nothing", async () => {
+  const s = synapse();
+  let reads = 0, free;
+  const m = mouthOn(s, { deadline: 150, brake: async () => (++reads === 3 ? new Promise(ok => { free = () => ok(true); }) : true) });
+  assert.equal((await m.ask({ room: ROOM })).outcome, "FetchFailed");
+  free();
+  await new Promise(r => setTimeout(r, 30));
+  assert.equal(s.calls.filter(c => c.startsWith("PUT")).length, 0);
+  assert.equal(m.puts.length, 1);
+});

tools/persona-matrix-mouth.mjs

@@ -770,8 +770,8 @@ export function createMouth({
     const seen = { room: "-", event: "-", size: "-", type: "-", sha256: "-" };
     const idOr = (sigil, v) => docs.isFetchId(sigil, v) ? v : "-"; // a hostile id never reaches the log
     let answered = false; // one log line per fetch: a gate step that finishes after the deadline answered is silent
-    const done = (outcome, { image = null, roomId = null, receipt = null, logged = "skipped" } = {}) => {
-      if (!answered) say(`fetch persona=${persona} room=${seen.room} event=${seen.event} outcome=${outcome} size=${seen.size} type=${seen.type} sha256=${seen.sha256} receipt=${logged}`);
+    const done = (outcome, { image = null, roomId = null, receipt = null, logged = "skipped", cause = null } = {}) => {
+      if (!answered) say(`fetch persona=${persona} room=${seen.room} event=${seen.event} outcome=${outcome} size=${seen.size} type=${seen.type} sha256=${seen.sha256} receipt=${logged}${cause === null ? "" : ` cause=${cause}`}`);
       answered = true;
       return { requestId, outcome, roomId, image, receipt };
     };
@@ -811,6 +811,7 @@ export function createMouth({
           throw error;
         }
         if (event?.room_id !== roomId) return done("NotAMember");
+        if (!docs.isFetchId("$", event.event_id)) return done("NoAttachment"); // the receipt names the event the homeserver returned, not the one asked for
         if (platformEvent(event)) return done("BridgedRoom");
         const content = event.content;
         if (event.type === "m.room.encrypted") return done("TypeRefused");
@@ -839,12 +840,11 @@ export function createMouth({
         }
         stored = true;
         if (!claimed) return done("StoredUnverified", { image, roomId });
-        const { receipt, word } = await postFileReceipt(roomId, albumRoot, eventId, computed, got.bytes.length, deadline);
-        return done("Stored", { image, roomId, receipt, logged: word });
+        const { receipt, word, cause } = await postFileReceipt(roomId, albumRoot, event.event_id, computed, got.bytes.length, deadline);
+        return done("Stored", { image, roomId, receipt, logged: word, cause });
       }));
     } catch (error) {
-      say(`fetch-error ${error?.message ?? error}`); // a diagnostic, not the fetch line
-      return done("FetchFailed", { logged: stored ? "failed" : "skipped" });
+      return done("FetchFailed", { logged: stored ? "failed" : "skipped", cause: causeOf(error) });
     }
   }
 
@@ -853,7 +853,7 @@ export function createMouth({
   // read or a PUT that fails, a held brake, proves nothing and posts nothing: the file stays stored and the receipt is nil. A deadline
   // is not such a failure and leaves the caller (it throws).
   async function postFileReceipt(roomId, albumRoot, fileEventId, sha256, size, deadline) {
-    const none = word => ({ receipt: null, word });
+    const none = (word, cause = null) => ({ receipt: null, word, cause });
     try {
       const room = encodeURIComponent(roomId);
       const [target, relation] = albumRoot === null ? [fileEventId, "m.reference"] : [albumRoot, "m.thread"];
@@ -873,8 +873,7 @@ export function createMouth({
       return { receipt: "Posted", word: "posted" };
     } catch (error) {
       if (deadline.aborted) throw error;
-      say(`file receipt not proven: ${error?.message ?? error}`);
-      return none("failed");
+      return none("failed", causeOf(error));
     }
   }
 
@@ -894,6 +893,11 @@ export function createMouth({
   return { start, syncOnce, ack, read, pendingAfter, tail, speakableRooms, send, openDirect, fetchAttachment, run, get userId() { return selfId; }, get pendingCount() { return pending.length; } };
 }
 
+// The log's word for a failure: error class and HTTP status only, never the message (it can hold a URL, an mxc or a sender-chosen id).
+function causeOf(error) {
+  return `${/^[A-Za-z]{1,32}$/.test(error?.name) ? error.name : "Error"}/${Number.isInteger(error?.status) ? error.status : "-"}`;
+}
+
 // Replace every secret in a message. `secrets` is one string or a list.
 export function redact(message, secrets) {
   let out = String(message);