Low overhead Database monitoring using Session Waits
Many DBAs have faced the situation where a Database monitoring tool imposed such a large overhead that the whole purpose of using that monitoring tool was lost. This article proposes a low overhead, high-level monitoring algorithm based on Session wait data available in all Oracle versions since 7.2. We will showcase this algorithm using a UNIX shell script to parse the output of a very simple SQL, and show you how to interpret it. The monitoring is low overhead because the data is read from memory based V$ tables. Using this algorithm, you could start database monitoring in a small way and build up and extend as you go.
Before we launch into the details, let us state upfront that this article is not about tuning using session wait data, although the wait interface is an excellent starting point in your tuning efforts. Nor is it about the wait interface itself or that waiting sessions are bad for the database. It points to a new way of using the wait interface as a database monitoring tool, in addition to its well known performance monitoring uses.
Let us launch straight into the meat of the matter. This high-level monitor is exclusively based on the V$SESSION_WAIT performance view which exposes the database event and resources for which sessions are waiting for. This view was introduced as far back as Oracle 7.2, but remained a buried gem until recent years. The author has been using this view to determine database-related issues since ’98 and has found that the structure of this view has remained constant all these years across all versions. The description of this view from an Oracle 9.2.0.4 database is shown in Figure 1 below:
Connected to:
Oracle9i
With the Partitioning, Oracle Label Security and OLAP
options
JServer Release 9.2.0.4.0 - Production
Name
Null? Type
-----------------------------------------
-------- ----------------------
SID
NUMBER
SEQ#
NUMBER
EVENT
VARCHAR2(64)
P1TEXT VARCHAR2(64)
P1
NUMBER
P1RAW
RAW(4)
P2TEXT
VARCHAR2(64)
P2 NUMBER
P2RAW
RAW(4)
P3TEXT
VARCHAR2(64)
P3
NUMBER
P3RAW
RAW(4)
WAIT_TIME
NUMBER
SECONDS_IN_WAIT NUMBER
STATE
VARCHAR2(19)
Figure 1
The Oracle 9i Database Reference manual describes the columns of this view. For the purpose of this article, we are primarily interested only in the following columns:
SID Session Identifier – same as SID from V$SESSION
EVENT Resource or event for which the session is waiting
P1, P2 and P3 Parameters which further describe the specifics for that EVENT
A list of Database wait events is detailed in Appendix A of the same Reference Manual. Again, we will only consider selected events. Depending on the event we encounter, we will then have to look at a further set of V$ and DBA views to better understand and diagnose the issue. Needless to say, these views are accessible only to a user with DBA privileges unless specifically granted. Although this view has generally been associated with performance monitoring and tuning, we will demonstrate the use of this data for just plain database level problem diagnosis in addition to performance diagnosis.
The reasoning behind the algorithm is quite simple - we will look at the V$SESSION_WAIT view and answer the following questions:
If particular “events of interest” occur, we can measure the number of occurrences of these “events of interest” for the various sessions against previously established thresholds. If the thresholds for these events are met or exceeded, we could then alert the DBA of these occurrences. The DBA can then use the values in the p1, p2 and p3 columns of a session in distress to further qualify the event and take appropriate action.
The first question – what the various sessions are waiting for - is answered by using the following SQL shown in Figure 2:
select event, count(*)
from v$session_wait
group by event;
Figure 2
The result is typically as shown below in Figure 3:
EVENT COUNT(*)
---------------------------------------- ----------
SQL*Net message from client 336
SQL*Net message to client 1
buffer busy waits 8
db file scattered read 4
db file sequential read 9
enqueue 2
direct path read 1
latch free 2
pipe get 10
pmon timer 1
rdbms ipc message 13
smon timer 1
Figure 3
A particular event shows up in the result if a database session is currently encountering a “wait” for that event – and this is the crux of it all. Thus, in the above example, 336 sessions are waiting for the “SQL*Net message from client” event, 8 sessions are currently waiting for the “buffer busy wait” event, 4 sessions for the “db file scattered read” event, 2 sessions for the “enqueue” event and so on.
Successive versions of Oracle have exposed an ever increasing number of these Wait events. However, we are fortunate that Oracle has retained the same name and meaning for those events that we will discuss here. Thus, this algorithm can be used for any version of the Oracle RDBMS starting all the way from Oracle 7.3.4 upto Oracle 9.2.0.4. [The reader should be aware of a bug in Oracle 9.2.0.3 that lumps all such events into a “Null event” – patching the RDBMS version to 9.2.0.4 solves this]
A number of these database events are considered “Null” events, or “Idle events”. These are used to signify database events that are normal or expected. For example, the “SQL*Net message from client” event occurs when the backend Oracle process is waiting for input from the user at that moment in time. The “smon timer” and “pmon timer” events signify that the SMON and PMON processes respectively are waiting for their wake-up timer message. In case you have installed the STATSPACK utility in your database, a full list of such Idle events can be seen from the STATSPACK.STATS$IDLE_EVENT table. Although there are many situations when these “idle” events do actually matter, for the most part they do not. And since we are not going to stress the performance part of this analysis, we will accept these ‘idle’ events for what they are and move on.
An important point to note is that the data presented by this view is a “snapshot-in-time” and will undergo constant change as sessions complete waiting for one event and progress to the next event. The Oracle kernel rolls the event count and the time waited by a session for a particular event into the V$SESSION_EVENT view – which is specific for that session – and then onward to the V$SYSTEM_EVENT view which is a system-wide counter. In turn, the data exposed by these views persist for the duration of that session and that instance (i.e. until instance restart) respectively.
The “events of interest” then, for the sake of this first level monitoring are the following:
buffer busy waits
db file sequential read
db file scattered read
enqueue
latch free
library cache load lock
library cache lock
library cache pin
SQL*Net message from dblink
SQL*Net message to dblink
We will explore these events one by one in subsequent sections, but before that, let us look at some snippets of a UNIX shell script that will help parse and check these events for the purpose of alerting a DBA. For brevity’s sake, we will consider only two events in this code snippet – they are the ‘latch free’ and ‘enqueue’ events.
The script is well commented, and should be simple to read. For the UNIX newbie, the ‘grep’ command is used to search for a specified line in a file (or pipe stream) and ‘awk’ can be used to extract the specified column in a line. The backquotes will execute the enclosed commands and place the output of these commands into an environment variable. The script invokes SQL*Plus and uses input redirection to obviate the need for another, external SQL command file. This is shown in Figure 4 below:
# Low overhead monitoring using Session Wait –
# Set event thresholds; Assume that all other
environment variables
# to enable database access are set
LIM_EV_ENQUEUE=1 # Lock threshold
LIM_EV_LATCH_FREE=4 # Latch threshold
WAIT_BEFORE_CHECK=60 # Seconds to wait for false alarm check
mailfile=<Mail file name, including path>
# Create a module so that the checks can be invoked as
required
# Parameter $1 is the
password for SYSTEM, $2 is the spool file name
check_events() {
> $2 # Nullify previous log/mail file
>$mailfile
# Use input redirection
with SQL*Plus; escape the special ‘$’ character
# in UNIX using a ‘\’ escape character
sqlplus system/$1 <<EOF
set pagesize
100
set trimspool
on
select event, count(*)
from v\$session_wait
group by event
spool $2
/
spool off
exit
EOF
echo "List of Triggering
events:" >>$mailfile
# This
is the key check – IS_THERE will be set to 1 if a ‘latch free’ event
# is present in the output
of the previous SQL
IS_THERE=`grep 'latch free' $2 | wc -l`
# If
the ‘latch free’ event is present, determine the number of sessions
# waiting on this event;
same applies to the ‘enqueue’ event
if [ $IS_THERE -gt 0 ]; then
EV_LATCH_FREE=`grep
'latch free' $2 | awk '{print $3}'`
else
EV_LATCH_FREE=0
Fi
IS_THERE=`grep 'enqueue' $2 | wc
-l`
if [ $IS_THERE -gt 0 ]; then
EV_ENQUEUE=`grep
'enqueue' $2 | awk '{print $2}'`
else
EV_ENQUEUE=0
fi
trigger=0
# Now check if the
thresholds are exceeded – if not ignore!
if [ $EV_LATCH_FREE -ge $LIM_EV_LATCH_FREE ]; then
trigger=`expr $trigger + 1`
LINE_TO_MAIL=`grep
'latch free' $2`
echo
$LINE_TO_MAIL >> $mailfile
fi
if [ $EV_ENQUEUE -ge $LIM_EV_ENQUEUE ]; then
trigger=`expr $trigger + 1`
LINE_TO_MAIL=`grep
'enqueue' $2`
echo
$LINE_TO_MAIL >> $mailfile
fi
} ## End of the chk_events module
# Now that code is built, invoke it, wait and recheck at proper interval
# This
is to ensure false alarms are not raised if the event limits were
# reached for a brief
duration. We are only interested if it persists
# consistently
for a specified period
check_events <your_system_password_here>
<your_log_file_name_here>
if [ $trigger -gt 0 ]; then
# Something
has triggered off - so wait and check again after awhile
sleep
$WAIT_BEFORE_CHECK
check_events <your_system_password_here> <your_log_file_name_here>
fi
# Now - if a trigger still
exists, then it is possibly an issue
# Mail the file to the
DBA!
if [ $trigger -gt 0 ]; then
mailx
-s "$1 : Possible Database problem: TTriggers = $trigger" \
your_dba@your_org.com
< $mailfile
fi
Figure 4
The script waits for a specified period of time, one minute in this case, when triggered just so that a temporary situation does not raise a false alarm.
Although a UNIX shell script was used here to showcase the algorithm, you could always use it in any other scripting environment such as Perl or PL/SQL and even Web-enable it via CGI scripts or JSP.
We earlier claimed that this was low overhead monitoring. We will substantiate that claim by measuring the work required using the AUTOTRACE feature of SQL*Plus as shown in Figure 5 below:
SQL> set autotrace on explain statistics
SQL> set timing on
SQL> select event, count(*) from v$session_wait
2 group by event;
EVENT COUNT(*)
----------------------------------------------------------------
----------
SQL*Net message from client
5
SQL*Net message to client 1
pmon timer
1
rdbms ipc message
6
smon timer
1
Elapsed:
00:00:00.18
Execution Plan
----------------------------------------------------------
0 SELECT STATEMENT Optimizer=CHOOSE
1 0
SORT (GROUP BY)
2 1
MERGE JOIN
3 2
FIXED TABLE (FULL) OF 'X$KSLED'
4 2
SORT (JOIN)
5 4
FIXED TABLE (FULL) OF 'X$KSUSECST'
Statistics
----------------------------------------------------------
18
recursive calls
0
db block gets
2
consistent gets
0
physical reads
0
redo size
582
bytes sent via SQL*Net to client
503
bytes received via SQL*Net from client
2
SQL*Net roundtrips to/from client
2
sorts (memory)
0
sorts (disk)
5
rows processed
Figure 5
With a typical elapsed time of 18 milliseconds per execution, accessing two internal X$ tables in memory and no parsing (other than the initial execution), this really is a low overhead monitor! The use of the ‘timex’ command on the UNIX script revealed a run time of just 0.08 seconds.
For those really curious about these X$ internal tables, X$KSLED provides the details of the Wait events while X$KSUSECST tracks the session details. Thus, the number of rows in X$KSLED is determined by the current set of possible wait events, which in turn depends on the RDBMS version. The number of rows in X$KSUSECT is determined by the ‘sessions’ parameter of init.ora – this in turn depends on the ‘processes’ parameter. The response of the query is bound to change when the ‘processes’ parameter is increased. However, we have seen very acceptable response even with ‘processes’ set to 1000.
We will now briefly explore the meaning of each of the identified events. Volumes have been written about some of these events, and there have been considerable arguments over the same. We will not go into details of these events, nor will we set hard and fast thresholds for these events. Rather, we will suggest reasonable values that we have used for the thresholds that you can start with and adjust later.
Buffer busy waits (BBW) are caused when an Oracle block is being read into the buffer cache (should be brief) or the buffer in question is in an incompatible mode because another session is modifying it. P1 and P2 provide the File number and block number respectively to be used against DBA_EXTENTS, while P3 specifies the mode. A trigger level of 4 should suffice – you will most probably find that multiple simultaneous updates to some ‘hot’ blocks and ‘hot’ indexes are causing these issues. Metalink Notes 34405.1 and 155971.1 are worth reading to understand the issues around BBW.
Generally, these two events correspond to single block (index and data block) read and multi-block read respectively. P1 and P2 denote the File and block number being read respectively, again to be used with DBA_EXTENTS, while P3 denotes the number of blocks being read (normally > 1 for scattered read). A high trigger level, such as 15, can be set for these events. In this case, an alert for either of these events would be triggered by ten or more sessions consistently performing that type of I/O, and may possibly mean that a bunch of programs are running simultaneously causing a temporary bottleneck. You may have to look into scheduling these jobs so that they don’t contend for the same I/O resources, all at the same time. Notes 34558.1 and 34559.1 explain these events in greater detail.
Enqueues are local locks that serialize access to various resources. This wait event indicates that one or more sessions are waiting for a lock on some resource that is held by another session (or sessions) in an incompatible mode to the requested mode. These are generally caused by user transactions holding ‘TX’ type locks – the waiting session posts this event and waits indefinitely. See Note 34566.1 for an in-depth analysis of this event. I would suggest a value of 1 for this trigger – an alert usually means that at least one session has locked an object (row or table) and one or more sessions are waiting for this previous session to COMMIT and thus release the lock. The V$LOCK, DBA_BLOCKERS and DBA_WAITERS views will provide adequate information for troubleshooting problems related to enqueues.
Latches are low level mechanisms that are used to protect internal memory structures and should normally be held for a brief period of time. This fact alone is sufficient for us to state that we should be alerted when there are too many sessions waiting for latches for an extended period of time. P2 denotes the type of latch – exposed by the V$LATCH and related views. You will find that latching for ‘cache buffer chains’, ‘shared pool’ and ‘library cache’ will be seen often, and is expected. You may want to set the trigger to half the number of CPUs in the Database server for starters, as latching is very CPU intensive and you would like to be alerted when heavy, consistent latching that ties up at least half the amount of CPU capacity occurs. Latch tuning and related issues are too complex to be dealt in this article, so we will stop here as we just want to be alerted during times of high latch activity. Steve Adams’ excellent book – Oracle 8i Internal Services – is a must read for those wanting to jump deep into this pool! You could always trace the currently executing set of SQLs by joining the V$SESSION and V$SQL views for these sessions, and look at tuning them.
These events relate to internal locks placed on stored PL/SQL procedures and packages that have been loaded into the library cache (part of the shared pool), and generally occur when a stored PL/SQL procedure, package or function is invalidated for whatever reason. This could be either explicit (stored object recompilation), or implicit (library cache invalidation due to statistics generation, object invalidation due to DDL on related and dependent objects). For example, when a user program is currently executing a stored procedure, and a developer tries to compile that object, the latter will wait on a ‘library cache pin’ or lock. The latter session will proceed only when the program releases it’s read-lock on the said object. Whatever the case may be, long awaiting library cache events should raise a trigger – something odd is going on! A trigger level of 3 is suggested. Metalink contains a large number of notes on this subject.
These events obviously relate to Database link traffic related waits. If you see these events, you should check for local queries that access data from remote databases or remote queries that peek into this database, again joining V$SQL and V$SESSION. In any case, if online transactions are involved in these queries, then you should consider using simple replication using Materialized views to improve response times. A trigger value of 2 is a good starting point.
Once you customize this script by setting your favorite list of events and sensible thresholds for your environment and implement it, you might start receiving emails or pages about possible issues in the databases being monitored. When you encounter these events, you should then use other V$ and DBA_ views to further probe why these events occurred – we have listed a few of them. For example, on consistently encountering “enqueue” alerts over lunchtime, you might deduce that users tend to update some rows and “forget” to commit the same before walking out for lunch. Or you might be encountering ‘library cache pin/lock” alerts frequently, leading you to deduce that Developers were performing changes to stored procedures and packages in the Production environment without proper authority or scheduling. An alternative explanation maybe that the Database Statistics collection routine (performed via ANALYZE or DBMS_STATS) may be running over time and has stepped into peak hour traffic. A high rate of “db file sequential/scattered reads” alerts overnight may mean that the Disk subsystem is unable to keep up with I/O requirements brought on by many different batch jobs starting at the same time. Buffer busy waits at particular times may again indicate objects that become hot spots in your database at these specific times. When Database link wait events are frequently encountered, you may want to look at using replication during off peak hours to avoid Database link based traffic during peak hours. As you can see, this type of monitoring is a good starting point for your investigations into issues.
So what comes next? This is by no means the complete set of events that need to be monitored – they are just a first set and you could add more as you go. The Oracle Reference Manual and Metalink notes are good places to start understanding what these events mean. Excellent books such as Steve Adams’ “Oracle 8i Internal Services”, Gaja Vaidyanatha’s “Oracle Performance Tuning 101”, Guy Harrison’s “Oracle SQL High Performance Tuning” and Cary Millsap’s “Optimizing Oracle Performance” will help with understanding the deeper issues.
You could also start with a simple script that pages or emails the DBA when triggered by one or more of these events, and then extend the script to further probe other V$ and DBA_views to automatically capture the environments of affected sessions and include this information in the email. You might provide all of this via an SSL enabled Web page using CGI scripts or Oracle iAS/Portal for remote diagnosis via the Internet. The possibilities are literally endless, limited only by your ingenuity, time and resources!
We have seen in this
article that the Session Wait interface, and specifically the V$SESSION_WAIT
view is a powerful tool that goes above and beyond performance tuning and lends
itself to low overhead database monitoring. A simple script was used to
showcase this algorithm and the wait events triggers that really matter were
discussed.