Bobby Durrett's DBA Blog

Hopefully this isn’t too redundant.  Saw another performance issue today caused by a type mismatch between a bind variable and the column it was compared to in a SQL statement.  I saw this in some real code and then built a simple testcase to prove out the concept: zip of testcase SQL and log.

The column being compared against was type VARCHAR2 and the bind variable was NUMBER.  Converting the variable to a character type with TO_CHAR resolved the issue.

Table definition:

create table test
(OWNER  VARCHAR2(30),
 TABLE_NAME VARCHAR2(30),
 TEST_COLUMN VARCHAR2(2000));

create index testi on test(TEST_COLUMN);

PL/SQL variable of the wrong type (number):

declare
V_NUMBER number;
begin

V_NUMBER := 1;

Execute immediate passing the bind variable that does not match the type of the column TEST_COLUMN:

execute immediate 'UPDATE TEST SET TABLE_NAME=''UPDATED'' 
WHERE TEST_COLUMN=:1' using V_NUMBER;

Note that I put in a carriage return so it would fit the blog width.  It is one line in the script.

Execute immediate converting the variable to a character before passing it so it matches the column in the where clause:

execute immediate 'UPDATE TEST SET TABLE_NAME=''UPDATEDAGAIN'' 
WHERE TEST_COLUMN=:1' using to_char(V_NUMBER);

With the TO_CHAR the update is much faster:

No TO_CHAR:

Elapsed: 00:00:01.45

With TO_CHAR:

Elapsed: 00:00:00.04

Plan without the TO_CHAR is full scan:

SQL_ID  41vfab6v87w4g, child number 0
-------------------------------------
UPDATE TEST SET TABLE_NAME='UPDATED' WHERE TEST_COLUMN=:1

Plan hash value: 3859524075

---------------------------------------------------------------------------
| Id  | Operation          | Name | Rows  | Bytes | Cost (%CPU)| Time     |
---------------------------------------------------------------------------
|   0 | UPDATE STATEMENT   |      |       |       |  2579 (100)|          |
|   1 |  UPDATE            | TEST |       |       |            |          |
|*  2 |   TABLE ACCESS FULL| TEST |     2 |    46 |  2579   (4)| 00:00:37 |
---------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   2 - filter(TO_NUMBER("TEST_COLUMN")=:1)

Plan with the TO_CHAR is index range scan:

SQL_ID  3229aq5w36kst, child number 0
-------------------------------------
UPDATE TEST SET TABLE_NAME='UPDATEDAGAIN' WHERE TEST_COLUMN=:1

Plan hash value: 3736755925

---------------------------------------------------------------------------
| Id  | Operation         | Name  | Rows  | Bytes | Cost (%CPU)| Time     |
---------------------------------------------------------------------------
|   0 | UPDATE STATEMENT  |       |       |       |     5 (100)|          |
|   1 |  UPDATE           | TEST  |       |       |            |          |
|*  2 |   INDEX RANGE SCAN| TESTI |     2 |    46 |     3   (0)| 00:00:01 |
---------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   2 - access("TEST_COLUMN"=:1)

– Bobby

I was working on some disk performance problems and came across a simple way to test the latency or delay built into the networks that connect my database servers to their disk storage.  All I have to do is read some disk blocks from a table several times to be sure they are cached in the disk storage server and then flush the database buffer cache and read from the table once more.  Since the blocks are not cached in the database buffer cache but are cached on the disk array the time it takes to read the blocks approaches the time it takes to copy the blocks over the network.  Of course there is some CPU on both the source and target to copy the blocks in memory but the physical disk read is eliminated and you see close to the minimum time it is possible for a transfer to take.

So, here is my simple test script.  It assumes the user, password, and tnsnames.ora name are passed as parameters and that the user is a DBA user like SYSTEM.

connect &1/&2@&3

-- create test that will show how fast reads
-- can be when cached on the disk subsystem

-- document version

select * from v$version;

-- create small table

drop table test;
create table test as select * from dba_tables where rownum < 1000;

-- query three times to get cached in the disk system

select sum(blocks) from test;
select sum(blocks) from test;
select sum(blocks) from test;

-- flush from database cache

alter system flush buffer_cache;

-- reconnect so session waits are cleared

disconnect
connect &1/&2@&3

select sum(blocks) from test;

-- show average scattered read
-- should be best time you can
-- get since blocks are cached
-- in the disk subsystem

VARIABLE monitored_sid number;

begin

SELECT sid into :monitored_sid from v$session 
where audsid=USERENV('SESSIONID');

end;
/

select  
total_waits,
time_waited_micro/total_waits
FROM V$SESSION_EVENT a
WHERE a.SID= :monitored_sid
and event='db file scattered read';

Here is what the output looks like on a slow system with network problems (over NFS in my case):

TOTAL_WAITS TIME_WAITED_MICRO/TOTAL_WAITS
----------- -----------------------------
          4                       1410.25

Here is what it looks like on a nice fiber network:

TOTAL_WAITS TIME_WAITED_MICRO/TOTAL_WAITS
----------- -----------------------------
          4                          40.5

40 microseconds for a disk read is sweet compared to 1410!

I’ve uploaded the script and three runs I made with it here.

– Bobby

P.S.  I realized this morning that the first example with 40 microseconds for a read is really just pulling from the operating system’s filesystem cache because the database I was testing on doesn’t use direct IO.  Here is a test on a system with the SAN that uses direct IO:

TOTAL_WAITS TIME_WAITED_MICRO/TOTAL_WAITS
----------- -----------------------------
          5                         478.4

I ran this several times and this was the best result.  The others were in the 600-700 microsecond range mostly.  So, I guess when you run the test script you are really testing everything behind the scenes that could benefit from caching except for the database’s buffer cache.  Without direct IO you may never reach your SAN network because you will have cached the blocks at the OS filesystem cache level.

I’ve seen some very good information posted in this feed which combines blog postings from many different Oracle performance experts who are part of what is called the “Oak Table”

http://www.oaktable.net/feed/blog-rss.xml (NO LONGER EXISTS)

I’ve been using Internet Explorer to keep track of new posts in its “Feeds” section of the Favorites.  Here is how to add the Oak Table blog feed to Internet Explorer:

Go to the URL listed above and click on “Subscribe to this feed”

Click on Subscribe button

Success!  Now click on Favorites and then Feeds

For any feed in your list if you see the feed name in a darker font it means there is a new post.  So, as I have time, I’ll go to my feeds and see which of the ones I’ve subscribed to have new posts.  If you are looking for performance tuning information I highly recommend the Oak Table feed.

– Bobby

In my forum discussion about free buffer waits I came across a term that I didn’t understand: “inode lock contention”.  I’m pretty sure I had seen this same term years ago on one of Steve Adams’ pages on IO.  But, I didn’t really understand what the term meant and so it was hard to understand whether this was something I was seeing on our production system that was experiencing “free buffer waits”.

First I had to figure out what an inode was.  I knew that it had something to do with the way Unix filesystems work but reading this article(NO LONGER EXISTS) really helped clear up what inodes are at least on HP-UX.  Inodes are small chunks of bytes that are used to define a Unix filesystem.  On HP-UX’s VxFS filesystems a type 1 inode can point to up to 10 extents of one or more contiguous 8K blocks on a large filesystem.  The filesystem I’ve been testing on appears to have 32 meg extents if I’m reading this output from lvdisplay correctly:

LV Size (Mbytes)            1472000
Current LE                  46000

Total size of 1,472,000 meg divided by 46,000 logical extents = 32 meg per extent.

Since the inode can point to 1 to 10 extents it could point to between 32 and 320 meg.

My test case had 15 tables that were more than 1 gigabytes each.  It seems like each table should span multiple inodes so even if there is locking at the inode level it looks like it won’t lock the entire table at once.  Still, it seems unlikely to me that every time a table is updated that reads from all the other parts of the table pointed to by the same inode are really blocked by an inode lock.  Yet that is what this document(NO LONGER EXISTS) suggests:

“During a read() system call, VxFS will acquire the inode lock in shared mode, allowing many processes to read a single file concurrently without lock contention. However, when a write() system call is made, VxFS will attempt to acquire the lock in exclusive mode. The exclusive lock allows only one write per file to be in progress at a time, and also blocks other processes reading the file. These locks on the VxFS inode can cause serious performance problems when there are one or more file writers and multiple file readers.”

It uses the term “file” but I assume if you have a large file that has multiple inodes it means it will lock just the pieces associated with the one inode that points to the blocks that are being written.  The article goes on to explain how you can use the “cio” option to enable concurrent IO and eliminate this inode contention preventing writers from blocking readers.  But, I’ve been testing with just the direct IO options and not the cio option and seeing great results.  So, would I see even better improvement with concurrent io?

I didn’t want to mess with our current filesystem mount options since testing had proven them to be so effective but I found that in glance, a performance monitoring tool like top, you have an option to display inode waits.  So, I took a test that was running with direct IO and had 15 merge statements loading data into the same empty table at once and ran glance to see if there were any inode waits.  There were not:

So, I don’t know if I can depend on this statistic in glance or not.  It appears that the direct IO mount options are all we need:

mincache=direct,convosync=direct

filesystemio_options=DIRECTIO

There may be some case within Oracle 11.2.03 on HP-UX 11.31 where you can be hampered by inode lock contention despite having direct IO enabled but my tests have not confirmed it and I’ve banged pretty hard on my test system with a couple of different types of tests.

– Bobby

I just read this post about a new patch that will allow you to affect the way the optimizer calculates clustering factor and hence how likely it is to choose a particular index for a query plan.

http://richardfoote.wordpress.com/2013/05/08/important-clustering-factor-calculation-improvement-fix-you/

Pretty cool.  I haven’t tried it, but it looks promising.

– Bobby

This is a good web site with Oracle internals information:

http://www.ixora.com.au/notes/ (NO LONGER EXISTS)

I’ve benefited from this one for years.

– Bobby

In my previous post I explained that setting db_writer_processes=1, dbwr_io_slaves=32 made a 2-3 times reduction in run time of my test of 15 concurrent updates.

Further testing has shown that an even greater improvement – really 10 times – can be made by switching to direct IO and maxing out the db writer processes.

To switch my test database to direct IO I had to do two things:

1. Ask one of our Unix administrators to remount the filesystem that contains the datafile being tested using these options: mincache=direct,convosync=direct
2. Change this parameter: filesystemio_options=directIO

Then I switched to what the documentation says is the maximum number of db writers:

1. db_writer_processes=36
2. dbwr_io_slaves=0

I had setup a test that generated free buffer waits by changing my update statements to update more blocks than could be held in the buffer cache and I had set log_checkpoint_interval back to its default of 0 so we wouldn’t get frequent checkpoints.  I also increased the redo logs to 2 gig so they wouldn’t switch and checkpoint frequently.  So, my test was getting plenty of free buffer waits and it took roughly 30 minutes for my 15 concurrent update statements to update 1 million rows each.  This was with my current production settings of db_writer_processes=4 and dbwr_io_slaves=0.

Here is a profile of the time spent by one update statement with no direct io and db_writer_processes=4 and dbwr_io_slaves=0:

TIMESOURCE                    SECONDS PERCENTAGE
-------------------------- ---------- ----------
TOTAL_TIME                       2503        100
free buffer waits                2097         84
db file scattered read            253         10
CPU                                61          2
UNACCOUNTED_TIME                   57          2
db file sequential read            26          1
latch: redo copy                    5          0
events in waitclass Other           2          0
log buffer space                    1          0

Here is a profile with the direct io options and db_writer_processes=36, dbwr_io_slaves=0:

TIMESOURCE                    SECONDS PERCENTAGE
-------------------------- ---------- ----------
TOTAL_TIME                        171        100
free buffer waits                  51         30
UNACCOUNTED_TIME                   41         24
db file scattered read             34         20
CPU                                23         13
log buffer space                   16          9
events in waitclass Other           3          2
latch: redo copy                    2          1

Incredible.  Thanks to Jonathan Lewis and Mark Powell for all of their patient discussion of this issue with me on our forum thread.

So, I guess the bottom line is that if you can’t get your filesystems mounted with direct IO options then the IO slaves may be the way to go in certain scenarios.  But, with direct IO it appears that upping the number of db writers is better than using IO slaves, at least in a scenario like mine were you have many concurrent updates filling the buffer cache with updated blocks and waiting on free buffer waits.

– Bobby

I’m working on an HP-UX system that doesn’t have asynchronous I/O configured and I’m getting a bunch of “free buffer waits” which indicates that the DBWR processes are having trouble writing updated blocks from memory to disk fast enough.  Some preliminary testing I’ve done implies that I should change the following init.ora parameters: db_writer_processes, dbwr_io_slaves.  Our current settings in production are:

db_writer_processes=4, dbwr_io_slaves=0

In my test database these settings were 2-3 times faster when running 15 parallel update statements (each updating 100,000 rows):

db_writer_processes=1, dbwr_io_slaves=32

I also tried bumping the writer processes way up to these settings:

db_writer_processes=36, dbwr_io_slaves=0

but this didn’t help at all.

I engaged in a forum discussion with some very helpful people here: forum thread

Prior to the forum discussion I reviewed the manuals, Oracle’s support site, some blog postings and a usergroup presentation and was left with contradictory and confusing information on what settings to try for these two parameters.  I got the impression that increasing db_writer_processes would help but in my test it did not.

I can’t come to any firm conclusions except to recommend that if you don’t have asychronous I/O on HP-UX try setting db_writer_processes=1, dbwr_io_slaves=32 (some number > 0) and see if it helps.  Of course always try any change in a test environment before making the change in production.

– Bobby

P.S.  This query should show you if you datafiles are using asynch i/o:

select ASYNCH_IO,count(*) from v$iostat_file group by ASYNCH_IO;

Here is the output on our production server with the free buffer waits:

SQL> select ASYNCH_IO,count(*) from v$iostat_file 
group by ASYNCH_IO;

ASYNCH_IO   COUNT(*)
--------- ----------
ASYNC_OFF        301

On a system with asynch I/O it looks like this:

SQL> select ASYNCH_IO,count(*) from v$iostat_file 
group by ASYNCH_IO;

ASYNCH_IO   COUNT(*)
--------- ----------
ASYNC_OFF         10
ASYNC_ON          27

The 10 files with asynch off are not data files.

p.s.  Interestingly an 11.2 manual says that HP-UX doesn’t support asynch IO on filesystems.  I haven’t verified this with a test but it looks like your best bet on HP-UX would be to use raw devices and ASM with asynch IO.

Oracle® Database Administrator’s Reference
11g Release 2 (11.2) for Linux and UNIX-Based Operating Systems

“To use asynchronous Input-Output on HP-UX, you must use an Automatic Storage Management disk group that uses raw partitions as the storage option for database files.”

In my case I’m just looking for a quick boost to an existing system with datafiles on filesystems on HP-UX so maybe in this kind of special case setting db_writer_processes=1, dbwr_io_slaves > 0 makes sense.  At least it is worth a try.

I used this query to debug some updating issues on a table:

select
ss.DATAOBJ#,
sn.END_INTERVAL_TIME,
ss.DB_BLOCK_CHANGES_DELTA,
ss.PHYSICAL_WRITES_DELTA
from 
DBA_HIST_SEG_STAT ss,
DBA_HIST_SNAPSHOT sn,
DBA_HIST_SEG_STAT_OBJ so
where 
so.OWNER='MYUSER' and
so.OBJECT_NAME='PLAN_TABLE' and
so.OBJECT_TYPE='TABLE' and
ss.OBJ#=so.OBJ# and
ss.DATAOBJ#=so.DATAOBJ# and
ss.snap_id=sn.snap_id
order by ss.snap_id,ss.DATAOBJ#;

This is just an example of a PLAN_TABLE in my schema.  I changed the schema name for security.  Here is edited output:

  DATAOBJ# END_INTERVAL_TIME         DB_BLOCK_CHANGES_DELTA PHYSICAL_WRITES_DELTA
---------- ------------------------- ---------------------- ---------------------
   2956377 17-APR-13 11.00.37.126 AM                     32                    11
   2956387 17-APR-13 11.00.37.126 AM                     16                     0
   2956389 17-APR-13 12.00.55.941 PM                     16                     8
   2956397 17-APR-13 12.00.55.941 PM                   3296                    35
   2956395 17-APR-13 02.00.31.239 PM                      0                     0

This could be useful to see when a given table was modified.

– Bobby

P.S. I think the DATAOBJ# changes when I truncate the table.  I usually truncate my PLAN_TABLE before doing a plan to make sure I don’t get an old plan by accident.

You can use DBA_HIST_ACTIVE_SESS_HISTORY to show details about the PeopleSoft operator id (OPRID) and which part of the online application they were in.  I was just looking at a Query Manager issue and found that DBA_HIST_ACTIVE_SESS_HISTORY populated these three columns with PeopleSoft specific information like this:

MODULE=QUERY_MANAGER

ACTION=QRY_SELECT

CLIENT_ID=OPRID of user running query manager

Pretty cool.  This is on HRMS 9.1 PeopleTools 8.50 Oracle database 11.2.0.3.

– Bobby