/* $Header: profiler.sql 243755.1 2007/01/16 10:55 csierra $ */ SET DOC OFF; /*============================================================================+ | Copyright (c) 2003 Oracle Corporation Redwood Shores, California, USA | | All rights reserved. | +=============================================================================+ | | FILENAME | | profiler.sql - Reporting PL/SQL Profiler data generated by DBMS_PROFILER | | | USAGE | | The PL/SQL Profiler package DBMS_PROFILER generates performance data on any | PL/SQL profiled library. This data includes execution time for every line | of profiled line of code as well as number of times each line was executed | | This profiler.sql script generates an HTML report out of the tables that | were populated by the DBMS_PROFILER package while profiling was active | | Connect into SQL*Plus as the application user which executed the actual | profiler (APPS for Oracle Applications), and execute this script providing | the run_id for the profiled transaction. | | SQL> START profiler.sql ; | | | DESCRIPTION | | The profiler.sql reports the results of the profiler stored into tables: | PLSQL_PROFILER_RUNS, PLSQL_PROFILER_UNITS and PLSQL_PROFILER_DATA. | | This script can be used on databases with RDBMS 8.1.7 or higher and it is | not constrained to Oracle Apps. | | This script profiler.sql requires one parameter: | | 1. p_runid: Corresponding to the runid for the profiled transaction | | | NOTES | | This script is part of a set compressed into file PROF.zip. Latest version | of PROF.zip can be downloaded from Note:243755.1 | | Documentation on using the DBMS_PROFILER can be found at: | | http://download-west.oracle.com/docs/cd/B10501_01/appdev.920/a96612/d_profil.htm#1003424 | | Read Note:243755.1 for further details. | | For feedback, email author carlos.sierra@oracle.com | | HISTORY | | 2003/07/14 CSIERRA Created | 2004/12/15 CSIERRA line# adjustments to compensate for offset reported on | SR 4205230.995 and Bug 4044091 | 2007/01/10 CSIERRA XP (platform 7) has a different time granularity | 2007/01/16 CSIERRA 9i does not have V$DATABASE.PLATFORM_ID | +============================================================================*/ REM Display of all runs for user to pick one to report SELECT runid, TO_CHAR(run_date,'DD-MON-RR HH24:MI:SS') run_date, SUBSTR(run_comment,1,40) run_comment FROM plsql_profiler_runs ORDER BY runid; PRO PRO Usage: PRO sqlplus apps/ PRO SQL> START profiler.sql ; PRO DEF p_top = 10; DEF p_runid = &1; VAR v_runid NUMBER; VAR v_top NUMBER; VAR v_time NUMBER; SET TERM OFF HEA OFF PAGES 50000 LIN 32000 NUM 14 VER OFF FEED OFF TRIMS ON RECSEP OFF SERVEROUT ON SIZE 1000000 ARRAY 100; REM Assign parameters to bind variables DECLARE v_rec v$database%ROWTYPE; BEGIN SELECT * INTO v_rec FROM v$database; IF v_rec.platform_id = 7 THEN :v_time := 1000000000000; END IF; END; / BEGIN :v_top := TO_NUMBER('&&p_top'); :v_runid := TO_NUMBER('&&p_runid'); IF NVL(:v_time, 0) = 0 THEN :v_time := 1000000000; END IF; END; / REM Rollup of total time for library units with zero time (due to known issue) DECLARE CURSOR c1_units_zero_time IS SELECT unit_number FROM plsql_profiler_units WHERE runid = :v_runid AND total_time = 0; BEGIN FOR c1 IN c1_units_zero_time LOOP DBMS_PROFILER.ROLLUP_UNIT(:v_runid,c1.unit_number); END LOOP; END; / REM line# adjustments to compensate for offset reported on SR 4205230.995 and Bug 4044091 DECLARE offset NUMBER; CURSOR c1_triggers IS SELECT unit_owner, unit_name, unit_type, unit_number FROM plsql_profiler_units WHERE runid = :v_runid AND unit_type = 'TRIGGER'; BEGIN FOR c1 IN c1_triggers LOOP SELECT NVL(MIN(line) - 1, -1) INTO offset FROM all_source WHERE owner = c1.unit_owner AND name = c1.unit_name AND type = c1.unit_type AND (UPPER(text) LIKE '%BEGIN%' OR UPPER(text) LIKE '%DECLARE%'); IF offset > 0 THEN UPDATE plsql_profiler_data SET line# = line# + offset WHERE runid = :v_runid AND unit_number = c1.unit_number; END IF; END LOOP; END; / REM Finds the Top "p_top" most expensive lines in terms of total time and flags them on plsql_profiler_data.spare1 REM For each library unit which has one of the "p_top" lines, it records the min_line and max_line on plsql_profiler_units DECLARE l_rowcount NUMBER; CURSOR c1_max_time IS SELECT d.ROWID row_id FROM plsql_profiler_units u, plsql_profiler_data d WHERE u.runid = :v_runid AND u.unit_owner <> 'SYS' AND d.runid = u.runid AND d.unit_number = u.unit_number AND ROUND(d.total_time/:v_time,2) > 0.00 ORDER BY d.total_time DESC; CURSOR c2_range IS SELECT unit_number, MIN(line#) min_line, MAX(line#) max_line FROM plsql_profiler_data WHERE runid = :v_runid AND spare1 IS NOT NULL GROUP BY unit_number; BEGIN UPDATE plsql_profiler_data SET spare1 = NULL WHERE runid = :v_runid; UPDATE plsql_profiler_units SET spare1 = NULL, spare2 = NULL WHERE runid = :v_runid; UPDATE plsql_profiler_units SET unit_timestamp = NULL WHERE runid = :v_runid AND unit_timestamp < SYSDATE - 3652.5; FOR c1 IN c1_max_time LOOP l_rowcount := c1_max_time%ROWCOUNT; IF l_rowcount = :v_top + 1 THEN EXIT; END IF; UPDATE plsql_profiler_data SET spare1 = l_rowcount WHERE ROWID = c1.row_id; END LOOP; FOR c2 IN c2_range LOOP UPDATE plsql_profiler_units SET spare1 = c2.min_line, spare2 = c2.max_line WHERE runid = :v_runid AND unit_number = c2.unit_number; END LOOP; END; / SPO profiler_&&p_runid..html; PRO profiler_&&p_runid..html PRO PRO PRO

profiler.sql - PL/SQL Profiler SET DEF '~'; PRO (MetaLink Note:243755.1)

SET DEF ON; PRO PRO

Profiled Run &&p_runid (plsql_profiler_runs)

PRO PRO PRO PRO PRO PRO PRO SELECT ''||CHR(10)|| ''||CHR(10)|| ''||CHR(10)|| ''||CHR(10)|| ''||CHR(10)|| '' FROM plsql_profiler_runs WHERE runid = :v_runid; PRO
RunDateTotal Time1Comment
'||TO_CHAR(runid)||''||TO_CHAR(run_date,'DD-MON-RR HH24:MI:SS')||''||TO_CHAR(ROUND(run_total_time/:v_time,2),'FM9999999999990.00')||''||run_comment||'
PRO Note 1: Total Time is in seconds PRO

Profiled PL/SQL Libraries (plsql_profiler_units)

PRO PRO PRO PRO PRO PRO PRO PRO PRO PRO SET DEF '~'; SELECT ''||CHR(10)|| ''||CHR(10)|| ''||CHR(10)|| ''||CHR(10)|| ''||CHR(10)|| ''||CHR(10)|| ''||CHR(10)|| ''||CHR(10)|| '' FROM plsql_profiler_units u WHERE u.runid = :v_runid AND ( u.unit_type <> 'ANONYMOUS BLOCK' OR ( u.unit_type = 'ANONYMOUS BLOCK' AND ROUND(u.total_time/:v_time,2) > 0.00 )) ORDER BY u.unit_number; SET DEF ON; PRO
UnitOwnerNameTypeTimestampTotal Time1Text Header
'||TO_CHAR(u.unit_number)||''||u.unit_owner||''|| DECODE(u.spare1,NULL,u.unit_name, ''||u.unit_name||'')|| ''||u.unit_type||''|| DECODE(u.unit_timestamp,NULL,NULL,TO_CHAR(u.unit_timestamp,'DD-MON-RR HH24:MI:SS'))|| ''||TO_CHAR(ROUND(u.total_time/:v_time,2),'FM9999999999990.00')||''|| ( SELECT REPLACE(REPLACE(s.text,'>','>'),'<','<') FROM all_source s WHERE s.owner = u.unit_owner AND s.name = u.unit_name AND s.type = u.unit_type AND s.line < 51 AND UPPER(s.text) LIKE ('%$%HEADER%') AND ROWNUM = 1 )||'
PRO Note 1: Total Time is in seconds PRO

Top &&p_top profiled source lines in terms of Total Time (plsql_profiler_data)

PRO PRO PRO PRO PRO PRO PRO PRO PRO PRO PRO PRO PRO PRO SET DEF '~'; SELECT ''||CHR(10)|| ''||CHR(10)|| ''||CHR(10)|| ''||CHR(10)|| ''||CHR(10)|| ''||CHR(10)|| ''||CHR(10)|| ''||CHR(10)|| ''||CHR(10)|| ''||CHR(10)|| ''||CHR(10)|| ''||CHR(10)|| '' FROM plsql_profiler_data d, plsql_profiler_units u WHERE d.runid = :v_runid AND d.spare1 IS NOT NULL AND u.runid = d.runid AND u.unit_number = d.unit_number ORDER BY d.total_time DESC; SET DEF ON; PRO
TopTotal Time1Times ExecutedMin Time2Max Time2UnitOwnerNameTypeLineText
'||TO_CHAR(d.spare1)||''||TO_CHAR(ROUND(d.total_time/:v_time,2),'FM9999999999990.00')||''||TO_CHAR(d.total_occur)||''||TO_CHAR(ROUND(d.min_time/:v_time,2),'FM9999999999990.00')||''||TO_CHAR(ROUND(d.max_time/:v_time,2),'FM9999999999990.00')||''||TO_CHAR(d.unit_number)||''||u.unit_owner||''||u.unit_name||''||u.unit_type||''|| DECODE(u.unit_type,'ANONYMOUS BLOCK',TO_CHAR(d.line#), ''|| TO_CHAR(d.line#)||'')|| ''|| ( SELECT REPLACE(REPLACE(s.text,'>','>'),'<','<') FROM all_source s WHERE s.owner = u.unit_owner AND s.name = u.unit_name AND s.type = u.unit_type AND s.line = d.line# )||'
PRO Note 1: Total Time is in seconds
PRO Note 2: Min and Max Time for one execution of this line (in seconds) SET DEF '~'; DECLARE l_total_time NUMBER; l_total_occur NUMBER; l_anchor VARCHAR2(100); CURSOR c1_units IS SELECT unit_number, unit_owner, unit_name, unit_type, spare1, spare2 FROM plsql_profiler_units WHERE runid = :v_runid AND spare1 IS NOT NULL ORDER BY unit_number; CURSOR c2_source ( c_owner VARCHAR2, c_name VARCHAR2, c_type VARCHAR2, c_line_min NUMBER, c_line_max NUMBER ) IS SELECT line, SUBSTR(REPLACE(REPLACE(text,'>','>'),'<','<'),1,220) text FROM all_source WHERE owner = c_owner AND name = c_name AND type = c_type AND line BETWEEN c_line_min - 50 AND c_line_max + 50 ORDER BY line; CURSOR c3_data ( c_unit_number NUMBER, c_line NUMBER ) IS SELECT spare1, total_time, total_occur FROM plsql_profiler_data WHERE runid = :v_runid AND unit_number = c_unit_number AND line# = c_line; -- -4 carlos BEGIN FOR c1 IN c1_units LOOP IF c1.unit_type <> 'ANONYMOUS BLOCK' THEN DBMS_OUTPUT.PUT_LINE( '

'|| ''|| 'Unit:'||TO_CHAR(c1.unit_number)||' '|| c1.unit_owner||'.'||c1.unit_name||' '|| '(all_source)

'); DBMS_OUTPUT.PUT_LINE(''); DBMS_OUTPUT.PUT_LINE(''); DBMS_OUTPUT.PUT_LINE(''); DBMS_OUTPUT.PUT_LINE(''); DBMS_OUTPUT.PUT_LINE(''); DBMS_OUTPUT.PUT_LINE(''); DBMS_OUTPUT.PUT_LINE(''); FOR c2 IN c2_source(c1.unit_owner, c1.unit_name, c1.unit_type, c1.spare1, c1.spare2) LOOP l_total_time := NULL; l_total_occur := NULL; l_anchor := NULL; FOR c3 IN c3_data(c1.unit_number, c2.line) LOOP l_total_time := c3.total_time; l_total_occur := c3.total_occur; IF c3.spare1 IS NOT NULL THEN l_anchor := 'T'||TO_CHAR(c3.spare1)||''; END IF; END LOOP; DBMS_OUTPUT.PUT_LINE(''); DBMS_OUTPUT.PUT_LINE(''); DBMS_OUTPUT.PUT_LINE(''); DBMS_OUTPUT.PUT_LINE(''); DBMS_OUTPUT.PUT_LINE(SUBSTR('',1,255)); DBMS_OUTPUT.PUT_LINE(''); END LOOP; DBMS_OUTPUT.PUT_LINE('
LineTotal Time1Times ExecutedText
'||TO_CHAR(c2.line)||l_anchor||''||TO_CHAR(ROUND(l_total_time/:v_time,2),'FM9999999999990.00')||''||TO_CHAR(l_total_occur)||''|| REPLACE(LPAD(LTRIM(c2.text), LENGTH(c2.text), '`'), '`', ' ')|| '
'); DBMS_OUTPUT.PUT_LINE('Note 1: Total Time is in seconds
'); DBMS_OUTPUT.PUT_LINE('Note Tn: Top "n" Line in terms of Total Time'); END IF; END LOOP; END; / SET DEF ON; PRO PRO SPO OFF; ROLLBACK; UNDEF 1 p_top p_runid; CLE COL; SET TERM ON HEA ON PAGES 24 LIN 80 NUM 10 VER ON FEED 6 TRIMS OFF RECSEP WR SERVEROUT OFF ARRAY 15 DOC ON;