matrix-org / matrix-org/matrix-hookshot
Hookshot sometimes randomly omit sending encryption keys to some devices
- Dominant language
- TypeScript
- Stars
- 450
- Forks
- 95
- Avg merge
- 1d 2h
- Merged PRs (30d)
- 23
Description
I cannot see any patterns. It just randomly happens sometimes for some devices. Then later it just starts working again without me doing anything. I cannot reproduce as I have not found any way to trigger this. Restarting one or more of Hookshot, Synapse, or Redis doesn't seem to make any difference.
Not sure if any of the below info is all that helpful tbh, but I guess better have too much than too little info
Here is one of my e2e Hookshot feed rooms seen from multiple devices and accounts. All of my Hookshot rooms tend to start and stop UTD-ing at the same time.
User on the same homeserver as Hookshot, Element Desktop. The two "test" messages were sent from the two Desktop sessions (device 1)

User on the same homeserver as Hookshot, Element Desktop, same account, another session (device 2)

Element Rageshake from this device
```log
2025-01-16T16:17:20.513Z W WARN matrix_sdk_crypto::machine: Failed to decrypt a room event: Can't find the room key to decrypt the event, withheld code: None
at /home/runner/.cargo/git/checkouts/matrix-rust-sdk-1f4927f82a3d27bb/37c17cf/crates/matrix-sdk-crypto/src/machine/mod.rs:1839
in matrix_sdk_crypto::machine::decrypt_room_event with room_id="!room_id:example.com" sender="@hookshot:example.com" event_id="$event_id" origin_server_ts="2025-01-16T16:17:20.246Z" algorithm="m.megolm.v1.aes-sha2" sender_key="curve25519:" session_id="" message_index=0
2025-01-16T16:17:20.514Z W Error decrypting event (id=$event_id type=m.room.encrypted sender=@hookshot:example.com room=!room_id:example.com ts=2025-01-16T16:17:20.246Z): DecryptionError[msg: The sender's device has not sent us the keys for this message., sender_key: , session_id: ]
2025-01-16T16:17:20.515Z W MatrixRTCSessionManager Decryption failed for event $event_id: MEGOLM_UNKNOWN_INBOUND_SESSION_ID will retry once only
2025-01-16T16:17:21.517Z W MatrixRTCSessionManager Decryption failed for event $event_id: MEGOLM_UNKNOWN_INBOUND_SESSION_ID
2025-01-16T16:18:08.187Z D FetchHttpApi: <-- POST https://matrix.example.com/_matrix/client/v3/rooms/!room_id%3Aexample.com/receipt/m.read.private/%24event_id [568ms 200]
```
User on the same homeserver as Hookshot, Element Desktop, same account, Element X iOS (device 3)

User on another homeserver, Element Desktop (device 4)

User on another homeserver, same user, Element X Android (device 5)

---
Hookshot is not logging anything relevant in debug mode.
Here is Synapse debug logs when grepping for the event ID
```log
2025-01-16 16:17:20,249 - synapse.handlers.message - 1321 - DEBUG - PUT-427 - Created event $
2025-01-16 16:17:20,251 - synapse.event_auth - 373 - DEBUG - PUT-427 - Allowing! , type=m.room.encrypted, state_key=None, outlier=False>
2025-01-16 16:17:20,310 - synapse.storage.databases.main.events - 2404 - DEBUG - persist_events-0 - _update_outliers_txn: events=['$'] have_persisted={}
2025-01-16 16:17:20,311 - synapse.storage.databases.main.events - 2413 - DEBUG - persist_events-0 - _update_outliers_txn: event=$ outlier=False outlier_persisted=None
2025-01-16 16:17:20,387 - synapse.federation.sender - 594 - INFO - process_event_queue_for_federation-0 - Unexpectedly did not have cached prev group for $
2025-01-16 16:17:20,413 - synapse.federation.sender - 631 - DEBUG - process_event_queue_for_federation-0 - Sending , type=m.room.encrypted, state_key=None, outlier=False> to {federated-server.tld', 'example.com'}
2025-01-16 16:18:07,827 - synapse.access.http.8008 - 463 - DEBUG - POST-503 - 78.144.30.127 - 8008 - Received request: POST /_matrix/client/v3/rooms/!%3Aexample.com/receipt/m.read.private/%24
2025-01-16 16:18:07,975 - synapse.storage.databases.main.receipts - 1095 - DEBUG - POST-503 - Receipt m.read.private for event $ in !:example.com (47662 ms old)
2025-01-16 16:18:08,079 - synapse.access.http.8008 - 508 - INFO - POST-503 - 78.144.30.127 - 8008 - {@twilight:example.com} Processed request: 0.219sec/0.033sec (0.009sec, 0.005sec) (0.031sec/0.052sec/6) 2B 200 "POST /_matrix/client/v3/rooms/!%3Aexample.com/receipt/m.read.private/%24 HTTP/1.1" [0 dbevts]
```
Also, as I'm looking closer at this and editing screenshots, etc. I noticed that I get two different encryption errors on different devices:
Device 1, all messages form Hookshot are red shield. This is the most reliable device of all, I don't think I have ever gotten a UTD from Hookshot here.

Device 2, mix of red and grey shields. On of the worst devices for Hookshot UTDs


Device 4, also a mix:

Contributor guide
Research direction
Start with the attached Element and Synapse logs, using the event ID, room ID, sender key, and session ID to compare the devices that receive keys with those that report unknown sessions. No source file or test is named; done would mean identifying a reproducible cause and ensuring encrypted Hookshot events consistently deliver usable keys to affected devices.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- redis, typescript
- Domain
- backend, security
- Issue type
- Bug
- Difficulty
- 5/5
- Estimated time
- Over a week
- Activity status
- Stale
- Clarity
- Needs clarification
- Newbie friendliness
- 25/100