Oracle FAQ Your Portal to the Oracle Knowledge Grid
HOME | ASK QUESTION | ADD INFO | SEARCH | E-MAIL US
 

Home -> Community -> Usenet -> c.d.o.server -> Re: 'alter session set sql_trace=true' bug or feature ?

Re: 'alter session set sql_trace=true' bug or feature ?

From: ghassan salem <pacg03_at_yahoo.fr>
Date: Tue, 23 Dec 2003 12:06:07 +0100
Message-ID: <nsVFb.1$TR4.21@news.oracle.com>


NetComrade wrote:

> are both instances running on the same machine?
> is udump set to the same place?
> check IO contention on device where trace file is @.
> 
> On Mon, 22 Dec 2003 01:16:22 GMT, "VC" <boston103_at_hotmail.com> wrote:
> 
> 

>>Hello,
>>
>>It appears that using sql trace which is an extremely important tool for
>>tuning SQL statements is a performance problem in itself under Oracle
>>9.2.0.4:
>>
>>Please observe this:
>>
>>============================================
>>Connected to:
>>Oracle9i Enterprise Edition Release 9.2.0.4.0 - Production
>>With the Partitioning, OLAP and Oracle Data Mining options
>>JServer Release 9.2.0.4.0 - Production
>>
>>SQL> drop table t1;
>>
>>Table dropped.
>>
>>SQL> create table t1(id int, data varchar2(30));
>>
>>Table created.
>>
>>SQL>
>>SQL> begin
>> 2 for i in 1..1000 loop
>> 3 insert into t1 values(i, 'xxxxxxxxxxxxxxxxxxxxx');
>> 4 end loop;
>> 5 end;
>> 6 /
>>
>>PL/SQL procedure successfully completed.
>>
>>SQL>
>>SQL> analyze table t1 compute statistics;
>>
>>Table analyzed.
>>
>>SQL>
>>SQL> set timing on
>>SQL> set autot trace stat expl
>>SQL> select a.id, count(*) from (select id from t1) a join (select id from
>>t1
>>on a.id<=b.id group by a.id;
>>
>>1000 rows selected.
>>
>>Elapsed: 00:00:00.05
>>
>>Execution Plan
>>----------------------------------------------------------
>> 0 SELECT STATEMENT Optimizer=CHOOSE (Cost=12 Card=1000 Bytes=6000)
>> 1 0 SORT (GROUP BY NOSORT) (Cost=12 Card=1000 Bytes=6000)
>> 2 1 MERGE JOIN (Cost=12 Card=50000 Bytes=300000)
>> 3 2 SORT (JOIN) (Cost=6 Card=1000 Bytes=3000)
>> 4 3 TABLE ACCESS (FULL) OF 'T1' (Cost=2 Card=1000 Bytes=3000)
>> 5 2 SORT (JOIN) (Cost=6 Card=1000 Bytes=3000)
>> 6 5 TABLE ACCESS (FULL) OF 'T1' (Cost=2 Card=1000 Bytes=3000)
>>
>>Statistics
>>----------------------------------------------------------
>> 0 recursive calls
>> 0 db block gets
>> 14 consistent gets
>> 0 physical reads
>> 0 redo size
>> 17505 bytes sent via SQL*Net to client
>> 1225 bytes received via SQL*Net from client
>> 68 SQL*Net roundtrips to/from client
>> 2 sorts (memory)
>> 0 sorts (disk)
>> 1000 rows processed
>>
>>SQL>
>>SQL> alter session set sql_trace=true;
>>
>>Session altered.
>>
>>SQL> select a.id, count(*) from (select id from t1) a join (select id from
>>t1 on a.id<=b.id group by a.id;
>>
>>1000 rows selected.
>>
>>Elapsed: 00:00:02.06
>>
>>Execution Plan
>>----------------------------------------------------------
>> 0 SELECT STATEMENT Optimizer=CHOOSE (Cost=12 Card=1000 Bytes=6000)
>> 1 0 SORT (GROUP BY NOSORT) (Cost=12 Card=1000 Bytes=6000)
>> 2 1 MERGE JOIN (Cost=12 Card=50000 Bytes=300000)
>> 3 2 SORT (JOIN) (Cost=6 Card=1000 Bytes=3000)
>> 4 3 TABLE ACCESS (FULL) OF 'T1' (Cost=2 Card=1000 Bytes= 3000)
>> 5 2 SORT (JOIN) (Cost=6 Card=1000 Bytes=3000)
>> 6 5 TABLE ACCESS (FULL) OF 'T1' (Cost=2 Card=1000 Bytes=3000)
>>
>>
>>Statistics
>>----------------------------------------------------------
>> 0 recursive calls
>> 0 db block gets
>> 14 consistent gets
>> 0 physical reads
>> 0 redo size
>> 17505 bytes sent via SQL*Net to client
>> 1225 bytes received via SQL*Net from client
>> 68 SQL*Net roundtrips to/from client
>> 2 sorts (memory)
>> 0 sorts (disk)
>> 1000 rows processed
>>===================================================================
>>
>>As you see the execution time for the query
>>
>> 'select a.id, count(*) from (select id from t1) a join (select id from t1
>>on a.id<=b.id group by a.id;'
>>
>>increased from 50 milliseconds to 2 seconds. No such effect can be seen
>>under Oracle 8.1.7.4.
>>This kind of sql_trace=true influence on performance can be observed on
>>different platforms (AIX, Solaris, Windows).
>>
>>For a larger dataset (10000 rows), the numbers are 36 seconds and 259
>>seconds respectively.
>>
>>Can anybody explain this performance 'improvement' between 8i and 9i ?
>>
>>Thanks.
>>
>>VC
>>
>>
> 
> 
> .......
> We use Oracle 8.1.7.4 on Solaris 2.7 boxes
> remove NSPAM to email

This is a bug (or a doc bug) : when sql_trace is enabled, system is collecting (in 9.2.0.3 and later) more stats than it did before (row_source_stats) and that seems to consume much more time. bug still not fixed 3009359

rgds Received on Tue Dec 23 2003 - 05:06:07 CST

Original text of this message

HOME | ASK QUESTION | ADD INFO | SEARCH | E-MAIL US