Using Postgresql 9.6.14, running the following query:
SELECT COUNT(*) AS "__count" FROM "crm_client" INNER JOIN "crm_role" ON ("crm_client"."role_ptr_id" = "crm_role"."id") INNER JOIN "tcauth_user" ON ("crm_role"."user_id" = "tcauth_user"."id") WHERE ("tcauth_user"."branch_id" = ? AND "tcauth_user"."is_deleted" = false) result -> ~3500
Seems so simple, yet is very slow. I get the following output from
explain analyze ...:
Finalize Aggregate (cost=24741.60..24741.60 rows=1 width=8) (actual time=429.478..429.478 rows=1 loops=1) -> Gather (cost=24741.49..24741.60 rows=1 width=8) (actual time=429.204..445.027 rows=2 loops=1) Workers Planned: 1 Workers Launched: 1 -> Partial Aggregate (cost=23741.49..23741.50 rows=1 width=8) (actual time=420.130..420.130 rows=1 loops=2) -> Nested Loop (cost=15134.68..23739.67 rows=3640 width=0) (actual time=89.982..419.729 rows=1729 loops=2) -> Hash Join (cost=15134.60..22918.76 rows=8621 width=4) (actual time=89.440..367.009 rows=7892 loops=2) Hash Cond: (crm_role.user_id = tcauth_user.id) -> Parallel Seq Scan on crm_role (cost=0.00..7519.84 rows=317948 width=8) (actual time=0.015..180.495 rows=271204 loops=2) -> Hash (cost=15085.97..15085.97 rows=13894 width=4) (actual time=89.225..89.225 rows=15655 loops=2) Buckets: 16384 Batches: 1 Memory Usage: 679kB -> Bitmap Heap Scan on tcauth_user (cost=149.43..15085.97 rows=13894 width=4) (actual time=6.147..78.915 rows=15655 loops=2) Recheck Cond: (branch_id = ?) Filter: (NOT is_deleted) Rows Removed by Filter: 253 Heap Blocks: exact=4844 -> Bitmap Index Scan on tcauth_user_09fd5b13 (cost=0.00..148.73 rows=15100 width=0) (actual time=5.176..5.176 rows=15914 Index Cond: (branch_id = ?) -> Index Only Scan using crm_client_pkey on crm_client (cost=0.08..0.09 rows=1 width=4) (actual time=0.006..0.006 rows=0 loops=15784) Index Cond: (role_ptr_id = crm_role.id) Heap Fetches: 73 Planning time: 2.769 ms Execution time: 445.225 ms
Why is this query so slow? I'm concerned about the
nested loop, but not sure if that's really the culprit. The expected costs of some steps are very different from the actual although the row counts are not that different, is this causing a poor query plan?
What can we do to improve the performance of this query (excluding increasing server specs.)? Would another index type help?
Would upgrading from pg 9.6 to 11 improve this?
Schema looks roughly like this:
CREATE TABLE tcauth_user ( id SERIAL PRIMARY KEY, is_deleted BOOLEAN DEFAULT TRUE, branch_id INT NOT NULL REFERENCES branches, ... ); CREATE TABLE crm_role ( id SERIAL PRIMARY KEY, user_id INT NOT NULL REFERENCES tcauth_user, ... ); CREATE TABLE crm_client ( id SERIAL PRIMARY KEY, role_ptr_id INT NOT NULL REFERENCES crm_role, ... );
All fields in joins and the where clause have
btree indexes. Obviously all tables have other fields not included here for brevity.
Update: (to add information requested by @jjanes below)
> explain (analyze, buffers) select count(*) from crm_role Aggregate (cost=8465.40..8465.40 rows=1 width=8) (actual time=111.896..111.896 rows=1 loops=1) Buffers: shared hit=6566 -> Seq Scan on crm_role (cost=0.00..8194.06 rows=542685 width=0) (actual time=0.022..72.772 rows=542726 loops=1) Buffers: shared hit=6566 Planning time: 0.346 ms Execution time: 111.976 ms
I'm running the query on the production database to get real results, unfortunately since it's on Heroku, it's not easy to enable
track_io_timing. The database is Heroku's "Standard 3" database.