First message sent in a federated server room is not visible to a newly joined user

[Zhani-M]

Description

First message sent in a federated server room is not visible to a newly joined user from another server until a second message is sent.

Steps to reproduce

• Set up two federated servers, Server A and Server B.
• Create two users, User C on Server A and User P on Server B.
• Create a room on Server A.
• Have User C join the room and send a message.
• Have User P join the same room from Server B.
• Observe that User P cannot see the previous message sent by User C.
• Have User C send another message.
• Observe that User P can now see all the previous messages in the room.

Homeserver

Private server

Synapse Version

Synapse/1.105.1

Installation Method

Docker (matrixdotorg/synapse)

Database

Postgress DB - no restores

Workers

Multiple workers

Platform

Kubernetes 1.30

Configuration

No response

Relevant log output

SERVER C ROOM EVENT LOG:

{
  "chunk": [
    {
      "content": {
        "m.federate": true,
        "room_version": "11",
        "type": "m.room"
      },
      "origin_server_ts": 1723552781136,
      "room_id": "[Private]",
      "sender": "[Private]",
      "state_key": "",
      "type": "m.room.create",
      "unsigned": {
        "age": 25890
      },
      "event_id": "$3-x8Hm6whC1iwEatgUW1R1fPfg8I3vD3ueZ828BHvR4",
      "user_id": "[Private]",
      "age": 25890
    },
    {
      "content": {
        "displayname": "admin-service-user",
        "membership": "join"
      },
      "origin_server_ts": 1723552781417,
      "room_id": "[Private]",
      "sender": "[Private]",
      "state_key": "[Private]",
      "type": "m.room.member",
      "unsigned": {
        "age": 25609
      },
      "event_id": "$cWC-nCXhCd9JbN6haIJupt4NXT-5Nd2GBS2YPzBW4SU",
      "user_id": "[Private]",
      "age": 25609
    },
    {
      "content": {
        "ban": 100,
        "events": {
          "m.room.avatar": 100,
          "m.room.invite": 100,
          "m.room.message": 50,
          "m.room.name": 100,
          "m.room.power_levels": 100,
          "m.room.redaction": 100
        },
        "events_default": 50,
        "invite": 100,
        "kick": 100,
        "redact": 100,
        "state_default": 50,
        "users": {
          "[Private]": 75,
          "[Private]": 100,
          "[Private]": 50
        },
        "users_default": 0
      },
      "origin_server_ts": 1723552781650,
      "room_id": "[Private]",
      "sender": "[Private]",
      "state_key": "",
      "type": "m.room.power_levels",
      "unsigned": {
        "age": 25376
      },
      "event_id": "$M2voXDPVYkALt9LtRjD3NQq9Xob5Hgqxmoge9IQUySk",
      "user_id": "[Private]",
      "age": 25376
    },
    {
      "content": {
        "alias": "[Private]"
      },
      "origin_server_ts": 1723552781679,
      "room_id": "[Private]",
      "sender": "[Private]",
      "state_key": "",
      "type": "m.room.canonical_alias",
      "unsigned": {
        "age": 25347
      },
      "event_id": "$j5sVGzISuwJtYqrlOEozT-vtisXgI09WIRneHxIqqfY",
      "user_id": "[Private]",
      "age": 25347
    },
    {
      "content": {
        "guest_access": "can_join"
      },
      "origin_server_ts": 1723552781680,
      "room_id": "!SzZenEWOOJxCvgNvkQ:matrix.api.[Private].com",
      "sender": "@admin-service-user:matrix.api.[Private].com",
      "state_key": "",
      "type": "m.room.guest_access",
      "unsigned": {
        "age": 25346
      },
      "event_id": "$jzftrw1geQbBBCEFakjfF3vCponj4eMNBcwEOMEue74",
      "user_id": "@admin-service-user:matrix.api.[Private].com",
      "age": 25346
    },
    {
      "content": {
        "join_rule": "invite"
      },
      "origin_server_ts": 1723552781680,
      "room_id": "!SzZenEWOOJxCvgNvkQ:matrix.api.[Private].com",
      "sender": "@admin-service-user:matrix.api.[Private].com",
      "state_key": "",
      "type": "m.room.join_rules",
      "unsigned": {
        "age": 25346
      },
      "event_id": "$nFv_Q2g-Sh6W1L7zj7y7oXWGYxEAV0wx9KAzRJlonWs",
      "user_id": "@admin-service-user:matrix.api.[Private].com",
      "age": 25346
    },
    {
      "content": {
        "history_visibility": "shared"
      },
      "origin_server_ts": 1723552781681,
      "room_id": "!SzZenEWOOJxCvgNvkQ:matrix.api.[Private].com",
      "sender": "@admin-service-user:matrix.api.[Private].com",
      "state_key": "",
      "type": "m.room.history_visibility",
      "unsigned": {
        "age": 25345
      },
      "event_id": "$Szdw-DSwuXPhG09tU7XR1uH-VYHipSsMgRfg1h1YsMo",
      "user_id": "@admin-service-user:matrix.api.[Private].com",
      "age": 25345
    },
    {
      "content": {
        "name": "RoomTest13"
      },
      "origin_server_ts": 1723552781682,
      "room_id": "!SzZenEWOOJxCvgNvkQ:matrix.api.remote-development.[private].com",
      "sender": "@admin-service-user:matrix.api.remote-development.[private].com",
      "state_key": "",
      "type": "m.room.name",
      "unsigned": {
        "age": 25344
      },
      "event_id": "$WoYgCxgrpWseqjwJOapp0A-JaknaB5ymFHrlohU4WjQ",
      "user_id": "@admin-service-user:matrix.api.remote-development.[private].com",
      "age": 25344
    },
    {
      "content": {
        "displayname": "Private",
        "membership": "invite"
      },
      "origin_server_ts": 1723552782654,
      "room_id": "!SzZenEWOOJxCvgNvkQ:matrix.api.remote-development.[private].com",
      "sender": "@admin-service-user:matrix.api.remote-development.[private].com",
      "state_key": "@0674ad5a-821f-4f4b-af2d-b61ea0fca8d0:matrix.api.remote-development.[private].com",
      "type": "m.room.member",
      "unsigned": {
        "age": 24372
      },
      "event_id": "$0e6TDZoqlHouteDJCOK27LqUXNnBOjBGJzTZHBovIxk",
      "user_id": "@admin-service-user:matrix.api.remote-development.[private].com",
      "age": 24372
    },
    {
      "content": {
        "displayname": "ee2fa896-1eeb-49ef-839d-236d55458ef1",
        "membership": "invite"
      },
      "origin_server_ts": 1723552783162,
      "room_id": "!SzZenEWOOJxCvgNvkQ:matrix.api.remote-development.[private].com",
      "sender": "@admin-service-user:matrix.api.remote-development.[private].com",
      "state_key": "@ee2fa896-1eeb-49ef-839d-236d55458ef1:matrix.api.remote-development.[private].com",
      "type": "m.room.member",
      "unsigned": {
        "age": 23864
      },
      "event_id": "$9SWbafArb8l3hSg05CUXWbeEFwGonuvSQGrM1t6fsUM",
      "user_id": "@admin-service-user:matrix.api.remote-development.[private].com",
      "age": 23864
    },
    {
      "content": {
        "displayname": "[private]",
        "membership": "join"
      },
      "origin_server_ts": 1723552783850,
      "room_id": "!SzZenEWOOJxCvgNvkQ:matrix.api.remote-development.[private].com",
      "sender": "@0674ad5a-821f-4f4b-af2d-b61ea0fca8d0:matrix.api.remote-development.[private].com",
      "state_key": "@0674ad5a-821f-4f4b-af2d-b61ea0fca8d0:matrix.api.remote-development.[private].com",
      "type": "m.room.member",
      "unsigned": {
        "replaces_state": "$0e6TDZoqlHouteDJCOK27LqUXNnBOjBGJzTZHBovIxk",
        "prev_content": {
          "displayname": "[private]",
          "membership": "invite"
        },
        "prev_sender": "@admin-service-user:matrix.api.remote-development.[private].com",
        "age": 23176
      },
      "event_id": "$lPhhY3ILsMoZGlS0yHN1Sa3od9lwAf4To4GFn7dPYHQ",
      "user_id": "@0674ad5a-821f-4f4b-af2d-b61ea0fca8d0:matrix.api.remote-development.[private].com",
      "age": 23176,
      "replaces_state": "$0e6TDZoqlHouteDJCOK27LqUXNnBOjBGJzTZHBovIxk",
      "prev_content": {
        "displayname": "[private]",
        "membership": "invite"
      }
    },
    {
      "content": {
        "body": "RoomTest13",
        "msgtype": "m.text"
      },
      "origin_server_ts": 1723552784297,
      "room_id": "!SzZenEWOOJxCvgNvkQ:matrix.api.remote-development.[private].com",
      "sender": "@0674ad5a-821f-4f4b-af2d-b61ea0fca8d0:matrix.api.remote-development.[private].com",
      "type": "m.room.message",
      "unsigned": {
        "age": 22729
      },
      "event_id": "$HyHjyNdIfIS53iZ-k3x68vD2EDrQ0oJ9zNLWtnHk_c8",
      "user_id": "@0674ad5a-821f-4f4b-af2d-b61ea0fca8d0:matrix.api.remote-development.[private].com",
      "age": 22729
    },
    {
      "content": {
        "avatar_url": null,
        "displayname": "ee2fa896-1eeb-49ef-839d-236d55458ef1",
        "membership": "join"
      },
      "origin_server_ts": 1723552784706,
      "room_id": "!SzZenEWOOJxCvgNvkQ:matrix.api.remote-development.[private].com",
      "sender": "@ee2fa896-1eeb-49ef-839d-236d55458ef1:matrix.api.remote-development.[private].com",
      "state_key": "@ee2fa896-1eeb-49ef-839d-236d55458ef1:matrix.api.remote-development.[private].com",
      "type": "m.room.member",
      "unsigned": {
        "age": 13,
        "replaces_state": "$9SWbafArb8l3hSg05CUXWbeEFwGonuvSQGrM1t6fsUM",
        "prev_content": {
          "displayname": "ee2fa896-1eeb-49ef-839d-236d55458ef1",
          "membership": "invite"
        },
        "prev_sender": "@admin-service-user:matrix.api.remote-development.[private].com"
      },
      "event_id": "$Z_zDWFIrNHkOsrWYm8zv94aP6XTUrkVQHDIFoyxB6Dk",
      "user_id": "@ee2fa896-1eeb-49ef-839d-236d55458ef1:matrix.api.remote-development.[private].com",
      "age": 13,
      "replaces_state": "$9SWbafArb8l3hSg05CUXWbeEFwGonuvSQGrM1t6fsUM",
      "prev_content": {
        "displayname": "ee2fa896-1eeb-49ef-839d-236d55458ef1",
        "membership": "invite"
      }
    }
  ],
  "start": "s0_0_0_0_0_0_0_0_0_0",
  "end": "t13-3395_0_0_0_0_0_0_0_0_0"
}

SERVER P ROOM EVENT LOG:

{
  "chunk": [
      {
          "content": {
              "avatar_url": null,
              "displayname": "ee2fa896-1eeb-49ef-839d-236d55458ef1",
              "membership": "join"
          },
          "origin_server_ts": 1723552784706,
          "room_id": "!SzZenEWOOJxCvgNvkQ:matrix.api.remote-development.[private].com",
          "sender": "@ee2fa896-1eeb-49ef-839d-236d55458ef1:matrix.api.remote-development.[private].com",
          "state_key": "@ee2fa896-1eeb-49ef-839d-236d55458ef1:matrix.api.remote-development.[private].com",
          "type": "m.room.member",
          "unsigned": {
              "age": 13,
              "replaces_state": "$9SWbafArb8l3hSg05CUXWbeEFwGonuvSQGrM1t6fsUM",
              "prev_content": {
                  "displayname": "ee2fa896-1eeb-49ef-839d-236d55458ef1",
                  "membership": "invite"
              },
              "prev_sender": "@admin-service-user:matrix.api.remote-development.[private].com"
          },
          "event_id": "$Z_zDWFIrNHkOsrWYm8zv94aP6XTUrkVQHDIFoyxB6Dk",
          "user_id": "@ee2fa896-1eeb-49ef-839d-236d55458ef1:matrix.api.remote-development.[private].com",
          "age": 13,
          "replaces_state": "$9SWbafArb8l3hSg05CUXWbeEFwGonuvSQGrM1t6fsUM",
          "prev_content": {
              "displayname": "ee2fa896-1eeb-49ef-839d-236d55458ef1",
              "membership": "invite"
          }
      }
  ],
  "start": "s0_0_0_0_0_0_0_0_0_0",
  "end": "t13-1225_0_0_0_0_0_0_0_0_0"
}

Anything else that would be useful to know?

No response

[maylukas]

We're seeing the same problem with Chat messages not being shown directly after joining the room. It takes sometimes like 30 min for them to be visible in the UI

[MadLittleMods]

I assume those are /messages responses based on the response shape.

Possible scenario

Here is a scenario that could be happening:

The newly joined server (Server P) will need to backfill the message history after it joins as it doesn't have any history. When the client makes a /messages request, it will trigger backfill over federation. If the other server (Server C) fails to respond or doesn't respond in time (federation -> client_timeout), the /messages request will return with no more messages.

The problem is that after that response, the client won't try to call /messages again because it thinks it reached the top of the timeline. We need is something like MSC3871 to give feedback to clients about the gaps so they can attempt to fill it in with /messages again.

You're probably eventually seeing the history because the client tries /messages again some time later where the backfill finally succeeds.

As an FYI, your client should be paginating /messages until no end property is returned (assuming you're trying to view history) (I see an end property` on the Server P response that you posted):

Note that an empty chunk does not necessarily imply that no more events are
available. Clients should continue to paginate until no end property is returned.

-- https://spec.matrix.org/v1.16/client-server-api/#get_matrixclientv3roomsroomidmessages

You can see the Complement tests we have for these kinds of scenarios that work in Synapse. There is one re-join case commented out there that we know doesn't work.

There is also a different scenario where events created during the remote join handshake aren't pulled in (being fixed by #19390)

Debugging further

After joining and trying to view history (make sure you do whatever to trigger them like scrolling up), are you able to the client make /messages requests until no end property? If not, this is a client bug.

Do the server logs show the failed federation backfill requests? Is it even trying to backfill?

What do the backfill responses look like?