DBE_PROFILER
The plprofiler provides an API for analyzing applications of stored procedures. It can collect, store, and delete data related to stored procedures.
Overview
Finding performance problems in PL/SQL functions and stored procedures may be difficult. The only query visible in the system or extended view is sent from the client. This is just the outermost stored procedure call. The plprofiler extension can be used to quickly identify the most time-consuming stored procedures and view the time consumption of a single statement.
You can use this tool to create a stored procedure and related table information in a session, call the plprofiler API to profiling the stored procedure, and then execute the stored procedure. In this case, the analysis data of the stored procedure is generated. You can query the system catalog to obtain data. Table 5 DBE_PROFILER.PL_PROFILING_FUNCTIONS lists the stored procedures involved in the profiling. Table 6 DBE_PROFILER.PL_PROFILING_DETAILS records details about the execution time of each statement in a stored procedure. Table 7 DBE_PROFILER.PL_PROFILING_CALLGRAPH records call stack information and the overall execution time of each stored procedure. Table 8 DBE_PROFILER.PL_PROFILING_TRACKINFO records the execution time of each phase of the stored procedure. You can call DBE_PROFILER.PL_CLEAR_PROFILING to delete one piece of data or all data stored in the system catalog after profiling.
After pl_start_profiling is executed, the dbe_profiler tool initializes the memory to prepare for data recording, stubs the stored procedures that are executed subsequently, records detailed information at key points, and records the information in the memory. Data in the memory is written to the four system catalogs only after the transaction is committed. When using the dbe_profiler tool in a transaction, note that data in the memory is not written to the system catalog because the transaction is not committed during transaction execution. Data is written to the system catalog only after the commit operation is executed. Similarly, after the rollback operation is executed, all data is deleted.
Permissions
Common users can access the DBE_PROFILER.PL_PROFILING_FUNCTIONS, DBE_PROFILER.PL_PROFILING_DETAILS, DBE_PROFILER.PL_PROFILING_CALLGRAPH and DBE_PROFILER.PL_PROFILING_TRACKINFO catalogs and have only the permission to query records.
APIs and System Catalogs
Table 1 DBE_PROFILER lists all APIs supported by the DBE_PROFILER advanced package.
API |
Description |
---|---|
DBE_PROFILER.PL_START_PLPROFILING |
Allows users to perform profiling on target stored procedures. |
DBE_PROFILER.PL_CLEAR_PROFILING |
Deletes one piece of data or all data stored in system catalogs after profiling. |
- DBE_PROFILER.PL_START_PLPROFILING
Allows users to perform profiling on target stored procedures. The function prototype of the DBE_PROFILER.PL_START_PLPROFILING function is as follows:
1
DBE_PROFILER.PL_START_PLPROFILING (run_id varchar2(64)) return void;
Table 2 DBE_PROFILER.PL_START_PLPROFILING parameters Parameter
Description
run_id
Execution ID of profiling. The system combines the session ID and execution ID into a character string in the format of sessionid_runid and writes the character string to the table as the unique ID of profiling.
- DBE_PROFILER.PL_CLEAR_PROFILING
Deletes one piece of data or all data stored in system catalogs after profiling. The function prototype of the DBE_PROFILER.PL_CLEAR_PROFILING function is as follows:
1
DBE_PROFILER.PL_CLEAR_PROFILING (run_id varchar2) return void;
Table 3 DBE_PROFILER.PL_CLEAR_PROFILING parameters Parameter
Description
run_id
If this parameter is not left empty, the unique ID of a profiling data record is deleted. If this parameter is left empty, all profiling data records are deleted.
The analysis data generated by the stored procedure is stored in the database system catalog. The catalog information is as follows:
Name |
---|
- Information about the DBE_PROFILER.PL_PROFILING_FUNCTIONS catalog is as follows:
Table 5 DBE_PROFILER.PL_PROFILING_FUNCTIONS Column
Type
Description
run_id
VARCHAR2(80) NOT NULL
Unique ID consisting of session ID and execution ID.
funcoid
BIGINT NOT NULL
Stored procedure ID.
schema
TEXT NOT NULL
Schema name.
funcname
TEXT NOT NULL
Stored procedure name.
total_occur
BIGINT
Total number of stored procedure execution times.
total_time
BIGINT
Total execution time of a stored procedure.
- Information about the DBE_PROFILER.PL_PROFILING_DETAILS catalog is as follows:
Table 6 DBE_PROFILER.PL_PROFILING_DETAILS Column
Type
Description
run_id
VARCHAR2(80) NOT NULL
Unique ID consisting of session ID and execution ID.
funcoid
BIGINT NOT NULL
Stored procedure ID.
line#
INTEGER NOT NULL
Line number.
source
TEXT
Stored procedure execution statement.
cmd_type
TEXT
Statement type.
total_occur
BIGINT
Number of statement execution times.
total_time
BIGINT
Total execution time of a statement.
min_time
BIGINT
Minimum execution time of a statement.
max_time
BIGINT
Maximum execution time of a statement.
- Information about the DBE_PROFILER.PL_PROFILING_CALLGRAPH catalog is as follows:
- Information about the DBE_PROFILER.PL_PROFILING_TRACKINFO catalog is as follows:
Table 8 DBE_PROFILER.PL_PROFILING_TRACKINFO Column
Type
Description
run_id
VARCHAR2(80) NOT NULL
Unique ID consisting of session ID and execution ID.
funcoid
BIGINT NOT NULL
Stored procedure ID.
step_name
TEXT NOT NULL
Execution phase name.
loops_count
INTEGER
Total number of execution times of the execution phase.
max_time
BIGINT
Maximum execution time of the execution phase.
min_time
BIGINT
Minimum execution time of the execution phase.
avg_time
BIGINT
Average execution time of the execution phase.
total_time
BIGINT
Total execution time of the execution phase.
Constraints
- The dbe_profiler.pl_start_profiling cannot be used in a stored procedure. Calling it in a stored procedure does not take effect.
- The dbe_profiler.pl_start_profiling does not support the function of recording transaction failure statistics to the system catalog.
- The length of the input parameter runid of dbe_profiler.pl_start_profiling is limited to 64 characters. If the length exceeds 64 characters, an error is reported.
- If the input parameter of dbe_profiler.pl_start_profiling is the same as the value of runid in the profiler system catalog, an error is reported.
- The plprofiler does not support anonymous block statements, PACKAGE initialization statements, and statements in nested subprograms.
- Committing and rolling back an autonomous transaction does not affect the data that has been committed by the primary transaction. Therefore, the plprofiler cannot record information about stored procedures that contain autonomous transactions.
Examples
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99 100 101 102 103 104 105 106 107 108 109 110 111 112 113 114 115 116 117 118 119 120 121 122 123 124 125 126 127 128 129 130 131 132 133 134 135 136 137 138 139 140 141 142 143 144 145 146 147 148 149 150 151 152 153 154 155 156 157 158 159 160 161 162 163 164 165 166 167 168 169 170 171 172 173 174 175 176 177 178 179 180 181 182 183 184 185 186 187 188 189 190 191 192 193 |
-- Step 1 Create tables and stored procedures. 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; / -- Step 2 Call the plprofiler API to profile the stored procedures. gaussdb=# SELECT dbe_profiler.pl_start_profiling('123'); gaussdb=# CALL p3(); -- Step 3 Query profiling information. -- Query the dbe_profiler.pl_profiling_functions catalog to check the stored procedures involved in 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) -- Query the dbe_profiler.pl_profiling_details catalog to check the execution time details of each statement in a stored procedure. 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) -- Query the dbe_profiler.pl_profiling_callgraph catalog to check the call stack information and the overall execution time of each stored procedure (total_time and self_time correspond to the total execution time of the stored procedure at the top of the call stack and the execution time of the stored procedure). 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) -- Query the dbe_profiler.pl_profiling_trackinfo catalog to check the execution time of each phase of the stored procedure. 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) -- Step 4 Delete data from the system catalog. 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; -- Step 5 Profile the stored procedure that contains an autonomous transaction. -- Create a table. gaussdb=# CREATE TABLE t2(a int, b int); -- Create a stored procedure that contains an autonomous transaction. 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; / -- Create a common stored procedure that calls an autonomous transaction stored procedure. 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); -- Query table information. 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; |
Feedback
Was this page helpful?
Provide feedbackThank you very much for your feedback. We will continue working to improve the documentation.See the reply and handling status in My Cloud VOC.
For any further questions, feel free to contact us through the chatbot.
Chatbot