element-call icon indicating copy to clipboard operation
element-call copied to clipboard
Published 4 weeks ago • verified publisher icon element-hq

RTCSession Error

Open sw7837 opened this issue 8 months ago • 35 comments

Description

Element Web is fine with video and voice When using ElementX on a mobile device, an error occurs Sometimes you can talk for a few minutes, sometimes you can't get in and report an error, Web and mobile are in a network,5Gwifi network speed stability is very good, synapse and elementX are the latest versions synapse built it,elementX didn't build it The server is 16C32GB

RTCSession Error The MembershipManager shut down because of the end condition: Error: Could not restart delayed event, even though delayed events are supported. tw: error sending request for url (https://chat.bitdu.love/_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_YkZjZSYxmnyWEACerjAg)

2025-04-15T20:26:57.029Z WARN livekit.transport rtc/transport.go:830 error reading data channel {"room": "!pLJrBmFowOYaQYdeyC:chat.test123.com", "roomID": "RM_nsG6Rpoota4y", "participant": "@nick:chat.test123.com:YKIXTBGXNH", "pID": "PA_bhtJgZptc4L4", "remote": false, "transport": "PUBLISHER", "label": "_lossy", "error": "[0xc00325a780] abort chunk, with following errors: (User Initiated Abort: Close called)"} 2025-04-15T20:26:57.029Z WARN livekit.transport rtc/transport.go:830 error reading data channel {"room": "!pLJrBmFowOYaQYdeyC:chat.test123.com", "roomID": "RM_nsG6Rpoota4y", "participant": "@nick:chat.test123.com:YKIXTBGXNH", "pID": "PA_bhtJgZptc4L4", "remote": false, "transport": "PUBLISHER", "label": "_reliable", "error": "[0xc00325a780] abort chunk, with following errors: (User Initiated Abort: Close called)"} 2025-04-15T20:26:57.032Z INFO livekit rtc/participant.go:1036 participant closing {"room": "!pLJrBmFowOYaQYdeyC:chat.test123.com", "roomID": "RM_nsG6Rpoota4y", "participant": "@nick:chat.test123.com:YKIXTBGXNH", "pID": "PA_bhtJgZptc4L4", "remote": false, "sendLeave": true, "reason": "CLIENT_REQUEST_LEAVE", "isExpectedToResume": false}

Steps to reproduce

When using ElementX on a mobile device, an error occurs Sometimes you can talk for a few minutes, sometimes you can't get in and report an error, Web and mobile are in a network,5Gwifi network speed stability is very good, synapse and elementX are the latest versions synapse built it,elementX didn't build it

Homeserver

chat.***

Synapse Version

latest

Installation Method

Docker (matrixdotorg/synapse)

Database

PostgreSQL

Workers

Single process

Platform

ubuntu 16c32g

Configuration

No response

Relevant log output

2025-04-15T20:26:57.029Z        WARN    livekit.transport       rtc/transport.go:830    error reading data channel      {"room": "!pLJrBmFowOYaQYdeyC:chat.test123.com", "roomID": "RM_nsG6Rpoota4y", "participant": "@nick:chat.test123.com:YKIXTBGXNH", "pID": "PA_bhtJgZptc4L4", "remote": false, "transport": "PUBLISHER", "label": "_lossy", "error": "[0xc00325a780] abort chunk, with following errors: (User Initiated Abort: Close called)"}
2025-04-15T20:26:57.029Z        WARN    livekit.transport       rtc/transport.go:830    error reading data channel      {"room": "!pLJrBmFowOYaQYdeyC:chat.test123.com", "roomID": "RM_nsG6Rpoota4y", "participant": "@nick:chat.test123.com:YKIXTBGXNH", "pID": "PA_bhtJgZptc4L4", "remote": false, "transport": "PUBLISHER", "label": "_reliable", "error": "[0xc00325a780] abort chunk, with following errors: (User Initiated Abort: Close called)"}
2025-04-15T20:26:57.032Z        INFO    livekit rtc/participant.go:1036 participant closing     {"room": "!pLJrBmFowOYaQYdeyC:chat.test123.com", "roomID": "RM_nsG6Rpoota4y", "participant": "@nick:chat.test123.com:YKIXTBGXNH", "pID": "PA_bhtJgZptc4L4", "remote": false, "sendLeave": true, "reason": "CLIENT_REQUEST_LEAVE", "isExpectedToResume": false}

Anything else that would be useful to know?

No response

sw7837 avatar Apr 15 '25 20:04 sw7837

Using Element is fine Using ElementX results in an error

sw7837 avatar Apr 15 '25 20:04 sw7837

Sounds more like an issue with Element X rather than Synapse.

ghost avatar Apr 20 '25 13:04 ghost

I have been experiencing the exact same problem (and submitted a couple of rage shake reports) - it happens using either the Apple or Android versions of Element X and am likewise having no issues at all with audio/video Element Calls between desktop computers.

ciyam avatar Apr 30 '25 03:04 ciyam

Just to confirm, I have been using elementX with selfhosted { Livekit and JWT } MatrixRTC without any problems in android.

Calls span from minutes to hours without any problems. Not element-call but widget mode. Previously element-call has also worked without any issues.

escix avatar May 01 '25 09:05 escix

@sw7837 I've moved this issue from the Synapse issue tracker to Element Call's. Please can you also "rageshake" from within the Element Call settings. That would help the team get the full logs (and the logs of any other clients present in the room at the time).

anoadragon453 avatar May 09 '25 11:05 anoadragon453

are you using synapse workers? and is there a chance the workers were restarted or so?

fkwp avatar May 09 '25 11:05 fkwp

I am wondering if the livekit-jwt service has something to do with this as I see the following (redacted) lines in its log:

May 10 17:09:54 <server> lk-jwt-service[32152]: 2025/05/10 17:09:54 Request from [::1]:57378 at "https://appassets.androidplatform.net"
May 10 17:09:54 <server> lk-jwt-service[32152]: 2025/05/10 17:09:54 Request from [::1]:57378 at "https://appassets.androidplatform.net"
May 10 17:09:54 <server> lk-jwt-service[32152]: 2025/05/10 17:09:54 Got user info for @<user1>:<server>
May 10 17:10:04 <server> lk-jwt-service[32152]: 2025/05/10 17:10:04 Request from [::1]:57378 at "https://call.element.io"
May 10 17:10:04 <server> lk-jwt-service[32152]: 2025/05/10 17:10:04 Request from [::1]:57378 at "https://call.element.io"
May 10 17:10:04 <server> lk-jwt-service[32152]: 2025/05/10 17:10:04 Got user info for @<user2>:<server>

As Livekit is self-hosted I don't understand why "appassets.androidplatform.net" and "call.element.io" are actually doing there in the log (the latter being from my laptop and the former being from my Android phone).

The following is the redacted content of https://host/.well-known/matrix/client:

{
    "m.homeserver":
    {
        "base_url": "https://<server>"
    },

    "org.matrix.msc4143.rtc_foci":
    [
        {
            "type": "livekit",
            "livekit_service_url": "https://<server>"
        }
    ]
}

I must admit I found the documentation concerning the "rtc_foci" to be contradictory (some examples include having host/livekit/jwt and others with host/livekit/sfu and another stating you only should put host which is what I had thought was working.

ciyam avatar May 10 '25 08:05 ciyam

If is referring to the same in the following both lines that is indeed wrong.

"base_url": "https://<server>" "livekit_service_url": "https://<server>"

Request from [::1]:57378 at "https://appassets.androidplatform.net" or Request from [::1]:57378 at "https://call.element.io" are referring to the Element Call client which was requesting the JWT token:

  • https://appassets.androidplatform.net hints at the in-app bundle
  • https://call.element.io hints at Element Call configures via a Widget URL

for details refer to https://github.com/element-hq/element-call?tab=readme-ov-file#-element-call-packaging and https://github.com/element-hq/element-call/blob/livekit/docs/embedded-standalone.md

I must admit I found the documentation concerning the "rtc_foci" to be contradictory (some examples include having host/livekit/jwt and others with host/livekit/sfu and another stating you only should put host which is what I had thought was working.

While there are many ways to achieve a single goal we do recommend the pattern as outlined here: https://github.com/element-hq/element-call/blob/livekit/docs/self-hosting.md

However, the issue as outlined by @sw7837 seems to be more related with an unreliable connection to the homeserver such that the delayed_event is kicking in and the call is ended. Hence, the Q if synapse workers are part of the setup.

fkwp avatar May 10 '25 16:05 fkwp

If is referring to the same in the following both lines that is indeed wrong.

I'm not sure that wrong is accurate as it does work that way (i.e. the livekit-jwt log would show nothing at all and you'd get a FOCI error if it couldn't connect).

But in any case I have now changed it to include the /livekit/jwt endpoint and it still behaves exactly as before.

So I am able to start an Element-Call between my laptop and Android phone and it appears to be working perfectly for a certain amount of time (sometimes as much as ten minutes if lucky) but then I end up getting the RTC Session Error (which occurs in the Android Element-X app).

ciyam avatar May 10 '25 23:05 ciyam

If is referring to the same in the following both lines that is indeed wrong.

I'm not sure that wrong is accurate as it does work that way (i.e. the livekit-jwt log would show nothing at all and you'd get a FOCI error if it couldn't connect).

But in any case I have now changed it to include the /livekit/jwt endpoint and it still behaves exactly as before.

So I am able to start an Element-Call between my laptop and Android phone and it appears to be working perfectly for a certain amount of time (sometimes as much as ten minutes if lucky) but then I end up getting the RTC Session Error (which occurs in the Android Element-X app).

it should be lk-jwt-service url.

livekit log should be showing some info (lk-jwt-service log will be empty).

Also turnserver log will also be helpful.

escix avatar May 11 '25 12:05 escix

This is some typical (redacted) log lines from the "livekit-sfu" service when starting an Element-Calll (the one that was working for ten minutes before I got the RTCSession Error):

May 11 09:35:34 host.name livekit-server[1419795]: 2025-05-11T09:35:34.820        INFO        livekit.pub        rtc/participant.go:1799        mediaTrack published        {"room": "!yMgKqTKzKHXDkwvvAd:host.name", "roomID": "RM_Ci63JpPjhq8t", "participant>
May 11 09:35:35 host.name livekit-server[1419795]: 2025-05-11T09:35:35.411        INFO        livekit.pub        rtc/participant.go:1799        mediaTrack published        {"room": "!yMgKqTKzKHXDkwvvAd:host.name", "roomID": "RM_Ci63JpPjhq8t", "participant>
May 11 09:45:26 host.name livekit-server[1419795]: 2025-05-11T09:45:26.280        INFO        livekit        rtc/participant.go:1036        participant closing        {"room": "!yMgKqTKzKHXDkwvvAd:host.name", "roomID": "RM_Ci63JpPjhq8t", "participant": "@>
May 11 09:45:40 host.name livekit-server[1419795]: 2025-05-11T09:45:40.170        INFO        livekit        rtc/participant.go:1036        participant closing        {"room": "!yMgKqTKzKHXDkwvvAd:host.name", "roomID": "RM_Ci63JpPjhq8t", "participant": "@>

Also turnserver log will also be helpful.

I have only enabled TURN on 443 (UDP) for Livekit as I am also using "coturn" to support the old Element app for calls - when I use the Livekit Tester it says that TURN is enabled but not usable (I thought that shouldn't matter as the WebRTC tests are completed without error).

ciyam avatar May 11 '25 21:05 ciyam

This is some typical (redacted) log lines from the "livekit-sfu" service when starting an Element-Calll (the one that was working for ten minutes before I got the RTCSession Error):

May 11 09:35:34 host.name livekit-server[1419795]: 2025-05-11T09:35:34.820        INFO        livekit.pub        rtc/participant.go:1799        mediaTrack published        {"room": "!yMgKqTKzKHXDkwvvAd:host.name", "roomID": "RM_Ci63JpPjhq8t", "participant>
May 11 09:35:35 host.name livekit-server[1419795]: 2025-05-11T09:35:35.411        INFO        livekit.pub        rtc/participant.go:1799        mediaTrack published        {"room": "!yMgKqTKzKHXDkwvvAd:host.name", "roomID": "RM_Ci63JpPjhq8t", "participant>
May 11 09:45:26 host.name livekit-server[1419795]: 2025-05-11T09:45:26.280        INFO        livekit        rtc/participant.go:1036        participant closing        {"room": "!yMgKqTKzKHXDkwvvAd:host.name", "roomID": "RM_Ci63JpPjhq8t", "participant": "@>
May 11 09:45:40 host.name livekit-server[1419795]: 2025-05-11T09:45:40.170        INFO        livekit        rtc/participant.go:1036        participant closing        {"room": "!yMgKqTKzKHXDkwvvAd:host.name", "roomID": "RM_Ci63JpPjhq8t", "participant": "@>

Also turnserver log will also be helpful.

I have only enabled TURN on 443 (UDP) for Livekit as I am also using "coturn" to support the old Element app for calls - when I use the Livekit Tester it says that TURN is enabled but not usable (I thought that shouldn't matter as the WebRTC tests are completed without error).

I am pretty sure it does matter, otherwise the clients won't be able to see each other. In the livekit test, I think, the client is directly connected to the server so it does work (single client).

escix avatar May 11 '25 23:05 escix

I am pretty sure it does matter, otherwise the clients won't be able to see each other.

If the clients can't see each other then how did I manage to have a ten minute Livekit audio and video call between the laptop and phone?

ciyam avatar May 11 '25 23:05 ciyam

Just to follow up - I enabled TURN for Livekit and it made no difference at all (call connected then died after a minute with the familiar RTC_Session Error).

it should be lk-jwt-service url.

This is not correct - when I changed it to have the endpoint it would no longer work at all (you just get Waiting For Media).

Looking at https://element.io/.well-known/matrix/client I see that it also does NOT specify the endpoint but just a server name (so the documentation stating you should use the /livekit/jwt endpoint is incorrect).

It's a shame that although I have Livekit working Element-X calls are just not usable (except between laptops) - guess I will be looking into installing Jitsi and sticking with Element for now.

ciyam avatar May 15 '25 21:05 ciyam

Image

This is the endpoint for the jwt from element.io

and this is from matrix.org:

"org.matrix.msc4143.rtc_foci": [ { "type": "livekit", "livekit_service_url": "https://livekit-jwt.call.matrix.org" } ]

Just to summarise:

you will have separate URLs for

  1. Livekit-JWT-Service (eg. https://jwt-service.mydomain.com) <- if you reach this in a webbrowser it will show "404 page not found"
  2. Livekit (eg. https://livekit.mydomain.com) <- if you reach this in web browser it will give you "OK"
  3. homeserver (eg. https://matrix.mydomain.com)
  4. Turnserver (eg. https://turn.mydomain.com)

the first two are for the MatrixRTC, third is the matrix server and the fourth turnserver.

escix avatar May 16 '25 12:05 escix

Looking at https://element.io/.well-known/matrix/client I see that it also does NOT specify the endpoint but just a server name (so the documentation stating you should use the /livekit/jwt endpoint is incorrect).

That is a valid observation. There are several ways how you could setup the MatrixRTC stack for the services "MatrixRTC Authorisation Service" and "LiveKit SFU web socket"

  • Using a hostname for each service separately, e.g.,
    • matrix-rtc-jwt.example.com
    • matrix-rtc-sfu.example.com
  • Using a single hostname with endpoint routing, e.g., matrix-rtc.example.com/livekit/{jwt,sfu}

Using endpoint routing saves you a hostname since you can reuse a single hostname. Hence, we do propose this in the self-hosting guide https://github.com/element-hq/element-call/blob/livekit/docs/self-hosting.md#matrix-site-endpoint-routing.

fkwp avatar May 16 '25 13:05 fkwp

As stated I am just using a single hostname (with reverse proxies to be more clear) and I have shown that both livekit-jwt and livekit-sfu are working (including adding Livekit's TURN which didn't make any difference) - in fact I have had a ten minute long audio and video Element Call between my laptop and Android phone (so there are no issues about end-points here as you would not even be able to start a call if they were not working).

So I think we are getting distracted by basic configuration options (which has been pointed out can be set up in different ways) and not looking into why the actual "RTC_Session" error is being displayed.

IMO a more relevant question is: What is the delayed event being used for and why would it not be found?

ciyam avatar May 16 '25 22:05 ciyam

As stated I am just using a single hostname (with reverse proxies to be more clear) and I have shown that both livekit-jwt and livekit-sfu are working (including adding Livekit's TURN which didn't make any difference) - in fact I have had a ten minute long audio and video Element Call between my laptop and Android phone (so there are no issues about end-points here as you would not even be able to start a call if they were not working).

So I think we are getting distracted by basic configuration options (which has been pointed out can be set up in different ways) and not looking into why the actual "RTC_Session" error is being displayed.

IMO a more relevant question is: What is the delayed event being used for and why would it not be found?

Yes, I thought that when your livekit log actually populated the connections.

So, lk-jwt and livekit must be working.

In my past experience it was always TURN server which caused intermittent connection issues and disconnections.

Does the TURN server log tells you anything?

Also, what happens when both the phone and the desktop clients are in LAN?

Web server logs?

escix avatar May 17 '25 00:05 escix

Does the TURN server log tells you anything?

Am not sure if the Livekit TURN server has some separate log but this is a redacted version from the livekit-sfu log of an Element Call that lasted about 1.5 minutes (before the RTCSession Error on the mobile).

In this case both the laptop and mobile are using the same WiFI network (the host itself is remote but is accessed using very reliable internet speeds of around 80/100 Mbs for download/upload).

13:17:54 host.tld livekit-server[]: 13:17:54 INFO livekit service/roommanager.go:384 starting RTC session {"room": "!room:host.tld", "roomID": "RM_ID", "participant": "@mobile:host.tld"
13:17:54 host.tld livekit-server[]: 13:17:54 INFO livekit service/roommanager.go:918 created TURN password {"username": "yd1c...", "password": "ctYV..."}
13:17:54 host.tld livekit-server[]: 13:17:54 INFO livekit rtc/participant.go:1217 migration complete {"room": "!room:host.tld", "roomID": "RM_ID", "participant": "@mobile:host.tld"
13:17:56 host.tld livekit-server[]: 13:17:56 INFO livekit rtc/room.go:474 participant active {"room": "!room:host.tld", "roomID": "RM_ID", "participant": "@mobile:host.tld"
13:17:56 host.tld livekit-server[]: 13:17:56 INFO livekit.pub rtc/participant.go:1799 mediaTrack published {"room": "!room:host.tld", "roomID": "RM_ID", "participant": "@mobile:host.tld"
13:17:58 host.tld livekit-server[]: 13:17:58 INFO livekit.pub rtc/participant.go:1799 mediaTrack published {"room": "!room:host.tld", "roomID": "RM_ID", "participant": "@mobile:host.tld"
13:18:04 host.tld livekit-server[]: 13:18:04 INFO livekit service/roommanager.go:384 starting RTC session {"room": "!room:host.tld", "roomID": "RM_ID", "participant": "@laptop:host.tld"
13:18:04 host.tld livekit-server[]: 13:18:04 INFO livekit service/roommanager.go:918 created TURN password {"username": "vJkY...", "password": "jnvL..."}
13:18:04 host.tld livekit-server[]: 13:18:04 INFO livekit rtc/participant.go:1217 migration complete {"room": "!room:host.tld", "roomID": "RM_ID", "participant": "@laptop:host.tld"
13:18:06 host.tld livekit-server[]: 13:18:06 INFO livekit rtc/room.go:474 participant active {"room": "!room:host.tld", "roomID": "RM_ID", "participant": "@laptop:host.tld"
13:18:06 host.tld livekit-server[]: 13:18:06 INFO livekit.pub rtc/participant.go:1799 mediaTrack published {"room": "!room:host.tld", "roomID": "RM_ID", "participant": "@laptop:host.tld"
13:18:07 host.tld livekit-server[]: 13:18:07 INFO livekit.pub rtc/participant.go:1799 mediaTrack published {"room": "!room:host.tld", "roomID": "RM_ID", "participant": "@laptop:host.tld"
13:18:07 host.tld livekit-server[]: 13:18:07 INFO livekit.pub rtc/participant.go:1799 mediaTrack published {"room": "!room:host.tld", "roomID": "RM_ID", "participant": "@laptop:host.tld"
13:18:08 host.tld livekit-server[]: 13:18:08 INFO livekit.pub rtc/participant.go:1799 mediaTrack published {"room": "!room:host.tld", "roomID": "RM_ID", "participant": "@laptop:host.tld"
13:19:43 host.tld livekit-server[]: 13:19:43 INFO livekit rtc/participant.go:1036 participant closing {"room": "!room:host.tld", "roomID": "RM_ID", "participant": "@mobile:host.tld"
13:19:48 host.tld livekit-server[]: 13:19:48 INFO livekit rtc/participant.go:1036 participant closing {"room": "!room:host.tld", "roomID": "RM_ID", "participant": "@laptop:host.tld"
13:20:08 host.tld livekit-server[]: 13:20:08 INFO livekit.room rtc/room.go:922 closing room {"room": "!room:host.tld", "roomID": "RM_ID"}
13:20:08 host.tld livekit-server[]: 13:20:08 INFO livekit service/roommanager.go:167 deleting room state {"room": "!room:host.tld"}
13:20:08 host.tld livekit-server[]: 13:20:08 INFO livekit.room service/roommanager.go:605 room closed {"room": "!room:host.tld", "roomID": "RM_ID"}
13:20:08 host.tld livekit-server[]: 13:20:08 INFO livekit.room rtc/room.go:906 closing idle room {"room": "!room:host.tld", "roomID": "RM_ID", "reason": "departure timeout"}

You can see it creates the TURN credentials (but doesn't appear to log anything else about TURN). Note that when running the Livekit Tester everything passes.

ciyam avatar May 17 '25 03:05 ciyam

I had issues with getting livekit turnserver working, so I used my previously configured turnserver rather than livekit.

You will have to include the external turnserver settings in the livekit yml.

escix avatar May 17 '25 04:05 escix

maybe worthwhile to first check with google STUN in livekit for testing.

escix avatar May 17 '25 04:05 escix

You will have to include the external turnserver settings in the livekit yml.

I had tried to get "coturn" to work with Livekit but had no luck with that at all.

The following are redacted from the matrix-synapse log (divided up into chunks of time).

Note here the "Delayed event not found" for "syd_dcof..." (this occurs right at the start of the call although the call continued for another minute and a half). There are two other delayed event codes (see the notes at the bottom).

13:17:54 - synapse.access.http.8008 - 508 - INFO - GET-56903 - 1.2.3.4 - 8008 - {None} Processed request: 0.000sec/0.000sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 1035B 200 "GET /_matrix/client/versions HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:17:54 - synapse.access.http.8008 - 508 - INFO - PUT-56904 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 0.005sec/0.000sec (0.001sec, 0.000sec) (0.000sec/0.003sec/1) 39B 200 "PUT /_matrix/client/v3/rooms/!room:host.tld/state/org.matrix.msc3401.call.member/_@mobile:host.tld_PQRSTUVWXYZ?org.matrix.msc4140.delay=15000 HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:17:54 - synapse.access.http.8008 - 508 - INFO - POST-56900 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 0.313sec/0.000sec (0.001sec, 0.000sec) (0.001sec/0.001sec/1) 285B 200 "POST /_matrix/client/unstable/org.matrix.simplified_msc3575/sync?pos=0%2Fs4099_1_0_11&timeout=30000 HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:17:54 - synapse.access.http.8008 - 508 - INFO - PUT-56905 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 0.044sec/0.001sec (0.005sec, 0.003sec) (0.002sec/0.009sec/9) 59B 200 "PUT /_matrix/client/v3/rooms/!room:host.tld/state/org.matrix.msc3401.call.member/_@mobile:host.tld_PQRSTUVWXYZ HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [1 dbevts]
13:17:54 - synapse.federation.sender - 594 - INFO - process_event_queue_for_federation-256 - Unexpectedly did not have cached prev group for $fU8C...
13:17:54 - synapse.access.http.8008 - 508 - INFO - POST-56902 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 0.291sec/0.000sec (0.002sec, 0.000sec) (0.002sec/0.004sec/4) 1906B 200 "POST /_matrix/client/unstable/org.matrix.simplified_msc3575/sync?pos=1894%2Fs4099_1_0_11&timeout=30000 HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:17:54 - synapse.access.http.8008 - 508 - INFO - GET-56901 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 0.301sec/0.000sec (0.003sec, 0.001sec) (0.002sec/0.007sec/7) 1953B 200 "GET /_matrix/client/v3/sync?filter=0&timeout=30000&org.matrix.msc4222.use_state_after=true&set_presence=unavailable&since=s4099_1_0_11 HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]
13:17:54 - synapse.http.server - 130 - INFO - POST-56908 - <XForwardedForRequest at 0x7655e4f42600 method='POST' uri='/_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_dcof...' clientproto='HTTP/1.1' site='8008'> SynapseError: 404 - Delayed event not found
13:17:54 - synapse.access.http.8008 - 508 - INFO - POST-56908 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 0.004sec/0.000sec (0.001sec, 0.001sec) (0.000sec/0.001sec/1) 59B 404 "POST /_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_dcof... HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:17:54 - synapse.access.http.8008 - 508 - INFO - POST-56911 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 0.004sec/0.001sec (0.001sec, 0.000sec) (0.000sec/0.003sec/1) 120B 200 "POST /_matrix/client/v3/user/@mobile:host.tld/openid/request_token HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:17:54 - synapse.access.http.8008 - 508 - INFO - PUT-56912 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 0.003sec/0.000sec (0.001sec, 0.000sec) (0.000sec/0.002sec/1) 39B 200 "PUT /_matrix/client/v3/rooms/!room:host.tld/state/org.matrix.msc3401.call.member/_@mobile:host.tld_PQRSTUVWXYZ?org.matrix.msc4140.delay=15000 HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:17:54 - synapse.access.http.8008 - 508 - INFO - GET-56913 - 127.0.0.1 - 8008 - {None} Processed request: 0.001sec/0.000sec (0.001sec, 0.000sec) (0.000sec/0.001sec/1) 32B 200 "GET /_matrix/federation/v1/openid/userinfo?access_token=<redacted> HTTP/1.1" "Go-http-client/1.1" [0 dbevts]

13:17:56 - synapse.federation.sender.transaction_manager - 127 - INFO - federation_transaction_transmission_loop-1969 - TX [fedx.tld] {1746861461485} Sending transaction [1746861461485], (PDUs: 0, EDUs: 1)
13:17:56 - synapse.access.http.8008 - 508 - INFO - GET-56907 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 2.247sec/0.003sec (0.002sec, 0.000sec) (0.000sec/0.000sec/0) 397B 200 "GET /_matrix/client/v3/sync?filter=0&timeout=30000&org.matrix.msc4222.use_state_after=true&set_presence=unavailable&since=s4100_1_0_11 HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]
13:17:56 - synapse.access.http.8008 - 508 - INFO - POST-56910 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 2.106sec/0.003sec (0.001sec, 0.000sec) (0.000sec/0.000sec/0) 285B 200 "POST /_matrix/client/unstable/org.matrix.simplified_msc3575/sync?pos=0%2Fs4100_1_0_11&timeout=30000 HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:17:56 - synapse.access.http.8008 - 508 - INFO - POST-56915 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 0.022sec/0.000sec (0.005sec, 0.000sec) (0.002sec/0.009sec/9) 2B 200 "POST /_matrix/client/v3/rooms/!room%3Ahost.tld/receipt/m.read/%24fU... HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]
13:17:56 - synapse.access.http.8008 - 508 - INFO - POST-56909 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 2.140sec/0.000sec (0.003sec, 0.000sec) (0.001sec/0.001sec/1) 512B 200 "POST /_matrix/client/unstable/org.matrix.simplified_msc3575/sync?pos=1894%2Fs4100_1_0_11&timeout=30000 HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:17:56 - synapse.access.http.8008 - 508 - INFO - POST-56917 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 0.002sec/0.000sec (0.001sec, 0.000sec) (0.000sec/0.000sec/0) 285B 200 "POST /_matrix/client/unstable/org.matrix.simplified_msc3575/sync?pos=0%2Fs4100_1_0_11&timeout=30000 HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:17:56 - synapse.access.http.8008 - 508 - INFO - GET-56918 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 0.007sec/0.000sec (0.002sec, 0.000sec) (0.000sec/0.005sec/2) 736B 200 "GET /_matrix/client/v3/sync?filter=0&timeout=30000&org.matrix.msc4222.use_state_after=true&set_presence=online&since=s4100_1_0_11 HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]
13:17:56 - synapse.http.matrixfederationclient - 364 - INFO - federation_transaction_transmission_loop-1969 - {PUT-O-3412} [fedx.tld] Completed request: 200 OK in 0.16 secs, got 11 bytes - PUT matrix-federation://fedx.tld/_matrix/federation/v1/send/1746861461485
13:17:56 - synapse.federation.sender.transaction_manager - 180 - INFO - federation_transaction_transmission_loop-1969 - TX [fedx.tld] {1746861461485} got 200 response
13:17:59 - synapse.access.http.8008 - 508 - INFO - POST-56923 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 0.008sec/0.000sec (0.001sec, 0.000sec) (0.000sec/0.007sec/1) 2B 200 "POST /_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_aanI... HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]

13:18:04 - synapse.access.http.8008 - 508 - INFO - GET-56924 - 1.2.3.4 - 8008 - {None} Processed request: 0.000sec/0.000sec (0.001sec, 0.000sec) (0.000sec/0.000sec/0) 1035B 200 "GET /_matrix/client/versions HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]
13:18:04 - synapse.access.http.8008 - 508 - INFO - POST-56927 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 0.003sec/0.000sec (0.000sec, 0.000sec) (0.000sec/0.002sec/1) 120B 200 "POST /_matrix/client/v3/user/%40laptop%3Ahost.tld/openid/request_token HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]
13:18:04 - synapse.access.http.8008 - 508 - INFO - PUT-56929 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 0.008sec/0.000sec (0.002sec, 0.001sec) (0.001sec/0.003sec/3) 2B 200 "PUT /_matrix/client/v3/sendToDevice/m.room.encrypted/m1747451884535.5 HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]
13:18:04 - synapse.access.http.8008 - 508 - INFO - POST-56921 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 7.812sec/0.000sec (0.002sec, 0.000sec) (0.001sec/0.001sec/2) 2214B 200 "POST /_matrix/client/unstable/org.matrix.simplified_msc3575/sync?pos=0%2Fs41478_0_11&timeout=30000 HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:18:04 - synapse.access.http.8008 - 508 - INFO - PUT-56930 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 0.003sec/0.000sec (0.001sec, 0.000sec) (0.000sec/0.002sec/1) 39B 200 "PUT /_matrix/client/v3/rooms/!room%3Ahost.tld/state/org.matrix.msc3401.call.member/_%40laptop%3Ahost.tld_WKIIFSXWOV?org.matrix.msc4140.delay=15000 HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]
13:18:04 - synapse.access.http.8008 - 508 - INFO - GET-56931 - 127.0.0.1 - 8008 - {None} Processed request: 0.001sec/0.000sec (0.001sec, 0.000sec) (0.000sec/0.001sec/1) 28B 200 "GET /_matrix/federation/v1/openid/userinfo?access_token=<redacted> HTTP/1.1" "Go-http-client/1.1" [0 dbevts]
13:18:04 - synapse.access.http.8008 - 508 - INFO - POST-56933 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 0.002sec/0.000sec (0.000sec, 0.000sec) (0.000sec/0.002sec/1) 2B 200 "POST /_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_aanI... HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:18:04 - synapse.access.http.8008 - 508 - INFO - PUT-56934 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 0.044sec/0.001sec (0.006sec, 0.001sec) (0.002sec/0.010sec/12) 59B 200 "PUT /_matrix/client/v3/rooms/!room%3Ahost.tld/state/org.matrix.msc3401.call.member/_%40laptop%3Ahost.tld_WKIIFSXWOV HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [1 dbevts]
13:18:04 - synapse.access.http.8008 - 508 - INFO - POST-56935 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 0.022sec/0.000sec (0.001sec, 0.000sec) (0.002sec/0.003sec/2) 285B 200 "POST /_matrix/client/unstable/org.matrix.simplified_msc3575/sync?pos=0%2Fs4100_147842_1_0_1_11&timeout=30000 HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:18:04 - synapse.federation.sender - 594 - INFO - process_event_queue_for_federation-257 - Unexpectedly did not have cached prev group for $F7zI...
13:18:04 - synapse.access.http.8008 - 508 - INFO - POST-56919 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 8.091sec/0.000sec (0.003sec, 0.000sec) (0.003sec/0.004sec/5) 2378B 200 "POST /_matrix/client/unstable/org.matrix.simplified_msc3575/sync?pos=1894%2Fs41478_0_11&timeout=30000 HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:18:04 - synapse.access.http.8008 - 508 - INFO - GET-56922 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 7.970sec/0.000sec (0.003sec, 0.001sec) (0.003sec/0.005sec/7) 2800B 200 "GET /_matrix/client/v3/sync?filter=0&timeout=30000&org.matrix.msc4222.use_state_after=true&set_presence=online&since=s41478_0_11 HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]
13:18:04 - synapse.access.http.8008 - 508 - INFO - GET-56943 - 1.2.3.4 - 8008 - {None} Processed request: 0.001sec/0.000sec (0.000sec, 0.000sec) (0.000sec/0.000sec/1) 21B 200 "GET /_matrix/client/v3/profile/%40laptop%3Ahost.tld HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]
13:18:04 - synapse.http.server - 130 - INFO - POST-56942 - <XForwardedForRequest at 0x7655e44eec60 method='POST' uri='/_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_iAoB...' clientproto='HTTP/1.1' site='8008'> SynapseError: 404 - Delayed event not found
13:18:04 - synapse.access.http.8008 - 508 - INFO - POST-56942 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 0.003sec/0.000sec (0.000sec, 0.000sec) (0.000sec/0.001sec/1) 59B 404 "POST /_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_iAoB... HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]

13:18:05 - synapse.access.http.8008 - 508 - INFO - POST-56945 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 0.006sec/0.000sec (0.001sec, 0.001sec) (0.001sec/0.003sec/4) 1962B 200 "POST /_matrix/client/v3/keys/query HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]
13:18:05 - synapse.access.http.8008 - 508 - INFO - PUT-56948 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 0.002sec/0.000sec (0.000sec, 0.001sec) (0.000sec/0.001sec/1) 39B 200 "PUT /_matrix/client/v3/rooms/!room%3Ahost.tld/state/org.matrix.msc3401.call.member/_%40laptop%3Ahost.tld_WKIIFSXWOV?org.matrix.msc4140.delay=15000 HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]
13:18:05 - synapse.access.http.8008 - 508 - INFO - POST-56938 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 0.189sec/0.002sec (0.001sec, 0.000sec) (0.000sec/0.000sec/0) 285B 200 "POST /_matrix/client/unstable/org.matrix.simplified_msc3575/sync?pos=0%2Fs4101_147842_1_0_1_11&timeout=30000 HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:18:05 - synapse.access.http.8008 - 508 - INFO - POST-56940 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 0.155sec/0.001sec (0.004sec, 0.000sec) (0.002sec/0.001sec/1) 1389B 200 "POST /_matrix/client/unstable/org.matrix.simplified_msc3575/sync?pos=1894%2Fs4101_147842_1_0_1_11&timeout=30000 HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:18:05 - synapse.federation.sender - 594 - INFO - process_event_queue_for_federation-258 - Unexpectedly did not have cached prev group for $acqV...
13:18:05 - synapse.access.http.8008 - 508 - INFO - PUT-56947 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 0.038sec/0.001sec (0.006sec, 0.002sec) (0.003sec/0.009sec/11) 59B 200 "PUT /_matrix/client/v3/rooms/!room:host.tld/send/m.room.encrypted/216182020bbb4ec7a19a5775adf6278a HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:18:05 - synapse.access.http.8008 - 508 - INFO - GET-56944 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 0.134sec/0.000sec (0.003sec, 0.000sec) (0.004sec/0.004sec/4) 1386B 200 "GET /_matrix/client/v3/sync?filter=0&timeout=30000&org.matrix.msc4222.use_state_after=true&set_presence=online&since=s4101_1_11 HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]

13:18:08 - synapse.access.http.8008 - 508 - INFO - POST-56950 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 3.078sec/0.002sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 285B 200 "POST /_matrix/client/unstable/org.matrix.simplified_msc3575/sync?pos=0%2Fs4102_1_0_11&timeout=30000 HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:18:08 - synapse.access.http.8008 - 508 - INFO - PUT-56954 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 0.036sec/0.000sec (0.005sec, 0.001sec) (0.003sec/0.008sec/10) 59B 200 "PUT /_matrix/client/v3/rooms/!room%3Ahost.tld/send/m.room.encrypted/m1747451888188.6 HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]
13:18:08 - synapse.access.http.8008 - 508 - INFO - POST-56951 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 3.037sec/0.001sec (0.003sec, 0.000sec) (0.002sec/0.001sec/1) 1333B 200 "POST /_matrix/client/unstable/org.matrix.simplified_msc3575/sync?pos=1894%2Fs4102_1_0_11&timeout=30000 HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:18:08 - synapse.federation.sender - 594 - INFO - process_event_queue_for_federation-259 - Unexpectedly did not have cached prev group for $Qik6...
13:18:08 - synapse.push.httppusher - 241 - INFO - httppush.process-32 - Processing 1 unprocessed push actions for @mobile:host.tld/im.vector.app.android/https://ntfy.host.tld/upFBAM...?up=1 starting at stream_ordering 4095
13:18:08 - synapse.access.http.8008 - 508 - INFO - GET-56952 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 3.038sec/0.000sec (0.003sec, 0.000sec) (0.003sec/0.006sec/4) 1418B 200 "GET /_matrix/client/v3/sync?filter=0&timeout=30000&org.matrix.msc4222.use_state_after=true&set_presence=online&since=s4102_1_0_11 HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]
13:18:08 - synapse.http.client - 442 - INFO - httppush.process-32 - Received response to POST https://ntfy.host.tld/_matrix/push/v1/notify: 200
13:18:08 - synapse.storage.databases.main.event_push_actions - 1396 - INFO - rotate_notifs-19680 - Rotating notifications
13:18:08 - synapse.storage.databases.main.event_push_actions - 1599 - INFO - rotate_notifs-19680 - Rotating notifications up to: 4103
13:18:08 - synapse.storage.databases.main.event_push_actions - 1685 - INFO - rotate_notifs-19680 - Rotating notifications, handling 2 rows
13:18:08 - synapse.storage.databases.main.event_push_actions - 1770 - INFO - rotate_notifs-19680 - Rotating notifications, deleted 0 push actions
13:18:08 - synapse.util.caches.lrucache - 217 - INFO - LruCache._expire_old_entries-19680 - Dropped 0 items from caches
13:18:08 - synapse.access.http.8008 - 508 - INFO - POST-56957 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 0.029sec/0.000sec (0.008sec, 0.001sec) (0.002sec/0.013sec/13) 21081B 200 "POST /_matrix/client/unstable/org.matrix.simplified_msc3575/sync?timeout=1000 HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [11 dbevts]
13:18:09 - synapse.access.http.8008 - 508 - INFO - POST-56960 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 0.009sec/0.000sec (0.000sec, 0.000sec) (0.000sec/0.008sec/1) 2B 200 "POST /_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_aanI... HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]

13:18:10 - synapse.access.http.8008 - 508 - INFO - POST-56962 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 0.002sec/0.000sec (0.000sec, 0.000sec) (0.000sec/0.002sec/1) 2B 200 "POST /_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_uwHv... HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]
13:18:15 - synapse.access.http.8008 - 508 - INFO - POST-56963 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 0.004sec/0.000sec (0.001sec, 0.000sec) (0.000sec/0.003sec/1) 2B 200 "POST /_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_aanI... HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:18:15 - synapse.access.http.8008 - 508 - INFO - POST-56965 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 0.004sec/0.000sec (0.001sec, 0.000sec) (0.000sec/0.003sec/1) 2B 200 "POST /_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_uwHv... HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]
13:18:20 - synapse.access.http.8008 - 508 - INFO - POST-56966 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 0.004sec/0.000sec (0.001sec, 0.000sec) (0.000sec/0.003sec/1) 2B 200 "POST /_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_aanI... HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:18:20 - synapse.access.http.8008 - 508 - INFO - POST-56968 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 0.004sec/0.000sec (0.001sec, 0.000sec) (0.000sec/0.003sec/1) 2B 200 "POST /_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_uwHv... HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]
13:18:25 - synapse.access.http.8008 - 508 - INFO - POST-56969 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 0.005sec/0.000sec (0.002sec, 0.000sec) (0.000sec/0.003sec/1) 2B 200 "POST /_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_aanI... HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:18:25 - synapse.access.http.8008 - 508 - INFO - POST-56971 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 0.004sec/0.000sec (0.001sec, 0.000sec) (0.000sec/0.003sec/1) 2B 200 "POST /_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_uwHv... HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]
13:18:30 - synapse.access.http.8008 - 508 - INFO - POST-56972 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 0.008sec/0.000sec (0.002sec, 0.000sec) (0.000sec/0.007sec/1) 2B 200 "POST /_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_aanI... HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:18:30 - synapse.access.http.8008 - 508 - INFO - POST-56974 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 0.004sec/0.000sec (0.002sec, 0.000sec) (0.000sec/0.003sec/1) 2B 200 "POST /_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_uwHv... HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]
13:18:35 - synapse.access.http.8008 - 508 - INFO - POST-56975 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 0.008sec/0.000sec (0.001sec, 0.000sec) (0.000sec/0.007sec/1) 2B 200 "POST /_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_aanI... HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:18:36 - synapse.access.http.8008 - 508 - INFO - POST-56977 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 0.002sec/0.000sec (0.000sec, 0.000sec) (0.000sec/0.001sec/1) 2B 200 "POST /_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_uwHv... HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]
13:18:38 - synapse.storage.databases.main.event_push_actions - 1396 - INFO - rotate_notifs-19681 - Rotating notifications
13:18:38 - synapse.storage.databases.main.event_push_actions - 1599 - INFO - rotate_notifs-19681 - Rotating notifications up to: 4103
13:18:38 - synapse.storage.databases.main.event_push_actions - 1685 - INFO - rotate_notifs-19681 - Rotating notifications, handling 0 rows
13:18:38 - synapse.storage.databases.main.event_push_actions - 1770 - INFO - rotate_notifs-19681 - Rotating notifications, deleted 0 push actions
13:18:38 - synapse.handlers.presence - 914 - INFO - persist_presence_changes-9839 - Persisting 1 unpersisted presence updates
13:18:38 - synapse.util.caches.lrucache - 217 - INFO - LruCache._expire_old_entries-19681 - Dropped 0 items from caches
13:18:38 - synapse.access.http.8008 - 508 - INFO - POST-56956 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 30.002sec/0.000sec (0.001sec, 0.000sec) (0.000sec/0.000sec/0) 285B 200 "POST /_matrix/client/unstable/org.matrix.simplified_msc3575/sync?pos=0%2Fs4103_147842_1_0_1_11&timeout=30000 HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:18:38 - synapse.access.http.8008 - 508 - INFO - POST-56958 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 30.003sec/0.000sec (0.001sec, 0.000sec) (0.000sec/0.000sec/0) 323B 200 "POST /_matrix/client/unstable/org.matrix.simplified_msc3575/sync?pos=1894%2Fs4103_147842_1_0_1_11&timeout=30000 HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:18:38 - synapse.access.http.8008 - 508 - INFO - GET-56959 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 30.002sec/0.000sec (0.002sec, 0.000sec) (0.000sec/0.000sec/0) 401B 200 "GET /_matrix/client/v3/sync?filter=0&timeout=30000&org.matrix.msc4222.use_state_after=true&set_presence=online&since=s4103_1_11 HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]
13:18:41 - synapse.access.http.8008 - 508 - INFO - POST-56982 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 0.005sec/0.000sec (0.002sec, 0.000sec) (0.000sec/0.004sec/1) 2B 200 "POST /_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_aanI... HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:18:41 - synapse.access.http.8008 - 508 - INFO - POST-56984 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 0.004sec/0.000sec (0.001sec, 0.000sec) (0.000sec/0.003sec/1) 2B 200 "POST /_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_uwHv... HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]
13:18:46 - synapse.access.http.8008 - 508 - INFO - POST-56985 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 0.004sec/0.001sec (0.001sec, 0.000sec) (0.000sec/0.003sec/1) 2B 200 "POST /_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_aanI... HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:18:46 - synapse.access.http.8008 - 508 - INFO - POST-56987 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 0.004sec/0.000sec (0.000sec, 0.001sec) (0.000sec/0.003sec/1) 2B 200 "POST /_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_uwHv... HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]
13:18:51 - synapse.access.http.8008 - 508 - INFO - POST-56988 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 0.004sec/0.000sec (0.000sec, 0.000sec) (0.000sec/0.003sec/1) 2B 200 "POST /_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_aanI... HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:18:51 - synapse.access.http.8008 - 508 - INFO - POST-56990 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 0.004sec/0.000sec (0.000sec, 0.001sec) (0.000sec/0.003sec/1) 2B 200 "POST /_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_uwHv... HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]
13:18:54 - twisted - 279 - INFO - sentinel - Timing out client: IPv4Address(type='TCP', host='127.0.0.1', port=37440)
13:18:56 - synapse.access.http.8008 - 508 - INFO - POST-56991 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 0.004sec/0.000sec (0.001sec, 0.000sec) (0.000sec/0.003sec/1) 2B 200 "POST /_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_aanI... HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:18:57 - synapse.access.http.8008 - 508 - INFO - POST-56993 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 0.003sec/0.000sec (0.000sec, 0.000sec) (0.000sec/0.003sec/1) 2B 200 "POST /_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_uwHv... HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]
13:19:01 - synapse.access.http.8008 - 508 - INFO - POST-56994 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 0.004sec/0.000sec (0.002sec, 0.000sec) (0.000sec/0.003sec/1) 2B 200 "POST /_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_aanI... HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:19:02 - synapse.access.http.8008 - 508 - INFO - POST-56996 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 0.004sec/0.000sec (0.001sec, 0.000sec) (0.000sec/0.003sec/1) 2B 200 "POST /_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_uwHv... HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]

13:19:07 - synapse.access.http.8008 - 508 - INFO - POST-56997 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 0.004sec/0.000sec (0.001sec, 0.000sec) (0.000sec/0.003sec/1) 2B 200 "POST /_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_aanI... HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:19:07 - synapse.access.http.8008 - 508 - INFO - POST-56999 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 0.004sec/0.000sec (0.001sec, 0.000sec) (0.000sec/0.003sec/1) 2B 200 "POST /_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_uwHv... HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]
13:19:08 - synapse.storage.databases.main.event_push_actions - 1396 - INFO - rotate_notifs-19682 - Rotating notifications
13:19:08 - synapse.storage.databases.main.event_push_actions - 1599 - INFO - rotate_notifs-19682 - Rotating notifications up to: 4103
13:19:08 - synapse.storage.databases.main.event_push_actions - 1685 - INFO - rotate_notifs-19682 - Rotating notifications, handling 0 rows
13:19:08 - synapse.storage.databases.main.event_push_actions - 1770 - INFO - rotate_notifs-19682 - Rotating notifications, deleted 0 push actions
13:19:08 - synapse.util.caches.lrucache - 217 - INFO - LruCache._expire_old_entries-19682 - Dropped 0 items from caches
13:19:08 - synapse.access.http.8008 - 508 - INFO - POST-56978 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 30.003sec/0.000sec (0.002sec, 0.000sec) (0.000sec/0.000sec/0) 285B 200 "POST /_matrix/client/unstable/org.matrix.simplified_msc3575/sync?pos=0%2Fs4103_147842_1_0_1_11&timeout=30000 HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:19:08 - synapse.access.http.8008 - 508 - INFO - POST-56979 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 30.004sec/0.000sec (0.002sec, 0.000sec) (0.000sec/0.000sec/0) 323B 200 "POST /_matrix/client/unstable/org.matrix.simplified_msc3575/sync?pos=1894%2Fs4103_147842_1_0_1_11&timeout=30000 HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:19:08 - synapse.access.http.8008 - 508 - INFO - GET-56981 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 30.002sec/0.000sec (0.002sec, 0.001sec) (0.000sec/0.000sec/0) 245B 200 "GET /_matrix/client/v3/sync?filter=0&timeout=30000&org.matrix.msc4222.use_state_after=true&set_presence=online&since=s4103_0_11 HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]
13:19:12 - synapse.access.http.8008 - 508 - INFO - POST-57004 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 0.004sec/0.000sec (0.001sec, 0.000sec) (0.000sec/0.003sec/1) 2B 200 "POST /_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_aanI... HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:19:12 - synapse.access.http.8008 - 508 - INFO - POST-57006 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 0.004sec/0.000sec (0.001sec, 0.000sec) (0.000sec/0.003sec/1) 2B 200 "POST /_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_uwHv... HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]
13:19:17 - synapse.access.http.8008 - 508 - INFO - POST-57007 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 0.003sec/0.000sec (0.000sec, 0.000sec) (0.000sec/0.003sec/1) 2B 200 "POST /_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_aanI... HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:19:18 - synapse.access.http.8008 - 508 - INFO - POST-57009 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 0.005sec/0.000sec (0.001sec, 0.000sec) (0.000sec/0.004sec/1) 2B 200 "POST /_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_uwHv... HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]
13:19:22 - synapse.access.http.8008 - 508 - INFO - POST-57010 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 0.004sec/0.000sec (0.001sec, 0.000sec) (0.000sec/0.003sec/1) 2B 200 "POST /_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_aanI... HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:19:23 - synapse.access.http.8008 - 508 - INFO - POST-57012 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 0.004sec/0.000sec (0.001sec, 0.000sec) (0.000sec/0.003sec/1) 2B 200 "POST /_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_uwHv... HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]
13:19:28 - synapse.access.http.8008 - 508 - INFO - POST-57013 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 0.004sec/0.000sec (0.000sec, 0.001sec) (0.000sec/0.003sec/1) 2B 200 "POST /_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_aanI... HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:19:28 - synapse.access.http.8008 - 508 - INFO - POST-57015 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 0.004sec/0.000sec (0.001sec, 0.000sec) (0.000sec/0.003sec/1) 2B 200 "POST /_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_uwHv... HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]
13:19:33 - synapse.access.http.8008 - 508 - INFO - POST-57016 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 0.004sec/0.000sec (0.001sec, 0.000sec) (0.000sec/0.003sec/1) 2B 200 "POST /_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_aanI... HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:19:33 - synapse.access.http.8008 - 508 - INFO - POST-57018 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 0.004sec/0.000sec (0.001sec, 0.000sec) (0.000sec/0.003sec/1) 2B 200 "POST /_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_uwHv... HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]
13:19:38 - synapse.storage.databases.main.event_push_actions - 1396 - INFO - rotate_notifs-19683 - Rotating notifications
13:19:38 - synapse.storage.databases.main.event_push_actions - 1599 - INFO - rotate_notifs-19683 - Rotating notifications up to: 4103
13:19:38 - synapse.storage.databases.main.event_push_actions - 1685 - INFO - rotate_notifs-19683 - Rotating notifications, handling 0 rows
13:19:38 - synapse.storage.databases.main.event_push_actions - 1770 - INFO - rotate_notifs-19683 - Rotating notifications, deleted 0 push actions
13:19:38 - synapse.handlers.presence - 914 - INFO - persist_presence_changes-9840 - Persisting 1 unpersisted presence updates
13:19:38 - synapse.util.caches.lrucache - 217 - INFO - LruCache._expire_old_entries-19683 - Dropped 0 items from caches
13:19:38 - synapse.access.http.8008 - 508 - INFO - POST-57000 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 30.004sec/0.002sec (0.002sec, 0.000sec) (0.000sec/0.000sec/0) 285B 200 "POST /_matrix/client/unstable/org.matrix.simplified_msc3575/sync?pos=0%2Fs4103_147842_1_0_1_11&timeout=30000 HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:19:38 - synapse.access.http.8008 - 508 - INFO - POST-57001 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 30.003sec/0.001sec (0.001sec, 0.000sec) (0.000sec/0.000sec/0) 323B 200 "POST /_matrix/client/unstable/org.matrix.simplified_msc3575/sync?pos=1894%2Fs4103_147842_1_0_1_11&timeout=30000 HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:19:38 - synapse.access.http.8008 - 508 - INFO - POST-57019 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 0.003sec/0.000sec (0.000sec, 0.000sec) (0.000sec/0.003sec/1) 2B 200 "POST /_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_aanI... HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:19:38 - synapse.access.http.8008 - 508 - INFO - GET-57003 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 30.003sec/0.000sec (0.001sec, 0.000sec) (0.000sec/0.000sec/0) 245B 200 "GET /_matrix/client/v3/sync?filter=0&timeout=30000&org.matrix.msc4222.use_state_after=true&set_presence=online&since=s4103_0_11 HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]
13:19:38 - synapse.metrics._gc - 127 - INFO - sentinel - Collecting gc 1
13:19:38 - synapse.access.http.8008 - 508 - INFO - GET-57023 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 0.002sec/0.001sec (0.002sec, 0.000sec) (0.000sec/0.000sec/0) 397B 200 "GET /_matrix/client/v3/sync?filter=0&timeout=30000&org.matrix.msc4222.use_state_after=true&set_presence=online&since=s4103_0_11 HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]
13:19:38 - synapse.access.http.8008 - 508 - INFO - POST-57026 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 0.004sec/0.000sec (0.001sec, 0.000sec) (0.000sec/0.003sec/1) 2B 200 "POST /_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_uwHv... HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]

13:19:44 - synapse.access.http.8008 - 508 - INFO - POST-57029 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 0.005sec/0.000sec (0.001sec, 0.000sec) (0.000sec/0.004sec/1) 2B 200 "POST /_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_uwHv... HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]
13:19:48 - synapse.access.http.8008 - 508 - INFO - POST-57020 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 10.271sec/0.000sec (0.001sec, 0.000sec) (0.001sec/0.001sec/1) 285B 200 "POST /_matrix/client/unstable/org.matrix.simplified_msc3575/sync?pos=0%2Fs4103_147842_1_0_1_11&timeout=30000 HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:19:48 - synapse.federation.sender - 594 - INFO - process_event_queue_for_federation-260 - Unexpectedly did not have cached prev group for $VO4d...
13:19:48 - synapse.push.httppusher - 241 - INFO - httppush.process-33 - Processing 0 unprocessed push actions for @mobile:host.tld/im.vector.app.android/https://ntfy.host.tld/upFBAM...?up=1 starting at stream_ordering 4103
13:19:48 - synapse.access.http.8008 - 508 - INFO - POST-57031 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 0.049sec/0.001sec (0.006sec, 0.001sec) (0.003sec/0.017sec/12) 2B 200 "POST /_matrix/client/unstable/org.matrix.msc4140/delayed_events/syd_uwHv... HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]
13:19:48 - synapse.access.http.8008 - 508 - INFO - POST-57021 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 10.275sec/0.000sec (0.002sec, 0.000sec) (0.002sec/0.005sec/4) 2378B 200 "POST /_matrix/client/unstable/org.matrix.simplified_msc3575/sync?pos=1894%2Fs4103_147842_1_0_1_11&timeout=30000 HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:19:48 - synapse.access.http.8008 - 508 - INFO - GET-57027 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 9.941sec/0.000sec (0.003sec, 0.000sec) (0.004sec/0.006sec/7) 2425B 200 "GET /_matrix/client/v3/sync?filter=0&timeout=30000&org.matrix.msc4222.use_state_after=true&set_presence=online&since=s4103_0_11 HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]
13:19:49 - synapse.access.http.8008 - 508 - INFO - POST-57035 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 0.574sec/0.001sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 285B 200 "POST /_matrix/client/unstable/org.matrix.simplified_msc3575/sync?pos=0%2Fs4104_147844_238_2328_2929_1_279_187_0_11&timeout=30000 HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:19:49 - synapse.access.http.8008 - 508 - INFO - POST-57037 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 0.015sec/0.001sec (0.002sec, 0.001sec) (0.001sec/0.007sec/6) 2B 200 "POST /_matrix/client/v3/rooms/!room%3Ahost.tld/receipt/m.read/%24VO... HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]
13:19:49 - synapse.access.http.8008 - 508 - INFO - POST-57034 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 0.596sec/0.001sec (0.003sec, 0.000sec) (0.000sec/0.000sec/0) 512B 200 "POST /_matrix/client/unstable/org.matrix.simplified_msc3575/sync?pos=1894%2Fs4104_147844_238_2328_2929_1_279_187_0_11&timeout=30000 HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:19:49 - synapse.access.http.8008 - 508 - INFO - GET-57033 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 0.754sec/0.000sec (0.004sec, 0.000sec) (0.002sec/0.005sec/3) 736B 200 "GET /_matrix/client/v3/sync?filter=0&timeout=30000&org.matrix.msc4222.use_state_after=true&set_presence=online&since=s4104_0_11 HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]
13:19:53 - synapse.access.http.8008 - 508 - INFO - POST-57041 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 3.513sec/0.001sec (0.002sec, 0.000sec) (0.001sec/0.001sec/1) 285B 200 "POST /_matrix/client/unstable/org.matrix.simplified_msc3575/sync?pos=0%2Fs4104_147844_238_2329_2929_1_279_187_0_11&timeout=30000 HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:19:53 - synapse.federation.sender - 594 - INFO - process_event_queue_for_federation-261 - Unexpectedly did not have cached prev group for $mA4g...
13:19:53 - synapse.access.http.8008 - 508 - INFO - POST-57040 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 3.548sec/0.000sec (0.002sec, 0.000sec) (0.002sec/0.004sec/4) 1906B 200 "POST /_matrix/client/unstable/org.matrix.simplified_msc3575/sync?pos=1894%2Fs4104_147844_238_2329_2929_1_279_187_0_11&timeout=30000 HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:19:53 - synapse.access.http.8008 - 508 - INFO - GET-57039 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 3.653sec/0.000sec (0.002sec, 0.000sec) (0.002sec/0.005sec/7) 1953B 200 "GET /_matrix/client/v3/sync?filter=0&timeout=30000&org.matrix.msc4222.use_state_after=true&set_presence=online&since=s4104_0_11 HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]
13:20:03 - synapse.access.http.8008 - 508 - INFO - POST-57044 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 9.306sec/0.001sec (0.002sec, 0.000sec) (0.000sec/0.000sec/0) 285B 200 "POST /_matrix/client/unstable/org.matrix.simplified_msc3575/sync?pos=0%2Fs4105_1_0_11&timeout=30000 HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:20:03 - synapse.access.http.8008 - 508 - INFO - POST-57047 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 0.014sec/0.001sec (0.004sec, 0.000sec) (0.001sec/0.007sec/6) 2B 200 "POST /_matrix/client/v3/rooms/!room%3Ahost.tld/receipt/m.read/%24mA... HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]
13:20:03 - synapse.access.http.8008 - 508 - INFO - POST-57045 - 1.2.3.4 - 8008 - {@mobile:host.tld} Processed request: 9.250sec/0.001sec (0.001sec, 0.000sec) (0.000sec/0.000sec/0) 512B 200 "POST /_matrix/client/unstable/org.matrix.simplified_msc3575/sync?pos=1894%2Fs4105_1_0_11&timeout=30000 HTTP/1.1" "Element X/25.04.3 (Android 15; 2025050700; Sdk d36b2a686)" [0 dbevts]
13:20:03 - synapse.access.http.8008 - 508 - INFO - GET-57043 - 1.2.3.4 - 8008 - {@laptop:host.tld} Processed request: 9.378sec/0.000sec (0.003sec, 0.000sec) (0.002sec/0.005sec/3) 736B 200 "GET /_matrix/client/v3/sync?filter=0&timeout=30000&org.matrix.msc4222.use_state_after=true&set_presence=online&since=s4105_1_0_11 HTTP/1.1" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko)" [0 dbevts]
13:20:08 - synapse.storage.databases.main.event_push_actions - 1396 - INFO - rotate_notifs-19684 - Rotating notifications
13:20:08 - synapse.storage.databases.main.event_push_actions - 1599 - INFO - rotate_notifs-19684 - Rotating notifications up to: 4105
13:20:08 - synapse.storage.databases.main.event_push_actions - 1685 - INFO - rotate_notifs-19684 - Rotating notifications, handling 0 rows
13:20:08 - synapse.storage.databases.main.event_push_actions - 1770 - INFO - rotate_notifs-19684 - Rotating notifications, deleted 0 push actions
13:20:08 - synapse.util.caches.lrucache - 217 - INFO - LruCache._expire_old_entries-19684 - Dropped 0 items from caches

Notes for delayed events:

Delayed events for "syd_aanI..." (mobile) start at 13:17:59 and continue roughly every 5 seconds until 13:19:38. Delayed events for "syd_uwHv..." (laptop) start at 13:18:10 and continue roughly every 5 seconds until 13:19:48.

ciyam avatar May 17 '25 08:05 ciyam

Same problem here. After a few seconds being in the conference with iOS and Mac OS the iOS app quits with this RTCSession error:

Image

This is the domain for the synapse-server and not for my livekit-server. Is it a synapse problem?

opa-rudi avatar May 21 '25 20:05 opa-rudi

Same problem here. After a few seconds being in the conference with iOS and Mac OS the iOS app quits with this RTCSession error:

Image This is the domain for the synapse-server and not for my livekit-server. Is it a synapse problem?

are you using synapse workers?

fkwp avatar May 21 '25 20:05 fkwp

Currently not. I am hosting only approx. 10 accounts.

opa-rudi avatar May 21 '25 22:05 opa-rudi

Same problem here. After a few seconds being in the conference with iOS and Mac OS the iOS app quits with this RTCSession error:

Image This is the domain for the synapse-server and not for my livekit-server. Is it a synapse problem?

I am seeing the same error on the mobile apps(ios and android) on selfhosted installation of matrix and element-call what is it related to.. i am not using synapse workers

jskyfacts avatar May 30 '25 09:05 jskyfacts

Your client needs to send a keep alive request every X seconds to let the server know they are still able to participate in the call. There can be any possible network or connection issue that results in the client failing the send this request. It might be a good idea to increase delayedLeaveEventDelayMs and decrease delayedLeaveEventRestartMs. It is surprising however, that you claim to have a very solid and stable network connection. Maybe there is another issue that prohibits the widget to send the delayed event. But since you say sometimes it works for multiple minutes the delayed events have to work in most cases.

toger5 avatar May 30 '25 14:05 toger5

We found that disabling the new MembershipManager via Developer mode on Element X on Android stopped the RTC error happening. We still need to work out why this helped, but passing on this info as it may help

joolsr avatar May 30 '25 16:05 joolsr

We found that disabling the new MembershipManager via Developer mode on Element X on Android stopped the RTC error happening.

I am not sure how to find this "option?" - I've tapped seven times and have the Developer Options menu but I see nothing about MembershipManager - am I missing something obvious?

Also - since a new update to Element-X (202505002) it no longer even connects to livekit-jwt (just dies as soon as I click on the Video icon) so I am getting very close to the point of just removing Element-X and waiting a couple of years before trying it again (as there is no way that this software can replace the old version of Element at the current rate that it is going backwards).

ciyam avatar May 30 '25 22:05 ciyam

We found that disabling the new MembershipManager via Developer mode on Element X on Android stopped the RTC error happening.

I am not sure how to find this "option?" - I've tapped seven times and have the Developer Options menu but I see nothing about MembershipManager - am I missing something obvious?

Also - since a new update to Element-X (202505002) it no longer even connects to livekit-jwt (just dies as soon as I click on the Video icon) so I am getting very close to the point of just removing Element-X and waiting a couple of years before trying it again (as there is no way that this software can replace the old version of Element at the current rate that it is going backwards).

I suggest you try 25.04.03 version as this is the most solid version for me for calls and notification.

escix avatar May 31 '25 00:05 escix