PostgreSQL跟蹤函式內部執行計畫方法

很多人可能在使用pg時會碰到這樣的問題：乙個sql單獨拿出來執行很快，但是放到函式裡面執行就很慢，想要知道函式裡面究竟慢在**，但是卻無從下手。因為我們沒辦法像對單個sql一樣直接explain來獲取執行計畫。

例如在oracle中我們可以通過例如10046trace這種方式來看看函式內部慢在**，那麼在pg中該如何去檢視內部的執行計畫呢？

auto_explain是pg自帶的乙個模組，為我們提供了一種方式來自動記錄慢速語句的執行計畫，而不需要手工執行explain。這在大型應用中追蹤未被優化的查詢時有用。

auto_explain的輸出更詳細的解釋可以參考expolain的解釋，或者man explain。

開啟auto_explain有兩種方式：

1、通過配置檔案postgresql.conf

需要重啟資料庫。

2、通過load 『auto_explain』;

這個只在當前session生效，不需要重啟資料庫, 需要超級使用者許可權。

其實還可以設定local_preload_libraries，session_preload_libraries引數來啟用。

例子：

1. 修改postgresql.conf配置檔案:

shared_preload_libraries =

'auto_explain'

新增如下配置:

auto_explain.log_min_duration = 0 # 為了方便檢視,這裡把時間設定為0,所有sql都會被auto_explain捕獲輸出.實際使用的時候適當調大。如 100ms auto_explain.log_analyze = true # 以下可選 auto_explain.log_verbose = true auto_explain.log_buffers = true auto_explain.log_nested_statements =

true

2、重啟資料庫

預設情況下日誌記錄在日誌檔案中。

查詢：

bill=
# select count(*) from tb1;                   
count  
---------
1000000(1
row)

檢視log日誌：

bill@test180
-> tail -f postgresql-
2020-05
-18_110158.csv
2020-05
-1811:28:52.056 cst,
"bill"
,"bill"
,2160
,"[local]"
,5ec1fd1a.
870,3,
"select"
,2020-05
-1811:12:26 cst,3/
60,0,log,
00000
,"duration: 70.772 ms  plan:
query text: select count(*) from tb1;
finalize aggregate  (cost=14542.55..14542.56 rows=1 width=8) (actual time=68.293..68.293 rows=1 loops=1)
output: count(*)
buffers: shared hit=8334
->  gather  (cost=14542.33..14542.54 rows=2 width=8) (actual time=68.169..70.752 rows=3 loops=1)
output: (partial count(*))
workers planned: 2
workers launched: 2
buffers: shared hit=8334
->  partial aggregate  (cost=13542.33..13542.34 rows=1 width=8) (actual time=65.305..65.305 rows=1 loops=3)
output: partial count(*)
buffers: shared hit=8334
worker 0: actual time=64.003..64.003 rows=1 loops=1
buffers: shared hit=2590
worker 1: actual time=63.998..63.998 rows=1 loops=1
buffers: shared hit=2654
->  parallel seq scan on public.tb1  (cost=0.00..12500.67 rows=416667 width=0) (actual time=0.016..41.887 rows=333333 loops=3)
output: id, info
buffers: shared hit=8334
worker 0: actual time=0.018..42.208 rows=310800 loops=1
buffers: shared hit=2590
worker 1: actual time=0.018..42.225 rows=318400 loops=1
buffers: shared hit=2654",,
,,,,
,,"explain_executorend, auto_explain.c:415"
,"psql"

3、如果你不想看日誌這麼麻煩，想在client直接顯示，也很方便，設定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
;

我們來看乙個輸出函式執行計畫的例子。

先建立乙個簡單的函式：

bill=
# create function f1(c1 int) returns int as $$
bill$# declare
bill$# rec int;
bill$# begin
bill$# select count(*) from tb1 where id < c1 into rec;
bill$# return rec;
bill$# end;
bill$# $$ language plpgsql strict;

呼叫函式：

可以看到執行計畫直接輸出出來了，即使函式十分複雜，內部sql的執行計畫也可以依次輸出，這樣我們就知道函式慢在**了。

bill=
# select f1(100);
psql: log:  duration: 0.055 ms  plan:
query text: select
count(*
)from tb1 where id < c1
aggregate  (cost=
5.03..5
.04rows
=1 width=8)
(actual time
=0.053..0
.053
rows
=1 loops=1)
output: count(*
)  buffers: shared hit=4-
>
index only scan using idx_tb1 on
public
.tb1  (cost=
0.42..4
.78rows
=100 width=0)
(actual time
=0.019..0
.040
rows
=99 loops=1)
output: id
index cond: (tb1.id <
100)
heap fetches: 99
buffers: shared hit=
4psql: log:  duration: 0.677 ms  plan:
query text: select f1(
100)
;result  (cost=
0.00..0
.26rows
=1 width=4)
(actual time
=0.672..0
.672
rows
=1 loops=1)
output: f1(
100)
buffers: shared hit=
39read=1
f1 ----99(
1row
)

PostgreSQL跟蹤函式內部執行計畫方法

PostgreSQL 慢查詢SQL語句跟蹤

PostgreSQL 慢查詢SQL跟蹤操作

postgreSQL常用函式

PostgreSQL跟蹤函式內部執行計畫方法

PostgreSQL 慢查詢SQL語句跟蹤

PostgreSQL 慢查詢SQL跟蹤操作

postgreSQL常用函式

相關推薦