Performance of Autotrace

I have been having some performance problems when using autotrace in some production systems. I finally had time to check out why.

I enabled sql trace in my autotrace session to see what was causing the slow response. As you may already know setting autotrace on opens another session other than the session you are executing your query in. This second session reports statistics of the main session which executes your query. This second session is the one I have enabled sql trace for.

In the original session, I set the timing on to see the elapsed times and run a simple query which returns immediately.

SQL> set timing on
SQL> select sid from v$mystat where rownum=1;

SID
----------
20892

Elapsed: 00:00:00.00
SQL> select * from dual;

D
-
X

Elapsed: 00:00:00.00

Now I set autotrace on.

SQL> set autot trace

This opens another session for me. You can now query v$session and find out that you have 2 sessions, one with sid=20892 which is the main session and another one with a different sid. I enable sql trace for that other session to see what it is doing. From another session run the following to enable sql trace.

SQL> exec dbms_system.SET_SQL_TRACE_IN_SESSION(133,9526,true);

PL/SQL procedure successfully completed.

Now from the main session I execute the same simple query again and set autotrace off after that.

SQL> select * from dual;

Elapsed: 00:01:14.08

Execution Plan
----------------------------------------------------------
   0      SELECT STATEMENT Optimizer=CHOOSE
   1    0   TABLE ACCESS (FULL) OF 'DUAL'




Statistics
----------------------------------------------------------
          0  recursive calls
          0  db block gets
          3  consistent gets
          0  physical reads
          0  redo size
        205  bytes sent via SQL*Net to client
        273  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
          1  rows processed

SQL> set autot off

Look at the elapsed time! It is more than 1 minutes with autotrace on. Now when I look at the trace file produced I see that the sql running this long is the following.

SELECT PT.VALUE
FROM
 SYS.V_$SESSTAT PT WHERE PT.SID=:1 AND PT.STATISTIC# IN (7,40,41,42,115,239,
  240,241,245,246) ORDER BY PT.STATISTIC#


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        2      0.00       0.00          0          0          0           0
Execute      2      0.00       0.00          0          0          0           0
Fetch        4     73.41      73.03          0          0          0          20
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        8     73.41      73.03          0          0          0          20

Misses in library cache during parse: 0
Optimizer goal: CHOOSE
Parsing user id: 32

Rows     Row Source Operation
-------  ---------------------------------------------------
     10  SORT ORDER BY
     10   FILTER
     10    FIXED TABLE FULL X$KSUSESTA
      1    FIXED TABLE FULL X$KSUSGIF

The view V_$SESSTAT is based on two fixed tables, named as X$KSUSESTA and X$KSUSGIF. X$KSUSESTA is a large object holding the statistics for all sessions. So, if you have thousands of sessions it may take a long time to query this fixed table and autotrace suffers from that. Here is the number of rows from this view in my instance.

SQL> select count(*) from X$KSUSESTA;

  COUNT(*)
----------
   7000000

Parsing in remote databases

I was trying to decrease the number of parses for a 9.2.0.7 production database when I realized that the top parsing sql was coming from another database through a database link. This sql has a parse/execute ratio of 1 meaning it is parsed every time it is called. I have searched the bug database and found that there is a bug about parsing when you are joining a local table with a remote table, the bug number is 4913460. For those who are using db links extensively the following is a test case showing the parsing problem in remote databases.

In the remote database create a simple table:

SQL> create table remote_table
  2  as select level remote_a from dual connect by level <=1000;

Table created.

SQL> create index remote_ind1 on remote_table(remote_a);

Index created.

In the local database create a simple table:

SQL> create table local_table
 2  as select level local_a from dual connect by level <=5000;

Table created.

SQL> create index local_index on local_table(local_a);

Index created.

Than create a database link connecting these two databases (commands not printed here) and query the local table joining it to the remote table:

declare
v_a number;
begin
for i in 1..1000 loop
select local_a into v_a from local_table
where local_a in (select remote_a from remote_table@test.world where remote_a=i);
end loop;
end;
/

In the remote database check v$sqlarea for the part of this sql (you can first get the hash_value by querying v$sqlarea with: sql_text like '%REMOTE_TABLE%'):

SQL> COLUMN   sql_text FORMAT   a30
SQL> select hash_value,sql_text,executions,parse_calls from v$sqlarea where hash_value=1971931531;

HASH_VALUE SQL_TEXT                       EXECUTIONS PARSE_CALLS
---------- ------------------------------ ---------- -----------
1971931531 SELECT "REMOTE_A" FROM "REMOTE       1000        1000
           _TABLE" "REMOTE_TABLE" WHERE "
           REMOTE_A"=:1

The sql in the remote database is parsed for every execution. In the local database again, try with EXISTS:

declare
v_a number;
begin
for i in 1..1000 loop
select local_a into v_a from local_table
where local_a=i and exists (select null from remote_table@test.world where remote_a=local_table.local_a);
end loop;
end;
/

The remote database shows:

SQL> r
  1* select hash_value,sql_text,executions,parse_calls from v$sqlarea where hash_value=1971931531

HASH_VALUE SQL_TEXT                       EXECUTIONS PARSE_CALLS
---------- ------------------------------ ---------- -----------
1971931531 SELECT "REMOTE_A" FROM "REMOTE       2000        2000
           _TABLE" "REMOTE_TABLE" WHERE "
           REMOTE_A"=:1

This bug will be fixed in 11.1 but has a patch on 9.2.0.8.

The Read Consistency Trap in Sql Tracing

There are some important things to consider when interpreting sql trace files. One of the most important ones is the read consistency trap as it is called in the documentation.

If you see different number of block reads with the same data at different times when you trace a sql statement, this can be one reason. A test case showing what this means follows:

SQL> create table t as select * from all_objects;

Table created.

SQL> alter session set sql_trace=true;

Session altered.

SQL> begin
 2  for t in (select * from t) loop
 3  null;
 4  end loop;
 5  end;
 6  /

PL/SQL procedure successfully completed.

After doing a full table scan from the above session, update all rows from another session:

SQL> update t set object_name='test';

23840 rows updated.

Execute the last sql from the first session again:

SQL> /

PL/SQL procedure successfully completed.

When you get the tkprof output with aggregate=no you can see the statistics for the two executions of the same statement differently without aggregation.

tkprof test_ora_6273.trc test.txt aggregate=no

In test.txt you can see the two executions of the statement:

SELECT *
FROM
T


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    23841      0.82       0.71        331      23844          0       23840
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total    23843      0.82       0.71        331      23844          0       23840

SELECT *
FROM
T


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    23841      1.19       1.00          0      48015          0       23840
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total    23843      1.19       1.00          0      48015          0       23840

Why did the numbers in the "query" column approximately double when the number of rows, the number of fetches did not change? Because there is an active transaction on the table which updated all the rows. So in order to get a read consistent view of the table the query goes to the undo blocks as well as table blocks.

What this suggests is; it is important when to trace an application. If the application you are trying to tune is running when there are transactions on the tables it accesses then you need to trace the application in that context. If you trace it when there are no transactions on its tables, you can come to the conclusion that the number of block reads is appropriate. Or you can focus on an sql taking much of the execution time when the sql you need to tune is actually another one.

An effect of sql_trace=true

Tom Kyte has a recent post about explain plan.

In that there is something I have not realized before that I want to share. When you execute a sql statement after you set sql_trace=true it is hard parsed again even if it is already in the shared pool.

A simple test is below.

SQL> select 'test' from dual;

'TES
----
test

SQL> alter session set sql_trace=true;

Session altered.

SQL> select 'test' from dual;

'TES
----
test

SQL> exit

The tkprof output shows that the same statement run after setting sql_trace=true is hard parsed again.

select 'test'
from
dual


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        2      0.00       0.00          0          1          0           1
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4      0.00       0.00          0          1          0           1

Misses in library cache during parse: 1

Compare this with the same sql run two times after setting sql_trace=true.

SQL> alter session set sql_trace=true;

Session altered.

SQL> select 'test2' from dual;

'TEST
-----
test2

SQL> r
 1* select 'test2' from dual

'TEST
-----
test2


SQL> exit



select 'test2'
from
dual


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        2      0.00       0.00          0          0          0           0
Execute      2      0.00       0.00          0          0          0           0
Fetch        4      0.00       0.00          0          2          0           2
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        8      0.00       0.00          0          2          0           2

Misses in library cache during parse: 1

Sql trace has the side effect of hard parsing every statement executed after it is enabled. If you have your sql statements already in the shared pool before enabling sql trace, be careful that you will be seeing the execution plans for your particular execution in that particular time, not the ones from the shared pool.

Client-side Load Balancing

A new case study has been published in Metalink about how to configure a high connect load environment. If you have an environment where bursts of logon activity appears sometimes and your tns listener is unable to cope with the demand then you can take a look at the note to see possible solutions. It is a simple note that basically describes how the tns listener works and what to when the listener cannot respond to connection requests.

There are mainly two solutions suggested:

1. Increasing the number of listeners
2. Using shared server

Increasing the number of listeners is the first logical solution that comes up. Because a single listener process can handle a limited number of requests at one time, multiple listener processes can handle many more requests. When you configure multiple listeners you also need to change the tns entries in your clients. The sample tns entry provided in that note is this:

GEORGE=
(DESCRIPTION=
(LOAD_BALANCE=ON)
(FAILOVER=ON)
(ADDRESS=(PROTOCOL=TCP)(HOST=george.us.oracle.com)(PORT=1521)
(ADDRESS=(PROTOCOL=TCP)(HOST=george.us.oracle.com)(PORT=1522)
(ADDRESS=(PROTOCOL=TCP)(HOST=george.us.oracle.com)(PORT=1523)
(ADDRESS=(PROTOCOL=TCP)(HOST=george.us.oracle.com)(PORT=1524)
(CONNECT_DATA=(SERVICE_NAME=V10R2.us.oracle.com)))

This ensures that connections are balanced between the specified ports, meaning different listener processes.

But there is one restriction that is not mentioned in the case study. If you have clients using Net8 (not higher versions) like Forms6i applications, the LOAD_BALANCE parameter does not exist, so you cannot load balance client connections using this entry. If you have such clients you need to use description lists in your tns entry as described in Metalink note 67137.1. The tns entry for load balancing in Net8 is like this:

TEST=
(DESCRIPTION_LIST=
(DESCRIPTION=
(ADDRESS=
(PROTOCOL=TCP)(HOST=host1)(PORT=1521)
)
(CONNECT_DATA=(SID=TEST))
)
(DESCRIPTION=
(ADDRESS=
(PROTOCOL=TCP)(HOST=host1)(PORT=1522)
)
(CONNECT_DATA=(SID=TEST))
)
)

Sure it is better to fix the application to correct the logon burst problem but in case you have a situation where you cannot fix the application for any reason it is good to be aware of these solutions.

Testing Blogmailr

From Lifehacker:

A new service to post to your blog by sending an e-mail is out. Blogmailr gives you an e-mail address to send your posts and allows to specify secure sender addresses to accept e-mails from.

I am sending this post using my secure Blogmailr address to see if it works.

See it for yourself at www.blogmailr.com.

Reverse Key Index

There is an option to create index entries as reversed, which is called reverse key indexes. Oracle stores the index entries as their bytes reversed, except rowids of course.

There are a few cases where reverse key indexes can help to improve performance. One is in RAC environments. If you have a column populated by an increasing sequence the new entries come to the same blocks when you are inserting rows. If you have many concurrent sessions inserting rows from different RAC instances then you will have a contention for the same index blocks between nodes. If you use reverse key indexes in this case then the new index entries will go to different blocks and contention will be reduced.

In single instance databases there is also a case where reverse key indexes can be helpful. If you have a column populated by an increasing sequence, you delete some old rows from the table and you do not do range scans on that column and you have contention issues on index blocks, reverse key indexes can be considered. The reverse key index will scatter the entries accross different blocks during inserting and your many concurrent sessions will not have index block contention issues.

If you are deleting some old rows, the blocks from a normal index on that column will have some used and some empty space in them, but they will not be put on the freelist because they are not completely free. That empty space will not be used because the sequence values are always increasing and they will not go to those old blocks because of that. You will be able to use that space for different values with reverse key indexes.

One of the things to be careful about reverse key indexes is that you cannot perform range scans on them. Because the entries are stored as reversed you lose the capability to range scan on that index.

I had a situation just fitting the reasons to use a reverse key index. We have many concurrent programs that insert into the same table. The table has a primary key column populated by an increasing sequence. There are no range scans on that column. The data is deleted time to time according to some rules which leave some old data undeleted in the table. When these programs are running statspack reports show high buffer busy waits for the index segment (More than 900,000 waits for a 30 minute period causing %85 of all buffer busy waits). Also as this database will be converted to a RAC database soon, this case seems very appropriate to use a reverse key index on the related column.

To change an existing index as a reverse key index you can use the alter index statement.

alter index indexname rebuild reverse;

After this change the index size was reduced down to 16MB from 250MB. This change got rid of the buffer busy waits on the index blocks. The program run time was reduced from about 40 minutes to about 25 minutes.

A few discussions from asktom about reverse key indexes are here, here and here.

Effective Oracle by Design

I have finished reading Effective Oracle by Design. I consider this as one of the must reads after Oracle documentation for both dbas and developers  (Oracle documentation comes before any other book of course). It is not a beginner's book, fundamentals of sql, plsql and database administration are not the topics of the book. Tom Kyte explains how to design and build high performance applications on the Oracle database.

Designing before building an application is the most important and critical item in developing successful applications. Unfortunately it is also generally the most overlooked part. Datatypes, table types, tools to use, database features to use are critical for the application's performance and success. The application developed without performance in mind will end as a failure most probably. In this book Tom Kyte explains what the right approach he thinks is to design successful applications. What are the different types of tables available? What are the tools available? How is a sql statement processed in the database? How can one use plsql effectively? When should we use a specific database feature and when should not we use that feature? All chapters presented with lots of examples and you can test the examples provided yourself to gain more understanding of the subject.

If you are a regular reader of the asktom site as I am, you will find examples and subjects scattered around many questions and answers similar to those in the book. The examples in the book were familiar to me. But he collects all those subjects and examples in this book in a systematic way. Each chapter can be read on its own but I strongly suggest reading it line by line from the beginning to the end. It is well worth the effort and the time.

The first print year of the book is 2003. The examples are on 9.2 and 8.1.7. But do not think that this is an outdated book for 10g. Because of the above mentioned reasons the contents are also applicable to applications being developed on 10g. Tom gives his thoughts, experience, hints, tips about the right approach to developing applications. These are independent of the database version.

According to me the most important chapters are 7th (Effective Schema Design), 8th (Effective SQL) and 9th (Effective PL/SQL Programming).

Having every dba and developer in your team read this book will immediately make a significant positive effect on the applications you develop.

So, now I have two books waiting to be read. Expert Oracle Database Architecture and Cost-Based Oracle Fundamentals.

DBA vs. Developer

A few days ago there was a short thread on asktom about the role of the developer and the dba. This is a topic that is usually discussed. Some think dbas are a blockage to stop the developers doing their work, some think dba is the king.

I have seen some dbas who think they do not need to know about plsql, analytics and other things related to development. I have seen many developers who are not aware of anything called analytics, tkprof, plsql features like bulk collect, etc. I think both are dangerous.

I have started my career as a developer writing code on Oracle Forms and plsql. I currently work as a production dba. This does not involve routine administration like backups, upgrades, installations, tablespace management, etc. only.  It involves sql tuning, reviewing the developers' code for performance improvements, suggesting physical schema design changes. Usually developers come to me to ask about a poorly performing sql or plsql procedure, about how to do something efficiently in plsql, about how to design the schemas. I can say I work as an internal consultant to developers.

Actually what I like in being this kind of a dba is the "working with developers" part, not the "production dba" part. I like to learn and study database features, sql and plsql tuning. Fortunately routine administration tasks are becoming easier and easier as new versions bring new features that are helpful to dbas and they take less amount of time in each new version.

Tom has a nice classification for dbas and developers. I consider myself as a dba/developer according to that. To be a successful dba you should know about development also, to be a successful developer you should know what the database features are, what it offers to you to do your job in an efficient way.

I cannot understand a dba who thinks that developers are a waste of time, who does not like to work with developers, who throws the code to the developers and order them to correct and tune it. As far as I have seen it is true that most developers do not know about cbo, analytics, tkprof, stuff they should know about, but the dba must take responsibility on this and try to make the developer aware of these and help them use all the features of the database appropriately. Databases are there to store data and data is there to be made available to users through programs made by developers. So it is a team work including dbas and developers to make the database useful to users.

Back to blogging

I have not posted anything here for a long time. That was because i had lost the will to blog. I did not give up reading all the blogs on my list during that time because i find all of them very useful and fun to read. But when it came to writing and posting myself, i did not have the will to do it.

Since my last post, nothing significant has changed. I have entered the OCP exams and received my database OCP certificate. I will post about that soon. I have read some Oracle books of course, the best and the most important one being Effective Oracle by Design. I have recently bought Cost-Based Oracle Fundamentals and Expert Oracle Database Architecture. I will post about these also.

So, back to blogging...

Index maintenance of 10G

I have read at Eric S. Emrick’s blog about the redo behaviour seen when updating a primary key column Oracle takes some special steps to prevent unique key collisions that may temporarily occur during the update. You can read what it does at Eric’s post in detail. As Eric shows, it maintains the index entries while doing the update, something like; update the table row, process the index leaf, update the second row, process the index leaf, etc..

I have realized that this behaviour changes in 10G R2 (i do not know about R1 as i have not tested on it). In 10G R2, it updates all the rows first without touching the index entries and changes the index entries afterwards. Here is a test case:

SQL> create table t as select rownum col1,1 col2
2  from all_objects
3  where rownum<=10; 

Table created.  

SQL> alter table t add primary key(col1);

Table altered.

SQL> select index_name from user_indexes where table_name = 'T';

INDEX_NAME
------------------------------
SYS_C0028217


SQL> update t set col1=col1+1;

10 rows updated.

The related log file shows that index maintenance steps come after all rows are updated:

       SCN  REL_FILE#  DATA_BLK#  DATA_OBJ# OP
---------- ---------- ---------- ---------- --------------------
2.9868E+10          0          0          0 START
2.9868E+10          3     131196     121729 UPDATE
2.9868E+10          3     131196     121729 UPDATE
2.9868E+10          3     131196     121729 UPDATE
2.9868E+10          3     131196     121729 UPDATE
2.9868E+10          3     131196     121729 UPDATE
2.9868E+10          3     131196     121729 UPDATE
2.9868E+10          3     131196     121729 UPDATE
2.9868E+10          3     131196     121729 UPDATE
2.9868E+10          3     131196     121729 UPDATE
2.9868E+10          3     131196     121729 UPDATE

  SCN  REL_FILE#  DATA_BLK#  DATA_OBJ# OP
---------- ---------- ---------- ---------- --------------------
2.9868E+10          0          0     121730 INTERNAL
2.9868E+10          0          0     121730 INTERNAL
2.9868E+10          0          0     121730 INTERNAL
2.9868E+10          0          0     121730 INTERNAL
2.9868E+10          0          0     121730 INTERNAL
2.9868E+10          0          0     121730 INTERNAL
2.9868E+10          0          0     121730 INTERNAL
2.9868E+10          0          0     121730 INTERNAL
2.9868E+10          0          0     121730 INTERNAL
2.9868E+10          0          0     121730 INTERNAL
2.9868E+10          0          0          0 COMMIT

SQL> select object_name, object_id from dba_objects where object_id in (121729,121730);

OBJECT_NAME                     OBJECT_ID
------------------------------ ----------
T                                  121729
SYS_C0028217                       121730

Compare this with Eric’s test case which shows (i have also tested this on 9.2):

            SCN  REL_FILE#  DATA_BLK#  DATA_OBJ# OP
--------------- ---------- ---------- ---------- --------------------
  4571216          0          0          0 START
  4571216          3        554       6480 UPDATE
  4571216          0          0       7149 INTERNAL
  4571216          3        554       6480 UPDATE
  4571216          0          0       7149 INTERNAL
  4571216          3        554       6480 UPDATE
  4571216          0          0       7149 INTERNAL
  4571216          3        554       6480 UPDATE
  4571216          0          0       7149 INTERNAL
  4571216          3        554       6480 UPDATE
  4571216          0          0       7149 INTERNAL
  4571216          3        554       6480 UPDATE
  4571216          0          0       7149 INTERNAL
  4571216          3        554       6480 UPDATE
  4571216          0          0       7149 INTERNAL
  4571216          3        554       6480 UPDATE
  4571216          0          0       7149 INTERNAL
  4571216          3        554       6480 UPDATE
  4571216          0          0       7149 INTERNAL
  4571216          3        554       6480 UPDATE
  4571216          0          0       7149 INTERNAL
  4571216          0          0       7149 INTERNAL

UPDATE: Please see the comments for this post, reason of the difference of the results between 9i and 10G are explained there.

coComments to follow the comments

From Eddie Awad i have read about a new cool service called coComments. Tracking my comments and people’s comments after that has always been a problem for me. This service gives you a single page to see all your comments you made to all the blogs you read. You put a bookmarklet to your browser and click on it when you are making a comment on a blog. From your coComments page you can view all the comments and also the comments made by other people after your comment (of course if they are also using coComments). You can register at coComments site, it is invitation based, Eddie Awad’s post has some invitation codes for that, so be quick if you want to use them as they can be used only once.

If you are a blog writer you can also put a small code in your blog and show your comments to the other blogs on your own page. I have placed this above the links section on the right. And you can also get an rss feed that tracks all the comments from the blog that you comment on.

Cool…

Test for performancing extension for Firefox

This post is written with the performancing extension for Firefox.

This extension opens an editor window inside your current tab in Firefox and lets you edit and post to Blogger, Wordpress and Movable Type. Works with Firefox 1.5.

I have read about this extension at Robert Scoble's blog.

Touch count bug

I came upon this comment from Jonathan Lewis. He talks about a bug related to the touch count. If you are full scanning some tables and you are using versions before 10g, be aware that they are not kept in the buffer cache no matter how frequently you scan them.

Here is a simple test case in 9.2.0.7.

create table t as select object_id from user_objects where rownum=1;

SQL> select data_object_id from user_objects2  where object_name='T';

DATA_OBJECT_ID
--------------
  20505
SQL> select distinct dbms_rowid.rowid_block_number(rowid) from t;

DBMS_ROWID.ROWID_BLOCK_NUMBER(ROWID)
------------------------------------
                        11970

SQL> begin
2  for t in (select * from t) loop
3     null;
4  end loop;
5  end;
6  /

PL/SQL procedure successfully completed.

SQL> select file#,dbablk,tch from x$bh where obj=20505;

FILE#     DBABLK        TCH
---------- ---------- ----------
  1      11969          3
  1      11970          0

After scanning the small table 10 times we see that the touch count for the block is 0.

So, how can we keep the small parameter tables which are scanned frequently? One thing to consider is the use of the file system cache as Jonathan Lewis mentiones in the same link. If you are using a file system cache than it is likely that these tables are in that cache and can be retrieved into the database buffer cache when requested.

Another option is to use a keep pool that is sized according to the sizes of the tables we want to keep and alter the tables to use that cache. This way we can keep the tables cached although scanning them does not increment the touch count.

Be careful about bind peeking

I have been trying to tune a plsql package which runs for more than 1.5 hours. When looking at the raw sql trace file, i saw that a select statement was causing thousands of db file sequential reads for some of the bind variables. The pseudo-code is like this:

Cursor c1 is select <col list> from <master table> order by <col>;
Cursor c2(v1 in number) is select <col list> from <table> where <col>=v_1;
Open c1;
loop
    Fetch from c1;
    Process c1 row;
    Open c2(<value from c1>);
    Loop
        Fetch from c2;
        Process c2 row;
    End loop;
End loop;

The problem sql statement was the select in cursor c2. It came out that it was performing well for some parameters and running awful for some parameters. The problem is that for the first time c2 is opened it produces an execution plan for the related parameter value and uses that plan for all the next calls to the same statement. This is called bind variable peeking. So if the next value for the bind variable is not similar to the previous one in terms of statistics (number of matching rows, etc...) the same plan may not be appropriate for it.

If you a have a column that has a skewed data distribution, a histogram on it and if you are using bind variables against that column you may suffer from the same problem.

Here is a very very simplified test case of the problem.

SQL> create table bind_test as select 'MANY' object_name,object_id from all_objects;

Table created.

SQL> insert into bind_test select * from bind_test;

24221 rows created.

SQL> r
1* insert into bind_test select * from bind_test

48442 rows created.

SQL> r
1* insert into bind_test select * from bind_test

96884 rows created.

SQL> commit;

Commit complete.

SQL> create index bind_test_ind on bind_test(object_name);

Index created.

SQL> insert into bind_test select 'FEW',object_id from all_objects where rownum<=10
2 ;

10 rows created.

SQL> commit;

Commit complete.

SQL> select object_name,count(*) from bind_test group by object_name;

OBJE COUNT(*)
---- ----------
FEW 10
MANY 193768

SQL> EXEC dbms_stats.gather_table_stats(ownname=>null,tabname=>'BIND_TEST',cascade=>true,method_opt=>'for all indexed columns size 2');

PL/SQL procedure successfully completed.

Now, i have a table with many rows that have ‘MANY’ as the object_name and very few rows that have ‘FEW’ as the object_name and a histogram on the object_name column.

SQL> alter session set events '10046 trace name context forever, level 12';

Session altered.

SQL> declare
  2  b1 varchar2(4);
  3  begin
  4  b1 := 'FEW';
  5  for t in (select * from bind_test where object_name=b1) loop
  6     null;
  7  end loop;
  8  b1 := 'MANY';
  9  for t in (select * from bind_test where object_name=b1) loop
 10     null;
 11  end loop;
 12  end;
 13  /

I run the same sql first for the value ‘FEW’ and then for the value ‘MANY’. The trace output shows:

SELECT *
FROM
 BIND_TEST WHERE OBJECT_NAME=:B1


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        2      0.00       0.00          0          0          0           0
Execute      2      0.01       0.01          0          0          0           0
Fetch   193770      5.33       5.70        398     387539          0      193768
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total   193774      5.34       5.71        398     387539          0      193768

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

Rows     Row Source Operation
-------  ---------------------------------------------------
      0  TABLE ACCESS BY INDEX ROWID BIND_TEST
      0   INDEX RANGE SCAN BIND_TEST_IND (object id 82756)

It uses the index on object_name which is good for the value ‘FEW’ but bad for the value ‘MANY’. Because when the statement was parsed the bind variable had the value ‘FEW’ and the execution plan is produced for that value. Subsequent runs of the statement used the same plan even if the bind variable’s value has completely different statistics.

If you have a similar situation, you can use literals instead of bind variables. For this, you have to hard code the values as literals to the statements or you can use dynamic sql and produce the sql with literals at run time. Be aware of the consequences (parsing, many different sqls in the shared pool, etc...).

If the performance of the query for most of the bind values is ok with a specific plan and negligibly worse for the other values with the same plan, you can use hints to force the same plan for all of the bind values (unlike the above simple example). Or you can use stored outlines instead of hints. This was the way i chose. I created a stored outline to force the same plan for the bind values. The execution time dropped to less than 15 minutes from more than 1 hour.

Any other solutions to the bind peeking problem i could not remember?

Bulk Collect

Executing sql statements in plsql programs causes a context switch between the plsql engine and the sql engine. Too many context switches may degrade performance dramatically. In order to reduce the number of these context switches we can use a feature named bulk binding. Bulk binding lets us to transfer rows between the sql engine and the plsql engine as collections. Bulk binding is available for select, insert, delete and update statements.

Bulk collect is the bulk binding syntax for select statements. All examples below are simplified versions of the live cases i have seen.

One of the things i usuallly come accross is that developers usually tend to use cursor for loops to process data. They declare a cursor, open it, fetch from it row by row in a loop and process the row they fetch.

Declare
Cursor c1 is select column_list from table_name>;
Rec1 c1%rowtype;
Begin
Open c1;
Loop;
Fetch c1 into r1;
Exit when c1%notfound;
--process rows...
End loop;
End;

Here is a simple test case to compare the performance of fetching row by row and using bulk collect to fetch all rows into a collection.

SQL> create table t_all_objects as select * from all_objects;

Table created.

SQL> insert into t_all_objects select * from t_all_objects;

3332 rows created.

SQL> r
1* insert into t_all_objects select * from t_all_objects

6664 rows created.

---replicated a couple of times

SQL> select count(*) from t_all_objects;

COUNT(*)
----------
213248

SQL> declare
cursor c1 is select object_name from t_all_objects;
2    3  rec1 c1%rowtype;
4  begin
5  open c1;
6  loop
7     fetch c1 into rec1;
8     exit when c1%notfound;
9
10     null;
11
12  end loop;
13  end;
14  /

PL/SQL procedure successfully completed.

Elapsed: 00:00:44.75

SQL> declare
2  cursor c1 is select object_name from t_all_objects;
3  type c1_type is table of c1%rowtype;
4  rec1 c1_type;
5  begin
6  open c1;
7
8     fetch c1 bulk collect into rec1;
9
10
11  end;
12  /

PL/SQL procedure successfully completed.

Elapsed: 00:00:05.32

As can be clearly seen, bulk collecting the rows shows a huge performance improvement over fetching row by row.

The above method (which fetched all the rows) may not be applicable to all cases. When there are many rows to process, we can limit the number of rows to bulk collect, process those rows and fetch again. Otherwise process memory gets bigger and bigger as you fetch the rows.

SQL> declare
2  cursor c1 is select object_name from t_all_objects;
3  type c1_type is table of c1%rowtype;
4  rec1 c1_type;
5  begin
6  open c1;
7  loop
8     fetch c1 bulk collect into rec1 limit 200;
9     for i in 1..rec1.count loop
10             null;
11     end loop;
12     exit when c1%notfound;
13  end loop;
14
15
16  end;
17  /

PL/SQL procedure successfully completed.

Elapsed: 00:00:04.07

Detailed documentation for bulk collect can be found in Chapter 5 - PL/SQL User’s Guide and Reference.
The above examples are on 9.2.

Synonyms for remote synonyms

In my last post i have mentioned about the sql*net message from client waits in Oracle Forms. I was working on the same problem and found out that the problem was related to the synonym the form accesses.

I have a synonym that points to a remote synonym in another database which points to a table in another schema in the same remote database.

In the remote database, i have a table on user_b which i want to to select from user_a. So, i create a synonym for it at user_a.

User_A: create synonym tab1 for user_b.tab1; --(assuming select privilege on user_b.tab1 has been granted to user_a)

In the local database (which the form connects):

Create database link remotedb.world
Connect to user_a identified by user_a
Using ‘remotedb’;

Create synonym tab1 for tab1@remotedb.world;

Then i create a simple form which connects to the user at the local database and uses tab1 as its base table. The form queries one row from that table and updates that row. The sql trace output for this form shows (the sql trace contains a select for update statement for one row and an update statement for that row):

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  SQL*Net message to client                     167        0.00          0.00
  SQL*Net message from client                   167        0.07          0.26
  SQL*Net message to dblink                      59        0.00          0.00
  SQL*Net message from dblink                    59        0.09          0.23
  latch free                                      1        0.00          0.00
  log file sync                                   1        0.12          0.12

I see that there are 167 waits for the sql*net message from client event and 59 waits for the sql*net message from db link event . The time waited here is much much worse in remote clients where the bandwidth is not much.

In the local database, if i recreate the synonym by specifying the table owner explicitly, there is a boost in performance:

Create or replace synonym tab1 for user_B.tab1@remotedb.world;

When i run the form again:

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  SQL*Net message to client                      14        0.00          0.00
  SQL*Net message from client                    14        0.31          0.48
  SQL*Net message to dblink                       8        0.00          0.00
  SQL*Net message from dblink                     8        0.02          0.06

Look at the number of waits, they are much much fewer than before.

So, if you are using Oracle Forms and use a synonym to a remote synonym as your base table, check if that synonym is created with the table owner specified or not. We had a huge performance improvement by recreating the synonym by specifying the table owner as you see.

(Both the local and remote databases are 9.2.0.5 in this test).

SQL*Net message from client

Sql*net message from client is generally considered an idle event as the Oracle server process is waiting for the client process. Some dbas do not pay any attention to this event. It is good this seems to be changing.

This case i have come into shows the importance of this event.
User queries a simple base block form which gets one row from a table (which contains that single row), changes one column and commits the change. The user is complaining about the performance of this form and says he always waits 5-6 seconds for this update. The sql trace for this session shows the following sql statements:

Select row from table;
Select row from table where rowid=:1 for update;
Update table set col=value where rowid=:2;

Each sql statement’s statistics show that all their elapsed times were 0.00. But here are the totals at the end of the trace file:

OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        4      0.01       0.00          0          0          0           0
Execute      7      0.00       0.01          0          0          0           1
Fetch        5      0.00       0.00          0         12          0           5
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total       16      0.01       0.02          0         12          0           6

Misses in library cache during parse: 0

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  SQL*Net message to client                     172        0.00          0.00
  SQL*Net message from client                   172        0.68          6.20
  latch free                                      1        0.00          0.00
  SQL*Net message to dblink                       8        0.00          0.00
  SQL*Net message from dblink                     8        0.00          0.01
  log file sync                                   1        0.00          0.00

Here we see why he is talking about the 5 seconds response time of this simple form. Sql*net message from client waits account for 6 seconds of elapsed time. There are 172 waits for this event. Surely any other action than reducing sql*net message from clients here can not make any improvements in performance. When we quit using base block and populating the block using a “select col_list into ... “ statement and then updating the row, we reduced the number of sql*net message from clients from 172 to 36 and response time from 6.20 sec to 1 sec.

How to make $1 million

Look at this idea to make one million dollars. A British student launched a web page and sells pixels. Here is what he is trying to do. Let’s see if he will be able to make it. Seems so. (from The Guardian online blog)

Oracle buys Siebel

Oracle buys Siebel and becomes No 1 in the CRM market.