Explain command and execution plan

The first step in tuning PostgreSQL queries is to understand how to read the execution plans generated by the EXPLAIN command. The EXPLAIN command shows the execution plan of a statement and how data from tables is scanned; for example, a table might be scanned using an index or sequential scan. Also, it shows how tables are joined, the join method, and the estimated number of rows.

The EXPLAIN command also has several options; the ANALYZE option causes the statement to be executed and returns the actual time and number of rows. Finally, the EXPLAIN command can give insights into a buffer's usage and caching. The synopsis for the EXPLAIN command is as follows, where the option can be one of: ANALYZE, VERBOSE, COSTS, BUFFERS, TIMING, SUMMARY, and FORMAT :

h EXPLAIN
Description: show the execution plan of a statement
Syntax:
EXPLAIN [ ( option [, ...] ) ] statement
EXPLAIN [ ANALYZE ] [ VERBOSE ] statement

To experiment with EXPLAIN command, one can create a simple table and populate it with data, as follows: 

postgres=# CREATE TABLE guru ( id INT PRIMARY KEY, name TEXT NOT NULL );
CREATE TABLE
postgres=# INSERT INTO guru SELECT n , md5 (random()::text) FROM generate_series (1, 100000) AS foo(n);
INSERT 0 100000
postgres=# -- To update table statistics
postgres=# ANALYSE guru;
ANALYZE

To get the execution plan of selecting all the records for the table guru, one can use EXPLAIN command, as follows: 

postgres=# EXPLAIN SELECT * FROM guru;
QUERY PLAN
-------------------------------------------------------------
Seq Scan on guru (cost=0.00..1834.00 rows=100000 width=37)
(1 row)

The execution plan is only a one-node sequential scan on the guru table, as shown in the preceding code. The number of rows is estimated correctly, as we analyzed the table after insert. Autovacuum is important for keeping your database's statistics up to date.

Certainly, wrong statistics mean poor execution plans. After database bulk operations, it is good to run the ANALYZE command to update the statistics. Also, one could control the data sampling performed by ANALYZE using the following:

ALTER TABLE <table name> ALTER COLUMN <column name> SET STATISTICS <integer>; 

Increasing column statistics allows a better estimation of rows, but also makes the autovacuum process slower. The cost is an estimation of the effort required to execute the query. In the preceding example, the cost, 0.00, is the cost to retrieve the first row, while the cost, 1834.00, is the cost to retrieve all rows, which is calculated as follows: (relpages ∗ seq_page cost) + (reltuples * cpu_tuple_cost). The number of relation pages (relpages) and the number of rows in relation (reltuples) can be found in pg_classseq_page_cost and cpu_tuple_cost contains planner related configuration settings. So, the cost 1834 is calculated as shown in the following example:

postgres=# SELECT relpages*current_setting('seq_page_cost')::numeric + reltuples*current_setting('cpu_tuple_cost')::numeric as cost FROM pg_class WHERE relname='guru';
cost
------
1834
(1 row)

For the simple case of a sequential scan, it is quite straightforward to calculate the cost. However, when a query involves predicates' evaluation, grouping, ordering, and joining, cost estimation becomes complicated. Finally, the width 37 is the average width of the tuple in bytes. This information can be found in the pg_stats table. To execute and get the cost in real time, one could use EXPLAIN (ANALYZE) or EXPLAIN ANALYZE. The following example returns all the rows where the ID is between 10 and 20

postgres=# EXPLAIN ANALYZE SELECT * FROM guru WHERE id >= 10 and id < 20;
QUERY PLAN
-------------------------------------------------------------------------------------------------------------------
Index Scan using guru_pkey on guru (cost=0.29..8.51 rows=11 width=37) (actual time=0.007..0.010 rows=10 loops=1)
Index Cond: ((id >= 10) AND (id < 20))
Planning time: 0.132 ms
Execution time: 0.028 ms
(4 rows)

In the preceding query, the planner got a very close estimation compared to the real values: it estimated 11 rows instead of 10. Also, the planner-generated execution plan now uses an index scan because we have used predicates. In the execution plan, one could also see other information, such as the number of loops and actual time. Note that the execution plan is four lines with different indentations. One should read the execution plan bottom-up and from the most to least indented. The Index Cond: ((id >= 10) AND (id < 20)) is indented and belongs to the Index Scan node. 

The EXPLAIN (BUFFERS) option shows the effect of caching and whether the cache is used and configured properly. To take a look at the complete effect of caching, one needs to perform cold and hot testing. Also, one can control the format of the execution plan. The following example shows the effect of using the BUFFERS and FORMAT options' cold and hot testing. To do cold testing, let's stop and start the server, as follows:

$ /etc/init.d/postgresql stop
$ /etc/init.d/postgresql start
Often, PostgreSQL restart is not enough to clean the cache. Note that PostgreSQL also utilizes the operating system buffers. In Ubuntu, one can clean the cache with the following command: echo 3 > /proc/sys/vm/drop_caches.

Now, let's read the guru table: 

postgres=# EXPLAIN (ANALYZE, FORMAT YAML, BUFFERS) SELECT * FROM guru;
QUERY PLAN
--------------------------------
- Plan: +
Node Type: "Seq Scan" +
Parallel Aware: false +
Relation Name: "guru" +
Alias: "guru" +
Startup Cost: 0.00 +
Total Cost: 1834.00 +
Plan Rows: 100000 +
Plan Width: 37 +
Actual Startup Time: 0.016+
Actual Total Time: 209.332+
Actual Rows: 100000 +
Actual Loops: 1 +
Shared Hit Blocks: 0 +
Shared Read Blocks: 834 +
Shared Dirtied Blocks: 0 +
Shared Written Blocks: 0 +
Local Hit Blocks: 0 +
Local Read Blocks: 0 +
Local Dirtied Blocks: 0 +
Local Written Blocks: 0 +
Temp Read Blocks: 0 +
Temp Written Blocks: 0 +
Planning Time: 0.660 +
Triggers: +
Execution Time: 213.879
(1 row)

To perform hot testing, the query needs to be executed again, as follows:

postgres=# EXPLAIN (ANALYZE, FORMAT YAML, BUFFERS) SELECT * FROM guru;
QUERY PLAN
--------------------------------
- Plan: +
Node Type: "Seq Scan" +
Parallel Aware: false +
Relation Name: "guru" +
Alias: "guru" +
Startup Cost: 0.00 +
Total Cost: 1834.00 +
Plan Rows: 100000 +
Plan Width: 37 +
Actual Startup Time: 0.009+
Actual Total Time: 10.105 +
Actual Rows: 100000 +
Actual Loops: 1 +
Shared Hit Blocks: 834 +
Shared Read Blocks: 0 +
Shared Dirtied Blocks: 0 +
Shared Written Blocks: 0 +
Local Hit Blocks: 0 +
Local Read Blocks: 0 +
Local Dirtied Blocks: 0 +
Local Written Blocks: 0 +
Temp Read Blocks: 0 +
Temp Written Blocks: 0 +
Planning Time: 0.035 +
Triggers: +
Execution Time: 14.447
(1 row)

The first thing one can notice is the execution time difference. The second execution time is around 93% less than the first execution time. This behavior is due to reading the data from memory instead of the hard disk, as we saw in the execution plan. For more details, have a look on Shared Hit Blocks , which simply means the data is found in the memory. 

..................Content has been hidden....................

You can't read the all page of ebook, please click here login for view all page.
Reset