From 311494bd44fd4d75a4ec9273aa29c8de540f1a92 Mon Sep 17 00:00:00 2001 From: Andy Balaam Date: Mon, 6 Nov 2023 09:19:21 +0000 Subject: [PATCH] Ignore receipts pointing at missing or invalid events (#3817) * Ignore receipts pointing at missing or invalid events * Remove extra whitespace from log message * Unit tests for ignoring invalid receipts * Improve comments around getEventReadUpTo * Re-instate second param to compareEventOrdering in test Co-authored-by: Richard van der Hoff <1389908+richvdh@users.noreply.github.com> * Further improve comments around getEventReadUpTo --------- Co-authored-by: Richard van der Hoff <1389908+richvdh@users.noreply.github.com> --- spec/unit/read-receipt.spec.ts | 1 + spec/unit/room.spec.ts | 240 ++++++++++++++++++++++----------- src/models/read-receipt.ts | 126 ++++++++++++++++- 3 files changed, 285 insertions(+), 82 deletions(-) diff --git a/spec/unit/read-receipt.spec.ts b/spec/unit/read-receipt.spec.ts index 953643c8cf9..ea27d515219 100644 --- a/spec/unit/read-receipt.spec.ts +++ b/spec/unit/read-receipt.spec.ts @@ -225,6 +225,7 @@ describe("Read receipt", () => { it("should not allow an older unthreaded receipt to clobber a `main` threaded one", () => { const userId = client.getSafeUserId(); const room = new Room(ROOM_ID, client, userId); + room.findEventById = jest.fn().mockReturnValue({} as MatrixEvent); const unthreadedReceipt: WrappedReceipt = { eventId: "$olderEvent", diff --git a/spec/unit/room.spec.ts b/spec/unit/room.spec.ts index b1db43f5dcd..481ccdcafe0 100644 --- a/spec/unit/room.spec.ts +++ b/spec/unit/room.spec.ts @@ -1746,6 +1746,7 @@ describe("Room", function () { it("should acknowledge if an event has been read", function () { const ts = 13787898424; room.addReceipt(mkReceipt(roomId, [mkRecord(eventToAck.getId()!, "m.read", userB, ts)])); + room.findEventById = jest.fn().mockReturnValue({} as MatrixEvent); expect(room.hasUserReadEvent(userB, eventToAck.getId()!)).toEqual(true); }); it("return false for an unknown event", function () { @@ -3147,106 +3148,195 @@ describe("Room", function () { const client = new TestClient(userA).client; const room = new Room(roomId, client, userA); - it("handles missing receipt type", () => { - room.getReadReceiptForUserId = (userId, ignore, receiptType): WrappedReceipt | null => { - return receiptType === ReceiptType.ReadPrivate ? ({ eventId: "eventId" } as WrappedReceipt) : null; - }; + describe("invalid receipts", () => { + beforeEach(() => { + // Clear the spies on logger.warn + jest.clearAllMocks(); + }); - expect(room.getEventReadUpTo(userA)).toEqual("eventId"); - }); + it("ignores receipts pointing at missing events", () => { + // Given a receipt exists + room.getReadReceiptForUserId = (): WrappedReceipt | null => { + return { eventId: "missingEventId" } as WrappedReceipt; + }; + // But the event ID it contains does not refer to an event we have + room.findEventById = jest.fn().mockReturnValue(null); - describe("prefers newer receipt", () => { - it("should compare correctly using timelines", () => { - room.getReadReceiptForUserId = (userId, ignore, receiptType): WrappedReceipt | null => { - if (receiptType === ReceiptType.ReadPrivate) { - return { eventId: "eventId1" } as WrappedReceipt; - } - if (receiptType === ReceiptType.Read) { - return { eventId: "eventId2" } as WrappedReceipt; - } - return null; + // When we ask what they have read + // Then we say "nothing" + expect(room.getEventReadUpTo(userA)).toBeNull(); + expect(logger.warn).toHaveBeenCalledWith("Ignoring receipt for missing event with id missingEventId"); + }); + + it("ignores receipts pointing at the wrong thread", () => { + // Given a threaded receipt exists + room.getReadReceiptForUserId = (): WrappedReceipt | null => { + return { eventId: "wrongThreadEventId", data: { ts: 0, thread_id: "thread1" } } as WrappedReceipt; }; + // But the event it refers to is in a thread + room.findEventById = jest.fn().mockReturnValue({ threadRootId: "thread2" } as MatrixEvent); + + // When we ask what they have read + // Then we say "nothing" + expect(room.getEventReadUpTo(userA)).toBeNull(); + expect(logger.warn).toHaveBeenCalledWith( + "Ignoring receipt because its thread_id (thread1) disagrees with the thread root (thread2) " + + "of the referenced event (event ID = wrongThreadEventId)", + ); + }); - for (let i = 1; i <= 2; i++) { - room.getUnfilteredTimelineSet = () => - ({ - compareEventOrdering: (event1, event2) => { - return event1 === `eventId${i}` ? 1 : -1; - }, - } as EventTimelineSet); + it("accepts unthreaded receipts pointing at an event in a thread", () => { + // Given an unthreaded receipt exists + room.getReadReceiptForUserId = (): WrappedReceipt | null => { + return { eventId: "inThreadEventId" } as WrappedReceipt; + }; + // And the event it refers to is in a thread + room.findEventById = jest.fn().mockReturnValue({ threadRootId: "thread2" } as MatrixEvent); - expect(room.getEventReadUpTo(userA)).toEqual(`eventId${i}`); - } + // When we ask what they have read + // Then we say the event + expect(room.getEventReadUpTo(userA)).toEqual("inThreadEventId"); }); - describe("correctly compares by timestamp", () => { - it("should correctly compare, if we have all receipts", () => { - for (let i = 1; i <= 2; i++) { - room.getUnfilteredTimelineSet = () => - ({ - compareEventOrdering: (_1, _2) => null, - } as EventTimelineSet); - room.getReadReceiptForUserId = (userId, ignore, receiptType): WrappedReceipt | null => { - if (receiptType === ReceiptType.ReadPrivate) { - return { eventId: "eventId1", data: { ts: i === 1 ? 2 : 1 } } as WrappedReceipt; - } - if (receiptType === ReceiptType.Read) { - return { eventId: "eventId2", data: { ts: i === 2 ? 2 : 1 } } as WrappedReceipt; - } - return null; - }; + it("accepts main thread receipts pointing at an event in main timeline", () => { + // Given a threaded receipt exists, in main thread + room.getReadReceiptForUserId = (): WrappedReceipt | null => { + return { eventId: "mainThreadEventId", data: { ts: 12, thread_id: "main" } } as WrappedReceipt; + }; + // And the event it refers to is in a thread + room.findEventById = jest.fn().mockReturnValue({ threadRootId: undefined } as MatrixEvent); - expect(room.getEventReadUpTo(userA)).toEqual(`eventId${i}`); - } - }); + // When we ask what they have read + // Then we say the event + expect(room.getEventReadUpTo(userA)).toEqual("mainThreadEventId"); + }); - it("should correctly compare, if private read receipt is missing", () => { - room.getUnfilteredTimelineSet = () => - ({ - compareEventOrdering: (_1, _2) => null, - } as EventTimelineSet); - room.getReadReceiptForUserId = (userId, ignore, receiptType): WrappedReceipt | null => { - if (receiptType === ReceiptType.Read) { - return { eventId: "eventId2", data: { ts: 1 } } as WrappedReceipt; - } - return null; - }; + it("accepts main thread receipts pointing at a thread root", () => { + // Given a threaded receipt exists, in main thread + room.getReadReceiptForUserId = (): WrappedReceipt | null => { + return { eventId: "rootId", data: { ts: 12, thread_id: "main" } } as WrappedReceipt; + }; + // And the event it refers to is in a thread, because it is a thread root + room.findEventById = jest + .fn() + .mockReturnValue({ isThreadRoot: true, threadRootId: "thread1" } as MatrixEvent); - expect(room.getEventReadUpTo(userA)).toEqual(`eventId2`); - }); + // When we ask what they have read + // Then we say the event + expect(room.getEventReadUpTo(userA)).toEqual("rootId"); }); + }); - describe("fallback precedence", () => { - beforeAll(() => { - room.getUnfilteredTimelineSet = () => - ({ - compareEventOrdering: (_1, _2) => null, - } as EventTimelineSet); - }); + describe("valid receipts", () => { + beforeEach(() => { + // When we look up the event referred to by the receipt, it exists + room.findEventById = jest.fn().mockReturnValue({} as MatrixEvent); + }); - it("should give precedence to m.read.private", () => { + it("handles missing receipt type", () => { + room.getReadReceiptForUserId = (userId, ignore, receiptType): WrappedReceipt | null => { + return receiptType === ReceiptType.ReadPrivate ? ({ eventId: "eventId" } as WrappedReceipt) : null; + }; + expect(room.getEventReadUpTo(userA)).toEqual("eventId"); + }); + + describe("prefers newer receipt", () => { + it("should compare correctly using timelines", () => { room.getReadReceiptForUserId = (userId, ignore, receiptType): WrappedReceipt | null => { if (receiptType === ReceiptType.ReadPrivate) { - return { eventId: "eventId1", data: { ts: 123 } }; + return { eventId: "eventId1" } as WrappedReceipt; } if (receiptType === ReceiptType.Read) { - return { eventId: "eventId2", data: { ts: 123 } }; + return { eventId: "eventId2" } as WrappedReceipt; } return null; }; - expect(room.getEventReadUpTo(userA)).toEqual(`eventId1`); + for (let i = 1; i <= 2; i++) { + room.getUnfilteredTimelineSet = () => + ({ + compareEventOrdering: (event1: string, _event2: string) => { + return event1 === `eventId${i}` ? 1 : -1; + }, + findEventById: jest.fn().mockReturnValue({} as MatrixEvent), + } as unknown as EventTimelineSet); + + expect(room.getEventReadUpTo(userA)).toEqual(`eventId${i}`); + } }); - it("should give precedence to m.read", () => { - room.getReadReceiptForUserId = (userId, ignore, receiptType): WrappedReceipt | null => { - if (receiptType === ReceiptType.Read) { - return { eventId: "eventId3" } as WrappedReceipt; + describe("correctly compares by timestamp", () => { + it("should correctly compare, if we have all receipts", () => { + for (let i = 1; i <= 2; i++) { + room.getUnfilteredTimelineSet = () => + ({ + compareEventOrdering: () => null, + findEventById: jest.fn().mockReturnValue({} as MatrixEvent), + } as unknown as EventTimelineSet); + room.getReadReceiptForUserId = (userId, ignore, receiptType): WrappedReceipt | null => { + if (receiptType === ReceiptType.ReadPrivate) { + return { eventId: "eventId1", data: { ts: i === 1 ? 2 : 1 } } as WrappedReceipt; + } + if (receiptType === ReceiptType.Read) { + return { eventId: "eventId2", data: { ts: i === 2 ? 2 : 1 } } as WrappedReceipt; + } + return null; + }; + + expect(room.getEventReadUpTo(userA)).toEqual(`eventId${i}`); } - return null; - }; + }); + + it("should correctly compare, if private read receipt is missing", () => { + room.getUnfilteredTimelineSet = () => + ({ + compareEventOrdering: () => null, + findEventById: jest.fn().mockReturnValue({} as MatrixEvent), + } as unknown as EventTimelineSet); + room.getReadReceiptForUserId = (userId, ignore, receiptType): WrappedReceipt | null => { + if (receiptType === ReceiptType.Read) { + return { eventId: "eventId2", data: { ts: 1 } } as WrappedReceipt; + } + return null; + }; + + expect(room.getEventReadUpTo(userA)).toEqual(`eventId2`); + }); + }); - expect(room.getEventReadUpTo(userA)).toEqual(`eventId3`); + describe("fallback precedence", () => { + beforeAll(() => { + room.getUnfilteredTimelineSet = () => + ({ + compareEventOrdering: () => null, + findEventById: jest.fn().mockReturnValue({} as MatrixEvent), + } as unknown as EventTimelineSet); + }); + + it("should give precedence to m.read.private", () => { + room.getReadReceiptForUserId = (userId, ignore, receiptType): WrappedReceipt | null => { + if (receiptType === ReceiptType.ReadPrivate) { + return { eventId: "eventId1", data: { ts: 123 } }; + } + if (receiptType === ReceiptType.Read) { + return { eventId: "eventId2", data: { ts: 123 } }; + } + return null; + }; + + expect(room.getEventReadUpTo(userA)).toEqual(`eventId1`); + }); + + it("should give precedence to m.read", () => { + room.getReadReceiptForUserId = (userId, ignore, receiptType): WrappedReceipt | null => { + if (receiptType === ReceiptType.Read) { + return { eventId: "eventId3" } as WrappedReceipt; + } + return null; + }; + + expect(room.getEventReadUpTo(userA)).toEqual(`eventId3`); + }); }); }); }); diff --git a/src/models/read-receipt.ts b/src/models/read-receipt.ts index 29eb1409a2c..d1c0f10c9c3 100644 --- a/src/models/read-receipt.ts +++ b/src/models/read-receipt.ts @@ -26,6 +26,7 @@ import { EventType } from "../@types/event"; import { EventTimelineSet } from "./event-timeline-set"; import { MapWithDefault } from "../utils"; import { NotificationCountType } from "./room"; +import { logger } from "../logger"; export function synthesizeReceipt(userId: string, event: MatrixEvent, receiptType: ReceiptType): MatrixEvent { return new MatrixEvent({ @@ -94,15 +95,119 @@ export abstract class ReadReceipt< } /** - * Get the ID of the event that a given user has read up to, or null if we - * have received no read receipts from them. + * Get the ID of the event that a given user has read up to, or null if: + * - we have received no read receipts for them, or + * - the receipt we have points at an event we don't have, or + * - the thread ID in the receipt does not match the thread root of the + * referenced event. + * + * (The event might not exist if it is not loaded, and the thread ID might + * not match if the event has moved thread because it was redacted.) + * * @param userId - The user ID to get read receipt event ID for * @param ignoreSynthesized - If true, return only receipts that have been - * sent by the server, not implicit ones generated - * by the JS SDK. - * @returns ID of the latest event that the given user has read, or null. + * sent by the server, not implicit ones generated + * by the JS SDK. + * @returns ID of the latest existing event that the given user has read, or null. */ public getEventReadUpTo(userId: string, ignoreSynthesized = false): string | null { + // Find what the latest receipt says is the latest event we have read + const latestReceipt = this.getLatestReceipt(userId, ignoreSynthesized); + + if (!latestReceipt) { + return null; + } + + return this.receiptPointsAtConsistentEvent(latestReceipt) ? latestReceipt.eventId : null; + } + + /** + * Returns true if the event pointed at by this receipt exists, and its + * threadRootId is consistent with the thread information in the receipt. + */ + private receiptPointsAtConsistentEvent(receipt: WrappedReceipt): boolean { + const event = this.findEventById(receipt.eventId); + if (!event) { + // If the receipt points at a non-existent event, we have multiple + // possibilities: + // + // 1. We don't have the event because it's not loaded yet - probably + // it's old and we're best off ignoring the receipt - we can just + // send a new one when we read a new event. + // + // 2. We have a bug e.g. we misclassified this event into the wrong + // thread. + // + // 3. The referenced event moved out of this thread (e.g. because it + // was deleted.) + // + // 4. The receipt had the incorrect thread ID (due to a bug in a + // client, or malicious behaviour). + logger.warn(`Ignoring receipt for missing event with id ${receipt.eventId}`); + + // This receipt is not "valid" because it doesn't point at an event + // we have. We want to pretend it doesn't exist. + return false; + } + + if (!receipt.data?.thread_id) { + // If this is an unthreaded receipt, it could point at any event, so + // there is no need to validate further - this receipt is valid. + return true; + } + // Otherwise it is a threaded receipt... + + if (receipt.data.thread_id === MAIN_ROOM_TIMELINE) { + // The receipt is for the main timeline: we check that the event is + // in the main timeline. + + // There are two ways to know an event is in the main timeline: + // either it has no threadRootId, or it is a thread root. + // (Note: it's a little odd because the thread root is in the main + // timeline, but it still has a threadRootId.) + const eventIsInMainTimeline = !event.threadRootId || event.isThreadRoot; + + if (eventIsInMainTimeline) { + // The receipt is for the main timeline, and so is the event, so + // the receipt is valid. + return true; + } + } else { + // The receipt is for a different thread (not the main timeline) + + if (event.threadRootId === receipt.data.thread_id) { + // If the receipt and event agree on the thread ID, the receipt + // is valid. + return true; + } + } + + // The receipt thread ID disagrees with the event thread ID. There are 2 + // possibilities: + // + // 1. The event moved to a different thread after the receipt was + // created. This can happen if the event was redacted because that + // moves it to the main timeline. + // + // 2. There is a bug somewhere - either we put the event into the wrong + // thread, or someone sent an incorrect receipt. + // + // In many cases, we won't get here because the call to findEventById + // would have already returned null. We include this check to cover + // cases when `this` is a room, meaning findEventById will find events + // in any thread, and to be defensive against unforeseen code paths. + logger.warn( + `Ignoring receipt because its thread_id (${receipt.data.thread_id}) disagrees ` + + `with the thread root (${event.threadRootId}) of the referenced event ` + + `(event ID = ${receipt.eventId})`, + ); + + // This receipt is not "valid" because it disagrees with us about what + // thread the event is in. We want to pretend it doesn't exist. + return false; + } + + private getLatestReceipt(userId: string, ignoreSynthesized: boolean): WrappedReceipt | null { // XXX: This is very very ugly and I hope I won't have to ever add a new // receipt type here again. IMHO this should be done by the server in // some more intelligent manner or the client should just use timestamps @@ -118,10 +223,10 @@ export abstract class ReadReceipt< // The public receipt is more likely to drift out of date so the private // one has precedence - if (!comparison) return privateReadReceipt?.eventId ?? publicReadReceipt?.eventId ?? null; + if (!comparison) return privateReadReceipt ?? publicReadReceipt ?? null; // If public read receipt is older, return the private one - return (comparison < 0 ? privateReadReceipt?.eventId : publicReadReceipt?.eventId) ?? null; + return (comparison < 0 ? privateReadReceipt : publicReadReceipt) ?? null; } public addReceiptToStructure( @@ -229,6 +334,13 @@ export abstract class ReadReceipt< public abstract setUnread(type: NotificationCountType, count: number): void; + /** + * Look in this room/thread's timeline to find an event. If `this` is a + * room, we look in all threads, but if `this` is a thread, we look only + * inside this thread. + */ + public abstract findEventById(eventId: string): MatrixEvent | undefined; + /** * This issue should also be addressed on synapse's side and is tracked as part * of https://github.com/matrix-org/synapse/issues/14837