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.

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

Dashboard performance issues #1540

Open
jgrau opened this issue Nov 13, 2024 · 1 comment
Open

Dashboard performance issues #1540

jgrau opened this issue Nov 13, 2024 · 1 comment

Comments

@jgrau
Copy link
Contributor

jgrau commented Nov 13, 2024

Hi @bensheldon 😄

I've been looking into slow performance of the dashboard in production and I want to share my findings in case you didn't know about the bottlenecks that we're seeing or you can spot some low hanging fruits.

Here's a typical trace of a request to /good_job/jobs:

Screenshot 2024-11-13 at 22 33 02

It's about a 20s load time where all the time is spent on database queries. The most expensive is

SELECT "good_jobs".*, "pg_locks".locktype, "pg_locks"."pid" = pg_backend_pid() AS owns_advisory_lock FROM "good_jobs" LEFT JOIN pg_locks ON pg_locks.locktype = $1 AND pg_locks.objsubid = $2 AND pg_locks.classid = ($3 || substr(md5($4 || $5 || "good_jobs"."id"::text), $6, $7))::bit(32)::int AND pg_locks.objid = (($8 || substr(md5($9 || $10 || "good_jobs"."id"::text), $11, $12))::bit(64) << $13)::bit(32)::int ORDER BY COALESCE(scheduled_at, created_at) DESC, id DESC LIMIT $14

An explain of that yields this result:

Limit  (cost=414045.20..414045.27 rows=25 width=1016)
  ->  Sort  (cost=414045.20..419319.12 rows=2109565 width=1016)
        Sort Key: (COALESCE(good_jobs.scheduled_at, good_jobs.created_at)) DESC, good_jobs.id DESC
        ->  Hash Left Join  (cost=15.02..354514.80 rows=2109565 width=1016)
              Hash Cond: (((((('x'::text || substr(md5(('good_jobs-'::text || (good_jobs.id)::text)), 1, 16)))::bit(32))::integer)::oid = l.classid) AND ((((((('x'::text || substr(md5(('good_jobs-'::text || (good_jobs.id)::text)), 1, 16)))::bit(64) << 32))::bit(32))::integer)::oid = l.objid))
              ->  Seq Scan on good_jobs  (cost=0.00..270116.65 rows=2109565 width=975)
              ->  Hash  (cost=15.00..15.00 rows=1 width=44)
                    ->  Function Scan on pg_lock_status l  (cost=0.00..15.00 rows=1 width=44)
                          Filter: ((locktype = 'advisory'::text) AND (objsubid = 1))
JIT:
  Functions: 17
  Options: Inlining false, Optimization false, Expressions true, Deforming true

Which visualises as

Screenshot 2024-11-13 at 22 47 25

As I understand that, the sequential scan is the culprit and I believe the scan is because of COALESCE(good_jobs.scheduled_at, good_jobs.created_at). On my system only schedule_at is indexed and not created_at. Shouldn't created_at be indexed as well?

@bensheldon
Copy link
Owner

Oof! That's slow. I think this is easier now with GoodJob v4:

  • The pg_locks could be replaced with a locked_at IS NOT NULL query
  • The COALESCE can be replaced solely with good_jobs.scheduled_at because now all jobs should have a scheduled_at regardless of whether they are expect to run immediately or in the future.

Would you want to try making a PR? Otherwise I can get to it ;-)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
Status: Inbox
Development

No branches or pull requests

2 participants