element-hq / element-hq/synapse

toDevice messages sent to appservice users while the appservice is offline are dropped

Open
#14,710 0 comments 0 reactions 0 assignees View on GitHub
A-Application-Service A-E2EE O-Occasional T-Defect
Dominant language
Python
Stars
4.6k
Forks
600
Avg merge
5d 22h
Merged PRs (30d)
51

Description

This issue has been migrated from [#14710](https://github.com/matrix-org/synapse/issues/14710).

---

### Description

With encrypted appservices enabled (all of it), appservices are meant to receive their to-device messages when they come back online. However, it appears Synapse is eating them instead.

The primary failure mode for appservices is being unable to decrypt messages sent to it while it was offline (and while keys are needed).

### Steps to reproduce

This is a bit challenging as it requires a fairly unique environment.

1. Have an encrypted appservice or way to inspect transactions
2. Turn off that appservice or otherwise take it offline.
3. Refresh Element Web (this will cause it to generate a new room key on startup)
4. Send a message
5. Turn the appservice back on
6. Monitor transactions for to-device messages

### Homeserver

localhost

### Synapse Version

1.73.0

### Installation Method

Docker (matrixdotorg/synapse)

### Database

postgresql, in a docker container

### Workers

Single process

### Platform

Docker for Windows, under Docker Compose for deployment

### Configuration

In the appservice:
```
de.sorunome.msc2409.push_ephemeral: true
org.matrix.msc3202: true
```

In `homeserver.yaml`:
```
experimental_features:
msc2409_to_device_messages_enabled: true
msc3202_device_masquerading: true
msc3202_transaction_extensions: true
#msc2285_enabled: true
msc1767_enabled: true
```

### Relevant log output

```shell
<< ================================================================== >>
<< FROM THE APPSERVICE, SHOWING AN ENCRYPTED MESSAGE WITHOUT ROOM KEY >>
<< ================================================================== >>

Mon, 19 Dec 2022 20:23:40 GMT [INFO] [index] Starting appservice...
@@ txn body: {
"de.sorunome.msc2409.ephemeral": [],
"de.sorunome.msc2409.to_device": [],
"events": []
}
Mon, 19 Dec 2022 20:23:47 GMT [INFO] [Appservice] Processing transaction 1628
Mon, 19 Dec 2022 20:23:47 GMT [INFO] [Appservice] 127.0.0.1 - - [19/Dec/2022:20:23:47 +0000] "PUT /_matrix/app/v1/transactions/1628?access_token=%3Credacted%3E HTTP/1.1" 200 2 "-" "Synapse/1.73.0"

@@ txn body: {
"de.sorunome.msc2409.ephemeral": [],
"de.sorunome.msc2409.to_device": [],
"events": [
{
"age": 14656,
"content": {
"algorithm": "m.megolm.v1.aes-sha2",
"ciphertext": "AwgAEqABsxVFPCsorrorifmg8ss5CSqEZOJqqGlz/c7lFSpr98OcPuziQh3jgCidW8fOlnOcV3q66hYEK65kmGIv6P9UOs2Q6yLlARWIqQzakQ+GxDBHZDp+o+STPM3Mq7gIyDnv9GvYbeOv/0rcBZ4KlXNTqSjG/bhJdE/lHhNAZit/NhwVNMUgmSMMcRxESyOumVppy0+Pvbi8Spb6mZr7WD0vcSZrOJKniHNOejxOpcZfcLIrpC0ViYUa6PwG7OrPC7BC5LjLKQXD1/wpWSy9L
mR28S1Wpzxd2kNq5rv77fBDFsfePx3WCYwgAg",
"device_id": "YOQFQRGBNR",
"sender_key": "g3do21sL26UntdxUsZjGHY20MghS1TzpCCXnNGPQ/Ww",
"session_id": "p9D4w2A+6ILVmAnNYBAD0w8gQpyNS+hJ+QQwl7+O8cM"
},
"event_id": "$CIdkAd1BWJezbYolsltKLEw8s7KCbkZUqyT17rEg66Q",
"origin_server_ts": 1671481413308,
"room_id": "!HvtWphayPOfPUjxONx:localhost",
"sender": "@travis:localhost",
"type": "m.room.encrypted",
"unsigned": {
"age": 14656
},
"user_id": "@travis:localhost"
}
]
}
Mon, 19 Dec 2022 20:23:47 GMT [INFO] [Appservice] Processing transaction 1629
Mon, 19 Dec 2022 20:23:47 GMT [INFO] [Appservice] Processing event of type m.room.encrypted
Mon, 19 Dec 2022 20:23:47 GMT [WARN] [Appservice] Bot client was not able to decrypt !HvtWphayPOfPUjxONx:localhost $CIdkAd1BWJezbYolsltKLEw8s7KCbkZUqyT17rEg66Q - trying other intents
Mon, 19 Dec 2022 20:23:47 GMT [DEBUG] [MatrixHttpClient] (REQ-6) GET http://localhost:8338/_matrix/client/v3/rooms/!HvtWphayPOfPUjxONx%3Alocalhost/joined_members
Mon, 19 Dec 2022 20:23:47 GMT [DEBUG] [MatrixHttpClient] (REQ-6) qs = {"user_id":"@crypto_main_bot_user:localhost","org.matrix.msc3202.device_id":"EQEMWWXBOT"}
Mon, 19 Dec 2022 20:23:47 GMT [DEBUG] [MatrixHttpClient] (REQ-6 RESP-H200) {
joined: {
'@crypto_main_bot_user:localhost': { avatar_url: null, display_name: 'crypto_main_bot_user' },
'@travis:localhost': {
avatar_url: 'mxc://localhost/QHWkCEbTILlymWtZbhcIIKkK',
display_name: 'TravisR'
}
}
}
Mon, 19 Dec 2022 20:23:47 GMT [ERROR] [Appservice] Decryption error on !HvtWphayPOfPUjxONx:localhost $CIdkAd1BWJezbYolsltKLEw8s7KCbkZUqyT17rEg66Q [Error: decryption failed because the room key is missing] {
code: 'GenericFailure'
}
Mon, 19 Dec 2022 20:23:47 GMT [ERROR] [index] Failed to decrypt !HvtWphayPOfPUjxONx:localhost $CIdkAd1BWJezbYolsltKLEw8s7KCbkZUqyT17rEg66Q because [Error: decryption failed because the room key is missing] {
code: 'GenericFailure'
}
```

### Anything else that would be useful to know?

It appears as though Synapse is sending two transactions when the appservice comes back online: is the first one (empty in the log output) meant to contain the missing EDUs?

Contributor guide

Open the contributing guide

Research direction

No source file or test is named. Start at the appservice transaction endpoint `/_matrix/app/v1/transactions` and trace handling of `de.sorunome.msc2409.to_device` while reproducing the offline/online sequence; done means the encrypted to-device message is present in a transaction after the appservice reconnects, rather than being dropped.

Written by the indexing model from the issue text.

Assessment

Tech stack
docker, postgresql, python
Domain
api, backend
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Mostly clear
Newbie friendliness
38/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.