Buffer Busy Waits and Freelist Contention

Buffer Busy Waits and Freelist Contention

Oracle Tips by Burleson Consulting

When multiple tasks want to insert or update rows in a table, there may be contention in the segment header for the table. This contention can manifest itself as a buffer busy wait or a freelist wait. Let’s look at some queries that can be run to identify these contention conditions. We are now ready to understand how they occur at the table and index level.

Oracle keeps a v$ view called v$waitstat and the stats$waitstat table for monitoring wait events. The following query shows how many times Oracle has waited for a freelist to become available. As you can see, it does not tell you which freelists are experiencing the contention problems:

SELECT CLASS, COUNT
FROM V$WAITSTAT
WHERE CLASS = 'free list';

    CLASS                           COUNT
---------------                  ------------
free list                         383

The main problem with the v$waitstat view and the stats$waitstat table is that they only keep the wait statistics for the whole database, and do not distinguish waits by table or index name. Here, you can see that Oracle had to wait 383 times for a table freelist to become available. This could represent a wait of 383 times on the same table or perhaps a single wait for 83 separate tables. While 383 seems to be a large number, remember that Oracle can perform hundreds of I/Os each second, so 383 could be quite insignificant to the overall system. In any case, if you suspect that you know which table’s freelist is having the contention, the table can be exported, dropped, and redefined to have more freelists. While an extra freelist consumes more of Oracle’s memory, additional freelists can help throughput on tables that have lots of insert statements. Generally, you should define extra freelists only on those tables that will have many concurrent update operations.

Remember, Oracle8i introduced a method where freelists can be dynamically added to segments. You can do this in Oracle with the alter table and alter index commands.

Using STATSPACK to Find Wait Contention

Now let’s look at how STATSPACK can identify these wait conditions. The stats$waitstat table contains a historical listing of all wait events. The stats$waitstat contain the following classes:

SQL> select distinct class from stats$waitstat

CLASS
------------------
bitmap block
bitmap index block
data block
extent map
free list
save undo block
save undo header
segment header
sort block
system undo block
system undo header
undo block
undo header
unused

rpt_waitstat.sql

set pages 999;
set lines 80;

column mydate heading 'Yr Mo Dy Hr'     format a13;
column class                              format a20;
column wait_count                         format 999,999;
column time                               format 999,999,999;
column avg_wait_secs                      format 99,999;

break on to_char(snap_time,'yyyy-mm-dd') skip 1;

select
   to_char(snap_time,'yyyy-mm-dd HH24')           mydate,
   e.class,
   e.wait_count - nvl(b.wait_count,0)             wait_count,
   e.time - nvl(b.time,0)                         time
from
   stats$waitstat     b,
   stats$waitstat     e,
   stats$snapshot     sn
where
   e.snap_id = sn.snap_id
and
   b.snap_id = e.snap_id-1
and
   b.class = e.class
and
(
   e.wait_count - b.wait_count > 1
   or
   e.time - b.time > 1
)
;

Here is a sample report from this query. Here we see a list of all wait events and the object of the wait. This information can sometimes provide insight into a contention problem within Oracle.

Yr   Mo Dy Hr CLASS                WAIT_COUNT         TIME
------------- -------------------- ---------- ------------
200112-20 11 data block                    2            0
200112-20 12 data block                   21            0
200112-20 12 undo header                   5            0
200112-20 13 data block                  407            0
200112-20 13 segment header                3            0
200112-20 13 undo block                  270            0
200112-20 13 undo header                  61            0
200112-20 16 data block                   55            0
200112-20 16 undo block                    8            0
200112-20 16 undo header                   5            0
200112-20 17 data block                  252            0
200112-20 18 data block                  311            0
200112-20 18 undo block                  173            0
200112-21 00 data block                2,268            0
200112-21 00 undo block                  744            0
200112-21 00 undo header                 132            0
200112-21 01 data block                2,761            0
200112-21 01 undo block                1,078            0
200112-21 01 undo header                 419            0
200112-21 05 data block                    7            0
200112-21 09 data block                   17            0
200112-21 09 undo block                    8            0
200112-21 10 data block                   30            0
200112-21 10 undo block                   29            0
200112-21 10 undo header                   4            0
200112-21 11 data block                  139            0
200112-21 11 undo header                   2            0
200112-21 12 data block                   17            0
200112-21 13 data block                   11            0
200112-21 14 data block                   42            0
200112-21 14 undo header                   2            0
200112-21 15 data block                   10            0
200112-21 15 undo block                    5            0
200112-21 16 data block                   23            0
200112-21 17 data block                   17            0
200112-21 17 undo block                    2            0
200112-21 18 data block                  122            0
200112-21 18 undo block                  117            0
200112-21 18 undo header                  19            0
200112-21 21 data block                   15            0
200112-21 22 data block                    3            0
200112-22 02 data block                   59            0
200112-22 08 data block                   19            0
200112-22 09 data block                   72            0
200112-22 09 undo block                    2            0
200112-22 10 data block                   57            0
200112-22 10 undo block                    7            0
200112-22 10 undo header                   3            0
200112-22 11 data block                  423            0
200112-22 11 undo block                   10            0
200112-22 16 data block                    2            0
200112-22 17 data block                  319            0
200112-22 17 undo block                  149            0
200112-22 17 undo header                  44            0
200112-22 18 data block                    3            0
200112-22 18 undo header                   2            0
200112-22 19 data block                   16            0
200112-22 20 data block                5,526            0
200112-22 20 segment header              30            0
200112-22 20 undo block                   46            0

Note that the segment header and data block waits are often related to competing update tasks that have to wait on a single freelist in the segment header.

While this STATSPACK report is useful for summarizing wait conditions within Oracle, it does not tell us the names of the objects that experienced the wait conditions. The following section will show you how to drill down and find the offending data block for buffer busy waits.

Finding Buffer Busy Waits with STATSPACK

We are discussing buffer busy waits now because buffer busy waits are usually associated with segment header contention that can be remedied by adding additional freelists for the table or index. However, buffer busy waits are measured at the instance level and it is to our benefit to look at the instance-wide reports on buffer busy waits.

Before proceeding, let’s remember that a buffer busy wait occurs when a database block is found in the data buffer but it is unavailable because another Oracle task is using the data block. Here is a sample STATSPACK report to display buffer busy waits for each of the three data buffers.

rpt_bbw.sql

set pages 9999;

column buffer_busy_wait format 999,999,999
column mydate heading 'yr. mo dy Hr.'

select
   to_char(snap_time,'yyyy-mm-dd HH24')      mydate,
   new.name,
   new.buffer_busy_wait-old.buffer_busy_wait buffer_busy_wait
from
   perfstat.stats$buffer_pool_statistics old,
   perfstat.stats$buffer_pool_statistics new,
   perfstat.stats$snapshot               sn
where
   new.name = old.name
and
   new.snap_id = sn.snap_id
and
   old.snap_id = sn.snap_id-1
and
   new.buffer_busy_wait-old.buffer_busy_wait > 1
group by
   to_char(snap_time,'yyyy-mm-dd HH24'),
   new.name,
   new.buffer_busy_wait-old.buffer_busy_wait
;

Here is a sample of the report from this script. Note that it provides instance-wide buffer busy waits and does not tell us the data blocks where the wait occurred. We will see advanced techniques for find the blocks in the next section.

yr. mo dy Hr NAME                 BUFFER_BUSY_WAIT
------------- -------------------- ----------------
200109-21 15 DEFAULT                             3
200110-02 15 DEFAULT                            11
200112-11 18 DEFAULT                            20

We can enhance this report to show times when the number of buffer busy waits is causing a performance problem. This script alerts when there are more than 400 buffer busy waits between snapshot intervals.

rpt_bbw_alert.sql

set pages 9999;

column buffer_busy_wait format 999,999,999
column mydate heading 'Yr Mo Dy Hr.' format a16

select
   to_char(snap_time,'yyyy-mm-dd HH24')           mydate,
   avg(new.buffer_busy_wait-old.buffer_busy_wait) buffer_busy_wait
from
   perfstat.stats$buffer_pool_statistics old,
   perfstat.stats$buffer_pool_statistics new,
   perfstat.stats$snapshot   sn
where
   new.snap_id = sn.snap_id
and
   old.snap_id = sn.snap_id-1
and
   new.buffer_busy_wait-old.buffer_busy_wait > 4000
group by
   to_char(snap_time,'yyyy-mm-dd HH24')
;

We can run this script and learn those time periods when buffer busy waits were excessive. This can provide the DBA with valuable clues about the tables and processes that were involved in creating the block wait conditions.

SQL> @rpt_bbw_alert.sql

Yr Mo Dy Hr. BUFFER_BUSY_WAIT
---------------- ----------------
2001-01-04 01               4,570
2001-01-04 06               4,576
2001-01-04 07               4,582
2001-01-04 11               4,669
2001-01-04 12               4,687
2001-01-04 13               4,692
2001-01-04 14               4,762
2001-01-04 20               4,867
2001-01-04 21               4,875
2001-01-04 23               4,883
2001-01-05 00               4,885
2001-01-07 20               5,462
2001-01-07 21               5,471
2001-01-07 22               5,476
2001-01-07 23               5,482
2001-01-08 00               5,482
2001-01-08 01               5,482
2001-01-08 02               5,484
2001-01-08 03               5,504
2001-01-08 04               5,505
2001-01-08 10               5,365
2001-01-08 11               5,396
2001-01-08 12               5,505
2001-01-08 13               5,943
2001-01-08 14               6,155
2001-01-08 15               6,226
2001-01-08 16               6,767
2001-01-08 17              14,396
2001-01-08 18              13,958
2001-01-08 19              13,972
2001-01-08 20              13,977
2001-01-08 21              13,979
2001-01-08 22              13,981
2001-01-08 23              13,982
2001-01-09 00              13,986
2001-01-10 23               4,517
2001-01-11 00               5,033
2001-01-16 21               9,048
2001-01-16 22               9,051
2001-01-16 23               9,051

We can also gain insight into the patterns behind buffer busy waits by averaging them by the hour of the day. The following STATSPACK script can be used to develop a buffer busy wait “signature.”

rpt_avg_bbw_hr.sql

set pages 9999;

column buffer_busy_wait format 999,999,999
column mydate heading 'Yr Mo Dy Hr.' format a16

select
   to_char(snap_time,'HH24')           mydate,
   avg(new.buffer_busy_wait-old.buffer_busy_wait) buffer_busy_wait
from
   perfstat.stats$buffer_pool_statistics old,
   perfstat.stats$buffer_pool_statistics new,
   perfstat.stats$snapshot   sn
where
   new.snap_id = sn.snap_id
and
   old.snap_id = sn.snap_id-1
having
   avg(new.buffer_busy_wait-old.buffer_busy_wait) > 0
group by
   to_char(snap_time,'HH24')
;

Here is the output from this script that we can paste into a spreadsheet for charting. We clearly see the average buffer busy waits for each hour of the day.

Yr Mo Dy Hr. BUFFER_BUSY_WAIT
---------------- ----------------
00                            155
02                             19
03                              0
06                              5
07                              4
08                              8
09                             28
10                             66
11                             28
13                             31
14                             45
15                            169
16                             61
17                            364
18                             48
19                             34
20                             88
22                             17
23                            186

The chart in Figure 10-12 shows the plot of buffer busy waits during a typical day. Here we see a clear spike in waits at 3:00 p.m. and again at 5:00 p.m. The next step would be to go to the stats$sql_summary table and try to locate the SQL and the underlying tables for these waits.

Figure 10-90: Average buffer busy waits by hour of the day

Now that we understand the general nature of buffer busy waits, let’s move on and see how we can find the exact object that caused the buffer busy wait.

Finding the Offending Block for a Buffer Busy Wait

As we discussed, Oracle does not keep an accumulator to track individual buffer busy waits. To see them, you must create a script to detect them and then schedule the task to run frequently on your database server.

get_busy.ksh

#!/bin/ksh

# First, we must set the environment . . . .
ORACLE_SID=proderp
export ORACLE_SID
ORACLE_HOME=`cat /var/opt/oracle/oratab|grep \^$ORACLE_SID:|cut -f2 -d':'`
export ORACLE_HOME
PATH=$ORACLE_HOME/bin:$PATH
export PATH

SERVER_NAME=`uname -a|awk '{print $2}'`
typeset -u SERVER_NAME
export SERVER_NAME

# sample every 10 seconds
SAMPLE_TIME=10

while true
do

   #*************************************************************
   # Test to see if Oracle is accepting connections
   #*************************************************************
   $ORACLE_HOME/bin/sqlplus -s /<<! > /tmp/check_$ORACLE_SID.ora
   select * from v\$database;
   exit
!

   #*************************************************************
   # If not, exit immediately . . .
   #*************************************************************
   check_stat=`cat /tmp/check_$ORACLE_SID.ora|grep -i error|wc -l`;
   oracle_num=`expr $check_stat`
   if [ $oracle_num -gt 0 ]
    then
    exit 0
   fi

   rm -f /export/home/oracle/statspack/busy.lst

   $ORACLE_HOME/bin/sqlplus -s perfstat/perfstat<<!> /tmp/busy.lst

   set feedback off;
   select
      sysdate,
      event,
      substr(tablespace_name,1,14),
      p2
   from
      v\$session_wait a,
      dba_data_files b
   where
      a.p1 = b.file_id
;
!

var=`cat /tmp/busy.lst|wc -l`

echo $var
if [[ $var -gt 1 ]];
then
echo
**********************************************************************"
echo "There are waits"
cat /tmp/busy.lst|mailx -s "Prod block wait found"\
don@remote-dba.net \
Larry_Ellison@oracle.com
echo
**********************************************************************"
exit
fi

sleep $SAMPLE_TIME
done

As we can see from this script, it probes the database for buffer busy waits every 10 seconds. When a buffer busy wait is found, it mails the date, tablespace name, and block number to the DBA. Here is an example of a block alert e-mail:

SYSDATE SUBSTR(TABLESP P2
--------- -------------- ----------
28-DEC-00 APPLSYSD 25654

Here we see that we have a block wait condition at block 25654 in the applsysd tablespace. To see the contents of this data block we have several command options:

SQL> alter system dump datafile 1 block 25654;
System altered.

or:

SQL > alter system dump datafile
SQL > '/u03/oradata/PROD/applsysd01.dbf' block 25654;
System altered.

or:

SQL> ALTER SESSION SET EVENTS 'IMMEDIATE TRACE NAME BLOCKDUMP LEVEL 25654';
System altered.

This will then generate a trace file that contains the detailed information about the contents of the data block. In most cases, this will be the first block in the table (the segment header). Let’s go to the udump directory and inspect the trace file.

oracle*PROD-/u01/app/oracle/admin/PROD/udump
>ls -alt|head
total 5544
-rw-r--r-- 1 oracle dba 69816 Dec 28 14:16 ora_4443.trc

Next, we look at the contents of the trace file using the UNIX more command.

root> more ora_4443.trc

Dump file /u01/app/oracle/admin/PROD/udump/ora_4443.trc
Oracle8 Enterprise Edition Release 8.0.5.1.0 - Production
.
.
.

Block header dump: rdba: 0x00406436
Object id on Block? Y
seg/obj: 0x63 csc: 0x00.d3aa2 itc: 9 flg: - typ: 2 - INDEX

Here we see that the object on this block is an index and the object ID is hex 63. We convert the hex 63 and see that our object ID is number 99.

We can then run a query against dba_objects and see the name of the index.

SQL> select object_name, object_type
2 from dba_objects
3 where object_id=99;

OBJECT_NAME
--------------------------------------------------------------------------
OBJECT_TYPE
---------------
VUST_IDX
INDEX

SQL> select table_name from dba_indexes
2 where index_name = 'CUST_IDX';

TABLE_NAME
------------------------------
CUSTOMER

So, here we see that our wait event was on the root index node for the cust_idx index. This index has only a single freelist and it appears that the contention was caused by multiple tasks competing for an insert on the customer table.

Now that we see how to monitor buffer busy waits, let’s move on to see how to reorganize Oracle tables for faster performance.

This is an excerpt from "Oracle9i High Performance tuning with STATSPACK" by Oracle Press.

If you like Oracle tuning, you may enjoy the new book "Oracle Tuning: The Definitive Reference", over 900 pages of BC's favorite tuning tips & scripts.

You can buy it direct from the publisher for 30%-off and get instant access to the code depot of Oracle tuning scripts.