The auto_explain PostgreSQL module provides a means for logging execution plans of slow statements automatically, without having to run EXPLAIN by hand. This is especially helpful for tracking down un-optimized queries in large applications.
To enable the auto_explain extension, add
shared_preload_libraries in the PostgreSQL server configuration parameters using the YB-TServer --ysql_pg_conf_csv flag:
Note that modifying
shared_preload_libraries requires restarting the YB-TServer.
You can customize the following auto_explain parameters:
||Minimum statement execution time, in milliseconds, that will cause the statement's plan to be logged. Setting this to zero logs all plans. Minus-one (the default) disables logging. For example, if you set it to 250ms then all statements that run 250ms or longer will be logged. Only superusers can change this setting.||-1|
||Print EXPLAIN ANALYZE output, rather than just EXPLAIN output when an execution plan is logged. When on, per-plan-node timing occurs for all statements executed, whether or not they run long enough to actually get logged. This can have an extremely negative impact on performance. Turning off
||Print buffer usage statistics when an execution plan is logged; equivalent to the BUFFERS option of EXPLAIN. Has no effect unless
||Print per-node timing information when an execution plan is logged; equivalent to the TIMING option of EXPLAIN. The overhead of repeatedly reading the system clock can slow down queries significantly on some systems, so it may be beneficial to set this parameter to off when only actual row counts, and not exact times, are needed. Has no effect unless
||Include trigger execution statistics when an execution plan is logged. Has no effect unless
||Print verbose details when an execution plan is logged; equivalent to the VERBOSE option of EXPLAIN. Only superusers can change this setting.||false|
||The format of the EXPLAIN output. Allowed values are
||Consider nested statements (statements executed inside a function) for logging. When off, only top-level query plans are logged. Only superusers can change this setting.||false|
||Explain only a set fraction of the statements in each session. The default 1 means explain all the queries. In case of nested statements, either all will be explained or none. Only superusers can change this setting.||1|
Note that the default behavior is to do nothing, so you must set at least
auto_explain.log_min_duration if you want any results.
To change auto_explain parameters, use the SET statement. For example:
SET auto_explain.log_min_duration = 0; SET auto_explain.log_analyze = true; SELECT count(*) FROM pg_class, pg_index WHERE oid = indrelid AND indisunique;
This produces log output similar to the following in the PostgreSQL log file in the
LOG: duration: 316.556 ms plan: Query Text: SELECT count(*) FROM pg_class, pg_index WHERE oid = indrelid AND indisunique; Aggregate (cost=216.39..216.40 rows=1 width=8) (actual time=316.489..316.489 rows=1 loops=1) -> Nested Loop (cost=0.00..213.89 rows=1000 width=0) (actual time=10.828..316.200 rows=110 loops=1) -> Seq Scan on pg_index (cost=0.00..100.00 rows=1000 width=4) (actual time=7.465..8.068 rows=110 loops=1) Remote Filter: indisunique -> Index Scan using pg_class_oid_index on pg_class (cost=0.00..0.11 rows=1 width=4) (actual time=2.673..2.673 rows=1 loops=110) Index Cond: (oid = pg_index.indrelid)