Sunday, October 16, 2022

Understand the impact of plan_cache_mode setting on prepared statement

   

1.Prepare test data

drop table if exists t_skewed;

create table t_skewed as
select (case when i>10 then 100 else i end) a,
rpad('a',10,'x') b from generate_series(1,1000000) i;

create index idx_t_skewed_a on t_skewed(a);

vacuum analyze t_skewed;

2.Enable auto_expain to capture the explain plan

LOAD 'auto_explain';
SET auto_explain.log_min_duration = 0;
SET auto_explain.log_analyze = true;

3. Use default parameter value (auto) for plan_cache_mode

test=# select * from pg_settings where name like '%plan_cache_mode%';
-[ RECORD 1 ]---+------------------------------------------------------------------
name            | plan_cache_mode
setting         | auto
unit            |
category        | Query Tuning / Other Planner Options
short_desc      | Controls the planners selection of custom or generic plan.
extra_desc      | Prepared statements can have custom and generic plans, and
                | the planner will attempt to choose which is better.  
                | This can be set to override the default behavior.
context         | user
vartype         | enum
source          | default
min_val         |
max_val         |
enumvals        | {auto,force_generic_plan,force_custom_plan}
boot_val        | auto
reset_val       | auto
sourcefile      |
sourceline      |
pending_restart | f

4. Use PREPARE statement to verify execution plans

Reference:

prepare myplan (int) as
    select count(*) from t_skewed where a=$1;
EXECUTE myplan(1);
EXECUTE myplan(2);
EXECUTE myplan(3);
EXECUTE myplan(4);
EXECUTE myplan(5);
EXECUTE myplan(6);
EXECUTE myplan(100);
EXECUTE myplan(7);

The optimizer is smart enough to switch different plans based on different parameters

2022-10-16 10:00:36.535 +08 [1741] LOG:  duration: 0.026 ms  plan:
	Query Text: prepare myplan (int) as
	    select count(*) from t_skewed where a=$1;
	Aggregate  (cost=4.45..4.46 rows=1 width=8) (actual time=0.014..0.019 rows=1 loops=1)
	  ->  Index Only Scan using idx_t_skewed_a on t_skewed  (cost=0.42..4.44 rows=1 width=0) (actual time=0.007..0.010 rows=1 loops=1)
	        Index Cond: (a = 5)
	        Heap Fetches: 0
2022-10-16 10:00:36.535 +08 [1741] LOG:  duration: 0.025 ms  plan:
	Query Text: prepare myplan (int) as
	    select count(*) from t_skewed where a=$1;
	Aggregate  (cost=4.45..4.46 rows=1 width=8) (actual time=0.013..0.018 rows=1 loops=1)
	  ->  Index Only Scan using idx_t_skewed_a on t_skewed  (cost=0.42..4.44 rows=1 width=0) (actual time=0.006..0.009 rows=1 loops=1)
	        Index Cond: (a = 6)
	        Heap Fetches: 0
2022-10-16 10:00:37.373 +08 [1741] LOG:  duration: 837.510 ms  plan:
	Query Text: prepare myplan (int) as
	    select count(*) from t_skewed where a=$1;
	Finalize Aggregate  (cost=12656.22..12656.23 rows=1 width=8) (actual time=834.689..837.499 rows=1 loops=1)
	  ->  Gather  (cost=12656.00..12656.21 rows=2 width=8) (actual time=834.261..837.479 rows=3 loops=1)
	        Workers Planned: 2
	        Workers Launched: 2
	        ->  Partial Aggregate  (cost=11656.00..11656.01 rows=1 width=8) (actual time=829.663..829.668 rows=1 loops=3)
	              ->  Parallel Seq Scan on t_skewed  (cost=0.00..10614.33 rows=416667 width=0) (actual time=0.037..422.477 rows=333330 loops=3)
	                    Filter: (a = 100)
	                    Rows Removed by Filter: 3
2022-10-16 10:01:29.082 +08 [1741] LOG:  duration: 0.047 ms  plan:
	Query Text: prepare myplan (int) as
	    select count(*) from t_skewed where a=$1;
	Aggregate  (cost=4.45..4.46 rows=1 width=8) (actual time=0.033..0.038 rows=1 loops=1)
	  ->  Index Only Scan using idx_t_skewed_a on t_skewed  (cost=0.42..4.44 rows=1 width=0) (actual time=0.020..0.024 rows=1 loops=1)
	        Index Cond: (a = 7)
	        Heap Fetches: 0

5. Use parameter value 'force_generic_plan' for plan_cache_mode, which is the default behavior prior to version 12 after first 5 executions in prepare statement and parameterized SQL functions.

test=# set plan_cache_mode=force_generic_plan;
SET

6. Use PREPARE statement to verify execution plans

Reference:

deallocate myplan;
prepare myplan (int) as
    select count(*) from t_skewed where a=$1;
EXECUTE myplan(1);
EXECUTE myplan(2);
EXECUTE myplan(3);
EXECUTE myplan(4);
EXECUTE myplan(5);
EXECUTE myplan(6);
EXECUTE myplan(100);
EXECUTE myplan(7);

Auto explain plan output for last 2 executions (parameter 100 & 7)

2022-10-16 10:10:46.631 +08 [1741] LOG:  duration: 836.106 ms  plan:
    Query Text: prepare myplan (int) as
        select count(*) from t_skewed where a=$1;
    Finalize Aggregate  (cost=12656.22..12656.23 rows=1 width=8) (actual time=833.208..836.094 rows=1 loops=1)
      ->  Gather  (cost=12656.00..12656.21 rows=2 width=8) (actual time=832.952..836.071 rows=3 loops=1)
            Workers Planned: 2
            Workers Launched: 2
            ->  Partial Aggregate  (cost=11656.00..11656.01 rows=1 width=8) (actual time=829.314..829.320 rows=1 loops=3)
                  ->  Parallel Seq Scan on t_skewed  (cost=0.00..10614.33 rows=416667 width=0) (actual time=0.036..421.988 rows=333330 loops=3)
                        Filter: (a = $1)
                        Rows Removed by Filter: 3
2022-10-16 10:10:46.677 +08 [1741] LOG:  duration: 45.417 ms  plan:
    Query Text: prepare myplan (int) as
        select count(*) from t_skewed where a=$1;
    Finalize Aggregate  (cost=12656.22..12656.23 rows=1 width=8) (actual time=42.787..45.404 rows=1 loops=1)
      ->  Gather  (cost=12656.00..12656.21 rows=2 width=8) (actual time=42.649..45.383 rows=3 loops=1)
            Workers Planned: 2
            Workers Launched: 2
            ->  Partial Aggregate  (cost=11656.00..11656.01 rows=1 width=8) (actual time=38.656..38.662 rows=1 loops=3)
                  ->  Parallel Seq Scan on t_skewed  (cost=0.00..10614.33 rows=416667 width=0) (actual time=24.509..38.649 rows=0 loops=3)
                        Filter: (a = $1)
                        Rows Removed by Filter: 333333

No comments:

Post a Comment