Posting is slow in larger communities

[ruudschilders]

Posting / commenting is very slow in larger communities

• When you click 'Post' or 'Reply', the icon will become spinning
• The post will immediately be available (if you check another tab)
• The spinning wheel will take up to 30 seconds !
• If you hit 'refresh' right after submitting, the post will be there. (So what is the 'Post' actually doing after it has inserted the post into the database??)

In the database I don't see long-running queries (over 2 seconds), but I do see many locks. When selecting from pg_locks I see the number varying between none and hundreds, continuously

[ruudschilders]

I want to add that this is a major issue for Lemmy.world right now. Performance is really good except for this issue.

[johanndt]

I've been helping Ruud look at this a bit @Nutomic, and I'm starting to think it's not db. If you post, and then in another window refresh the comments, the new reply is almost instantly there. So it gets inserted to the DB very fast. Maybe there's some other db things which happen which might make the database label accurate, but it could just as easily be something happening in the rust code after the insert. Or even some exception being raised and the server never replies to the client which is waiting.

The spinning wheel almost always stop after the same amount of time, eg 30 seconds, suggesting it's nginx or the web server closing the connection after x seconds.

[RocketDerp]

I'm starting to think it's not db. If you post, and then in another window refresh the comments, the new reply is almost instantly there.

There are numerous places within the lemmy-ui webapp that seem to spin forever when encountering an error. The sign-up and login form both have issues with this behavior in 0.17.3 when encountering predictable problems, such as trying to sign-up with a username that already exists.

If you go to the official developer testing server sign-on form and try to create an account called "RocketDerp" that already exists, it does not deal with this gracefully. https://voyager.lemmy.ml/signup

[ruudschilders]

Most times the spinning wheel does stop after 20 to 30 seconds and you're returned to the page you were, just like it should. (but should be faster :-) ) So no error occurs.

[RocketDerp]

When selecting from pg_locks I see the number varying between none and hundreds, continuously

I created a Lemmy posting HOWTO of looking at pg_locks like the screen shot says: https://lemmy.ml/post/1237418

[ruudschilders]

Thanks, I'll check once lemmy.ml is back (gives 502 now)

[snowe2010]

Most times the spinning wheel does stop after 20 to 30 seconds and you're returned to the page you were, just like it should. (but should be faster :-) ) So no error occurs.

I've left it and seen the spinning wheel go for hours with no response. I see no logs in any of the docker containers either. So it's very confusing to me what could be happening.

[RocketDerp]

There is a PostgreSQL extension pg_stat_statements for helping track which statements are running into performance problems. I think this has less overhead than cranking up logging.

https://www.timescale.com/blog/identify-postgresql-performance-bottlenecks-with-pg_stat_statements/

Install steps on Ubuntu:

https://pganalyze.com/docs/install/self_managed/02_enable_pg_stat_statements_deb

Using the convention of "Lemmy from Scratch" install instructions:

sudo -iu postgres psql -c "ALTER SYSTEM SET shared_preload_libraries = 'pg_stat_statements';"

And the database server has to be restarted.

I'm seeing high execution average time for incoming federation data on this SQL: INSERT INTO "comment_like" ("person_id", "comment_id", "post_id", "score") VALUES ($1, $2, $3, $4) ON CONFLICT ("comment_id", "person_id") DO UPDATE SET "person_id" = $5, "comment_id" = $6, "post_id" = $7, "score" = $8 RETURNING "comment_like"."id", "comment_like"."person_id", "comment_like"."comment_id", "comment_like"."post_id", "comment_like"."score", "comment_like"."published"

With federation-only activity (I only have myself as interactive user), I am also finding this query is called thousands of times and running very slow, with average time over 9 seconds for each run: SELECT "person"."id", "person"."name", "person"."display_name", "person"."avatar", "person"."banned", "person"."published", "person"."updated", "person"."actor_id", "person"."bio", "person"."local", "person"."banner", "person"."deleted", "person"."inbox_url", "person"."shared_inbox_url", "person"."matrix_user_id", "person"."admin", "person"."bot_account", "person"."ban_expires", "person"."instance_id", "person_aggregates"."id", "person_aggregates"."person_id", "person_aggregates"."post_count", "person_aggregates"."post_score", "person_aggregates"."comment_count", "person_aggregates"."comment_score" FROM ("person" INNER JOIN "person_aggregates" ON ("person_aggregates"."person_id" = "person"."id")) WHERE (("person"."admin" = $1) AND ("person"."deleted" = $2)) ORDER BY "person"."published"

[RocketDerp]

Ok, so is the query that is being run thousands of times (with federation incoming data being the primary activity of my instance) this query?

https://github.com/LemmyNet/lemmy/blob/d97ff65fe1e9c31e9f7c977a66100816816e07be/crates/db_views_actor/src/person_view.rs#LL37C6-L37C6

  pub async fn admins(pool: &DbPool) -> Result<Vec<Self>, Error> {
    let conn = &mut get_conn(pool).await?;
    let admins = person::table
      .inner_join(person_aggregates::table)
      .select((person::all_columns, person_aggregates::all_columns))
      .filter(person::admin.eq(true))
      .filter(person::deleted.eq(false))
      .order_by(person::published)
      .load::<PersonViewTuple>(conn)
      .await?;

Searching for Admins in the person table?

[ruudschilders]

I found the cause of the issue. I had the 'Federation debug' mode enabled in admin settings. This causes federation to happen in the foreground when posting. I apparently forgot to turn it off after the initial troubleshooting...

Turning the setting off and restarting lemmy solved it!