Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

High DB usage while logs continuously say sync_partial_state_room-244 - Updating state for $eventid #16980

Open
anoadragon453 opened this issue Mar 5, 2024 · 1 comment
Open

High DB usage while logs continuously say sync_partial_state_room-244 - Updating state for $eventid #16980

anoadragon453 opened this issue Mar 5, 2024 · 1 comment
Labels
A-Database O-Occasional S-Major T-Defect

Comments

@anoadragon453
Copy link
Member

anoadragon453 commented Mar 5, 2024 •
edited
Loading

Description

After deploying v1.102.0 final release on matrix.org, we noticed that the get_partial_state_events_batch DB txn was taking a lot of DB time on the main process. The restart happened at 13:03 (the gap):

image

Potentially related to #16895, though with a different failure mode.

This is hammering the database. At the moment we're waiting to see if the partial sync completes successfully.

Steps to reproduce

Join a room over federation with partial room joins enabled.

Homeserver

matrix.org

Synapse Version

v1.102.0

Installation Method

pip (from PyPI)

Database

PostgreSQL

Workers

Multiple workers

Platform

linux

Configuration

No response

Relevant log output

Click to see log output 
2024-03-05 13:03:39,418 - synapse.handlers.federation - 1917 - INFO - sync_partial_state_room-244 - Syncing state for room !redacted via pixie.town
2024-03-05 13:03:57,312 - synapse.handlers.federation_event - 628 - INFO - sync_partial_state_room-244 - Updating state for $H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc
2024-03-05 13:03:59,173 - synapse.handlers.federation_event - 1129 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc- - Event $H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc is missing prev_events ['$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw']: calculating state for a backwards extremity
2024-03-05 13:03:59,173 - synapse.handlers.federation_event - 1151 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc- - Requesting state after missing prev_event $4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw
2024-03-05 13:04:11,322 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw-- - {GET-O-2500} [pixie.town] Completed request: 200 OK in 12.15 secs, got 1252629 bytes - GET matrix-federation://pixie.town/_matrix/federation/v1/state_ids/%21FoJntBPsgEcEgAcddK%3Apixie.town?event_id=%244yWz8-DUZbbktdlkYXFUrI3
2024-03-05 13:05:42,921 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw--- - {GET-O-7483} [pixie.town] Completed request: 200 OK in 71.00 secs, got 22325777 bytes - GET matrix-federation://pixie.town/_matrix/federation/v1/state/%21FoJntBPsgEcEgAcddK%3Apixie.town?event_id=%244yWz8-DUZbbktdlkYXFUrI3ZA
2024-03-05 13:05:44,544 - synapse.federation.federation_client - 638 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw--- - Processing from /state: 1786 state events, 24858 auth events
2024-03-05 13:06:16,429 - synapse.handlers.federation_event - 1387 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw-- - /state returned 26644 events
2024-03-05 13:06:35,167 - synapse.handlers.federation_event - 1690 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw--- - Persisting 3278 remaining outliers: ['$-4ynY9w4mVnrZAPfAb1SQ3OLLr-lwtX1Kwq7S1ygmK0', '$-BL74jNOWkAOANfGgHg3auPKFd8iDOIdcCW74vyIuWo', '$-SVvPXeNreDFV2YI-d3V09moBVI6-66byRf0ZoS5gNQ', '$-VGBEGeNnNkwCoaMiR1AjgHoXRNHI60O49dRHESoa
2024-03-05 13:06:39,981 - synapse.http.client - 929 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw----- - Received response to POST synapse-replication://event_persister-2/_synapse/replication/fed_send_events/QhOKxsUtEN: 200
2024-03-05 13:06:39,982 - synapse.replication.tcp.client - 330 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw---- - Waiting for repl stream 'events' to reach 4751683348 (event_persister-2); currently at: 4751682674
2024-03-05 13:06:45,056 - synapse.replication.tcp.client - 340 - WARNING - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw---- - Timed out waiting for repl stream 'events' to reach 4751683348 (event_persister-2); currently at: 4751683057
2024-03-05 13:06:45,056 - synapse.replication.tcp.client - 330 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw---- - Waiting for repl stream 'backfill' to reach 47736336 (event_persister-2); currently at: 47736135
2024-03-05 13:06:48,331 - synapse.replication.tcp.client - 350 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw---- - Finished waiting for repl stream 'backfill' to reach 47736336 (event_persister-2)
2024-03-05 13:06:49,929 - synapse.http.client - 929 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw----- - Received response to POST synapse-replication://event_persister-2/_synapse/replication/fed_send_events/eSZNlUbcMx: 200
2024-03-05 13:06:49,930 - synapse.replication.tcp.client - 330 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw---- - Waiting for repl stream 'events' to reach 4751683720 (event_persister-2); currently at: 4751683511
2024-03-05 13:06:51,879 - synapse.replication.tcp.client - 350 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw---- - Finished waiting for repl stream 'events' to reach 4751683720 (event_persister-2)
2024-03-05 13:06:51,879 - synapse.replication.tcp.client - 330 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw---- - Waiting for repl stream 'backfill' to reach 47736539 (event_persister-2); currently at: 47736439
2024-03-05 13:06:51,896 - synapse.replication.tcp.client - 350 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw---- - Finished waiting for repl stream 'backfill' to reach 47736539 (event_persister-2)
2024-03-05 13:06:54,058 - synapse.http.client - 929 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw----- - Received response to POST synapse-replication://event_persister-2/_synapse/replication/fed_send_events/PrKgEqCrUJ: 200
2024-03-05 13:06:54,058 - synapse.replication.tcp.client - 330 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw---- - Waiting for repl stream 'events' to reach 4751683872 (event_persister-2); currently at: 4751683859
2024-03-05 13:06:54,390 - synapse.replication.tcp.client - 350 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw---- - Finished waiting for repl stream 'events' to reach 4751683872 (event_persister-2)
2024-03-05 13:06:54,390 - synapse.replication.tcp.client - 330 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw---- - Waiting for repl stream 'backfill' to reach 47736739 (event_persister-2); currently at: 47736639
2024-03-05 13:06:54,424 - synapse.replication.tcp.client - 350 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw---- - Finished waiting for repl stream 'backfill' to reach 47736739 (event_persister-2)
2024-03-05 13:06:57,497 - synapse.http.client - 929 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw----- - Received response to POST synapse-replication://event_persister-2/_synapse/replication/fed_send_events/haeYAifNLt: 200
2024-03-05 13:06:57,498 - synapse.replication.tcp.client - 330 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw---- - Waiting for repl stream 'backfill' to reach 47736939 (event_persister-2); currently at: 47736839
2024-03-05 13:06:57,576 - synapse.replication.tcp.client - 350 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw---- - Finished waiting for repl stream 'backfill' to reach 47736939 (event_persister-2)
2024-03-05 13:06:59,591 - synapse.http.client - 929 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw----- - Received response to POST synapse-replication://event_persister-2/_synapse/replication/fed_send_events/GtIIVqoKuz: 200
2024-03-05 13:06:59,594 - synapse.replication.tcp.client - 330 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw---- - Waiting for repl stream 'backfill' to reach 47737139 (event_persister-2); currently at: 47737039
2024-03-05 13:06:59,671 - synapse.replication.tcp.client - 350 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw---- - Finished waiting for repl stream 'backfill' to reach 47737139 (event_persister-2)
2024-03-05 13:07:01,123 - synapse.http.client - 929 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw----- - Received response to POST synapse-replication://event_persister-2/_synapse/replication/fed_send_events/cOGPtOyHPt: 200
2024-03-05 13:07:01,123 - synapse.replication.tcp.client - 330 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw---- - Waiting for repl stream 'backfill' to reach 47737339 (event_persister-2); currently at: 47737239
2024-03-05 13:07:01,163 - synapse.replication.tcp.client - 350 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw---- - Finished waiting for repl stream 'backfill' to reach 47737339 (event_persister-2)
2024-03-05 13:07:02,497 - synapse.http.client - 929 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw----- - Received response to POST synapse-replication://event_persister-2/_synapse/replication/fed_send_events/XLqUkCUyXY: 200
2024-03-05 13:07:03,360 - synapse.http.client - 929 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw----- - Received response to POST synapse-replication://event_persister-2/_synapse/replication/fed_send_events/sDgzudgLnZ: 200
2024-03-05 13:07:03,360 - synapse.replication.tcp.client - 330 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw---- - Waiting for repl stream 'backfill' to reach 47737741 (event_persister-2); currently at: 47737641
2024-03-05 13:07:03,418 - synapse.replication.tcp.client - 350 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw---- - Finished waiting for repl stream 'backfill' to reach 47737741 (event_persister-2)
2024-03-05 13:07:04,681 - synapse.http.client - 929 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw----- - Received response to POST synapse-replication://event_persister-2/_synapse/replication/fed_send_events/XPMDwvzSzx: 200
2024-03-05 13:07:04,681 - synapse.replication.tcp.client - 330 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw---- - Waiting for repl stream 'backfill' to reach 47737941 (event_persister-2); currently at: 47737841
2024-03-05 13:07:04,729 - synapse.replication.tcp.client - 350 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw---- - Finished waiting for repl stream 'backfill' to reach 47737941 (event_persister-2)
2024-03-05 13:07:05,640 - synapse.http.client - 929 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw----- - Received response to POST synapse-replication://event_persister-2/_synapse/replication/fed_send_events/iaFoHXTZft: 200
2024-03-05 13:07:05,641 - synapse.replication.tcp.client - 330 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw---- - Waiting for repl stream 'backfill' to reach 47738141 (event_persister-2); currently at: 47738041
2024-03-05 13:07:05,684 - synapse.replication.tcp.client - 350 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw---- - Finished waiting for repl stream 'backfill' to reach 47738141 (event_persister-2)
2024-03-05 13:07:06,494 - synapse.http.client - 929 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw----- - Received response to POST synapse-replication://event_persister-2/_synapse/replication/fed_send_events/ETXsDuGxss: 200
2024-03-05 13:07:06,494 - synapse.replication.tcp.client - 330 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw---- - Waiting for repl stream 'backfill' to reach 47738342 (event_persister-2); currently at: 47738242
2024-03-05 13:07:06,558 - synapse.replication.tcp.client - 350 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw---- - Finished waiting for repl stream 'backfill' to reach 47738342 (event_persister-2)
2024-03-05 13:07:07,463 - synapse.http.client - 929 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw----- - Received response to POST synapse-replication://event_persister-2/_synapse/replication/fed_send_events/QnoHUjVgFG: 200
2024-03-05 13:07:07,464 - synapse.replication.tcp.client - 330 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw---- - Waiting for repl stream 'backfill' to reach 47738542 (event_persister-2); currently at: 47738442
2024-03-05 13:07:07,490 - synapse.replication.tcp.client - 350 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw---- - Finished waiting for repl stream 'backfill' to reach 47738542 (event_persister-2)
2024-03-05 13:07:08,368 - synapse.http.client - 929 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw----- - Received response to POST synapse-replication://event_persister-2/_synapse/replication/fed_send_events/PcmBNktafn: 200
2024-03-05 13:07:08,368 - synapse.replication.tcp.client - 330 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw---- - Waiting for repl stream 'backfill' to reach 47738742 (event_persister-2); currently at: 47738642
2024-03-05 13:07:08,407 - synapse.replication.tcp.client - 350 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw---- - Finished waiting for repl stream 'backfill' to reach 47738742 (event_persister-2)
2024-03-05 13:07:09,184 - synapse.http.client - 929 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw----- - Received response to POST synapse-replication://event_persister-2/_synapse/replication/fed_send_events/WaHBqABMMU: 200
2024-03-05 13:07:09,184 - synapse.replication.tcp.client - 330 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw---- - Waiting for repl stream 'backfill' to reach 47738942 (event_persister-2); currently at: 47738842
2024-03-05 13:07:09,229 - synapse.replication.tcp.client - 350 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw---- - Finished waiting for repl stream 'backfill' to reach 47738942 (event_persister-2)
2024-03-05 13:07:10,094 - synapse.http.client - 929 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw----- - Received response to POST synapse-replication://event_persister-2/_synapse/replication/fed_send_events/pUiDgPHBLs: 200
2024-03-05 13:07:10,095 - synapse.replication.tcp.client - 330 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw---- - Waiting for repl stream 'backfill' to reach 47739142 (event_persister-2); currently at: 47739042
2024-03-05 13:07:10,126 - synapse.replication.tcp.client - 350 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw---- - Finished waiting for repl stream 'backfill' to reach 47739142 (event_persister-2)
2024-03-05 13:07:10,869 - synapse.http.client - 929 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw----- - Received response to POST synapse-replication://event_persister-2/_synapse/replication/fed_send_events/nljjhUMXFb: 200
2024-03-05 13:07:10,869 - synapse.replication.tcp.client - 330 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw---- - Waiting for repl stream 'backfill' to reach 47739342 (event_persister-2); currently at: 47739242
2024-03-05 13:07:10,915 - synapse.replication.tcp.client - 350 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw---- - Finished waiting for repl stream 'backfill' to reach 47739342 (event_persister-2)
2024-03-05 13:07:11,280 - synapse.http.client - 929 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw----- - Received response to POST synapse-replication://event_persister-2/_synapse/replication/fed_send_events/xPJvGFuKYH: 200
2024-03-05 13:07:11,281 - synapse.replication.tcp.client - 330 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw---- - Waiting for repl stream 'backfill' to reach 47739420 (event_persister-2); currently at: 47739342
2024-03-05 13:07:11,311 - synapse.replication.tcp.client - 350 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw---- - Finished waiting for repl stream 'backfill' to reach 47739420 (event_persister-2)
2024-03-05 13:07:11,506 - synapse.http.matrixfederationclient - 362 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw----$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw- - {GET-O-12822} [pixie.town] Completed request: 200 OK in 0.17 secs, got 774 bytes - GET matrix-federation://pixie.town/_matrix/federation/v1/event/%244yWz8-DUZbbktdlkYXFUrI3ZAfXx
2024-03-05 13:07:11,508 - synapse.handlers.federation_event - 1638 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw--- - Fetched 1 events of 1 requested
2024-03-05 13:07:11,508 - synapse.handlers.federation_event - 1690 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw---- - Persisting 1 remaining outliers: ['$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw']
2024-03-05 13:07:11,550 - synapse.http.client - 929 - INFO - sync_partial_state_room-244-$H_h1mqnAkXjIg7BKpQZoEDAF1sQntb1ypYvv7DbWsmc--$4yWz8-DUZbbktdlkYXFUrI3ZAfXxmzSfWAybKj_DSUw------ - Received response to POST synapse-replication://event_persister-2/_synapse/replication/fed_send_events/UcjgvsJOXQ: 200
2024-03-05 13:07:13,624 - synapse.handlers.federation_event - 628 - INFO - sync_partial_state_room-244 - Updating state for $lwXtryTVdA9GncJHnj-oH1jmPro9Cbnzj2-J0wKyThk
2024-03-05 13:07:14,493 - synapse.handlers.federation_event - 628 - INFO - sync_partial_state_room-244 - Updating state for $pB-icAKJTTHGPv_7RKC-OipO6OW2RZw4axExCRpEw1U
2024-03-05 13:07:14,571 - synapse.handlers.federation_event - 628 - INFO - sync_partial_state_room-244 - Updating state for $XOWsJkRK6GNiF-tN6ts4wTUUzasdzXBiS55qFYSeSEQ
2024-03-05 13:07:15,406 - synapse.handlers.federation_event - 628 - INFO - sync_partial_state_room-244 - Updating state for $KMlU0n2SLVv3-5ap8vX9-JYcTX5UPGFMDHkvg7QP25A
2024-03-05 13:07:16,248 - synapse.handlers.federation_event - 628 - INFO - sync_partial_state_room-244 - Updating state for $1c72mLfsazsAMq89UvMm-aL9hUOQW9SkKnJPp2ZQ_fI
2024-03-05 13:07:17,107 - synapse.handlers.federation_event - 628 - INFO - sync_partial_state_room-244 - Updating state for $tx29v3bWlNv_SSKPxnS8rHYZAu4cpe2OVlDbX0QDps0
2024-03-05 13:07:17,158 - synapse.state - 668 - INFO - sync_partial_state_room-244-$tx29v3bWlNv_SSKPxnS8rHYZAu4cpe2OVlDbX0QDps0--- - Resolving state for !redacted with groups [871818734, 871818751]
2024-03-05 13:07:18,889 - synapse.handlers.federation_event - 628 - INFO - sync_partial_state_room-244 - Updating state for $vIVUmnseSYThrprQMgodllJU85ryAJOdMhzeKFEqyHg
2024-03-05 13:07:19,681 - synapse.handlers.federation_event - 628 - INFO - sync_partial_state_room-244 - Updating state for $q9kvCDQZS-lZirPTLH9nTzR1KCQSyJsednWxUACAdF8
2024-03-05 13:07:20,499 - synapse.handlers.federation_event - 628 - INFO - sync_partial_state_room-244 - Updating state for $O7nuFFdjk80Cfj8iNYDfzUAtktBMPDLcHedwD779t2k
2024-03-05 13:07:21,359 - synapse.handlers.federation_event - 628 - INFO - sync_partial_state_room-244 - Updating state for $l2TwbsIm78sz23x9ARJKLsJY90Q5WWk7tuXWraXQDMs
2024-03-05 13:07:22,247 - synapse.handlers.federation_event - 628 - INFO - sync_partial_state_room-244 - Updating state for $T5N2C9z6-KQlQG8lxWhiSd1MX2ZQrrkHfXMbviADoYo
2024-03-05 13:07:23,173 - synapse.handlers.federation_event - 628 - INFO - sync_partial_state_room-244 - Updating state for $OVrCsgdHviH20PTLl4O0ZiwXAGN51aqkUk_N5bPY9ZI
2024-03-05 13:07:24,090 - synapse.handlers.federation_event - 628 - INFO - sync_partial_state_room-244 - Updating state for $hzdJkNCIvcBbSKei92PKaGDf1yyRDLC1tyAxA_At768
2024-03-05 13:07:25,007 - synapse.handlers.federation_event - 628 - INFO - sync_partial_state_room-244 - Updating state for $1s80bOxuZlmS3dqlBegdL-u6qkC0JuOpXaKPEXuK90E
2024-03-05 13:07:26,400 - synapse.handlers.federation_event - 628 - INFO - sync_partial_state_room-244 - Updating state for $EPOabdEMG1ga5no1K2m9qh0OKnPH_7GEA-XNldF9idw
2024-03-05 13:07:27,447 - synapse.handlers.federation_event - 628 - INFO - sync_partial_state_room-244 - Updating state for $IbUWbi1neFFIgP7VribdEaRq8Ka1bmk6oolSL99F5BI
2024-03-05 13:07:28,448 - synapse.handlers.federation_event - 628 - INFO - sync_partial_state_room-244 - Updating state for $5lZc2ucAt-FaaaOS-aIiE7YyYMMMP-knbZ6ZH-JKWEk
2024-03-05 13:07:29,235 - synapse.handlers.federation_event - 628 - INFO - sync_partial_state_room-244 - Updating state for $t50HKgV8C1A2q13YNqEEzGXiWY8w_81-pqtLCazS0Ic
2024-03-05 13:07:30,287 - synapse.handlers.federation_event - 628 - INFO - sync_partial_state_room-244 - Updating state for $GyOykj_w2gLVrt6g6s9lZTKjEpqd_kALzYkHtfLeIl0
2024-03-05 13:07:31,217 - synapse.handlers.federation_event - 628 - INFO - sync_partial_state_room-244 - Updating state for $3-geVsRwjyea1sr6Oo2oBXcnuJ_hEGb28XCeg1vQbCQ
2024-03-05 13:07:32,155 - synapse.handlers.federation_event - 628 - INFO - sync_partial_state_room-244 - Updating state for $wqX7SQqIdJX_QURV3Angf7n3lTnuaOAYa10eMldzgyI
2024-03-05 13:07:32,964 - synapse.handlers.federation_event - 628 - INFO - sync_partial_state_room-244 - Updating state for $iTP2mJH_IryadahiEaBLgT2-YgHsvWNu6zv-5uskAkg
2024-03-05 13:07:33,767 - synapse.handlers.federation_event - 628 - INFO - sync_partial_state_room-244 - Updating state for $YxzY0i7SLzwKJHsz-BOIWLbfUZIXJc4x-woqZWri7Q4
...

Anything else that would be useful to know?

No response
@anoadragon453
Copy link
Member Author

To resolve this on matrix.org, we ended up purging the room from the database (using the v2 Delete Room Admin API) and restarting the main process to clear the job.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
A-Database O-Occasional S-Major T-Defect
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@anoadragon453 @reivilibre