Skip to Main Content

Breadcrumb

Question and Answer

Tom Kyte

Thanks for the question, Peter.

Asked: April 20, 2002 - 9:18 pm UTC

Last updated: May 13, 2003 - 7:35 am UTC

Version: 8.1.7

Viewed 1000+ times

You Asked

Hi Tom,

I tried to reproduce what you did on p279 ~ 281 of your book
about the effect the scattered random reads of an index has
on the system performance.

The example below (from your book) shows that logical I/O's
is indeed much higher when the "disorganized" table is queried.
However, it also shows that there's really not much difference
in elapsed time! In fact, I ran these queries many times and
sometimes the query on "disorganized" ran faster. How can this
be possible?

thanks

.......................................................................
CREATE TABLE colocated (x int, y varchar2(2000)) pctfree 0;

BEGIN
FOR I IN 1..100000 LOOP
INSERT INTO colocated VALUES
(i, RPAD(dbms_random.random, 75, ‘*’));
END LOOP;

commit;
END;
/

ALTER TABLE colocated ADD CONSTRAINT colocated_pk PRIMARY KEY(x);

CREATE TABLE disorganized NOLOGGING PCTFREE 0 AS
SELECT x, y FROM colocated ORDER BY y;

ALTER TABLE disorganized ADD CONSTRAINT disorganized_pk PRIMARY KEY(x);
.......................................................................

set autotrace traceonly explain statistics
set timing on

SELECT * FROM colocated
WHERE x BETWEEN 20000 AND 40000;

20001 rows selected.

Elapsed: 00:00:03.25

Execution Plan
----------------------------------------------------------
0 SELECT STATEMENT Optimizer=CHOOSE
1 0 TABLE ACCESS (BY INDEX ROWID) OF 'COLOCATED'
2 1 INDEX (RANGE SCAN) OF 'COLOCATED_PK' (UNIQUE)


Statistics
----------------------------------------------------------
0 recursive calls
0 db block gets
2908 consistent gets
0 physical reads
0 redo size
1800272 bytes sent via SQL*Net to client
93622 bytes received via SQL*Net from client
1335 SQL*Net roundtrips to/from client
0 sorts (memory)
0 sorts (disk)
20001 rows processed


SELECT * FROM disorganized
WHERE x BETWEEN 20000 AND 40000;

20001 rows selected.

Elapsed: 00:00:03.45

Execution Plan
----------------------------------------------------------
0 SELECT STATEMENT Optimizer=CHOOSE
1 0 TABLE ACCESS (BY INDEX ROWID) OF 'DISORGANIZED'
2 1 INDEX (RANGE SCAN) OF 'DISORGANIZED_PK' (UNIQUE)



and Tom said...

Wall clock time like that is useful to a degree *in a single user system* with no wait events (all buffered IO, you own the CPU, no waiting on disk to through things off). In your case, you probably have a large enough buffer cache, you did not hit physical reads -- it was all about CPU. If you look at my example, the first query (colocated) did 258 physical reads, the second -- 1,684 (buffer cache not big enough to hold it all)

What you have to take into consideration as well are the other hidden scalability factors. Each consistent get will UP the number of latches we get to process this query. A latch = lock, lock = serialization device, serialization device = less scalable.

Using the technique outlined on:

</code> http://asktom.oracle.com/~tkyte/runstats.html <code>

I ran this test:


ops$tkyte@ORA817DEV.US.ORACLE.COM> create table colocated ( x int, y varchar2(2000) ) pctfree 0;
Table created.

ops$tkyte@ORA817DEV.US.ORACLE.COM> begin
2 for i in 1 .. 100000
3 loop
4 insert into colocated values ( i, rpad(dbms_random.random,75,'*') );
5 end loop;
6 end;
7 /
PL/SQL procedure successfully completed.

ops$tkyte@ORA817DEV.US.ORACLE.COM> create table disorganized nologging pctfree 0
2 as
3 select x, y from colocated ORDER BY y
4 /
Table created.

ops$tkyte@ORA817DEV.US.ORACLE.COM> alter table colocated add constraint colocated_pk primary key(x);

Table altered.

ops$tkyte@ORA817DEV.US.ORACLE.COM> alter table disorganized add constraint disorganized_pk primary key(x);

Table altered.

ops$tkyte@ORA817DEV.US.ORACLE.COM> drop table run_stats;
Table dropped.

ops$tkyte@ORA817DEV.US.ORACLE.COM> create table run_stats ( runid varchar2(15), name varchar2(80), value int );
Table created.

ops$tkyte@ORA817DEV.US.ORACLE.COM> create or replace view stats
2 as select 'STAT...' || a.name name, b.value
3 from v$statname a, v$mystat b
4 where a.statistic# = b.statistic#
5 union all
6 select 'LATCH.' || name, gets
7 from v$latch;

View created.

ops$tkyte@ORA817DEV.US.ORACLE.COM> declare
2 l_start number;
3
4 type Tab is table of varchar2(255);
5 l_x Tab;
6 l_y Tab;
7 begin
8 insert into run_stats select 'before', stats.* from stats;
9
10 l_start := dbms_utility.get_time;
11 select x, y bulk collect into l_x, l_y from COLOCATED where x between 20000 and 40000;
12 dbms_output.put_line( l_x.count || ' rows fetched from colocated' );
13 dbms_output.put_line( (dbms_utility.get_time-l_start) || ' hsecs' );
14
15
16 insert into run_stats select 'after 1', stats.* from stats;
17 l_start := dbms_utility.get_time;
18 select x, y bulk collect into l_x, l_y from DISORGANIZED where x between 20000 and 40000;
19 dbms_output.put_line( l_x.count || ' rows fetched from disorganized' );
20 dbms_output.put_line( (dbms_utility.get_time-l_start) || ' hsecs' );
21
22 insert into run_stats select 'after 2', stats.* from stats;
23 end;
24 /
20001 rows fetched from colocated
45 hsecs
20001 rows fetched from disorganized
166 hsecs

PL/SQL procedure successfully completed.

showing that the wall clock is better for colocated (using RBO here, both used index plans, that can be confirmed by tkprof)

Now, more importantly, lets look at the nitty gritty details:


ops$tkyte@ORA817DEV.US.ORACLE.COM> select a.name, b.value-a.value run1, c.value-b.value run2,
2 ( (c.value-b.value)-(b.value-a.value)) diff
3 from run_stats a, run_stats b, run_stats c
4 where a.name = b.name
5 and b.name = c.name
6 and a.runid = 'before'
7 and b.runid = 'after 1'
8 and c.runid = 'after 2'
9 and (c.value-a.value) > 0
10 and (c.value-b.value) <> (b.value-a.value)
11 order by abs( (c.value-b.value)-(b.value-a.value))
12 /

NAME RUN1 RUN2 DIFF
------------------------------ ---------- ---------- ----------
...
STAT...free buffer requested 261 8243 7982
STAT...physical reads 257 8241 7984
LATCH.cache buffers lru chain 260 8302 8042
STAT...session pga memory 0 8512 8512
STAT...session logical reads 295 20055 19760
STAT...buffer is not pinned co 231 19999 19768
unt

STAT...buffer is pinned count 39787 20019 -19768
STAT...no work - consistent re 264 20032 19768
ad gets

STAT...consistent gets 269 20038 19769
LATCH.cache buffers chains 871 48482 47611

39 rows selected.
ops$tkyte@ORA817DEV.US.ORACLE.COM>



Lots more Latches. Latches in a single user system are not worrisome. Add a user and they drop your speed like a falling brick.



Rating

  (6 ratings)

Is this answer out of date? If it is, please let us know via a Comment

Comments

Peter L, April 24, 2002 - 9:07 pm UTC

Hi Tom,

I'm the person who posted the question. I ran the following script in my environment and got a very different result!?

thanks

declare
type Tab is table of varchar2(255);

l_start number;
l_x Tab;
l_y Tab;

begin
delete from run_stats;
commit;

-- start by getting a snapshot of the v$ tables
insert into run_stats
select 'before', stat.*
from (
select 'STAT...' || a.name name, b.value
from v$statname a, v$mystat b
where a.statistic# = b.statistic#
union all
select 'LATCH.' || name, gets
from v$latch) stat;

-- and start timing...
l_start := dbms_utility.get_time;


SELECT x, y BULK COLLECT
INTO l_x, l_y
FROM colocated
WHERE x BETWEEN 20000 AND 40000;

dbms_output.put_line( (dbms_utility.get_time-l_start) || ' hsecs' );

-- get another snapshot and start timing again...
insert into run_stats
select 'after 1', stat.*
from (
select 'STAT...' || a.name name, b.value
from v$statname a, v$mystat b
where a.statistic# = b.statistic#
union all
select 'LATCH.' || name, gets
from v$latch) stat;

l_start := dbms_utility.get_time;

SELECT x, y BULK COLLECT
INTO l_x, l_y
FROM disorganized
WHERE x BETWEEN 20000 AND 40000;

dbms_output.put_line( (dbms_utility.get_time-l_start) || ' hsecs' );
insert into run_stats
select 'after 2', stat.*
from (
select 'STAT...' || a.name name, b.value
from v$statname a, v$mystat b
where a.statistic# = b.statistic#
union all
select 'LATCH.' || name, gets
from v$latch) stat;
end;
/

col name for a40

select a.name, b.value-a.value run1, c.value-b.value run2,
( (c.value-b.value)-(b.value-a.value)) diff
from run_stats a, run_stats b, run_stats c
where a.name = b.name
and b.name = c.name
and a.runid = 'before'
and b.runid = 'after 1'
and c.runid = 'after 2'
and (c.value-a.value) > 0
and (c.value-b.value) <> (b.value-a.value)
order by abs( (c.value-b.value)-(b.value-a.value))
/


NAME RUN1 RUN2 DIFF
------------------------------ --------- --------- ---------
LATCH.redo allocation 9 10 1
STAT...enqueue requests 1 0 -1
STAT...messages sent 1 0 -1
STAT...prefetched blocks 922 923 1
STAT...recursive cpu usage 35 36 1
STAT...redo entries 6 8 2
LATCH.active checkpoint queue 0 3 3
latch

STAT...db block changes 13 16 3
LATCH.redo writing 3 6 3
STAT...calls to get snapshot s 3 7 4
cn: kcmgss

LATCH.messages 4 10 6
STAT...consistent gets 1069 1075 6
STAT...hot buffers moved to he 7 0 -7
ad of LRU

LATCH.undo global data 2 10 8
STAT...db block gets 15 27 12
STAT...session logical reads 1084 1102 18
LATCH.cache buffers chains 3362 3391 29
LATCH.session idle bit 40 2 -38
LATCH.cache buffers lru chain 1064 1110 46
LATCH.shared pool 104 20 -84
LATCH.checkpoint queue latch 2 120 118
STAT...redo size 19720 20232 512
LATCH.library cache 660 74 -586
LATCH.row cache objects 3276 0 -3276



Tom Kyte
April 25, 2002 - 7:16 am UTC

What is your version and did you run this in ISOLATION (latches are cumulative across ALL sessions, the last part only makes sense in isolation. See
</code> http://asktom.oracle.com/~tkyte/runstats.html <code>

for details)

and always do a full cut and paste of the stuff from sqlplus, like I do.

A reader, May 10, 2002 - 6:11 pm UTC

Here's the result I have. The table structures and data are the same as the ones above.

Ran in isolation on an Oracle instance on my PC.  The ran this many times just made sure whatever should be in memory was already in memory.  The question is why is result I produced so much different from that produced in your environment given that we have the same table structures and data?

PL*SQL Version: 9.0.1.0.0

SQL> select * from v$version;

BANNER
----------------------------------------------------------
Oracle9i Enterprise Edition Release 9.0.1.1.1 - Production
PL/SQL Release 9.0.1.1.1 - Production
CORE    9.0.1.1.1       Production
TNS for 32-bit Windows: Version 9.0.1.1.0 - Production
NLSRTL Version 9.0.1.1.1 - Production


SQL> declare
  2      type    Tab is table of varchar2(255);
  3  
  4      l_start number;
  5      l_x Tab;
  6      l_y Tab;
  7  
  8  begin
  9      delete from run_stats;
 10      commit;
 11  
 12      -- start by getting a snapshot of the v$ tables
 13      insert into run_stats 
 14      select 'before', stat.*
 15      from  (
 16      select 'STAT...' || a.name name, b.value
 17      from   v$statname a, v$mystat b
 18      where  a.statistic# = b.statistic#
 19      union  all
 20      select 'LATCH.' || name,  gets
 21      from   v$latch) stat;
 22  
 23      -- and start timing...
 24      l_start := dbms_utility.get_time;
 25  
 26  
 27      SELECT x, y BULK COLLECT
 28      INTO   l_x, l_y
 29      FROM   colocated
 30      WHERE  x BETWEEN 20000 AND 40000;
 31  
 32      dbms_output.put_line( (dbms_utility.get_time-l_start) || ' hsecs' );
 33  
 34      -- get another snapshot and start timing again... 
 35      insert into run_stats 
 36      select 'after 1', stat.*
 37      from  (
 38      select 'STAT...' || a.name name, b.value
 39      from   v$statname a, v$mystat b
 40      where  a.statistic# = b.statistic#
 41      union  all
 42      select 'LATCH.' || name,  gets
 43      from   v$latch) stat;
 44  
 45      l_start := dbms_utility.get_time;
 46  
 47      SELECT x, y BULK COLLECT
 48      INTO   l_x, l_y
 49      FROM   disorganized
 50      WHERE  x BETWEEN 20000 AND 40000;
 51  
 52      dbms_output.put_line( (dbms_utility.get_time-l_start) || ' hsecs' );
 53      insert into run_stats 
 54      select 'after 2', stat.*
 55      from  (
 56      select 'STAT...' || a.name name, b.value
 57      from   v$statname a, v$mystat b
 58      where  a.statistic# = b.statistic#
 59      union  all
 60      select 'LATCH.' || name,  gets
 61      from   v$latch) stat;
 62  end;
 63  /

PL/SQL procedure successfully completed.

SQL> select a.name, b.value-a.value run1, c.value-b.value run2,
  2         ( (c.value-b.value)-(b.value-a.value)) diff
  3    from run_stats a, run_stats b, run_stats c
  4   where a.name = b.name
  5     and b.name = c.name
  6     and a.runid = 'before'
  7     and b.runid = 'after 1'
  8     and c.runid = 'after 2'
  9     and (c.value-a.value) > 0
 10     and (c.value-b.value) <> (b.value-a.value)
 11   order by abs( (c.value-b.value)-(b.value-a.value))
 12  /

NAME                                           RUN1       RUN2       DIFF
---------------------------------------- ---------- ---------- ----------
LATCH.channel operations parent latch             0          1          1
LATCH.redo writing                                3          4          1
LATCH.session timer                               0          1          1
STAT...enqueue requests                           1          0         -1
STAT...redo entries                              24         23         -1
STAT...change write time                          1          0         -1
STAT...calls to kcmgcs                           11         12          1
LATCH.enqueue hash chains                         0          2          2
LATCH.undo global data                            4          6          2
LATCH.shared pool                                23         20         -3
STAT...db block changes                          43         40         -3
STAT...recursive cpu usage                       30         33          3
LATCH.enqueues                                    0          4          4
LATCH.redo allocation                            23         27          4
STAT...calls to get snapshot scn: kcmgss          3          7          4
STAT...db block gets                             34         38          4
LATCH.library cache                              71         67         -4
LATCH.checkpoint queue latch                      1          8          7
LATCH.messages                                    1          9          8
STAT...buffer is not pinned count              2177       2186          9
STAT...no work - consistent read gets          2177       2186          9
STAT...table scan blocks gotten                2177       2186          9
STAT...consistent gets                         2185       2199         14
STAT...session logical reads                   2219       2237         18
STAT...redo size                              25396      25576        180
LATCH.multiblock read objects                     0        340        340
STAT...prefetched blocks                          0       1185       1185
STAT...free buffer requested                      1       1356       1355
STAT...physical reads                             0       1356       1356
LATCH.cache buffers lru chain                  2178       3542       1364
LATCH.cache buffers chains                     4500       5898       1398

31 rows selected.


 

Tom Kyte
May 11, 2002 - 7:02 am UTC

run tkprof and make sure the queries are using the index (the purpose of the test).

Based on your consistent gets -- I'm going to guess that either:

o you didn't add the constraints and there are no primary keys on X.
o you have analyzed the table and the optimizer is saying "index = bad idea", which in general it is since we are getting 20,000 rows from 100,000 (20% of the table)


When I run the example "as is" on 9i on Windows, I get:

...
STAT...no work - consistent re 524 20085 19561
ad gets

STAT...consistent gets 533 20100 19567
LATCH.cache buffers chains 1910 40485 38575

38 rows selected.

When I drop the primary keys I get:

...
STAT...consistent gets 2189 2204 15
STAT...db block changes 64 46 -18
LATCH.enqueues 26 6 -20
STAT...hot buffers moved to he 36 0 -36
ad of LRU.....

32 rows selected.


which is more in tune with what you have


Why couldn't I create a view based on v$..

Prince., May 15, 2002 - 4:36 pm UTC

Tom,

I tried to create a view similar to your "STATS" view.

SQL> create or replace view stats as
  2    select a.name name, b.value
  3          from v$statname a, v$mystat b
  4          where a.statistic# = b.statistic#
  5  /
        from v$statname a, v$mystat b
                           *
ERROR at line 3:
ORA-00942: table or view does not exist
                                                            

SQL> select * from v$mystat where rownum < 2 ;

       SID STATISTIC#      VALUE
---------- ---------- ----------
         8          0          1

Why am I getting this problem? What am I missing.

Note: I tried prefixing the view/synonym with sys. / sys.v_$ , but none of them work.

I am conneted as a user with DBA privileges.

Thanks
 

Tom Kyte
May 16, 2002 - 1:01 pm UTC

see
</code> http://asktom.oracle.com/~tkyte/runstats.html <code>

you have access to v$mystat via a role.



colocated or disorganized

A reader, January 16, 2003 - 7:57 am UTC

>>CREATE TABLE colocated (x int, y varchar2(2000)) pctfree 0;

>>CREATE TABLE disorganized

On what basis are you saying that the 2 tables created above are colocated or disorganized? How can you make out from the create table statement that the data is going to be colocated or disorganized?

Thank you

Tom Kyte
January 16, 2003 - 8:55 am UTC

in one, we:

CREATE TABLE colocated (x int, y varchar2(2000)) pctfree 0;

BEGIN
FOR I IN 1..100000 LOOP
INSERT INTO colocated VALUES
(i, RPAD(dbms_random.random, 75, ‘*’));
END LOOP;

commit;
END;
/
ALTER TABLE colocated ADD CONSTRAINT colocated_pk PRIMARY KEY(x);


so in this table, if you look on the database blocks, you would TEND to find that:

1,random******
2,random******
3,random*******
....
N,random*******


the data in the table is going to be more or less "sorted" by x. When we:

CREATE TABLE disorganized NOLOGGING PCTFREE 0 AS
SELECT x, y FROM colocated ORDER BY y;

ALTER TABLE disorganized ADD CONSTRAINT disorganized_pk PRIMARY KEY(x);

we'll find that data is organized in the table like this:


1032,random*****
32,random*****
2323,random*****
522,random*****


That is - the data in the table is NOT sorted by X -- so 1 is not by 2 is not by 3 and so on.





colocated or disorganized

A reader, January 16, 2003 - 10:42 am UTC


Colocated Table with CBO

Vivek Sharma, May 13, 2003 - 6:05 am UTC

Hi Tom,

I was also going thru this same example from your book. I have created the colocated table as mentioned in your book and the primary key constraint was added as well. When I first executed the query 

set autot traceonly

SQL> select * from colocated where x between 20000 and 40000;

20001 rows selected.


Execution Plan
----------------------------------------------------------
   0      SELECT STATEMENT Optimizer=CHOOSE
   1    0   TABLE ACCESS (BY INDEX ROWID) OF 'COLOCATED'
   2    1     INDEX (RANGE SCAN) OF 'PK_COLOCATED' (UNIQUE)




Statistics
----------------------------------------------------------
          0  recursive calls
          0  db block gets
       3156  consistent gets
          0  physical reads
          0  redo size
    1788256  bytes sent via SQL*Net to client
      93627  bytes received via SQL*Net from client
       1335  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
      20001  rows processed

It used the Primary Key index with 3516 consisten gets. 
When I queried it for

SQL> select * from colocated where x between 20000 and 80000;

60001 rows selected.

Elapsed: 00:01:83.70

Execution Plan
----------------------------------------------------------
   0      SELECT STATEMENT Optimizer=CHOOSE
   1    0   TABLE ACCESS (BY INDEX ROWID) OF 'COLOCATED'
   2    1     INDEX (RANGE SCAN) OF 'PK_COLOCATED' (UNIQUE)




Statistics
----------------------------------------------------------
          0  recursive calls
          0  db block gets
       9462  consistent gets
          0  physical reads
          0  redo size
    5391872  bytes sent via SQL*Net to client
     280317  bytes received via SQL*Net from client
       4002  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
      60001  rows processed

It again used the primary key index with 9462 consistent gets.
Then I analyzed the table so that it uses CBO

SQL> analyze table colocated compute statistics for table for all indexes for all indexed columns;

SQL> select * from colocated where x between 20000 and 40000;

20001 rows selected.

Elapsed: 00:00:56.40

Execution Plan
----------------------------------------------------------
   0      SELECT STATEMENT Optimizer=CHOOSE (Cost=133 Card=19991 Bytes
          =1579289)

   1    0   TABLE ACCESS (FULL) OF 'COLOCATED' (Cost=133 Card=19991 By
          tes=1579289)





Statistics
----------------------------------------------------------
          0  recursive calls
          5  db block gets
       3479  consistent gets
          0  physical reads
          0  redo size
    1796266  bytes sent via SQL*Net to client
      93626  bytes received via SQL*Net from client
       1335  SQL*Net roundtrips to/from client
          1  sorts (memory)
          0  sorts (disk)
      20001  rows processed

SQL> select * from colocated where x between 20000 and 80000;

60001 rows selected.

Elapsed: 00:01:108.30

Execution Plan
----------------------------------------------------------
   0      SELECT STATEMENT Optimizer=CHOOSE (Cost=133 Card=59971 Bytes
          =4737709)

   1    0   TABLE ACCESS (FULL) OF 'COLOCATED' (Cost=133 Card=59971 By
          tes=4737709)





Statistics
----------------------------------------------------------
          0  recursive calls
          5  db block gets
       6088  consistent gets
          0  physical reads
          0  redo size
    5391872  bytes sent via SQL*Net to client
     280317  bytes received via SQL*Net from client
       4002  SQL*Net roundtrips to/from client
          1  sorts (memory)
          0  sorts (disk)
      60001  rows processed


The behaviour of both the queries changed and it went for full table scan with 3479 consistent gets against 3156 for 20001 rows and more elapsed time than previous. For Second Query, 6088 consistent gets against 9462 for 60001 rows again with more elapsed time. 

When it was using index, it was running faster and after analyzing it runs slow. This is when there is no load on the database but I am afraid when there are many users connected to the DB, what would be the impact. 

Please Explain this behavior.
Thanks and Regards
Vivek Sharma 

Tom Kyte
May 13, 2003 - 7:35 am UTC

elapsed timing in sqlplus is of great academic interest but pretty useless. tell me, what is 1:108.30? I don't know myself.

You are timing the amount of time it takes sqlplus to process the data, to paint the screen, the network to transfer, the database to process other peoples requests. Most relevant, it times the time to query the v$ tables as well which in MANY cases takes longer then the query itself.

Use TKPROF and TIMED_STATISTICS.

In the above, the CBO did the right things in all cases and if you tkprof it, you'll find it is faster.

More to Explore

PL/SQL demos

Check out more PL/SQL tutorials on our LiveSQL tool.

PL/SQL docs

PL/SQL reference manual from the Oracle documentation library