前言:存储过程可能涉及很多的SQL及控制块,我们看到的执行时间是整个过程块的执行时间,如果我们认为性能有问题,我们只能逐条SQL的分析,查找问题SQL,效率非常低下。KingbaseES 提供了 plsql_plprofiler 扩展插件, 可以方便用户跟踪分析过程的每条语句的执行情况,能让我们快速定位问题。
以下以例子的方式演示plsql_plprofiler的使用。
1、创建扩展插件
create extension plsql_plprofiler
2、创建演示的存储过程
create or replace procedure p1 as
cnt integer;
begin
for i in 1..100 loop
select count(*) into cnt from t1;
end loop;
select count(*) into cnt from t2;
end;
/
3、收集数据
test=# select pl_profiler_reset_local(); --清理本地数据
pl_profiler_reset_local
-------------------------
(1 row)
test=# select pl_profiler_reset_shared(); --清理全局数据
pl_profiler_reset_shared
--------------------------
(1 row)
test=# select pl_profiler_set_enabled_local(true); --启动本地会话分析器
pl_profiler_set_enabled_local
-------------------------------
t
(1 row)
test=# call p1();
CALL
test=# select pl_profiler_set_enabled_local(false); --关闭本地会话分析器
pl_profiler_set_enabled_local
-------------------------------
f
(1 row)
test=# select pl_profiler_collect_data();
pl_profiler_collect_data
--------------------------
0
(1 row)
4、分析数据
test=# select pl_profiler_func_oids_shared();
pl_profiler_func_oids_shared
------------------------------
{16485}
(1 row)
test=# select func_oid, func_oid::regproc as funcname,line_number, source from pl_profiler_funcs_source(pl_profiler_func_oids_shared());
func_oid | funcname | line_number | source
----------+----------+-------------+---------------------------------------
16485 | p1 | 0 | -- Line 0
16485 | p1 | 1 |
16485 | p1 | 2 | cnt integer;
16485 | p1 | 3 | begin
16485 | p1 | 4 | for i in 1..100 loop
16485 | p1 | 5 | select count(*) into cnt from t1;
16485 | p1 | 6 | end loop;
16485 | p1 | 7 | select count(*) into cnt from t2;
16485 | p1 | 8 | end
(9 rows)
SELECT L.func_oid::regproc as funcname,
L.func_oid as func_oid,
L.line_number,
sum(L.exec_count)::bigint AS exec_count,
sum(L.total_time)::bigint AS total_time,
max(L.longest_time)::bigint AS longest_time,
S.source
FROM pl_profiler_linestats_shared() L
JOIN pl_profiler_funcs_source(pl_profiler_func_oids_shared) S
ON S.func_oid = L.func_oid AND S.line_number = L.line_number
GROUP BY L.func_oid, L.line_number, S.source
ORDER BY L.func_oid, L.line_number;
funcname | func_oid | line_number | exec_count | total_time | longest_time | source
----------+----------+-------------+------------+------------+--------------+---------------------------------------
p1 | 16485 | 0 | 1 | 1296 | 1296 | -- Line 0
p1 | 16485 | 1 | 0 | 0 | 0 |
p1 | 16485 | 2 | 0 | 0 | 0 | cnt integer;
p1 | 16485 | 3 | 1 | 1294 | 1294 | begin
p1 | 16485 | 4 | 1 | 1098 | 1098 | for i in 1..100 loop
p1 | 16485 | 5 | 100 | 946 | 202 | select count(*) into cnt from t1;
p1 | 16485 | 6 | 0 | 0 | 0 | end loop;
p1 | 16485 | 7 | 1 | 193 | 193 | select count(*) into cnt from t2;
p1 | 16485 | 8 | 0 | 0 | 0 | end
(9 rows)
从收集到的数据可以某条SQL 执行次数、总执行时间(单位us)。
注意:控制块是包含内部所有语句的执行时间的,如:本例的for 循环