"Your server isn't divulging details about prev_events referenced in this event" upon join, when other servers create events without incrementing `depth`

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

---

### Description

Under some circumstances involving a custom resident homeserver, Synapse rejects the join of another homeserver, as well as the first `m.room.message` following the join, with "Your server isn't divulging details about prev_events referenced in this event", even though it successfully persisted these prev_events.

Most curiously, this goes away if either:

1. if `hs-s` sends two messages instead of one only errors on the join, then manages to recover from the error when receiving the two PDUs with `m.room.message` (even though both are sent in the same transaction)
2. if `hs-r` is running any commit before https://github.com/matrix-org/synapse/commit/ecb6fe9d9cf8375b760eb727be0e1dec3612e026 then the error does not happen at all

### Steps to reproduce

1. custom homeserver `hs-c` creates a room
2. Synapse `hs-r` joins it (`make_join` + `send_join` to `hs-c`)
3. Synapse `hs-s` joins it (ditto; and it sees `hs-r`'s `m.room.member` in `make_join`'s reply); `hc-c` forwards it to `hs-r`
4. `hs-s` then sends a `m.room.message` to the room
5. Client waits forever for `hs-r` to get the message

`hs-r` then fails to process both events from `hs-s` with: `ERROR 403: Your server isn't divulging details about prev_events referenced in this event.`

Here is an example session (`c-r` and `c-s` are shorthands for `@receiver:hs-c` and `@sender:hs-s`).

First, hs-r joins the room as expected:

```json5
c-r -> hs-r: POST http://localhost:34745/_matrix/client/v3/join/%23testroom%3Ahs-c.localhost%3A49005

hs-r -> hc-c: GET /_matrix/federation/v1/query/directory?room_alias=%23testroom%3Ahs-c.localhost%3A49005
hs-c -> hs-r: HTTP/1.1" 200 - { "room_id": "!roomid:hs-c.localhost:49005", "servers": [ "hs-c.localhost:49005" ] }

hs-r -> hs-c: GET /_matrix/federation/v1/make_join/%21roomid%3Ahs-c.localhost%3A49005/%40receiver%3Ahs-r.localhost%3A37051?ver=1&ver=2&ver=3&ver=4&ver=5&ver=6&ver=org.matrix.msc2176&ver=7&ver=8&ver=9&ver=org.matrix.msc3787&ver=10&ver=org.matrix.msc2716v4
hc-c -> hs-r: HTTP/1.1" 200 -
{
"event": {
"auth_events": [
"$HhL8VDbLxXnA20bDBotKPvN5nA9g3dQVd9Z4AdLt9wI",
"$jlJY1i6dkKcPD4mdyUGndklDpTWlXbCe2Wb_8y3hAYc",
"$lWiBmqqAmCrLeslJyrclIRArVc2aSsiQwkpeExK2U8I"
],
"depth": 0,
"prev_events": [ "$lWiBmqqAmCrLeslJyrclIRArVc2aSsiQwkpeExK2U8I" ],
"content": { "membership": "join" },
"origin": "example.org",
"origin_server_ts": 1679676912146,
"room_id": "!roomid:hs-c.localhost:49005",
"sender": "@receiver:hs-r.localhost:37051",
"state_key": "@receiver:hs-r.localhost:37051",
"type": "m.room.member"
},
"room_version": "9"
}

[omitted: request to v2 send_join errors with 400 M_UNRECOGNIZED]

hs-r -> hs-c: PUT https://hs-c.localhost:49005/_matrix/federation/v1/send_join/%21roomid%3Ahs-c.localhost%3A49005/%24XIUf0Jg_6IW7ScFWOsQd83kQX69w3L4Z-UAECIj-sCo
{
"auth_events": [
"$HhL8VDbLxXnA20bDBotKPvN5nA9g3dQVd9Z4AdLt9wI",
"$jlJY1i6dkKcPD4mdyUGndklDpTWlXbCe2Wb_8y3hAYc",
"$lWiBmqqAmCrLeslJyrclIRArVc2aSsiQwkpeExK2U8I"
],
"content": { "avatar_url": null, "displayname": "receiver", "membership": "join" },
"depth": 0,
"hashes": { "sha256": "08fI2+ZK3iHS7v5BUEsmAuDnCGVVw91OoPCO53TUsFc" },
"origin": "hs-r.localhost:37051",
"origin_server_ts": 1679676912146,
"prev_events": [ "$lWiBmqqAmCrLeslJyrclIRArVc2aSsiQwkpeExK2U8I" ],
"room_id": "!roomid:hs-c.localhost:49005",
"sender": "@receiver:hs-r.localhost:37051",
"signatures": { "hs-r.localhost:37051": { "ed25519:a_mpCA": "+1KgWZ995c2z0Z2Tv6fWRr7lpxqjXjSsYzoGMsNvpzUVZGQwb2LqAxyDDXIkP4RrzH+dYibVLDHcX41nxaWzCQ" } },
"state_key": "@receiver:hs-r.localhost:37051",
"type": "m.room.member",
"unsigned": { "age": 1 }
}
hs-c -> hs-r:HTTP/1.1" 200 -
-> [
200,
{
"auth_chain": [ ],
"origin": "hs-c.localhost:49005",
"state": [
{
"auth_events": [ ],
"depth": 0,
"prev_events": [ ],
"content": { "creator": "@creator:hs-c.localhost:49005", "room_version": "9" },
"origin_server_ts": 1679676912146,
"room_id": "!roomid:hs-c.localhost:49005",
"sender": "@creator:hs-c.localhost:49005",
"state_key": "",
"type": "m.room.create",
"hashes": { "sha256": "JBn9JBE0nuiPgoNdmfOVJtmO3FDSTogFUuT+uqxt2XA" },
"signatures": { "hs-c.localhost:49005": { "ed25519:1": "TzmRDngHKWgkzj4cVAnsZySQr+Ppv8XM+yG1XhpWdbYPTPuGtPZHPsnCOrrORQDG8vCimOJRPtgD8ge6ZyePAA" } }
} /* X event id: $HhL8VDbLxXnA20bDBotKPvN5nA9g3dQVd9Z4AdLt9wI */,
{
"auth_events": [ "$HhL8VDbLxXnA20bDBotKPvN5nA9g3dQVd9Z4AdLt9wI" ],
"depth": 0,
"prev_events": [ "$HhL8VDbLxXnA20bDBotKPvN5nA9g3dQVd9Z4AdLt9wI" ],
"content": { "membership": "join" },
"origin_server_ts": 1679676912146,
"room_id": "!roomid:hs-c.localhost:49005",
"sender": "@creator:hs-c.localhost:49005",
"state_key": "@creator:hs-c.localhost:49005",
"type": "m.room.member",
"hashes": { "sha256": "V15kvJOsf2PZXTPUzmUEI/zyyeKZxzKjLKr59jmC6qE" },
"signatures": { "hs-c.localhost:49005": { "ed25519:1": "Z7mwmLtzXPZ1QhjvcP8QlNK0/M8wgBXGBDfl4hKXdhsfsz4dGCezIaUlxC16CktfMWHhS031FFP+uR40bIjoCg" } }
} /* X event id: $5K5xj1rzu7bOXIA_Q2a2DRtnxImWW8i1pPpioD-XrFU */,
{
"auth_events": [ "$HhL8VDbLxXnA20bDBotKPvN5nA9g3dQVd9Z4AdLt9wI", "$5K5xj1rzu7bOXIA_Q2a2DRtnxImWW8i1pPpioD-XrFU" ],
"depth": 0,
"prev_events": [ "$5K5xj1rzu7bOXIA_Q2a2DRtnxImWW8i1pPpioD-XrFU" ],
"content": {
"ban": 50,
"events": { "m.room.name": 100, "m.room.power_levels": 100 },
"events_default": 0,
"invite": 50,
"kick": 50,
"notifications": { "room": 20 },
"redact": 50,
"state_default": 50,
"users": { "@creator:hs-c.localhost:49005": 100 },
"users_default": 0
},
"origin_server_ts": 1679676912146,
"room_id": "!roomid:hs-c.localhost:49005",
"sender": "@creator:hs-c.localhost:49005",
"state_key": "",
"type": "m.room.power_levels",
"hashes": { "sha256": "Zlbuqzb+PzM9xkSYrlobEgXWEtKMGSy4dm9/ygIKIXU" },
"signatures": { "hs-c.localhost:49005": { "ed25519:1": "ADU+fZWY6mBWdr28N7g2zH+Q/4hmPf3cErLVr1lLuPHwFFsqIrRBioN+A3N2aRszYIrIEkn3TlqvpBbKS4JbAw" } }
} /* X event id: $jlJY1i6dkKcPD4mdyUGndklDpTWlXbCe2Wb_8y3hAYc */,
{
"auth_events": [
"$HhL8VDbLxXnA20bDBotKPvN5nA9g3dQVd9Z4AdLt9wI",
"$5K5xj1rzu7bOXIA_Q2a2DRtnxImWW8i1pPpioD-XrFU",
"$jlJY1i6dkKcPD4mdyUGndklDpTWlXbCe2Wb_8y3hAYc"
],
"depth": 0,
"prev_events": [ "$jlJY1i6dkKcPD4mdyUGndklDpTWlXbCe2Wb_8y3hAYc" ],
"content": { "join_rule": "public" },
"origin_server_ts": 1679676912146,
"room_id": "!roomid:hs-c.localhost:49005",
"sender": "@creator:hs-c.localhost:49005",
"state_key": "",
"type": "m.room.join_rules",
"hashes": { "sha256": "fHTo5qMD0tLMEMANGd5kwh3GOk8a5wOVP5U0f+Q3f3w" },
"signatures": { "hs-c.localhost:49005": { "ed25519:1": "nludaLrT3J/6Ink4TomFjBeAS2pI9XrX4VBq5axXqdLWmmRXJ5UWzOyZKWBo2/Kjj6v8H4oPpurhldySCrLeCw" } }
} /* X event id: $lWiBmqqAmCrLeslJyrclIRArVc2aSsiQwkpeExK2U8I */,
{
"auth_events": [
"$HhL8VDbLxXnA20bDBotKPvN5nA9g3dQVd9Z4AdLt9wI",
"$5K5xj1rzu7bOXIA_Q2a2DRtnxImWW8i1pPpioD-XrFU",
"$jlJY1i6dkKcPD4mdyUGndklDpTWlXbCe2Wb_8y3hAYc"
],
"depth": 0,
"prev_events": [ "$jlJY1i6dkKcPD4mdyUGndklDpTWlXbCe2Wb_8y3hAYc" ],
"content": { "alias": "#testroom:hs-c.localhost:49005" },
"origin_server_ts": 1679676912146,
"room_id": "!roomid:hs-c.localhost:49005",
"sender": "@creator:hs-c.localhost:49005",
"state_key": "",
"type": "m.room.canonical_alias",
"hashes": { "sha256": "v1le6vfPC/vmWXLKLXGAtVIGgttd23y6rv13ZAUf6aU" },
"signatures": { "hs-c.localhost:49005": { "ed25519:1": "iyD6iPwZWhftvgQA+C/vD30NttPCS/W4/tleZ6Z7rEjDoNuGrgY8MQN/ByLwi1CA5wqNs1aMpfVtce6YJFwTBQ" } }
} /* X event id: $xJWTNqWJBy-2nD6sLscd1q3A1OchNHCk0PdFzHGfwQ0 */,
{
"auth_events": [
"$HhL8VDbLxXnA20bDBotKPvN5nA9g3dQVd9Z4AdLt9wI",
"$5K5xj1rzu7bOXIA_Q2a2DRtnxImWW8i1pPpioD-XrFU",
"$jlJY1i6dkKcPD4mdyUGndklDpTWlXbCe2Wb_8y3hAYc"
],
"depth": 0,
"prev_events": [ "$jlJY1i6dkKcPD4mdyUGndklDpTWlXbCe2Wb_8y3hAYc" ],
"content": { "history_visibility": "world_readable" },
"origin_server_ts": 1679676912146,
"room_id": "!roomid:hs-c.localhost:49005",
"sender": "@creator:hs-c.localhost:49005",
"state_key": "",
"type": "m.room.history_visibility",
"hashes": { "sha256": "46eI0CqnYJET/yOTfI/UCgKXuKW20HQ4io03iLzryaM" },
"signatures": { "hs-c.localhost:49005": { "ed25519:1": "/OA1wH0G7UBvZ+0ughwdHYCx7tdD49IrO7k66EpAYWEKBPqH4zgV5fI5SdtXrs4hJYlzTiaqeX1LM56bPkG2DQ" } }
} /* X event id: $BY9oFN0QkzjKrAcK_LtMoUUTqPYl9Q8HLTyo9CF1k4c */
]
}
]

hs-r -> hs-c: GET /_matrix/key/v2/server
hs-c -> hr-r: HTTP/1.1" 200 -
{
"server_name": "hs-c.localhost:49005",
"verify_keys": { "ed25519:1": { "key": "X4U4vyfvBTyE/Wneqgimltt+VZYspRgRWh+Yy8ONZms" } },
"old_verify_keys": { },
"valid_until_ts": 1679680514519,
"signatures": { "hs-c.localhost:49005": { "ed25519:1": "f+ndbmatFQcVbEdZAQKJ1qtQf9Bti0om7b2CXcdyKm6FcHd+taJpnqtbHMwagqCRE2JVZYUck/VVBkrWKBWSCg" } }
}

hs-r -> c-r : 200
{ "room_id": "!roomid:hs-c.localhost:49005" }

c-r -> hs-r: GET /_matrix/client/v3/sync?timeout=1000
hs-r -> c-r : 200
{
"next_batch": "s2_1_0_1_1_1_1_2_0",
"account_data": {
"events": [
{
"type": "m.push_rules",
"content": {
/* redacted */
}
}
]
},
"device_one_time_keys_count": { "signed_curve25519": 0 },
"org.matrix.msc2732.device_unused_fallback_key_types": [ ],
"device_unused_fallback_key_types": [ ],
"rooms": {
"join": {
"!roomid:hs-c.localhost:49005": {
"timeline": {
"events": [
{
"content": { "membership": "join", "displayname": "receiver", "avatar_url": null },
"origin_server_ts": 1679676912146,
"sender": "@receiver:hs-r.localhost:37051",
"state_key": "@receiver:hs-r.localhost:37051",
"type": "m.room.member",
"unsigned": { "age": 158 },
"event_id": "$XIUf0Jg_6IW7ScFWOsQd83kQX69w3L4Z-UAECIj-sCo"
}
],
"prev_batch": "s2_1_0_1_1_1_1_2_0",
"limited": false
},
"state": {
"events": [
{
"content": { "join_rule": "public" },
"origin_server_ts": 1679676912146,
"sender": "@creator:hs-c.localhost:49005",
"state_key": "",
"type": "m.room.join_rules",
"unsigned": { },
"event_id": "$lWiBmqqAmCrLeslJyrclIRArVc2aSsiQwkpeExK2U8I"
},
{
"content": {
"ban": 50,
"events": { "m.room.name": 100, "m.room.power_levels": 100 },
"events_default": 0,
"invite": 50,
"kick": 50,
"notifications": { "room": 20 },
"redact": 50,
"state_default": 50,
"users": { "@creator:hs-c.localhost:49005": 100 },
"users_default": 0
},
"origin_server_ts": 1679676912146,
"sender": "@creator:hs-c.localhost:49005",
"state_key": "",
"type": "m.room.power_levels",
"unsigned": { },
"event_id": "$jlJY1i6dkKcPD4mdyUGndklDpTWlXbCe2Wb_8y3hAYc"
},
{
"content": { "creator": "@creator:hs-c.localhost:49005", "room_version": "9" },
"origin_server_ts": 1679676912146,
"sender": "@creator:hs-c.localhost:49005",
"state_key": "",
"type": "m.room.create",
"unsigned": { },
"event_id": "$HhL8VDbLxXnA20bDBotKPvN5nA9g3dQVd9Z4AdLt9wI"
},
{
"content": { "membership": "join" },
"origin_server_ts": 1679676912146,
"sender": "@creator:hs-c.localhost:49005",
"state_key": "@creator:hs-c.localhost:49005",
"type": "m.room.member",
"unsigned": { },
"event_id": "$5K5xj1rzu7bOXIA_Q2a2DRtnxImWW8i1pPpioD-XrFU"
},
{
"content": { "alias": "#testroom:hs-c.localhost:49005" },
"origin_server_ts": 1679676912146,
"sender": "@creator:hs-c.localhost:49005",
"state_key": "",
"type": "m.room.canonical_alias",
"unsigned": { },
"event_id": "$xJWTNqWJBy-2nD6sLscd1q3A1OchNHCk0PdFzHGfwQ0"
},
{
"content": { "history_visibility": "world_readable" },
"origin_server_ts": 1679676912146,
"sender": "@creator:hs-c.localhost:49005",
"state_key": "",
"type": "m.room.history_visibility",
"unsigned": { },
"event_id": "$BY9oFN0QkzjKrAcK_LtMoUUTqPYl9Q8HLTyo9CF1k4c"
}
]
},
"account_data": { "events": [ ] },
"ephemeral": { "events": [ ] },
"unread_notifications": { "notification_count": 0, "highlight_count": 0 },
"summary": { }
}
}
}
}
```

Note that the above contains event `$lWiBmqqAmCrLeslJyrclIRArVc2aSsiQwkpeExK2U8I` (it's the `join_rules` at the beginning of the state event array); it's the event it will later pretend not to know.

Then `@sender:hs-s` registers and joins the room, ending with:

```json5
hs-s -> hs-c: PUT https://hs-c.localhost:49005/_matrix/federation/v1/send_join/%21roomid%3Ahs-c.localhost%3A49005/%24y_IDcbtWXhZD9TLa1gBfWHUpUoUyyvnjY5pG3PzHSoI
{
"auth_events": [
"$HhL8VDbLxXnA20bDBotKPvN5nA9g3dQVd9Z4AdLt9wI",
"$jlJY1i6dkKcPD4mdyUGndklDpTWlXbCe2Wb_8y3hAYc",
"$lWiBmqqAmCrLeslJyrclIRArVc2aSsiQwkpeExK2U8I"
],
"content": { "avatar_url": null, "displayname": "sender", "membership": "join" },
"depth": 0,
"hashes": { "sha256": "sImI4ZSewzfFMpwUwe07tqlBlPdbyiABi7OvOB6I6Mc" },
"origin": "hs-s.localhost:51845",
"origin_server_ts": 1679676912146,
"prev_events": [ "$lWiBmqqAmCrLeslJyrclIRArVc2aSsiQwkpeExK2U8I" ],
"room_id": "!roomid:hs-c.localhost:49005",
"sender": "@sender:hs-s.localhost:51845",
"signatures": { "hs-s.localhost:51845": { "ed25519:a_FCBT": "KmOlxIkUq2UJSnZIxso7G9ZY4592ZXl4Y/Z26wq9tBcY+w6WHeR3McX7KiNLeuUOmLBiOKHor5UJKmiKrgsPDg" } },
"state_key": "@sender:hs-s.localhost:51845",
"type": "m.room.member",
"unsigned": { "age": 1 }
} /* X event id: $y_IDcbtWXhZD9TLa1gBfWHUpUoUyyvnjY5pG3PzHSoI */

hs-c -> hs-r: hs-r.localhost:37051 PUT /_matrix/federation/v1/send/b0d1940b-be62-4f2a-8ebb-3b03e0d74718
{
"edus": [ ],
"origin": "hs-r.localhost:37051",
"origin_server_ts": 1679676914929,
"pdus": [
{
"auth_events": [
"$HhL8VDbLxXnA20bDBotKPvN5nA9g3dQVd9Z4AdLt9wI",
"$jlJY1i6dkKcPD4mdyUGndklDpTWlXbCe2Wb_8y3hAYc",
"$lWiBmqqAmCrLeslJyrclIRArVc2aSsiQwkpeExK2U8I"
],
"content": { "avatar_url": null, "displayname": "sender", "membership": "join" },
"depth": 0,
"hashes": { "sha256": "sImI4ZSewzfFMpwUwe07tqlBlPdbyiABi7OvOB6I6Mc" },
"origin": "hs-s.localhost:51845",
"origin_server_ts": 1679676912146,
"prev_events": [ "$lWiBmqqAmCrLeslJyrclIRArVc2aSsiQwkpeExK2U8I" ],
"room_id": "!roomid:hs-c.localhost:49005",
"sender": "@sender:hs-s.localhost:51845",
"signatures": { "hs-s.localhost:51845": { "ed25519:a_FCBT": "KmOlxIkUq2UJSnZIxso7G9ZY4592ZXl4Y/Z26wq9tBcY+w6WHeR3McX7KiNLeuUOmLBiOKHor5UJKmiKrgsPDg" } },
"state_key": "@sender:hs-s.localhost:51845",
"type": "m.room.member",
"unsigned": { "age": 1 }
} /* X event id: $y_IDcbtWXhZD9TLa1gBfWHUpUoUyyvnjY5pG3PzHSoI */
]
}

hs-r logs:
hs-r.localhost:37051 17:55:14 DEBUG synapse.access.http.34745 - PUT-5 - ::1 - 34745 - Received request: PUT /_matrix/federation/v1/send/b0d1940b-be62-4f2a-8ebb-3b03e0d74718
hs-r.localhost:37051 17:55:14 DEBUG synapse.http.matrixfederationclient - ServerKeyFetcher-2 - {GET-O-7} [hs-c.localhost:49005] Sending request: GET matrix://hs-c.localhost:49005/_matrix/key/v2/server; timeout 10.000000s
hs-r.localhost:37051 17:55:14 DEBUG synapse.http.federation.matrix_federation_agent - ServerKeyFetcher-2 - Connecting to hs-c.localhost:49005

hs-r -> hs-c: /_matrix/key/v2/server
hs-c -> hs-r: HTTP/1.1" 200 -
{
"server_name": "hs-c.localhost:49005",
"verify_keys": { "ed25519:1": { "key": "X4U4vyfvBTyE/Wneqgimltt+VZYspRgRWh+Yy8ONZms" } },
"old_verify_keys": { },
"valid_until_ts": 1679680514936,
"signatures": { "hs-c.localhost:49005": { "ed25519:1": "qpaVZ4Ndu9zA/z+2n9XNYwjGiZhPcZs3O3UB/FTwFTWlmcBudFiR0KhMV9fBny0eJT9kZyzLqe47xlIwtC1SDA" } }
}

hs-r and hs-s logs:
hs-r.localhost:37051 17:55:14 DEBUG synapse.http.matrixfederationclient - ServerKeyFetcher-2 - {GET-O-7} [hs-c.localhost:49005] Got response headers: 200 OK
hs-r.localhost:37051 17:55:14 INFO synapse.http.matrixfederationclient - ServerKeyFetcher-2 - {GET-O-7} [hs-c.localhost:49005] Completed request: 200 OK in 0.01 secs, got 326 bytes - GET matrix://hs-c.localhost:49005/_matrix/key/v2/server
hs-r.localhost:37051 17:55:14 INFO synapse.federation.transport.server.federation - PUT-5 - Received txn b0d1940b-be62-4f2a-8ebb-3b03e0d74718 from hs-c.localhost:49005. (PDUs: 1, EDUs: 0)
hs-r.localhost:37051 17:55:14 DEBUG synapse.http.matrixfederationclient - ServerKeyFetcher-3 - {GET-O-8} [hs-s.localhost:51845] Sending request: GET matrix://hs-s.localhost:51845/_matrix/key/v2/server; timeout 10.000000s
hs-r.localhost:37051 17:55:14 DEBUG synapse.http.federation.matrix_federation_agent - ServerKeyFetcher-3 - Connecting to hs-s.localhost:51845
hs-s.localhost:51845 17:55:14 DEBUG synapse.access.https.51845 - GET-3 - ::1 - 51845 - Received request: GET /_matrix/key/v2/server
hs-s.localhost:51845 17:55:14 INFO synapse.access.https.51845 - GET-3 - ::1 - 51845 - {None} Processed request: 0.000sec/0.000sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 323B 200 "GET /_matrix/key/v2/server HTTP/1.1" "Synapse/1.72.0" [0 dbevts]
hs-r.localhost:37051 17:55:15 DEBUG synapse.http.matrixfederationclient - ServerKeyFetcher-3 - {GET-O-8} [hs-s.localhost:51845] Got response headers: 200 OK
hs-r.localhost:37051 17:55:15 INFO synapse.http.matrixfederationclient - ServerKeyFetcher-3 - {GET-O-8} [hs-s.localhost:51845] Completed request: 200 OK in 0.06 secs, got 323 bytes - GET matrix://hs-s.localhost:51845/_matrix/key/v2/server
hs-r.localhost:37051 17:55:15 INFO synapse.federation.federation_server - _process_incoming_pdus_in_room_inner-0 - handling received PDU in room !roomid:hs-c.localhost:49005:
hs-r.localhost:37051 17:55:15 INFO synapse.access.http.34745 - PUT-5 - ::1 - 34745 - {hs-c.localhost:49005} Processed request: 0.087sec/0.001sec (0.001sec, 0.001sec) (0.002sec/0.009sec/6) 60B 200 "PUT /_matrix/federation/v1/send/b0d1940b-be62-4f2a-8ebb-3b03e0d74718 HTTP/1.1" "Python-urllib/3.11" [0 dbevts]

hs-r -> hs-c:
{ "pdus": { "$y_IDcbtWXhZD9TLa1gBfWHUpUoUyyvnjY5pG3PzHSoI": { } } }

hs-r logs:
::1 - - [24/Mar/2023 17:55:15] "PUT /_matrix/federation/v1/send_join/%21roomid%3Ahs-c.localhost%3A49005/%24y_IDcbtWXhZD9TLa1gBfWHUpUoUyyvnjY5pG3PzHSoI HTTP/1.1" 200 -
hs-s.localhost:51845 17:55:15 DEBUG synapse.http.matrixfederationclient - POST-2 - {PUT-O-4} [hs-c.localhost:49005] Got response headers: 200 OK
hs-r.localhost:37051 17:55:15 WARNING synapse.handlers.federation_event - _process_incoming_pdus_in_room_inner-0-$y_IDcbtWXhZD9TLa1gBfWHUpUoUyyvnjY5pG3PzHSoI - Rejecting: failed to fetch 1 prev events: ['$lWiBmqqAmCrLeslJyrclIRArVc2aSsiQwkpeExK2U8I']
hs-r.localhost:37051 17:55:15 WARNING synapse.federation.federation_server - _process_incoming_pdus_in_room_inner-0 - Error handling PDU $y_IDcbtWXhZD9TLa1gBfWHUpUoUyyvnjY5pG3PzHSoI: ERROR 403: Your server isn't divulging details about prev_events referenced in this event.
```

First instance of the error ^

And then `hs-s` and `hs-c` complete the join:

```json5
hs-c -> hs-s:
[
200,
{
"auth_chain": [ ],
"origin": "hs-c.localhost:49005",
"state": [
{
"auth_events": [ ],
"depth": 0,
"prev_events": [ ],
"content": { "creator": "@creator:hs-c.localhost:49005", "room_version": "9" },
"origin_server_ts": 1679676912146,
"room_id": "!roomid:hs-c.localhost:49005",
"sender": "@creator:hs-c.localhost:49005",
"state_key": "",
"type": "m.room.create",
"hashes": { "sha256": "JBn9JBE0nuiPgoNdmfOVJtmO3FDSTogFUuT+uqxt2XA" },
"signatures": { "hs-c.localhost:49005": { "ed25519:1": "TzmRDngHKWgkzj4cVAnsZySQr+Ppv8XM+yG1XhpWdbYPTPuGtPZHPsnCOrrORQDG8vCimOJRPtgD8ge6ZyePAA" } }
} /* X event id: $HhL8VDbLxXnA20bDBotKPvN5nA9g3dQVd9Z4AdLt9wI */,
{
"auth_events": [ "$HhL8VDbLxXnA20bDBotKPvN5nA9g3dQVd9Z4AdLt9wI" ],
"depth": 0,
"prev_events": [ "$HhL8VDbLxXnA20bDBotKPvN5nA9g3dQVd9Z4AdLt9wI" ],
"content": { "membership": "join" },
"origin_server_ts": 1679676912146,
"room_id": "!roomid:hs-c.localhost:49005",
"sender": "@creator:hs-c.localhost:49005",
"state_key": "@creator:hs-c.localhost:49005",
"type": "m.room.member",
"hashes": { "sha256": "V15kvJOsf2PZXTPUzmUEI/zyyeKZxzKjLKr59jmC6qE" },
"signatures": { "hs-c.localhost:49005": { "ed25519:1": "Z7mwmLtzXPZ1QhjvcP8QlNK0/M8wgBXGBDfl4hKXdhsfsz4dGCezIaUlxC16CktfMWHhS031FFP+uR40bIjoCg" } }
} /* X event id: $5K5xj1rzu7bOXIA_Q2a2DRtnxImWW8i1pPpioD-XrFU */,
{
"auth_events": [ "$HhL8VDbLxXnA20bDBotKPvN5nA9g3dQVd9Z4AdLt9wI", "$5K5xj1rzu7bOXIA_Q2a2DRtnxImWW8i1pPpioD-XrFU" ],
"depth": 0,
"prev_events": [ "$5K5xj1rzu7bOXIA_Q2a2DRtnxImWW8i1pPpioD-XrFU" ],
"content": {
"ban": 50,
"events": { "m.room.name": 100, "m.room.power_levels": 100 },
"events_default": 0,
"invite": 50,
"kick": 50,
"notifications": { "room": 20 },
"redact": 50,
"state_default": 50,
"users": { "@creator:hs-c.localhost:49005": 100 },
"users_default": 0
},
"origin_server_ts": 1679676912146,
"room_id": "!roomid:hs-c.localhost:49005",
"sender": "@creator:hs-c.localhost:49005",
"state_key": "",
"type": "m.room.power_levels",
"hashes": { "sha256": "Zlbuqzb+PzM9xkSYrlobEgXWEtKMGSy4dm9/ygIKIXU" },
"signatures": { "hs-c.localhost:49005": { "ed25519:1": "ADU+fZWY6mBWdr28N7g2zH+Q/4hmPf3cErLVr1lLuPHwFFsqIrRBioN+A3N2aRszYIrIEkn3TlqvpBbKS4JbAw" } }
} /* X event id: $jlJY1i6dkKcPD4mdyUGndklDpTWlXbCe2Wb_8y3hAYc */,
{
"auth_events": [
"$HhL8VDbLxXnA20bDBotKPvN5nA9g3dQVd9Z4AdLt9wI",
"$5K5xj1rzu7bOXIA_Q2a2DRtnxImWW8i1pPpioD-XrFU",
"$jlJY1i6dkKcPD4mdyUGndklDpTWlXbCe2Wb_8y3hAYc"
],
"depth": 0,
"prev_events": [ "$jlJY1i6dkKcPD4mdyUGndklDpTWlXbCe2Wb_8y3hAYc" ],
"content": { "join_rule": "public" },
"origin_server_ts": 1679676912146,
"room_id": "!roomid:hs-c.localhost:49005",
"sender": "@creator:hs-c.localhost:49005",
"state_key": "",
"type": "m.room.join_rules",
"hashes": { "sha256": "fHTo5qMD0tLMEMANGd5kwh3GOk8a5wOVP5U0f+Q3f3w" },
"signatures": { "hs-c.localhost:49005": { "ed25519:1": "nludaLrT3J/6Ink4TomFjBeAS2pI9XrX4VBq5axXqdLWmmRXJ5UWzOyZKWBo2/Kjj6v8H4oPpurhldySCrLeCw" } }
} /* X event id: $lWiBmqqAmCrLeslJyrclIRArVc2aSsiQwkpeExK2U8I */,
{
"auth_events": [
"$HhL8VDbLxXnA20bDBotKPvN5nA9g3dQVd9Z4AdLt9wI",
"$5K5xj1rzu7bOXIA_Q2a2DRtnxImWW8i1pPpioD-XrFU",
"$jlJY1i6dkKcPD4mdyUGndklDpTWlXbCe2Wb_8y3hAYc"
],
"depth": 0,
"prev_events": [ "$jlJY1i6dkKcPD4mdyUGndklDpTWlXbCe2Wb_8y3hAYc" ],
"content": { "alias": "#testroom:hs-c.localhost:49005" },
"origin_server_ts": 1679676912146,
"room_id": "!roomid:hs-c.localhost:49005",
"sender": "@creator:hs-c.localhost:49005",
"state_key": "",
"type": "m.room.canonical_alias",
"hashes": { "sha256": "v1le6vfPC/vmWXLKLXGAtVIGgttd23y6rv13ZAUf6aU" },
"signatures": { "hs-c.localhost:49005": { "ed25519:1": "iyD6iPwZWhftvgQA+C/vD30NttPCS/W4/tleZ6Z7rEjDoNuGrgY8MQN/ByLwi1CA5wqNs1aMpfVtce6YJFwTBQ" } }
} /* X event id: $xJWTNqWJBy-2nD6sLscd1q3A1OchNHCk0PdFzHGfwQ0 */,
{
"auth_events": [
"$HhL8VDbLxXnA20bDBotKPvN5nA9g3dQVd9Z4AdLt9wI",
"$5K5xj1rzu7bOXIA_Q2a2DRtnxImWW8i1pPpioD-XrFU",
"$jlJY1i6dkKcPD4mdyUGndklDpTWlXbCe2Wb_8y3hAYc"
],
"depth": 0,
"prev_events": [ "$jlJY1i6dkKcPD4mdyUGndklDpTWlXbCe2Wb_8y3hAYc" ],
"content": { "history_visibility": "world_readable" },
"origin_server_ts": 1679676912146,
"room_id": "!roomid:hs-c.localhost:49005",
"sender": "@creator:hs-c.localhost:49005",
"state_key": "",
"type": "m.room.history_visibility",
"hashes": { "sha256": "46eI0CqnYJET/yOTfI/UCgKXuKW20HQ4io03iLzryaM" },
"signatures": { "hs-c.localhost:49005": { "ed25519:1": "/OA1wH0G7UBvZ+0ughwdHYCx7tdD49IrO7k66EpAYWEKBPqH4zgV5fI5SdtXrs4hJYlzTiaqeX1LM56bPkG2DQ" } }
} /* X event id: $BY9oFN0QkzjKrAcK_LtMoUUTqPYl9Q8HLTyo9CF1k4c */,
{
"auth_events": [
"$HhL8VDbLxXnA20bDBotKPvN5nA9g3dQVd9Z4AdLt9wI",
"$jlJY1i6dkKcPD4mdyUGndklDpTWlXbCe2Wb_8y3hAYc",
"$lWiBmqqAmCrLeslJyrclIRArVc2aSsiQwkpeExK2U8I"
],
"content": { "avatar_url": null, "displayname": "receiver", "membership": "join" },
"depth": 0,
"hashes": { "sha256": "08fI2+ZK3iHS7v5BUEsmAuDnCGVVw91OoPCO53TUsFc" },
"origin": "hs-r.localhost:37051",
"origin_server_ts": 1679676912146,
"prev_events": [ "$lWiBmqqAmCrLeslJyrclIRArVc2aSsiQwkpeExK2U8I" ],
"room_id": "!roomid:hs-c.localhost:49005",
"sender": "@receiver:hs-r.localhost:37051",
"signatures": { "hs-r.localhost:37051": { "ed25519:a_mpCA": "+1KgWZ995c2z0Z2Tv6fWRr7lpxqjXjSsYzoGMsNvpzUVZGQwb2LqAxyDDXIkP4RrzH+dYibVLDHcX41nxaWzCQ" } },
"state_key": "@receiver:hs-r.localhost:37051",
"type": "m.room.member",
"unsigned": { "age": 1 }
} /* X event id: $XIUf0Jg_6IW7ScFWOsQd83kQX69w3L4Z-UAECIj-sCo */
]
}
]

hs-s logs:
hs-s.localhost:51845 17:55:15 INFO synapse.http.matrixfederationclient - POST-2 - {PUT-O-4} [hs-c.localhost:49005] Completed request: 200 OK in 0.10 secs, got 4817 bytes - PUT matrix://hs-c.localhost:49005/_matrix/federation/v1/send_join/%21roomid%3Ahs-c.localhost%3A49005/%24y_IDcbtWXhZD9TLa1gBfWHUpUoUyyvnjY5pG3PzHSoI
hs-s.localhost:51845 17:55:15 INFO synapse.federation.federation_client - POST-2 - Processing from send_join 7 events
hs-s.localhost:51845 17:55:15 DEBUG synapse.http.matrixfederationclient - ServerKeyFetcher-0 - {GET-O-5} [hs-c.localhost:49005] Sending request: GET matrix://hs-c.localhost:49005/_matrix/key/v2/server; timeout 10.000000s
hs-s.localhost:51845 17:55:15 DEBUG synapse.http.federation.matrix_federation_agent - ServerKeyFetcher-0 - Connecting to hs-c.localhost:49005
hs-s.localhost:51845 17:55:15 DEBUG synapse.http.matrixfederationclient - ServerKeyFetcher-1 - {GET-O-6} [hs-r.localhost:37051] Sending request: GET matrix://hs-r.localhost:37051/_matrix/key/v2/server; timeout 10.000000s
hs-s.localhost:51845 17:55:15 DEBUG synapse.http.federation.matrix_federation_agent - ServerKeyFetcher-1 - Connecting to hs-r.localhost:37051

hs-s -> hs-c: /_matrix/key/v2/server
hs-c -> hs-s: HTTP/1.1" 200 -
{
"server_name": "hs-c.localhost:49005",
"verify_keys": { "ed25519:1": { "key": "X4U4vyfvBTyE/Wneqgimltt+VZYspRgRWh+Yy8ONZms" } },
"old_verify_keys": { },
"valid_until_ts": 1679680515032,
"signatures": { "hs-c.localhost:49005": { "ed25519:1": "qImqwSMcj7uSGHZ/5UZOt/+tfn/ln4EaInJL2msrPp61lEaQC/zDnQ1BJ+lnBDYsB3nrKdpzO2Xphx1+BUk1Bw" } }
}

hs-s and hs-r logs:
hs-s.localhost:51845 17:55:15 DEBUG synapse.http.matrixfederationclient - ServerKeyFetcher-0 - {GET-O-5} [hs-c.localhost:49005] Got response headers: 200 OK
hs-s.localhost:51845 17:55:15 INFO synapse.http.matrixfederationclient - ServerKeyFetcher-0 - {GET-O-5} [hs-c.localhost:49005] Completed request: 200 OK in 0.01 secs, got 326 bytes - GET matrix://hs-c.localhost:49005/_matrix/key/v2/server
hs-r.localhost:37051 17:55:15 DEBUG synapse.access.https.37051 - GET-6 - ::1 - 37051 - Received request: GET /_matrix/key/v2/server
hs-r.localhost:37051 17:55:15 INFO synapse.access.https.37051 - GET-6 - ::1 - 37051 - {None} Processed request: 0.000sec/0.000sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 323B 200 "GET /_matrix/key/v2/server HTTP/1.1" "Synapse/1.72.0" [0 dbevts]
hs-s.localhost:51845 17:55:15 DEBUG synapse.http.matrixfederationclient - ServerKeyFetcher-1 - {GET-O-6} [hs-r.localhost:37051] Got response headers: 200 OK
hs-s.localhost:51845 17:55:15 INFO synapse.http.matrixfederationclient - ServerKeyFetcher-1 - {GET-O-6} [hs-r.localhost:37051] Completed request: 200 OK in 0.02 secs, got 323 bytes - GET matrix://hs-r.localhost:37051/_matrix/key/v2/server
hs-s.localhost:51845 17:55:15 INFO synapse.handlers.federation_event - POST-2 - Persisting 1 of 7 remaining outliers: ['$HhL8VDbLxXnA20bDBotKPvN5nA9g3dQVd9Z4AdLt9wI']
hs-s.localhost:51845 17:55:15 INFO synapse.handlers.federation_event - POST-2 - Persisting 1 of 6 remaining outliers: ['$5K5xj1rzu7bOXIA_Q2a2DRtnxImWW8i1pPpioD-XrFU']
hs-s.localhost:51845 17:55:15 INFO synapse.handlers.federation_event - POST-2 - Persisting 1 of 5 remaining outliers: ['$jlJY1i6dkKcPD4mdyUGndklDpTWlXbCe2Wb_8y3hAYc']
hs-s.localhost:51845 17:55:15 INFO synapse.handlers.federation_event - POST-2 - Persisting 3 of 4 remaining outliers: ['$lWiBmqqAmCrLeslJyrclIRArVc2aSsiQwkpeExK2U8I', '$xJWTNqWJBy-2nD6sLscd1q3A1OchNHCk0PdFzHGfwQ0', '$BY9oFN0QkzjKrAcK_LtMoUUTqPYl9Q8HLTyo9CF1k4c']
hs-s.localhost:51845 17:55:15 INFO synapse.handlers.federation_event - POST-2 - Persisting 1 of 1 remaining outliers: ['$XIUf0Jg_6IW7ScFWOsQd83kQX69w3L4Z-UAECIj-sCo']
hs-s.localhost:51845 17:55:15 INFO synapse.handlers.federation_event - POST-2 - Peristing join-via-remote (partial_state: False)
hs-s.localhost:51845 17:55:15 INFO synapse.access.http.50071 - POST-2 - ::1 - 50071 - {@sender:hs-s.localhost:51845} Processed request: 0.227sec/0.000sec (0.003sec, 0.001sec) (0.004sec/0.014sec/21) 42B 200 "POST /_matrix/client/v3/join/%23testroom%3Ahs-c.localhost%3A49005 HTTP/1.1" "Python-urllib/3.11" [4 dbevts]

hs-s -> c-s : 200
{ "room_id": "!roomid:hs-c.localhost:49005" }

c-s -> hs-s: GET /_matrix/client/v3/sync?timeout=1000
hs-s -> c: 200
{
"next_batch": "s2_1_0_1_1_1_1_2_0",
"account_data": {
"events": [
{
"type": "m.push_rules",
"content": {
/* redacted */
}
}
]
},
"device_one_time_keys_count": { "signed_curve25519": 0 },
"org.matrix.msc2732.device_unused_fallback_key_types": [ ],
"device_unused_fallback_key_types": [ ],
"rooms": {
"join": {
"!roomid:hs-c.localhost:49005": {
"timeline": {
"events": [
{
"content": { "membership": "join", "displayname": "sender", "avatar_url": null },
"origin_server_ts": 1679676912146,
"sender": "@sender:hs-s.localhost:51845",
"state_key": "@sender:hs-s.localhost:51845",
"type": "m.room.member",
"unsigned": { "age": 238 },
"event_id": "$y_IDcbtWXhZD9TLa1gBfWHUpUoUyyvnjY5pG3PzHSoI"
}
],
"prev_batch": "s2_1_0_1_1_1_1_2_0",
"limited": false
},
"state": {
"events": [
{
"content": { "membership": "join" },
"origin_server_ts": 1679676912146,
"sender": "@creator:hs-c.localhost:49005",
"state_key": "@creator:hs-c.localhost:49005",
"type": "m.room.member",
"unsigned": { },
"event_id": "$5K5xj1rzu7bOXIA_Q2a2DRtnxImWW8i1pPpioD-XrFU"
},
{
"content": { "history_visibility": "world_readable" },
"origin_server_ts": 1679676912146,
"sender": "@creator:hs-c.localhost:49005",
"state_key": "",
"type": "m.room.history_visibility",
"unsigned": { },
"event_id": "$BY9oFN0QkzjKrAcK_LtMoUUTqPYl9Q8HLTyo9CF1k4c"
},
{
"content": { "creator": "@creator:hs-c.localhost:49005", "room_version": "9" },
"origin_server_ts": 1679676912146,
"sender": "@creator:hs-c.localhost:49005",
"state_key": "",
"type": "m.room.create",
"unsigned": { },
"event_id": "$HhL8VDbLxXnA20bDBotKPvN5nA9g3dQVd9Z4AdLt9wI"
},
{
"content": { "join_rule": "public" },
"origin_server_ts": 1679676912146,
"sender": "@creator:hs-c.localhost:49005",
"state_key": "",
"type": "m.room.join_rules",
"unsigned": { },
"event_id": "$lWiBmqqAmCrLeslJyrclIRArVc2aSsiQwkpeExK2U8I"
},
{
"content": { "alias": "#testroom:hs-c.localhost:49005" },
"origin_server_ts": 1679676912146,
"sender": "@creator:hs-c.localhost:49005",
"state_key": "",
"type": "m.room.canonical_alias",
"unsigned": { },
"event_id": "$xJWTNqWJBy-2nD6sLscd1q3A1OchNHCk0PdFzHGfwQ0"
},
{
"content": { "avatar_url": null, "displayname": "receiver", "membership": "join" },
"origin_server_ts": 1679676912146,
"sender": "@receiver:hs-r.localhost:37051",
"state_key": "@receiver:hs-r.localhost:37051",
"type": "m.room.member",
"unsigned": { "age": 1 },
"event_id": "$XIUf0Jg_6IW7ScFWOsQd83kQX69w3L4Z-UAECIj-sCo"
},
{
"content": {
"ban": 50,
"events": { "m.room.name": 100, "m.room.power_levels": 100 },
"events_default": 0,
"invite": 50,
"kick": 50,
"notifications": { "room": 20 },
"redact": 50,
"state_default": 50,
"users": { "@creator:hs-c.localhost:49005": 100 },
"users_default": 0
},
"origin_server_ts": 1679676912146,
"sender": "@creator:hs-c.localhost:49005",
"state_key": "",
"type": "m.room.power_levels",
"unsigned": { },
"event_id": "$jlJY1i6dkKcPD4mdyUGndklDpTWlXbCe2Wb_8y3hAYc"
}
]
},
"account_data": { "events": [ ] },
"ephemeral": { "events": [ ] },
"unread_notifications": { "notification_count": 0, "highlight_count": 0 },
"summary": { }
}
}
}
}
```

Then `@sender:hs-s` sends a message:

```json5
c-s -> hs-s: PUT http://localhost:50071/_matrix/client/v3/rooms/%21roomid%3Ahs-c.localhost%3A49005/send/m.room.message/d8b91459-9289-4d78-b727-fbbf8950c55a
{ "body": "hello world", "msgtype": "m.text" }
hs-s -> c-s : 200
{ "event_id": "$spB7dvLz53tx1cYeyv8GIH0uP7CVLW0urlPmtSDrj3A" }

logs from hs-s and hs-r:
hs-r.localhost:37051 17:55:15 DEBUG synapse.access.http.34745 - GET-7 - ::1 - 34745 - Received request: GET /_matrix/client/v3/sync?since=s2_1_0_1_1_1_1_2_0&timeout=1000
hs-s.localhost:51845 17:55:15 INFO synapse.federation.sender - process_event_queue_for_federation-1 - Unexpectedly did not have cached prev group for $spB7dvLz53tx1cYeyv8GIH0uP7CVLW0urlPmtSDrj3A
hs-s.localhost:51845 17:55:15 INFO synapse.federation.sender.transaction_manager - federation_transaction_transmission_loop-0 - TX [hs-r.localhost:37051] {1679676912667} Sending transaction [1679676912667], (PDUs: 1, EDUs: 0)
hs-s.localhost:51845 17:55:15 DEBUG synapse.http.matrixfederationclient - federation_transaction_transmission_loop-0 - {PUT-O-7} [hs-r.localhost:37051] Sending request: PUT matrix://hs-r.localhost:37051/_matrix/federation/v1/send/1679676912667; timeout 60.000000s
hs-s.localhost:51845 17:55:15 INFO synapse.federation.sender.transaction_manager - federation_transaction_transmission_loop-1 - TX [hs-c.localhost:49005] {1679676912668} Sending transaction [1679676912668], (PDUs: 1, EDUs: 0)
hs-s.localhost:51845 17:55:15 DEBUG synapse.http.matrixfederationclient - federation_transaction_transmission_loop-1 - {PUT-O-8} [hs-c.localhost:49005] Sending request: PUT matrix://hs-c.localhost:49005/_matrix/federation/v1/send/1679676912668; timeout 60.000000s
hs-s.localhost:51845 17:55:15 DEBUG synapse.http.federation.matrix_federation_agent - federation_transaction_transmission_loop-1 - Connecting to hs-c.localhost:49005
hs-r.localhost:37051 17:55:15 DEBUG synapse.access.https.37051 - PUT-8 - ::1 - 37051 - Received request: PUT /_matrix/federation/v1/send/1679676912667
hs-r.localhost:37051 17:55:15 DEBUG synapse.http.matrixfederationclient - ServerKeyFetcher-4 - {GET-O-9} [hs-s.localhost:51845] Sending request: GET matrix://hs-s.localhost:51845/_matrix/key/v2/server; timeout 10.000000s
hs-s.localhost:51845 17:55:15 DEBUG synapse.access.https.51845 - GET-6 - ::1 - 51845 - Received request: GET /_matrix/key/v2/server
hs-s.localhost:51845 17:55:15 INFO synapse.access.https.51845 - GET-6 - ::1 - 51845 - {None} Processed request: 0.000sec/0.001sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 323B 200 "GET /_matrix/key/v2/server HTTP/1.1" "Synapse/1.72.0" [0 dbevts]
hs-r.localhost:37051 17:55:15 DEBUG synapse.http.matrixfederationclient - ServerKeyFetcher-4 - {GET-O-9} [hs-s.localhost:51845] Got response headers: 200 OK
hs-r.localhost:37051 17:55:15 INFO synapse.http.matrixfederationclient - ServerKeyFetcher-4 - {GET-O-9} [hs-s.localhost:51845] Completed request: 200 OK in 0.00 secs, got 323 bytes - GET matrix://hs-s.localhost:51845/_matrix/key/v2/server
hs-s.localhost:51845 17:55:15 INFO synapse.http.matrixfederationclient - federation_transaction_transmission_loop-1 - {PUT-O-8} [hs-c.localhost:49005] Got response headers: 400 Bad Request
hs-s.localhost:51845 17:55:15 WARNING synapse.http.matrixfederationclient - federation_transaction_transmission_loop-1 - {PUT-O-8} [hs-c.localhost:49005] Request failed: PUT matrix://hs-c.localhost:49005/_matrix/federation/v1/send/1679676912668: HttpResponseException('400: Bad Request')
hs-s.localhost:51845 17:55:15 INFO synapse.http.matrixfederationclient - federation_transaction_transmission_loop-1 - Retrying request with trailing slash
hs-s.localhost:51845 17:55:15 DEBUG synapse.http.matrixfederationclient - federation_transaction_transmission_loop-1 - {PUT-O-9} [hs-c.localhost:49005] Sending request: PUT matrix://hs-c.localhost:49005/_matrix/federation/v1/send/1679676912668/; timeout 60.000000s
hs-s.localhost:51845 17:55:15 DEBUG synapse.http.federation.matrix_federation_agent - federation_transaction_transmission_loop-1 - Connecting to hs-c.localhost:49005
hs-r.localhost:37051 17:55:15 INFO synapse.federation.transport.server.federation - PUT-8 - Received txn 1679676912667 from hs-s.localhost:51845. (PDUs: 1, EDUs: 0)
hs-r.localhost:37051 17:55:15 DEBUG synapse.http.matrixfederationclient - ServerKeyFetcher-5 - {GET-O-10} [hs-s.localhost:51845] Sending request: GET matrix://hs-s.localhost:51845/_matrix/key/v2/server; timeout 10.000000s
hs-s.localhost:51845 17:55:15 DEBUG synapse.access.https.51845 - GET-7 - ::1 - 51845 - Received request: GET /_matrix/key/v2/server
hs-s.localhost:51845 17:55:15 INFO synapse.access.https.51845 - GET-7 - ::1 - 51845 - {None} Processed request: 0.000sec/0.000sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 323B 200 "GET /_matrix/key/v2/server HTTP/1.1" "Synapse/1.72.0" [0 dbevts]
hs-r.localhost:37051 17:55:15 DEBUG synapse.http.matrixfederationclient - ServerKeyFetcher-5 - {GET-O-10} [hs-s.localhost:51845] Got response headers: 200 OK
hs-r.localhost:37051 17:55:15 INFO synapse.http.matrixfederationclient - ServerKeyFetcher-5 - {GET-O-10} [hs-s.localhost:51845] Completed request: 200 OK in 0.00 secs, got 323 bytes - GET matrix://hs-s.localhost:51845/_matrix/key/v2/server

hs-s -> hs-c: /_matrix/federation/v1/send/1679676912668/
/* redacted */
hs-c -> hs-s: 400
{ "errcode": "M_UNRECOGNIZED", "error": "Unknown endpoint" }

logs:
hs-s.localhost:51845 17:55:15 INFO synapse.http.matrixfederationclient - federation_transaction_transmission_loop-1 - {PUT-O-8} [hs-c.localhost:49005] Got response headers: 400 Bad Request
hs-s.localhost:51845 17:55:15 WARNING synapse.http.matrixfederationclient - federation_transaction_transmission_loop-1 - {PUT-O-8} [hs-c.localhost:49005] Request failed: PUT matrix://hs-c.localhost:49005/_matrix/federation/v1/send/1679676912668: HttpResponseException('400: Bad Request')
hs-s.localhost:51845 17:55:15 INFO synapse.http.matrixfederationclient - federation_transaction_transmission_loop-1 - Retrying request with trailing slash
hs-s.localhost:51845 17:55:15 DEBUG synapse.http.matrixfederationclient - federation_transaction_transmission_loop-1 - {PUT-O-9} [hs-c.localhost:49005] Sending request: PUT matrix://hs-c.localhost:49005/_matrix/federation/v1/send/1679676912668/; timeout 60.000000s
hs-s.localhost:51845 17:55:15 DEBUG synapse.http.federation.matrix_federation_agent - federation_transaction_transmission_loop-1 - Connecting to hs-c.localhost:49005
hs-r.localhost:37051 17:55:15 INFO synapse.federation.transport.server.federation - PUT-8 - Received txn 1679676912667 from hs-s.localhost:51845. (PDUs: 1, EDUs: 0)
hs-r.localhost:37051 17:55:15 DEBUG synapse.http.matrixfederationclient - ServerKeyFetcher-5 - {GET-O-10} [hs-s.localhost:51845] Sending request: GET matrix://hs-s.localhost:51845/_matrix/key/v2/server; timeout 10.000000s
hs-s.localhost:51845 17:55:15 DEBUG synapse.access.https.51845 - GET-7 - ::1 - 51845 - Received request: GET /_matrix/key/v2/server
hs-s.localhost:51845 17:55:15 INFO synapse.access.https.51845 - GET-7 - ::1 - 51845 - {None} Processed request: 0.000sec/0.000sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 323B 200 "GET /_matrix/key/v2/server HTTP/1.1" "Synapse/1.72.0" [0 dbevts]
hs-r.localhost:37051 17:55:15 DEBUG synapse.http.matrixfederationclient - ServerKeyFetcher-5 - {GET-O-10} [hs-s.localhost:51845] Got response headers: 200 OK
hs-r.localhost:37051 17:55:15 INFO synapse.http.matrixfederationclient - ServerKeyFetcher-5 - {GET-O-10} [hs-s.localhost:51845] Completed request: 200 OK in 0.00 secs, got 323 bytes - GET matrix://hs-s.localhost:51845/_matrix/key/v2/server

hs-s -> hs-c: /_matrix/federation/v1/send/1679676912668/
/* redacted */
hs-c -> hs-s: 400
{ "errcode": "M_UNRECOGNIZED", "error": "Unknown endpoint" }

logs:
hs-s.localhost:51845 17:55:15 INFO synapse.http.matrixfederationclient - federation_transaction_transmission_loop-1 - {PUT-O-9} [hs-c.localhost:49005] Got response headers: 400 Bad Request
hs-s.localhost:51845 17:55:15 WARNING synapse.http.matrixfederationclient - federation_transaction_transmission_loop-1 - {PUT-O-9} [hs-c.localhost:49005] Request failed: PUT matrix://hs-c.localhost:49005/_matrix/federation/v1/send/1679676912668/: HttpResponseException('400: Bad Request')
hs-s.localhost:51845 17:55:15 INFO synapse.federation.sender.transaction_manager - federation_transaction_transmission_loop-1 - TX [hs-c.localhost:49005] {1679676912668} got 400 response
hs-s.localhost:51845 17:55:15 WARNING synapse.federation.sender.per_destination_queue - federation_transaction_transmission_loop-1 - TX [hs-c.localhost:49005] Received 400 response to transaction: 400: Bad Request
hs-r.localhost:37051 17:55:15 INFO synapse.federation.federation_server - _process_incoming_pdus_in_room_inner-1 - handling received PDU in room !roomid:hs-c.localhost:49005:
hs-r.localhost:37051 17:55:15 INFO synapse.access.https.37051 - PUT-8 - ::1 - 37051 - {hs-s.localhost:51845} Processed request: 0.028sec/0.001sec (0.001sec, 0.000sec) (0.001sec/0.010sec/5) 60B 200 "PUT /_matrix/federation/v1/send/1679676912667 HTTP/1.1" "Synapse/1.72.0" [0 dbevts]
hs-s.localhost:51845 17:55:15 DEBUG synapse.http.matrixfederationclient - federation_transaction_transmission_loop-0 - {PUT-O-7} [hs-r.localhost:37051] Got response headers: 200 OK
hs-s.localhost:51845 17:55:15 INFO synapse.http.matrixfederationclient - federation_transaction_transmission_loop-0 - {PUT-O-7} [hs-r.localhost:37051] Completed request: 200 OK in 0.03 secs, got 60 bytes - PUT matrix://hs-r.localhost:37051/_matrix/federation/v1/send/1679676912667
hs-s.localhost:51845 17:55:15 INFO synapse.federation.sender.transaction_manager - federation_transaction_transmission_loop-0 - TX [hs-r.localhost:37051] {1679676912667} got 200 response
hs-r.localhost:37051 17:55:15 INFO synapse.handlers.federation_event - _process_incoming_pdus_in_room_inner-1-$spB7dvLz53tx1cYeyv8GIH0uP7CVLW0urlPmtSDrj3A - Acquiring room lock to fetch 1 missing prev_events: ['$y_IDcbtWXhZD9TLa1gBfWHUpUoUyyvnjY5pG3PzHSoI']
hs-r.localhost:37051 17:55:15 INFO synapse.handlers.federation_event - _process_incoming_pdus_in_room_inner-1-$spB7dvLz53tx1cYeyv8GIH0uP7CVLW0urlPmtSDrj3A - Acquired room lock to fetch 1 missing prev_events
hs-r.localhost:37051 17:55:15 INFO synapse.handlers.federation_event - _process_incoming_pdus_in_room_inner-1-$spB7dvLz53tx1cYeyv8GIH0uP7CVLW0urlPmtSDrj3A - Requesting missing events between ['$XIUf0Jg_6IW7ScFWOsQd83kQX69w3L4Z-UAECIj-sCo'] and $spB7dvLz53tx1cYeyv8GIH0uP7CVLW0urlPmtSDrj3A
hs-r.localhost:37051 17:55:15 DEBUG synapse.http.matrixfederationclient - _process_incoming_pdus_in_room_inner-1-$spB7dvLz53tx1cYeyv8GIH0uP7CVLW0urlPmtSDrj3A - {POST-O-11} [hs-s.localhost:51845] Sending request: POST matrix://hs-s.localhost:51845/_matrix/federation/v1/get_missing_events/%21roomid%3Ahs-c.localhost%3A49005; timeout 60.000000s
hs-s.localhost:51845 17:55:15 DEBUG synapse.access.https.51845 - POST-8 - ::1 - 51845 - Received request: POST /_matrix/federation/v1/get_missing_events/%21roomid%3Ahs-c.localhost%3A49005
hs-s.localhost:51845 17:55:15 DEBUG synapse.http.matrixfederationclient - ServerKeyFetcher-2 - {GET-O-10} [hs-r.localhost:37051] Sending request: GET matrix://hs-r.localhost:37051/_matrix/key/v2/server; timeout 10.000000s
hs-r.localhost:37051 17:55:15 DEBUG synapse.access.https.37051 - GET-9 - ::1 - 37051 - Received request: GET /_matrix/key/v2/server
hs-r.localhost:37051 17:55:15 INFO synapse.access.https.37051 - GET-9 - ::1 - 37051 - {None} Processed request: 0.000sec/0.000sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 323B 200 "GET /_matrix/key/v2/server HTTP/1.1" "Synapse/1.72.0" [0 dbevts]
hs-s.localhost:51845 17:55:15 DEBUG synapse.http.matrixfederationclient - ServerKeyFetcher-2 - {GET-O-10} [hs-r.localhost:37051] Got response headers: 200 OK
hs-s.localhost:51845 17:55:15 INFO synapse.http.matrixfederationclient - ServerKeyFetcher-2 - {GET-O-10} [hs-r.localhost:37051] Completed request: 200 OK in 0.00 secs, got 323 bytes - GET matrix://hs-r.localhost:37051/_matrix/key/v2/server
hs-s.localhost:51845 17:55:15 INFO synapse.access.https.51845 - POST-8 - ::1 - 51845 - {hs-r.localhost:37051} Processed request: 0.011sec/0.000sec (0.000sec, 0.000sec) (0.001sec/0.001sec/5) 3278B 200 "POST /_matrix/federation/v1/get_missing_events/%21roomid%3Ahs-c.localhost%3A49005 HTTP/1.1" "Synapse/1.72.0" [0 dbevts]
hs-r.localhost:37051 17:55:15 DEBUG synapse.http.matrixfederationclient - _process_incoming_pdus_in_room_inner-1-$spB7dvLz53tx1cYeyv8GIH0uP7CVLW0urlPmtSDrj3A - {POST-O-11} [hs-s.localhost:51845] Got response headers: 200 OK
hs-r.localhost:37051 17:55:15 INFO synapse.http.matrixfederationclient - _process_incoming_pdus_in_room_inner-1-$spB7dvLz53tx1cYeyv8GIH0uP7CVLW0urlPmtSDrj3A - {POST-O-11} [hs-s.localhost:51845] Completed request: 200 OK in 0.01 secs, got 3278 bytes - POST matrix://hs-s.localhost:51845/_matrix/federation/v1/get_missing_events/%21roomid%3Ahs-c.localhost%3A49005
hs-r.localhost:37051 17:55:15 DEBUG synapse.http.matrixfederationclient - ServerKeyFetcher-6 - {GET-O-12} [hs-c.localhost:49005] Sending request: GET matrix://hs-c.localhost:49005/_matrix/key/v2/server; timeout 10.000000s
hs-r.localhost:37051 17:55:15 DEBUG synapse.http.federation.matrix_federation_agent - ServerKeyFetcher-6 - Connecting to hs-c.localhost:49005
hs-r.localhost:37051 17:55:15 DEBUG synapse.http.matrixfederationclient - ServerKeyFetcher-7 - {GET-O-13} [hs-s.localhost:51845] Sending request: GET matrix://hs-s.localhost:51845/_matrix/key/v2/server; timeout 10.000000s
hs-s.localhost:51845 17:55:15 DEBUG synapse.access.https.51845 - GET-9 - ::1 - 51845 - Received request: GET /_matrix/key/v2/server
hs-s.localhost:51845 17:55:15 INFO synapse.access.https.51845 - GET-9 - ::1 - 51845 - {None} Processed request: 0.000sec/0.000sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 323B 200 "GET /_matrix/key/v2/server HTTP/1.1" "Synapse/1.72.0" [0 dbevts]
hs-r.localhost:37051 17:55:15 DEBUG synapse.http.matrixfederationclient - ServerKeyFetcher-7 - {GET-O-13} [hs-s.localhost:51845] Got response headers: 200 OK
hs-r.localhost:37051 17:55:15 INFO synapse.http.matrixfederationclient - ServerKeyFetcher-7 - {GET-O-13} [hs-s.localhost:51845] Completed request: 200 OK in 0.00 secs, got 323 bytes - GET matrix://hs-s.localhost:51845/_matrix/key/v2/server

hs-r -> hs-c: GET /_matrix/key/v2/server
hs-c -> hs-r:
{
"server_name": "hs-c.localhost:49005",
"verify_keys": { "ed25519:1": { "key": "X4U4vyfvBTyE/Wneqgimltt+VZYspRgRWh+Yy8ONZms" } },
"old_verify_keys": { },
"valid_until_ts": 1679680515258,
"signatures": { "hs-c.localhost:49005": { "ed25519:1": "vLS372z1yDXsEkzI6wV5LspbF7LIuG4whm3O1bCNCrGedANrchVyZJbrGPWeZjzZSpiOLa0VW81Af+PIR20PDA" } }
}

logs:
hs-r.localhost:37051 17:55:15 DEBUG synapse.http.matrixfederationclient - ServerKeyFetcher-6 - {GET-O-12} [hs-c.localhost:49005] Got response headers: 200 OK
hs-r.localhost:37051 17:55:15 INFO synapse.http.matrixfederationclient - ServerKeyFetcher-6 - {GET-O-12} [hs-c.localhost:49005] Completed request: 200 OK in 0.01 secs, got 326 bytes - GET matrix://hs-c.localhost:49005/_matrix/key/v2/server
hs-r.localhost:37051 17:55:15 INFO synapse.handlers.federation_event - _process_incoming_pdus_in_room_inner-1-$spB7dvLz53tx1cYeyv8GIH0uP7CVLW0urlPmtSDrj3A - Got 5 prev_events
hs-r.localhost:37051 17:55:15 INFO synapse.handlers.federation_event - _process_incoming_pdus_in_room_inner-1-$spB7dvLz53tx1cYeyv8GIH0uP7CVLW0urlPmtSDrj3A - De-outliering event $HhL8VDbLxXnA20bDBotKPvN5nA9g3dQVd9Z4AdLt9wI
hs-r.localhost:37051 17:55:15 INFO synapse.handlers.federation_event - _process_incoming_pdus_in_room_inner-1-$spB7dvLz53tx1cYeyv8GIH0uP7CVLW0urlPmtSDrj3A - De-outliering event $5K5xj1rzu7bOXIA_Q2a2DRtnxImWW8i1pPpioD-XrFU
hs-r.localhost:37051 17:55:15 INFO synapse.handlers.federation_event - _process_incoming_pdus_in_room_inner-1-$spB7dvLz53tx1cYeyv8GIH0uP7CVLW0urlPmtSDrj3A - De-outliering event $jlJY1i6dkKcPD4mdyUGndklDpTWlXbCe2Wb_8y3hAYc
hs-r.localhost:37051 17:55:15 INFO synapse.handlers.federation_event - _process_incoming_pdus_in_room_inner-1-$spB7dvLz53tx1cYeyv8GIH0uP7CVLW0urlPmtSDrj3A - De-outliering event $lWiBmqqAmCrLeslJyrclIRArVc2aSsiQwkpeExK2U8I
hs-r.localhost:37051 17:55:15 INFO synapse.handlers.federation_event - _process_incoming_pdus_in_room_inner-1-$spB7dvLz53tx1cYeyv8GIH0uP7CVLW0urlPmtSDrj3A-$y_IDcbtWXhZD9TLa1gBfWHUpUoUyyvnjY5pG3PzHSoI - Processing pulled event
hs-r.localhost:37051 17:55:15 INFO synapse.handlers.federation_event - _process_incoming_pdus_in_room_inner-1-$spB7dvLz53tx1cYeyv8GIH0uP7CVLW0urlPmtSDrj3A-$y_IDcbtWXhZD9TLa1gBfWHUpUoUyyvnjY5pG3PzHSoI - Event $y_IDcbtWXhZD9TLa1gBfWHUpUoUyyvnjY5pG3PzHSoI is missing prev_events ['$lWiBmqqAmCrLeslJyrclIRArVc2aSsiQwkpeExK2U8I']: calculating state for a backwards extremity
hs-r.localhost:37051 17:55:15 INFO synapse.handlers.federation_event - _process_incoming_pdus_in_room_inner-1-$spB7dvLz53tx1cYeyv8GIH0uP7CVLW0urlPmtSDrj3A-$y_IDcbtWXhZD9TLa1gBfWHUpUoUyyvnjY5pG3PzHSoI - Requesting state after missing prev_event $lWiBmqqAmCrLeslJyrclIRArVc2aSsiQwkpeExK2U8I
hs-r.localhost:37051 17:55:15 DEBUG synapse.http.matrixfederationclient - _process_incoming_pdus_in_room_inner-1-$spB7dvLz53tx1cYeyv8GIH0uP7CVLW0urlPmtSDrj3A-$y_IDcbtWXhZD9TLa1gBfWHUpUoUyyvnjY5pG3PzHSoI-$lWiBmqqAmCrLeslJyrclIRArVc2aSsiQwkpeExK2U8I - {GET-O-14} [hs-s.localhost:51845] Sending request: GET matrix://hs-s.localhost:51845/_matrix/federation/v1/state_ids/%21roomid%3Ahs-c.localhost%3A49005?event_id=%24lWiBmqqAmCrLeslJyrclIRArVc2aSsiQwkpeExK2U8I; timeout 60.000000s
hs-s.localhost:51845 17:55:15 DEBUG synapse.access.https.51845 - GET-10 - ::1 - 51845 - Received request: GET /_matrix/federation/v1/state_ids/%21roomid%3Ahs-c.localhost%3A49005?event_id=%24lWiBmqqAmCrLeslJyrclIRArVc2aSsiQwkpeExK2U8I
hs-s.localhost:51845 17:55:15 DEBUG synapse.http.matrixfederationclient - ServerKeyFetcher-3 - {GET-O-11} [hs-r.localhost:37051] Sending request: GET matrix://hs-r.localhost:37051/_matrix/key/v2/server; timeout 10.000000s
hs-r.localhost:37051 17:55:15 DEBUG synapse.access.https.37051 - GET-10 - ::1 - 37051 - Received request: GET /_matrix/key/v2/server
hs-r.localhost:37051 17:55:15 INFO synapse.access.https.37051 - GET-10 - ::1 - 37051 - {None} Processed request: 0.000sec/0.000sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 323B 200 "GET /_matrix/key/v2/server HTTP/1.1" "Synapse/1.72.0" [0 dbevts]
hs-s.localhost:51845 17:55:15 DEBUG synapse.http.matrixfederationclient - ServerKeyFetcher-3 - {GET-O-11} [hs-r.localhost:37051] Got response headers: 200 OK
hs-s.localhost:51845 17:55:15 INFO synapse.http.matrixfederationclient - ServerKeyFetcher-3 - {GET-O-11} [hs-r.localhost:37051] Completed request: 200 OK in 0.00 secs, got 323 bytes - GET matrix://hs-r.localhost:37051/_matrix/key/v2/server
hs-s.localhost:51845 17:55:15 INFO synapse.http.server - GET-10 - SynapseError: 404 - State not known at event $lWiBmqqAmCrLeslJyrclIRArVc2aSsiQwkpeExK2U8I
hs-s.localhost:51845 17:55:15 INFO synapse.access.https.51845 - GET-10 - ::1 - 51845 - {hs-r.localhost:37051} Processed request: 0.009sec/0.000sec (0.000sec, 0.000sec) (0.000sec/0.000sec/1) 105B 404 "GET /_matrix/federation/v1/state_ids/%21roomid%3Ahs-c.localhost%3A49005?event_id=%24lWiBmqqAmCrLeslJyrclIRArVc2aSsiQwkpeExK2U8I HTTP/1.1" "Synapse/1.72.0" [0 dbevts]
hs-r.localhost:37051 17:55:15 INFO synapse.http.matrixfederationclient - _process_incoming_pdus_in_room_inner-1-$spB7dvLz53tx1cYeyv8GIH0uP7CVLW0urlPmtSDrj3A-$y_IDcbtWXhZD9TLa1gBfWHUpUoUyyvnjY5pG3PzHSoI-$lWiBmqqAmCrLeslJyrclIRArVc2aSsiQwkpeExK2U8I - {GET-O-14} [hs-s.localhost:51845] Got response headers: 404 Not Found
hs-r.localhost:37051 17:55:15 WARNING synapse.http.matrixfederationclient - _process_incoming_pdus_in_room_inner-1-$spB7dvLz53tx1cYeyv8GIH0uP7CVLW0urlPmtSDrj3A-$y_IDcbtWXhZD9TLa1gBfWHUpUoUyyvnjY5pG3PzHSoI-$lWiBmqqAmCrLeslJyrclIRArVc2aSsiQwkpeExK2U8I - {GET-O-14} [hs-s.localhost:51845] Request failed: GET matrix://hs-s.localhost:51845/_matrix/federation/v1/state_ids/%21roomid%3Ahs-c.localhost%3A49005?event_id=%24lWiBmqqAmCrLeslJyrclIRArVc2aSsiQwkpeExK2U8I: HttpResponseException('404: Not Found')
hs-r.localhost:37051 17:55:15 WARNING synapse.handlers.federation_event - _process_incoming_pdus_in_room_inner-1-$spB7dvLz53tx1cYeyv8GIH0uP7CVLW0urlPmtSDrj3A-$y_IDcbtWXhZD9TLa1gBfWHUpUoUyyvnjY5pG3PzHSoI - Error attempting to resolve state at missing prev_events: 404: Not Found
hs-r.localhost:37051 17:55:15 WARNING synapse.handlers.federation_event - _process_incoming_pdus_in_room_inner-1-$spB7dvLz53tx1cYeyv8GIH0uP7CVLW0urlPmtSDrj3A-$y_IDcbtWXhZD9TLa1gBfWHUpUoUyyvnjY5pG3PzHSoI - Pulled event $y_IDcbtWXhZD9TLa1gBfWHUpUoUyyvnjY5pG3PzHSoI failed history check.
hs-r.localhost:37051 17:55:15 INFO synapse.handlers.federation_event - _process_incoming_pdus_in_room_inner-1-$spB7dvLz53tx1cYeyv8GIH0uP7CVLW0urlPmtSDrj3A-$HhL8VDbLxXnA20bDBotKPvN5nA9g3dQVd9Z4AdLt9wI - Processing pulled event
hs-r.localhost:37051 17:55:15 INFO synapse.state - persist_events-5 - Resolving state for !roomid:hs-c.localhost:49005 with groups [2, 4]
hs-r.localhost:37051 17:55:15 INFO synapse.handlers.federation_event - _process_incoming_pdus_in_room_inner-1-$spB7dvLz53tx1cYeyv8GIH0uP7CVLW0urlPmtSDrj3A-$5K5xj1rzu7bOXIA_Q2a2DRtnxImWW8i1pPpioD-XrFU - Processing pulled event
hs-r.localhost:37051 17:55:15 INFO synapse.state - persist_events-6 - Resolving state for !roomid:hs-c.localhost:49005 with groups [2, 5]
hs-r.localhost:37051 17:55:15 INFO synapse.handlers.federation_event - _process_incoming_pdus_in_room_inner-1-$spB7dvLz53tx1cYeyv8GIH0uP7CVLW0urlPmtSDrj3A-$jlJY1i6dkKcPD4mdyUGndklDpTWlXbCe2Wb_8y3hAYc - Processing pulled event

[noise from ijson.common.IncompleteJSONError]

logs:
hs-r.localhost:37051 17:55:15 INFO synapse.state - persist_events-7 - Resolving state for !roomid:hs-c.localhost:49005 with groups [2, 6]
hs-r.localhost:37051 17:55:15 INFO synapse.handlers.federation_event - _process_incoming_pdus_in_room_inner-1-$spB7dvLz53tx1cYeyv8GIH0uP7CVLW0urlPmtSDrj3A-$lWiBmqqAmCrLeslJyrclIRArVc2aSsiQwkpeExK2U8I - Processing pulled event
hs-r.localhost:37051 17:55:15 WARNING synapse.handlers.federation_event - _process_incoming_pdus_in_room_inner-1-$spB7dvLz53tx1cYeyv8GIH0uP7CVLW0urlPmtSDrj3A - Rejecting: failed to fetch 1 prev events: ['$y_IDcbtWXhZD9TLa1gBfWHUpUoUyyvnjY5pG3PzHSoI']
hs-r.localhost:37051 17:55:15 WARNING synapse.federation.federation_server - _process_incoming_pdus_in_room_inner-1 - Error handling PDU $spB7dvLz53tx1cYeyv8GIH0uP7CVLW0urlPmtSDrj3A: ERROR 403: Your server isn't divulging details about prev_events referenced in this event.

[noise from ijson.common.IncompleteJSONError]
```

and then nothing happens unless one of the clients sends a message.

### Homeserver

n/a

### Synapse Version

v1.74.0rc1 up to develop

### Installation Method

Other (please mention below)

### Database

sqlite

### Workers

Single process

### Platform

ran with poetry from git

### Configuration

config template:

```yaml
server_name: {server_name}
public_baseurl: http://{name}.localhost:{port}/
enable_registration: true
enable_registration_without_verification: true

# Configure server to listen on both $https_port and $port
# This overides some of the default settings above
listeners:
- port: {https_port}
type: http
tls: true
bind_addresses: ['::1', '127.0.0.1']
resources:
- names: [client, federation]
- port: {port}
tls: false
bind_addresses: ['::1', '127.0.0.1']
type: http
x_forwarded: true
resources:
- names: [client, federation]
compress: false

use_insecure_ssl_client_just_for_testing_do_not_use: true
federation_verify_certificates: false

# Set paths for the TLS certificates.
tls_certificate_path: "{directory_path}/tls.crt"
tls_private_key_path: "{directory_path}/tls.key"

# Ignore keys from the trusted keys server
trusted_key_servers: []
# - server_name: "matrix.org"
# accept_keys_insecurely: true

# disable presence, it's noisy
presence:
enabled: false

# Allow the servers to communicate over localhost.
ip_range_whitelist:
- '127.0.0.1/8'
- '::1/128'

report_stats: false

log_config: "{log_config}"
```

### Relevant log output

```shell
see above, interleaved with request dumps
```

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

_No response_