Suppose one day that you’re at your desk, when you get a telephone call from someone complaining that a query is running slow.

You’re given the following setup:

create table drop_me
as
select rownum id, a.*
from dba_objects a
     cross join dba_objects b 
where rownum <= 5000000;

create table drop_me2
as
select *
from drop_me
order by dbms_random.random;

create index drop_me2_idx on drop_me2 (id);

And the query that you’re trying to tune looks like this:

select a.id
     , a.owner
     , a.object_name
     , a.subobject_name
     , a.object_id
     , a.data_object_id
     , a.object_type
     , b.created
     , b.last_ddl_time
     , b.timestamp
     , b.status
     , b.temporary
     , b.generated
     , b.secondary
from drop_me a
     inner join drop_me2 b on (a.id = b.id);

If I run this on my own system, I get this:

Fetched 200 rows in 4.686 seconds
We got results in 4.686 seconds

You can see that the query runs for a little over 4.6 seconds on my system before it starts returning rows.

“That’s no good!” you say, so you sprinkle a hint or two into your query…

select /*+ leading(a b) 
           use_nl(b)
           index(b (drop_me2.object_id)) 
        */
       a.id
     , a.owner
     , a.object_name
     , a.subobject_name
     , a.object_id
     , a.data_object_id
     , a.object_type
     , b.created
     , b.last_ddl_time
     , b.timestamp
     , b.status
     , b.temporary
     , b.generated
     , b.secondary
from drop_me a
     inner join drop_me2 b on (a.id = b.id);

Annnnnd BOOM! You’re a freaking tuning genius!!

Fetched 200 rows in 0.018 seconds
WHOA!!!!! LESS THAN A TENTH OF A SECOND!

Now your query returns rows in less than a tenth of a second!

You put your new query into production, glowing with pride of your awesome tuning abilities, patting yourself on the back.

Except…shortly after you deploy the query, you get another phone call….and the person on the other end of the phone isn’t congratulating you…they’re complaining that the run time of the query is worse!

Now what the heck??!?

You just saw this query run in less than a tenth of a second!

Surely they’re just crazy, right?! It CAN’T be running slower.

What happened???!

Well, what happened was you accidentally “untuned” the query, and it does, in fact, run more slowly than before.

Why The Query Is Actually Slower Now

You see, in the previous example you didn’t run the whole query…you only fetched the first 200 rows.

Fetched 200 rows
Only 200 rows fetched

(Btw, the number of rows you pull back will be determined by how high you set your SQL Array Fetch Size)

But the query isn’t yet complete. You’ve not fetched all the rows–you’re only looking at the first 200.

Let me show you what I mean–I’ll run a Pl/SQL block that runs and fetches both result sets in their entirety, emulating a SQL Array Fetch Size of 200:

set serveroutput on
declare
  cursor c_original_query
  is
  select a.id
       , a.owner
       , a.object_name
       , a.subobject_name
       , a.object_id
       , a.data_object_id
       , a.object_type
       , b.created
       , b.last_ddl_time
       , b.timestamp
       , b.status
       , b.temporary
       , b.generated
       , b.secondary
  from drop_me a
       inner join drop_me2 b on (a.id = b.id); 
       
       
       
  cursor c_untuned_query
  is
  select /*+ leading(a b) 
           use_nl(b)
           index(b (drop_me2.object_id)) 
        */
         a.id
       , a.owner
       , a.object_name
       , a.subobject_name
       , a.object_id
       , a.data_object_id
       , a.object_type
       , b.created
       , b.last_ddl_time
       , b.timestamp
       , b.status
       , b.temporary
       , b.generated
       , b.secondary
  from drop_me a
       inner join drop_me2 b on (a.id = b.id); 
       
  v_start_query timestamp;
  v_fetch_first_row timestamp;
  v_stop_query timestamp;
  v_first_fetch boolean;
  
  type t_result_set1 is table of c_original_query%rowtype;
  v_result_set1 t_result_set1;
  
  type t_result_set2 is table of c_untuned_query%rowtype;
  v_result_set2 t_result_set2;
begin
  ----------------------
  -- First Query
  v_first_fetch := true;
  
  v_start_query := systimestamp;
  open c_original_query;
  
  <<original_query>>
  loop
    fetch c_original_query bulk collect into v_result_set1 limit 200;
    
    if v_first_fetch then
      v_fetch_first_row := systimestamp;
      v_first_fetch := false;
    end if;
    
    exit when v_result_set1.count = 0;
  end loop original_query;
  
  close c_original_query;
  v_stop_query := systimestamp;
  
  dbms_output.put_line('Original Query');
  dbms_output.put_line('---------------');
  dbms_output.put_line('Time to get first 200 rows: ' || (v_fetch_first_row - v_start_query));
  dbms_output.put_line('Overall runtime: ' || (v_stop_query - v_start_query) || chr(10) || chr(10));



  ----------------------
  -- Second Query
  v_first_fetch := true;
  
  v_start_query := systimestamp;  
  open c_untuned_query;
  
  <<untuned_query>>
  loop
    fetch c_untuned_query bulk collect into v_result_set2 limit 200;
    
    if v_first_fetch then
      v_fetch_first_row := systimestamp;
      v_first_fetch := false;
    end if;
    
    exit when v_result_set2.count = 0;
  end loop untuned_query;
  
  close c_untuned_query;
  v_stop_query := systimestamp;
  
  dbms_output.put_line('"Untuned" Query');
  dbms_output.put_line('---------------');
  dbms_output.put_line('Time to get first 200 rows: ' || (v_fetch_first_row - v_start_query));
  dbms_output.put_line('Overall runtime: ' || (v_stop_query - v_start_query) || chr(10) || chr(10));
  
end;
/

The results:

Original Query
---------------
Time to get first 200 rows: +000000000 00:00:04.051163000
Overall runtime: +000000000 00:00:16.432053000


"Untuned" Query
---------------
Time to get first 200 rows: +000000000 00:00:00.004241000
Overall runtime: +000000000 00:00:29.657454000

The accidentally-untuned query is almost twice as slow as the original query. Even though it started returning rows almost instantly, it took almost 30 seconds to run to completion; whereas the original (unmodified) query runs in just over 16 seconds.

Bottom line: You cannot judge the performance of a query until you’ve fetched all the rows. If your query starts returning rows to the database client, it doesn’t mean that your query is “done” (at least, not until the last row is fetched).

If you want to know the true run time of your query, you must run it to completion (in other words, fetch all the rows).

Free Oracle SQL Tuning Guide

Checkout my FREE guide, 7 SQL Tuning Secrets You Can Use Immediately, Even If You’ve Never Tuned a Query In Your Life!

Get it here: tuningsql.com/secrets

7 SQL Tuning Secrets You can Use Immediately, Even If You've Never Tuned A Query In Your Life

Leave a Reply

Your email address will not be published. Required fields are marked *