使用plsql_plprofiler 分析过程块的执行

前言：存储过程可能涉及很多的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 循环