Oracle Trace Facility

From: Paul Knights <pgk_at_dcs.ed.ac.uk>
Date: Tue, 24 Aug 1993 13:33:58 GMT
Message-ID: <CC9n0n.13v_at_dcs.ed.ac.uk>


Hello

I'm currently using the Oracle Trace Facility to gather statistics about the performance of queries. On the whole the statistics make sense but one situation has arisen that I am unable to explain. A situation has arisen where when comparing two queries the total data blocks accessed by the first query is significantly greater then the second query yet the total elapsed time for the query is significantly less. This situation is explained in more detail below:

I am examining the performance of the following Multiple Join Query

SELECT T1.JOIN_T3_T1, T2.JOIN_T3_T1, T3.JOIN_T3_T1 FROM T1, T2, T3
WHERE T1.JOIN_T1_T2 = T2.JOIN_T1_T2
  AND T2.JOIN_T2_T3 = T3.JOIN_T2_T3; by varying the data in the tables T1, T2 and T3 and by varying the order of the FROM list to control which Join is performed first.

At the moment I have 5000 records in each of T1, T2 and T3. The Join of T1 and T2 on JOIN_T1_T2 produces 2000 records. The Join of T2 and T3 on JOIN_T2_T3 produces 10 records. T2 is indexed on JOIN_T2_T3 and T3 is indexed on JOIN_T2_T3. No other indexes exist. Each table has identical structure :

 Name                            Null?    Type
 ------------------------------- -------- ----
 JOIN_T1_T2                               NUMBER(6)
 JOIN_T2_T3                               NUMBER(6)
 JOIN_T3_T1                               NUMBER(6)
 SPARE1                                   NUMBER(6)
 SPARE2                                   NUMBER(6)
 SPARE3                                   NUMBER(6)

Now, if I issue the above query the Trace Facility produces the following stats:

          CPU    ELAP    PHYS    CR      CUR     ROWS

=== ==== ==== == === ====
TOTAL: 1033 3659 127 15262 192 10

If I rearrange the FROM list to "T3, T2, T1" then I get the following stats:

          CPU    ELAP    PHYS    CR      CUR     ROWS

=== ==== ==== == === ====
TOTAL: 1267 5298 130 4398 584 10

The thing to note is the variation in CR+CUR (ie total data blocks accessed) compared to ELAP (total elapsed time). For the second query the total data blocks accessed decreases dramatically yet the elapsed time has INCREASED. I was expecting that the elapsed time would increase as total data blocks accessed increased (this is what happens with all my other queries and is the sensible thing to happen).

The problem does not occur if T1 is indexed on JOIN_T1_T2 and T2 is also indexed on JOIN_T1_T2 as well as the indexes mentioned above.

For anybody who has had the patience to get this far into the posting, can you explain why the elapsed time increases yet the total blocks read has decreased. Any advice would be gratefully received.

Note that the statistics produced above have been produced as averages over several runs to ensure that the results I was getting were not "blips". All the runs produced were on or about the above stats.

The version of Oracle is ORACLE RDBMS V6.0.33.1.1.

Thanks

Paul K. Received on Tue Aug 24 1993 - 15:33:58 CEST

Original text of this message