PostgreSQL DBA-Extension (auto_explain)
This article briefly introduces the plug-in for PostgreSQL: auto_explain. The plug-in automatically explain SQL statements and prints the execution plan in a log file.
Installation
Compilation and installation
[pg12@localhost auto_explain] $makemake-C. /.. / src/backend generated-headersmake [1]: Entering directory `/ home/pg12/source/postgresql-12.1/src/backend'make-C catalog distprep generated-header-symlinksmake [2]: Entering directory` / home/pg12/source/postgresql-12.1/src/backend/catalog'make [2]: Nothing to be done for `distprep'.make [2]: Nothing to be done for `generated-header-symlinks'.make [2]: Leaving Directory `/ home/pg12/source/postgresql-12.1/src/backend/catalog'make-C utils distprep generated-header-symlinksmake [2]: Entering directory` / home/pg12/source/postgresql-12.1/src/backend/utils'make [2]: Nothing to be done for `distprep'.make [2]: Nothing to be done for `generated-header-symlinks'.make [2]: Leaving directory `/ home/pg12/source/postgresql-12.1/src/backend/utils'make [1]: Leaving Directory `/ home/pg12/source/postgresql-12.1/src/backend'gcc-std=gnu99-Wall-Wmissing-prototypes-Wpointer-arith-Wdeclaration-after-statement-Werror=vla-Wendif-labels-Wmissing-format-attribute-Wformat-security-fno-strict-aliasing-fwrapv-fexcess-precision=standard-g-O0-DOPTIMIZER_DEBUG-G3-gdwarf-2-fPIC-I. -I. -I../../src/include-D_GNU_SOURCE-I/usr/include/libxml2-c-o auto_explain.o auto_explain.c-MMD-MP-MF .deps / auto_explain.Pogcc-std=gnu99-Wall-Wmissing-prototypes-Wpointer-arith-Wdeclaration-after-statement-Werror=vla-Wendif-labels-Wmissing-format-attribute-Wformat-security-fno-strict-aliasing-fwrapv-fexcess-precision=standard-g-O0-DOPTIMIZER_DEBUG-G3-gdwarf-2-fPIC-shared- O auto_explain.so auto_explain.o-L../../src/port-L../../src/common-Wl -- as-needed-Wl,-rpath,'/appdb/pg12/pg12.1/lib' -- enable-new-dtags [pg12@localhost auto_explain] $make installmake-C. /.. / src/backend generated-headersmake [1]: Entering directory `/ home/pg12/source/postgresql-12.1/src/backend'make-C catalog distprep generated-header-symlinksmake [2]: Entering directory` / home/pg12/source/postgresql-12.1/src/backend/catalog'make [2]: Nothing to be done for `distprep'.make [2]: Nothing to be done for `generated-header- Symlinks'.make [2]: Leaving directory `/ home/pg12/source/postgresql-12.1/src/backend/catalog'make-C utils distprep generated-header-symlinksmake [2]: Entering directory` / home/pg12/source/postgresql-12.1/src/backend/utils'make [2]: Nothing to be done for `distprep'.make [2]: Nothing to be done for `generated-header-symlinks'.make [2]: Leaving directory `/ home/pg12/source/postgresql-12.1/src/backend / utils'make [1]: Leaving directory `/ home/pg12/source/postgresql-12.1/src/backend'/bin/mkdir-p'/ appdb/pg12/pg12.1/lib/postgresql'/bin/install-c-m 755 auto_explain.so' / appdb/pg12/pg12.1/lib/postgresql/auto_explain.so'
Experience
Modify configuration file and restart database
[pg12@localhost pg121db] $cat postgresql.auto.conf # Do not edit this file manuallyhands # It will be overwritten by the ALTER SYSTEM command.shared_preload_libraries = 'auto_explain,anon' [pg12@localhost pg121db] $[pg12@localhost auto_explain] $pg_ctl restartwaiting for server to shut down.... Doneserver stoppedwaiting for server to start....2019-11-20 16 starting PostgreSQL 32 starting PostgreSQL 21.013 CST [20847] LOG: starting PostgreSQL 12.1 on x86_64-pc-linux-gnu, compiled by gcc (GCC) 4.8.5 20150623 (Red Hat 4.8.5-16), 64-bit2019-11-20 16 V 32 starting PostgreSQL 21.013 CST [20847] LOG: listening on IPv4 address "0.0.0.0" Port 54322019-11-20 16 port 32 LOG 21.013 CST [20847] LOG: listening on IPv6 address ":", port 54322019-11-20 16 redirecting log output to logging collector process2019 32 listening on IPv6 address 21.015 CST [20847] LOG: listening on Unix socket "/ data/pg12/.s.PGSQL.5432" 2019-11-20 16 Swiss 32 listening on IPv6 address 21.088 CST [20847] LOG: redirecting log output to logging collector process2019-11-20 16 Swiss 32 Switzerland 21.088 CST [20847] HINT: Future log output will appear in directory "pg_log". Doneserver started [pg12@localhost auto_explain] $
Set auto_explain parameters and load parameters
[local:/data/pg12]: 5432 pg12@testdb=# alter system set auto_explain.log_min_duration = 0 pg_ctl reloadserver signaled alter SYSTEM [local:/data/pg12]: 5432 pg12@testdb=# alter system set auto_explain.log_analyze = on;ALTER SYSTEM [local:/data/pg12]: 5432 pg12@testdb=#. [pg12@localhost pg121db] $pg_ctl reloadserver signaled [pg12@localhost pg121db] $
Execute queries in psql and check log output
[local:/data/pg12]: 5432 pg12@testdb=# select * from tbl; id-(0 rows) [local:/data/pg12]: 5432 pg12@testdb=# 2019-11-20 1615 35 rows 34.480 CST, "pg12", "testdb", 20869, "[local]", 5dd4fa24.5185 CST,3/8,0,LOG,00000 62, "SELECT", 2019-11-20 16:32:36 CST,3/8,0,LOG,00000, "duration: 0.019 ms plan:Query Text: select * from tbl" Seq Scan on tbl (cost=0.00..35.50 rows=2550 width=4) (actual time=0.009..0.009 rows=0 loops=1) "," psql "--[local:/data/pg12]: 5432 pg12@testdb=# select * from tbl where id = 100::float Id-100 (1 row) [local:/data/pg12]: 5432 pg12@testdb=# 2019-11-20 16 pg12@testdb=# 54V 08.280 CST, "pg12", "testdb", 21506, "[local]", 5dd4fcf 2.5402 CST,3/5,0,LOG,00000 2, "SELECT", 2019-11-20 16:44:34 CST,3/5,0,LOG,00000, "duration: 38.947 ms plan:Query Text: select * from tbl where id = 100::float" Seq Scan on tbl (cost=0.00..1943.00 rows=500 width=4) (actual time=0.135..38.925 rows=1 loops=1) Filter: (id):: double precision = '100'::double precision) Rows Removed by Filter: 99999 "," psql "
Testing using the JDBC program
/ * * / package testPG;import java.sql.Connection;import java.sql.DriverManager;import java.sql.PreparedStatement;import java.sql.ResultSet;import java.sql.SQLException;public class TestAutoExplain {public static void main (String [] args) {try (Connection conn = DriverManager.getConnection ("jdbc:postgresql://192.168.26.28:5432/testdb", "pg12", "root")) {TestExplicitType (conn); TestImplicitType (conn) } catch (SQLException se) {System.out.println (se.getMessage ());} catch (Exception e) {e.printStackTrace ();} finally {} / / end try} public static void TestExplicitType (Connection conn) {try (PreparedStatement pstmt = conn.prepareStatement ("SELECT id from tbl where id =?");) {conn.setAutoCommit (true); pstmt.setInt (1,100) Try (ResultSet rs = pstmt.executeQuery ()) {if (rs.next ()) {int id = rs.getInt ("id"); System.out.println ("id:" + id);}} catch (SQLException se) {System.out.println (se.getMessage ());} catch (Exception e) {e.printStackTrace () } finally {} / / end try} / / end public static void TestImplicitType (Connection conn) {try (PreparedStatement pstmt = conn.prepareStatement ("SELECT id from tbl where id =?");) {conn.setAutoCommit (true); pstmt.setObject (1,100); try (ResultSet rs = pstmt.executeQuery ()) {if (rs.next ()) {int id = rs.getInt ("id") System.out.println ("id:" + id);}} catch (SQLException se) {System.out.println (se.getMessage ());} catch (Exception e) {e.printStackTrace ();} finally {} / / end try} / / end} / / end Class
Database background log output
2019-11-20 16 testdb 4515 CST, "pg12", "testdb", 21581, "192.168.119.33 testdb 54001", 5dd4fd43.544d Person1, "SELECT", 2019-11-20 16:45:55 CST,4/22,0,LOG,00000 "duration: 28.367 ms plan:Query Text: SELECT id from tbl where id = $1Index Only Scan using idx_tbl_id on tbl (cost=0.29..8.31 rows=1 width=4) (actual time=28.301..28.311 rows=1 loops=1) Index Cond: (id = 100,100) Heap Fetches: 1", "PostgreSQL JDBC Driver" 2019-11-20 16pur45 CST 55.365 CST, "pg12", "testdb", 21581, "192.168.119.33 SELECT id from tbl where id 54001", 5dd4fd43.544dmem2 "SELECT", 2019-11-20 16:45:55 CST,4/23,0,LOG,00000, "duration: 0.080 ms plan:Query Text: SELECT id from tbl where id = $1Index Only Scan using idx_tbl_id on tbl (cost=0.29..8.31 rows=1 width=4) (actual time=0.064..0.067 rows=1 loops=1) Index Cond: (id = 100) Heap Fetches: 1", "PostgreSQL JDBC Driver"
Although setObject is used as the parameter setting, the driver correctly sets the parameter type to int, and there is no conversion of double-> int.
references
Making Mystery-Solving Easier with auto_explain
