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

From: VC <boston103_at_hotmail.com>
Date: Mon, 22 Dec 2003 01:16:22 GMT
Message-ID: <GBrFb.173628$_M.790976@attbi_s54>

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 Received on Sun Dec 21 2003 - 19:16:22 CST