matrix-org / matrix-js-sdk

Matrix Client-Server SDK for JavaScript
Apache License 2.0
1.54k stars 580 forks source link

A lot of /sync calls within very short time. #4414

Open theobouwman opened 3 days ago

theobouwman commented 3 days ago

(New to Matrix)

I was just following https://hub.docker.com/r/matrixdotorg/synapse to setup a local server without any configuration.

Then when I run the code below a lot of /sync requests are made. Is this normal behaviour?

import * as sdk from "matrix-js-sdk";
import { RoomEvent } from "matrix-js-sdk";

const adminUserId = "@admin:testmomo.matrix.host";
const adminAccessToken = "xxxx";

const matrixClient = sdk.createClient({
    baseUrl: "http://localhost:8008",
    accessToken: adminAccessToken,
    userId: adminUserId,
});

matrixClient.on(RoomEvent.Timeline, function (event, room, toStartOfTimeline) {
    if (toStartOfTimeline) {
        return; // don't print paginated results
    }
    if (event.getType() !== "m.room.message") {
        return; // only print messages
    }
    console.log(
        // the room name will update with m.room.name events automatically
        "(%s) %s :: %s",
        room?.name,
        event.getSender(),
        event.getContent().body,
    );
});

matrixClient.on(sdk.RoomStateEvent.Members, function (event, state, member) {
    const room = matrixClient.getRoom(state.roomId);
    if (!room) {
        return;
    }
    const memberList = state.getMembers();
    console.log(room.name);
    console.log(Array(room.name.length + 1).join("=")); // underline
    for (var i = 0; i < memberList.length; i++) {
        console.log("(%s) %s", memberList[i].membership, memberList[i].name);
    }
});

matrixClient.startClient({
    initialSyncLimit: 20,
    threadSupport: true
});
yarn run v1.22.19
$ tsx app.ts
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/versions
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/versions [39ms 200]
Getting saved sync token...
Getting push rules...
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/pushrules/
Attempting to send queued to-device messages
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/capabilities
Got saved sync token
Got reply from saved sync, exists? false
All queued to-device messages sent
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/capabilities [11ms 200]
Fetched new server capabilities
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/pushrules/ [14ms 200]
Adding default global override push rule .org.matrix.msc3786.rule.room.server_acl
Adding default global underride push rule .org.matrix.msc3914.rule.room.call
Got push rules
Prepare lazy loading for sync...
Storing client options...
Stored client options
Getting filter...
FetchHttpApi: --> POST http://localhost:8008/_matrix/client/v3/user/%40admin%3Atestmomo.matrix.host/filter
FetchHttpApi: <-- POST http://localhost:8008/_matrix/client/v3/user/%40admin%3Atestmomo.matrix.host/filter [12ms 200]
Sending initial sync request...
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&_cacheBuster=xxx
Waiting for saved sync before starting sync processing...
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&_cacheBuster=xxx [19ms 200]
Adding default global override push rule .org.matrix.msc3786.rule.room.server_acl
Adding default global underride push rule .org.matrix.msc3914.rule.room.call
(Empty room) @admin:testmomo.matrix.host :: nos.nl
(Empty room) @admin:testmomo.matrix.host :: https://nos.nl
(Empty room) @admin:testmomo.matrix.host :: test
Resuming queue after resumed sync
Attempting to send queued to-device messages
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
All queued to-device messages sent
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [11ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [20ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [7ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [9ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [22ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [10ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [14ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [19ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [21ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [17ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [20ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [27ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [16ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [23ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [25ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [19ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [20ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [25ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [17ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [15ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [19ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [16ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [15ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [19ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [18ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [17ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [17ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [22ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [27ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [16ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [18ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [27ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [18ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [14ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [16ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [17ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [16ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [19ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [28ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [18ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [19ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [26ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [17ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [18ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
FetchHttpApi: <-- GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx [20ms 200]
FetchHttpApi: --> GET http://localhost:8008/_matrix/client/v3/sync?filter=xxx&timeout=xxx&since=xxx
richvdh commented 7 hours ago

It is not normal: /sync should not return until there is something useful to return. But it sounds more like a server-side issue than a client-side one.

One question: can you inspect the HTTP requests (or inspect the server-side logs), and (a) check that the "timeout" query parameter is sensible (it is specified in milliseconds), (b) see if the "since" values on the requests are different or the same