Cary, Thanks for your replay, But that the ? 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 separate OH. RH AS 3.0. Regards, Jurijs 9268222 ============================================ 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 To: <oracle-l@xxxxxxxxxxxxx> cc: Subject: RE: 10046 event is useless in 9.2.0.4 version for response time measuring !!! Jurijs, You've identified the bug correctly. The response time impact will vary = 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 = 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 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=20 version for response time measuring! I have tied to run loop.sql (see below for full text) with and without=20 10046 event on 9.2.0.4 & 9.2.0.5. The results scared me. Take a look: . 9.2.0.4=20 without 6,45 sec=20 !!!!!!!!!!! with 37,36 sec=20 . 9.2.0.5 without 5,48 sec=20 !!!!!!!!!!! with 7,19 sec . After short investigation it is appears that it is BUG 3009359. http://metalink.oracle.com/metalink/plsql/showdoc?db=3DNOT&id=3D3009359.8= 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=20 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=20 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 = rows ------- ------ -------- ---------- ---------- ---------- ----------=20 ---------- Parse 1 0.00 0.00 0 0 0 = 0 Execute 1000 0.08 0.08 0 0 0 = 0 Fetch 1000 37.07 36.19 0 132000 0 = 1000 ------- ------ -------- ---------- ---------- ---------- ----------=20 ---------- total 2001 37.15 36.27 0 132000 0 = 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=3D132000 r=3D0 w=3D0 time=3D36185613 us) 10001000 TABLE ACCESS BY INDEX ROWID TESTLIO (cr=3D132000 r=3D0 w=3D0=20 time=3D28015044 us) 10001000 INDEX RANGE SCAN TESTLIO_I1 (cr=3D25000 r=3D0 w=3D0 = time=3D9976625=20 us)(object id 6318) ****************************************** 9205 ****************************************** SELECT COUNT(V) FROM TESTLIO WHERE N BETWEEN 10000 AND 20000 call count cpu elapsed disk query current = rows ------- ------ -------- ---------- ---------- ---------- ----------=20 ---------- Parse 1 0.00 0.00 0 0 0 = 0 Execute 1000 0.05 0.07 0 0 0 = 0 Fetch 1000 6.89 6.72 0 132000 0 = 1000 ------- ------ -------- ---------- ---------- ---------- ----------=20 ---------- total 2001 6.94 6.81 0 132000 0 = 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=3D60 dep=3D1 uid=3D0 oct=3D3 lid=3D0 = tim=3D1065854307286108=20 hv=3D518780277 ad=3D'5aca2538' SELECT count(v) from testlio where n between 10000 and 20000 END OF STMT PARSE = #5:c=3D0,e=3D485,p=3D0,cr=3D0,cu=3D0,mis=3D1,r=3D0,dep=3D1,og=3D4,tim=3D1= 065854307286097 BINDS #5: EXEC = #5:c=3D0,e=3D134,p=3D0,cr=3D0,cu=3D0,mis=3D0,r=3D0,dep=3D1,og=3D4,tim=3D1= 065854307286405 FETCH=20 #5:c=3D40000,e=3D36240,p=3D0,cr=3D132,cu=3D0,mis=3D0,r=3D1,dep=3D1,og=3D4= ,tim=3D1065854307322684 BINDS #5: EXEC = #5:c=3D0,e=3D85,p=3D0,cr=3D0,cu=3D0,mis=3D0,r=3D0,dep=3D1,og=3D4,tim=3D10= 65854307322899 FETCH=20 #5:c=3D40000,e=3D36128,p=3D0,cr=3D132,cu=3D0,mis=3D0,r=3D1,dep=3D1,og=3D4= ,tim=3D1065854307359065 BINDS #5: EXEC = #5:c=3D0,e=3D81,p=3D0,cr=3D0,cu=3D0,mis=3D0,r=3D0,dep=3D1,og=3D4,tim=3D10= 65854307359268 FETCH=20 #5:c=3D30000,e=3D36181,p=3D0,cr=3D132,cu=3D0,mis=3D0,r=3D1,dep=3D1,og=3D4= ,tim=3D1065854307395487 BINDS #5: EXEC = #5:c=3D0,e=3D81,p=3D0,cr=3D0,cu=3D0,mis=3D0,r=3D0,dep=3D1,og=3D4,tim=3D10= 65854307395689 FETCH=20 #5:c=3D40000,e=3D36145,p=3D0,cr=3D132,cu=3D0,mis=3D0,r=3D1,dep=3D1,og=3D4= ,tim=3D1065854307431871 BINDS #5: ****************************************** 9204 ****************************************** PARSING IN CURSOR #5 len=3D60 dep=3D1 uid=3D0 oct=3D3 lid=3D0 = tim=3D1065854501680779=20 hv=3D4259315813 ad=3D'5bc9bfdc' SELECT COUNT(V) FROM TESTLIO WHERE N BETWEEN 10000 AND 20000 END OF STMT PARSE=20 #5:c=3D0,e=3D7476,p=3D0,cr=3D0,cu=3D0,mis=3D1,r=3D0,dep=3D1,og=3D4,tim=3D= 1065854501680769 BINDS #5: EXEC = #5:c=3D0,e=3D134,p=3D0,cr=3D0,cu=3D0,mis=3D0,r=3D0,dep=3D1,og=3D4,tim=3D1= 065854501681077 FETCH=20 #5:c=3D10000,e=3D6736,p=3D0,cr=3D132,cu=3D0,mis=3D0,r=3D1,dep=3D1,og=3D4,= tim=3D1065854501687852 BINDS #5: EXEC = #5:c=3D0,e=3D82,p=3D0,cr=3D0,cu=3D0,mis=3D0,r=3D0,dep=3D1,og=3D4,tim=3D10= 65854501688065 FETCH=20 #5:c=3D0,e=3D6707,p=3D0,cr=3D132,cu=3D0,mis=3D0,r=3D1,dep=3D1,og=3D4,tim=3D= 1065854501694810 BINDS #5: EXEC = #5:c=3D0,e=3D81,p=3D0,cr=3D0,cu=3D0,mis=3D0,r=3D0,dep=3D1,og=3D4,tim=3D10= 65854501695011 FETCH=20 #5:c=3D10000,e=3D6699,p=3D0,cr=3D132,cu=3D0,mis=3D0,r=3D1,dep=3D1,og=3D4,= tim=3D1065854501701747 BINDS #5: EXEC = #5:c=3D0,e=3D79,p=3D0,cr=3D0,cu=3D0,mis=3D0,r=3D0,dep=3D1,og=3D4,tim=3D10= 65854501701944 FETCH=20 #5:c=3D10000,e=3D6747,p=3D0,cr=3D132,cu=3D0,mis=3D0,r=3D1,dep=3D1,og=3D4,= tim=3D1065854501708729 BINDS #5: EXEC = #5:c=3D0,e=3D80,p=3D0,cr=3D0,cu=3D0,mis=3D0,r=3D0,dep=3D1,og=3D4,tim=3D10= 65854501708927 FETCH=20 #5:c=3D10000,e=3D6650,p=3D0,cr=3D132,cu=3D0,mis=3D0,r=3D1,dep=3D1,og=3D4,= tim=3D1065854501715614 BINDS #5: =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=3D=3D=3D=3D=3D=3D= =3D=3D=3D -- 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=20 (f,'aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa');= end loop; end; / create index testlio_i1 on testlio (n) tablespace users; 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 ---------------------------------------------------------------- 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 //www.freelists.org/archives/oracle-l/ FAQ is at //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 //www.freelists.org/archives/oracle-l/ FAQ is at //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 //www.freelists.org/archives/oracle-l/ FAQ is at //www.freelists.org/help/fom-serve/cache/1.html -----------------------------------------------------------------