Skip to Main Content

Breadcrumb

Question and Answer

Tom Kyte

Thanks for the question, Raj.

Asked: April 04, 2001 - 5:34 pm UTC

Last updated: March 25, 2013 - 2:14 pm UTC

Version: 8.1.5.0.0

Viewed 10K+ times! This question is

You Asked

Hi Tom,

I have two questions:
Ques1. I am executing a package which calls another package(thru DB link) which is in different instance. It was working fine but suddenly now I started getting this error below-

ORA-02064: distributed operation not supported
ORA-06512: at "SCPEP.NDP_CON", line 145


Ques2. I have seen the use of DBMS_PROFILER package in one of your solutions below. You have run some scripts to view the report on this package. I am just curious about how to see the outcome of this package. What are the scripts did you run??

I really appreciate your help.

Thanks.
Raj

--------------------------------------------------------------------
The fastest is to bite the bullet, configure sufficient rollback and do the update in a single update statement.

The second fastest is to bit the bullet, configure sufficient rollback and do the transaction in a single loop without commits.

The commit is what will slow you down. You'll have to consider how you will restart this process as well. Watch out for the ora-01555 which will inevitably get you if you are updating the table you are reading as well.

As for the code above, we can use the source code profiler provided in the 8i database to analyze this. I created the following procedures and ran them:

create or replace procedure do_mod as
cnt number := 0;
begin
dbms_profiler.start_profiler( 'mod' );
for i in 1 .. 500000
loop
cnt := cnt + 1;
if ( mod(cnt,1000) = 0 )
then
commit;
end if;
end loop;
dbms_profiler.stop_profiler;
end;
/
create or replace procedure no_mod as
cnt number := 0;
begin
dbms_profiler.start_profiler( 'no mod' );
for i in 1 .. 500000
loop
cnt := cnt + 1;
if ( cnt = 1000 )
then
commit;
cnt := 0;
end if;
end loop;
dbms_profiler.stop_profiler;
end;
/
exec do_mod
exec no_mod

Now, after running the profiler reports I find:
=
=
====================
Total time

GRAND_TOTAL
------------------
11.41
=
=
====================
Total time spent on each run

RUNID RUN_COMMENT SECS
----- ----------- -------
1 mod 8.18
2 no mod 3.23
=
=
====================
Percentage of time in each module, for each run separately

RUNID RUN_COMMENT UNIT_OWNER UNIT_NAME SECS PERCEN
----- ----------- ---------- ------------ ----- ---------
1 mod OPS$TKYTE DO_MOD 8.18 100.0
2 no mod OPS$TKYTE NO_MOD 3.23 100.0
=
=
====================
Percentage of time in each module, summarized across runs

UNIT_OWNER UNIT_NAME SECS PERCENTAG
----------- -------------- ------ ---------------
OPS$TKYTE DO_MOD 8.18 71.67
OPS$TKYTE NO_MOD 3.23 28.32
SYS DBMS_PROFILER .00 .00

So already, this shows that the MOD function takes longer. Just to prove that it is MOD
=
=
====================
Lines taking more than 1% of the total time, each run separate

RUNID HSECS PCT OWNER UNIT_NAME LINE# TEXT
----- ------ ---- ------ ---------- ------ --------------------
1 550.06 48.2 OPS$TKYTE DO_MOD 9 if ( mod(cnt,1000) = 0 )
1 135.22 11.9 OPS$TKYTE DO_MOD 8 cnt := cnt + 1;
2 107.71 9.4 OPS$TKYTE NO_MOD 8 cnt := cnt + 1;
2 104.34 9.1 OPS$TKYTE NO_MOD 9 if ( cnt = 1000 )
1 67.95 6.0 OPS$TKYTE DO_MOD 6 for i in 1..500000
2 64.66 5.7 OPS$TKYTE NO_MOD 12 cnt := 0;
1 64.64 5.7 OPS$TKYTE DO_MOD 11 commit;
2 44.99 3.9 OPS$TKYTE NO_MOD 6 for i in 1..500000

8 rows selected.

that clinches it -- using MOD took about 5.5 seconds, doing if ( cnt=1000 ) took 1 second PLUS the time to do cnt := 0 gives a grant total of about 1.5 seconds.

5.5 for mod
1.5 for cnt=1000; cnt:=0;


and Tom said...

1) sounds like somebody modified the remote procedure and added a COMMIT or ROLLBACK or something that does a commit or rollback implicitly (DDL for example). Find out what has changed in the remote procedure -- you cannot commit in a remote procedure -- only the invoking procedure can do that.


2)

Your DBA may have to install the profiler in your database. The procedure for installing this package is simple:

ć cd $ORACLE_HOME/rdbms/admin
ć Using SVRMGRL you would connect as SYS or INTERNAL
ć Run profload.sql

In order to actually use the profiler after that, you will need to have the profiling tables installed. You can install these once per database but I recommend each developer would have their own copy. Fortunately, the DBMS_PROFILER package is built with invokers rights and unqualified tablenames so that we can install the tables in each schema and the profiler package will use them. The reason you each want your own tables is so that you only see the results of your profiling runs, not those of your coworkers. In order to get a copy of the profiling tables in your schema, you would run $ORACLE_HOME\rdbms\admin\proftab in SQLPlus. After you run proftab.sql, you¡¦ll need to run profrep.sql as well. This script creates views and packages to operate on the profiler tables in order to generate reports. This script is found in $ORACLE_HOME\plsql\demo\profrep.sql. You should run this in your schema as well after creating the tables.

I like to keep a small script around to reset these tables (clear them out). After I¡¦ve done a run or two and have analyzed the results ¡V I run this script to reset the tables. I have the following in a script I call profreset.sql:

delete from plsql_profiler_data;
delete from plsql_profiler_units;
delete from plsql_profiler_runs;

finally, and to answer the question, you will find $ORACLE_HOME/plsql/demo/profsum.sql. that is what generates the report.




Rating

  (59 ratings)

Is this answer out of date? If it is, please let us know via a Comment

Comments

dbms_profiler

Pramod, May 23, 2001 - 8:23 am UTC


dbms_profiler

Pramod, May 23, 2001 - 8:23 am UTC


DBMS_PROFILER

Milen Alexiev, October 15, 2001 - 10:59 am UTC

Very detailed and clear explanations and instructions
how to install the package

A reader, May 03, 2002 - 7:25 pm UTC

Hi Tom,

Can you please post the script (profsum.sql) you have on p. 1164 ~ 1166 of your book on this website? I tried many times to find it on www.wrox.com, but could never find it.

thanks

Tom Kyte
May 03, 2002 - 7:36 pm UTC

set echo off
set linesize 5000
set trimspool on
set serveroutput on
set termout off

column owner format a11
column unit_name format a14
column text format a21 word_wrapped
column runid format 9999
column secs format 999.99
column hsecs format 999.99
column grand_total format 9999.99
column run_comment format a11 word_wrapped
column line# format 99999
column pct format 999.9
column unit_owner format a11

spool profsum.out

/* Clean out rollup results, and recreate */
update plsql_profiler_units set total_time = 0;

execute prof_report_utilities.rollup_all_runs;

prompt =
prompt =
prompt ====================
prompt Total time
select grand_total/1000000000 as grand_total
from plsql_profiler_grand_total;

prompt =
prompt =
prompt ====================
prompt Total time spent on each run
select runid,
substr(run_comment,1, 30) as run_comment,
run_total_time/1000000000 as secs
from (select a.runid, sum(a.total_time) run_total_time, b.run_comment
from plsql_profiler_units a, plsql_profiler_runs b
where a.runid = b.runid group by a.runid, b.run_comment )
where run_total_time > 0
order by runid asc;


prompt =
prompt =
prompt ====================
prompt Percentage of time in each module, for each run separately

select p1.runid,
substr(p2.run_comment, 1, 20) as run_comment,
p1.unit_owner,
decode(p1.unit_name, '', '<anonymous>',
substr(p1.unit_name,1, 20)) as unit_name,
p1.total_time/1000000000 as secs,
TO_CHAR(100*p1.total_time/p2.run_total_time, '999.9') as percentage
from plsql_profiler_units p1,
(select a.runid, sum(a.total_time) run_total_time, b.run_comment
from plsql_profiler_units a, plsql_profiler_runs b
where a.runid = b.runid group by a.runid, b.run_comment ) p2
where p1.runid=p2.runid
and p1.total_time > 0
and p2.run_total_time > 0
and (p1.total_time/p2.run_total_time) >= .01
order by p1.runid asc, p1.total_time desc;

column secs form 9.99
prompt =
prompt =
prompt ====================
prompt Percentage of time in each module, summarized across runs
select p1.unit_owner,
decode(p1.unit_name, '', '<anonymous>', substr(p1.unit_name,1, 25)) as unit_name,
p1.total_time/1000000000 as secs,
TO_CHAR(100*p1.total_time/p2.grand_total, '99999.99') as percentage
from plsql_profiler_units_cross_run p1,
plsql_profiler_grand_total p2
order by p1.total_time DESC;


prompt =
prompt =
prompt ====================
prompt Lines taking more than 1% of the total time, each run separate
select p1.runid as runid,
p1.total_time/10000000 as Hsecs,
p1.total_time/p4.grand_total*100 as pct,
substr(p2.unit_owner, 1, 20) as owner,
decode(p2.unit_name, '', '<anonymous>', substr(p2.unit_name,1, 20)) as unit_name,
p1.line#,
( select p3.text
from all_source p3
where p3.owner = p2.unit_owner and
p3.line = p1.line# and
p3.name=p2.unit_name and
p3.type not in ( 'PACKAGE', 'TYPE' )) text
from plsql_profiler_data p1,
plsql_profiler_units p2,
plsql_profiler_grand_total p4
where (p1.total_time >= p4.grand_total/100)
AND p1.runID = p2.runid
and p2.unit_number=p1.unit_number
order by p1.total_time desc;

prompt =
prompt =
prompt ====================
prompt Most popular lines (more than 1%), summarize across all runs
select p1.total_time/10000000 as hsecs,
p1.total_time/p4.grand_total*100 as pct,
substr(p1.unit_owner, 1, 20) as unit_owner,
decode(p1.unit_name, '', '<anonymous>',
substr(p1.unit_name,1, 20)) as unit_name,
p1.line#,
( select p3.text from all_source p3
where (p3.line = p1.line#) and
(p3.owner = p1.unit_owner) AND
(p3.name = p1.unit_name) and
(p3.type not in ( 'PACKAGE', 'TYPE' ) ) ) text
from plsql_profiler_lines_cross_run p1,
plsql_profiler_grand_total p4
where (p1.total_time >= p4.grand_total/100)
order by p1.total_time desc;

execute prof_report_utilities.rollup_all_runs;

prompt =
prompt =
prompt ====================
prompt Number of lines actually executed in different units (by unit_name)

select p1.unit_owner,
p1.unit_name,
count( decode( p1.total_occur, 0, null, 0)) as lines_executed ,
count(p1.line#) as lines_present,
count( decode( p1.total_occur, 0, null, 0))/count(p1.line#) *100
as pct
from plsql_profiler_lines_cross_run p1
where (p1.unit_type in ( 'PACKAGE BODY', 'TYPE BODY',
'PROCEDURE', 'FUNCTION' ) )
group by p1.unit_owner, p1.unit_name;


prompt =
prompt =
prompt ====================
prompt Number of lines actually executed for all units
select count(p1.line#) as lines_executed
from plsql_profiler_lines_cross_run p1
where (p1.unit_type in ( 'PACKAGE BODY', 'TYPE BODY',
'PROCEDURE', 'FUNCTION' ) )
AND p1.total_occur > 0;


prompt =
prompt =
prompt ====================
prompt Total number of lines in all units
select count(p1.line#) as lines_present
from plsql_profiler_lines_cross_run p1
where (p1.unit_type in ( 'PACKAGE BODY', 'TYPE BODY',
'PROCEDURE', 'FUNCTION' ) );

spool off
set termout on
edit profsum.out
set linesize 131

Can you explain it a bit more, preferably with an example......

Ashok, May 06, 2002 - 11:04 pm UTC

Hi Tom
You said "Find out what has changed in the remote procedure -- you cannot commit in a remote procedure -- only the invoking procedure can do that."
When you say 'Commit in a remote procedure', does it mean that the remote procedure should not have a commit statement in it? Also if a DDL is allowed via a remote procedure then why should a commit not be given in it? I hope my question/doubt is properly phrased.


Can you clear my doubt which i had posted in my earlier review?

Ashok, May 08, 2002 - 5:49 am UTC


Tom Kyte
May 08, 2002 - 8:05 am UTC

the remote procedure should have no transaction control statements in it, DDL commits (transaction control) hence no DDL should be done (use DBMS_JOB to remotely SCHEDULE a job to do the DDL after you commit)

Mike, March 08, 2003 - 1:25 am UTC

"
the remote procedure should have no transaction control statements in it, DDL
commits (transaction control) hence no DDL should be done (use DBMS_JOB to
remotely SCHEDULE a job to do the DDL after you commit)
"

I am not very sure what you meant in above. Could you please give an example (demo)

Thanks

Tom Kyte
March 08, 2003 - 9:00 am UTC

If you have my book "Expert one on one Oracle" -- i cover this but what I mean is you should not do DDL in the remote procedure, the remote procedure should instead do:


...
dbms_job.submit( l_job, 'execute immediate ''create table t ( x int )'';' );
.....

Now, when the remote procedure is committed, the job will become visible and will run shortly after.

Which chapter covers that?

Mike, March 08, 2003 - 11:50 am UTC


Tom Kyte
March 08, 2003 - 1:28 pm UTC

I talk about it in the autonomous transaction chapter.

I demonstrate DDL (like analyze and such) in the necessary supplied packages appendix on dbms_job.


Doing DDL is not really any different then calling a procedure at the end of the day -- it's just an execute immediate.

ORA-2064

Sean, March 18, 2003 - 4:04 pm UTC

Tom,
I want to test/recreate on ORA-02064. But I am confused after all.
ORA8i -- remote db, jnas -- local db

owb_repos@ora8i> drop table test;

Table dropped.

owb_repos@ora8i> CREATE TABLE TEST (ID NUMBER, NAME VARCHAR2(25));

Table created.

owb_repos@ora8i> create or replace package call_fdm is
2 procedure pop_test(p_id in number, p_name in varchar2);
3 end call_fdm;
4 /

Package created.

owb_repos@ora8i>
owb_repos@ora8i> create or replace package body call_fdm
2 is
3 procedure pop_test(p_id in number, p_name in varchar2)
4 is
5 begin
6 insert into test values(p_id, p_name);
7 commit;
8 end;
9 End call_fdm;
10 /

Package body created.

owb_repos@ora8i>
owb_repos@ora8i> create or replace package body call_fdm
2 is
3 procedure pop_test(p_id in number, p_name in varchar2)
4 is
5 begin
6 insert into test values(p_id, p_name);
7 commit;
8 end;
9 End call_fdm;
10 /

Package body created.

owb_repos@ora8i>

You see I have COMMIT in the remote packge.

From the local JNAS
owb_repos@jnas> exec call_fdm.pop_test@ORA8I_OWBLINK.US.ORACLE.COM(4,'d');

PL/SQL procedure successfully completed.

owb_repos@jnas> select * from test@ORA8I_OWBLINK.US.ORACLE.COM;
ID NAME
---------- -------------------------
4 d

Why Oracle did not return with ORA-02064?

Tom Kyte
March 18, 2003 - 5:11 pm UTC

they are trying to relax restrictions all of the time...

I will say I sometimes wish plsql did not support commit and rollback at all. I firmly believe transaction control belongs in the CLIENT and no where else.

Sean, March 18, 2003 - 5:14 pm UTC

ORA-02064 returned as COMMIT with an OUT parameter.
I have just read it document carefully.

Please explain

Yogesh, August 06, 2003 - 10:21 am UTC

I was going thru the doc I came across following explainations for ORA-02064 distributed operation not supported

Cause: One of the following unsupported operations was attempted:

Array execute of a remote update with a subquery that references a database link, or

What is array execute ?

An update of a long column with bind variable and an update of a second column with a subquery that both references a database link and a bind variable, or

A commit is issued in a coordinated session from an RPC with OUT parameters.

can't understand 2nd and 3rd .. can you please explain in simple words ...


Tom Kyte
August 06, 2003 - 10:59 am UTC



it is a bulk bind in plsql talk. when you bind a host array with many inputs. in pro*c might look like this:


int x[50];

... code to fill up x....

exec sql update t@remote_site set x = :x where exists ( select null from t@remote_site where y = :x );

for example -- that update will be executed 50 times by the server since we used an array bind.



the

"An update of a long column with bind variable and an update of a second column
with a subquery that both references a database link and a bind variable, or"

seems obvious

update t
set LONG_COLUMN = :x,
y = (select y from t2@remote where z = :z )


and the third just means "you called a remote stored procedure (RPC) from a distributed transaction and the remote stored procedure has OUT parameters"


More Info

Yogesh, August 06, 2003 - 10:32 am UTC

My application is designed in such a way that remote procedure will send a Table type and my proc will process entire records in that table and then send a set of errors (if any) for those records in the table .....

Now if I can't commit in that proc and lets say first record from my table type updated record no 10, column c1 in one database table .. now my second update again trying to update same record but some different column .. lets say c2 .. but as old changes are not comitted this update don't work ...

Is my understand right ? if yes what could be the solution in such scenarios



Tom Kyte
August 06, 2003 - 10:59 am UTC

why won't the update work? you can see your changes, you just cannot "see" anyone elses uncommitted changes.

More Info

Yogesh, August 06, 2003 - 3:20 pm UTC

Thanks for the explanation .... I was getting the error due to 3 i.e. commit. But the scenario whcih I have mentioned is something like following

I get following from remote db call

featurename featurevalue
abcd 10
xyz 20

now my code read that record by record.

so I have first record which is mapped to table1, row1, column1, so I issued a command

update table1 set column1=10 where row1=abcd

there is no commit after that as I get error, now second statement

update table1 set column2=20 where row1=xyz

I'm facing problem here... when it tried updating table .. it waited lond and gave me "dead lock" error and came out. What could be causing this error ?

But when I added commit in the code, and tested locally (not using dblink) ... it worked fine. I could not make out what was causing prob!!! can you please suggest something





Tom Kyte
August 09, 2003 - 12:08 pm UTC

that row, "where row1=xyz" is locked by someone else -- it is that simple.




DBMS_Profiler - Time Statistics

Steven Cooper, August 06, 2003 - 6:20 pm UTC

Tom,

I am using your profsum.sql script to test a basic pl/sql procedure / trigger combination to insert 10 rows into a dummy table just to get the hang of DBMS_Profiler, but I'm not completely convinced about the timed statistics it is showing me. I ran the below code and it all returned instantly, but according to DBMS_Profiler it took 6.6 Secs, It no way took that long:
Is it me or is time running fast in england? :)

Heres the Code:

@reset_prof
drop table t;
drop procedure test;
drop sequence t_seq;

create table t
(
x int,
y date
)
/
create sequence t_seq start with 1 increment by 1 cache 10;

create or replace trigger t_bi
before insert on t for each row
begin
select t_Seq.nextval
into :new.x
from dual;
end;
/

create or replace procedure test
as
begin
for x in 1 .. 10
loop
insert into t values (null,sysdate);
end loop;
end;
/

EXEC DBMS_PROFILER.START_PROFILER('Test');
exec test;
EXEC DBMS_PROFILER.STOP_PROFILER;

Heres the profiler report:

7 rows updated.


PL/SQL procedure successfully completed.

=
=
====================
Total time

GRAND_TOTAL
-----------
6.61

=
=
====================
Total time spent on each run

RUNID RUN_COMMENT SECS
----- ----------- -------
10 Test 6.61

=
=
====================
Percentage of time in each module, for each run separately

RUNID RUN_COMMENT UNIT_OWNER UNIT_NAME SECS PERCEN
----- ----------- ----------- -------------- ------- ------
10 Test BANK TEST 4.28 64.8
10 Test BANK T_BI 2.21 33.4

=
=
====================
Percentage of time in each module, summarized across runs

UNIT_OWNER UNIT_NAME SECS PERCENTAG
----------- -------------- ----- ---------
BANK TEST 4.28 64.79
BANK T_BI 2.21 33.38
<anonymous> <anonymous> .12 1.83

=
=
====================
Lines taking more than 1% of the total time, each run separate

RUNID HSECS PCT OWNER UNIT_NAME LINE# TEXT
----- ------- ------ ----------- -------------- ------ ---------------------
10 426.33 64.5 BANK TEST 6 insert into t values
(null,sysdate);

10 219.21 33.2 BANK T_BI 2

=
=
====================
Most popular lines (more than 1%), summarize across all runs

HSECS PCT UNIT_OWNER UNIT_NAME LINE# TEXT
------- ------ ----------- -------------- ------ ---------------------
426.33 64.5 BANK TEST 6 insert into t values
(null,sysdate);

219.21 33.2 BANK T_BI 2
12.07 1.8 <anonymous> <anonymous> 1


PL/SQL procedure successfully completed.

=
=
====================
Number of lines actually executed in different units (by unit_name)

UNIT_OWNER UNIT_NAME LINES_EXECUTED LINES_PRESENT PCT
----------- -------------- -------------- ------------- ------
BANK TEST 3 3 100.0

=
=
====================
Number of lines actually executed for all units

LINES_EXECUTED
--------------
3

=
=
====================
Total number of lines in all units

LINES_PRESENT
-------------
3

Also I ran the normal profsum.sql in [Oracle_Home]\plsql\demo and that reports the same times. any ideas other than I have no concept of time or my watch stopped? :)

Thanks in advance
Steven



Tom Kyte
August 09, 2003 - 11:57 am UTC

version? (platform is obvious - the one that couldn't figure out the rest of the free world uses \ as the escape character...)

Oooops!

Steven Cooper, August 10, 2003 - 4:13 pm UTC

Sorry Tom ,

We just had a heat wave over here (26C) ;) it must have gone to my head. or maybe I typed too quick for windoZZZZzzzzzzz (2000) to keep up.

Anyway I'm running a local version of 8.1.7. on my desktop Win 2K machine and it was the only session running.

Cheers

Steven

Tom Kyte
August 10, 2003 - 4:57 pm UTC

unfortunately for you (for most fortunate for me), I do not have a windoze machine to test with.

On my solaris box -- 8174 -- this worked just fine (when I wrote expert one on one, I was using windows -- version 816 -- and it worked there as well).

when I run this I get:

9 rows updated.


PL/SQL procedure successfully completed.

=
=
====================
Total time

GRAND_TOTAL
-----------
.02

=
=
====================
Total time spent on each run

RUNID RUN_COMMENT SECS
----- ----------- -------
1 Test .02

....


Is there a chance your numbers are "100 times greater"? Perhaps it is that -- if you set timing on, does it seem to run in about 0.6 seconds?

Steven Cooper, August 10, 2003 - 5:29 pm UTC

Tom,

I ran the test again with timing on:

scott@dev> exec test;

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.70

I then ran it again with DBMS_Profiler:

Elapsed: 00:00:00.21

GRAND_TOTAL
-----------
13.65

Elapsed: 00:00:00.60
=
=
====================
Total time spent on each run

RUNID RUN_COMMENT SECS
----- ----------- -------
10 Test 6.61
11 Test2 7.04 <-- This is the Second test


If I adjust your summary script and divide by ten zeros instead of 9 I get:

Elapsed: 00:00:00.20
=
=
====================
Total time

GRAND_TOTAL
-----------
1.36

Elapsed: 00:00:00.10
=
=
====================
Total time spent on each run

RUNID RUN_COMMENT SECS
----- ----------- -------
10 Test .66
11 Test2 .70

Elapsed: 00:00:00.10

This looks more like it. what do you think?

Steven


Tom Kyte
August 10, 2003 - 7:53 pm UTC

I would concurr -- I see no "bugs" filed against it -- but it does look like an order of 100 problem for some reason.


ORA-02064 and out parameters

Yogesh, August 20, 2003 - 4:14 pm UTC

what is the reason why we can't use OUT parameters in a RPC call ? asking just for curiosity.

Secondly, can I make any transaction autonomous by using PRAGMA AUTONOMOUS_TRANSACTION; especially when transaction is a RPC. If no then is there any other way we can make a part of transaction autonomous in case of RPC ?


Tom Kyte
August 21, 2003 - 5:30 pm UTC 

you can?

ops$tkyte@ORA920> variable x number
ops$tkyte@ORA920> print x

         X
----------


ops$tkyte@ORA920> exec p@aria_dev( :x )

PL/SQL procedure successfully completed.

ops$tkyte@ORA920> print x

         X
----------
        55

ops$tkyte@ORA920>





you cannot do autonomous transactions over dblink.  documented restriction.

dbms_profiler reports

Arun Gupta, August 23, 2003 - 2:47 pm UTC

Tom,
We use ref cursor in all stored procs. If I use profiler, will it give correct results since the query associated with ref cursor is not executed till I do a fetch from it. I do as:
a) Start profiler
b) exec package.stored_proc(ref_cursor);
c) Stop profiler
d) Run report
What would be the right way to do this?
Thanks






Tom Kyte
August 23, 2003 - 6:27 pm UTC

the profiler only shows code, not sql execution. for sql execution -- use tkprof and sql_trace

ORA-02064

Yogesh, September 01, 2003 - 4:48 pm UTC

I'm getting ORA-02064 exception when a procedure is being called over dblink and when that procedure tries to create a table dynamically ... it works from other user from the same instance .. but not on dblink ... what is the solution ?

my procdure which creates the table dynamically have authid as definer ...

Tom Kyte
September 01, 2003 - 6:00 pm UTC

[tkyte@tkyte-pc-isdn tkyte]$ oerr ora 2064
02064, 00000, "distributed operation not supported"
// *Cause: One of the following unsupported operations was attempted:
// 1. array execute of a remote update with a subquery that references
// a dblink, or
// 2. an update of a long column with bind variable and an update of
// a second column with a subquery that both references a dblink
// and a bind variable, or
// 3. a commit is issued in a coordinated session from an RPC with
// OUT parameters.
// *Action: simplify remote update statement
[tkyte@tkyte-pc-isdn tkyte]$

(ddl commits)

That aside, excessively poor practice to be creating objects in a stored procedure -- it is slow, it is error prone, it is just all around "bad". You should rethink your approach. the object in most cases should exist already.

some of the exceptions might be a maintainence routine to implement a sliding window on a partitioned table or something -- but in general -- my eyebrow goes up a notch when someone says "trying to create a table in a procedure..."

Error while creating dbms_profiler package

p.s.vinodh, December 09, 2003 - 6:39 am UTC 

hi tom,
iam trying to creat dbms_profile server side package but it is showing error i could not able to trace it , can you throw some light on it tom.


i connected  user-- sys as sysdba 
and then  executed profload file but it is showing invalid sql error so i tried to execute the part by part to i executed dbmspbp it executed fine . next i executed prvtpbp.plb but its is showing error as it is wrapped procedure i not able to trace what was the problem.

kindly help me out to tom.

thanks in advance.



Connected to Oracle9i Enterprise Edition Release 9.2.0.1.0 
Connected as sys


SQL> @F:\ORACLE\ORA92\RDBMS\ADMIN\dbmspbp.sql

Package created

Grant succeeded

Synonym created

SQL> @F:\ORACLE\ORA92\RDBMS\ADMIN\prvtpbp.plb

0
0
9
2
0 a0 109 :2 a0 ff 1d 17 b5
9
2
0 3 7 b f 13 17 18
21
9
2
0 1 d 1f 2a :4 1
9
4
0 :8 1
23
4
:3 0 1 :3 0 2
:3 0 3 :3 0 4
:3 0 2 0 3
:2 0 6 5 8
:8 0
3
4
:3 0
1
4
0
7
0
1
14
0
0
0 0 0 0 0 0 0 0
0 0 0 0 0 0 0 0
0 0 0 0
0

ORA-00900: invalid SQL statement

Warning: Package body created with compilation errors

SQL> show err
Errors for PACKAGE BODY SYS.DBMS_PROFILER:

LINE/COL ERROR
-------- ----------------------------------------------------------------------------
21/11    PLS-00201: identifier 'SYS.DBMS_PROFILER_LIB' must be declared
16/3     PL/SQL: Item ignored
34/11    PLS-00201: identifier 'SYS.DBMS_PROFILER_LIB' must be declared
32/3     PL/SQL: Item ignored
43/11    PLS-00201: identifier 'SYS.DBMS_PROFILER_LIB' must be declared
41/3     PL/SQL: Item ignored
51/11    PLS-00201: identifier 'SYS.DBMS_PROFILER_LIB' must be declared
49/3     PL/SQL: Item ignored
59/11    PLS-00201: identifier 'SYS.DBMS_PROFILER_LIB' must be declared
57/3     PL/SQL: Item ignored
69/11    PLS-00201: identifier 'SYS.DBMS_PROFILER_LIB' must be declared
67/3     PL/SQL: Item ignored
89/9     PLS-00307: too many declarations of 'INTERNAL_VERSION_CHECK' match this call
89/5     PL/SQL: Statement ignored
111/9    PLS-00307: too many declarations of 'INTERNAL_VERSION_CHECK' match this call
111/5    PL/SQL: Statement ignored
140/9    PLS-00307: too many declarations of 'INTERNAL_VERSION_CHECK' match this call
140/5    PL/SQL: Statement ignored
152/9    PLS-00307: too many declarations of 'INTERNAL_VERSION_CHECK' match this call
152/5    PL/SQL: Statement ignored

SQL>

Tom Kyte
December 09, 2003 - 6:43 am UTC

you use @profload.sql to install this package.

dbms_profiler errorr

p.s.vinodh, December 09, 2003 - 7:56 am UTC 

Hi tom,
thanks for your prompt reply ,
well i tried that, but it is showing same error to identify that, i tried to run the script which is refered inside profload.sql.

ok here i will paste the error message which comes if i run profload.sql file

thanks,



Connected to Oracle9i Enterprise Edition Release 9.2.0.1.0 
Connected as sys


SQL> @F:\ORACLE\ORA92\RDBMS\ADMIN\profload

Package created

Grant succeeded

Synonym created

0
0
9
2
0 a0 109 :2 a0 ff 1d 17 b5
9
2
0 3 7 b f 13 17 18
21
9
2
0 1 d 1f 2a :4 1
9
4
0 :8 1
23
4
:3 0 1 :3 0 2
:3 0 3 :3 0 4
:3 0 2 0 3
:2 0 6 5 8
:8 0
3
4
:3 0
1
4
0
7
0
1
14
0
0
0 0 0 0 0 0 0 0
0 0 0 0 0 0 0 0
0 0 0 0
0

ORA-00900: invalid SQL statement

Warning: Package body created with compilation errors



Testing for correct installation
PACKAGE BODY sys.DBMS_PROFILER - missing or invalid

PL/SQL procedure successfully completed

SQL>

Tom Kyte
December 09, 2003 - 8:26 am UTC

what sqlplus are you using -- try the command line one and make sure its the 9ir2 version.

Thanks,

p.s.vinodh, December 10, 2003 - 9:13 am UTC

Hi tom,
Thanks, Actually i was using 8.0.4 SQLPLUS version.
It is working fine with 9iR2 version tom..

i worked with profiler as in your book.Thats working great and its very much useful to tune and identify the bottleneck in procedures and packages.


Thanks,

My grand_total is 0

Lewis, December 10, 2003 - 10:11 am UTC

I've run this many times now and I keep getting a grand_total of sero which raises several divide by zero errors. All of the timings in the profiler tables are zero. I've run your profsum and the demo with the same results.

timed_statistics was false so I changed that to true but still no love.

Any ideas?

Thanks,

Lewis

Tom Kyte
December 10, 2003 - 3:42 pm UTC

are you running something that actually takes a MEASURABLE amount of time?

how's about an example?

The overall process is taking about 10 minutes

Lewis, December 10, 2003 - 10:33 pm UTC

It's a process that's reading a few thousand rows for about 10 tables and aggregating them and uses utl_file to create a file to send to an external system. There is definately time involved here. I can't give this as an example without giving you a bunch of packages and an export of the database. It does take time though.

To test that it wasn't something wierd in my code, I wrote a procedure that looped 1000 times and inserted into a table each time through the loop. Same thing, 0 on total_time and min/max times.

It doesn't matter if I do 1000 times or 10000, or 250000. Always 0 for all times. I'm in 8.1.7.4. timed_statistics is NOT set for the DB. I did an alter session to turn timed_statistics on. Does that make any difference?

I can send you anything you might need, my code example, DB parameters, the actual values in the profiler tables, etc. Just let me know.

Thanks,

Lewis


Tom Kyte
December 11, 2003 - 5:40 am UTC

what platform are you using?

0 totals

Lewis, December 11, 2003 - 8:05 am UTC

I'm on Compaq TRU64.

Thanks,

Lewis

Tom Kyte
December 11, 2003 - 8:12 am UTC

Profiling makes use of the underlying time functions available on the Operating System. Solaris, AIX and HP support time functions with nanosecond granularity. In particular they support the gethrtime() time function which returns time with nanosecond granularity. Tru64, Data General and VMS support time functions with millisecond granularity. On these platforms profiling can only support up to millisecond granularity. Nanosecond granularity is needed to get decent profiling data on "lines of code that execute really fast".


so, you should have some aggregate times but the code will appear to run "infinitely fast" since the underly OS you are using does not support a clock with a fine enough resolution.

Wow! Thank you

Lewis, December 11, 2003 - 8:28 am UTC

I would have beat my head against the wall forever over that one.

code coverage

Sudhanshu, June 07, 2004 - 1:06 am UTC

Using DBMS_PROFILER I have developed a pl/sql code coverage tool.
I have two files :-
code_coverage.sql <contents below>
---------------------------------------------------------
SET MARKUP HTML ON SPOOL ON PREFORMAT ON ENTMAP OFF -
HEAD '<TITLE>CODE COVERAGE REPORT</TITLE> -
<STYLE type="text/css"> -
<!-- BODY {background: #FFFFFF} --> -
</STYLE>' -
BODY 'TEXT="#000080"' -

SET pagesize 10000
SET linesize 132
COLUMN line format 9999
COLUMN text format a180

SET VERIFY OFF ECHO OFF

VARIABLE A1 NUMBER
VARIABLE A2 NUMBER
VARIABLE A3 NUMBER
VARIABLE A4 NUMBER
VARIABLE A5 VARCHAR2(30)
SET FEEDBACK OFF
BEGIN
:A3 := &1;
:A5 := '&2';
SELECT unit_number into :A4 from plsql_profiler_units where runid = :A3 and unit_name = :A5;
SELECT count(*) INTO :A1 from plsql_profiler_data where runid = :A3 and unit_number = :A4;
select count(*) INTO :A2 from plsql_profiler_data where runid = :A3 and unit_number = :A4 and TOTAL_OCCUR > 0;
END;
/

SPOOL c:\CODE_COVERAGE_OUTPUT.html
select :A1 AS "NUMBER OF EXECUTABLE STMTS." from dual;
SELECT :A2 AS "NUMBER OF STMTS. COVERED" from dual;
SELECT (:A2/:A1*100) AS "CODE COVERAGE PERCENTAGE" from dual;

SELECT s.line line,
DECODE(p.occured,0,'<FONT color=#FF00Ff>'||substr(s.text,1,length(s.text)-1)||'</FONT>',s.text) text
FROM (SELECT d.TOTAL_OCCUR occured,
u.unit_type,
d.line#
FROM plsql_profiler_units u,
plsql_profiler_data d
WHERE d.RUNID = u.runid
AND d.UNIT_NUMBER = u.unit_number
--AND d.TOTAL_OCCUR > 0
AND u.runid = :A3
AND u.unit_name = :A5) p,
user_source s
WHERE p.line#(+) = NVL (s.line, NULL)
AND p.unit_type(+) = NVL (s.TYPE, NULL)
AND s.NAME = :A5
ORDER BY s.TYPE,
s.NAME,
s.line
/

SPOOL OFF
SET VERIFY ON FEEDBACK ON
EXIT
--------------------------------------------------------

And cc.bat <contents below>
--------------------------------------------------------
sqlplusw scott/tiger@dev @code_coverage.sql 1 Package_Name
--------------------------------------------------------

This works fine except for one problem.
Suppose I have a FOR LOOP and if the control doesn't go inside the loop then the last statement inside the LOOP will be shown as executed. Also if the control never goes into exception block still the last statement in the exception block is shown as having being executed.
I have checked with the entries in plsql_profiler_data table there also these two particular lines are having TOTAL_OCCUR column > 0.

Is this a bug in DBMS_PROFILER package ?

Thanks
Sudhanshu


Tom Kyte
June 07, 2004 - 8:19 am UTC

I would say "probably not". Just a nuance of the way plsql is jumping over blocks of code.

profiler report didn't show dbms_output name

Sean, July 13, 2004 - 12:08 pm UTC

Hi Tom.

I am running dbms_profiler example on your "expert" book. My report didn't show "dbms_output" name, instead it shows "anonymous" (Oracle902 on Window 2000). Here is the part of the report:

====================
Percentage of time in each module, for each run separately

RUNID RUN_COMMENT UNIT_OWNER UNIT_NAME SECS PERCEN
----- ----------- ----------- -------------- ------- ------
1 factorial SCOTT FACT_RECURSIVE 3.60 92.5
recursive

1 factorial <anonymous> <anonymous> .09 2.4
recursive

1 factorial <anonymous> <anonymous> .07 1.7
recursive

1 factorial <anonymous> <anonymous> .06 1.6
recursive

RUNID RUN_COMMENT UNIT_OWNER UNIT_NAME SECS PERCEN
----- ----------- ----------- -------------- ------- ------

1 factorial <anonymous> <anonymous> .04 1.1
recursive


Thanks so much for your help.






Tom Kyte
July 13, 2004 - 12:31 pm UTC

in order to trace code owned by others, you need the privilege to do so, it just didn't trace the dbms_output stuff here -- you did not have the privs to do so.

the anonymous is the anonymous blocks we must execute in order to run code in the first place.

One Clarification

Muhammad Riaz Shahid, December 17, 2004 - 8:22 pm UTC

Hello Tom !

here is my scenerio:

we have two db servers (say db1 and db2). on db1, there is a function called channel_selection on db1.

desc channel_selection
FUNCTION channel_selection RETURNS VARCHAR2
Argument Name Type In/Out Default?
------------------------------ ----------------------- ----
P_CL_NO VARCHAR2 IN
P_R_NO VARCHAR2 IN

The user at db2 is issuing command like :

declare
chan varchar2(1);
begin
chan:=channel_selection@DbLinkToDb1(:Val1,:Val2);
if chan='A' then
-- do some update and insert oprations
elsif chan='B'
then
-- do some update and insert oprations
else null;
end if;
commit;
end;

But when we execute this code, we are getting :

ORA-02064: distributed operation not supported

Db1 is running on Oracle 8i (Windoze 2000) and Db2 is running on Oracle 7.3 (IBM AIX).

Note that the function channel_selection on db1 doens't contain any update/insert/delete, just select's.

Whats your expert opinion about that ???

Tom Kyte
December 18, 2004 - 8:47 am UTC

and this relates to dbms_profiler how?

Clarification

Muhammad Riaz Shahid, December 21, 2004 - 12:44 am UTC

Question 1 was:

Ques1. I am executing a package which calls another package(thru DB link) which
is in different instance. It was working fine but suddenly now I started getting
this error below-

ORA-02064: distributed operation not supported
ORA-06512: at "SCPEP.NDP_CON", line 145

Isn't that relates to that ???

But anyhow, i've solved the problem. There was nothing wrong at remote side (db2). The function was calling a procedure in-between processing which contained a commit statement so it was not allowing us to run that function. I made that procedure to use Autonomous Function and all was ok.

Thanks again ...

Tom Kyte
December 21, 2004 - 8:42 am UTC



my question was -- what did your question about distributed transactions have to do with a question about dbms_profiler?

how to profile on schema(user).

Mehroz, April 26, 2005 - 11:22 pm UTC

I am new to oracle10g, I there a way to create a profile a schema to know how many application are connected and how long it is taking to exec objects etc. I like to so something similar to MS-SQL server profiler(we are moving to oracle bear with me).

Regards
Mehroz

Tom Kyte
April 27, 2005 - 7:46 am UTC

There is a ton of stuff. dbconsole (the home page for the database) contains a wealth of information. and for application tracing, sql_trace rules.

</code> http://otn.oracle.com/pls/db10g/portal.portal_demo3?selected=3 
are all of the 10g books, you probably want to read

A) the CONCEPTS guide, you will never be sorry you did, trust me

B) the application developers guide (when you have time)

C)
http://otn.oracle.com/pls/db10g/portal.portal_demo3?selected=3 <code> The performance tuning guide for details on what you can do with trace and other tools

profrep.sql

A reader, July 06, 2005 - 12:29 am UTC

Tom

In 10g I cannot find the profrep.sql script in the rdbms directory? Help

Help with DBMS_PROFILER

A reader, November 09, 2005 - 4:30 pm UTC

when I run the profsum.sql, I am getting no results.
Just zeros all the way through the report.

What am I doing wrong?

I put the dbms_profiler.start_profiler(run_comment=>'..');
and dbms_profiler.stop_profiler;
statements in one of the procedures that gets called when I run another procedure.

Tom Kyte
November 11, 2005 - 10:27 am UTC

give example. show cut and paste from sqlplus with example code and show what you mean by all zeroes?

this is one I use to demonstrate this feature:

set echo on
clear screen
create or replace procedure do_something
as
l_x number := 0;
begin
for i in 1 .. 100
loop
l_x := l_x + 1;
end loop;
end;
/
pause

clear screen
create or replace
function fact_recursive( n int ) return number
as
begin
if ( n = 1 )
then
return 1;
else
if ( mod(n,3) = 0 )
then
do_something;
end if;
return n * fact_recursive(n-1);
end if;
end;
/
pause

clear screen
create or replace
function fact_iterative( n int ) return number
as
l_result number default 1;
begin
for i in 2 .. n
loop
if ( mod(i,3) = 0 )
then
do_something;
end if;
l_result := l_result * i;
end loop;
return l_result;
end;
/
pause

clear screen
set serveroutput off
exec dbms_profiler.start_profiler( 'factorial recursive' )
begin
for i in 1 .. 100 loop
dbms_output.put_line( fact_recursive(50) );
end loop;
end;
/
exec dbms_profiler.stop_profiler
exec dbms_profiler.start_profiler( 'factorial iterative' )
begin
for i in 1 .. 100 loop
dbms_output.put_line( fact_iterative(50) );
end loop;
end;
exec dbms_profiler.stop_profiler
set serveroutput on size 1000000
pause

@profsum


DBMS_PROFILER

Reader, January 11, 2006 - 7:40 am UTC

In addition to dbms_profiler do we have anything else to trace a plsql package ?

Thanks

Tom Kyte
January 12, 2006 - 10:25 am UTC

what do you want to trace exactly - there is the profiler for source code level, there is sql_trace for the sql, there is dbms_trace to trace many things (exceptions, and such)

profsum jsut for a runid?

Eduardo Reis, January 19, 2006 - 1:15 pm UTC

This thread help me a lot on my work, thanks.
Just for curiosity, there is a profsum version to only display one runid?

Tom Kyte
January 19, 2006 - 1:55 pm UTC

no, i never trimmed it down to that, pretty simple script though..

Giving errors (DBMS_PROFILE)

Nikhil, November 30, 2006 - 4:04 am UTC

Tom,
Iam working on 10g and I did the following:

Connect as SYS
Ran the script profload.sql
Ran the script proftab.SQL

I suppose 10g does not have profrep.sql, I assume the equivalent is profsum.sql (I took this from your earlier posting).

Ran the following script:

create or replace procedure do_mod as
cnt number := 0;
begin
dbms_profiler.start_profiler( 'mod' );
for i in 1 .. 500000
loop
cnt := cnt + 1;
if ( mod(cnt,1000) = 0 )
then
commit;
end if;
end loop;
dbms_profiler.stop_profiler;
end;
/

When I try to execute the profsum.sql it shows the error:

ERROR at line 1:
ORA-06550: line 1, column 7:
PLS-00201: identifier 'PROF_REPORT_UTILITIES.ROLLUP_ALL_RUNS' must be declared
ORA-06550: line 1, column 7:
PL/SQL: Statement ignored

Am I missing something? Please let me know.



Tom Kyte
November 30, 2006 - 9:56 am UTC

the other scripts are in the demo directories (to be loaded from the companion cd)



you'll need them, that is where the package you are trying to run is

Question on DBMS_PROFILER

Mark, April 18, 2007 - 12:42 pm UTC

set serveroutput on

DECLARE
l_result BINARY_INTEGER;
l_run NUMBER;
BEGIN
l_result := DBMS_PROFILER.start_profiler(run_comment => 'do_something: ' || SYSDATE);
do_something;
l_result := DBMS_PROFILER.stop_profiler;
select plsql_profiler_runnumber.currval into l_run FROM DUAL;
dbms_output.put_line(l_result);
dbms_output.put_line(l_run);
END;

If do_something calls Proc_A and which in turn calls Proc_B then how I do the profiling for these procedures?

When I execute the following query, I cannot see the timings of Proc_A and Proc_B.

select s.line "Line", p.total_occur "Occur", p.total_time "Msec", s.text "Text"
from all_source s, (select u.unit_owner, u.unit_name,
u.unit_type, d.line#, d.total_occur,
d.total_time/1000000 total_time
from plsql_profiler_data d,
plsql_profiler_units u
where u.runid = 5
and u.runid = d.runid
and u.unit_number = d.unit_number) p
where s.owner = p.unit_owner (+)
and s.name = p.unit_name (+)
and s.type = p.unit_type (+)
and s.line = p.line# (+)
and s.name = 'DO_SOMETHING'
and s.owner = 'USER'
order by s.line;

Thanks

Tom Kyte
April 18, 2007 - 1:01 pm UTC 

create or replace procedure proc_b
as
    x number := 0;
begin
    for i in 1 .. 100
    loop
        x := x+1;
    end loop;
end;
/
create or replace procedure proc_a
as
    x number := 0;
begin
    for i in 1 .. 100
    loop
        x := x+1;
    end loop;
    proc_b;
end;
/
create or replace procedure do_something
as
    l_x    number := 0;
begin
    for i in 1 .. 100
    loop
        l_x := l_x + 1;
    end loop;
    proc_a;
end;
/
pause

clear screen
create or replace
function fact_recursive( n int ) return number
as
begin
        if ( n = 1 )
        then
            return 1;
        else
            if ( mod(n,3) = 0 )
            then
                do_something;
            end if;
            return n * fact_recursive(n-1);
        end if;
end;
/
pause

clear screen
create or replace
function fact_iterative( n int ) return number
as
        l_result number default 1;
begin
        for i in 2 .. n
        loop
            if ( mod(i,3) = 0 )
            then
                do_something;
            end if;
            l_result := l_result * i;
        end loop;
        return l_result;
end;
/
pause

clear screen
set serveroutput off
exec dbms_profiler.start_profiler( 'factorial recursive' )
begin
    for i in 1 .. 100 loop
        dbms_output.put_line( fact_recursive(50) );
    end loop;
end;
/
exec dbms_profiler.stop_profiler
exec dbms_profiler.start_profiler( 'factorial iterative' )
begin
    for i in 1 .. 100 loop
        dbms_output.put_line( fact_iterative(50) );
    end loop;
end;
/
exec dbms_profiler.stop_profiler
set serveroutput on size 1000000
pause

@profsum


i did that and saw the proc_a proc_b stuff - like this:


====================
Percentage of time in each module, for each run separately

RUNID RUN_COMMENT UNIT_OWNER  UNIT_NAME         SECS PERCEN
----- ----------- ----------- -------------- ------- ------
    1 factorial   OPS$TKYTE   DO_SOMETHING       .21   32.1
      recursive

    1 factorial   OPS$TKYTE   PROC_A             .21   31.7
      recursive

    1 factorial   OPS$TKYTE   PROC_B             .21   31.6
      recursive

    1 factorial   OPS$TKYTE   FACT_RECURSIVE     .03    4.5
      recursive

    2 factorial   OPS$TKYTE   PROC_A             .21   32.8
      iterative

    2 factorial   OPS$TKYTE   DO_SOMETHING       .21   32.7
      iterative

    2 factorial   OPS$TKYTE   PROC_B             .20   31.7
      iterative

    2 factorial   OPS$TKYTE   FACT_ITERATIVE     .02    2.8
      iterative


8 rows selected.

Thanks

Mark, April 19, 2007 - 9:25 am UTC

Hello Tom,
Thanks for the reply. Think so I don't have execute permission on prof_report_utilities.rollup_all_runs.

Timings related to remotely called procedures are not inserted in plsql_profiler_data table if the procedures are remote calls.

Am I missing something or is this the way?
Tom Kyte
April 19, 2007 - 9:51 am UTC

I did not follow this thought here....

"think so I don't have execute permission" - could not understand that.

missing what? if you call a remote procedure (first mention that it, well, would be a remote procedure - that would be useful to know from step one), the remote procedure would be executed remotely and wouldn't really be able to insert into your local database - so no, the remote code would not write locally.

dbms_profiler in a connection pool setup

Gokul Kumar, September 27, 2008 - 7:39 pm UTC

Hi Tom,

If the application uses connection pooling, is it possible to use dbms_profiler ?

If yes, how to differentiate the runs in the system tables ?

Rgds,
Gokul
Tom Kyte
September 28, 2008 - 10:22 am UTC

you name the runs yourself. when you invoke the start/stop

dbms_profiler and memory leakage

Nenad, February 24, 2009 - 1:11 pm UTC

Hi Tom,

I hope that my question is in the context of this post:

We have a long running job which causes memory leaking. In order to find which part of the job is causing this, I would have to profile each "unit" of our code and capture pga_used_mem from v$process before and after execution.

Can I monitor memory consumption within my session using DBMS_PROFILER?

Thanks,
Nenad
Tom Kyte
February 24, 2009 - 5:13 pm UTC

the profiler does not record memory usage.

dbms_profiler and memory leakage

Nenad, February 25, 2009 - 6:08 am UTC

Would you recommend using column SPARE1 to save capture the memory usage:

CREATE OR REPLACE TRIGGER bri_prof_memory
BEFORE INSERT
ON plsql_profiler_data
REFERENCING NEW AS NEW OLD AS OLD
FOR EACH ROW
DECLARE
v_used_mem NUMBER;
BEGIN
SELECT p.pga_used_mem
INTO v_used_mem
FROM SYS.v_$process p, SYS.v_$session s
WHERE p.addr = s.paddr AND s.audsid = USERENV ('sessionid');

:new.spare1:=v_used_mem;

END bri_prof_memory;
Tom Kyte
February 25, 2009 - 7:10 am UTC

I would not, no. You would not want to put a plsql trigger on a table that is being used to profile plsql performance - it could be a disaster.

I am very very much into instrumenting code, might be a motivator for you to instrument YOUR code - on entry and exit points - then you can collect *anything* you want.

do you believe this memory leak to be "oracle memory leak" or "our plsql program is allocating lots of stuff in global variables that are tables and is leaking memory" - can you describe what you are looking for?

dbms_profiler and memory leakage

Nenad, February 25, 2009 - 11:52 am UTC

Many thanks , Tom.

The code was originally deployed on Oracle9i Enterprise Edition Release 9.2.0.4.0. To put it simple, the package reads a XML message from AQ, parses the XML using XDK and "instead of" trigger on a object view, performs complex business logic within the trigger and saves data to the underling tables.

As you suggested, I will have to implement the code instrumentation on entry/exit points. Just wanted to use shortcut. It would be useful if oracle implements memory usage monitoring within its profiler in future releases.

Thanks again.
Nenad
Tom Kyte
February 25, 2009 - 6:12 pm UTC

if you believe this to be an oracle memory, please utilize support (it is not clear what you believe this to be - I was just trying to get that). Support can in fact help you enable tracing events to track this down if you believe it is internal to Oracle and not in your code.

Another schema executing procedure having start/stop profiler

ora dev, January 07, 2010 - 12:14 pm UTC

Tom,
I have two issues when using DBMS_PROFILER mostly I believe because the package is based on invokers rights. Can you please throw light on these and show any alternative way to achieve the below objectives?

Issue 1:
I have a procedure like this in schema a1:

create or replace procedure proftest
is
 v_runnumber number;
 a number;
 b number := 0;
begin
  dbms_profiler.START_PROFILER('a','b',v_runnumber);
  for i in 1..30 loop
     a := a+ 1;
     a := (b+ a + 1)/30;   
  end loop;

  dbms_profiler.STOP_PROFILER;
  
  dbms_output.put_line('runnumber is ' || v_runnumber);

end proftest;
/


grant execute,debug on proftest to a2;

After connecting to a2 when proftest procedure is executed, the profiler runid is generated but there are no records in plsql_profiler_data table for that runid.

Issue 2:

In any procedure between dbms_profiler.START_PROFILER and dbms_profiler.STOP_PROFILER if there is call to procedure that is owned by another schema then the lines of that procedure are not profiled.

Appreciate your time on this and expert advice. Thank you.


can you please follow up on question asked above?

ora dev, February 14, 2010 - 1:55 pm UTC

I have not received follow up on question asked above. Is it due to:
1) Question not relevant to the original post? If so I will wait to post it as a fresh question.
2) There are no alternatives to those issues? If so then can it be called limitation of Oracle's implementation of dbms_profiler?
3) Something else?
Tom Kyte
February 16, 2010 - 12:57 pm UTC

if I cannot answer something immediately (given constraints like I'm sitting in an airport or whatever, without immediate access to lots of my resources) I skip it and I never come back to old one (I work with a FIFO - first in, first out - queue).

so, I just very quickly glanced at the documentation for this package, clicked on "security model" and found this:

http://docs.oracle.com/docs/cd/B19306_01/appdev.102/b14258/d_profil.htm#i999855

compile it with debug.

A reader, February 17, 2010 - 4:12 am UTC

Tom this may be most basic or stupid question on your site. DBMS_Profiler is used when we are optimizing the code or should it be part of every procedure? I have seen some of your links for code instrumentaion but could not grasp it how to implement in my development, can you please provide step by step instruction and their use in development.
Tom Kyte
February 17, 2010 - 9:16 am UTC

profiling is typically done to squeeze the last 0.N% out of the code - for tuning done after all of the other stuff is done, to analyze where you spend most of your time and where you should therefore spend you time fine tuning.

dbms_profiler for java

KG, March 11, 2011 - 5:50 am UTC

Hi Tom
Can i use the profiler in plsql calling Java stored in database .
We have a situation where sometime java code takes longer to execute where in database it doesnt show what exactly its waiting on .
AWR/ASH shows shows higher % of java activity and nothing beyond that
Tom Kyte
March 11, 2011 - 7:38 am UTC

The plsql profiler only profiles plsql code, sorry.

How do i profile java

KG, March 11, 2011 - 1:06 pm UTC

Tom
How do i profile java code then?
ASH shows Java execution activity like below

Phase of Execution % Activity Avg Active Sessions
SQL Execution 96.22 2.40
Java Execution 27.08 0.68
PLSQL RPC 3.19 0.08
Parse 1.78 0.04
Hard Parse 1.63 0.04

Went through oracle java developers guide and metalink ,not much of information is available.
On web some tools are mentioned but not sure that can be used

Guide for correct approach
Tom Kyte
March 11, 2011 - 3:36 pm UTC

No idea, I don't put very much java into my database. You'd have to ask a java developer if there is anything in the language that permits native profiling.

NP

KG, March 13, 2011 - 10:07 am UTC

Developer is not aware himself. Whenever it takes longer time to run he thinks issue with database .
I check v$session_Event if its been waiting on something for long ,but they dont show longer waits .
Anyways No issues Tom.Thanks for all help

PL/SQL Code coverage

Lal, July 30, 2012 - 12:10 am UTC

Tom,

For getting the code coverage of a PL/SQL we need to use the dbms_profiler package.
Is there a way where i can enable the dbms_profiler at the database level using some parameter?.

Requirement is to capture the code coverage of PL/SQL procedures from our test environment,
when the testers test the application. Application uses J2EE and connection pooling.

One of the solutions i got is to use a logon and logoff trigger where i can invoke the dbms_profiler start and stop
procedures for each connection.

But my doubt is will this approach work when using connection pooling?
Any other options to achieve this?

Thanks always for your precious time.
Tom Kyte
July 30, 2012 - 12:02 pm UTC

it would work for a connection pool - the connection pool would start a connection - and the trigger would fire - and the profiling would start, until the connection pool closes that connection

Profiling package from a different schema

Binish, August 17, 2012 - 4:30 am UTC

Tom,

I tried to profile a package from a different schema having execute privilege on the package.

As shown in following code

CONNECT DEVPROCS/DEVPROCS@orcl

grant execute, debug on PKG_INTERFACE to DEVUSER;
alter package PKG_INTERFACE compile debug;
alter package PKG_INTERFACE compile debug body;

CONNECT DEVUSER/DEVUSER@orcl
SET SERVEROUT ON
DECLARE

p1 VARCHAR2(20);
return_flag VARCHAR2(20);

BEGIN

DBMS_PROFILER.START_PROFILER();
PKG_INTERFACE.GET_DATA('ab','x',p1,return_flag);
DBMS_OUTPUT.put_line('data: '||p1);
DBMS_PROFILER.STOP_PROFILER;

END;
/

This collects the profiler data of the anonymous block only in the PL\SQL profiler tables. The package data is not shown.
Any suggestions ? Please help

Details do not account for total runtime

Matthew McPeak, March 05, 2013 - 11:30 am UTC 

Tom,

Can you explain this?

<code>
select r.runid, r.run_total_time / power(10,9), ( SELECT sum(total_time) FROM plsql_profiler_data d WHERE d.runid = r.runid )/power(10,9) detail_total_time
from plsql_profiler_runs r
where r.runid = 62

RUNID                                  R.RUN_TOTAL_TIME/POWER(10,9)           DETAIL_TOTAL_TIME                      
-------------------------------------- -------------------------------------- -------------------------------------- 
                                    62                           16.311999999                            4.729814291


I use DBMS_PROFILER all the time, but recently, for one package, I am in a situation where the detail data does not account for anything close to the actual run time.

Thanks in advance!

matt

</code>
Tom Kyte
March 05, 2013 - 1:19 pm UTC

give me an example to reproduce with please.

How?

Matthew McPeak, March 05, 2013 - 3:10 pm UTC

How do you recommend I do that? I tried a few small examples, but they don't reproduce the problem -- for those examples, the total time from PLSQL_PROFILER_DATA is pretty complete.

To reproduce the actual problem, you'd need my application and data, which is extensive (Oracle e-BS Suite plus custom extensions).

On a related note, I know that DBMS_LOCK.SLEEP() will count in the total run time but won't show in PLSQL_PROFILER_DATA. Are there other things like that? Would it be any package that I don't have CREATE PRIVILEGE on? And, if so, if I give myself CREATE ANY PACKAGE will that ensure that I see *everything*?

Thanks!
Matt
Tom Kyte
March 06, 2013 - 11:02 am UTC

are all units "profiled" from top to bottom, is every bit of code involved part of the profile?

if every bit of code is not profiled, you'll have aggregate mismatches - timing at the aggregate level would be accurate, whereas the sum of the details would be misleading.

Try the hierarchical profiler...

Brendan, March 06, 2013 - 11:40 am UTC

Matthew,

If you are on v11 you should probably switch to DBMS_HProf. I've not used the old profiler, but from using the newer hierarchical profiler recently, I don't believe the issue you report with DBMS_Lock occurs; also, it looks to be a lot better generally, and is quite easy to use. From the advanced app developer's guide ( http://docs.oracle.com/cd/E11882_01/appdev.112/e25518.pdf ):

'The PL/SQL hierarchical profiler:
■ Reports the dynamic execution profile of your PL/SQL program, organized by subprogram calls
■ Accounts for SQL and PL/SQL execution times separately
■ Requires no special source or compile-time preparation'

I don't think there are pauses

Matthew McPeak, March 06, 2013 - 11:47 am UTC 

Do you mean: do I call PAUSE_PROFILER and RESUME_PROFILER anywhere?  I do not.

There is a call the START_PROFILER at the beginning and STOP_PROFILER at the end. 

Here is the script I use for testing.

<code>
DECLARE
  l_result_code   VARCHAR2 (1);
  l_msg_data      VARCHAR2 (4000);
  l_item_count    NUMBER := 0;

  -- Variables for PL/SQL profiler
  b_profile       BOOLEAN := TRUE;
  x_rc            BINARY_INTEGER;
  x_run_number    BINARY_INTEGER;
  
  l_record_count NUMBER;
BEGIN
  -- Start PL/SQL profiler
  IF b_profile THEN
    x_rc   := DBMS_PROFILER.start_profiler (run_comment => 'Matt Test', run_comment1 => 'No comment', run_number => x_run_number);
  END IF;

  prts_perf_util_pkg.start_timing ('EXTRACT_TOTAL');

  FOR r
    IN (SELECT   mi.stars_model_item_id,
                 mi.rm_item_number,
                 p.port_code,
                 p.port_name
        FROM     verp_vps_active_ports_v p CROSS JOIN verp_vps_model_items mi
        inner join matt_sde_test_pool p on p.model_item_id = mi.stars_model_item_id
        WHERE        mi.production_source = p.production_source
                 AND p.labor_process_org = 'Y'
                 AND mi.stars_model_item_id IS NOT NULL --                 AND mi.rm_item_number = 'DDD-02-F-WHI'
                 AND mi.model_year IN ('2013.0') --, '2014.0')
                 -- Exclude "F" spec imports, since these don't have data and make our timing results
                 -- look better than they are.
                 AND NOT (mi.production_source = 'J' AND mi.spec_code = 'F')
--                 AND mi.model_code = 'DDF'
--                 and mi.spec_code = 'C'
and p.vpn_count >= 50
        ORDER BY DBMS_RANDOM.VALUE, mi.rm_item_number, p.port_code) LOOP
    EXIT WHEN l_item_count >= 1;
    l_item_count   := l_item_count + 1;
    prts_perf_util_pkg.start_timing ('EXTRACT_MOSC_PORT');

    -- Peg only
    verp_vps_supply_extract_pkg.extract_supply_and_demand (p_model_item_id               => r.stars_model_item_id, --5648928,
                                                           p_port_code                   => r.port_code,
                                                           p_extract_supply_flag         => 'Y',
                                                           p_extract_stars_demand_flag   => 'Y',
                                                           p_extract_sam_demand_flag     => 'Y',
                                                           p_extract_dqm_demand_flag     => 'Y',
                                                           p_extract_maui_demand_flag    => 'Y',
                                                           p_extract_allo_demand_flag    => 'Y',
                                                           p_extract_other_demand_flag   => 'Y',
                                                           p_repeg_supply_and_demand_flag => 'Y',
                                                           x_result_code                 => l_result_code,
                                                           x_msg_data                    => l_msg_data);
                                                           

--  verp_vps_supply_extract_pkg.match_supply_demand (p_model_item_id => r.stars_model_item_id, p_port_code => r.port_code, x_rowcount => l_record_count);
                                                           

    prts_perf_util_pkg.stop_timing ('EXTRACT_MOSC_PORT');
    DBMS_OUTPUT.put_line (
      l_msg_data || ', ' || l_result_code || ' [' || prts_perf_util_pkg.get_timing ('EXTRACT_MOSC_PORT') || ']');
  END LOOP;

  prts_perf_util_pkg.stop_timing ('EXTRACT_TOTAL');
  DBMS_OUTPUT.put_line ('Total: ' || l_item_count || ' items refreshed in ' || prts_perf_util_pkg.get_timing ('EXTRACT_TOTAL'));

  -- End PL/SQL Profiler
  IF b_profile THEN
    x_rc   := DBMS_PROFILER.stop_profiler;
    DBMS_OUTPUT.put_line ('PL/SQL Profiler Run Number = ' || x_run_number);
  END IF;
END;
</code>
Tom Kyte
March 06, 2013 - 1:59 pm UTC

I was asking if the code you are running is code you can profile:

http://docs.oracle.com/cd/B19306_01/appdev.102/b14258/d_profil.htm#i999855

for the reason you cannot "see" dbms_lock, you might be missing "other stuff" as well.

missing create capability
using native compiled code


I think everything should be profile-able

Matthew McPeak, March 06, 2013 - 3:47 pm UTC 

Here is a query and report from DBA_DEPENDENCIES on the code I am trying to profile.  I am running as user "APPS".

<code>
select dd.referenced_owner || '.' || dd.referenced_name || ' (' || dd.referenced_type || ')' referenced_object, plos.plsql_optimize_level, plos.plsql_code_type, plos.plsql_debug from dba_dependencies dd left join DBA_PLSQL_OBJECT_SETTINGS plos on plos.owner = dd.referenced_owner and plos.name = dd.referenced_name and plos.type = dd.referenced_type
where dd.owner = 'APPS'
and dd.name = 'VERP_VPS_SUPPLY_EXTRACT_PKG'
and dd.type = 'PACKAGE BODY'
and dd.referenced_type not in ('SYNONYM','VIEW')




SYS.STANDARD (PACKAGE)                     2 INTERPRETED FALSE
APPS.FND_GLOBAL (PACKAGE)                  2 INTERPRETED FALSE
APPS.FND_API (PACKAGE)                     2 INTERPRETED FALSE
APPS.DUAL (NON-EXISTENT)                                      
APPS.PLITBLM (NON-EXISTENT)                                   
APPS.DBMS_LOCK (NON-EXISTENT)                                 
APPS.DBMS_APPLICATION_INFO (NON-EXISTENT)                     
APPS.DBMS_RANDOM (NON-EXISTENT)                               
APPS.VERP_FND_UTILITY_PKG (PACKAGE)        2 INTERPRETED FALSE
APPS.PRTS_PERF_UTIL_PKG (PACKAGE)          2 INTERPRETED FALSE
APPS.VERP_OTM_DEALER_PORTS (NON-EXISTENT)                     
APPS.VERP_DLR_HIER_UTIL_PKG (PACKAGE)      2 INTERPRETED FALSE
APPS.VERP_VPS_LOCK_PKG (PACKAGE)           2 INTERPRETED FALSE
APPS.VERP_VPS_SUPPLY_EXTRACT_PKG (PACKAGE) 2 INTERPRETED FALSE
</code>
Tom Kyte
March 07, 2013 - 8:57 am UTC

you'd need to write a connect by query to get the dependency tree.

to see if apps.x calls apps.y which calls foo.bar which calls bar.foo

CONNECT BY version

Matthew McPeak, March 08, 2013 - 1:41 pm UTC 

Here it is.  Thanks for your help so far!

<code>
WITH dd AS
       (SELECT /*+ MATERIALIZE */
              LPAD    (' ', LEVEL * 2, ' ')
                   || dd.referenced_owner
                   || '.'
                   || dd.referenced_name
                   || ' ('
                   || dd.referenced_type
                   || ')'
                     referenced_object,
                   dd.referenced_type,
                   dd.referenced_name,
                   dd.referenced_owner,
                   rownum rn
        FROM       dba_dependencies dd
--      WHERE      referenced_type NOT IN ('TABLE', 'SYNONYM')
        CONNECT BY name = PRIOR referenced_name AND owner = PRIOR referenced_owner AND TYPE = PRIOR referenced_type
        START WITH name = 'VERP_VPS_SUPPLY_EXTRACT_PKG' AND TYPE = 'PACKAGE BODY' AND owner = 'APPS')
SELECT dd.referenced_object,
       plos.plsql_optimize_level,
       plos.plsql_code_type,
       plos.plsql_debug
FROM     dd
       LEFT JOIN
         dba_plsql_object_settings plos
       ON plos.owner = dd.referenced_owner AND plos.name = dd.referenced_name AND plos.TYPE = dd.referenced_type
ORDER BY dd.rn       


  APPS.DBMS_LOCK (NON-EXISTENT)                                       
  PUBLIC.DBMS_LOCK (SYNONYM)                                          
    SYS.DBMS_LOCK (PACKAGE)                        2 INTERPRETED FALSE
      SYS.STANDARD (PACKAGE)                       2 INTERPRETED FALSE
  APPS.DBMS_RANDOM (NON-EXISTENT)                                     
  PUBLIC.DBMS_RANDOM (SYNONYM)                                        
    SYS.DBMS_RANDOM (PACKAGE)                      2 INTERPRETED FALSE
      SYS.STANDARD (PACKAGE)                       2 INTERPRETED FALSE
  APPS.DUAL (NON-EXISTENT)                                            
  PUBLIC.DUAL (SYNONYM)                                               
    SYS.DUAL (TABLE)                                                  
  APPS.FND_API (PACKAGE)                           2 INTERPRETED FALSE
    SYS.STANDARD (PACKAGE)                         2 INTERPRETED FALSE
  APPS.FND_FLEX_VALUES (SYNONYM)                                      
    APPLSYS.FND_FLEX_VALUES (TABLE)                                   
  APPS.FND_FLEX_VALUES_DFV (VIEW)                                     
    APPS.FND_FLEX_VALUES (SYNONYM)                                    
      APPLSYS.FND_FLEX_VALUES (TABLE)                                 
    APPS.FND_NUMBER (PACKAGE)                      2 INTERPRETED FALSE
      SYS.STANDARD (PACKAGE)                       2 INTERPRETED FALSE
  APPS.FND_FLEX_VALUE_SETS (SYNONYM)                                  
    APPLSYS.FND_FLEX_VALUE_SETS (TABLE)                               
  APPS.FND_GLOBAL (PACKAGE)                        2 INTERPRETED FALSE
    APPS.FND_CONST (PACKAGE)                       2 INTERPRETED FALSE
      SYS.STANDARD (PACKAGE)                       2 INTERPRETED FALSE
    SYS.STANDARD (PACKAGE)                         2 INTERPRETED FALSE
  APPS.PLITBLM (NON-EXISTENT)                                         
  PUBLIC.PLITBLM (SYNONYM)                                            
    SYS.PLITBLM (PACKAGE)                          2 INTERPRETED FALSE
      SYS.STANDARD (PACKAGE)                       2 INTERPRETED FALSE
  APPS.SPF_DEBUG (SYNONYM)                                            
    APPS.VERP_DOS_SPF_DEBUG_PKG (PACKAGE)          2 INTERPRETED FALSE
      SYS.STANDARD (PACKAGE)                       2 INTERPRETED FALSE
  SYS.STANDARD (PACKAGE)                           2 INTERPRETED FALSE
  APPS.VERP_DLR_HIER_UTIL_PKG (PACKAGE)            2 INTERPRETED FALSE
    SYS.STANDARD (PACKAGE)                         2 INTERPRETED FALSE
  APPS.VERP_DOS_VEHICLES (SYNONYM)                                    
    VERPCUST.VERP_DOS_VEHICLES (TABLE)                                
  APPS.VERP_OTM_DEALER_PORTS (NON-EXISTENT)                           
  PUBLIC.VERP_OTM_DEALER_PORTS (SYNONYM)                              
    VERPCUST.VERP_OTM_DEALER_PORTS (TABLE)                            
  APPS.VERP_VPS_ALLO_CTRL_NATIONAL (SYNONYM)                          
    VERPCUST.VERP_VPS_ALLO_CTRL_NATIONAL (TABLE)                      
  APPS.VERP_VPS_DEMANDED_UNITS (SYNONYM)                              
    VERPCUST.VERP_VPS_DEMANDED_UNITS (TABLE)                          
  APPS.VERP_VPS_DEMANDED_UNITS_S (SYNONYM)                            
    VERPCUST.VERP_VPS_DEMANDED_UNITS_S (SEQUENCE)                     
  APPS.VERP_VPS_DEMAND_PRIORITY_V (VIEW)                              
    APPS.FND_FLEX_VALUES (SYNONYM)                                    
      APPLSYS.FND_FLEX_VALUES (TABLE)                                 
    APPS.FND_FLEX_VALUES_DFV (VIEW)                                   
      APPS.FND_FLEX_VALUES (SYNONYM)                                  
        APPLSYS.FND_FLEX_VALUES (TABLE)                               
      APPS.FND_NUMBER (PACKAGE)                    2 INTERPRETED FALSE
        SYS.STANDARD (PACKAGE)                     2 INTERPRETED FALSE
    APPS.FND_FLEX_VALUE_SETS (SYNONYM)                                
      APPLSYS.FND_FLEX_VALUE_SETS (TABLE)                             
    APPS.FND_NUMBER (PACKAGE)                      2 INTERPRETED FALSE
      SYS.STANDARD (PACKAGE)                       2 INTERPRETED FALSE
    APPS.VERP_DLR_HIER_UTIL_PKG (PACKAGE)          2 INTERPRETED FALSE
      SYS.STANDARD (PACKAGE)                       2 INTERPRETED FALSE
    APPS.VERP_VPS_DEMANDED_UNITS (SYNONYM)                            
      VERPCUST.VERP_VPS_DEMANDED_UNITS (TABLE)                        
  APPS.VERP_VPS_LOCK_PKG (PACKAGE)                 2 INTERPRETED FALSE
    SYS.STANDARD (PACKAGE)                         2 INTERPRETED FALSE
  APPS.VERP_VPS_MASTER_SCHEDULES (SYNONYM)                            
    VERPCUST.VERP_VPS_MASTER_SCHEDULES (TABLE)                        
  APPS.VERP_VPS_MODEL_ITEMS (SYNONYM)                                 
    VERPCUST.VERP_VPS_MODEL_ITEMS (TABLE)                             
  APPS.VERP_VPS_PEGGING_RUNS_S (SYNONYM)                              
    VERPCUST.VERP_VPS_PEGGING_RUNS_S (SEQUENCE)                       
  APPS.VERP_VPS_PO_HEADERS (SYNONYM)                                  
    VERPCUST.VERP_VPS_PO_HEADERS (TABLE)                              
  APPS.VERP_VPS_STARS_DEMAND_DETAIL_V (VIEW)                          
    APPS.DUAL (NON-EXISTENT)                                          
    PUBLIC.DUAL (SYNONYM)                                             
      SYS.DUAL (TABLE)                                                
    APPS.MTL_PARAMETERS (SYNONYM)                                     
      INV.MTL_PARAMETERS (TABLE)                                      
    APPS.OE_ORDER_HEADERS_ALL (SYNONYM)                               
      ONT.OE_ORDER_HEADERS_ALL (TABLE)                                
    APPS.OE_ORDER_HOLDS_ALL (SYNONYM)                                 
      ONT.OE_ORDER_HOLDS_ALL (TABLE)                                  
    APPS.OE_ORDER_LINES_ALL (SYNONYM)                                 
      ONT.OE_ORDER_LINES_ALL (TABLE)                                  
    APPS.OE_TRANSACTION_TYPES_TL (SYNONYM)                            
      ONT.OE_TRANSACTION_TYPES_TL (TABLE)                             
    APPS.SAM_ORDERS (SYNONYM)                                         
      VERPCUST.SAM_ORDERS (TABLE)                                     
    APPS.VERP_FND_UTILITY_PKG (PACKAGE)            2 INTERPRETED FALSE
      APPS.FND_API (PACKAGE)                       2 INTERPRETED FALSE
        SYS.STANDARD (PACKAGE)                     2 INTERPRETED FALSE
      SYS.STANDARD (PACKAGE)                       2 INTERPRETED FALSE
    APPS.VERP_OM_SOLD_ORDERS (SYNONYM)                                
      VERPCUST.VERP_OM_SOLD_ORDERS (TABLE)                            
    APPS.VERP_VIG_VEHICLES (SYNONYM)                                  
      VERPCUST.VERP_VIG_VEHICLES (TABLE)                              
    APPS.VERP_VPS_ALLO_CALENDAR_MV (TABLE)                            
    APPS.VERP_VPS_ALLO_CTRL_NATIONAL (SYNONYM)                        
      VERPCUST.VERP_VPS_ALLO_CTRL_NATIONAL (TABLE)                    
    APPS.VERP_VPS_DEALERS_MV (TABLE)                                  
    APPS.VERP_VPS_DEPLOYMENTS (SYNONYM)                               
      VERPCUST.VERP_VPS_DEPLOYMENTS (TABLE)                           
    APPS.VERP_VPS_MAUI_ACCOUNTS (SYNONYM)                             
      VERPCUST.VERP_VPS_MAUI_ACCOUNTS (TABLE)                         
    APPS.VERP_VPS_MAUI_QUANTITIES (SYNONYM)                           
      VERPCUST.VERP_VPS_MAUI_QUANTITIES (TABLE)                       
    APPS.VERP_VPS_MODEL_ITEMS (SYNONYM)                               
      VERPCUST.VERP_VPS_MODEL_ITEMS (TABLE)                           
  APPS.VERP_VPS_STARS_SUPPLY_DETAIL_V (VIEW)                          
    APPS.DUAL (NON-EXISTENT)                                          
    PUBLIC.DUAL (SYNONYM)                                             
      SYS.DUAL (TABLE)                                                
    APPS.FND_NUMBER (PACKAGE)                      2 INTERPRETED FALSE
      SYS.STANDARD (PACKAGE)                       2 INTERPRETED FALSE
    APPS.VERP_DOS_VEHICLES (SYNONYM)                                  
      VERPCUST.VERP_DOS_VEHICLES (TABLE)                              
    APPS.VERP_OM_VIN_STATUS_SUMMARY (NON-EXISTENT)                    
    PUBLIC.VERP_OM_VIN_STATUS_SUMMARY (SYNONYM)                       
      VERPCUST.VERP_OM_VIN_STATUS_SUMMARY (TABLE)                     
    APPS.VERP_VIG_PORTS (SYNONYM)                                     
      VERPCUST.VERP_VIG_PORTS (TABLE)                                 
    APPS.VERP_VIG_VEHICLES (SYNONYM)                                  
      VERPCUST.VERP_VIG_VEHICLES (TABLE)                              
    APPS.VERP_VIG_VESSEL_PORTS (SYNONYM)                              
      VERPCUST.VERP_VIG_VESSEL_PORTS (TABLE)                          
    PUBLIC.VERP_VPS_BOAT_LOAD_REQUESTS (SYNONYM)                      
      VERPCUST.VERP_VPS_BOAT_LOAD_REQUESTS (TABLE)                    
    APPS.VERP_VPS_MODEL_ITEMS (SYNONYM)                               
      VERPCUST.VERP_VPS_MODEL_ITEMS (TABLE)                           
    APPS.VERP_VPS_TRANSIT_TIMES_V (VIEW)                              
      APPS.FND_FLEX_VALUES (SYNONYM)                                  
        APPLSYS.FND_FLEX_VALUES (TABLE)                               
      APPS.FND_FLEX_VALUES_DFV (VIEW)                                 
        APPS.FND_FLEX_VALUES (SYNONYM)                                
          APPLSYS.FND_FLEX_VALUES (TABLE)                             
        APPS.FND_NUMBER (PACKAGE)                  2 INTERPRETED FALSE
          SYS.STANDARD (PACKAGE)                   2 INTERPRETED FALSE
      APPS.FND_FLEX_VALUE_SETS (SYNONYM)                              
        APPLSYS.FND_FLEX_VALUE_SETS (TABLE)                           
      APPS.FND_NUMBER (PACKAGE)                    2 INTERPRETED FALSE
        SYS.STANDARD (PACKAGE)                     2 INTERPRETED FALSE
  APPS.VERP_VPS_SUPPLY_EXTRACT_PKG (PACKAGE)       2 INTERPRETED FALSE
    SYS.STANDARD (PACKAGE)                         2 INTERPRETED FALSE
  APPS.VERP_VPS_TRANSIT_TIMES_V (VIEW)                                
    APPS.FND_FLEX_VALUES (SYNONYM)                                    
      APPLSYS.FND_FLEX_VALUES (TABLE)                                 
    APPS.FND_FLEX_VALUES_DFV (VIEW)                                   
      APPS.FND_FLEX_VALUES (SYNONYM)                                  
        APPLSYS.FND_FLEX_VALUES (TABLE)                               
      APPS.FND_NUMBER (PACKAGE)                    2 INTERPRETED FALSE
        SYS.STANDARD (PACKAGE)                     2 INTERPRETED FALSE
    APPS.FND_FLEX_VALUE_SETS (SYNONYM)                                
      APPLSYS.FND_FLEX_VALUE_SETS (TABLE)
</code>
Tom Kyte
March 11, 2013 - 8:20 am UTC

so apps calls sys packages, none of those would be profiled at the detail level.

Hard to believe

Matthew McPeak, March 11, 2013 - 10:41 am UTC

Thanks. It's hard to believe that 70-80% of my execution time is in SYS packages though.

I guess I need to run it through HPROF to confirm that?


Tom Kyte
March 11, 2013 - 1:30 pm UTC

you'd be best served by using that, yes

see
http://barrymcgillin.blogspot.com/2012/04/using-hierarchical-profiler-in-sql.html

it is much more informative/easy to use

Followup

Matthew McPeak, March 11, 2013 - 2:27 pm UTC

Tom,

DBMS_HPROF is giving me details covering the entire elapsed time, so that is good.

Just for fun, I did a run with both profilers turned on, just to see what was different.

Almost all of the "missing time" is accounted for in three MERGE statements. For example, in one merge (line 1124), the PL/SQL profiler had only 3.7 seconds, while the hierarchical profiler has a function elapsed time of 20.827 seconds.

I use both MERGE and the DBMS profiler all the time, but I never noticed such a large discrepency before.

Very odd. Guess I'll stick with hprof.

Matt

Followup on your comment on February 16, 2010 regarding profiling a procedure in different schema

anil, March 23, 2013 - 9:24 am UTC

Hi Tom , Your comment "Followup February 16, 2010 - 12pm Central time zone:

if I cannot answer something immediately (given constraints like I'm sitting in an airport or whatever, without immediate access to lots of my resources) I skip it and I never come back to old one (I work with a FIFO - first in, first out - queue).

so, I just very quickly glanced at the documentation for this package, clicked on "security model" and found this:


http://download.oracle.com/docs/cd/B19306_01/appdev.102/b14258/d_profil.htm#i999855


compile it with debug. "


I compiled the procedure with compile debug, and also gave create procedure priviledges to calling schema.
Still the data is NOT populated in plsql_profiler_units and plsql_profiler_data. I see only plsql_profiler_runs getting populated
Tom Kyte
March 25, 2013 - 2:14 pm UTC

give full example. show the step by steps I have to take to reproduce your issue. remember that when building a test case - I don't need your actual code - a test production like:

create procedure p as x number; begin x := 5; dbms_output.put_line( 'hello world '|| x ); end;

would be sufficient to test with. but show all of the steps in as LITTLE CODE AS POSSIBLE.

http://asktom.oracle.com/Misc/how-to-ask-questions.html
more

Connor and Chris don't just spend all day on AskTOM. You can also catch regular content via Connor's blog and Chris's blog. Or if video is more your thing, check out Connor's latest video and Chris's latest video from their Youtube channels. And of course, keep up to date with AskTOM via the official twitter account.

More to Explore

PL/SQL demos

Check out more PL/SQL tutorials on our LiveSQL tool.

PL/SQL docs

PL/SQL reference manual from the Oracle documentation library