Planning time is time-consuming

From: Mikhail Balayan <mv(dot)balayan(at)gmail(dot)com>
To: pgsql-performance(at)postgresql(dot)org
Subject: Planning time is time-consuming
Date: 2023-09-08 10:51:16
Message-ID: CAC2oM1bUqsBFQKVrZy9Z95SuDbmj-uSkXdbYfTnRwyTACSmd4w@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-performance

Hello,
I have three tables:
- test_db_bench_1
- test_db_bench_tenants
- test_db_bench_tenant_closure

And the query to join them:
SELECT "test_db_bench_1"."id" id, "test_db_bench_1"."tenant_id"
FROM "test_db_bench_1"
JOIN "test_db_bench_tenants" AS "tenants_child" ON
(("tenants_child"."uuid" = "test_db_bench_1"."tenant_id")
AND
("tenants_child"."is_deleted" != true))
JOIN "test_db_bench_tenant_closure" AS "tenants_closure" ON
(("tenants_closure"."child_id" = "tenants_child"."id")
AND
("tenants_closure"."barrier" <= 0))
JOIN "test_db_bench_tenants" AS "tenants_parent" ON
(("tenants_parent"."id" = "tenants_closure"."parent_id")
AND
("tenants_parent"."uuid" IN ('4c79c1c5-21ae-45a0-8734-75d67abd0330'))
AND
("tenants_parent"."is_deleted" != true))
LIMIT 1

With following execution plan:

QUERY PLAN
---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Limit (cost=1.56..1.92 rows=1 width=44) (actual time=0.010..0.011 rows=0
loops=1)
-> Nested Loop (cost=1.56..162.42 rows=438 width=44) (actual
time=0.009..0.009 rows=0 loops=1)
-> Nested Loop (cost=1.13..50.27 rows=7 width=36) (actual
time=0.008..0.009 rows=0 loops=1)
-> Nested Loop (cost=0.84..48.09 rows=7 width=8) (actual
time=0.008..0.009 rows=0 loops=1)
-> Index Scan using test_db_bench_tenants_uuid on
test_db_bench_tenants tenants_parent (cost=0.41..2.63 rows=1 width=8)
(actual time=0.008..0.008 rows=0 loops=1)
Index Cond: ((uuid)::text =
'4c79c1c5-21ae-45a0-8734-75d67abd0330'::text)
Filter: (NOT is_deleted)
-> Index Scan using test_db_bench_tenant_closure_pkey
on test_db_bench_tenant_closure tenants_closure (cost=0.42..45.06 rows=40
width=16) (never executed)
Index Cond: (parent_id = tenants_parent.id)
Filter: (barrier <= 0)
-> Index Scan using test_db_bench_tenants_pkey on
test_db_bench_tenants tenants_child (cost=0.29..0.31 rows=1 width=44)
(never executed)
Index Cond: (id = tenants_closure.child_id)
Filter: (NOT is_deleted)
-> Index Scan using test_db_bench_1_idx_tenant_id_3 on
acronis_db_bench_heavy (cost=0.43..14.66 rows=136 width=44) (never
executed)
Index Cond: ((tenant_id)::text = (tenants_child.uuid)::text)
Planning Time: 0.732 ms
Execution Time: 0.039 ms

Where the planning time gets in the way as it takes an order of magnitude
more time than the actual execution.

Is there a possibility to reduce this time? And, in general, to understand
why planning takes so much time.

What I have tried:
- disabled JIT, which resulted in a minor improvement, around 5
microseconds.
- disabled constraint_exclusion, which also didn't have a significant
impact.

Sizes of tables and indexes:
-- test_db_bench_1
List of relations
Schema | Name | Type | Owner | Persistence | Access method |
Size | Description
--------+-----------------+-------+--------+-------------+---------------+---------+-------------
public | test_db_bench_1 | table | dbuser | permanent | heap |
5351 MB |

Column | Type | Collation | Nullable
| Default

---------------------------+------------------------+-----------+----------+----------------------------------------------
------
id | bigint | | not null
| nextval('test_db_bench_1_id_seq'::regclass)
uuid | uuid | | not null |
checksum | character varying(64) | | not null |
tenant_id | character varying(36) | | not null |
cti_entity_uuid | character varying(36) | | |
euc_id | character varying(64) | | not null |
workflow_id | bigint | | |
state | integer | | not null |
type | character varying(64) | | not null |
queue | character varying(64) | | not null |
priority | integer | | not null |
issuer_id | character varying(64) | | not null |
issuer_cluster_id | character varying(64) | | |
heartbeat_ivl_str | character varying(64) | | |
heartbeat_ivl_ns | bigint | | |
queue_timeout_str | character varying(64) | | |
queue_timeout_ns | bigint | | |
ack_timeout_str | character varying(64) | | |
ack_timeout_ns | bigint | | |
exec_timeout_str | character varying(64) | | |
exec_timeout_ns | bigint | | |
life_time_str | character varying(64) | | |
life_time_ns | bigint | | |
max_assign_count | integer | | not null |
assign_count | integer | | not null |
max_fail_count | integer | | not null |
fail_count | integer | | not null |
cancellable | boolean | | not null |
cancel_requested | boolean | | not null |
blocker_count | integer | | not null |
started_by_user | character varying(256) | | |
policy_id | character varying(64) | | |
policy_type | character varying(64) | | |
policy_name | character varying(256) | | |
resource_id | character varying(64) | | |
resource_type | character varying(64) | | |
resource_name | character varying(256) | | |
tags | text | | |
affinity_agent_id | character varying(64) | | not null |
affinity_cluster_id | character varying(64) | | not null |
argument | bytea | | |
context | bytea | | |
progress | integer | | |
progress_total | integer | | |
assigned_agent_id | character varying(64) | | |
assigned_agent_cluster_id | character varying(64) | | |
enqueue_time_str | character varying(64) | | |
enqueue_time_ns | bigint | | not null |
assign_time_str | character varying(64) | | |
assign_time_ns | bigint | | |
start_time_str | character varying(64) | | |
start_time_ns | bigint | | |
update_time_str | character varying(64) | | not null |
update_time_ns | bigint | | not null |
completion_time_str | character varying(64) | | |
completion_time_ns | bigint | | |
result_code | integer | | |
result_error | bytea | | |
result_warnings | bytea | | |
result_payload | bytea | | |
const_val | integer | | |
Indexes:
"test_db_bench_1_pkey" PRIMARY KEY, btree (id)
"test_db_bench_1_idx_completion_time_ns_1" btree (completion_time_ns)
"test_db_bench_1_idx_cti_entity_uuid_2" btree (cti_entity_uuid)
"test_db_bench_1_idx_enqueue_time_ns_10" btree (enqueue_time_ns)
"test_db_bench_1_idx_euc_id_4" btree (euc_id)
"test_db_bench_1_idx_policy_id_12" btree (policy_id)
"test_db_bench_1_idx_queue_18" btree (queue, type, tenant_id)
"test_db_bench_1_idx_queue_19" btree (queue, type, euc_id)
"test_db_bench_1_idx_queue_5" btree (queue, state, affinity_agent_id,
affinity_cluster_id, tenant_id, priority)
"test_db_bench_1_idx_queue_6" btree (queue, state, affinity_agent_id,
affinity_cluster_id, euc_id, priority)
"test_db_bench_1_idx_resource_id_11" btree (resource_id)
"test_db_bench_1_idx_resource_id_14" btree (resource_id,
enqueue_time_ns)
"test_db_bench_1_idx_result_code_13" btree (result_code)
"test_db_bench_1_idx_start_time_ns_9" btree (start_time_ns)
"test_db_bench_1_idx_state_8" btree (state, completion_time_ns)
"test_db_bench_1_idx_tenant_id_3" btree (tenant_id)
"test_db_bench_1_idx_type_15" btree (type)
"test_db_bench_1_idx_type_16" btree (type, tenant_id, enqueue_time_ns)
"test_db_bench_1_idx_type_17" btree (type, euc_id, enqueue_time_ns)
"test_db_bench_1_idx_update_time_ns_7" btree (update_time_ns)
"test_db_bench_1_idx_uuid_0" btree (uuid)
"test_db_bench_1_uuid_key" UNIQUE CONSTRAINT, btree (uuid)

-- test_db_bench_tenants
Schema | Name | Type | Owner | Persistence | Access
method | Size | Description
--------+-----------------------+-------+--------+-------------+---------------+---------+-------------
public | test_db_bench_tenants | table | dbuser | permanent | heap
| 8432 kB |

Column | Type | Collation | Nullable | Default
-------------------+------------------------+-----------+----------+---------
id | bigint | | not null |
uuid | character varying(36) | | not null |
name | character varying(255) | | not null |
kind | character(1) | | not null |
is_deleted | boolean | | not null | false
parent_id | bigint | | not null |
parent_has_access | boolean | | not null | true
nesting_level | smallint | | not null |
Indexes:
"test_db_bench_tenants_pkey" PRIMARY KEY, btree (id)
"test_db_bench_tenants_uuid" UNIQUE CONSTRAINT, btree (uuid)

-- test_db_bench_tenant_closure
Schema | Name | Type | Owner | Persistence |
Access method | Size | Description
--------+------------------------------+-------+--------+-------------+---------------+-------+-------------
public | test_db_bench_tenant_closure | table | dbuser | permanent |
heap | 22 MB |

Column | Type | Collation | Nullable | Default
-------------+--------------+-----------+----------+---------
parent_id | bigint | | not null |
child_id | bigint | | not null |
parent_kind | character(1) | | not null |
barrier | smallint | | not null | 0
Indexes:
"test_db_bench_tenant_closure_pkey" PRIMARY KEY, btree (parent_id,
child_id)
"cybercache_tenants_closure_child_id_idx" btree (child_id)

Postgresql version: 15.3 (Debian 15.3-1.pgdg110+1) on x86_64-pc-linux-gnu,
compiled by gcc (Debian 10.2.1-6) 10.2.1 20210110, 64-bit
And just in case it matters, this is an experimental setup, so Postgresql
running in Docker.

Thank you.

--
Mikhail

Responses

Browse pgsql-performance by date

  From Date Subject
Next Message Thomas Munro 2023-09-10 22:37:34 Re: FW: query pg_stat_ssl hang 100%cpu
Previous Message Michael Paquier 2023-09-08 02:48:28 Re: FW: query pg_stat_ssl hang 100%cpu