this post was submitted on 19 Jun 2023
21 points (95.7% liked)

Lemmy Server Performance

420 readers
1 users here now

Lemmy Server Performance

lemmy_server uses the Diesel ORM that automatically generates SQL statements. There are serious performance problems in June and July 2023 preventing Lemmy from scaling. Topics include caching, PostgreSQL extensions for troubleshooting, Client/Server Code/SQL Data/server operator apps/sever operator API (performance and storage monitoring), etc.

founded 1 year ago
MODERATORS
 

I have been working with pg_stat_statements extension to PG and it give us a way to see the actual SQL statements being executed by lemmy_server and the number of times they are being called.

This has less overhead than cranking up logging and several cloud computing services enable it by default (example) - so I don't believe it will have a significant slow down of the server.

A DATABASE RESTART WILL BE REQUIRED

It does require that PostgreSQL be restarted. Which can take 10 or 15 seconds, typically.

Debian / Ubuntu install steps

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

Following the conventions of "Lemmy from Scratch" server install commands:

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

Followed by a restart of the PostgreSQL service.

top 10 comments
sorted by: hot top controversial new old
[–] [email protected] 2 points 1 year ago* (last edited 1 year ago)

Update July 24, 2023

Some major stored procedure SQL problems were overlooked until 2 days ago. I submitted revised statements to fix a massive write operation on every single post and comment creation on a local site. The site_aggregates table... every row modified instead of a single row. https://github.com/LemmyNet/lemmy/pull/3704

I was curious why pg_stat_statements didn't draw more attention to the INSERT statements hitting so many rows, and I found out that by default it does not take into account stored procedure execution! https://stackoverflow.com/questions/56741860/pg-stat-activity-how-to-see-current-activity-inside-a-running-stored-procedure

pg_stat_statements.track = all

Now I'm seeing far more activity than I have been looking at for the past 2 months... the stored procedure statements are showing up!

Install steps: https://gist.github.com/rcanepa/535163dc249539912c25

[–] RoundSparrow 2 points 1 year ago

Interesting, over here at programmer.dev this shows "10 comments" when I don't think there were ever that many, are edits being counted as new comments? I did edit postings several times.

[–] [email protected] 2 points 1 year ago
[–] [email protected] 1 points 1 year ago

@[email protected] If you find queries that are slow could you post the EXPLAIN ANALYZE here or send them to me? You can do it manually or maybe use https://www.postgresql.org/docs/current/auto-explain.html

[–] [email protected] 1 points 1 year ago* (last edited 1 year ago)

Running for the past 24 hours, my server is almost all federation activity, subscribed to the most active communities I could find on other instances to get some data in my database. My signup is closed and I'm the only interactive user, doing mostly read-only operations.

So far with federation and reading of content being the only activity, 313 SQL statements have been identified. I'm running on a Oracle Cloud Ubuntu 22.04 system with 24GB of RAM and 200GB of block storage with 4x2Ghz Ampere Arm cores.

LIKES / UPVOTES: I'm seeing that upvotes on both the comment and post are taking over 1/3 of a second each to INSERT, 0.37 and 0.35 seconds mean average to do a single insert from incoming federation activity. with 24GB of RAM, the index should be in cache/RAM, but locking and I/O to write and log is taking significant time. That's with only 304319 rows in my comment_like table / 124218 in post_like, not nearly the amount of rows I expect Beehaw, Lemmy.ml and other long-running sites have.

[–] [email protected] 1 points 1 year ago* (last edited 1 year ago) (1 children)

This query is asking the database to slice into a string in ORDER BY and in WHERE criteria:

SELECT "comment"."id", "comment"."creator_id", "comment"."post_id", "comment"."content", "comment"."removed", "comment"."published", "comment"."updated", "comment"."deleted", "comment"."ap_id", "comment"."local", "comment"."path", "comment"."distinguished", "comment"."language_id", "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", "post"."id", "post"."name", "post"."url", "post"."body", "post"."creator_id", "post"."community_id", "post"."removed", "post"."locked", "post"."published", "post"."updated", "post"."deleted", "post"."nsfw", "post"."embed_title", "post"."embed_description", "post"."embed_video_url", "post"."thumbnail_url", "post"."ap_id", "post"."local", "post"."language_id", "post"."featured_community", "post"."featured_local", "community"."id", "community"."name", "community"."title", "community"."description", "community"."removed", "community"."published", "community"."updated", "community"."deleted", "community"."nsfw", "community"."actor_id", "community"."local", "community"."icon", "community"."banner", "community"."hidden", "community"."posting_restricted_to_mods", "community"."instance_id", "comment_aggregates"."id", "comment_aggregates"."comment_id", "comment_aggregates"."score", "comment_aggregates"."upvotes", "comment_aggregates"."downvotes", "comment_aggregates"."published", "comment_aggregates"."child_count", "comment_aggregates"."hot_rank", "community_person_ban"."id", "community_person_ban"."community_id", "community_person_ban"."person_id", "community_person_ban"."published", "community_person_ban"."expires", "community_follower"."id", "community_follower"."community_id", "community_follower"."person_id", "community_follower"."published", "community_follower"."pending", "comment_saved"."id", "comment_saved"."comment_id", "comment_saved"."person_id", "comment_saved"."published", "person_block"."id", "person_block"."person_id", "person_block"."target_id", "person_block"."published", "comment_like"."score"

 FROM ((((((((((("comment" INNER JOIN "person" ON ("comment"."creator_id" = "person"."id")) INNER JOIN "post" ON ("comment"."post_id" = "post"."id")) INNER JOIN "community" ON ("post"."community_id" = "community"."id")) INNER JOIN "comment_aggregates" ON ("comment_aggregates"."comment_id" = "comment"."id")) LEFT OUTER JOIN "community_person_ban" ON ((("community"."id" = "community_person_ban"."community_id") AND ("community_person_ban"."person_id" = "comment"."creator_id")) AND (("community_person_ban"."expires" IS NULL) OR ("community_person_ban"."expires" > CURRENT_TIMESTAMP)))) LEFT OUTER JOIN "community_follower" ON (("post"."community_id" = "community_follower"."community_id") AND ("community_follower"."person_id" = $1))) LEFT OUTER JOIN "comment_saved" ON (("comment"."id" = "comment_saved"."comment_id") AND ("comment_saved"."person_id" = $2))) LEFT OUTER JOIN "person_block" ON (("comment"."creator_id" = "person_block"."target_id") AND ("person_block"."person_id" = $3))) LEFT OUTER JOIN "community_block" ON (("community"."id" = "community_block"."community_id") AND ("community_block"."person_id" = $4))) LEFT OUTER JOIN "comment_like" ON (("comment"."id" = "comment_like"."comment_id") AND ("comment_like"."person_id" = $5))) LEFT OUTER JOIN "local_user_language" ON (("comment"."language_id" = "local_user_language"."language_id") AND ("local_user_language"."local_user_id" = $6)))

 WHERE ((("community"."hidden" = $7) OR ("community_follower"."person_id" = $8)) AND (nlevel("comment"."path") <= $9)) ORDER BY subpath("comment"."path", $10, $11), "comment_aggregates"."hot_rank" DESC LIMIT $12 OFFSET $13

the nlevel on comment.path field <= and the ORDER BY subpath on the same field are really dragging down this query.

I am still trying to figure out the circumstances on the lemmy-ui webapp where this particular 13 parameter query is triggered. A GitHub grep of the source code shows 'subpath' is only used in a single place.

[–] [email protected] 2 points 1 year ago* (last edited 1 year ago)

There seems a variation of this query that takes 14 parameters instead of 13:

SELECT "comment"."id", "comment"."creator_id", "comment"."post_id", "comment"."content", "comment"."removed", "comment"."published", "comment"."updated", "comment"."deleted", "comment"."ap_id", "comment"."local", "comment"."path", "comment"."distinguished", "comment"."language_id", "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", "post"."id", "post"."name", "post"."url", "post"."body", "post"."creator_id", "post"."community_id", "post"."removed", "post"."locked", "post"."published", "post"."updated", "post"."deleted", "post"."nsfw", "post"."embed_title", "post"."embed_description", "post"."embed_video_url", "post"."thumbnail_url", "post"."ap_id", "post"."local", "post"."language_id", "post"."featured_community", "post"."featured_local", "community"."id", "community"."name", "community"."title", "community"."description", "community"."removed", "community"."published", "community"."updated", "community"."deleted", "community"."nsfw", "community"."actor_id", "community"."local", "community"."icon", "community"."banner", "community"."hidden", "community"."posting_restricted_to_mods", "community"."instance_id", "comment_aggregates"."id", "comment_aggregates"."comment_id", "comment_aggregates"."score", "comment_aggregates"."upvotes", "comment_aggregates"."downvotes", "comment_aggregates"."published", "comment_aggregates"."child_count", "comment_aggregates"."hot_rank", "community_person_ban"."id", "community_person_ban"."community_id", "community_person_ban"."person_id", "community_person_ban"."published", "community_person_ban"."expires", "community_follower"."id", "community_follower"."community_id", "community_follower"."person_id", "community_follower"."published", "community_follower"."pending", "comment_saved"."id", "comment_saved"."comment_id", "comment_saved"."person_id", "comment_saved"."published", "person_block"."id", "person_block"."person_id", "person_block"."target_id", "person_block"."published", "comment_like"."score"

 FROM ((((((((((("comment" INNER JOIN "person" ON ("comment"."creator_id" = "person"."id")) INNER JOIN "post" ON ("comment"."post_id" = "post"."id")) INNER JOIN "community" ON ("post"."community_id" = "community"."id")) INNER JOIN "comment_aggregates" ON ("comment_aggregates"."comment_id" = "comment"."id")) LEFT OUTER JOIN "community_person_ban" ON ((("community"."id" = "community_person_ban"."community_id") AND ("community_person_ban"."person_id" = "comment"."creator_id")) AND (("community_person_ban"."expires" IS NULL) OR ("community_person_ban"."expires" > CURRENT_TIMESTAMP)))) LEFT OUTER JOIN "community_follower" ON (("post"."community_id" = "community_follower"."community_id") AND ("community_follower"."person_id" = $1))) LEFT OUTER JOIN "comment_saved" ON (("comment"."id" = "comment_saved"."comment_id") AND ("comment_saved"."person_id" = $2))) LEFT OUTER JOIN "person_block" ON (("comment"."creator_id" = "person_block"."target_id") AND ("person_block"."person_id" = $3))) LEFT OUTER JOIN "community_block" ON (("community"."id" = "community_block"."community_id") AND ("community_block"."person_id" = $4))) LEFT OUTER JOIN "comment_like" ON (("comment"."id" = "comment_like"."comment_id") AND ("comment_like"."person_id" = $5))) LEFT OUTER JOIN "local_user_language" ON (("comment"."language_id" = "local_user_language"."language_id") AND ("local_user_language"."local_user_id" = $6)))

 WHERE (("comment"."path" <@ $7 AND (("community"."hidden" = $8) OR ("community_follower"."person_id" = $9))) AND (nlevel("comment"."path") <= $10)) ORDER BY subpath("comment"."path", $11, $12), "comment_aggregates"."hot_rank" DESC LIMIT $13 OFFSET $14
[–] [email protected] 1 points 1 year ago* (last edited 1 year ago)

Damn it - I made a mistake

Ok, re-reading the documentation again, I made a major error interpreting these results.

mean_exec_time double precision: Mean time spent executing the statement, in milliseconds

All my statements about INSERT on Upvotes taking 1/3 of a second are wrong, it's less than 1 millisecond. Although it sure doesn't feel that fast when you are interactively using Lemmy 0.18 and pressing the Vote buttons, it seems rather sluggish. I've almost never seen fractions of a milliseconds, but here it is.

[–] [email protected] 0 points 1 year ago* (last edited 1 year ago) (1 children)

Once the extension is installed and enabled, you can reset the stats whenever you want and it will start to build a new list of queries and I assume reset the average execution time.

I found a curious query that seems to take 10 or 11 seconds on my server:

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"

This query is being called over 1000 times an hour with my instance only really doing incoming Federation content. Should this be optimized by doing a subSELECT on the WHERE clause before doing the INNER JOIN?

[–] [email protected] 1 points 1 year ago

IMPORTANT NOTE: I am rusty on my PostgreSQL, it's been over 10 years since I designed and ran a major time-critical website with it. That is not "SECONDS", it is "MILLISECONDS", but it is still a slow query being called frequently.

load more comments
view more: next ›