RE: 10046 event is useless in 9.2.0.4 version for response time measuring !!!

Jurijs,

Even if something takes 6x longer to run the one time you trace it, it's
still better to have the detailed 10046 data than risk being tricked by =
the
aggregation problems introduced by using V$ data.

The problem with 9.2.0.4 is measured in hours at worst. The problem with
being tricked by V$ data is often measurable in months.

I'm not sure whether there's a 9.2.0.4 back-port available. It's a good
question to ask Oracle.
=20

Cary Millsap
Hotsos Enterprises, Ltd.
http://www.hotsos.com
* Nullius in verba *

Upcoming events:
- Performance Diagnosis 101: 8/10 Boston, 9/14 San Francisco, 10/5 =
Charlotte
- SQL Optimization 101: 7/26 Washington DC, 8/16 Minneapolis, 9/20 =
Hartford
- Hotsos Symposium 2005: March 6-10 Dallas
- Visit www.hotsos.com for schedule details...


-----Original Message-----
From: oracle-l-bounce@xxxxxxxxxxxxx =
[mailto:oracle-l-bounce@xxxxxxxxxxxxx]
On Behalf Of J.Velikanovs@xxxxxxxx
Sent: Monday, August 02, 2004 10:46 AM
To: oracle-l@xxxxxxxxxxxxx
Cc: oracle-l@xxxxxxxxxxxxx; oracle-l-bounce@xxxxxxxxxxxxx
Subject: RE: 10046 event is useless in 9.2.0.4 version for response time
measuring !!!

Cary,
Thanks for your replay,
But that the .=20
How to discover performance problems on 9.2.0.4, then?
It is seem that 9.2.0.5 not the option ;(
.
Is to ask backport is a good idea in this case, I wonder.
Does some body in the list have tried it?
.
Cary, that is your experience? How to get around it?
.
PS Forgot to mention, test has been executed on the one machine. Two=20
separate OH. RH AS 3.0.

Regards,
Jurijs
9268222
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=
=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D=3D
http://otn.oracle.com/ocm/jvelikanovs.html






"Cary Millsap" <cary.millsap@xxxxxxxxxx>
Sent by: oracle-l-bounce@xxxxxxxxxxxxx
02.08.2004 18:07
Please respond to oracle-l
=20
        To:     <oracle-l@xxxxxxxxxxxxx>
        cc:=20
        Subject:        RE: 10046 event is useless in 9.2.0.4 version =
for=20
response time measuring !!!


Jurijs,

You've identified the bug correctly. The response time impact will vary =
=3D
from
virtually zero to the 6X number you've discovered, or even worse. (The
problem is the worst for sessions that nest NESTED LOOPS row source
operations inside each other.)

It's a bug. Fix it. The problem is fixed in 9.2.0.5.


Cary Millsap
Hotsos Enterprises, Ltd.
http://www.hotsos.com
* Nullius in verba *

Upcoming events:
- Performance Diagnosis 101: 8/10 Boston, 9/14 San Francisco, 10/5 =3D
Charlotte
- SQL Optimization 101: 7/26 Washington DC, 8/16 Minneapolis, 9/20 =3D
Hartford
- Hotsos Symposium 2005: March 6-10 Dallas
- Visit www.hotsos.com for schedule details...


-----Original Message-----
From: oracle-l-bounce@xxxxxxxxxxxxx =3D
[mailto:oracle-l-bounce@xxxxxxxxxxxxx]
On Behalf Of J.Velikanovs@xxxxxxxx
Sent: Monday, August 02, 2004 8:19 AM
To: 'oracle-l@xxxxxxxxxxxxx '
Subject: 10046 event is useless in 9.2.0.4 version for response time
measuring !!!

My regards to all,
At the moment I have impression that, 10046 event is useless in =
9.2.0.4=3D20
version for response time measuring!
I have tied to run loop.sql (see below for full text) with and =
without=3D20
10046 event on 9.2.0.4 & 9.2.0.5.
The results scared me.
Take a look:
.
9.2.0.4=3D20
without 6,45 sec=3D20
!!!!!!!!!!! with 37,36 sec=3D20
.
9.2.0.5
without 5,48 sec=3D20
!!!!!!!!!!! with 7,19 sec
.
After short investigation it is appears that it is BUG 3009359.
http://metalink.oracle.com/metalink/plsql/showdoc?db=3D3DNOT&id=3D3D30093=
59.8=3D

No one-off fix on 9.2.0.4.
.
So it's appears, that 10046 is useless on 9.2.0.4, because SQL =
Trace=3D20
itself takes 580% of response time.
.
Any comments?!
Have any body solution for this issue.
.
As appears from dictation from this list, to go to 9.2.0.5 is not =
good=3D20
idea, because of instability and other issues.

Thanks in advance,
Jurijs


******************************************
-- loop.sql
declare
vn number;
begin
for f in 1..1000 loop
select count(v) into vn from testlio where n between 10000 and 20000;
end loop;
end;
/
******************************************


TKPROF output
******************************************
9204
******************************************
SELECT count(v)
from
 testlio where n between 10000 and 20000


call     count       cpu    elapsed       disk      query    current  =
=3D
rows
------- ------  -------- ---------- ---------- ---------- =
----------=3D20
----------
Parse        1      0.00       0.00          0          0          0     =
=3D
0
Execute   1000      0.08       0.08          0          0          0     =
=3D
0
Fetch     1000     37.07      36.19          0     132000          0  =
=3D
1000
------- ------  -------- ---------- ---------- ---------- =
----------=3D20
----------
total     2001     37.15      36.27          0     132000          0  =
=3D
1000

Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: SYS   (recursive depth: 1)

Rows     Row Source Operation
-------  ---------------------------------------------------
   1000  SORT AGGREGATE (cr=3D3D132000 r=3D3D0 w=3D3D0 time=3D3D36185613 =
us)
10001000   TABLE ACCESS BY INDEX ROWID TESTLIO (cr=3D3D132000 r=3D3D0 =
w=3D3D0=3D20
time=3D3D28015044 us)
10001000    INDEX RANGE SCAN TESTLIO_I1 (cr=3D3D25000 r=3D3D0 w=3D3D0 =
=3D
time=3D3D9976625=3D20
us)(object id 6318)

******************************************
9205
******************************************
SELECT COUNT(V)
FROM
 TESTLIO WHERE N BETWEEN 10000 AND 20000


call     count       cpu    elapsed       disk      query    current  =
=3D
rows
------- ------  -------- ---------- ---------- ---------- =
----------=3D20
----------
Parse        1      0.00       0.00          0          0          0     =
=3D
0
Execute   1000      0.05       0.07          0          0          0     =
=3D
0
Fetch     1000      6.89       6.72          0     132000          0  =
=3D
1000
------- ------  -------- ---------- ---------- ---------- =
----------=3D20
----------
total     2001      6.94       6.81          0     132000          0  =
=3D
1000

Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: SYS   (recursive depth: 1)

Rows     Row Source Operation
-------  ---------------------------------------------------
   1000  SORT AGGREGATE
10001000   TABLE ACCESS BY INDEX ROWID TESTLIO
10001000    INDEX RANGE SCAN TESTLIO_I1 (object id 6289)

******************************************

RAW portion of TRC file
******************************************
9204
******************************************
PARSING IN CURSOR #5 len=3D3D60 dep=3D3D1 uid=3D3D0 oct=3D3D3 lid=3D3D0 =
=3D
tim=3D3D1065854307286108=3D20
hv=3D3D518780277 ad=3D3D'5aca2538'
SELECT count(v) from testlio where n between 10000 and 20000
END OF STMT
PARSE =3D
#5:c=3D3D0,e=3D3D485,p=3D3D0,cr=3D3D0,cu=3D3D0,mis=3D3D1,r=3D3D0,dep=3D3D=
1,og=3D3D4,tim=3D3D1=3D
065854307286097
BINDS #5:
EXEC =3D
#5:c=3D3D0,e=3D3D134,p=3D3D0,cr=3D3D0,cu=3D3D0,mis=3D3D0,r=3D3D0,dep=3D3D=
1,og=3D3D4,tim=3D3D1=3D
065854307286405
FETCH=3D20
#5:c=3D3D40000,e=3D3D36240,p=3D3D0,cr=3D3D132,cu=3D3D0,mis=3D3D0,r=3D3D1,=
dep=3D3D1,og=3D3D4=3D
,tim=3D3D1065854307322684
BINDS #5:
EXEC =3D
#5:c=3D3D0,e=3D3D85,p=3D3D0,cr=3D3D0,cu=3D3D0,mis=3D3D0,r=3D3D0,dep=3D3D1=
,og=3D3D4,tim=3D3D10=3D
65854307322899
FETCH=3D20
#5:c=3D3D40000,e=3D3D36128,p=3D3D0,cr=3D3D132,cu=3D3D0,mis=3D3D0,r=3D3D1,=
dep=3D3D1,og=3D3D4=3D
,tim=3D3D1065854307359065
BINDS #5:
EXEC =3D
#5:c=3D3D0,e=3D3D81,p=3D3D0,cr=3D3D0,cu=3D3D0,mis=3D3D0,r=3D3D0,dep=3D3D1=
,og=3D3D4,tim=3D3D10=3D
65854307359268
FETCH=3D20
#5:c=3D3D30000,e=3D3D36181,p=3D3D0,cr=3D3D132,cu=3D3D0,mis=3D3D0,r=3D3D1,=
dep=3D3D1,og=3D3D4=3D
,tim=3D3D1065854307395487
BINDS #5:
EXEC =3D
#5:c=3D3D0,e=3D3D81,p=3D3D0,cr=3D3D0,cu=3D3D0,mis=3D3D0,r=3D3D0,dep=3D3D1=
,og=3D3D4,tim=3D3D10=3D
65854307395689
FETCH=3D20
#5:c=3D3D40000,e=3D3D36145,p=3D3D0,cr=3D3D132,cu=3D3D0,mis=3D3D0,r=3D3D1,=
dep=3D3D1,og=3D3D4=3D
,tim=3D3D1065854307431871
BINDS #5:
******************************************
9204
******************************************
PARSING IN CURSOR #5 len=3D3D60 dep=3D3D1 uid=3D3D0 oct=3D3D3 lid=3D3D0 =
=3D
tim=3D3D1065854501680779=3D20
hv=3D3D4259315813 ad=3D3D'5bc9bfdc'
SELECT COUNT(V) FROM TESTLIO WHERE N BETWEEN 10000 AND 20000
END OF STMT
PARSE=3D20
#5:c=3D3D0,e=3D3D7476,p=3D3D0,cr=3D3D0,cu=3D3D0,mis=3D3D1,r=3D3D0,dep=3D3=
D1,og=3D3D4,tim=3D3D=3D
1065854501680769
BINDS #5:
EXEC =3D
#5:c=3D3D0,e=3D3D134,p=3D3D0,cr=3D3D0,cu=3D3D0,mis=3D3D0,r=3D3D0,dep=3D3D=
1,og=3D3D4,tim=3D3D1=3D
065854501681077
FETCH=3D20
#5:c=3D3D10000,e=3D3D6736,p=3D3D0,cr=3D3D132,cu=3D3D0,mis=3D3D0,r=3D3D1,d=
ep=3D3D1,og=3D3D4,=3D
tim=3D3D1065854501687852
BINDS #5:
EXEC =3D
#5:c=3D3D0,e=3D3D82,p=3D3D0,cr=3D3D0,cu=3D3D0,mis=3D3D0,r=3D3D0,dep=3D3D1=
,og=3D3D4,tim=3D3D10=3D
65854501688065
FETCH=3D20
#5:c=3D3D0,e=3D3D6707,p=3D3D0,cr=3D3D132,cu=3D3D0,mis=3D3D0,r=3D3D1,dep=3D=
3D1,og=3D3D4,tim=3D3D=3D
1065854501694810
BINDS #5:
EXEC =3D
#5:c=3D3D0,e=3D3D81,p=3D3D0,cr=3D3D0,cu=3D3D0,mis=3D3D0,r=3D3D0,dep=3D3D1=
,og=3D3D4,tim=3D3D10=3D
65854501695011
FETCH=3D20
#5:c=3D3D10000,e=3D3D6699,p=3D3D0,cr=3D3D132,cu=3D3D0,mis=3D3D0,r=3D3D1,d=
ep=3D3D1,og=3D3D4,=3D
tim=3D3D1065854501701747
BINDS #5:
EXEC =3D
#5:c=3D3D0,e=3D3D79,p=3D3D0,cr=3D3D0,cu=3D3D0,mis=3D3D0,r=3D3D0,dep=3D3D1=
,og=3D3D4,tim=3D3D10=3D
65854501701944
FETCH=3D20
#5:c=3D3D10000,e=3D3D6747,p=3D3D0,cr=3D3D132,cu=3D3D0,mis=3D3D0,r=3D3D1,d=
ep=3D3D1,og=3D3D4,=3D
tim=3D3D1065854501708729
BINDS #5:
EXEC =3D
#5:c=3D3D0,e=3D3D80,p=3D3D0,cr=3D3D0,cu=3D3D0,mis=3D3D0,r=3D3D0,dep=3D3D1=
,og=3D3D4,tim=3D3D10=3D
65854501708927
FETCH=3D20
#5:c=3D3D10000,e=3D3D6650,p=3D3D0,cr=3D3D132,cu=3D3D0,mis=3D3D0,r=3D3D1,d=
ep=3D3D1,og=3D3D4,=3D
tim=3D3D1065854501715614
BINDS #5:




=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D=
3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D
=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D=
3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D
=3D3D=3D3D=3D3D
-- mk loop
drop table testlio ;
create table testlio (n number, v varchar2(1000)) tablespace users;
begin for f in 1..30000 loop
insert into testlio values=3D20
(f,'aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa');=
=3D

end loop;
end;
/
create index testlio_i1 on testlio (n) tablespace users;



Jurijs
9268222
=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D=
3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D
=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D3D=3D=
3D=3D3D=3D3D=3D3D=3D3D
http://otn.oracle.com/ocm/jvelikanovs.html


----------------------------------------------------------------
Please see the official ORACLE-L FAQ: http://www.orafaq.com
----------------------------------------------------------------
To unsubscribe send email to:  oracle-l-request@xxxxxxxxxxxxx
put 'unsubscribe' in the subject line.
--
Archives are at http://www.freelists.org/archives/oracle-l/
FAQ is at http://www.freelists.org/help/fom-serve/cache/1.html
-----------------------------------------------------------------

----------------------------------------------------------------
Please see the official ORACLE-L FAQ: http://www.orafaq.com
----------------------------------------------------------------
To unsubscribe send email to:  oracle-l-request@xxxxxxxxxxxxx
put 'unsubscribe' in the subject line.
--
Archives are at http://www.freelists.org/archives/oracle-l/
FAQ is at http://www.freelists.org/help/fom-serve/cache/1.html
-----------------------------------------------------------------


----------------------------------------------------------------
Please see the official ORACLE-L FAQ: http://www.orafaq.com
----------------------------------------------------------------
To unsubscribe send email to:  oracle-l-request@xxxxxxxxxxxxx
put 'unsubscribe' in the subject line.
--
Archives are at http://www.freelists.org/archives/oracle-l/
FAQ is at http://www.freelists.org/help/fom-serve/cache/1.html
-----------------------------------------------------------------

----------------------------------------------------------------
Please see the official ORACLE-L FAQ: http://www.orafaq.com
----------------------------------------------------------------
To unsubscribe send email to:  oracle-l-request@xxxxxxxxxxxxx
put 'unsubscribe' in the subject line.
--
Archives are at http://www.freelists.org/archives/oracle-l/
FAQ is at http://www.freelists.org/help/fom-serve/cache/1.html
-----------------------------------------------------------------

Other related posts: