DBE_PROFILER

--step1 创建表和存储过程
gaussdb=# DROP TABLE IF EXISTS t1;
gaussdb=# CREATE TABLE t1 (i int);
gaussdb=# CREATE OR REPLACE PROCEDURE p1() AS
	sql_stmt varchar2(200);
	result number;
BEGIN
    for i in 1..1000 loop
      insert into t1 values(1);
    end loop;
    sql_stmt := 'select count(*) from t1';
    EXECUTE IMMEDIATE sql_stmt into result;
END;
/
gaussdb=# CREATE OR REPLACE PROCEDURE p2() AS
BEGIN
   p1();
END;
/
gaussdb=# CREATE OR REPLACE PROCEDURE p3() AS
BEGIN
    p2();
END;
/

--step2 调用plprofiler接口对存储过程进行profiling
gaussdb=# SELECT dbe_profiler.pl_start_profiling('123');
gaussdb=# CALL p3();

--step3 查询相关profiling信息
--查询dbe_profiler.pl_profiling_functions表查看此次profiling涉及的存储过程
gaussdb=# SELECT * FROM dbe_profiler.pl_profiling_functions ORDER BY run_id, funcoid;
       run_id        | funcoid | schema | funcname | total_occur | total_time 
---------------------+---------+--------+----------+-------------+------------
 140300887521024_123 |   16770 | public | p1()     |           1 |      54217
 140300887521024_123 |   16771 | public | p2()     |           1 |      54941
 140300887521024_123 |   16772 | public | p3()     |           1 |      55758
(3 rows)
--查询dbe_profiler.pl_profiling_details表查看存过内每条语句的执行时间细节
gaussdb=# SELECT * FROM dbe_profiler.pl_profiling_details WHERE funcoid = 16770 ORDER BY run_id, funcoid, line#;
       run_id        | funcoid | line# |                   source                    |  cmd_type  | total_occur | total_time | max_time | min_time 
---------------------+---------+-------+---------------------------------------------+------------+-------------+------------+----------+----------
 140300887521024_123 |   16770 |     1 |  DECLARE                                    |            |           0 |          0 |        0 |        0
 140300887521024_123 |   16770 |     2 | sql_stmt varchar2(200);                     |            |           0 |          0 |        0 |        0
 140300887521024_123 |   16770 |     3 | result number;                              |            |           0 |          0 |        0 |        0
 140300887521024_123 |   16770 |     4 | begin                                       |            |           0 |          0 |        0 |        0
 140300887521024_123 |   16770 |     5 |     for i in 1..1000 loop                   | FORI       |           1 |      52496 |    52496 |    52496
 140300887521024_123 |   16770 |     6 |       insert into t1 values(1);             | EXECSQL    |        1000 |      51970 |     2115 |       47
 140300887521024_123 |   16770 |     7 |     end loop;                               |            |           0 |          0 |        0 |        0
 140300887521024_123 |   16770 |     8 |     sql_stmt := 'select count(*) from t1';  | ASSIGN     |           1 |        446 |      446 |      446
 140300887521024_123 |   16770 |     9 |     EXECUTE IMMEDIATE sql_stmt into result; | DYNEXECUTE |           1 |       1271 |     1271 |     1271
 140300887521024_123 |   16770 |    10 | end                                         |            |           0 |          0 |        0 |        0
(10 rows)
--查询dbe_profiler.pl_profiling_callgraph表查看调用栈信息和对应每个存过执行的整体时间（total_time、self_time对应调用栈栈顶存储过程的总时间和自身执行时间）
gaussdb=# SELECT * FROM dbe_profiler.pl_profiling_callgraph ORDER BY run_id, stack;
       run_id        |                                   stack                                   | self_time 
---------------------+---------------------------------------------------------------------------+-----------
 140300887521024_123 | {"public.p3() oid=16772"}                                                 |       817
 140300887521024_123 | {"public.p3() oid=16772","public.p2() oid=16771"}                         |       724
 140300887521024_123 | {"public.p3() oid=16772","public.p2() oid=16771","public.p1() oid=16770"} |     54217
(3 rows)
--查询dbe_profiler.pl_profiling_trackinfo表查看存储过程每个阶段的执行时间
gaussdb=# SELECT step_name, loops_count FROM dbe_profiler.pl_profiling_trackinfo WHERE funcoid=16770;
  step_name   | loops_count 
--------------+-------------
 init         |           1
 package      |           1
 spictx       |           1
 compile      |           1
 exec_context |           1
 execute      |           1
 exec_cursor  |           1
 cleanup      |           1
 finsh        |           1
(9 rows)

--step4 删除系统表数据
gaussdb=# SELECT dbe_profiler.pl_clear_profiling('');
gaussdb=# SELECT step_name, loops_count FROM dbe_profiler.pl_profiling_trackinfo WHERE funcoid=16770;
 step_name | loops_count 
-----------+-------------
(0 rows)
gaussdb=# DROP TABLE t1;

--step5 profiling包含自治事务的存储过程。
--建表
gaussdb=# CREATE TABLE t2(a int, b int);
--创建包含自治事务的存储过程
gaussdb=# CREATE OR REPLACE PROCEDURE autonomous(a int, b int)  AS 
DECLARE 
	num3 int := a;
	num4 int := b;
	PRAGMA AUTONOMOUS_TRANSACTION;
BEGIN
	insert into t2 values(num3, num4); 
	dbe_output.print_line('just use call.');
END;
/
--创建调用自治事务存储过程的普通存储过程
gaussdb=# CREATE OR REPLACE PROCEDURE autonomous_1(a int, b int)  AS 
DECLARE 
BEGIN
	dbe_output.print_line('just no use call.');
	insert into t2 values(666, 666);
	autonomous(a,b);
END;
/
gaussdb=# SELECT dbe_profiler.pl_start_profiling ('100');
gaussdb=# CALL autonomous(11,22);
--查询表信息
gaussdb=# SELECT * FROM dbe_profiler.pl_profiling_functions ORDER BY run_id, funcoid;
 run_id | funcoid | schema | funcname | total_occur | total_time 
--------+---------+--------+----------+-------------+------------
(0 rows)

gaussdb=# SELECT * FROM dbe_profiler.pl_profiling_details ORDER BY run_id, funcoid, line#;
 run_id | funcoid | line# | source | cmd_type | total_occur | total_time | max_time | min_time 
--------+---------+-------+--------+----------+-------------+------------+----------+----------
(0 rows)

gaussdb=# SELECT * FROM dbe_profiler.pl_profiling_callgraph ORDER BY run_id, stack;
 run_id | stack | self_time 
--------+-------+-----------
(0 rows)

gaussdb=# SELECT * FROM dbe_profiler.pl_profiling_trackinfo ORDER BY run_id, funcoid;
 run_id | funcoid | step_name | loops_count | max_time | min_time | avg_time | total_time 
--------+---------+-----------+-------------+----------+----------+----------+------------
(0 rows)

gaussdb=# SELECT dbe_profiler.pl_start_profiling ('101');
gaussdb=# CALL autonomous_1(11,22);
gaussdb=# SELECT * FROM dbe_profiler.pl_profiling_functions ORDER BY run_id, funcoid;
       run_id        | funcoid |   schema   |    funcname    | total_occur | total_time 
---------------------+---------+------------+----------------+-------------+------------
 140421237831424_101 |   10422 | dbe_output | print_line()   |           1 |        758
 140421237831424_101 |   16771 | public     | autonomous_1() |           1 |      23855
(2 rows)

gaussdb=# SELECT * FROM dbe_profiler.pl_profiling_details ORDER BY run_id, funcoid, line#;
       run_id        | funcoid | line# |                   source                    | cmd_type | total_occur | total_time | max_time | min_time 
---------------------+---------+-------+---------------------------------------------+----------+-------------+------------+----------+----------
 140421237831424_101 |   10422 |     1 |                                             |          |           0 |          0 |        0 |        0
 140421237831424_101 |   10422 |     2 | BEGIN                                       |          |           0 |          0 |        0 |        0
 140421237831424_101 |   10422 |     3 |     PKG_UTIL.io_print(format, true);        | PERFORM  |           1 |        754 |      754 |      754
 140421237831424_101 |   10422 |     4 | END;                                        |          |           0 |          0 |        0 |        0
 140421237831424_101 |   10422 |     5 |                                             |          |           0 |          0 |        0 |        0
 140421237831424_101 |   16771 |     1 |                                             |          |           0 |          0 |        0 |        0
 140421237831424_101 |   16771 |     2 | DECLARE                                     |          |           0 |          0 |        0 |        0
 140421237831424_101 |   16771 |     3 | BEGIN                                       |          |           0 |          0 |        0 |        0
 140421237831424_101 |   16771 |     4 | dbe_output.print_line('just no use call.'); | PERFORM  |           1 |       2435 |     2435 |     2435
 140421237831424_101 |   16771 |     5 | insert into t2 values(666, 666);            | EXECSQL  |           1 |        602 |      602 |      602
 140421237831424_101 |   16771 |     6 | autonomous(a,b);                            | PERFORM  |           1 |      20813 |    20813 |    20813
 140421237831424_101 |   16771 |     7 | END                                         |          |           0 |          0 |        0 |        0
(12 rows)

gaussdb=# SELECT * FROM dbe_profiler.pl_profiling_callgraph ORDER BY run_id, stack;
       run_id        |                                  stack                                  | self_time 
---------------------+-------------------------------------------------------------------------+-----------
 140421237831424_101 | {"public.autonomous_1() oid=16771"}                                     |     23097
 140421237831424_101 | {"public.autonomous_1() oid=16771","dbe_output.print_line() oid=10422"} |       758
(2 rows)

gaussdb=# SELECT * FROM dbe_profiler.pl_profiling_trackinfo ORDER BY run_id, funcoid;
       run_id        | funcoid |  step_name   | loops_count | max_time | min_time | avg_time | total_time 
---------------------+---------+--------------+-------------+----------+----------+----------+------------
 140421237831424_101 |   10422 | init         |           1 |        0 |        0 |        0 |          0
 140421237831424_101 |   10422 | package      |           1 |        9 |        9 |        9 |          9
 140421237831424_101 |   10422 | spictx       |           1 |        1 |        1 |        1 |          1
 140421237831424_101 |   10422 | compile      |           1 |      383 |      383 |      383 |        383
 140421237831424_101 |   10422 | exec_context |           1 |        1 |        1 |        1 |          1
 140421237831424_101 |   10422 | execute      |           1 |     1301 |     1301 |     1301 |       1301
 140421237831424_101 |   10422 | exec_cursor  |           1 |        3 |        3 |        3 |          3
 140421237831424_101 |   10422 | cleanup      |           1 |       11 |       11 |       11 |         11
 140421237831424_101 |   10422 | finsh        |           1 |        0 |        0 |        0 |          0
 140421237831424_101 |   16771 | init         |           1 |        0 |        0 |        0 |          0
 140421237831424_101 |   16771 | package      |           1 |      103 |      103 |      103 |        103
 140421237831424_101 |   16771 | spictx       |           1 |        1 |        1 |        1 |          1
 140421237831424_101 |   16771 | compile      |           1 |     1869 |     1869 |     1869 |       1869
 140421237831424_101 |   16771 | exec_context |           1 |        3 |        3 |        3 |          3
 140421237831424_101 |   16771 | execute      |           1 |    24011 |    24011 |    24011 |      24011
 140421237831424_101 |   16771 | exec_cursor  |           1 |        1 |        1 |        1 |          1
 140421237831424_101 |   16771 | cleanup      |           1 |       16 |       16 |       16 |         16
 140421237831424_101 |   16771 | finsh        |           1 |        1 |        1 |        1 |          1
(18 rows)

gaussdb=# SELECT dbe_profiler.pl_clear_profiling('');
gaussdb=# SELECT * FROM dbe_profiler.pl_profiling_functions;
 run_id | funcoid | schema | funcname | total_occur | total_time 
--------+---------+--------+----------+-------------+------------
(0 rows)

gaussdb=# DROP TABLE t2;