Timing an ALL_ROWS query

The whole point is to benchmark the SQL WITHOUT returning buckets of data across the network. Returning Gigs of data is just not feasible for really large SQLs.

Here's another example:

SQL> select * from ed_proj_map where rownum > 1;

no rows selected

Elapsed: 00:00:00.13

SQL> set autotrace traceonly statistics
SQL> select * from ed_proj_map;

297975 rows selected.

Elapsed: 00:00:49.45

Statistics
----------------------------------------------------------
          0  recursive calls
          0  db block gets
      20577  consistent gets
        751  physical reads
          0  redo size
   11486383  bytes sent via SQL*Net to client
     219012  bytes received via SQL*Net from client
      19866  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
     297975  rows processed

This shows that ROWNUM>1 had sub-second response, but AUTOTRACE took 50 seconds. This leads us to believe that ROWNUM>1 did not do any work. But lets look at TK*Prof (I was running SQL*Trace as well):

select *
from
 ed_proj_map where rownum > 1


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        1      0.17       0.16        751        752          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        3      0.17       0.16        751        752          0           0

Misses in library cache during parse: 0
Optimizer mode: CHOOSE
Parsing user id: 23

Rows     Row Source Operation
-------  ---------------------------------------------------
      0  COUNT  (cr=752 pr=751 pw=0 time=164361 us)
      0   FILTER  (cr=752 pr=751 pw=0 time=164354 us)
 297975    TABLE ACCESS FULL ED_PROJ_MAP (cr=752 pr=751 pw=0 time=302618 us)

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

select *
from
 ed_proj_map


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch    19866      0.58       0.67        751      20577          0      297975
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total    19868      0.58       0.67        751      20577          0      297975

Misses in library cache during parse: 0
Optimizer mode: CHOOSE
Parsing user id: 23

Rows     Row Source Operation
-------  ---------------------------------------------------
 297975  TABLE ACCESS FULL OBJ#(151802) (cr=20577 pr=751 pw=0 time=299767 us)

The above shows that Oracle read the same number of rows from the table both with and without the ROWNUM>1, and they both took about the same about of time to do so. But why did the AUTOTRACE example take 49 seconds? ROWNUM>1 is doing all the data retrieval work, but not the data delivery which appears to be 95+% of the job.

The problem I had not previously noticed - but was highlighted in your AUTOTRACE and my SQL*Trace above, is that although ROWNUM>1 reads the same number of rows, the Consistent Gets ("query" in TkProf) is markedly different. I can't make sense of this.

As a third comparison, I wrote a PL/SQL wrapper to fetch the rows without returning them to the SQL*Plus client. Here is the trace:

declare
        cursor c1 is select * from ed_proj_map;
        type c1_tbl_typ is table of c1%rowtype;
        c1_tbl c1_tbl_typ;
begin
        open c1;
        loop
                fetch c1 bulk collect into c1_tbl limit 1000;
                exit when c1%notfound;
        end loop;
        close c1;
end;

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.05       0.02          0          0          0           1
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      0.05       0.02          0          0          0           1

Misses in library cache during parse: 1
Optimizer mode: CHOOSE
Parsing user id: 23
********************************************************************************

SELECT *
FROM
 ED_PROJ_MAP


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.01       0.00          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch      298      0.74       1.09        751       1047          0      297975
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total      300      0.75       1.09        751       1047          0      297975

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

Interestingly, though not identical - this seems to be more comparable to the ROWNUM>1 example. This seems logical since - like ROWNUM>1 - the rows are not delivered to the client.

As another comparison, I ran the raw query from SQL*Plus, spooling the data to /dev/null (not displaying on the screen):

select *
from
 ed_proj_map


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch    19866      0.74       0.74        751      20577          0      297975
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total    19868      0.74       0.74        751      20577          0      297975

Misses in library cache during parse: 0
Optimizer mode: CHOOSE
Parsing user id: 23

Rows     Row Source Operation
-------  ---------------------------------------------------
 297975  TABLE ACCESS FULL OBJ#(151802) (cr=20577 pr=751 pw=0 time=601432 us)

The Consistent Gets / Query is back up to AUTOTRACE TRACEONLY levels, but like AUTOTRACE the query took about a minute to finish.

My findings:

• ROWNUM>1 does all the work of retrieval without the overheads of delivery. This is desirable because when we compare the performance of two SQLs that deliver the same data, it is the retrieval speed we are trying to tune.
• ROWNUM>1 is orders of magnitude faster to benchmark a query than AUTOTRACE TRACEONLY.
• Returning rows to a host program (eg. SQL*Plus) involves some activity that increases Consistent Gets.

OK, I think we're talking about two different things. If you want to know how long it will take in Production to resolve a SQL and return the data either to the client or to a PL/SQL routine, ROWNUM>1 will not give you any idea of the REAL elapsed time including fetches. But speaking only for myself, I have never once wanted to do that. If I want to know how long a production program takes, I time it in Production.

My intention here - and I concede that I did not make it clear - is that when you have an under-performing SQL to tune, you want some means of determining how much faster your tuned version will be. All being equal, the tuned version will return the same data across the same network (or to the same PL/SQL program); what is different is the Explain Plan - the steps performed to retrieve the data.

By using ROWNUM>1 you can benchmark the old version, and compare that benchmark to the new version. This will give you an accurate picture of the likely tuning benefit.

Of course all of this is equally possible using any of the other methods I described in the article - including AUTOTRACE; but with the exception of the SELECT MAX() option, the exercise takes longer because of the fetches, which we are happy to do without because they are a constant.

I suppose it would have been clearer if I had worked through a tuning case-study showing an untuned SQL, its benchmark, a tuned benchmark, then the tuned SQL fetching. I may yet do that and tack it to the bottom with a note.