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.
15 Comments
RoundSparrow@programming.dev · 3 pts · 3y
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.
RoundSparrow@lemmy.ml · 2 pts · 3y
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 INSERWT 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
Install steps: https://gist.github.com/rcanepa/535163dc249539912c25
phiresky@lemmy.world · 2 pts · 3y
@roundsparrow@lemmy.ml 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
RoundSparrow@lemmy.ml · 2 pts · 3y
source: https://github.com/LemmyNet/lemmy/pull/3482
RoundSparrow@lemmy.ml · 2 pts · 3y
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:
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?
RoundSparrow@lemmy.ml · 1 pts · 3y
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.
RoundSparrow@lemmy.ml · 1 pts · 3y
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 millisecondsAll 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.
RoundSparrow@lemmy.ml · 1 pts · 3y
This query is asking the database to slice into a string in ORDER BY and in WHERE criteria:
the
nlevelon comment.path field <= and the ORDER BYsubpathon 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.
RoundSparrow@lemmy.ml · 2 pts · 3y
There seems a variation of this query that takes 14 parameters instead of 13: