very slow sync with element-web 1.11.110 since upgrading synapse to v1.138.0

[twouters]

Description

Since upgrading synapse from 1.137.0 to 1.138.0 syncing takes ~15-20min when I reload element-web before I'm able to chat.

Something similar happened before the summer until 1.135.0 (I think) was released, but I suppose it's a new issue now since that fix is still present.

Steps to reproduce

• run v.1.37.0
• reload element-web and have a (somewhat) quick sync
• upgrade to v1.38.0
• reload element-web and notice a very slow sync

Homeserver

my own server

Synapse Version

v1.138.0

Installation Method

Docker (matrixdotorg/synapse)

Database

postgresql, single server

Workers

Single process

Platform

Running on an older machine with slow disks, so it has always been a bit slow and these performance regressions tend to have a big impact.

Configuration

No response

Relevant log output

Will collect them if needed. The reason for this report is mostly to raise awareness of a performance regression between the previous release and the last one.

Anything else that would be useful to know?

Synapse is running behind an nginx reverse proxy.

[anoadragon453]

@twouters thanks for your report. I assume you are talking about /_matrix/client/v3/sync requests as you mentioned Element Web (which only experimentally supports sliding sync). If you could provide logs from your Synapse instance surrounding any slow /sync requests that would help us identify where to start looking.

If you have metrics for your host and can identify any spikes in graphs when a /sync request is performed, then even better.

[twouters]

I'm not using sliding sync.
Will gather some logs but don't have metrics enabled at this time.

[twouters]

I'm not using sliding sync. Will gather some logs but don't have metrics enabled at this time.

[twouters]

I've activated metrics and setup a prometheus+grafana last weekend + upgraded synapse to 35c9cbb but did not see any improvements.

I've restarted element-desktop at 13:35 CEST and was able to use it at 14:05(-ish)

Are there any specific grafana panels I can share? (exporting to raintank worked for one panel Cache size but it seems like they're having an outage because I currently can't export more.

[MadLittleMods]

Are there any specific grafana panels I can share?

@twouters Overview section, Database section, Requests section, anything that stands out

upgraded synapse to 35c9cbb

There is a fix for a performance regression right after the commit you used. You can try out v1.138.2 which also includes the fix. Although this is unrelated to /sync, it may be something affecting the entire process.

[twouters]

huh, weird, i explicitly picked that release because it (should?) include that change? ddc7627

Anyway, I'll give v1.138.2 a try.

[twouters]

version 1.138.2 still syncs very slow, restarted my client at 17:35 CEST and it took more than 30 minutes to sync.

I'll start with screenshots for now, let me know if you need more details.

Overview section

Database section

Requests section

[anoadragon453]

@twouters Looks like your server is definitely DB-constrained.

Could you provide some of the top contenders under the "DB transaction by total txn time" graph so we can see what queries specifically are taking the longest? We can then cross-check with any that may have changed in v1.138.0.

[twouters]

external sharing seems to be working again atm: https://snapshots.raintank.io/dashboard/snapshot/POHUEthyvt2EjrLJttbhMvnrnU1Aiu2o

I downgraded to v1.137.0 and am still experiencing this issue.
EXA had some issues with syncing as well (since upgrading to v1.138.2), so I logged out and cleared all data and logged in again to resolve those syncing issues, not sure what was going on.
I just did the same with element-web(/desktop) and am waiting for the initial sync to complete.

It might not be directly related to going from 1.137.0 to 1.138.0 since the downgrade resulted in the same slow sync, so if nothing comes out of the provided data (see raintank like) we might as well close this issue and I'll reopen a new one once I've had the time to figure out what happened and can reproduce the same issues.

[twouters]

Just restarted element after the initial sync and it's up after a minute or so (on v1.137.0) so I'll upgrade tomorrow and see what happens.

[twouters]

Yeah, i'm a bit impatient. Upgraded to 1.138.2 and restarted element and I'm already logged in.

[anoadragon453]

FYI from the grafana graphs, the most intense queries were:

• quick burst of 500% persist_events
• sustained 288% do_fetch
• quick burst of 616% get_recent_references_for_event
• about five bursts of 250-500% get_thread_summaries
• 125% get_threads_participated

Which sounds like threading may need some optimisation at the DB layer. cc @reivilibre who is working in the area at the moment, for your interest.