Skip to content
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions changelog.d/19838.bugfix
Original file line number Diff line number Diff line change
@@ -0,0 +1 @@
Fix a bug where a threaded read receipt could incorrectly win over a clashing unthreaded one (MSC4102) when the two were served in separate `/sync` responses, e.g. when received over federation as separate EDUs.

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

How did you reproduce the TestThreadReceiptsInSyncMSC4102 failure locally? Or did the LLM just spot what was wrong based on the test flake output from CI?

I struggled: #19171

Copy link
Copy Markdown
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This was a case of throwing LLM at the logs of a flakey run. What it spit out made sense and seemed to match what was happening, and the suggested fix (this) made sense in the context of what we were doing when reading as well.

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Per my points in matrix-org/complement#881, I think this may be missing the mark on the behavior of MSC4102

Copy link
Copy Markdown
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

How so? We want to make sure that when combining receipts for the same event ID we want the unthreaded to win? MSC4102 does only talk about EDUs, but I think the idea is still that you want unthreaded to win everywhere?

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

but I think the idea is still that you want unthreaded to win everywhere?

I don't think there is any spec for this.

We want to record all of the read receipts and only deduplicate if there are conflicting read receipts when creating m.receipt EDU's. We seem to already be doing this.

And to better clarify and exaggerate why this is fine, it's okay to send and receive a threaded read receipt for the same event two hours after the unthreaded read receipt. See MSC3771 which explains,

This MSC proposes allowing the same receipt type to exist multiple times in a room per user:

  • Once for the unthreaded timeline.
  • Once for the main timeline in the room.
  • Once per threaded timeline.

And the only restriction is that "this still does not allow a caller to move their receipts backwards in a room"


If this breakdown is to be believed, the bug appears to be in the following behavior especially "The unthreaded receipt was never surfaced" part. Why is /sync advancing past its persisted position?

  1. Alice sends an unthreaded receipt for event B, then a threaded receipt for the same event B. Both are federated to hs2 as two separate m.receipt EDUs and persisted there at receipts stream positions 2 (unthreaded) and 3
    (threaded).
  2. Bob's initial sync advanced its receipt token to 2 but emitted no receipt; his next (incremental) sync window was (2,3], containing only the threaded receipt.
  3. The unthreaded receipt was never surfaced, so the threaded one "won" → MSC4102 violation → timeout.

86 changes: 60 additions & 26 deletions synapse/storage/databases/main/receipts.py
Original file line number Diff line number Diff line change
Expand Up @@ -907,36 +907,70 @@ def _insert_linearized_receipt_txn(
stream_ordering = int(res[0]) if res else None
rx_ts = res[1] if res else 0

# We don't want to clobber receipts for more recent events, so we
# have to compare orderings of existing receipts
# We don't want to clobber receipts for more recent events, so we have
# to compare orderings of existing receipts.
#
# We fetch the user's existing receipts for this room and receipt type
# (including both threaded and unthreaded receipts) in a single query:
# every receipt whose event ordering we know (for the same-thread
# comparison below), plus the unthreaded receipt for *this* event even
# if we don't know its ordering (for the MSC4102 check below).
if stream_ordering is not None:
if thread_id is None:
thread_clause = "r.thread_id IS NULL"
thread_args: tuple[str, ...] = ()
else:
thread_clause = "r.thread_id = ?"
thread_args = (thread_id,)

# If the receipt doesn't have a stream ordering it is because we
# don't have the associated event, and so must be a remote receipt.
# Hence it's safe to just allow new receipts to clobber it.
sql = f"""
SELECT r.event_stream_ordering, r.event_id FROM receipts_linearized AS r
sql = """
SELECT r.event_stream_ordering, r.event_id, r.thread_id
FROM receipts_linearized AS r
WHERE r.room_id = ? AND r.receipt_type = ? AND r.user_id = ?
AND r.event_stream_ordering IS NOT NULL AND {thread_clause}
"""
txn.execute(
sql,
(
room_id,
receipt_type,
user_id,
)
+ thread_args,
AND (
r.event_stream_ordering IS NOT NULL
OR (r.thread_id IS NULL AND r.event_id = ?)
)
"""
txn.execute(sql, (room_id, receipt_type, user_id, event_id))

for so, eid, existing_thread_id in txn:
# MSC4102: an unthreaded receipt always supersedes a threaded
# one for the *same* event. If we are inserting a threaded
# receipt but already have an unthreaded receipt for this user
# at the same event, then the threaded receipt is semantically
# meaningless, so we drop it rather than persisting it.
#
# We match on event id (mirroring the read-time dedup in
# `ReceiptInRoom.merge_to_content`) rather than on ordering, so
# this also covers a remote unthreaded receipt whose event we
# hadn't seen when it arrived (and so has a NULL
# event_stream_ordering).
#
# Doing this at insert time, as well as when serving receipts,
# makes the "prefer unthreaded" behaviour durable: otherwise the
# threaded receipt could be served on its own in a later /sync
# response (e.g. when the unthreaded and threaded receipts
# arrive in separate federation EDUs and so end up at different
# stream positions), causing the client to incorrectly see it
# win.
Comment on lines +943 to +949

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Can we drop the /sync behavior in favor the insert solution we have here?

Perhaps instead an assert at the /sync level.

Copy link
Copy Markdown
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Mmm, possibly. We wouldn't want to do it immediately to handle existing receipts in the DB.

if (
thread_id is not None
and existing_thread_id is None
and eid == event_id
):
logger.debug(
"Ignoring threaded receipt for %s in favour of "
"existing unthreaded receipt",
event_id,
)
return None

# The remaining check compares stream orderings, so skip
# receipts for older events, and remote receipts whose event we
# don't have (NULL ordering). It's safe to clobber events with
# NULL ordering as they are pointing at unknown events that we
# haven't seen (and are likely from before we joined the room).
if so is None or int(so) < stream_ordering:
continue

Comment thread
erikjohnston marked this conversation as resolved.
for so, eid in txn:
if int(so) >= stream_ordering:
# Don't clobber a receipt for a more recent event in the same
# thread. (When inserting an unthreaded receipt, thread_id is
# None and this matches the existing unthreaded receipt.)
if existing_thread_id == thread_id:
logger.debug(
"Ignoring new receipt for %s in favour of existing "
"one for later event %s",
Expand Down
78 changes: 78 additions & 0 deletions tests/storage/test_receipts.py
Original file line number Diff line number Diff line change
Expand Up @@ -237,6 +237,84 @@ def test_get_receipts_for_user(self) -> None:
)
self.assertEqual(res, {self.room_id1: event1_2_id, self.room_id2: event2_1_id})

def test_threaded_receipt_dropped_when_unthreaded_exists(self) -> None:

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Seems like the TestThreadReceiptsInSyncMSC4102 Complement test should also be updated to better separate read receipts across EDU's so it can consistently stress the failure case. Or could be an additional new test that does that (engineered homeserver)

Copy link
Copy Markdown
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Have updated it in matrix-org/complement#881

"""MSC4102: a threaded receipt that clashes with an existing unthreaded
receipt *for the same event* should be dropped at insert time, so the
unthreaded receipt durably wins regardless of how the receipts are
later served down /sync. A threaded receipt for a *different* event is
not a clash and is kept (matching the read-time dedup in
`ReceiptInRoom.merge_to_content`, which keys off event id).

Regression test for the Complement test TestThreadReceiptsInSyncMSC4102,
which flaked because the read-time dedup alone doesn't survive the
receipts being served in separate /sync responses.
"""
event1_id = self.create_and_send_event(
self.room_id1, UserID.from_string(OTHER_USER_ID)
)
# A second event. event1 is used as the thread-root id for the
# threaded receipts below; storage doesn't check thread membership.
event2_id = self.create_and_send_event(
self.room_id1, UserID.from_string(OTHER_USER_ID)
)

# Insert an unthreaded receipt for the second event.
pos = self.get_success(
self.store.insert_receipt(
room_id=self.room_id1,
receipt_type=ReceiptTypes.READ,
user_id=OUR_USER_ID,
event_ids=[event2_id],
thread_id=None,
data={},
)
)
self.assertIsNotNone(pos)

# A threaded receipt that clashes with it (same event) should be
# dropped.
pos = self.get_success(
self.store.insert_receipt(
room_id=self.room_id1,
receipt_type=ReceiptTypes.READ,
user_id=OUR_USER_ID,
event_ids=[event2_id],
thread_id=event1_id,
data={},
)
)
self.assertIsNone(pos)

# A threaded receipt for a *different* event is not a clash, so it is
# kept.
pos = self.get_success(
self.store.insert_receipt(
room_id=self.room_id1,
receipt_type=ReceiptTypes.READ,
user_id=OUR_USER_ID,
event_ids=[event1_id],
thread_id=event1_id,
data={},
)
)
self.assertIsNotNone(pos)

# The unthreaded receipt at event2 wins (no thread_id), and the
# non-clashing threaded receipt at event1 is retained.
to_key = self.store.get_max_receipt_stream_id()
receipts = self.get_success(
self.store.get_linearized_receipts_for_rooms([self.room_id1], to_key=to_key)
)
content = receipts[0]["content"]
self.assertEqual(set(content.keys()), {event1_id, event2_id})
self.assertNotIn(
"thread_id", content[event2_id][ReceiptTypes.READ][OUR_USER_ID]
)
self.assertEqual(
content[event1_id][ReceiptTypes.READ][OUR_USER_ID]["thread_id"],
event1_id,
)

def test_get_last_receipt_event_id_for_user(self) -> None:
# Send some events into the first room
event1_1_id = self.create_and_send_event(
Expand Down
Loading