DBMS_PROFILER v16

The DBMS_PROFILER package collects and stores performance information about the PL/pgSQL and SPL statements that are executed during a performance profiling session. Use these functions and procedures to control the profiling tool.

Function/procedureReturn typeDescription
FLUSH_DATAStatus Code or ExceptionFlushes performance data collected in the current session without terminating the session. Profiling continues.
GET_VERSION(major OUT, minor OUT)n/aReturns the version number of this package.
INTERNAL_VERSION_CHECKStatus CodeConfirms that the current version of the profiler works with the current database.
PAUSE_PROFILERStatus Code or ExceptionPauses data collection.
RESUME_PROFILERStatus Code or ExceptionResumes data collection.
START_PROFILER(run_comment, run_comment1 [, run_number OUT ])Status Code or ExceptionStarts data collection.
STOP_PROFILERStatus Code or ExceptionStops data collection and flushes performance data to the PLSQL_PROFILER_RAWDATA table.

The functions in the DBMS_PROFILER package return a status code to indicate success or failure. The DBMS_PROFILER procedures raise an exception only if they encounter a failure. The table shows the status codes and messages returned by the functions and the exceptions raised by the procedures.

Status codeMessageExceptionDescription
-1error versionversion_mismatchThe profiler version and the database are incompatible.
0successn/aThe operation completed successfully.
1error_paramprofiler_errorThe operation received an incorrect parameter.
2error_ioprofiler_errorThe data flush operation failed.

FLUSH_DATA

The FLUSH_DATA function/procedure flushes the data collected in the current session without terminating the profiler session. The data is flushed to the tables described in the EDB Postgres Advanced Server Performance Features Guide. The function and procedure signatures are:

<status> INTEGER FLUSH_DATA

FLUSH_DATA

Parameters

status

Status code returned by the operation.

GET_VERSION

The GET_VERSION procedure returns the version of DBMS_PROFILER. The procedure signature is:

GET_VERSION(<major> OUT INTEGER, <minor> OUT INTEGER)

Parameters

major

The major version number of DBMS_PROFILER.

minor

The minor version number of DBMS_PROFILER.

INTERNAL_VERSION_CHECK

The INTERNAL_VERSION_CHECK function confirms that the current version of DBMS_PROFILER works with the current database. The function signature is:

<status> INTEGER INTERNAL_VERSION_CHECK

Parameters

status

Status code returned by the operation.

PAUSE_PROFILER

The PAUSE_PROFILER function/procedure pauses a profiling session. The function and procedure signatures are:

<status> INTEGER PAUSE_PROFILER

PAUSE_PROFILER

Parameters

status

Status code returned by the operation.

RESUME_PROFILER

The RESUME_PROFILER function/procedure pauses a profiling session. The function and procedure signatures are:

<status> INTEGER RESUME_PROFILER

RESUME_PROFILER

Parameters

status

Status code returned by the operation.

START_PROFILER

The START_PROFILER function/procedure starts a data collection session. The function and procedure signatures are:

<status> INTEGER START_PROFILER(<run_comment> TEXT := SYSDATE,
   <run_comment1> TEXT := '' [, <run_number> OUT INTEGER ])

START_PROFILER(<run_comment> TEXT := SYSDATE,
  <run_comment1> TEXT := '' [, <run_number> OUT INTEGER ])

Parameters

run_comment

A user-defined comment for the profiler session. The default value is SYSDATE.

run_comment1

An additional user-defined comment for the profiler session. The default value is ''.

run_number

The session number of the profiler session.

status

Status code returned by the operation.

STOP_PROFILER

The STOP_PROFILER function/procedure stops a profiling session and flushes the performance information to the DBMS_PROFILER tables and view. The function and procedure signatures are:

<status> INTEGER STOP_PROFILER

STOP_PROFILER

Parameters

status

Status code returned by the operation.

Using DBMS_PROFILER

The DBMS_PROFILER package collects and stores performance information about the PL/pgSQL and SPL statements that are executed during a profiling session. You can review the performance information in the tables and views provided by the profiler.

DBMS_PROFILER works by recording a set of performance-related counters and timers for each line of PL/pgSQL or SPL statement that executes in a profiling session. The counters and timers are stored in a table named SYS.PLSQL_PROFILER_DATA. When you complete a profiling session, DBMS_PROFILER writes a row to the performance statistics table for each line of PL/pgSQL or SPL code that executed in the session. For example, suppose you execute the following function:

1 - CREATE OR REPLACE FUNCTION getBalance(acctNumber INTEGER)
2 - RETURNS NUMERIC AS $$
3 - DECLARE
4 -   result NUMERIC;
5 - BEGIN
6 -   SELECT INTO result balance FROM acct WHERE id = acctNumber;
7 -
8 -   IF (result IS NULL) THEN
9 -       RAISE INFO 'Balance is null';
10-   END IF;
11-
12-   RETURN result;
13- END;
14- $$ LANGUAGE 'plpgsql';

DBMS_PROFILER adds one PLSQL_PROFILER_DATA entry for each line of code in the getBalance() function, including blank lines and comments. The entry corresponding to the SELECT statement executed exactly one time and required a very small amount of time to execute. On the other hand, the entry corresponding to the RAISE INFO statement executed once or not at all, depending on the value for the balance column.

Some of the lines in this function contain no executable code so the performance statistics for those lines always contains zero values.

To start a profiling session, invoke the DBMS_PROFILER.START_PROFILER function or procedure. Once you've invoked START_PROFILER, EDB Postgres Advanced Server profiles every PL/pgSQL or SPL function, procedure, trigger, or anonymous block that your session executes until you either stop or pause the profiler by calling STOP_PROFILER or PAUSE_PROFILER.

Note

When you start or resume the profiler, the profiler gathers performance statistics only for functions/procedures/triggers that start after the call to START_PROFILER (or RESUME_PROFILER).

While the profiler is active, EDB Postgres Advanced Server records a large set of timers and counters in memory. When you invoke the STOP_PROFILER or FLUSH_DATA function/procedure, DBMS_PROFILER writes those timers and counters to a set of three tables:

  • SYS.PLSQL_PROFILER_RAWDATA

    Contains the performance counters and timers for each statement executed in the session.

  • SYS.PLSQL_PROFILER_RUNS

    Contains a summary of each run, aggregating the information found in PLSQL_PROFILER_RAWDATA.

  • SYS.PLSQL_PROFILER_UNITS

    Contains a summary of each code unit (function, procedure, trigger, or anonymous block) executed in a session.

In addition, DBMS_PROFILER defines a view, SYS.PLSQL_PROFILER_DATA, which contains a subset of the PLSQL_PROFILER_RAWDATA table.

A user who is not a superuser can gather profiling information but can't view that profiling information unless a superuser grants specific privileges on the profiling tables stored in the SYS schema. This permits a nonprivileged user to gather performance statistics without exposing information that the administrator might want to keep secret.

Querying the DBMS_PROFILER tables and view

The following example uses DBMS_PROFILER to retrieve performance information for procedures, functions, and triggers included in the sample data distributed with EDB Postgres Advanced Server.

  1. Open the EDB-PSQL command line, and establish a connection to the EDB Postgres Advanced Server database. Use an EXEC statement to start the profiling session:
acctg=# EXEC dbms_profiler.start_profiler('profile list_emp');

EDB-SPL Procedure successfully completed
Note

The call to start_profiler() includes a comment that DBMS_PROFILER associates with the profiler session.

  1. Call the list_emp function:
acctg=# SELECT list_emp();
Output
INFO:  EMPNO    ENAME
INFO:  -----    -------
INFO:  7369     SMITH
INFO:  7499     ALLEN
INFO:  7521     WARD
INFO:  7566     JONES
INFO:  7654     MARTIN
INFO:  7698     BLAKE
INFO:  7782     CLARK
INFO:  7788     SCOTT
INFO:  7839     KING
INFO:  7844     TURNER
INFO:  7876     ADAMS
INFO:  7900     JAMES
INFO:  7902     FORD
INFO:  7934     MILLER
 list_emp
----------

(1 row)
  1. Stop the profiling session with a call to dbms_profiler.stop_profiler:
acctg=# EXEC dbms_profiler.stop_profiler;

EDB-SPL Procedure successfully completed
  1. Start a new session with the dbms_profiler.start_profiler function followed by a new comment:
acctg=# EXEC dbms_profiler.start_profiler('profile get_dept_name and
emp_sal_trig');

EDB-SPL Procedure successfully completed
  1. Invoke the get_dept_name function:
acctg=# SELECT get_dept_name(10);
Output
 get_dept_name
---------------
 ACCOUNTING
(1 row)
  1. Execute an UPDATE statement that causes a trigger to execute:
acctg=# UPDATE memp SET sal = 500 WHERE empno = 7902;
INFO: Updating employee 7902
INFO: ..Old salary: 3000.00
INFO: ..New salary: 500.00
INFO: ..Raise: -2500.00
INFO: User enterprisedb updated employee(s) on 04-FEB-14
UPDATE 1
  1. End the profiling session and flush the performance information to the profiling tables:
acctg=# EXEC dbms_profiler.stop_profiler;

EDB-SPL Procedure successfully completed
  1. Query the plsql_profiler_runs table to view a list of the profiling sessions, arranged by runid:
acctg=# SELECT * FROM plsql_profiler_runs;
Output
 runid | related_run |  run_owner   |         run_date
 |              run_comment               | run_total_time | run_system_info
 | run_comment1 | spare1
-------+-------------+--------------+---------------------------+-------------
---------------------------+----------------+-----------------+--------------
+--------
      1 |             | enterprisedb | 04-FEB-14 09:32:48.874315 | profile
      list_emp                       |           4154 |
      |              |
      2 |             | enterprisedb | 04-FEB-14 09:41:30.546503 | profile
      get_dept_name and emp_sal_trig |           2088 |
      |              |
(2 rows)
  1. Query the plsql_profiler_units table to view the amount of time consumed by each unit (function, procedure, or trigger):
acctg=# SELECT * FROM plsql_profiler_units;
Output
 runid | unit_number | unit_type |  unit_owner  |
 unit_name            | unit_timestamp | total_time | spare1 | spare2
-------+-------------+-----------+--------------+----------------------------
-----+----------------+------------+--------+--------
     1 |       16999 | FUNCTION  | enterprisedb |
     list_emp()                      |                |          4 |        |
     2 |       17002 | FUNCTION  | enterprisedb |
     user_audit_trig()               |                |          1 |        |
     2 |       17000 | FUNCTION  | enterprisedb | get_dept_name(p_deptno
     numeric) |                |          1 |        |
     2 |       17004 | FUNCTION  | enterprisedb |
     emp_sal_trig()                  |                |          1 |        |
(4 rows)
  1. Query the plsql_profiler_rawdata table to view a list of the wait-event counters and wait-event times:
acctg=# SELECT runid, sourcecode, func_oid, line_number, exec_count,
tuples_returned, time_total FROM plsql_profiler_rawdata;
Output
 runid |                            sourcecode                           |
 func_oid | line_number | exec_count | tuples_returned | time_total
-------+-----------------------------------------------------------------+---
-------+-------------+------------+-----------------+------------
    1 | DECLARE
    |    16999 |           1 |          0 |               0 |          0
    1 |     v_empno         NUMERIC(4);
    |    16999 |           2 |          0 |               0 |          0
    1 |     v_ename         VARCHAR(10);
    |    16999 |           3 |          0 |               0 |          0
    1 |     emp_cur CURSOR FOR
    |    16999 |           4 |          0 |               0 |          0
    1 |         SELECT empno, ename FROM memp ORDER BY empno;
    |    16999 |           5 |          0 |               0 |          0
    1 | BEGIN
    |    16999 |           6 |          0 |               0 |          0
    1 |     OPEN emp_cur;
    |    16999 |           7 |          0 |               0 |          0
    1 |     RAISE INFO 'EMPNO    ENAME';
    |    16999 |           8 |          1 |               0 |   0.001621
    1 |     RAISE INFO '-----    -------';
    |    16999 |           9 |          1 |               0 |   0.000301
    1 |     LOOP
    |    16999 |          10 |          1 |               0 |    4.6e-05
    1 |         FETCH emp_cur INTO v_empno, v_ename;
    |    16999 |          11 |          1 |               0 |   0.001114
    1 |         EXIT WHEN NOT FOUND;
    |    16999 |          12 |         15 |               0 |   0.000206
    1 |         RAISE INFO '%     %', v_empno, v_ename;
    |    16999 |          13 |         15 |               0 |    8.3e-05
    1 |     END LOOP;
    |    16999 |          14 |         14 |               0 |   0.000773
    1 |     CLOSE emp_cur;
    |    16999 |          15 |          0 |               0 |          0
    1 |     RETURN;
    |    16999 |          16 |          1 |               0 |      1e-05
    1 | END;
    |    16999 |          17 |          1 |               0 |          0
    1 |
    |    16999 |          18 |          0 |               0 |          0
    2 | DECLARE
    |    17002 |           1 |          0 |               0 |          0
    2 |     v_action        VARCHAR(24);
    |    17002 |           2 |          0 |               0 |          0
    2 |     v_text          TEXT;
    |    17002 |           3 |          0 |               0 |          0
    2 | BEGIN
    |    17002 |           4 |          0 |               0 |          0
    2 |     IF TG_OP = 'INSERT' THEN
    |    17002 |           5 |          0 |               0 |          0
    2 |         v_action := ' added employee(s) on ';
    |    17002 |           6 |          1 |               0 |   0.000143
    2 |     ELSIF TG_OP = 'UPDATE' THEN
    |    17002 |           7 |          0 |               0 |          0
    2 |         v_action := ' updated employee(s) on ';
    |    17002 |           8 |          0 |               0 |          0
    2 |     ELSIF TG_OP = 'DELETE' THEN
    |    17002 |           9 |          1 |               0 |    3.2e-05
    2 |         v_action := ' deleted employee(s) on ';
    |    17002 |          10 |          0 |               0 |          0
    2 |     END IF;
    |    17002 |          11 |          0 |               0 |          0
    2 |     v_text := 'User ' || USER || v_action || CURRENT_DATE;
    |    17002 |          12 |          0 |               0 |          0
    2 |     RAISE INFO ' %', v_text;
    |    17002 |          13 |          1 |               0 |   0.000383
    2 |     RETURN NULL;
    |    17002 |          14 |          1 |               0 |    6.3e-05
    2 | END;
    |    17002 |          15 |          1 |               0 |    3.6e-05
    2 |
    |    17002 |          16 |          0 |               0 |          0
    2 | DECLARE
    |    17000 |           1 |          0 |               0 |          0
    2 |     v_dname         VARCHAR(14);
    |    17000 |           2 |          0 |               0 |          0
    2 | BEGIN
    |    17000 |           3 |          0 |               0 |          0
    2 |     SELECT INTO v_dname dname FROM dept WHERE deptno = p_deptno;
    |    17000 |           4 |          0 |               0 |          0
    2 |     RETURN v_dname;
    |    17000 |           5 |          1 |               0 |   0.000647
    2 |     IF NOT FOUND THEN
    |    17000 |           6 |          1 |               0 |    2.6e-05
    2 |         RAISE INFO 'Invalid department number %', p_deptno;
    |    17000 |           7 |          0 |               0 |          0
    2 |         RETURN '';
    |    17000 |           8 |          0 |               0 |          0
    2 |     END IF;
    |    17000 |           9 |          0 |               0 |          0
    2 | END;
    |    17000 |          10 |          0 |               0 |          0
    2 |
    |    17000 |          11 |          0 |               0 |          0
    2 | DECLARE
    |    17004 |           1 |          0 |               0 |          0
    2 |     sal_diff       NUMERIC(7,2);
    |    17004 |           2 |          0 |               0 |          0
    2 | BEGIN
    |    17004 |           3 |          0 |               0 |          0
    2 |     IF TG_OP = 'INSERT' THEN
    |    17004 |           4 |          0 |               0 |          0
    2 |         RAISE INFO 'Inserting employee %', NEW.empno;
    |    17004 |           5 |          1 |               0 |    8.4e-05
    2 |         RAISE INFO '..New salary: %', NEW.sal;
    |    17004 |           6 |          0 |               0 |          0
    2 |         RETURN NEW;
    |    17004 |           7 |          0 |               0 |          0
    2 |     END IF;
    |    17004 |           8 |          0 |               0 |          0
    2 |     IF TG_OP = 'UPDATE' THEN
    |    17004 |           9 |          0 |               0 |          0
    2 |         sal_diff := NEW.sal - OLD.sal;
    |    17004 |          10 |          1 |               0 |   0.000355
    2 |         RAISE INFO 'Updating employee %', OLD.empno;
    |    17004 |          11 |          1 |               0 |   0.000177
    2 |         RAISE INFO '..Old salary: %', OLD.sal;
    |    17004 |          12 |          1 |               0 |    5.5e-05
    2 |         RAISE INFO '..New salary: %', NEW.sal;
    |    17004 |          13 |          1 |               0 |    3.1e-05
    2 |         RAISE INFO '..Raise     : %', sal_diff;
    |    17004 |          14 |          1 |               0 |    2.8e-05
    2 |         RETURN NEW;
    |    17004 |          15 |          1 |               0 |    2.7e-05
    2 |     END IF;
    |    17004 |          16 |          1 |               0 |      1e-06
    2 |     IF TG_OP = 'DELETE' THEN
    |    17004 |          17 |          0 |               0 |          0
    2 |         RAISE INFO 'Deleting employee %', OLD.empno;
    |    17004 |          18 |          0 |               0 |          0
    2 |         RAISE INFO '..Old salary: %', OLD.sal;
    |    17004 |          19 |          0 |               0 |          0
    2 |         RETURN OLD;
    |    17004 |          20 |          0 |               0 |          0
    2 |     END IF;
    |    17004 |          21 |          0 |               0 |          0
    2 | END;
    |    17004 |          22 |          0 |               0 |          0
    2 |
    |    17004 |          23 |          0 |               0 |          0
 (68 rows)
                                                                                                                   
  1. Query the plsql_profiler_data view to review a subset of the information found in plsql_profiler_rawdata table:
acctg=# SELECT * FROM plsql_profiler_data;
Output
runid | unit_number | line# | total_occur | total_time | min_time | max_time
| spare1 | spare2 | spare3 | spare4
-------+-------------+-------+-------------+------------+----------+---------
-+--------+--------+--------+--------
     1 |       16999 |     1 |           0 |          0 |        0 |
     0 |        |        |        |
     1 |       16999 |     2 |           0 |          0 |        0 |
     0 |        |        |        |
     1 |       16999 |     3 |           0 |          0 |        0 |
     0 |        |        |        |
     1 |       16999 |     4 |           0 |          0 |        0 |
     0 |        |        |        |
     1 |       16999 |     5 |           0 |          0 |        0 |
     0 |        |        |        |
     1 |       16999 |     6 |           0 |          0 |        0 |
     0 |        |        |        |
     1 |       16999 |     7 |           0 |          0 |        0 |
     0 |        |        |        |
     1 |       16999 |     8 |           1 |   0.001621 | 0.001621 |
     0.001621 |        |        |        |
     1 |       16999 |     9 |           1 |   0.000301 | 0.000301 |
     0.000301 |        |        |        |
     1 |       16999 |    10 |           1 |    4.6e-05 |  4.6e-05 |  4.6e-
     05 |        |        |        |
     1 |       16999 |    11 |           1 |   0.001114 | 0.001114 |
     0.001114 |        |        |        |
     1 |       16999 |    12 |          15 |   0.000206 |    5e-06 |  7.8e-
     05 |        |        |        |
     1 |       16999 |    13 |          15 |    8.3e-05 |    2e-06 |  4.7e-
     05 |        |        |        |
     1 |       16999 |    14 |          14 |   0.000773 |  4.7e-05 |
     0.000116 |        |        |        |
     1 |       16999 |    15 |           0 |          0 |        0 |
     0 |        |        |        |
     1 |       16999 |    16 |           1 |      1e-05 |    1e-05 |    1e-
     05 |        |        |        |
     1 |       16999 |    17 |           1 |          0 |        0 |
     0 |        |        |        |
     1 |       16999 |    18 |           0 |          0 |        0 |
     0 |        |        |        |
     2 |       17002 |     1 |           0 |          0 |        0 |
     0 |        |        |        |
     2 |       17002 |     2 |           0 |          0 |        0 |
     0 |        |        |        |
     2 |       17002 |     3 |           0 |          0 |        0 |
     0 |        |        |        |
     2 |       17002 |     4 |           0 |          0 |        0 |
     0 |        |        |        |
     2 |       17002 |     5 |           0 |          0 |        0 |
     0 |        |        |        |
     2 |       17002 |     6 |           1 |   0.000143 | 0.000143 |
     0.000143 |        |        |        |
     2 |       17002 |     7 |           0 |          0 |        0 |
     0 |        |        |        |
     2 |       17002 |     8 |           0 |          0 |        0 |
     0 |        |        |        |
     2 |       17002 |     9 |           1 |    3.2e-05 |  3.2e-05 |  3.2e-
     05 |        |        |        |
     2 |       17002 |    10 |           0 |          0 |        0 |
     0 |        |        |        |
     2 |       17002 |    11 |           0 |          0 |        0 |
     0 |        |        |        |
     2 |       17002 |    12 |           0 |          0 |        0 |
     0 |        |        |        |
     2 |       17002 |    13 |           1 |   0.000383 | 0.000383 |
     0.000383 |        |        |        |
     2 |       17002 |    14 |           1 |    6.3e-05 |  6.3e-05 |  6.3e-
     05 |        |        |        |
     2 |       17002 |    15 |           1 |    3.6e-05 |  3.6e-05 |  3.6e-
     05 |        |        |        |
     2 |       17002 |    16 |           0 |          0 |        0 |
     0 |        |        |        |
     2 |       17000 |     1 |           0 |          0 |        0 |
     0 |        |        |        |
     2 |       17000 |     2 |           0 |          0 |        0 |
     0 |        |        |        |
     2 |       17000 |     3 |           0 |          0 |        0 |
     0 |        |        |        |
     2 |       17000 |     4 |           0 |          0 |        0 |
     0 |        |        |        |
     2 |       17000 |     5 |           1 |   0.000647 | 0.000647 |
     0.000647 |        |        |        |
     2 |       17000 |     6 |           1 |    2.6e-05 |  2.6e-05 |  2.6e-
     05 |        |        |        |
     2 |       17000 |     7 |           0 |          0 |        0 |
     0 |        |        |        |
     2 |       17000 |     8 |           0 |          0 |        0 |
     0 |        |        |        |
     2 |       17000 |     9 |           0 |          0 |        0 |
     0 |        |        |        |
     2 |       17000 |    10 |           0 |          0 |        0 |
     0 |        |        |        |
     2 |       17000 |    11 |           0 |          0 |        0 |
     0 |        |        |        |
     2 |       17004 |     1 |           0 |          0 |        0 |
     0 |        |        |        |
     2 |       17004 |     2 |           0 |          0 |        0 |
     0 |        |        |        |
     2 |       17004 |     3 |           0 |          0 |        0 |
     0 |        |        |        |
     2 |       17004 |     4 |           0 |          0 |        0 |
     0 |        |        |        |
     2 |       17004 |     5 |           1 |    8.4e-05 |  8.4e-05 |  8.4e-
     05 |        |        |        |
     2 |       17004 |     6 |           0 |          0 |        0 |
     0 |        |        |        |
     2 |       17004 |     7 |           0 |          0 |        0 |
     0 |        |        |        |
     2 |       17004 |     8 |           0 |          0 |        0 |
     0 |        |        |        |
     2 |       17004 |     9 |           0 |          0 |        0 |
     0 |        |        |        |
     2 |       17004 |    10 |           1 |   0.000355 | 0.000355 |
     0.000355 |        |        |        |
     2 |       17004 |    11 |           1 |   0.000177 | 0.000177 |
     0.000177 |        |        |        |
     2 |       17004 |    12 |           1 |    5.5e-05 |  5.5e-05 |  5.5e-
     05 |        |        |        |
     2 |       17004 |    13 |           1 |    3.1e-05 |  3.1e-05 |  3.1e-
     05 |        |        |        |
     2 |       17004 |    14 |           1 |    2.8e-05 |  2.8e-05 |  2.8e-
     05 |        |        |        |
     2 |       17004 |    15 |           1 |    2.7e-05 |  2.7e-05 |  2.7e-
     05 |        |        |        |
     2 |       17004 |    16 |           1 |      1e-06 |    1e-06 |    1e-
     06 |        |        |        |
     2 |       17004 |    17 |           0 |          0 |        0 |
     0 |        |        |        |
     2 |       17004 |    18 |           0 |          0 |        0 |
     0 |        |        |        |
     2 |       17004 |    19 |           0 |          0 |        0 |
     0 |        |        |        |
     2 |       17004 |    20 |           0 |          0 |        0 |
     0 |        |        |        |
     2 |       17004 |    21 |           0 |          0 |        0 |
     0 |        |        |        |
     2 |       17004 |    22 |           0 |          0 |        0 |
     0 |        |        |        |
     2 |       17004 |    23 |           0 |          0 |        0 |
     0 |        |        |        |
(68 rows)

DBMS_PROFILER reference

The EDB Postgres Advanced Server installer creates the following tables and views that you can query to review PL/SQL performance profile information:

Table nameDescription
PLSQL_PROFILER_RUNSTable containing information about all profiler runs, organized by runid.
PLSQL_PROFILER_UNITSTable containing information about all profiler runs, organized by unit.
PLSQL_PROFILER_DATAView containing performance statistics.
PLSQL_PROFILER_RAWDATATable containing the performance statistics and the extended performance statistics for DRITA counters and timers.

PLSQL_PROFILER_RUNS

The PLSQL_PROFILER_RUNS table contains the following columns:

ColumnData typeDescription
runidINTEGER (NOT NULL)Unique identifier (plsql_profiler_runnumber)
related_runINTEGERThe runid of a related run
run_ownerTEXTThe role that recorded the profiling session
run_dateTIMESTAMP WITHOUT TIME ZONEThe profiling session start time
run_commentTEXTUser comments relevant to this run
run_total_timeBIGINTRun time (in microseconds)
run_system_infoTEXTCurrently unused
run_comment1TEXTAdditional user comments
spare1TEXTCurrently unused

PLSQL_PROFILER_UNITS

The PLSQL_PROFILER_UNITS table contains the following columns:

ColumnData typeDescription
runidINTEGERUnique identifier (plsql_profiler_runnumber)
unit_numberOIDCorresponds to the OID of the row in the pg_proc table that identifies the unit
unit_typeTEXTPL/SQL function, procedure, trigger or anonymous block
unit_ownerTEXTThe identity of the role that owns the unit
unit_nameTEXTThe complete signature of the unit
unit_timestampTIMESTAMP WITHOUT TIME ZONECreation date of the unit (currently NULL)
total_timeBIGINTTime spent within the unit (in milliseconds)
spare1BIGINTCurrently unused
spare2BIGINTCurrently unused

PLSQL_PROFILER_DATA

The PLSQL_PROFILER_DATA view contains the following columns:

ColumnData typeDescription
runidINTEGERUnique identifier (plsql_profiler_runnumber)
unit_numberOIDObject ID of the unit that contains the current line
line#INTEGERCurrent line number of the profiled workload
total_occurBIGINTThe number of times that the line was executed
total_timeDOUBLE PRECISIONThe amount of time spent executing the line (in seconds)
min_timeDOUBLE PRECISIONThe minimum execution time for the line
max_timeDOUBLE PRECISIONThe maximum execution time for the line
spare1NUMBERCurrently unused
spare2NUMBERCurrently unused
spare3NUMBERCurrently unused
spare4NUMBERCurrently unused

PLSQL_PROFILER_RAWDATA

The PLSQL_PROFILER_RAWDATA table contains the statistical and wait-events information found in the PLSQL_PROFILER_DATA view, as well as the performance statistics returned by the DRITA counters and timers.

ColumnData typeDescription
runidINTEGERThe run identifier (plsql_profiler_runnumber).
sourcecodeTEXTThe individual line of profiled code.
func_oidOIDObject ID of the unit that contains the current line.
line_numberINTEGERCurrent line number of the profiled workload.
exec_countBIGINTThe number of times that the line was executed.
tuples_returnedBIGINTCurrently unused.
time_totalDOUBLE PRECISIONThe amount of time spent executing the line, in seconds.
time_shortestDOUBLE PRECISIONThe minimum execution time for the line.
time_longestDOUBLE PRECISIONThe maximum execution time for the line.
num_scansBIGINTCurrently unused.
tuples_fetchedBIGINTCurrently unused.
tuples_insertedBIGINTCurrently unused.
tuples_updatedBIGINTCurrently unused.
tuples_deletedBIGINTCurrently unused.
blocks_fetchedBIGINTCurrently unused.
blocks_hitBIGINTCurrently unused.
wal_writeBIGINTA server has waited for a write to the write-ahead log buffer. Expect this value to be high.
wal_flushBIGINTA server has waited for the write-ahead log to flush to disk.
wal_file_syncBIGINTA server has waited for the write-ahead log to sync to disk (related to the wal_sync_method parameter which, by default, is 'fsync' - better performance can be gained by changing this parameter to open_sync).
db_file_readBIGINTA server has waited for the completion of a read (from disk).
db_file_writeBIGINTA server has waited for the completion of a write (to disk).
db_file_syncBIGINTA server has waited for the operating system to flush all changes to disk.
db_file_extendBIGINTA server has waited for the operating system while adding a new page to the end of a file.
sql_parseBIGINTCurrently unused.
query_planBIGINTA server has generated a query plan.
other_lwlock_acquireBIGINTA server has waited for other light-weight lock to protect data.
shared_plan_cache_collisionBIGINTA server has waited for the completion of the shared_plan_cache_collision event.
shared_plan_cache_insertBIGINTA server has waited for the completion of the shared_plan_cache_insert event.
shared_plan_cache_hitBIGINTA server has waited for the completion of the shared_plan_cache_hit event.
shared_plan_cache_missBIGINTA server has waited for the completion of the shared_plan_cache_miss event.
shared_plan_cache_lockBIGINTA server has waited for the completion of the shared_plan_cache_lock event.
shared_plan_cache_busyBIGINTA server has waited for the completion of the shared_plan_cache_busy event.
shmemindexlockBIGINTA server has waited to find or allocate space in the shared memory.
oidgenlockBIGINTA server has waited to allocate or assign an OID.
xidgenlockBIGINTA server has waited to allocate or assign a transaction ID.
procarraylockBIGINTA server has waited to get a snapshot or clearing a transaction ID at transaction end.
sinvalreadlockBIGINTA server has waited to retrieve or remove messages from shared invalidation queue.
sinvalwritelockBIGINTA server has waited to add a message to the shared invalidation queue.
walbufmappinglockBIGINTA server has waited to replace a page in WAL buffers.
walwritelockBIGINTA server has waited for WAL buffers to be written to disk.
controlfilelockBIGINTA server has waited to read or update the control file or creation of a new WAL file.
checkpointlockBIGINTA server has waited to perform a checkpoint.
clogcontrollockBIGINTA server has waited to read or update the transaction status.
subtranscontrollockBIGINTA server has waited to read or update the sub-transaction information.
multixactgenlockBIGINTA server has waited to read or update the shared multixact state.
multixactoffsetcontrollockBIGINTA server has waited to read or update multixact offset mappings.
multixactmembercontrollockBIGINTA server has waited to read or update multixact member mappings.
relcacheinitlockBIGINTA server has waited to read or write the relation cache initialization file.
checkpointercommlockBIGINTA server has waited to manage the fsync requests.
twophasestatelockBIGINTA server has waited to read or update the state of prepared transactions.
tablespacecreatelockBIGINTA server has waited to create or drop the tablespace.
btreevacuumlockBIGINTA server has waited to read or update the vacuum related information for a B-tree index.
addinshmeminitlockBIGINTA server has waited to manage space allocation in shared memory.
autovacuumlockBIGINTThe autovacuum launcher waiting to read or update the current state of autovacuum workers.
autovacuumschedulelockBIGINTA server has waited to ensure that the table selected for a vacuum still needs vacuuming.
syncscanlockBIGINTA server has waited to get the start location of a scan on a table for synchronized scans.
relationmappinglockBIGINTA server has waited to update the relation map file used to store catalog to file node mapping.
asyncctllockBIGINTA server has waited to read or update shared notification state.
asyncqueuelockBIGINTA server has waited to read or update the notification messages.
serializablexacthashlockBIGINTA server has waited to retrieve or store information about serializable transactions.
serializablefinishedlistlockBIGINTA server has waited to access the list of finished serializable transactions.
serializablepredicatelocklistlockBIGINTA server has waited to perform an operation on a list of locks held by serializable transactions.
oldserxidlockBIGINTA server has waited to read or record the conflicting serializable transactions.
syncreplockBIGINTA server has waited to read or update information about synchronous replicas.
backgroundworkerlockBIGINTA server has waited to read or update the background worker state.
dynamicsharedmemorycontrollockBIGINTA server has waited to read or update the dynamic shared memory state.
autofilelockBIGINTA server has waited to update the postgresql.auto.conf file.
replicationslotallocationlockBIGINTA server has waited to allocate or free a replication slot.
replicationslotcontrollockBIGINTA server has waited to read or update replication slot state.
committscontrollockBIGINTA server has waited to read or update transaction commit timestamps.
committslockBIGINTA server has waited to read or update the last value set for the transaction timestamp.
replicationoriginlockBIGINTA server has waited to set up, drop, or use replication origin.
multixacttruncationlockBIGINTA server has waited to read or truncate multixact information.
oldsnapshottimemaplockBIGINTA server has waited to read or update old snapshot control information.
backendrandomlockBIGINTA server has waited to generate a random number.
logicalrepworkerlockBIGINTA server has waited for the action on logical replication worker to finish.
clogtruncationlockBIGINTA server has waited to truncate the write-ahead log or waiting for write-ahead log truncation to finish.
bulkloadlockBIGINTA server has waited for the bulkloadlock to bulk upload the data.
edbresourcemanagerlockBIGINTThe edbresourcemanagerlock provides detail about edb resource manager lock module.
wal_write_timeBIGINTThe amount of time that the server has waited for a wal_write wait event to write to the write-ahead log buffer (expect this value to be high).
wal_flush_timeBIGINTThe amount of time that the server has waited for a wal_flush wait event to write-ahead log to flush to disk.
wal_file_sync_timeBIGINTThe amount of time that the server has waited for a wal_file_sync wait event to write-ahead log to sync to disk (related to the wal_sync_method parameter which, by default, is 'fsync' - better performance can be gained by changing this parameter to open_sync).
db_file_read_timeBIGINTThe amount of time that the server has waited for the db_file_read wait event for completion of a read (from disk).
db_file_write_timeBIGINTThe amount of time that the server has waited for the db_file_write wait event for completion of a write (to disk).
db_file_sync_timeBIGINTThe amount of time that the server has waited for the db_file_sync wait event to sync all changes to disk.
db_file_extend_timeBIGINTThe amount of time that the server has waited for the db_file_extend wait event while adding a new page to the end of a file.
sql_parse_timeBIGINTThe amount of time that the server has waited for the sql_parse wait event to parse a SQL statement.
query_plan_timeBIGINTThe amount of time that the server has waited for the query_plan wait event to compute the execution plan for a SQL statement.
other_lwlock_acquire_timeBIGINTThe amount of time that the server has waited for the other_lwlock_acquire wait event to protect data.
shared_plan_cache_collision_timeBIGINTThe amount of time that the server has waited for the shared_plan_cache_collision wait event.
shared_plan_cache_insert_timeBIGINTThe amount of time that the server has waited for the shared_plan_cache_insert wait event.
shared_plan_cache_hit_timeBIGINTThe amount of time that the server has waited for the shared_plan_cache_hit wait event.
shared_plan_cache_miss_timeBIGINTThe amount of time that the server has waited for the shared_plan_cache_miss wait event.
shared_plan_cache_lock_timeBIGINTThe amount of time that the server has waited for the shared_plan_cache_lock wait event.
shared_plan_cache_busy_timeBIGINTThe amount of time that the server has waited for the shared_plan_cache_busy wait event.
shmemindexlock_timeBIGINTThe amount of time that the server has waited for the shmemindexlock wait event to find or allocate space in the shared memory.
oidgenlock_timeBIGINTThe amount of time that the server has waited for the oidgenlock wait event to allocate or assign an OID.
xidgenlock_timeBIGINTThe amount of time that the server has waited for xidgenlock wait event to allocate or assign a transaction ID.
procarraylock_timeBIGINTThe amount of time that the server has waited for a procarraylock wait event to clear a transaction ID at transaction end.
sinvalreadlock_timeBIGINTThe amount of time that the server has waited for a sinvalreadlock wait event to retrieve or remove messages from shared invalidation queue.
sinvalwritelock_timeBIGINTThe amount of time that the server has waited for a sinvalwritelock wait event to add a message to the shared invalidation queue.
walbufmappinglock_timeBIGINTThe amount of time that the server has waited for a walbufmappinglock wait event to replace a page in WAL buffers.
walwritelock_timeBIGINTThe amount of time that the server has waited for a walwritelock wait event to write the WAL buffers to disk.
controlfilelock_timeBIGINTThe amount of time that the server has waited for a controlfilelock wait event to read or update the control file or to create a new WAL file.
checkpointlock_timeBIGINTThe amount of time that the server has waited for a checkpointlock wait event to perform a checkpoint.
clogcontrollock_timeBIGINTThe amount of time that the server has waited for a clogcontrollock wait event to read or update the transaction status.
subtranscontrollock_timeBIGINTThe amount of time that the server has waited for the subtranscontrollock wait event to read or update the sub-transaction information.
multixactgenlock_timeBIGINTThe amount of time that the server has waited for the multixactgenlock wait event to read or update the shared multixact state.
multixactoffsetcontrollock_timeBIGINTThe amount of time that the server has waited for the multixactoffsetcontrollock wait event to read or update multixact offset mappings.
multixactmembercontrollock_timeBIGINTThe amount of time that the server has waited for the multixactmembercontrollock wait event to read or update multixact member mappings.
relcacheinitlock_timeBIGINTThe amount of time that the server has waited for the relcacheinitlock wait event to read or write the relation cache initialization file.
checkpointercommlock_timeBIGINTThe amount of time that the server has waited for the checkpointercommlock wait event to manage the fsync requests.
twophasestatelock_timeBIGINTThe amount of time that the server has waited for the twophasestatelock wait event to read or update the state of prepared transactions.
tablespacecreatelock_timeBIGINTThe amount of time that the server has waited for the tablespacecreatelock wait event to create or drop the tablespace.
btreevacuumlock_timeBIGINTThe amount of time that the server has waited for the btreevacuumlock wait event to read or update the vacuum related information for a B-tree index.
addinshmeminitlock_timeBIGINTThe amount of time that the server has waited for the addinshmeminitlock wait event to manage space allocation in shared memory.
autovacuumlock_timeBIGINTThe amount of time that the server has waited for the autovacuumlock wait event to read or update the current state of autovacuum workers.
autovacuumschedulelock_timeBIGINTThe amount of time that the server has waited for the autovacuumschedulelock wait event to ensure that the table selected for a vacuum still needs vacuuming.
syncscanlock_timeBIGINTThe amount of time that the server has waited for the syncscanlock wait event to get the start location of a scan on a table for synchronized scans.
relationmappinglock_timeBIGINTThe amount of time that the server has waited for the relationmappinglock wait event to update the relation map file used to store catalog to file node mapping.
asyncctllock_timeBIGINTThe amount of time that the server has waited for the asyncctllock wait event to read or update shared notification state.
asyncqueuelock_timeBIGINTThe amount of time that the server has waited for the asyncqueuelock wait event to read or update the notification messages.
serializablexacthashlock_timeBIGINTThe amount of time that the server has waited for the serializablexacthashlock wait event to retrieve or store information about serializable transactions.
serializablefinishedlistlock_timeBIGINTThe amount of time that the server has waited for the serializablefinishedlistlock wait event to access the list of finished serializable transactions.
serializablepredicatelocklistlock_timeBIGINTThe amount of time that the server has waited for the serializablepredicatelocklistlock wait event to perform an operation on a list of locks held by serializable transactions.
oldserxidlock_timeBIGINTThe amount of time that the server has waited for the oldserxidlock wait event to read or record the conflicting serializable transactions.
syncreplock_timeBIGINTThe amount of time that the server has waited for the syncreplock wait event to read or update information about synchronous replicas.
backgroundworkerlock_timeBIGINTThe amount of time that the server has waited for the backgroundworkerlock wait event to read or update the background worker state.
dynamicsharedmemorycontrollock_timeBIGINTThe amount of time that the server has waited for the dynamicsharedmemorycontrollock wait event to read or update the dynamic shared memory state.
autofilelock_timeBIGINTThe amount of time that the server has waited for the autofilelock wait event to update the postgresql.auto.conf file.
replicationslotallocationlock_timeBIGINTThe amount of time that the server has waited for the replicationslotallocationlock wait event to allocate or free a replication slot.
replicationslotcontrollock_timeBIGINTThe amount of time that the server has waited for the replicationslotcontrollock wait event to read or update replication slot state.
committscontrollock_timeBIGINTThe amount of time that the server has waited for the committscontrollock wait event to read or update transaction commit timestamps.
committslock_timeBIGINTThe amount of time that the server has waited for the committslock wait event to read or update the last value set for the transaction timestamp.
replicationoriginlock_timeBIGINTThe amount of time that the server has waited for the replicationoriginlock wait event to set up, drop, or use replication origin.
multixacttruncationlock_timeBIGINTThe amount of time that the server has waited for the multixacttruncationlock wait event to read or truncate multixact information.
oldsnapshottimemaplock_timeBIGINTThe amount of time that the server has waited for the oldsnapshottimemaplock wait event to read or update old snapshot control information.
backendrandomlock_timeBIGINTThe amount of time that the server has waited for the backendrandomlock wait event to generate a random number.
logicalrepworkerlock_timeBIGINTThe amount of time that the server has waited for the logicalrepworkerlock wait event for an action on logical replication worker to finish.
clogtruncationlock_timeBIGINTThe amount of time that the server has waited for the clogtruncationlock wait event to truncate the write-ahead log or waiting for write-ahead log truncation to finish.
bulkloadlock_timeBIGINTThe amount of time that the server has waited for the bulkloadlock wait event to bulk upload the data.
edbresourcemanagerlock_timeBIGINTThe amount of time that the server has waited for the edbresourcemanagerlock wait event.
totalwaitsBIGINTThe total number of event waits.
totalwaittimeBIGINTThe total time spent waiting for an event.