Read receipts sent in worker mode have incorrect timestamp data

[turt2live]

See also: element-hq/element-web#9211

When using worker mode with develop (ie: matrix.org), read receipts sent by the federation sender have the wrong data: instead of an object, it is sending a string which ends up looking like this:

"@turt2live:matrix.org": "{\"ts\": 1553059870117}"

I believe the issue stems from get_all_updated_receipts in storage/receipts.py which returns the data as a string, not as an object. This gets passed along to the ReceiptsStream because of the update_function, which then goes through the serialization normally to be sent as RDATA to the federation sender.

The federation sender then sees a row which looks like this (different homeserver):

[(1450, ReceiptsStreamRow(room_id='!lEvyBPwjuIKeUKTXlQ:dev.t2host.io', receipt_type='m.read', user_id='@aslidyhasukdg:dev.t2host.io', event_id='$1553062163148103bSYiG:matrix.org', data='{"ts": 1553062166607}'))]

As shown, the data is a string, which then goes through the JSON serialization and off to remote servers which happily consume and store this:

synapse=# select stream_id, room_id, receipt_type, user_id, event_id, data from receipts_linearized where user_id = '@turt2live:matrix.org' order by stream_id desc limit 1;
 stream_id |              room_id              | receipt_type |        user_id        |             event_id              |           data
-----------+-----------------------------------+--------------+-----------------------+-----------------------------------+---------------------------
      1446 | !lEvyBPwjuIKeUKTXlQ:dev.t2host.io | m.read       | @turt2live:matrix.org | $1553059866145EthFl:dev.t2host.io | "{\"ts\": 1553059870117}"
(1 row)

Opening this issue because I'm not really clear on what the fix would be: Having get_all_updated_receipts return a real object sounds right, but I'm not sure what would then happen to the pusherpool.py thing, if anything.

[richvdh]

fixed by #4927

[BrainBlasted]

Did this fix land in 0.99.3? The homeserver I use is on 0.99.3 but this is still occurring.

fractal_matrix_api::model::room: Value of timestamp 'ts': "{\"ts\": 1553066255912}"
fractal_matrix_api::model::room: Working around synapse bug 4898

[turt2live]

It looks like it was supposed to be, is the homeserver sending the invalid read receipt on 0.99.3 or just the receiving end?

[BrainBlasted]

It's still sending the invalid receipt.

[richvdh]

@BrainBlasted sending it where? To other servers, or just to your client?

As a user of a 0.99.3 server, you might still see receipts sent by users on other (pre-0.99.3) servers, which your server will forward on to your client. If this is the case, can you see which servers the invalid receipts are coming from? Given that, afaik, this bug was only present in 0.99.2 and only affected synapses deployed in worker-mode, it should be easy to get any remaining affected servers updated.

[redsky17]

I started noticing this while debugging some nheko issues against my own homeserver (which is up-to-date 0.99.3). I have instances where I get the string-escaped "ts" object section.

[turt2live]

@redsky17 are the users which are producing those read receipts also on your homeserver or do they reside elsewhere?

[redsky17]

I'm currently the only one using my homeserver.

At least one of the messed up read receipts was from a user on matrix.org. I'll see if I can dig up some actual data.

[redsky17]

Here's an excerpt of a really long chain of nested read receipts:

"$o0lUOgpVhSO86pQibCEhgzwhD9+HJNq6GTTG+WUb0nw": {"m.read": {"@SijmenSchoon:matrix.org": "{\"ts\": 1553258856825}"}}

[richvdh]

That read-receipt is timestamped Fri Mar 22 12:47:36 2019. I think it is likely it was sent by matrix.org before this fix landed.

Looking at my own homeserver, it looks like I haven't received any incorrectly-formatted RRs since 2019-03-25.

I'm therefore going to assume that this bug is fixed and people are just seeing historical artifacts.

[redsky17]

While the timestamp may be dated prior to the fix, it was related to me by my homeserver just the other day. Isn't there some benefit to cleaning up the old bad messages rather than continuing to propagate them?

[richvdh]

you could try clearing the bad rows out of the receipts_graph table... keep a backup though!

[ma1uta]

Receive wrong receipts from matrix.org

curl  https://matrix.org:8443/_matrix/federation/v1/version
1.12.1rc1 (b=matrix-org-hotfixes,66cd243e6)