PostgreSQL plan_cache_mode

Are you struggling with performance issues in your Spring, Jakarta EE, or Java EE application?

What if there were a tool that could automatically detect what caused performance issues in your JPA and Hibernate data access layer?

Wouldn’t it be awesome to have such a tool to watch your application and prevent performance issues during development, long before they affect production systems?

Well, Hypersistence Optimizer is that tool! And it works with Spring Boot, Spring Framework, Jakarta EE, Java EE, Quarkus, Micronaut, or Play Framework.

So, rather than fixing performance issues in your production system on a Saturday night, you are better off using Hypersistence Optimizer to help you prevent those issues so that you can spend your time on the things that you love!

Introduction

In this article, we are going to analyze the PostgreSQL plan_cache_mode setting and see when it’s useful to override a given generic plan using the the force_custom_plan strategy.

Domain Model

Let’s assume we have the following post table:

The post table for PostgreSQL plan_cache_mode

The post_status type is an Enum that was created like this:

 CREATE TYPE post_status AS ENUM ( 'PENDING', 'APPROVED', 'SPAM' ) 

We have 100,000 post records in our database that have a very skewed distribution of status values.

For example, if we run the following SQL query:

 SELECT a.*, matching_records::float/row_count AS selectivity FROM ( SELECT status, COUNT(<em>) AS matching_records FROM post GROUP BY status ) a CROSS JOIN LATERAL ( SELECT COUNT(</em>) AS row_count FROM post ) b ORDER BY selectivity DESC 

We get the following results:

 | status | matching_records | selectivity | | -------- | ---------------- | ----------- | | APPROVED | 95000 | 0.95 | | PENDING | 4000 | 0.04 | | SPAM | 1000 | 0.01 | 
  • 95% of the post records match the APPROVED status value.
  • 4% of the post records have the status of PENDING.
  • 1% of the post table records are marked as spam.

Filtering by status

Now, we have various features in our application that require us to filter the post records by their status using the following SQL query:

 SELECT id, title, status FROM post WHERE status = ? 

To avoid a full-table scan, most often, you might think of creating an index on the status column like this:

 CREATE INDEX idx_post_status ON post (status) 

However, based on the status value selectivity, PostgreSQL might or might not use the idx_post_status when executing the aforementioned SQL query.

For example, when filtering by the status of PENDING, PostgreSQL uses the following SQL execution plan:

 Bitmap Heap Scan on post (cost=46.44..1231.07 rows=3890 width=57) (actual time=0.233..1.132 rows=4000 loops=1) Recheck Cond: (status = 'PENDING'::post_status) Heap Blocks: exact=46 -> Bitmap Index Scan on idx_post_status (cost=0.00..45.47 rows=3890 width=0) (actual time=0.211..0.212 rows=4000 loops=1) Index Cond: (status = 'PENDING'::post_status) 

The execution plan scans the idx_post_status index and creates a bitmap of in-memory pages where the matching post records are located. Afterward, the Bitmap Heap Scan will scan the post table pages based on the page identifiers found in the bitmap.

When filtering the post records by the status of SPAM, PostgreSQL will use an Index Scan instead of a Bitmap Index Scan:

 Index Scan using idx_post_status on post (cost=0.29..1089.83 rows=963 width=57) (actual time=0.059..0.500 rows=1000 loops=1) Index Cond: (status = 'SPAM'::post_status) 

And, if we filter the post records by the status of APPROVED, PostgreSQL will ignore the idx_post_status index and use a full-table scan on the post table:

 Seq Scan on post (cost=0.00..2386.00 rows=95147 width=57) (actual time=0.034..36.765 rows=95000 loops=1) Filter: (status = 'APPROVED'::post_status) Rows Removed by Filter: 5000 

Using an index when having to scan 95% of a table has a much higher cost than just scanning the table, hence the sequential scan when filtering by the status of APPROVED.

As I explained in this article, because the status values are skewed, it makes sense only to index the values that have high selectivity, such as PENDING and SPAM.

Therefore, since we cannot use the idx_post_status for the status value of APPROVED, we can modify the idx_post_status to a partial one that filters out the APPROVED value:

 CREATE INDEX idx_post_status ON post (status) WHERE (status <> APPROVED) 

Default PostgreSQL plan_cache_mode

As I explained in this article, PostgreSQL will generate a custom execution plan on the first 4 executions of a given Prepared Statement. From the 5th execution onwards, PostgreSQL will use a generic plan instead.

We can validate this behavior using the following test case:

 executeStatement( connection, "LOAD 'auto_explain'", "SET auto_explain.log_analyze=true", "SET auto_explain.log_min_duration=0" ); LOGGER.info( "Plan cache mode: {}", selectColumn( connection, "SHOW plan_cache_mode", String.class ) ); try (PreparedStatement statement = connection.prepareStatement(""" SELECT id, title, status FROM post WHERE status = ? """)) { for (int i = 1; i <= 10; i++) { executeStatementWithStatus(statement, PostStatus.APPROVED); } executeStatementWithStatus(statement, PostStatus.SPAM); } 

The executeStatementWithStatus method is just a utility that helps us execute the PreparedStatement with a given status value:

 protected int executeStatementWithStatus( PreparedStatement statement, PostStatus status) throws SQLException { LOGGER.info( "Statement is {}prepared on the server", PostgreSQLQueries.isUseServerPrepare(statement) ? "" : "not " ); int rowCount = 0; statement.setObject( 1, PostgreSQLQueries.toEnum(status, "post_status"), Types.OTHER ); try(ResultSet resultSet = statement.executeQuery()) { while (resultSet.next()) { rowCount++; } } return rowCount; } 

This test case executes the following steps:

  • First, it prints the default value of the plan_cache_mode setting
  • Afterward, it will execute the PreparedStatement 10 times with the status value of APPROVED
  • At the end, it will execute the PreparedStatement one more time with the value of SPAM
 Plan cache mode: auto Statement is not prepared on the server Time:127, Query:[" SELECT id, title, status FROM post WHERE status = ? "], Params:[(APPROVED)] Statement is not prepared on the server Time:124, Query:[" SELECT id, title, status FROM post WHERE status = ? "], Params:[(APPROVED)] Statement is not prepared on the server Time:128, Query:[" SELECT id, title, status FROM post WHERE status = ? "], Params:[(APPROVED)] Statement is not prepared on the server Time:116, Query:[" SELECT id, title, status FROM post WHERE status = ? "], Params:[(APPROVED)] Statement is prepared on the server Time:100, Query:[" SELECT id, title, status FROM post WHERE status = ? "], Params:[(APPROVED)] Statement is prepared on the server Time:137, Query:[" SELECT id, title, status FROM post WHERE status = ? "], Params:[(APPROVED)] ... Statement is prepared on the server Time:93, Query:[" SELECT id, title, status FROM post WHERE status = ? "], Params:[(APPROVED)] Statement is prepared on the server Time:22, Query:[" SELECT id, title, status FROM post WHERE status = ? "], Params:[(SPAM)] 

You can see that the first 4 executions were not prepared on the server, and from the 5th execution the prepared statement is using a generic plan that’s cached for the duration of the current connection.

If you check the Time part, you will see that the APPROVED bind parameter value takes from 93 to 137 milliseconds. And when we use the SPAM bind parameter value, we get an execution time of 22 milliseconds, which is quite high for fetching 1000 records.

If we inspect the PostgreSQL database log, we get the following entries:

 LOG: duration: 124.261 ms plan: Query Text: SELECT id, title, status FROM post WHERE status = $1   Seq Scan on post (cost=0.00..2386.00 rows=94997 width=57) (actual time=0.040..29.204 rows=95000 loops=1) Filter: (status = 'APPROVED'::post_status) Rows Removed by Filter: 5000 LOG: duration: 122.864 ms plan: Query Text: SELECT id, title, status FROM post WHERE status = $1   Seq Scan on post (cost=0.00..2386.00 rows=94997 width=57) (actual time=0.020..23.542 rows=95000 loops=1) Filter: (status = 'APPROVED'::post_status) Rows Removed by Filter: 5000 LOG: duration: 127.540 ms plan: Query Text: SELECT id, title, status FROM post WHERE status = $1   Seq Scan on post (cost=0.00..2386.00 rows=94997 width=57) (actual time=0.024..24.103 rows=95000 loops=1) Filter: (status = 'APPROVED'::post_status) Rows Removed by Filter: 5000 LOG: duration: 114.467 ms plan: Query Text: SELECT id, title, status FROM post WHERE status = $1   Seq Scan on post (cost=0.00..2386.00 rows=94997 width=57) (actual time=0.030..21.212 rows=95000 loops=1) Filter: (status = 'APPROVED'::post_status) Rows Removed by Filter: 5000 LOG: duration: 100.076 ms plan: Query Text: SELECT id, title, status FROM post WHERE status = $1   Seq Scan on post (cost=0.00..2386.00 rows=94997 width=57) (actual time=0.021..18.262 rows=95000 loops=1) Filter: (status = 'APPROVED'::post_status) Rows Removed by Filter: 5000 LOG: duration: 136.927 ms plan: Query Text: SELECT id, title, status FROM post WHERE status = $1   Seq Scan on post (cost=0.00..2386.00 rows=94997 width=57) (actual time=0.049..26.003 rows=95000 loops=1) Filter: (status = 'APPROVED'::post_status) Rows Removed by Filter: 5000   ...   LOG: duration: 93.088 ms plan: Query Text: SELECT id, title, status FROM post WHERE status = $1   Seq Scan on post (cost=0.00..2386.00 rows=33333 width=57) (actual time=0.021..17.735 rows=95000 loops=1) Filter: (status = $1) Rows Removed by Filter: 5000 LOG: duration: 21.263 ms plan: Query Text: SELECT id, title, status FROM post WHERE status = $1   Seq Scan on post (cost=0.00..2386.00 rows=33333 width=57) (actual time=19.982..20.207 rows=1000 loops=1) Filter: (status = $1) Rows Removed by Filter: 99000 

Because a generic plan is used from the 5th execution, the SPAM bind parameter value also run a sequential scan instead of using the idx_post_status index.

The Rows Removed by Filter: 99000 part in the last query execution plan tells us that PostgreSQL has scanned 100,000 record only to filter out and skip 99% of them.

Using the force_custom_plan option of the plan_cache_mode

According to PostgreSQL documentation, if we don’t want to reuse a generic plan, we can change the plan_cache_mode to use the force_custom_plan option.

With the force_custom_plan option in place, PostgreSQL will always generate a custom plan when executing a prepared statement.

For example, if we set the force_custom_plan option prior to executing the prepared statement that uses the SPAM bind parameter value:

 try (PreparedStatement statement = connection.prepareStatement(""" SELECT id, title, status FROM post WHERE status = ? """)) { for (int i = 1; i <= 5; i++) { executeStatementWithStatus(statement, PostStatus.APPROVED); } executeStatementWithStatus(statement, PostStatus.SPAM); executeStatement( connection, "SET plan_cache_mode=force_custom_plan" ); executeStatementWithStatus(statement, PostStatus.SPAM); } 

We can see that the query execution is faster after we set the force_custom_plan option

 Time:19, Query:[" SELECT id, title, status FROM post WHERE status = ? "], Params:[(SPAM)] SET plan_cache_mode=force_custom_plan Time:2, Query:[" SELECT id, title, status FROM post WHERE status = ? "], Params:[(SPAM)] 

If we inspect the database query log, we can see that force_custom_plan makes PostgreSQL skip the generic plan and generate a new one that can take advantage of the idx_post_status index:

 LOG: duration: 18.290 ms plan: Query Text: SELECT id, title, status FROM post WHERE status = $1   Seq Scan on post (cost=0.00..2386.00 rows=33333 width=57) (actual time=17.012..17.215 rows=1000 loops=1) Filter: (status = $1) Rows Removed by Filter: 99000 LOG: duration: 1.443 ms plan: Query Text: SELECT id, title, status FROM post WHERE status = $1   Bitmap Heap Scan on post (cost=16.37..1187.67 rows=1043 width=57) (actual time=0.146..0.306 rows=1000 loops=1) Recheck Cond: (status = 'SPAM'::post_status) Heap Blocks: exact=13 -> Bitmap Index Scan on idx_post_status (cost=0.00..16.11 rows=1043 width=0) (actual time=0.142..0.142 rows=1000 loops=1) Index Cond: (status = 'SPAM'::post_status) 

Awesome, right?

If you enjoyed this article, I bet you are going to love my Book and Video Courses as well.

Seize the deal! 40% discount. Seize the deal! 40% discount. Seize the deal! 40% discount.

Conclusion

When executing a prepared statement, PostgreSQL might use either a custom or a generic plan.

In case we observe that PostgreSQL chooses a generic plan that’s not suitable for the provided bind parameter values, then we can use the force_custom_plan strategy to instruct PostgreSQL to skip the generic plan and generate a custom plan on every query execution.

Transactions and Concurrency Control eBook

Leave a Reply

This site uses Akismet to reduce spam. Learn how your comment data is processed.