Synapse main worker locks up in sync_partial_state_room while persisting outliers

ggogel commented 4 months ago

Description

I've noticed an issue on my homeserver when joining some large public rooms. I tested several rooms.

These rooms are causing the issue:

fdroid:f-droid.org
ecips:matrix.org
ipfs-chatter:ipfs.io

Joining these similar large rooms works fine:

jellyfin-troubleshooting:matrix.org
jellyfin:matrix.org
kubernetes:matrix.org

First, the homeserver starts the partial sync and gets the state events from another homeserver. This works fine. Then it starts persisting these events. Shortly after, the main worker locks up, blocking any incoming connection. Persisting x remaining outliers is logged, then the log stops.

I first noticed this because the main worker was constantly killed by Kubernetes due to the liveness probe set on /health. I tried to remove the liveness probe but even after 30 minutes, it didn't finish persisting the events.

All clients lose connection to the server.

Steps to reproduce

Join one of the large public rooms listed above

Homeserver

gogel.me

Synapse Version

1.100.0

Installation Method

Docker (matrixdotorg/synapse)

Database

PostgreSQL (single server on K8s)

I migrated from SQLite years ago

Workers

Multiple workers

Platform

Kubernetes Helm chart: https://artifacthub.io/packages/helm/ananace-charts/matrix-synapse values.yaml

matrix-synapse:
  serverName: gogel.me
  publicServerName: matrix.gogel.me
  enable_registration: false
  ingress:
    annotations:
      nginx.ingress.kubernetes.io/use-regex: "true"
      nginx.ingress.kubernetes.io/proxy-body-size: 50m
      kubernetes.io/ingress.class: nginx
      nginx.ingress.kubernetes.io/upstream-hash-by: $http_x_forwarded_for
  extraConfig:
    max_upload_size: 50M
    media_retention:
      remote_media_lifetime: 30d
    turn_uris: [ "turn:turn.gogel.me:3478?transport=udp", "turn:turn.gogel.me:3478?transport=tcp" ]
    turn_shared_secret: "xxxxxxx"
    turn_user_lifetime: 86400000
    turn_allow_guests: true
    email:
      smtp_host: xxxxxxxx
      smtp_port: 587
      smtp_user: xxxxxx
      smtp_pass: xxxxxxxx
      require_transport_security: true
      notif_from: "%(app)s homeserver <xxxx@gogel.me>"
      app_name: matrix.gogel.me
  postgresql:
    enabled: true
    auth:
      password: xxxx
      username: xxxxx
      database: xxxxx
    primary:
      initdb:
        args: "--lc-collate=C --lc-ctype=C"
      persistence:
        size: 64Gi
      extendedConfiguration: |-
        shared_buffers = 8GB
        effective_cache_size = 16GB
        work_mem = 128MB
        maintenance_work_mem = 2GB
        autovacuum_work_mem = 1GB
        max_connections = 200
  persistence:
    enabled: true
    accessMode: ReadWriteOnce
    size: 64Gi
  signingkey:
    job:
      enabled: false
    existingSecret: matrix-synapse-signingkey
    existingSecretKey: signing.key
  workers:
    default:
      replicaCount: 3
    generic_worker:
      enabled: true
    media_repository:
      enabled: true
      listeners: [media]
      replicaCount: 1
      strategy:
        type: "Recreate"
      csPaths:
        - "/_matrix/media/.*"
        - "/_synapse/admin/v1/purge_media_cache$"
        - "/_synapse/admin/v1/room/.*/media"
        - "/_synapse/admin/v1/user/.*/media"
        - "/_synapse/admin/v1/media/"
        - "/_synapse/admin/v1/quarantine_media/"
        - "/_synapse/admin/v1/users/.*/media$"
      paths:
        - "/_matrix/media/.*"
  synapse:
    strategy:
      type: "Recreate"
    startupProbe:
      failureThreshold: 30
      tcpSocket:
        port: 8008
      httpGet: null
      periodSeconds: 1
      successThreshold: 1
      timeoutSeconds: 1
    readinessProbe: null
    livenessProbe: null

Configuration

No unusual or experimental config options. No synapse modules. See the provided values.yaml.

Relevant log output

2024-02-09 15:59:16,108 - synapse.handlers.federation_event - 1690 - INFO - sync_partial_state_room-2-$aCnx8OjNdO_Fd74ZxCQEI1EXwqLkr0OynU0yD7akAGE-$pH9lk8e5fzXCbafTDdlIIXWZrx9pEhWnib0NKX6dj4U- Persisting 136364 remaining outliers: ['$--1iDJXV5FvFrdT60dRrgMQIYQXBbSyCyLDAUHsVJYQ', '$--UdJrmHk606c69XoQ0UkIhQXOAzOm1FMBnw03j5yv4', '$-0JOiFZFWU3j_8UgNrxXHewWd2Kotvhg5FOw8P9AXR8', '$-0NJlSuAyk3HLJrC-cRB61OioZvp7P3O4Cq0pi1OHAk', '$-187dTMhg_EUlD7SVyP3b1U-8Lf5pAubXNF7-odcKcM', ...]

Anything else that would be useful to know?

No response

ggogel commented 4 months ago

I investigated the issue a bit more. All of these rooms have in common that the partial room sync already receives 100k+ state events. Then almost all of these events are classified as outliers. Outliers are described here https://github.com/element-hq/synapse/blob/7c805f00a787b53b0eacddb9cb4b5470b9c8d135/docs/development/room-dag-concepts.md?plain=1#L33-L71

The relevant lines of code are here: https://github.com/element-hq/synapse/blob/7c805f00a787b53b0eacddb9cb4b5470b9c8d135/synapse/handlers/federation_event.py#L1642-L1770

I also found this very recent PRs: https://github.com/matrix-org/synapse/pull/16649 It was released with 1.97.0

https://github.com/element-hq/synapse/issues/16788 https://github.com/element-hq/synapse/pull/7 Both released with 1.100.0

I'm asking myself:

Why does a partial sync contain so many events?
Why are almost all of them considered outliers?
Why is persisting these outliers a blocking operation?
Implications on the security and reliability of a server if a user knowingly or unknowingly joins those rooms

ggogel commented 4 months ago

I just downgraded to version 1.99.0 and this fixed the issue. For testing, I joined the room #fdroid:f-droid.org. Joining still takes long but the main worker doesn't lock up when persisting outliers. The server is still responsive and other messages are still logged. I can send and receive messages on my client. The worst thing I monitored were response times of 10s on /health for about a minute. Compared to 1.100.0, where the main worker locks up completely. As described earlier, I waited 30 minutes before killing the main worker.

The log (filtered for sync_partial_state_room) looks like this now. Persisting is done in batches :

2024-02-10 17:44:57,880 - synapse.handlers.federation_event - 1697 - INFO - sync_partial_state_room-0-$cJlGI6g4DoQuzmgPipStdVtxBZBnrAYNI0nYnwlGC_I-$O7bZrEXXudaPA8sI1QzUkHXH4LXxyuinqpEWJlCppiA- Persisting 3085 of 136478 remaining outliers: ['$7tDgmqoTHVLYEtsBQl9ievJ76WqOPB9UITII6vuyplc', '$RnIy9dIhwZZTOTsTUZgQfLvqC41sX7lCicMC3tCwGE8', '$jnT6VX0k9V3-G3PNfyG-sO2FHweYHJW2wu5mY4WEYHs', '$qkp3GFD13Jl1NNDuDZcKB7GB8uWvZEcMx7R4KUrTyqE', '$C6ZwWFbQVJHewg7FIJlo7ZvWdrS78LFeMDwi0W1iuEA', ...]
2024-02-10 17:45:08,272 - synapse.handlers.federation_event - 1697 - INFO - sync_partial_state_room-0-$cJlGI6g4DoQuzmgPipStdVtxBZBnrAYNI0nYnwlGC_I-$O7bZrEXXudaPA8sI1QzUkHXH4LXxyuinqpEWJlCppiA- Persisting 1905 of 136478 remaining outliers: ['$A9v-WT9-zCcZiRkVA0Y1uvGS3-Betx4bCJcPNMiLzxM', '$xTy5-gf1x8Jz4h3-gkLAZjLDiDfmKBHiyMIe_mIp_Og', '$Zmi4sfDgoMos5Nf5fowstIxTYgro11o9w1fd7I5EE8k', '$VfG5eEP_v2FXuinw6z_vNUrQ-iU5A3LTxbymncswCnY', '$bzvz38T1VuxnV8-4Q4MZ-VLICg3M32eDLPkkMoxaPKs', ...]
2024-02-10 17:45:14,483 - synapse.handlers.federation_event - 1697 - INFO - sync_partial_state_room-0-$cJlGI6g4DoQuzmgPipStdVtxBZBnrAYNI0nYnwlGC_I-$O7bZrEXXudaPA8sI1QzUkHXH4LXxyuinqpEWJlCppiA- Persisting 1699 of 136478 remaining outliers: ['$coCJZymEOpKhbCIziUurHgIZ1r9F05WFT-GlrbsnrRA', '$9YU7C1llhT37pEbsWcOaAe9lHegYAR6pf66994WVsr0', '$kEH92bXuPLHmLN19hKedPz5C9q23R6VOVjWr05JXGwQ', '$GtjeupXya7mpYsYNGEBWWv47wkjrzzML7VTM2m3yx4M', '$C-YYzkKftthGi7cu0S69wwxA-5cLwFe9QR8P4TA_Hng', ...]
2024-02-10 17:45:19,487 - synapse.handlers.federation_event - 1697 - INFO - sync_partial_state_room-0-$cJlGI6g4DoQuzmgPipStdVtxBZBnrAYNI0nYnwlGC_I-$O7bZrEXXudaPA8sI1QzUkHXH4LXxyuinqpEWJlCppiA- Persisting 1368 of 136478 remaining outliers: ['$K6BPTNueB7Slfw26OPje0zI7BedxF6z1bj-zxGNYdI4', '$pf2YtUNapZrxbVZasC9rLmVIrKdEvCBvTb8lSjwmveU', '$sNhOrmyNnFKg8WpwHIXmn3hxppWLO69lXzv_tTA9gjw', '$8_seRoiCi2yJKNJzlJ85Ge2376n1cCerTc5NBQozM2s', '$crGLvHUG64ORv-R0LH7FP4QL4XrsPyeSY6adSXrt-gg', ...]
2024-02-10 17:45:23,787 - synapse.handlers.federation_event - 1697 - INFO - sync_partial_state_room-0-$cJlGI6g4DoQuzmgPipStdVtxBZBnrAYNI0nYnwlGC_I-$O7bZrEXXudaPA8sI1QzUkHXH4LXxyuinqpEWJlCppiA- Persisting 1285 of 136478 remaining outliers: ['$noadwZ0Hbosvz3tjHkjY5OtpCQEwWrqSDQI6ST4eag8', '$gDn1VKQApzQ1poi2BrNMNdVI8GftjWLoCbKi2NAgXHc', '$WPLBJUlYVVEhor3doUXq_vGct8r-xkDEUG26cR6_oWE', '$6POE83FvAHVk2i5UtjWpBtooHysLF02ZBhNhn-tcUxg', '$N6RuwOsAxsQMU-Z4IUo8B8VRHPrFKZpRTsmGcXJIfo8', ...]
2024-02-10 17:45:27,471 - synapse.handlers.federation_event - 1697 - INFO - sync_partial_state_room-0-$cJlGI6g4DoQuzmgPipStdVtxBZBnrAYNI0nYnwlGC_I-$O7bZrEXXudaPA8sI1QzUkHXH4LXxyuinqpEWJlCppiA- Persisting 1101 of 136478 remaining outliers: ['$0INiXQbtCfXA_-6C8F_qv6OV0nie9yB8poIQqqKzPbs', '$3ZIMTm8dx2Y39Gk6C02E6hHl_k50rP2ayTIdPMqcK74', '$42pcwHLUJiETXX5eQslFPh6IErVUyvFA_1gjL31_EjY', '$rWc758eqDYZQ792BdyhOe9I6S-RB94tSeE1HmmHvdo0', '$ygwxKkrACEkk3LWK0F1s47r_tR9BpSNuGnMv3UAoEgc', ...]
2024-02-10 17:45:30,985 - synapse.handlers.federation_event - 1697 - INFO - sync_partial_state_room-0-$cJlGI6g4DoQuzmgPipStdVtxBZBnrAYNI0nYnwlGC_I-$O7bZrEXXudaPA8sI1QzUkHXH4LXxyuinqpEWJlCppiA- Persisting 1055 of 136478 remaining outliers: ['$H0QLZFrf8tgV_MZ-TV_B9ecWwwcAKRDPCH3MbQPZ_tQ', '$vOwao7sI5C58M6dIyXPk7XdVQoO6teyh0K5ctyD4cAY', '$k07_2I5nzrsGzq4IDzVMdyc5Rm3QJ5Yst2kZi8f1jyo', '$OS57htfXaxZ2ZQPjCseL2gwlAoiVYOigu3Z4VWncaMI', '$Gesx00_G4NRGwgwUHeppnvbLRX8wLbXn0d5rA9T-obM', ...]
2024-02-10 17:45:34,326 - synapse.handlers.federation_event - 1697 - INFO - sync_partial_state_room-0-$cJlGI6g4DoQuzmgPipStdVtxBZBnrAYNI0nYnwlGC_I-$O7bZrEXXudaPA8sI1QzUkHXH4LXxyuinqpEWJlCppiA- Persisting 921 of 136478 remaining outliers: ['$yBR-l_TKd71PYpTzlyA3_SWIXBOWTgwKxlkFocRAQBU', '$SpXbgJFkjjp-M5b_waPJo2nc13Lz8KM9kC0C6O1ZdPk', '$bx7Bkl3_9jMagPveQXs6uAAJtFHf__d70kt84g80Pjg', '$dPnWUA1ji1FqSsNKsO0diRa8N3IqnFnhNhRtYlCWrbs', '$ZLmHyJBq4hhKGC6BsJASI6aGtu-d6Yy0_risqJOLBac', ...]
2024-02-10 17:45:37,323 - synapse.handlers.federation_event - 1697 - INFO - sync_partial_state_room-0-$cJlGI6g4DoQuzmgPipStdVtxBZBnrAYNI0nYnwlGC_I-$O7bZrEXXudaPA8sI1QzUkHXH4LXxyuinqpEWJlCppiA- Persisting 907 of 136478 remaining outliers: ['$fxsFX0ltFzNceB5_4T4ybgOQURFj4wZ7hZA9O6nIFIc', '$gsgrZDPxefo7KouDwOqOUuRQ8tKL8AL71-8VyeFk96U', '$vh0nTZeZjWly46cTbvGm7VeSaaQpxO-iHuORaRZBODk', '$XdrFSRO3rBN8IO1SHWijRbuUwwmnmoB15n2IhtH8iTo', '$cPAaJSK38t-AySKwxhiOSPsqW7WnhWXohv4Vi2M8N5Q', ...]
2024-02-10 17:45:39,975 - synapse.handlers.federation_event - 1697 - INFO - sync_partial_state_room-0-$cJlGI6g4DoQuzmgPipStdVtxBZBnrAYNI0nYnwlGC_I-$O7bZrEXXudaPA8sI1QzUkHXH4LXxyuinqpEWJlCppiA- Persisting 827 of 136478 remaining outliers: ['$9QcON6K3iuQaloPXsWshf2vzcKsNMUW4qvCDgJfZDZw', '$wIYfGAfWTIXAK5PRG8Bjxs0WaHYLwRsGd1fNPnkiTow', '$hPwd0lPqfsbKFRv2vIKexf842I1K-AibxPq_1ftZW-U', '$eD5A6FDqERjWFTKhmZyrEMwehZzy0iO_C2IJWcSbcys', '$FCOdsjaUrmNy9aL1XHFUUAK03DQj1PEXDS2wh1PtOWA', ...]

It appears that the changes in #7 released in version 1.100.0 are responsible for this issue. Persisting seems to be a blocking operation and therefore batch-processing was probably the better solution.

@erikjohnston I'm pinging you because these PRs came from you. Can you have a look at this, please?

erikjohnston commented 4 months ago

Oh, hmm. Thanks. My guess is that it has maxed out CPU and so is blocking the reactor from progressing. The solution is to probably periodically yield while handling all the events. https://github.com/element-hq/synapse/pull/16903 is an attempt to do just that, would be interested if you can test it to see if it helps.

ggogel commented 4 months ago

Thanks for the reply.

CPU wasn't a bottleneck. I only monitored CPU usage of 1 CPU from the main worker. The node was at about 1.6 out of 8 CPUs. If anything I/O was the bottleneck.

I'll try to test #16903 later. Is there a container image that I can pull or do I need to build it myself?

I'm also wondering why the old solution with the batches was discarded. I tested several rooms and didn't have any issues and it was quite fast.

erikjohnston commented 4 months ago

CPU wasn't a bottleneck. I only monitored CPU usage of 1 CPU from the main worker. The node was at about 1.6 out of 8 CPUs. If anything I/O was the bottleneck.

Oh, interesting. Usually when Synapse "deadlocks" it means that the main thread has become blocked spinning lots of CPU.

If you can reproduce I'd be interested in the output of running https://github.com/benfred/py-spy (if possible) against it. That will tell us what it's doing. Alternatively (or as well) temporarily setting the log level to DEBUG might show what it is actually doing (though don't share it publicly, debug logs can contain sensitive information).

I'll try to test #16903 later. Is there a container image that I can pull or do I need to build it myself?

Thanks. I'm afraid there aren't any prebuilt containers for it.

I'm also wondering why the old solution with the batches was discarded. I tested several rooms and didn't have any issues and it was quite fast.

The problem was that in the previous version the "batching" aspect wasn't intentional, and so it sometime got into a perverse situation where it was doing one event at a time (which was then very slow).

ggogel commented 4 months ago

CPU wasn't a bottleneck. I only monitored CPU usage of 1 CPU from the main worker. The node was at about 1.6 out of 8 CPUs. If anything I/O was the bottleneck.

Oh, interesting. Usually when Synapse "deadlocks" it means that the main thread has become blocked spinning lots of CPU.

If you can reproduce I'd be interested in the output of running https://github.com/benfred/py-spy (if possible) against it. That will tell us what it's doing. Alternatively (or as well) temporarily setting the log level to DEBUG might show what it is actually doing (though don't share it publicly, debug logs can contain sensitive information).

Which command of py spy would help to debug it?

erikjohnston commented 4 months ago

We use: py-spy record -o flame.svg --nonblocking --gil --duration 30 --pid <PID>

ggogel commented 4 months ago

I've tested it. First of all I wasn't able to run py-spy in a Kubernetes Pod. The OS didn't seem happy about that:

py-spy record -o flame.svg --nonblocking --gil --duration 30 --pid 1
Error: Operation not permitted (os error 1)
Reason: Operation not permitted (os error 1)

First I joined the room #fdroid:f-droid.org again and there were no problems. Although the amount of synced events was much less even though the room copy seemed to be deleted from the server.

Logs filtered for "partial":

2024-02-12 13:14:59,753 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$eKTRVAHe0GUmhGlvQqwQAQPpkrJVzWN_cHVz-mIMVUk- {GET-O-1399} [f-droid.org] Completed request: 200 OK in 0.55 secs, got 899 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24eKTRVAHe0GUmhGlvQqwQAQPpkrJVzWN_cHVz-mIMVUk
2024-02-12 13:14:59,760 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$iv3O3GZeW04W3Zp0vPE3u-iUAhMzqZx6U_TgDdpQSE8- {GET-O-1400} [f-droid.org] Completed request: 200 OK in 0.55 secs, got 879 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24iv3O3GZeW04W3Zp0vPE3u-iUAhMzqZx6U_TgDdpQSE8
2024-02-12 13:14:59,765 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$3g0Md52SjHq60E70phscUQjdkNtrO-zJlJb-QqfJpsE- {GET-O-1397} [f-droid.org] Completed request: 200 OK in 0.58 secs, got 848 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%243g0Md52SjHq60E70phscUQjdkNtrO-zJlJb-QqfJpsE
2024-02-12 13:14:59,775 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$9Y61I9zsAbhl4-73t9v2Kx15c6ftJIGoocuiL2qcGvw- {GET-O-1398} [f-droid.org] Completed request: 200 OK in 0.57 secs, got 883 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%249Y61I9zsAbhl4-73t9v2Kx15c6ftJIGoocuiL2qcGvw
2024-02-12 13:14:59,791 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$PfPOlkP-T9jiTFvCANaVs1JvNhuJDtl-SpZhWA-pqJs- {GET-O-1402} [f-droid.org] Completed request: 200 OK in 0.04 secs, got 871 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24PfPOlkP-T9jiTFvCANaVs1JvNhuJDtl-SpZhWA-pqJs
2024-02-12 13:14:59,799 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$XAUOsQNvdGcD5NjbybmdVuy7YCdx7_YbRa8dwh6WyyY- {GET-O-1401} [f-droid.org] Completed request: 200 OK in 0.58 secs, got 881 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24XAUOsQNvdGcD5NjbybmdVuy7YCdx7_YbRa8dwh6WyyY
2024-02-12 13:14:59,856 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$kehH95K823fE6-JvaQXgpKjyOq0DpwaUvqY96Ul_zrc- {GET-O-1405} [f-droid.org] Completed request: 200 OK in 0.08 secs, got 869 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24kehH95K823fE6-JvaQXgpKjyOq0DpwaUvqY96Ul_zrc
2024-02-12 13:14:59,857 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$LF_lSpy8jqUiNhnuYw2NiDlMqGC-Ll0ClLa1TcnWkmI- {GET-O-1403} [f-droid.org] Completed request: 200 OK in 0.10 secs, got 875 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24LF_lSpy8jqUiNhnuYw2NiDlMqGC-Ll0ClLa1TcnWkmI
2024-02-12 13:14:59,858 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$gSRhhMgRHJEmXOmZ4hQStWLWAT5HMV7kIeYvJWjUEYA- {GET-O-1404} [f-droid.org] Completed request: 200 OK in 0.09 secs, got 884 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24gSRhhMgRHJEmXOmZ4hQStWLWAT5HMV7kIeYvJWjUEYA
2024-02-12 13:15:00,363 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$atPmXN81-QHdXjiU5GGzF5S-JmTm4_2OlXyo1QndXz0- {GET-O-1406} [f-droid.org] Completed request: 200 OK in 0.57 secs, got 863 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24atPmXN81-QHdXjiU5GGzF5S-JmTm4_2OlXyo1QndXz0
2024-02-12 13:15:00,376 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$5mO0l5CoB06T5MgrB5MjVT86P1PPCR5tmO6Ts_wQwgY- {GET-O-1407} [f-droid.org] Completed request: 200 OK in 0.58 secs, got 884 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%245mO0l5CoB06T5MgrB5MjVT86P1PPCR5tmO6Ts_wQwgY
2024-02-12 13:15:00,422 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$skaTZtOnn5xMjRMFiXuNyss4rfsL8vTK0mefYK2RMdA- {GET-O-1409} [f-droid.org] Completed request: 200 OK in 0.56 secs, got 871 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24skaTZtOnn5xMjRMFiXuNyss4rfsL8vTK0mefYK2RMdA
2024-02-12 13:15:00,426 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$Ty7xramZjNYL_4jzh5E24QuzxcQm1X6T14GDo0nGi4g- {GET-O-1411} [f-droid.org] Completed request: 200 OK in 0.06 secs, got 961 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24Ty7xramZjNYL_4jzh5E24QuzxcQm1X6T14GDo0nGi4g
2024-02-12 13:15:00,436 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$S1bu0wwFoUcPeO9tCrCT--SexpWNG373QD0MAegKNeo- {GET-O-1410} [f-droid.org] Completed request: 200 OK in 0.58 secs, got 883 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24S1bu0wwFoUcPeO9tCrCT--SexpWNG373QD0MAegKNeo
2024-02-12 13:15:00,438 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$P2M8qBrdfp0mEY-5rOzOpYycTPjM9ni4xgSY4qYdJOQ- {GET-O-1408} [f-droid.org] Completed request: 200 OK in 0.58 secs, got 883 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24P2M8qBrdfp0mEY-5rOzOpYycTPjM9ni4xgSY4qYdJOQ
2024-02-12 13:15:00,924 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$B_hAWGJT8iDdDAwcaAgzfYfdoD_j8OKqleIrTj-jhr0- {GET-O-1412} [f-droid.org] Completed request: 200 OK in 0.55 secs, got 884 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24B_hAWGJT8iDdDAwcaAgzfYfdoD_j8OKqleIrTj-jhr0
2024-02-12 13:15:00,957 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$HC9sOdbNnkne3VseLFQtbP9JznFOuDKPrIYeDcugSnM- {GET-O-1413} [f-droid.org] Completed request: 200 OK in 0.53 secs, got 870 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24HC9sOdbNnkne3VseLFQtbP9JznFOuDKPrIYeDcugSnM
2024-02-12 13:15:00,994 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$rplbnsf6DPjGb6CuyUCsz6C5vDNIi8pl5b7GfMxGKiY- {GET-O-1417} [f-droid.org] Completed request: 200 OK in 0.07 secs, got 884 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24rplbnsf6DPjGb6CuyUCsz6C5vDNIi8pl5b7GfMxGKiY
2024-02-12 13:15:01,020 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$SEnTU8R2NVJjiU28CIxhXnswhSpGapvMlhfDbXd202A- {GET-O-1414} [f-droid.org] Completed request: 200 OK in 0.59 secs, got 877 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24SEnTU8R2NVJjiU28CIxhXnswhSpGapvMlhfDbXd202A
2024-02-12 13:15:01,021 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$55xBNicIe5QqRrqXXAQRH1zIW9-uDwUSxmDT6o3ekdA- {GET-O-1416} [f-droid.org] Completed request: 200 OK in 0.58 secs, got 765 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%2455xBNicIe5QqRrqXXAQRH1zIW9-uDwUSxmDT6o3ekdA
2024-02-12 13:15:01,031 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$AXIIloW1Bup3kOYfijvBGELOhAFBxe2qFVZU-1C-ots- {GET-O-1415} [f-droid.org] Completed request: 200 OK in 0.59 secs, got 884 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24AXIIloW1Bup3kOYfijvBGELOhAFBxe2qFVZU-1C-ots
2024-02-12 13:15:01,072 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$5Vl-OAkanra5q6yXcAEX55bHtmLAw36qtMm43XOu8oI- {GET-O-1418} [f-droid.org] Completed request: 200 OK in 0.11 secs, got 956 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%245Vl-OAkanra5q6yXcAEX55bHtmLAw36qtMm43XOu8oI
2024-02-12 13:15:01,076 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$-77GIzhJ6S9YO5X-hoeCZfGUMw8XJD5dllYqPoIxglA- {GET-O-1419} [f-droid.org] Completed request: 200 OK in 0.08 secs, got 927 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24-77GIzhJ6S9YO5X-hoeCZfGUMw8XJD5dllYqPoIxglA
2024-02-12 13:15:01,082 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$yT_zX9lh70_IjAidvumF_DmQLwtlyRmJ6jQ1rVoohVE- {GET-O-1421} [f-droid.org] Completed request: 200 OK in 0.06 secs, got 884 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24yT_zX9lh70_IjAidvumF_DmQLwtlyRmJ6jQ1rVoohVE
2024-02-12 13:15:01,633 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$8uR-sadSmb13x4KIdgKACl9P8VLgyC9GT2cNOLsy1J0- {GET-O-1420} [f-droid.org] Completed request: 200 OK in 0.61 secs, got 902 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%248uR-sadSmb13x4KIdgKACl9P8VLgyC9GT2cNOLsy1J0
2024-02-12 13:15:01,644 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$JQHb1B1JirQwr9_k6iU2giy3xj3SxZRr3pVaRNp5VCI- {GET-O-1422} [f-droid.org] Completed request: 200 OK in 0.61 secs, got 878 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24JQHb1B1JirQwr9_k6iU2giy3xj3SxZRr3pVaRNp5VCI
2024-02-12 13:15:01,646 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$yA8anlUHp5tp4l4Bkv5PtSoN8MXTTBU0eIYavZot4vI- {GET-O-1425} [f-droid.org] Completed request: 200 OK in 0.56 secs, got 871 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24yA8anlUHp5tp4l4Bkv5PtSoN8MXTTBU0eIYavZot4vI
2024-02-12 13:15:01,687 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$aeEAzxxvAIggvzRiIkqpyKdBDbPsGZ5sKKmpiku_gBg- {GET-O-1423} [f-droid.org] Completed request: 200 OK in 0.61 secs, got 884 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24aeEAzxxvAIggvzRiIkqpyKdBDbPsGZ5sKKmpiku_gBg
2024-02-12 13:15:01,689 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$W5mpKrWEzNA-yif3XdNVY6ulOIfh8sGtUVg-5y01AZU- {GET-O-1424} [f-droid.org] Completed request: 200 OK in 0.61 secs, got 875 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24W5mpKrWEzNA-yif3XdNVY6ulOIfh8sGtUVg-5y01AZU
2024-02-12 13:15:01,717 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$5qE1DJ_SZbJXwd8oGB-6qibwKI1ByGPMyMSBis4K6S4- {GET-O-1426} [f-droid.org] Completed request: 200 OK in 0.08 secs, got 884 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%245qE1DJ_SZbJXwd8oGB-6qibwKI1ByGPMyMSBis4K6S4
2024-02-12 13:15:02,253 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$-FNr61pSjgVLTAUIOOpASJg8Fwph3goZNeQ3gTqnx78- {GET-O-1428} [f-droid.org] Completed request: 200 OK in 0.61 secs, got 863 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24-FNr61pSjgVLTAUIOOpASJg8Fwph3goZNeQ3gTqnx78
2024-02-12 13:15:02,255 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$F8L8GEO7-dylr3SGjJ0qREjGQv8gGd4ElWvRBpWcC58- {GET-O-1427} [f-droid.org] Completed request: 200 OK in 0.61 secs, got 884 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24F8L8GEO7-dylr3SGjJ0qREjGQv8gGd4ElWvRBpWcC58
2024-02-12 13:15:02,292 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$FXebCpnpjr2Octw4C_sXbhOsfKGG5cbO20RWhn4q8OQ- {GET-O-1429} [f-droid.org] Completed request: 200 OK in 0.60 secs, got 877 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24FXebCpnpjr2Octw4C_sXbhOsfKGG5cbO20RWhn4q8OQ
2024-02-12 13:15:02,303 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$T3G0dSbmDa4KfNn8ejrSDoJtzWFeps8yCjs3kgBk3QA- {GET-O-1430} [f-droid.org] Completed request: 200 OK in 0.61 secs, got 865 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24T3G0dSbmDa4KfNn8ejrSDoJtzWFeps8yCjs3kgBk3QA
2024-02-12 13:15:02,304 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$FzI1_egS171ZFKTXNyHW5Wzxki1NEcjkgdIjROqaLvc- {GET-O-1431} [f-droid.org] Completed request: 200 OK in 0.59 secs, got 884 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24FzI1_egS171ZFKTXNyHW5Wzxki1NEcjkgdIjROqaLvc
2024-02-12 13:15:02,305 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$IWfGUqsOkM7u871oVhCuAq8SNyisE41MB3XMcgklt0E- {GET-O-1432} [f-droid.org] Completed request: 200 OK in 0.05 secs, got 887 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24IWfGUqsOkM7u871oVhCuAq8SNyisE41MB3XMcgklt0E
2024-02-12 13:15:02,325 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$LS9bcDV6RGSfgFaF-MLGIyl8IfBe_eXswPf2tfLzT3o- {GET-O-1433} [f-droid.org] Completed request: 200 OK in 0.07 secs, got 875 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24LS9bcDV6RGSfgFaF-MLGIyl8IfBe_eXswPf2tfLzT3o
2024-02-12 13:15:02,355 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$cCru8Oc796bSZ6BTcXwkgUNkuhvBn7pU_vBB07P7NQk- {GET-O-1434} [f-droid.org] Completed request: 200 OK in 0.06 secs, got 859 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24cCru8Oc796bSZ6BTcXwkgUNkuhvBn7pU_vBB07P7NQk
2024-02-12 13:15:02,391 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$2CHGA7RYUXz_Zzb6SubbWLfk9_4yspAVoQ4XpmEQXLA- {GET-O-1435} [f-droid.org] Completed request: 200 OK in 0.09 secs, got 884 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%242CHGA7RYUXz_Zzb6SubbWLfk9_4yspAVoQ4XpmEQXLA
2024-02-12 13:15:02,863 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$81LJvMP0nM5PHEMvj4ENwMVgvGf-wJwyEbxvsoOvL0c- {GET-O-1437} [f-droid.org] Completed request: 200 OK in 0.55 secs, got 863 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%2481LJvMP0nM5PHEMvj4ENwMVgvGf-wJwyEbxvsoOvL0c
2024-02-12 13:15:02,901 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$B3yOLlqtgzc1SNMm9Fle_92adoAWT_q4nSBiqvrdEmY- {GET-O-1436} [f-droid.org] Completed request: 200 OK in 0.59 secs, got 830 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24B3yOLlqtgzc1SNMm9Fle_92adoAWT_q4nSBiqvrdEmY
2024-02-12 13:15:02,906 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$vZ2APnzM2mEObfwyyJQU-WLH62vJKDwUvvFwVjtzuiM- {GET-O-1439} [f-droid.org] Completed request: 200 OK in 0.55 secs, got 879 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24vZ2APnzM2mEObfwyyJQU-WLH62vJKDwUvvFwVjtzuiM
2024-02-12 13:15:02,928 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$dOSMRv2VRoKf403AFkMm46Y4X_SNetb4zSSBRWx38wc- {GET-O-1441} [f-droid.org] Completed request: 200 OK in 0.06 secs, got 859 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24dOSMRv2VRoKf403AFkMm46Y4X_SNetb4zSSBRWx38wc
2024-02-12 13:15:02,930 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$PGpX-hYMxllARn0v0xutZvxLzAWY2gpzO3f7vrbsMrI- {GET-O-1438} [f-droid.org] Completed request: 200 OK in 0.60 secs, got 762 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24PGpX-hYMxllARn0v0xutZvxLzAWY2gpzO3f7vrbsMrI
2024-02-12 13:15:02,956 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$5CRt9dKiZzPZvytACBuBow22R5LXfiKAO3IVen6ygeI- {GET-O-1440} [f-droid.org] Completed request: 200 OK in 0.56 secs, got 865 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%245CRt9dKiZzPZvytACBuBow22R5LXfiKAO3IVen6ygeI
2024-02-12 13:15:03,444 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$HpgduRLHrLeCFgP1x5yhfeq7KFr8ip1-xq5h2HeLVu4- {GET-O-1443} [f-droid.org] Completed request: 200 OK in 0.54 secs, got 896 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24HpgduRLHrLeCFgP1x5yhfeq7KFr8ip1-xq5h2HeLVu4
2024-02-12 13:15:03,479 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$Z5TpD-u8i2uR70r0ON09MDiCL6CJtnyn-nPBh9ko6zM- {GET-O-1442} [f-droid.org] Completed request: 200 OK in 0.58 secs, got 859 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24Z5TpD-u8i2uR70r0ON09MDiCL6CJtnyn-nPBh9ko6zM
2024-02-12 13:15:03,494 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$cWD0tsoyjkrRfC7H2lgHAMhy7hjsbFY31L9IzGajGSw- {GET-O-1446} [f-droid.org] Completed request: 200 OK in 0.54 secs, got 871 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24cWD0tsoyjkrRfC7H2lgHAMhy7hjsbFY31L9IzGajGSw
2024-02-12 13:15:03,537 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$MkMy-vAY1Yot8XoHdSm7x2mAbSNbGWrcUuG8h4VbrAM- {GET-O-1445} [f-droid.org] Completed request: 200 OK in 0.61 secs, got 883 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24MkMy-vAY1Yot8XoHdSm7x2mAbSNbGWrcUuG8h4VbrAM
2024-02-12 13:15:03,538 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$KL3G7d4QRkPj_woa3_IpO_w0A69I5Gyiivq58qHbzCI- {GET-O-1448} [f-droid.org] Completed request: 200 OK in 0.09 secs, got 884 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24KL3G7d4QRkPj_woa3_IpO_w0A69I5Gyiivq58qHbzCI
2024-02-12 13:15:03,539 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$wHx8gpCgcp6OVEMUN2brTKpFpQmD0thtRRnd5ONewBs- {GET-O-1444} [f-droid.org] Completed request: 200 OK in 0.61 secs, got 865 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24wHx8gpCgcp6OVEMUN2brTKpFpQmD0thtRRnd5ONewBs
2024-02-12 13:15:03,547 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$W4KoaQg2sa7xY43PdzE9b1hzruKkcAsLVKDlua2t3y4- {GET-O-1449} [f-droid.org] Completed request: 200 OK in 0.07 secs, got 873 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24W4KoaQg2sa7xY43PdzE9b1hzruKkcAsLVKDlua2t3y4
2024-02-12 13:15:03,603 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$NiuunV_l9BA9_Rhb_sg_WFs2vkQ7Aq2I0VocChcd9kc- {GET-O-1450} [f-droid.org] Completed request: 200 OK in 0.11 secs, got 884 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24NiuunV_l9BA9_Rhb_sg_WFs2vkQ7Aq2I0VocChcd9kc
2024-02-12 13:15:03,617 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$br574Bgr3KoUQDI4wl5Q-jkuHBbJgwB3BXOu8UIEoyE- {GET-O-1451} [f-droid.org] Completed request: 200 OK in 0.08 secs, got 884 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24br574Bgr3KoUQDI4wl5Q-jkuHBbJgwB3BXOu8UIEoyE
2024-02-12 13:15:04,135 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$x8lidA3yEqGuULIoa8eWg_k385Fo7K2UgPVYXLnxxS4- {GET-O-1454} [f-droid.org] Completed request: 200 OK in 0.59 secs, got 883 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24x8lidA3yEqGuULIoa8eWg_k385Fo7K2UgPVYXLnxxS4
2024-02-12 13:15:04,142 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$Y-2XK-jyGatKn4Gb-QM61yesf63okAqG5qGzEIYm0KE- {GET-O-1452} [f-droid.org] Completed request: 200 OK in 0.60 secs, got 911 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24Y-2XK-jyGatKn4Gb-QM61yesf63okAqG5qGzEIYm0KE
2024-02-12 13:15:04,148 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$c4SMMme3sohLCVRDCXTcYljHy2tRHQ4RX1_x8mlELU0- {GET-O-1453} [f-droid.org] Completed request: 200 OK in 0.60 secs, got 887 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24c4SMMme3sohLCVRDCXTcYljHy2tRHQ4RX1_x8mlELU0
2024-02-12 13:15:04,178 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$nv03BIMn4xtI3fby1ZeqMC6axOp8Ft-xEIL8lueGtV0- {GET-O-1455} [f-droid.org] Completed request: 200 OK in 0.57 secs, got 842 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24nv03BIMn4xtI3fby1ZeqMC6axOp8Ft-xEIL8lueGtV0
2024-02-12 13:15:04,199 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$fIO8K3nmkHdmOvCDUDCqqNQykJxEaXXtnZLagDtHZvA- {GET-O-1456} [f-droid.org] Completed request: 200 OK in 0.58 secs, got 902 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24fIO8K3nmkHdmOvCDUDCqqNQykJxEaXXtnZLagDtHZvA
2024-02-12 13:15:04,215 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$HJ0pliqHxGl0ooIcUhq4PxFWwWD2K9oQ9P3hCkNxepk- {GET-O-1457} [f-droid.org] Completed request: 200 OK in 0.08 secs, got 863 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24HJ0pliqHxGl0ooIcUhq4PxFWwWD2K9oQ9P3hCkNxepk
2024-02-12 13:15:04,723 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$KcZF1w9DsA_BolJf1Vhzc2sy-R4ylPECjGv9MWGbwKY- {GET-O-1458} [f-droid.org] Completed request: 200 OK in 0.58 secs, got 902 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24KcZF1w9DsA_BolJf1Vhzc2sy-R4ylPECjGv9MWGbwKY
2024-02-12 13:15:04,728 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$wevjH7tad2bMpXuoO5o8YmdQtvfHKCQlH9ueb-LXm7o- {GET-O-1459} [f-droid.org] Completed request: 200 OK in 0.58 secs, got 884 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24wevjH7tad2bMpXuoO5o8YmdQtvfHKCQlH9ueb-LXm7o
2024-02-12 13:15:04,758 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$rr5W-iY1ta8cdk7nP8ZLTXt6DcN71Hm_peSsHjjOrag- {GET-O-1460} [f-droid.org] Completed request: 200 OK in 0.58 secs, got 878 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24rr5W-iY1ta8cdk7nP8ZLTXt6DcN71Hm_peSsHjjOrag
2024-02-12 13:15:04,759 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$kwM8_8S9fZtUnJtFMMTgXVon1GwUDjXVV9NSyN29fFg- {GET-O-1462} [f-droid.org] Completed request: 200 OK in 0.54 secs, got 847 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24kwM8_8S9fZtUnJtFMMTgXVon1GwUDjXVV9NSyN29fFg
2024-02-12 13:15:04,760 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$fNjK5ALtXCuMbmJbnOYl29XS8eoWeUvYCZAQtn__tfk- {GET-O-1461} [f-droid.org] Completed request: 200 OK in 0.56 secs, got 902 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24fNjK5ALtXCuMbmJbnOYl29XS8eoWeUvYCZAQtn__tfk
2024-02-12 13:15:04,819 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$8Pjx5X5GED8CFGCFXoap4J1T2GF_vpd0XHrAa86O9_I- {GET-O-1465} [f-droid.org] Completed request: 200 OK in 0.06 secs, got 873 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%248Pjx5X5GED8CFGCFXoap4J1T2GF_vpd0XHrAa86O9_I
2024-02-12 13:15:04,822 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$UsBOVK11vSd5SXC556FH2G7-jgvSlRDW7YTj4FLzhYU- {GET-O-1463} [f-droid.org] Completed request: 200 OK in 0.10 secs, got 881 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24UsBOVK11vSd5SXC556FH2G7-jgvSlRDW7YTj4FLzhYU
2024-02-12 13:15:04,823 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$rgAZjHlv9_0D1et1nJlVNBrRHwDM6pAQcMmSoHCP6tk- {GET-O-1466} [f-droid.org] Completed request: 200 OK in 0.06 secs, got 884 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24rgAZjHlv9_0D1et1nJlVNBrRHwDM6pAQcMmSoHCP6tk
2024-02-12 13:15:04,824 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$d-usLe80UiHB8KBMX4pIUXSgwL8wGn-cb-9FSLTZG2w- {GET-O-1464} [f-droid.org] Completed request: 200 OK in 0.10 secs, got 865 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24d-usLe80UiHB8KBMX4pIUXSgwL8wGn-cb-9FSLTZG2w
2024-02-12 13:15:05,324 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$AfbxkONQbQsPJQGG3F3T5WFicpMSY3Ylir1gSkdZA7k- {GET-O-1467} [f-droid.org] Completed request: 200 OK in 0.56 secs, got 896 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24AfbxkONQbQsPJQGG3F3T5WFicpMSY3Ylir1gSkdZA7k
2024-02-12 13:15:05,391 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$iozIvCdeAoVoSh4sTZTXe_vdg7IHelqNyBtG9VeZ8yw- {GET-O-1472} [f-droid.org] Completed request: 200 OK in 0.06 secs, got 874 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24iozIvCdeAoVoSh4sTZTXe_vdg7IHelqNyBtG9VeZ8yw
2024-02-12 13:15:05,405 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$lCGDP7wBZ1FarLkS_ILbYhLpRaE3odrOLY6Vd2XU_dQ- {GET-O-1468} [f-droid.org] Completed request: 200 OK in 0.58 secs, got 863 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24lCGDP7wBZ1FarLkS_ILbYhLpRaE3odrOLY6Vd2XU_dQ
2024-02-12 13:15:05,406 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$WxCSEX3HiK92FUCoMtl10Nah6E1uDkg5_47s0miuxxA- {GET-O-1469} [f-droid.org] Completed request: 200 OK in 0.58 secs, got 931 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24WxCSEX3HiK92FUCoMtl10Nah6E1uDkg5_47s0miuxxA
2024-02-12 13:15:05,406 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$jTuHWlVN0Su93gHruYoEevpKDrfCi_icIH4ZeYPuI1M- {GET-O-1471} [f-droid.org] Completed request: 200 OK in 0.58 secs, got 884 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24jTuHWlVN0Su93gHruYoEevpKDrfCi_icIH4ZeYPuI1M
2024-02-12 13:15:05,417 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$Or4nzVbrfu-qJgWDmQ-Z2uhy1wRVPynqSXTs4DVEXuw- {GET-O-1470} [f-droid.org] Completed request: 200 OK in 0.59 secs, got 867 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24Or4nzVbrfu-qJgWDmQ-Z2uhy1wRVPynqSXTs4DVEXuw
2024-02-12 13:15:05,926 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$nGaFMenklA9k8qH93OB-a6LcQBPJ2Yvn4pa-Y8Ya_mM- {GET-O-1473} [f-droid.org] Completed request: 200 OK in 0.53 secs, got 863 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24nGaFMenklA9k8qH93OB-a6LcQBPJ2Yvn4pa-Y8Ya_mM
2024-02-12 13:15:05,985 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$c7jb-SjcIVYKEUCqPPDZLl04FFWGOPclC9MfxZtYrO4- {GET-O-1475} [f-droid.org] Completed request: 200 OK in 0.58 secs, got 896 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24c7jb-SjcIVYKEUCqPPDZLl04FFWGOPclC9MfxZtYrO4
2024-02-12 13:15:06,002 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$BXbvfiUEn91lkbZnDSzuYiWnBhW2EisTwHnvarGPk7s- {GET-O-1476} [f-droid.org] Completed request: 200 OK in 0.59 secs, got 878 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24BXbvfiUEn91lkbZnDSzuYiWnBhW2EisTwHnvarGPk7s
2024-02-12 13:15:06,003 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$v1ouW4H9j3r6efr5Ge_pzyniB0gkKx3T1v58GdiRdTY- {GET-O-1474} [f-droid.org] Completed request: 200 OK in 0.60 secs, got 884 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24v1ouW4H9j3r6efr5Ge_pzyniB0gkKx3T1v58GdiRdTY
2024-02-12 13:15:06,018 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$rB5q2kHXcsMmMFtlHhTiNW9K4IyEbjDfmo85vx91ljg- {GET-O-1477} [f-droid.org] Completed request: 200 OK in 0.60 secs, got 883 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24rB5q2kHXcsMmMFtlHhTiNW9K4IyEbjDfmo85vx91ljg
2024-02-12 13:15:06,033 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$qI0OqpsfIWEl6GFrunZc_wk7F5NQ3-hIrm2g4xMDHog- {GET-O-1479} [f-droid.org] Completed request: 200 OK in 0.05 secs, got 896 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24qI0OqpsfIWEl6GFrunZc_wk7F5NQ3-hIrm2g4xMDHog
2024-02-12 13:15:06,043 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$_Zw30uHvCfbEYpw78TmI2t8qbnPICnT_Yz-OAAKOoks- {GET-O-1478} [f-droid.org] Completed request: 200 OK in 0.12 secs, got 859 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24_Zw30uHvCfbEYpw78TmI2t8qbnPICnT_Yz-OAAKOoks
2024-02-12 13:15:06,053 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$FQYKwNKRA404WsyNuG4_vLfYAhX55T60Gnwqr28_cD4- {GET-O-1481} [f-droid.org] Completed request: 200 OK in 0.05 secs, got 884 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24FQYKwNKRA404WsyNuG4_vLfYAhX55T60Gnwqr28_cD4
2024-02-12 13:15:06,083 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$qNrd-d8M3oYSa945Hq8IW5mAYyJFOVLqYe4fbmxRPbA- {GET-O-1480} [f-droid.org] Completed request: 200 OK in 0.08 secs, got 902 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24qNrd-d8M3oYSa945Hq8IW5mAYyJFOVLqYe4fbmxRPbA
2024-02-12 13:15:06,611 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$nbHlTSm_PGt37qIYpnvD2ZfR4IQMaVESgbriHM383pk- {GET-O-1482} [f-droid.org] Completed request: 200 OK in 0.59 secs, got 887 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24nbHlTSm_PGt37qIYpnvD2ZfR4IQMaVESgbriHM383pk
2024-02-12 13:15:06,633 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$Oi5DrY83AJ2uHdwWOdPnHhPFKRDaedv070G4IlDjPZ4- {GET-O-1483} [f-droid.org] Completed request: 200 OK in 0.60 secs, got 883 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24Oi5DrY83AJ2uHdwWOdPnHhPFKRDaedv070G4IlDjPZ4
2024-02-12 13:15:06,647 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$maH92sz-xSAz0BpB0eFtPGV6vuxhHtti3BLPSS8J_as- {GET-O-1484} [f-droid.org] Completed request: 200 OK in 0.60 secs, got 905 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24maH92sz-xSAz0BpB0eFtPGV6vuxhHtti3BLPSS8J_as
2024-02-12 13:15:06,658 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$oz_e9-2JZRwGp3fZGAt1Xh_nglvlpCVi2sYnOozXhr0- {GET-O-1485} [f-droid.org] Completed request: 200 OK in 0.60 secs, got 902 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24oz_e9-2JZRwGp3fZGAt1Xh_nglvlpCVi2sYnOozXhr0
2024-02-12 13:15:06,659 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$yg0jJIoPFjyZlncdw6qaB0BZdgwxU5G0Q26vQFsuktk- {GET-O-1486} [f-droid.org] Completed request: 200 OK in 0.58 secs, got 893 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24yg0jJIoPFjyZlncdw6qaB0BZdgwxU5G0Q26vQFsuktk
2024-02-12 13:15:06,664 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$uBoWpj6l6NgNziwOZl0eWzBIP9_-G4TUg7RFibsY7Sw- {GET-O-1487} [f-droid.org] Completed request: 200 OK in 0.05 secs, got 884 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24uBoWpj6l6NgNziwOZl0eWzBIP9_-G4TUg7RFibsY7Sw
2024-02-12 13:15:07,182 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$bRGaK1EH1GWQsP3Bfsp18KmwumFOx1SheykA3dCumh4- {GET-O-1489} [f-droid.org] Completed request: 200 OK in 0.53 secs, got 887 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24bRGaK1EH1GWQsP3Bfsp18KmwumFOx1SheykA3dCumh4
2024-02-12 13:15:07,214 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$zpndgHIUAddDLCExVDFKNfe6SudnidmH3619oSqotEQ- {GET-O-1488} [f-droid.org] Completed request: 200 OK in 0.58 secs, got 867 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24zpndgHIUAddDLCExVDFKNfe6SudnidmH3619oSqotEQ
2024-02-12 13:15:07,263 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$O_yLKe54vJvFiXwMIupETEVW6c7xxm18Bvp_XhMXMGc- {GET-O-1490} [f-droid.org] Completed request: 200 OK in 0.60 secs, got 806 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24O_yLKe54vJvFiXwMIupETEVW6c7xxm18Bvp_XhMXMGc
2024-02-12 13:15:07,266 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$XKhbBQ2g7F7499kGtN2ojnMOVf4C-NKH1X6sC_MzKPI- {GET-O-1491} [f-droid.org] Completed request: 200 OK in 0.60 secs, got 840 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24XKhbBQ2g7F7499kGtN2ojnMOVf4C-NKH1X6sC_MzKPI
2024-02-12 13:15:07,272 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$Ej1Sv-XYZME5sG5n5hLpEklEQZY4m7eLtFowFo7ihSw- {GET-O-1493} [f-droid.org] Completed request: 200 OK in 0.09 secs, got 896 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24Ej1Sv-XYZME5sG5n5hLpEklEQZY4m7eLtFowFo7ihSw
2024-02-12 13:15:07,274 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$fvzW9Jr2XHmb9RMu9bLGokPG-FdqQh6tGmOjLcLg0uw- {GET-O-1492} [f-droid.org] Completed request: 200 OK in 0.61 secs, got 875 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24fvzW9Jr2XHmb9RMu9bLGokPG-FdqQh6tGmOjLcLg0uw
2024-02-12 13:15:07,317 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$Y69w9qF7RcfoxEvZldzLM5eHKRBt6wdP91kVyKpsGlc- {GET-O-1494} [f-droid.org] Completed request: 200 OK in 0.10 secs, got 883 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24Y69w9qF7RcfoxEvZldzLM5eHKRBt6wdP91kVyKpsGlc
2024-02-12 13:15:07,355 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$DfwrKNbaLX5l-_U906gVF6ZqNrzyfj5qlOZyVfolivE- {GET-O-1495} [f-droid.org] Completed request: 200 OK in 0.09 secs, got 883 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24DfwrKNbaLX5l-_U906gVF6ZqNrzyfj5qlOZyVfolivE
2024-02-12 13:15:07,356 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$EDHJUQo7dyNHLYsRUor_By1ZWA9T1XpXdi0le9AYcnU- {GET-O-1496} [f-droid.org] Completed request: 200 OK in 0.09 secs, got 890 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24EDHJUQo7dyNHLYsRUor_By1ZWA9T1XpXdi0le9AYcnU
2024-02-12 13:15:07,853 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$bM5HqeonK1XrNLZi-uJh--cHvzhnmzs8bfUmDvSBeV8- {GET-O-1497} [f-droid.org] Completed request: 200 OK in 0.58 secs, got 874 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24bM5HqeonK1XrNLZi-uJh--cHvzhnmzs8bfUmDvSBeV8
2024-02-12 13:15:07,860 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$8ybwGGJBlP1NwTgSVbGQIE4Y1mur1ZwfmMmTpBSdu2c- {GET-O-1498} [f-droid.org] Completed request: 200 OK in 0.59 secs, got 870 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%248ybwGGJBlP1NwTgSVbGQIE4Y1mur1ZwfmMmTpBSdu2c
2024-02-12 13:15:07,871 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$SqVhU4z1rfl7Hu2q4piSCAPTeN7hbE2aMz_58HaHCJo- {GET-O-1499} [f-droid.org] Completed request: 200 OK in 0.55 secs, got 912 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24SqVhU4z1rfl7Hu2q4piSCAPTeN7hbE2aMz_58HaHCJo
2024-02-12 13:15:07,927 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$-0qGB9kDufFMA5csQT3GbiJIg1GMA20KYyeJe4Yo79E- {GET-O-1502} [f-droid.org] Completed request: 200 OK in 0.07 secs, got 884 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24-0qGB9kDufFMA5csQT3GbiJIg1GMA20KYyeJe4Yo79E
2024-02-12 13:15:07,936 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$xrLRkUTXPCBLaYwJorXs3_V97frx7EStQhbOwlF7ft8- {GET-O-1500} [f-droid.org] Completed request: 200 OK in 0.58 secs, got 871 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24xrLRkUTXPCBLaYwJorXs3_V97frx7EStQhbOwlF7ft8
2024-02-12 13:15:07,947 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$eEkkAPUtcTvWtS-j5eZ4BT7JdbaiUmw1IyPE_6zs9Z8- {GET-O-1501} [f-droid.org] Completed request: 200 OK in 0.59 secs, got 884 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24eEkkAPUtcTvWtS-j5eZ4BT7JdbaiUmw1IyPE_6zs9Z8
2024-02-12 13:15:08,429 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$qSMYPWLkOSpNSKalL3YVHihVMvQB_8uYq0K2gKd6_0I- {GET-O-1503} [f-droid.org] Completed request: 200 OK in 0.57 secs, got 878 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24qSMYPWLkOSpNSKalL3YVHihVMvQB_8uYq0K2gKd6_0I
2024-02-12 13:15:08,441 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$YaHA1aP2cfLUeaAuzUyhPxuBgoYyVGqDAMw19DwBNaU- {GET-O-1504} [f-droid.org] Completed request: 200 OK in 0.57 secs, got 883 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24YaHA1aP2cfLUeaAuzUyhPxuBgoYyVGqDAMw19DwBNaU
2024-02-12 13:15:08,476 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$3lRLXSG5Q_7mQd_IFUxPPF8hOtfpOEOHCfLeH8cs9_0- {GET-O-1506} [f-droid.org] Completed request: 200 OK in 0.54 secs, got 873 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%243lRLXSG5Q_7mQd_IFUxPPF8hOtfpOEOHCfLeH8cs9_0
2024-02-12 13:15:08,522 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$2T3BzSwdu6aLV1-SoBp9Evc0PA66WgO4OBJVH_2HNHs- {GET-O-1508} [f-droid.org] Completed request: 200 OK in 0.09 secs, got 871 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%242T3BzSwdu6aLV1-SoBp9Evc0PA66WgO4OBJVH_2HNHs
2024-02-12 13:15:08,523 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$WwpvBYdOB16VNMLjlrzPaTw91RzOGQ3DWgc1o_cbCEs- {GET-O-1509} [f-droid.org] Completed request: 200 OK in 0.08 secs, got 902 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24WwpvBYdOB16VNMLjlrzPaTw91RzOGQ3DWgc1o_cbCEs
2024-02-12 13:15:08,524 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$sSyA_Xj6ypB8Jf64IziaQiwIPhk0WDuuadOLNq5INhs- {GET-O-1507} [f-droid.org] Completed request: 200 OK in 0.58 secs, got 879 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24sSyA_Xj6ypB8Jf64IziaQiwIPhk0WDuuadOLNq5INhs
2024-02-12 13:15:08,527 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$okzO7bwqqs0pzHngpsSIW1Udr4M9R8lwBVmoUAqKz3Y- {GET-O-1510} [f-droid.org] Completed request: 200 OK in 0.05 secs, got 834 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24okzO7bwqqs0pzHngpsSIW1Udr4M9R8lwBVmoUAqKz3Y
2024-02-12 13:15:08,527 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$x0jV93Df2VLJ8JB6ZZmFilteS2lp3yLh9aTryG-H_E0- {GET-O-1505} [f-droid.org] Completed request: 200 OK in 0.60 secs, got 865 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24x0jV93Df2VLJ8JB6ZZmFilteS2lp3yLh9aTryG-H_E0
2024-02-12 13:15:08,589 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$ExF9oc9YWPkOLeflPbrRTXINMCCW3A5wT-ms5HUSI54- {GET-O-1511} [f-droid.org] Completed request: 200 OK in 0.06 secs, got 873 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24ExF9oc9YWPkOLeflPbrRTXINMCCW3A5wT-ms5HUSI54
2024-02-12 13:15:09,072 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$ZFum6d7OaR5Ye26JMsI1wMfuIeEZIbLzzhymtkHezWo- {GET-O-1512} [f-droid.org] Completed request: 200 OK in 0.54 secs, got 896 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%24ZFum6d7OaR5Ye26JMsI1wMfuIeEZIbLzzhymtkHezWo
2024-02-12 13:15:09,093 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8-$1iDsVqGCUK-Evu3mtC0URBftJsT3AdX65wUVd1Uxk4U- {GET-O-1513} [f-droid.org] Completed request: 200 OK in 0.56 secs, got 878 bytes - GET matrix-federation://f-droid.org/_matrix/federation/v1/event/%241iDsVqGCUK-Evu3mtC0URBftJsT3AdX65wUVd1Uxk4U
2024-02-12 13:15:09,095 - synapse.handlers.federation_event - 1638 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8- Fetched 443 events of 445 requested
2024-02-12 13:15:09,130 - synapse.handlers.federation_event - 1690 - INFO - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8- Persisting 443 remaining outliers: ['$-gqIumKMQzYxE5sv26jYYxQXg-5h-dMgVGHqhUFsoJo', '$1Ffrjjl9sqNUpkRZ4yGtttMjkUidepu90dYZ_SzcWiI', '$1iDsVqGCUK-Evu3mtC0URBftJsT3AdX65wUVd1Uxk4U', '$2ZQdr051go57NuRFkfP0wxmzcbBz8jyUbwHFxO5OZGg', '$55xBNicIe5QqRrqXXAQRH1zIW9-uDwUSxmDT6o3ekdA', ...]
2024-02-12 13:15:14,628 - synapse.handlers.federation_event - 1355 - WARNING - sync_partial_state_room-0-$LN9zgAqr7Md27D-pVqwXqs10SqPMd1aeASA2Wsadrws-$pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8- Failed to fetch missing state events for $pL8X4sUYnyh69mt6JaJIFcZ7ZI0tr6gWEXIK8Xm87u8 {'$xvVyiy19KtOVwofXHJsSaJNykFrK62i2e-fNp-tupos'}
2024-02-12 13:15:15,155 - synapse.replication.tcp.resource - 215 - INFO - replication_notifier-439- Streaming: un_partial_stated_event -> 115 (limited: False, updates: 1, max token: 115)
2024-02-12 13:15:15,159 - synapse.handlers.federation - 1925 - INFO - sync_partial_state_room-0- Updating current state for !hbPGQxyHEvFEncGQxE:f-droid.org
2024-02-12 13:15:49,107 - synapse.handlers.federation - 1935 - INFO - sync_partial_state_room-0- Handling any pending device list updates
2024-02-12 13:15:49,178 - synapse.handlers.device - 1545 - INFO - sync_partial_state_room-0- Got pending device list update in room !hbPGQxyHEvFEncGQxE:f-droid.org: @serge90:matrix.org / NQAVGQTLTQ
2024-02-12 13:15:49,230 - synapse.handlers.federation - 1939 - INFO - sync_partial_state_room-0- Clearing partial-state flag for !hbPGQxyHEvFEncGQxE:f-droid.org
2024-02-12 13:15:49,302 - synapse.handlers.federation - 1943 - INFO - sync_partial_state_room-0- State resync complete for !hbPGQxyHEvFEncGQxE:f-droid.org
2024-02-12 13:15:49,303 - synapse.storage.util.partial_state_events_tracker - 156 - INFO - sync_partial_state_room-0- Notifying 1 things waiting for un-partial-stating of room !hbPGQxyHEvFEncGQxE:f-droid.org
2024-02-12 13:15:49,303 - synapse.storage.util.partial_state_events_tracker - 187 - INFO - maybe_backfill_in_the_background-3- Room has un-partial-stated
2024-02-12 13:15:49,322 - synapse.replication.tcp.resource - 215 - INFO - replication_notifier-481- Streaming: un_partial_stated_room -> 39 (limited: False, updates: 1, max token: 39)

Then I tried to enter the room #ecips:matrix.org and the main worker locked up again. It was then killed by the liveness probe after two minutes.

2024-02-12 13:17:12,939 - synapse.handlers.federation_event - 539 - INFO - POST-2452- Peristing join-via-remote <FrozenEvent event_id=$17077438320JejHE:gogel.me, type=m.room.member, state_key=@gerrit:gogel.me, outlier=False> (partial_state: True)
2024-02-12 13:17:13,159 - synapse.handlers.federation - 1917 - INFO - sync_partial_state_room-1- Syncing state for room !WMZPgpQpdMulhwFOdV:matrix.org via matrix.org
2024-02-12 13:17:13,220 - synapse.handlers.federation_event - 628 - INFO - sync_partial_state_room-1- Updating state for $17077438320JejHE:gogel.me
2024-02-12 13:17:13,248 - synapse.handlers.federation_event - 1129 - INFO - sync_partial_state_room-1-$17077438320JejHE:gogel.me- Event $17077438320JejHE:gogel.me is missing prev_events ['$1707737825499kXHmJ:matrix.org']: calculating state for a backwards extremity
2024-02-12 13:17:13,248 - synapse.handlers.federation_event - 1151 - INFO - sync_partial_state_room-1-$17077438320JejHE:gogel.me- Requesting state after missing prev_event $1707737825499kXHmJ:matrix.org
2024-02-12 13:17:13,501 - synapse.storage.util.partial_state_events_tracker - 179 - INFO - GET-2462- Awaiting un-partial-stating of room !WMZPgpQpdMulhwFOdV:matrix.org
    await self._partial_state_room_tracker.await_full_state(room_id)
  File "/usr/local/lib/python3.11/site-packages/synapse/storage/util/partial_state_events_tracker.py", line 179, in await_full_state
2024-02-12 13:17:23,789 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-1-$17077438320JejHE:gogel.me-$1707737825499kXHmJ:matrix.org- {GET-O-1572} [matrix.org] Completed request: 200 OK in 10.54 secs, got 6452226 bytes - GET matrix-federation://matrix.org/_matrix/federation/v1/state_ids/%21WMZPgpQpdMulhwFOdV%3Amatrix.org?event_id=%241707737825499kXHmJ%3Amatrix.org
2024-02-12 13:19:14,030 - synapse.http.matrixfederationclient - 756 - INFO - sync_partial_state_room-1-$17077438320JejHE:gogel.me-$1707737825499kXHmJ:matrix.org- {GET-O-1715} [matrix.org] Got response headers: 524
2024-02-12 13:19:14,031 - synapse.http.matrixfederationclient - 799 - INFO - sync_partial_state_room-1-$17077438320JejHE:gogel.me-$1707737825499kXHmJ:matrix.org- {GET-O-1715} [matrix.org] Request failed: GET matrix-federation://matrix.org/_matrix/federation/v1/state/%21WMZPgpQpdMulhwFOdV%3Amatrix.org?event_id=%241707737825499kXHmJ%3Amatrix.org: HttpResponseException('524: ')
2024-02-12 13:19:14,031 - synapse.util.retryutils - 283 - INFO - sync_partial_state_room-1-$17077438320JejHE:gogel.me-$1707737825499kXHmJ:matrix.org- Connection to matrix.org was unsuccessful (<class 'synapse.api.errors.RequestSendFailed'>(Failed to send request: HttpResponseException: 524: )); backoff now 600000
2024-02-12 13:19:14,031 - synapse.handlers.federation_event - 1186 - WARNING - sync_partial_state_room-1-$17077438320JejHE:gogel.me- Error attempting to resolve state at missing prev_events: Failed to send request: HttpResponseException: 524:
2024-02-12 13:19:14,031 - synapse.handlers.federation - 2004 - INFO - sync_partial_state_room-1- Failed to get state for !WMZPgpQpdMulhwFOdV:matrix.org at <FrozenEvent event_id=$17077438320JejHE:gogel.me, type=m.room.member, state_key=@gerrit:gogel.me, outlier=False> from matrix.org because ERROR 403: We can't get valid state history.
2024-02-12 13:19:14,032 - synapse.handlers.federation - 2012 - INFO - sync_partial_state_room-1- Syncing state for room !WMZPgpQpdMulhwFOdV:matrix.org via matrix.nek0.net instead
2024-02-12 13:19:14,070 - synapse.handlers.federation_event - 628 - INFO - sync_partial_state_room-1- Updating state for $17077438320JejHE:gogel.me
2024-02-12 13:19:14,077 - synapse.handlers.federation_event - 1129 - INFO - sync_partial_state_room-1-$17077438320JejHE:gogel.me- Event $17077438320JejHE:gogel.me is missing prev_events ['$1707737825499kXHmJ:matrix.org']: calculating state for a backwards extremity
2024-02-12 13:19:14,077 - synapse.handlers.federation_event - 1151 - INFO - sync_partial_state_room-1-$17077438320JejHE:gogel.me- Requesting state after missing prev_event $1707737825499kXHmJ:matrix.org
2024-02-12 13:19:14,084 - synapse.http.federation.well_known_resolver - 260 - INFO - sync_partial_state_room-1-$17077438320JejHE:gogel.me-$1707737825499kXHmJ:matrix.org- Fetching https://matrix.nek0.net/.well-known/matrix/server
2024-02-12 13:19:15,225 - synapse.http.federation.well_known_resolver - 197 - INFO - sync_partial_state_room-1-$17077438320JejHE:gogel.me-$1707737825499kXHmJ:matrix.org- Response from .well-known: {'m.server': 'matrix.nek0.net:443'}
2024-02-12 13:19:22,114 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-1-$17077438320JejHE:gogel.me-$1707737825499kXHmJ:matrix.org- {GET-O-1723} [matrix.nek0.net] Completed request: 200 OK in 8.04 secs, got 6452226 bytes - GET matrix-federation://matrix.nek0.net/_matrix/federation/v1/state_ids/%21WMZPgpQpdMulhwFOdV%3Amatrix.org?event_id=%241707737825499kXHmJ%3Amatrix.org
2024-02-12 13:20:45,032 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-1-$17077438320JejHE:gogel.me-$1707737825499kXHmJ:matrix.org- {GET-O-1724} [matrix.nek0.net] Completed request: 200 OK in 76.53 secs, got 208521768 bytes - GET matrix-federation://matrix.nek0.net/_matrix/federation/v1/state/%21WMZPgpQpdMulhwFOdV%3Amatrix.org?event_id=%241707737825499kXHmJ%3Amatrix.org
2024-02-12 13:20:45,214 - synapse.federation.federation_client - 638 - INFO - sync_partial_state_room-1-$17077438320JejHE:gogel.me-$1707737825499kXHmJ:matrix.org- Processing from /state: 10331 state events, 174754 auth events
2024-02-12 13:22:31,197 - synapse.handlers.federation_event - 1387 - INFO - sync_partial_state_room-1-$17077438320JejHE:gogel.me-$1707737825499kXHmJ:matrix.org- /state returned 185085 events
2024-02-12 13:22:39,521 - synapse.handlers.federation_event - 1690 - INFO - sync_partial_state_room-1-$17077438320JejHE:gogel.me-$1707737825499kXHmJ:matrix.org- Persisting 185053 remaining outliers: ['$155294529942816iTjCt:matrix.parity.io', '$15529497701468284rYUcd:matrix.org', '$15529834951580652snqva:matrix.org', '$15530959058876xlpYD:t2bot.io', '$15531025489411QoSlf:t2bot.io', ...]

While persisting the endpoint /health still becomes unresponsive. Although a few lines are still written to the logs (from a later run, didn't catch it in the first one):

2024-02-12 13:33:45,711 - synapse.access.http.9093 - 472 - INFO - POST-976- ::ffff:10.42.188.53 - 9093 - {None} Processed request: 0.001sec/55.561sec (0.004sec, 0.000sec) (0.000sec/0.000sec/0) 304B 200 "POST /_synapse/replication/fed_send_edu/m.presence/LTavfRUAWz HTTP/1.1" "Synapse/1.101.0rc1" [0 dbevts]
2024-02-12 13:33:45,713 - synapse.federation.sender.transaction_manager - 127 - INFO - federation_transaction_transmission_loop-1435- TX [wirtschaftstools.de] {1707744599372} Sending transaction [1707744599372], (PDUs: 0, EDUs: 1)
2024-02-12 13:33:45,718 - synapse.metrics._gc - 127 - INFO - sentinel- Collecting gc 1
2024-02-12 13:33:45,883 - synapse.http.federation.matrix_federation_agent - 371 - INFO - federation_transaction_transmission_loop-640- Failed to connect to pitmamatrix.in.ua:8448: User timeout caused connection failure.
2024-02-12 13:33:45,883 - synapse.http.matrixfederationclient - 799 - INFO - federation_transaction_transmission_loop-640- {PUT-O-635} [pitmamatrix.in.ua] Request failed: PUT matrix-federation://pitmamatrix.in.ua/_matrix/federation/v1/send/1707744598589: TimeoutError('')
2024-02-12 13:33:45,888 - synapse.handlers.presence - 913 - INFO - persist_presence_changes-1- Persisting 37 unpersisted presence updates
2024-02-12 13:33:45,893 - synapse.util.caches.lrucache - 217 - INFO - LruCache._expire_old_entries-5- Dropped 0 items from caches
2024-02-12 13:33:45,916 - synapse.http.federation.matrix_federation_agent - 371 - INFO - federation_transaction_transmission_loop-686- Failed to connect to matrix.bbalm.me:8448: User timeout caused connection failure.
2024-02-12 13:33:45,917 - synapse.http.matrixfederationclient - 799 - INFO - federation_transaction_transmission_loop-686- {PUT-O-681} [matrix.bbalm.me] Request failed: PUT matrix-federation://matrix.bbalm.me/_matrix/federation/v1/send/1707744598635: TimeoutError('')
2024-02-12 13:33:45,922 - synapse.http.federation.matrix_federation_agent - 371 - INFO - federation_transaction_transmission_loop-693- Failed to connect to tonibot.ddns.net:8448: User timeout caused connection failure.
2024-02-12 13:33:45,922 - synapse.http.matrixfederationclient - 799 - INFO - federation_transaction_transmission_loop-693- {PUT-O-688} [tonibot.ddns.net] Request failed: PUT matrix-federation://tonibot.ddns.net/_matrix/federation/v1/send/1707744598642: TimeoutError('')
2024-02-12 13:33:45,925 - twisted - 282 - INFO - sentinel- Timing out client: IPv6Address(type='TCP', host='::ffff:10.42.188.45', port=40264, flowInfo=0, scopeID=0)
2024-02-12 13:33:45,927 - synapse.http.federation.matrix_federation_agent - 371 - INFO - federation_transaction_transmission_loop-1417- Failed to connect to mymatrix.yorili.com:8448: User timeout caused connection failure.
2024-02-12 13:33:45,928 - synapse.http.matrixfederationclient - 799 - INFO - federation_transaction_transmission_loop-1417- {PUT-O-1417} [mymatrix.yorili.com] Request failed: PUT matrix-federation://mymatrix.yorili.com/_matrix/federation/v1/send/1707744599355: TimeoutError('')
2024-02-12 13:33:45,933 - synapse.http.federation.matrix_federation_agent - 371 - INFO - federation_transaction_transmission_loop-1425- Failed to connect to matrix.gnu.fun:8448: User timeout caused connection failure.
2024-02-12 13:33:45,934 - synapse.http.matrixfederationclient - 799 - INFO - federation_transaction_transmission_loop-1425- {PUT-O-1424} [gnu.fun] Request failed: PUT matrix-federation://gnu.fun/_matrix/federation/v1/send/1707744599362: TimeoutError('')
2024-02-12 13:33:45,934 - synapse.http.federation.matrix_federation_agent - 371 - INFO - federation_transaction_transmission_loop-1429- Failed to connect to matrix.donjuan.lecturify.net:8448: User timeout caused connection failure.
2024-02-12 13:33:45,934 - synapse.http.matrixfederationclient - 799 - INFO - federation_transaction_transmission_loop-1429- {PUT-O-1428} [matrix.donjuan.lecturify.net] Request failed: PUT matrix-federation://matrix.donjuan.lecturify.net/_matrix/federation/v1/send/1707744599366: TimeoutError('')
2024-02-12 13:33:45,939 - twisted - 282 - INFO - sentinel- Timing out client: IPv6Address(type='TCP', host='::ffff:10.42.188.45', port=43320, flowInfo=0, scopeID=0)
2024-02-12 13:33:45,944 - twisted - 282 - INFO - sentinel- Timing out client: IPv6Address(type='TCP', host='::ffff:10.42.188.45', port=50148, flowInfo=0, scopeID=0)
2024-02-12 13:33:45,944 - twisted - 282 - INFO - sentinel- Timing out client: IPv6Address(type='TCP', host='::ffff:10.42.188.45', port=53952, flowInfo=0, scopeID=0)
2024-02-12 13:33:45,944 - twisted - 282 - INFO - sentinel- Timing out client: IPv6Address(type='TCP', host='::ffff:10.42.188.45', port=42142, flowInfo=0, scopeID=0)
2024-02-12 13:33:45,947 - twisted - 282 - INFO - sentinel- Timing out client: IPv6Address(type='TCP', host='::ffff:10.42.188.45', port=35314, flowInfo=0, scopeID=0)
2024-02-12 13:33:45,947 - twisted - 282 - INFO - sentinel- Timing out client: IPv6Address(type='TCP', host='::ffff:10.42.188.45', port=35328, flowInfo=0, scopeID=0)
2024-02-12 13:33:45,947 - twisted - 282 - INFO - sentinel- Timing out client: IPv6Address(type='TCP', host='::ffff:10.42.188.45', port=45578, flowInfo=0, scopeID=0)
2024-02-12 13:33:45,949 - twisted - 282 - INFO - sentinel- Timing out client: IPv6Address(type='TCP', host='::ffff:10.42.188.53', port=32864, flowInfo=0, scopeID=0)
2024-02-12 13:33:45,950 - synapse.http.matrixfederationclient - 799 - INFO - federation_transaction_transmission_loop-1267- {PUT-O-1269} [jkl.hacklab.fi] Request failed: PUT matrix-federation://jkl.hacklab.fi/_matrix/federation/v1/send/1707744599208: RequestGenerationFailed:[CancelledError()]
2024-02-12 13:33:45,956 - twisted - 282 - INFO - sentinel- Timing out client: IPv6Address(type='TCP', host='::ffff:10.42.188.53', port=32808, flowInfo=0, scopeID=0)
2024-02-12 13:33:45,957 - twisted - 282 - INFO - sentinel- Timing out client: IPv6Address(type='TCP', host='::ffff:10.42.193.41', port=54714, flowInfo=0, scopeID=0)
2024-02-12 13:33:45,957 - twisted - 282 - INFO - sentinel- Timing out client: IPv6Address(type='TCP', host='::ffff:10.42.193.41', port=44082, flowInfo=0, scopeID=0)
2024-02-12 13:33:45,958 - twisted - 282 - INFO - sentinel- Timing out client: IPv6Address(type='TCP', host='::ffff:10.42.188.45', port=53926, flowInfo=0, scopeID=0)
2024-02-12 13:33:45,958 - twisted - 282 - INFO - sentinel- Timing out client: IPv6Address(type='TCP', host='::ffff:10.42.135.32', port=40726, flowInfo=0, scopeID=0)
2024-02-12 13:33:45,958 - twisted - 282 - INFO - sentinel- Timing out client: IPv6Address(type='TCP', host='::ffff:10.42.193.41', port=46118, flowInfo=0, scopeID=0)
2024-02-12 13:33:45,958 - twisted - 282 - INFO - sentinel- Timing out client: IPv6Address(type='TCP', host='::ffff:10.42.193.41', port=53672, flowInfo=0, scopeID=0)
2024-02-12 13:33:45,960 - twisted - 282 - INFO - sentinel- Timing out client: IPv6Address(type='TCP', host='::ffff:10.42.135.32', port=40790, flowInfo=0, scopeID=0)
2024-02-12 13:33:45,960 - twisted - 282 - INFO - sentinel- Timing out client: IPv6Address(type='TCP', host='::ffff:10.42.135.32', port=58040, flowInfo=0, scopeID=0)
2024-02-12 13:33:45,961 - twisted - 282 - INFO - sentinel- Timing out client: IPv6Address(type='TCP', host='::ffff:10.42.135.32', port=40744, flowInfo=0, scopeID=0)
2024-02-12 13:34:24,622 - twisted - 282 - INFO - sync_partial_state_room-0-$17077438320JejHE:gogel.me-$1707737825499kXHmJ:matrix.org-$1591661830104300UudYJ:t2bot.io- Received SIGTERM, shutting down.
2024-02-12 13:34:44,954 - synapse.http.site - 384 - INFO - POST-977- Connection from client lost before response was sent
2024-02-12 13:34:44,959 - synapse.http.matrixfederationclient - 799 - INFO - federation_transaction_transmission_loop-1432- {PUT-O-1431} [pizzuhh.dev] Request failed: PUT matrix-federation://pizzuhh.dev/_matrix/federation/v1/send/1707744599369: RequestTransmissionFailed:[ConnectionLost('Connection lost')]
2024-02-12 13:34:44,959 - synapse.http.matrixfederationclient - 799 - INFO - federation_transaction_transmission_loop-1430- {PUT-O-1429} [mtrx.nz] Request failed: PUT matrix-federation://mtrx.nz/_matrix/federation/v1/send/1707744599367: ResponseNeverReceived:[ConnectionLost('Connection lost')]
2024-02-12 13:34:44,967 - synapse.access.http.8008 - 472 - INFO - GET-978- 109.255.84.102 - 8008 - {None} Processed request: 0.000sec/-0.000sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 42B 404 "GET /.well-known/matrix/server HTTP/1.1" "Synapse/1.99.0" [0 dbevts]
2024-02-12 13:34:44,969 - synapse.replication.http.federation - 196 - INFO - POST-979- Got 'm.presence' edu from agdersam.no
2024-02-12 13:34:44,974 - synapse.access.http.8008 - 472 - INFO - GET-980- 73.102.94.53 - 8008 - {None} Processed request: 0.000sec/-0.000sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 42B 404 "GET /.well-known/matrix/server HTTP/1.1" "Synapse/1.100.0" [0 dbevts]
2024-02-12 13:34:44,975 - synapse.replication.http.federation - 196 - INFO - POST-981- Got 'm.presence' edu from matrix.jaytie.de
2024-02-12 13:34:44,978 - synapse.replication.http.federation - 196 - INFO - POST-982- Got 'm.presence' edu from matrix.coniass.com
2024-02-12 13:34:44,981 - synapse.http.site - 384 - INFO - GET-826- Connection from client lost before response was sent
2024-02-12 13:34:44,985 - synapse.http.site - 384 - INFO - GET-889- Connection from client lost before response was sent
2024-02-12 13:34:44,986 - synapse.access.http.8008 - 472 - INFO - GET-889- 192.168.179.106 - 8008 - {@wabot:gogel.me} Processed request: 77.789sec/59.081sec (0.008sec, 0.005sec) (0.025sec/0.048sec/7) 0B 200! "GET /_matrix/client/v3/sync?timeout=30000&since=s1482298_108387050_11_2829280_213499_109_127685_2510947_0_39&filter=0&set_presence=online HTTP/1.1" "Python/3.11 aiohttp/3.8.5" [0 dbevts]
2024-02-12 13:34:44,988 - synapse.http.site - 384 - INFO - GET-883- Connection from client lost before response was sent
2024-02-12 13:34:44,989 - synapse.access.http.8008 - 472 - INFO - GET-883- 192.168.179.106 - 8008 - {@factorialbot:gogel.me} Processed request: 77.794sec/59.089sec (0.016sec, 0.001sec) (0.024sec/0.061sec/7) 0B 200! "GET /_matrix/client/v3/sync?timeout=30000&since=s1482298_108387050_11_2829280_213499_109_127685_2510947_0_39&filter=0&set_presence=online HTTP/1.1" "Python/3.11 aiohttp/3.8.5" [0 dbevts]
2024-02-12 13:34:44,990 - synapse.http.site - 384 - INFO - GET-887- Connection from client lost before response was sent
2024-02-12 13:34:44,991 - synapse.access.http.8008 - 472 - INFO - GET-887- 192.168.179.106 - 8008 - {@songwhipbot:gogel.me} Processed request: 77.790sec/59.089sec (0.004sec, 0.004sec) (0.019sec/0.060sec/7) 0B 200! "GET /_matrix/client/v3/sync?timeout=30000&since=s1482298_108387050_11_2829280_213499_109_127685_2510947_0_39&filter=0&set_presence=online HTTP/1.1" "Python/3.11 aiohttp/3.8.5" [0 dbevts]
2024-02-12 13:34:44,992 - synapse.http.site - 384 - INFO - GET-886- Connection from client lost before response was sent
2024-02-12 13:34:44,993 - synapse.access.http.8008 - 472 - INFO - GET-886- 192.168.179.106 - 8008 - {@tmdbbot:gogel.me} Processed request: 77.790sec/59.092sec (0.007sec, 0.006sec) (0.028sec/0.051sec/7) 0B 200! "GET /_matrix/client/v3/sync?timeout=30000&since=s1482298_108387050_11_2829280_213499_109_127685_2510947_0_39&filter=0&set_presence=online HTTP/1.1" "Python/3.11 aiohttp/3.8.5" [0 dbevts]
2024-02-12 13:34:44,994 - synapse.http.site - 384 - INFO - GET-884- Connection from client lost before response was sent
2024-02-12 13:34:44,995 - synapse.access.http.8008 - 472 - INFO - GET-884- 192.168.179.106 - 8008 - {@udbot:gogel.me} Processed request: 77.792sec/59.095sec (0.003sec, 0.003sec) (0.029sec/0.039sec/7) 0B 200! "GET /_matrix/client/v3/sync?timeout=30000&since=s1482298_108387050_11_2829280_213499_109_127685_2510947_0_39&filter=0&set_presence=online HTTP/1.1" "Python/3.11 aiohttp/3.8.5" [0 dbevts]
2024-02-12 13:34:44,996 - synapse.http.site - 384 - INFO - GET-890- Connection from client lost before response was sent
2024-02-12 13:34:44,997 - synapse.access.http.8008 - 472 - INFO - GET-890- 192.168.179.106 - 8008 - {@mediabot:gogel.me} Processed request: 77.777sec/59.089sec (0.007sec, 0.003sec) (0.041sec/0.026sec/7) 0B 200! "GET /_matrix/client/v3/sync?timeout=30000&since=s1482298_108387050_11_2829280_213499_109_127685_2510947_0_39&filter=0&set_presence=online HTTP/1.1" "Python/3.11 aiohttp/3.8.5" [0 dbevts]
2024-02-12 13:34:44,998 - synapse.http.site - 384 - INFO - GET-880- Connection from client lost before response was sent
2024-02-12 13:34:44,998 - synapse.access.http.8008 - 472 - INFO - GET-880- 192.168.179.106 - 8008 - {@trumpbot:gogel.me} Processed request: 77.801sec/59.101sec (0.007sec, 0.004sec) (0.041sec/0.043sec/7) 0B 200! "GET /_matrix/client/v3/sync?timeout=30000&since=s1482298_108387050_11_2829280_213499_109_127685_2510947_0_39&filter=1&set_presence=online HTTP/1.1" "Python/3.11 aiohttp/3.8.5" [0 dbevts]
2024-02-12 13:34:44,999 - synapse.http.site - 384 - INFO - GET-888- Connection from client lost before response was sent
2024-02-12 13:34:44,999 - synapse.access.http.8008 - 472 - INFO - GET-888- 192.168.179.106 - 8008 - {@urlbot:gogel.me} Processed request: 77.789sec/59.098sec (0.005sec, 0.004sec) (0.040sec/0.026sec/7) 0B 200! "GET /_matrix/client/v3/sync?timeout=30000&since=s1482298_108387050_11_2829280_213499_109_127685_2510947_0_39&filter=0&set_presence=online HTTP/1.1" "Python/3.11 aiohttp/3.8.5" [0 dbevts]
2024-02-12 13:34:44,999 - synapse.http.site - 384 - INFO - GET-891- Connection from client lost before response was sent
2024-02-12 13:34:44,999 - synapse.access.http.8008 - 472 - INFO - GET-891- 192.168.179.106 - 8008 - {@rssbot:gogel.me} Processed request: 77.774sec/59.091sec (0.005sec, 0.003sec) (0.039sec/0.028sec/7) 0B 200! "GET /_matrix/client/v3/sync?timeout=30000&since=s1482298_108387050_11_2829280_213499_109_127685_2510947_0_39&filter=1&set_presence=online HTTP/1.1" "Python/3.11 aiohttp/3.8.5" [0 dbevts]
2024-02-12 13:34:45,000 - synapse.http.site - 384 - INFO - GET-892- Connection from client lost before response was sent
2024-02-12 13:34:45,000 - synapse.access.http.8008 - 472 - INFO - GET-892- 192.168.179.106 - 8008 - {@pollbot:gogel.me} Processed request: 77.774sec/59.090sec (0.003sec, 0.003sec) (0.038sec/0.028sec/7) 0B 200! "GET /_matrix/client/v3/sync?timeout=30000&since=s1482298_108387050_11_2829280_213499_109_127685_2510947_0_39&filter=1&set_presence=online HTTP/1.1" "Python/3.11 aiohttp/3.8.5" [0 dbevts]
2024-02-12 13:34:45,000 - synapse.http.site - 384 - INFO - GET-893- Connection from client lost before response was sent
2024-02-12 13:34:45,000 - synapse.access.http.8008 - 472 - INFO - GET-893- 192.168.179.106 - 8008 - {@stonksbot:gogel.me} Processed request: 77.773sec/59.090sec (0.006sec, 0.004sec) (0.039sec/0.025sec/7) 0B 200! "GET /_matrix/client/v3/sync?timeout=30000&since=s1482298_108387050_11_2829280_213499_109_127685_2510947_0_39&filter=0&set_presence=online HTTP/1.1" "Python/3.11 aiohttp/3.8.5" [0 dbevts]
2024-02-12 13:34:45,000 - synapse.http.site - 384 - INFO - GET-879- Connection from client lost before response was sent
2024-02-12 13:34:45,000 - synapse.access.http.8008 - 472 - INFO - GET-879- 192.168.179.106 - 8008 - {@giphybot:gogel.me} Processed request: 77.803sec/59.104sec (0.010sec, 0.003sec) (0.044sec/0.035sec/7) 0B 200! "GET /_matrix/client/v3/sync?timeout=30000&since=s1482298_108387050_11_2829280_213499_109_127685_2510947_0_39&filter=0&set_presence=online HTTP/1.1" "Python/3.11 aiohttp/3.8.5" [0 dbevts]
2024-02-12 13:34:45,001 - synapse.http.site - 384 - INFO - GET-885- Connection from client lost before response was sent
2024-02-12 13:34:45,001 - synapse.access.http.8008 - 472 - INFO - GET-885- 192.168.179.106 - 8008 - {@socialmediabot:gogel.me} Processed request: 77.804sec/59.089sec (0.010sec, 0.004sec) (0.032sec/0.039sec/7) 0B 200! "GET /_matrix/client/v3/sync?timeout=30000&since=s1482298_108387048_11_2829280_213499_109_127685_2510947_0_39&filter=0&set_presence=online HTTP/1.1" "Python/3.11 aiohttp/3.8.5" [0 dbevts]
2024-02-12 13:34:45,001 - synapse.http.site - 384 - INFO - GET-881- Connection from client lost before response was sent
2024-02-12 13:34:45,001 - synapse.access.http.8008 - 472 - INFO - GET-881- 192.168.179.106 - 8008 - {@dicebot:gogel.me} Processed request: 77.813sec/59.090sec (0.007sec, 0.005sec) (0.030sec/0.062sec/10) 0B 200! "GET /_matrix/client/v3/sync?timeout=30000&since=s1482298_108387048_11_2829280_213499_109_127685_2510947_0_39&filter=0&set_presence=online HTTP/1.1" "Python/3.11 aiohttp/3.8.5" [0 dbevts]
2024-02-12 13:34:45,001 - synapse.http.site - 384 - INFO - GET-882- Connection from client lost before response was sent
2024-02-12 13:34:45,001 - synapse.access.http.8008 - 472 - INFO - GET-882- 192.168.179.106 - 8008 - {@xkcdbot:gogel.me} Processed request: 77.797sec/59.104sec (0.005sec, 0.003sec) (0.022sec/0.067sec/7) 0B 200! "GET /_matrix/client/v3/sync?timeout=30000&since=s1482298_108387050_11_2829280_213499_109_127685_2510947_0_39&filter=0&set_presence=online HTTP/1.1" "Python/3.11 aiohttp/3.8.5" [0 dbevts]
2024-02-12 13:34:45,055 - synapse.http.site - 384 - INFO - GET-975- Connection from client lost before response was sent
2024-02-12 13:34:45,055 - synapse.access.http.8008 - 472 - INFO - GET-975- 10.0.8.2 - 8008 - {@gerrit:gogel.me} Processed request: 58.690sec/59.129sec (0.003sec, 0.000sec) (0.001sec/0.010sec/3) 0B 200! "GET /_matrix/client/v3/sync?filter=6&timeout=30000&set_presence=unavailable&since=s1482298_108387195_11_2829281_213499_109_127685_2510947_0_39 HTTP/1.1" "Mozilla/5.0 (Macintosh; Apple Mac OS X 14_3_1) AppleWebKit/537.36.0 (KHTML, like Gecko) Chrome/118.0.5993.159 Safari/537.36.0" [0 dbevts]
2024-02-12 13:34:45,067 - synapse.http.server - 683 - INFO - GET-880- Connection disconnected before response was written: AttributeError("'NoneType' object has no attribute 'registerProducer'")
2024-02-12 13:34:45,068 - synapse.http.server - 683 - INFO - GET-882- Connection disconnected before response was written: AttributeError("'NoneType' object has no attribute 'registerProducer'")
2024-02-12 13:34:45,069 - synapse.http.server - 683 - INFO - GET-883- Connection disconnected before response was written: AttributeError("'NoneType' object has no attribute 'registerProducer'")
2024-02-12 13:34:45,070 - synapse.http.server - 683 - INFO - GET-888- Connection disconnected before response was written: AttributeError("'NoneType' object has no attribute 'registerProducer'")
2024-02-12 13:34:45,071 - synapse.http.server - 683 - INFO - GET-879- Connection disconnected before response was written: AttributeError("'NoneType' object has no attribute 'registerProducer'")
2024-02-12 13:34:45,071 - synapse.http.server - 683 - INFO - GET-884- Connection disconnected before response was written: AttributeError("'NoneType' object has no attribute 'registerProducer'")
2024-02-12 13:34:45,072 - synapse.http.server - 683 - INFO - GET-886- Connection disconnected before response was written: AttributeError("'NoneType' object has no attribute 'registerProducer'")
2024-02-12 13:34:45,074 - synapse.http.server - 683 - INFO - GET-889- Connection disconnected before response was written: AttributeError("'NoneType' object has no attribute 'registerProducer'")
2024-02-12 13:34:45,075 - synapse.http.server - 683 - INFO - GET-887- Connection disconnected before response was written: AttributeError("'NoneType' object has no attribute 'registerProducer'")
2024-02-12 13:34:45,076 - synapse.http.federation.matrix_federation_agent - 371 - INFO - federation_transaction_transmission_loop-675- Failed to connect to matrix.privatephoneshop.com:443: DNS lookup failed: no results for hostname lookup: matrix.privatephoneshop.com.
2024-02-12 13:34:45,076 - synapse.http.matrixfederationclient - 799 - INFO - federation_transaction_transmission_loop-675- {PUT-O-670} [privatephoneshop.com] Request failed: PUT matrix-federation://privatephoneshop.com/_matrix/federation/v1/send/1707744598624: DNSLookupError('no results for hostname lookup: matrix.privatephoneshop.com')
2024-02-12 13:34:45,076 - synapse.http.server - 683 - INFO - GET-890- Connection disconnected before response was written: AttributeError("'NoneType' object has no attribute 'registerProducer'")
2024-02-12 13:34:45,077 - synapse.http.server - 683 - INFO - GET-891- Connection disconnected before response was written: AttributeError("'NoneType' object has no attribute 'registerProducer'")
2024-02-12 13:34:45,078 - synapse.federation.sender - 1021 - INFO - wake_destinations_needing_catchup-2- Destination danielsol.dev has outstanding catch-up, waking up.
2024-02-12 13:34:45,078 - synapse.storage.databases.main.event_push_actions - 1360 - INFO - rotate_notifs-5- Rotating notifications
2024-02-12 13:34:45,079 - synapse.http.server - 683 - INFO - GET-892- Connection disconnected before response was written: AttributeError("'NoneType' object has no attribute 'registerProducer'")
2024-02-12 13:34:45,079 - synapse.http.server - 683 - INFO - GET-893- Connection disconnected before response was written: AttributeError("'NoneType' object has no attribute 'registerProducer'")
2024-02-12 13:34:45,080 - synapse.http.server - 683 - INFO - GET-881- Connection disconnected before response was written: AttributeError("'NoneType' object has no attribute 'registerProducer'")
2024-02-12 13:34:45,081 - synapse.http.server - 683 - INFO - GET-885- Connection disconnected before response was written: AttributeError("'NoneType' object has no attribute 'registerProducer'")
2024-02-12 13:34:45,082 - synapse.http.server - 683 - INFO - GET-975- Connection disconnected before response was written: AttributeError("'NoneType' object has no attribute 'registerProducer'")
2024-02-12 13:34:45,084 - synapse.storage.databases.main.event_push_actions - 1564 - INFO - rotate_notifs-5- Rotating notifications up to: 1482298
2024-02-12 13:34:45,086 - synapse.access.http.9093 - 472 - INFO - POST-981- ::ffff:10.42.135.32 - 9093 - {None} Processed request: 0.002sec/0.109sec (0.002sec, 0.000sec) (0.000sec/0.000sec/0) 304B 200 "POST /_synapse/replication/fed_send_edu/m.presence/YYcYKscoKN HTTP/1.1" "Synapse/1.101.0rc1" [0 dbevts]
2024-02-12 13:34:45,086 - synapse.access.http.9093 - 472 - INFO - POST-982- ::ffff:10.42.193.41 - 9093 - {None} Processed request: 0.001sec/0.108sec (0.001sec, 0.000sec) (0.000sec/0.000sec/0) 304B 200 "POST /_synapse/replication/fed_send_edu/m.presence/ftRtcHzIJY HTTP/1.1" "Synapse/1.101.0rc1" [0 dbevts]
2024-02-12 13:34:45,087 - synapse.access.http.8008 - 472 - INFO - GET-983- 51.105.9.128 - 8008 - {None} Processed request: 0.000sec/0.107sec (0.001sec, 0.000sec) (0.000sec/0.000sec/0) 52B 200 "GET /_matrix/federation/v1/version HTTP/1.1" "Mozilla/5.0 (compatible; MSIE 9.0; Windows NT 6.1; Trident/5.0; AppInsights)" [0 dbevts]
2024-02-12 13:34:45,089 - synapse.federation.sender.transaction_manager - 127 - INFO - federation_transaction_transmission_loop-1437- TX [malhotra.cc] {1707744599373} Sending transaction [1707744599373], (PDUs: 0, EDUs: 1)
2024-02-12 13:34:45,091 - synapse.storage.databases.main.event_push_actions - 1650 - INFO - rotate_notifs-5- Rotating notifications, handling 0 rows
2024-02-12 13:34:45,100 - synapse.http.federation.matrix_federation_agent - 371 - INFO - federation_transaction_transmission_loop-1433- Failed to connect to matrix.ruinous.social:443: No route to host: 101: Network is unreachable.
2024-02-12 13:34:45,101 - synapse.http.matrixfederationclient - 799 - INFO - federation_transaction_transmission_loop-1433- {PUT-O-1432} [ruinous.social] Request failed: PUT matrix-federation://ruinous.social/_matrix/federation/v1/send/1707744599370: NoRouteError('Network is unreachable')
2024-02-12 13:34:45,106 - synapse.http.federation.matrix_federation_agent - 371 - INFO - federation_transaction_transmission_loop-1434- Failed to connect to matrix.timecube.club:443: HostnameAddress(hostname=b'matrix.timecube.club', port=443)
2024-02-12 13:34:45,106 - synapse.http.matrixfederationclient - 799 - INFO - federation_transaction_transmission_loop-1434- {PUT-O-1433} [timecube.club] Request failed: PUT matrix-federation://timecube.club/_matrix/federation/v1/send/1707744599371: ConnectingCancelledError(HostnameAddress(hostname=b'matrix.timecube.club', port=443))
2024-02-12 13:34:45,106 - synapse.http.federation.matrix_federation_agent - 371 - INFO - federation_transaction_transmission_loop-324- Failed to connect to libresolutions.network:443: HostnameAddress(hostname=b'libresolutions.network', port=443)
2024-02-12 13:34:45,107 - synapse.http.matrixfederationclient - 799 - INFO - federation_transaction_transmission_loop-324- {PUT-O-323} [libresolutions.network] Request failed: PUT matrix-federation://libresolutions.network/_matrix/federation/v1/send/1707744598278: ConnectingCancelledError(HostnameAddress(hostname=b'libresolutions.network', port=443))
2024-02-12 13:34:45,107 - synapse.http.matrixfederationclient - 799 - INFO - federation_transaction_transmission_loop-856- {PUT-O-849} [psps.cat] Request failed: PUT matrix-federation://psps.cat/_matrix/federation/v1/send/1707744598803: TimeoutError('Timed out after 60s')
2024-02-12 13:34:45,114 - synapse.util.caches.lrucache - 217 - INFO - LruCache._expire_old_entries-6- Dropped 0 items from caches
2024-02-12 13:34:45,116 - synapse.replication.tcp.redis - 286 - WARNING - redis_ping-10- Failed to send ping to a redis connection
2024-02-12 13:34:45,117 - synapse.replication.tcp.redis - 286 - WARNING - redis_ping-11- Failed to send ping to a redis connection

I would guess that the yield comes too late when everything is already timed out.

shyrwall commented 4 months ago

Same for me. Locks completely not even writing to logs and 100% cpu. Both 1.100.0 and 1.101.0. Rollbacked to 1.99.0 and it's fine.

Also tested 1.101.0 with https://github.com/element-hq/synapse/pull/16903 and it seems to fix the problem.

ggogel commented 4 months ago

Also tested 1.101.0 with #16903 and it seems to fix the problem.

Interesting. I think that the behavior of https://github.com/element-hq/synapse/blob/24ac3bb5cad978faeae375f0bdc3156f8f7ac227/synapse/handlers/federation_event.py#L1767 is very dependent on the host OS. In my case, it only yielded after over a minute. Whereas, with the batch-processing, the response time is about 10s in the worst case.

erikjohnston commented 4 months ago

@ggogel that shouldn't be OS dependent as its a Twisted sleep function, rather than an OS level sleep.

From the posted logs:

2024-02-12 13:20:45,032 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-1-$17077438320JejHE:gogel.me-$1707737825499kXHmJ:matrix.org- {GET-O-1724} [matrix.nek0.net] Completed request: 200 OK in 76.53 secs, got 208521768 bytes - GET matrix-federation://matrix.nek0.net/_matrix/federation/v1/state/%21WMZPgpQpdMulhwFOdV%3Amatrix.org?event_id=%241707737825499kXHmJ%3Amatrix.org
2024-02-12 13:20:45,214 - synapse.federation.federation_client - 638 - INFO - sync_partial_state_room-1-$17077438320JejHE:gogel.me-$1707737825499kXHmJ:matrix.org- Processing from /state: 10331 state events, 174754 auth events
2024-02-12 13:22:31,197 - synapse.handlers.federation_event - 1387 - INFO - sync_partial_state_room-1-$17077438320JejHE:gogel.me-$1707737825499kXHmJ:matrix.org- /state returned 185085 events
2024-02-12 13:22:39,521 - synapse.handlers.federation_event - 1690 - INFO - sync_partial_state_room-1-$17077438320JejHE:gogel.me-$1707737825499kXHmJ:matrix.org- Persisting 185053 remaining outliers: ['$155294529942816iTjCt:matrix.parity.io', '$15529497701468284rYUcd:matrix.org', '$15529834951580652snqva:matrix.org', '$15530959058876xlpYD:t2bot.io', '$15531025489411QoSlf:t2bot.io', ...]

There are a few pauses there. When did it get killed? One thing that is interesting is that it looks like we pause for almost two minutes processing the received events. Are there log lines between them?

I've also updated #16903 to also batch up the persistence, in case that was also causing problems.

ggogel commented 4 months ago

@ggogel that shouldn't be OS dependent as its a Twisted sleep function, rather than an OS level sleep.

From the posted logs:

2024-02-12 13:20:45,032 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-1-$17077438320JejHE:gogel.me-$1707737825499kXHmJ:matrix.org- {GET-O-1724} [matrix.nek0.net] Completed request: 200 OK in 76.53 secs, got 208521768 bytes - GET matrix-federation://matrix.nek0.net/_matrix/federation/v1/state/%21WMZPgpQpdMulhwFOdV%3Amatrix.org?event_id=%241707737825499kXHmJ%3Amatrix.org
2024-02-12 13:20:45,214 - synapse.federation.federation_client - 638 - INFO - sync_partial_state_room-1-$17077438320JejHE:gogel.me-$1707737825499kXHmJ:matrix.org- Processing from /state: 10331 state events, 174754 auth events
2024-02-12 13:22:31,197 - synapse.handlers.federation_event - 1387 - INFO - sync_partial_state_room-1-$17077438320JejHE:gogel.me-$1707737825499kXHmJ:matrix.org- /state returned 185085 events
2024-02-12 13:22:39,521 - synapse.handlers.federation_event - 1690 - INFO - sync_partial_state_room-1-$17077438320JejHE:gogel.me-$1707737825499kXHmJ:matrix.org- Persisting 185053 remaining outliers: ['$155294529942816iTjCt:matrix.parity.io', '$15529497701468284rYUcd:matrix.org', '$15529834951580652snqva:matrix.org', '$15530959058876xlpYD:t2bot.io', '$15531025489411QoSlf:t2bot.io', ...]

There are a few pauses there. When did it get killed? One thing that is interesting is that it looks like we pause for almost two minutes processing the received events. Are there log lines between them?

I've also updated #16903 to also batch up the persistence, in case that was also causing problems.

I filtered this part of the log for the string "partial".

In the last log, you can see that response times go over one minute and all logs are within the same second. This is after "persisting x remaining outliers" is logged. So I think it only yielded after about one minute for a fraction of a second.

I've configured the pod to get killed after 3 timeouts of 30s seconds in a 30s interval. So basically if it's unresponsive for two minutes.

I'll see if I can test the new changes.

ggogel commented 4 months ago

I built a new image based on 6fa13b4f927c10b5f4e9495be746ec28849f5cb6 and the behavior remains unchanged. I'm attaching the full log this time (25k+ lines). After Persisting 185053 remaining outliers a few lines are logged, then readiness probes trigger, and finally the liveness probes kill the container.

6fa13b4f927c10b5f4e9495be746ec28849f5cb6.log

ggogel commented 4 months ago

Just to double check I made another build based on master (equals tag 1.111.0) with the changes from #16930 cherry-picked and the behavior is still the same.

6fa13b4f927c10b5f4e9495be746ec28849f5cb6-master_2024-02-15_00-45-45.log

ggogel commented 4 months ago

@erikjohnston I got py-spy working by adding this to the deployment:

securityContext:
  capabilities:
    add:
    - SYS_PTRACE

I used the build based on 1.111.0 with the changes from #16903.

I pulled three flame graphs right after Persisting ... remaining outliers: output-1 output-2 output-3

Looks like it's already stalling here: https://github.com/element-hq/synapse/blob/6fa13b4f927c10b5f4e9495be746ec28849f5cb6/synapse/handlers/federation_event.py#L1741-L1743

shyrwall commented 4 months ago

Same for me. Locks completely not even writing to logs and 100% cpu. Both 1.100.0 and 1.101.0. Rollbacked to 1.99.0 and it's fine.

Also tested 1.101.0 with #16903 and it seems to fix the problem.

Problem came back so I guess it was correct that #16903 did not fix it. Sorry for the wrong post.

jaywink commented 4 months ago

We had an EMS host with this issue and applying #16903 on top of v1.101.0 did help:

Before the patch the synapse main process was being constantly killed due to liveness probes failing as reported here.

ggogel commented 4 months ago

It probably depends a lot on the room.

Which room was it and how many outlier objects did it have?

ggogel commented 4 months ago

@anoadragon453, could you please provide specifics regarding the tests you conducted? It would be helpful to know which rooms were tested and the number of outlier events identified in each.

In the screenshot of @jaywink it seems like the CPU was a bottleneck. In my case, there is no CPU bottleneck.

anoadragon453 commented 4 months ago

@ggogel Sorry, I was referring to the EMS host that @jaywink has already mentioned. I don't know any further details than that at the moment, as I haven't delved too deeply into this issue myself.

ggogel commented 4 months ago

@anoadragon453 So, was there any internal discussion before deciding on this fix, or was it accepted based on the provided information?

I'm asking because if this solution only works for rooms with around 10k outliers but still causes issues in rooms with over 100k outliers, then it might not really solve the problem.

@shyrwall also posted that the patch fixes the issue on their side. Then the issue came back again. Because it all depends on the room. If we're not testing the patch on the same rooms then any discussion about the issue being fixed is pointless because the results are not comparable.

daedric7 commented 4 months ago

I think i hit this bug, running v1.102.0rc1.

After joining #_oftc_#osm:matrix.org:

anoadragon453 commented 4 months ago

@ggogel The latter. I'm afraid I don't have much time to devote to this issue at the moment, but hope to do so in the next couple of weeks.

jaywink commented 4 months ago

@anoadragon453 we hit this with attendees.fosdem.org (fosdem-attendees.ems.host), k8s has been constantly killing it due to liveness probes failing, until I applied https://github.com/element-hq/synapse/pull/16903, which stabilized it. The previously mentioned customer host issues have not returned, I'll monitor whether the FOSDEM attendees host stays stable.

Which room was it and how many outlier objects did it have?

Is there an easy way to figure out the room?

ggogel commented 4 months ago

Is there an easy way to figure out the room?

You can filter the logs of the main worker for the keyword "partial". This gives you all the log entries regarding partial join, which should include the room ID.

jaywink commented 4 months ago

!YTvKGNlinIzlkMTVRl:matrix.org ie #element-web:matrix.org does have a ton of log activity with the word partial. It does feel it has died down since I patched it, so maybe that room?

ggogel commented 4 months ago

Most likely. After the partial join is completed, these log messages stop and the temporary partial room copy is turned into a "full" room copy. At least from my understanding.

I cannot currently test any official matrix.org rooms, like #element-web:matrix.org, since my homeserver is banned from them. I'm still awaiting a response from abuse@matrix.org.

ggogel commented 4 months ago

I think we're hitting two different problems after the change.

1) Stalling due to not releasing the CPU, which was likely fixed in #16903.

2) A potential deadlock here, as seen in the flame graphs posted by me. https://github.com/element-hq/synapse/blob/6fa13b4f927c10b5f4e9495be746ec28849f5cb6/synapse/event_auth.py#L178-L180

I created a PR #16968, with additional information on why I believe this is a deadlock.

jaywink commented 4 months ago

@ggogel I think attendees.fosdem.org now hit the second part as described above by you. I tried your patch on it and it seems to have managed to unstick the host from being constantly killed due to deadlock, but it also breaks room creation:

Traceback (most recent call last):
  File "/usr/local/lib/python3.11/site-packages/synapse/http/server.py", line 332, in _async_render_wrapper
    callback_return = await self._async_render(request)
                      ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/synapse/http/server.py", line 544, in _async_render
    callback_return = await raw_callback_return
                      ^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/synapse/rest/client/room.py", line 171, in on_POST
    return await self._do(request, requester)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/synapse/rest/client/room.py", line 176, in _do
    room_id, _, _ = await self._room_creation_handler.create_room(
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/synapse/handlers/room.py", line 948, in create_room
    ) = await self._send_events_for_new_room(
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/synapse/handlers/room.py", line 1309, in _send_events_for_new_room
    last_event = await self.event_creation_handler.handle_new_client_event(
                 ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/synapse/util/metrics.py", line 120, in measured_func
    r = await func(self, *args, **kwargs)
        ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/site-packages/synapse/handlers/message.py", line 1466, in handle_new_client_event
    await self._event_auth_handler.check_auth_rules_from_context(
  File "/usr/local/lib/python3.11/site-packages/synapse/handlers/event_auth.py", line 70, in check_auth_rules_from_context
    await check_state_independent_auth_rules(
  File "/usr/local/lib/python3.11/site-packages/synapse/event_auth.py", line 181, in check_state_independent_auth_rules
    auth_events = copy.deepcopy(batched_auth_events)
                  ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/copy.py", line 146, in deepcopy
    y = copier(x, memo)
        ^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/copy.py", line 231, in _deepcopy_dict
    y[deepcopy(key, memo)] = deepcopy(value, memo)
                             ^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/copy.py", line 172, in deepcopy
    y = _reconstruct(x, memo, *rv)
        ^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/copy.py", line 271, in _reconstruct
    state = deepcopy(state, memo)
            ^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/copy.py", line 146, in deepcopy
    y = copier(x, memo)
        ^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/copy.py", line 231, in _deepcopy_dict
    y[deepcopy(key, memo)] = deepcopy(value, memo)
                             ^^^^^^^^^^^^^^^^^^^^^
  File "/usr/local/lib/python3.11/copy.py", line 161, in deepcopy
    rv = reductor(4)
         ^^^^^^^^^^^
TypeError: cannot pickle 'builtins.EventInternalMetadata' object

ggogel commented 4 months ago

@ggogel I think attendees.fosdem.org now hit the second part as described above by you. I tried your patch on it and it seems to have managed to unstick the host from being constantly killed due to deadlock, but it also breaks room creation

Thanks for the feedback. I also hit this error at some point. I'm working on a different implementation now.

ggogel commented 4 months ago

@jaywink The problem seems to be fixed on the latest version of my PR. I was able to join the rooms #element-web:matrix.org, #synapse:matrix.org and #element-android:matrix.org. I'm going to test more rooms soon.

element-hq / synapse