diff --git a/tests/persona-matrix-mouth-fetch.test.mjs b/tests/persona-matrix-mouth-fetch.test.mjs index c943313..de29c90 100644 --- a/tests/persona-matrix-mouth-fetch.test.mjs +++ b/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); +}); diff --git a/tools/persona-matrix-mouth.mjs b/tools/persona-matrix-mouth.mjs index a069ffe..acd7b77 100644 --- a/tools/persona-matrix-mouth.mjs +++ b/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);