Planning time is time-consuming

2023-09-10 Thread Mikhail Balayan
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_iv

Re: Planning time is time-consuming

2023-09-10 Thread Laurenz Albe
On Fri, 2023-09-08 at 18:51 +0800, Mikhail Balayan wrote:
> 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.

You could try to VACUUM the involved tables; indexes with many entries pointing 
to dead tuples
can cause a long planing time.

Also, there are quite a lot of indexes on "test_db_bench_1".  On a test 
database, drop some
indexes and see if that makes a difference.

Finally, check if "default_statistics_target" is set to a high value, or if the 
"Stats target"
for some column in the "\d+ tablename" output is set higher than 100.

Yours,
Laurenz Albe




Re: Planning time is time-consuming

2023-09-10 Thread Anupam b
Also, if you write sql with bind params, planning time should be once for the 
sql.  Subsequent sql will use cached stmt.

Get Outlook for Android

From: Laurenz Albe 
Sent: Sunday, September 10, 2023 6:15:43 PM
To: Mikhail Balayan ; [email protected] 

Subject: Re: Planning time is time-consuming

On Fri, 2023-09-08 at 18:51 +0800, Mikhail Balayan wrote:
> 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.

You could try to VACUUM the involved tables; indexes with many entries pointing 
to dead tuples
can cause a long planing time.

Also, there are quite a lot of indexes on "test_db_bench_1".  On a test 
database, drop some
indexes and see if that makes a difference.

Finally, check if "default_statistics_target" is set to a high value, or if the 
"Stats target"
for some column in the "\d+ tablename" output is set higher than 100.

Yours,
Laurenz Albe




Re: Planning time is time-consuming

2023-09-10 Thread Andreas Kretschmer



On 11 September 2023 03:15:43 CEST, Laurenz Albe  
wrote:
>On Fri, 2023-09-08 at 18:51 +0800, Mikhail Balayan wrote:
>> 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.
>
>You could try to VACUUM the involved tables; indexes with many entries 
>pointing to dead tuples
>can cause a long planing time.
>
>Also, there are quite a lot of indexes on "test_db_bench_1".  On a test 
>database, drop some
>indexes and see if that makes a difference.

You can use pg_stat_user_indexes to check if those indexes are in use or not.



>
>Finally, check if "default_statistics_target" is set to a high value, or if 
>the "Stats target"
>for some column in the "\d+ tablename" output is set higher than 100.
>
>Yours,
>Laurenz Albe
>
>