Oracle provides dbms_profiler for tracing PL/SQL code and finding any performace bottlenecks.
This post shows how to use it.
For using dbms_profiler, first it should be installed.
Install dbms_profile and populate tables.
- @?/rdbms/admin/profload.sql (Install dbms_profiler)
- @?/rdbms/admin/proftab.sql (Populate profiler tables).
How to trace :
- exec dbms_profiler.start_profiler('Sample1');
- Run PL/SQL code (it would be better to be proc/func/package instead of anonymous code.
- exec dbms_profiler.stop_profiler;
- exec DBMS_PROFILER.FLUSH_DATA;
How to see the result :
- Which runid is for current trace
SELECT runid,
run_date,
run_comment,
run_total_time
FROM plsql_profiler_runs
ORDER BY runid;
- Total elapsed time of each PL/SQL code.
SELECT u.runid,
u.unit_number,
u.unit_type,
u.unit_owner,
u.unit_name,
d.line#,
d.total_occur,
d.total_time,
d.min_time,
d.max_time
FROM plsql_profiler_units u
JOIN plsql_profiler_data d ON u.runid = d.runid AND u.unit_number = d.unit_number
WHERE u.runid = &1
ORDER BY u.unit_number, d.line#;
FYI : Also putting dbms_utility.get_time(); in PL/SQL code would show exact run time execution of each PL/SQL pieces.
6 comments:
hi,
You r doing great work,
iam a new oracle DBA learning from your blog, in a recent interview i was asked how u will tune a sql query running for a long time..
pls help me on this..
Great work.
I followed your instructions but I get incoerent results:
from sqlplus the package procedure runs for about 4 secs. When i review DBMS_PROFILER results I get durations of thousands of secs...
any suggestion?
Hi,
Thanks for comment.
Please let me know on which version of Oracle you ran DBMS_PROFILER.
Shervin
Hi, shervin, the RDBMS is 9.2.0.7 (patched following oracle guidelines).this is the profsum script header:
Rem $Header: profsum.sql 13-apr-98.19:17:28 astocks Exp $
... and this is an extract from the profsum output:
===========================Results for run #1 made on 21-MAR-08 18:31:03 =========================
(ultimo) Run total time: 2803.72 seconds
[...]
19.994 1126,1389 ,05632384 fetch cur_contact_pool into tmp_id;
the strange is that when i run the script in sqlplus with timing on it takes 4.07 secs to do the job:
SQL> exec wcm.history.fy(180);
Procedura PL/SQL completata correttamente.
Passati: 00:00:04.07
Fabio
I have seen a lot of work on TEMP so I'VE ENLARGED SORT_AREA_SIZE to 50MB (also if the sort ratio disk/memory does'nt suggest to do it, it was done mainly in memory).
Other ratios (dbcache, etc).
And I can tell you also that using tracing timings are ok:
SELECT CONTACT_POOL_ID
FROM
CONTACT_POOL WHERE CONTACT_LIST_ID IN ( SELECT CONTACT_LIST_ID FROM
CONTACT_LIST WHERE CAMPAIGN_ID IN ( SELECT CAMPAIGN_ID FROM CAMPAIGNS C
WHERE TRUNC(SYSDATE-TO_DATE(C.DATA_FINE,'YYYYMMDD')) > :B1 AND
(C.DATA_FINE_OUT IS NULL OR TRUNC(SYSDATE-TO_DATE(C.DATA_FINE_OUT,
'YYYYMMDD')) > :B1 ) ) )
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 19993 1.20 1.30 948 20378 2 19992
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 19994 1.20 1.30 948 20378 2 19992
Misses in library cache during parse: 0
Optimizer goal: CHOOSE
Parsing user id: 60 (WCM) (recursive depth: 1)
Rows Execution Plan
------- ---------------------------------------------------
0 SELECT STATEMENT GOAL: CHOOSE
0 NESTED LOOPS
0 MERGE JOIN (CARTESIAN)
0 TABLE ACCESS GOAL: ANALYZED (FULL) OF 'CAMPAIGNS'
0 BUFFER (SORT)
0 INDEX GOAL: ANALYZED (FAST FULL SCAN) OF
'SYS_IOT_TOP_31635' (UNIQUE)
0 INDEX GOAL: ANALYZED (UNIQUE SCAN) OF 'SYS_IOT_TOP_31638'
(UNIQUE)
Post a Comment