PostgreSQL 函数调试、诊断、优化 auto_explain
PostgreSQL 函數(shù)調(diào)試 & auto_explain
作者
digoal
日期
2016-11-21
標簽
PostgreSQL , pldebugger , 函數(shù)調(diào)試 , auto_explain
背景
PostgreSQL的服務(wù)端編程能力比較強，不僅支持像java, R, python這種流行的編程語言，另外還內(nèi)置了一個與Oracle plsql功能幾乎一致的plpgsql語言。
對于開發(fā)人員來說，有了語言還不夠的，調(diào)試是非常常見的需求。
所以PostgreSQL的函數(shù)語言怎么調(diào)試呢，使用pldebugger即可。
pldebugger的安裝
https://git.postgresql.org/gitweb/?p=pldebugger.git;a=summary
plpgsql調(diào)試方法
https://www.pgadmin.org/docs/1.22/debugger.html
除了函數(shù)的調(diào)試，還有函數(shù)內(nèi)SQL的執(zhí)行計劃如何觀測。
auto_explain
auto_explain 一個比較給力的模塊.
用于向日志輸出超出定義閾值執(zhí)行時間的SQL的執(zhí)行計劃。更強大的是可以選擇是否輸出內(nèi)嵌SQL的執(zhí)行計劃(如函數(shù)中的SQL).
auto_explain的輸出更詳細的解釋可以參考EXPLAIN的解釋。或者man EXPLAIN.
SYNOPSIS EXPLAIN [ ( option [, ...] ) ] statement EXPLAIN [ ANALYZE ] [ VERBOSE ] statement where option can be one of: ANALYZE [ boolean ] VERBOSE [ boolean ] COSTS [ boolean ] BUFFERS [ boolean ] FORMAT { TEXT | XML | JSON | YAML }開啟方式有兩種 :
1. 通過配置文件postgresql.conf
需要重啟數(shù)據(jù)庫。
2. 通過LOAD 'auto_explain';
這個只在當前SESSION生效，不需要重啟數(shù)據(jù)庫, 需要超級用戶權(quán)限。
其實還可以設(shè)置local_preload_libraries，session_preload_libraries參數(shù)來啟用。
例子
1. 修改配置文件:
shared_preload_libraries = 'auto_explain'新增如下配置:
auto_explain.log_min_duration = 0 # 為了方便查看,這里把時間設(shè)置為0,所有SQL都會被auto_explain捕獲輸出.實際使用的時候適當調(diào)大。如 100ms auto_explain.log_analyze = true # 以下可選 auto_explain.log_verbose = true auto_explain.log_buffers = true auto_explain.log_nested_statements = true然后重啟數(shù)據(jù)庫.重啟時會輸出一個LOG
postgres@db5-> LOG: loaded library "$libdir/auto_explain.so"下面來執(zhí)行幾條SQL
postgres@db5-> psql -h 127.0.0.1 digoal digoal psql (9.1beta1) Type "help" for help. digoal=> select * from tbl_user_info limit 2; id | firstname | lastname | corp ----+-----------+----------+---------- 1 | zhou1 | digoal1 | sky-mobi 2 | zhou2 | digoal2 | sky-mobi (2 rows) digoal=> select count(*) from tbl_test; count --------- 1000100 (1 row)日志輸出
2011-06-08 15:19:14.390 CST,"digoal","digoal",13789,"127.0.0.1:59549",4def2270.35dd,1,"SELECT",2011-06-08 15:19:12 CST,2/18,0,LOG,00 000,"duration: 0.040 ms plan: Query Text: select * from tbl_user_info limit 2; Limit (cost=0.00..0.04 rows=2 width=31) (actual time=0.020..0.023 rows=2 loops=1) Output: id, firstname, lastname, corp Buffers: shared hit=1 -> Seq Scan on public.tbl_user_info (cost=0.00..183.00 rows=10000 width=31) (actual time=0.014..0.015 rows=2 loops=1) Output: id, firstname, lastname, corp Buffers: shared hit=1",,,,,,,,,"psql" 2011-06-08 15:19:17.902 CST,"digoal","digoal",13789,"127.0.0.1:59549",4def2270.35dd,2,"SELECT",2011-06-08 15:19:12 CST,2/19,0,LOG,00 000,"duration: 1232.064 ms plan: Query Text: select count(*) from tbl_test; Aggregate (cost=16927.25..16927.26 rows=1 width=0) (actual time=1232.044..1232.045 rows=1 loops=1) Output: count(*) Buffers: shared hit=4426 -> Seq Scan on public.tbl_test (cost=0.00..14427.00 rows=1000100 width=0) (actual time=0.015..626.872 rows=1000100 loops=1) Output: id Buffers: shared hit=4426",,,,,,,,,"psql"2. 通過LOAD 'auto_explain' ;
這個只在當前SESSION生效，不需要重啟數(shù)據(jù)庫, 需要超級用戶權(quán)限。
首先先恢復(fù)postgresql.conf的配置，去除前面的配置.然后重啟數(shù)據(jù)庫.
普通用戶不允許加載auto_explain模塊.(普通用戶只允許加載$libdir/plugins目錄下的模塊,但是auto_explain即使拷貝到這個目錄也不行)
digoal=> load 'auto_explain'; ERROR: access to library "auto_explain" is not allowed digoal=> \c digoal postgres You are now connected to database "digoal" as user "postgres". digoal=# load 'auto_explain'; LOAD digoal=# set auto_explain.log_min_duration=0; SET digoal=# select * from tbl_user_info limit 2; id | firstname | lastname | corp ----+-----------+----------+---------- 1 | zhou1 | digoal1 | sky-mobi 2 | zhou2 | digoal2 | sky-mobi (2 rows)查看日志
2011-06-08 15:25:33.361 CST,"postgres","digoal",13968,"127.0.0.1:15445",4def23d5.3690,1,"SELECT",2011-06-08 15:25:09 CST,2/9,0,LOG,0 0000,"duration: 0.048 ms plan: Query Text: select * from tbl_user_info limit 2; Limit (cost=0.00..0.04 rows=2 width=31) -> Seq Scan on tbl_user_info (cost=0.00..183.00 rows=10000 width=31)",,,,,,,,,"psql"連接到digoal用戶，這個LOAD的模塊消失(后面會有解釋).
digoal=# load 'auto_explain'; LOAD digoal=# set session auto_explain.log_min_duration=0; SET digoal=# \c digoal digoal You are now connected to database "digoal" as user "digoal". digoal=> select * from tbl_user_info limit 3; id | firstname | lastname | corp ----+-----------+----------+---------- 1 | zhou1 | digoal1 | sky-mobi 2 | zhou2 | digoal2 | sky-mobi 3 | zhou3 | digoal3 | sky-mobi (3 rows)查看日志，沒有auto_explain的輸出.即使這里使用了session來定義這個參數(shù)的有效范圍。
原因是session重新分配了，因為\c digoal digoal 相當于重新連接，backend也重新生成,如下.
digoal=> select * from pg_stat_activity; datid | datname | procpid | usesysid | usename | application_name | client_addr | client_hostname | client_port | backend_s tart | xact_start | query_start | waiting | current_query -------+---------+---------+----------+---------+------------------+-------------+-----------------+-------------+------------------ -------------+-------------------------------+-------------------------------+---------+--------------------------------- 16430 | digoal | 14155 | 16423 | digoal | psql | 127.0.0.1 | | 5959 | 2011-06-08 15:31: 32.794906+08 | 2011-06-08 15:31:40.616346+08 | 2011-06-08 15:31:40.616346+08 | f | select * from pg_stat_activity; (1 row) digoal=> \c digoal postgres You are now connected to database "digoal" as user "postgres". digoal=# select * from pg_stat_activity; datid | datname | procpid | usesysid | usename | application_name | client_addr | client_hostname | client_port | backend_ start | xact_start | query_start | waiting | current_query -------+---------+---------+----------+----------+------------------+-------------+-----------------+-------------+----------------- --------------+-------------------------------+-------------------------------+---------+--------------------------------- 16430 | digoal | 14161 | 10 | postgres | psql | 127.0.0.1 | | 5961 | 2011-06-08 15:31 :43.937297+08 | 2011-06-08 15:31:45.178005+08 | 2011-06-08 15:31:45.178005+08 | f | select * from pg_stat_activity; (1 row)那么如何避免這樣的情況發(fā)生呢? 答案是使用set role .
digoal=# load 'auto_explain'; LOAD digoal=# set session auto_explain.log_min_duration=0; SET digoal=# set role digoal; SET digoal=> select * from tbl_user_info limit 3; id | firstname | lastname | corp ----+-----------+----------+---------- 1 | zhou1 | digoal1 | sky-mobi 2 | zhou2 | digoal2 | sky-mobi 3 | zhou3 | digoal3 | sky-mobi (3 rows)再看日志,已經(jīng)有了 :
2011-06-08 15:29:30.011 CST,"postgres","digoal",14062,"127.0.0.1:5939",4def24bc.36ee,1,"SELECT",2011-06-08 15:29:00 CST,2/29,0,LOG,0 0000,"duration: 0.031 ms plan: Query Text: select * from tbl_user_info limit 3; Limit (cost=0.00..0.05 rows=3 width=31) -> Seq Scan on tbl_user_info (cost=0.00..183.00 rows=10000 width=31)",,,,,,,,,"psql"如果你不想看日志這么麻煩，想在client直接顯示，也很方便，設(shè)置client_min_messages='log'就可以看到auto explain的輸出了。
set client_min_messages='log'; set auto_explain.log_min_duration = 0; set auto_explain.log_analyze = true; set auto_explain.log_verbose = true; set auto_explain.log_buffers = true; set auto_explain.log_nested_statements = true;postgres=# do language plpgsql $$ declare begin perform 1 from pg_class where oid=1; end; $$;LOG: duration: 0.008 ms plan: Query Text: SELECT 1 from pg_class where oid=1 Index Only Scan using pg_class_oid_index on pg_catalog.pg_class (cost=0.27..1.29 rows=1 width=4) (actual time=0.006..0.006 rows=0 loops=1)Output: 1Index Cond: (pg_class.oid = '1'::oid)Heap Fetches: 0Buffers: shared hit=2 DO參考
1. man LOAD
2. man EXPLAIN
3.?http://www.postgresql.org/docs/9.6/static/auto-explain.html
總結(jié)
以上是生活随笔為你收集整理的PostgreSQL 函数调试、诊断、优化 auto_explain的全部內(nèi)容，希望文章能夠幫你解決所遇到的問題。
- 上一篇： 梦到闺蜜意味着什么
- 下一篇： 梦到给别人钱什么意思