Database tuning can be a complex exercise, but it can be facilitated by a systematic approach. This chapter describes a systematic five-step approach to performance tuning. It also presents the most important tools provided by Oracle to help with performance tuning; Statspack is given equal time because tools such as Automatic Workload Repository (AWR) and Automatic Database Diagnostic Monitor (ADDM) require licenses and are not available at most sites.¹ In particular, you learn a powerful method of mining the Statspack and AWR repositories for data on performance trends. This data can be graphed by using tools such as Microsoft Excel.

Of course, I can only give you a brief introduction to the vast topic of database tuning. If you want to continue your study of this topic, the best book you will every find is Database Performance Tuning Guide in the Oracle documentation set. I recommend that you do the exercises listed at the end of the chapter—they will familiarize you with the most common tools for database tuning. The best way to learn is by doing.

Using a Systematic Five-Step Tuning Method

Once upon a time, a database-tuning expert saw a drunken man on his hands and knees searching for something under a bright streetlight. “Have you lost something?” he asked the drunk.

“My keys,” said the drunk.

The performance expert offered to help, and he too got on his hands and knees to search for the lost keys. After concluding that no keys were to be found under the streetlight, he began questioning the drunk. “When was the last time you remember seeing your keys?” he asked.

“At the bar,” said the drunk.

“Then why are you searching here?”

“Because it is so much brighter here!”

The story is fictional, and the moral is that you must concentrate your efforts in the appropriate place. You shouldn’t focus your exertion wherever it is most convenient to do so—the problem might not be in the Oracle database at all.

Here is an example of a case where poor performance was reported but the database was not the problem. The output shown in Listing 16-1 was produced by using the dbms_monitor.session_trace:enable procedure to trace a poorly performing batch process and then using the tkprof utility to summarize the trace data. The session was traced for about 40 minutes, and the data shows that the Oracle database spent only 140.08 seconds executing SQL queries. The bulk of the time—2,138.67 seconds—was spent waiting for further instructions from the program. This clearly showed that the database was not the problem.

OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse    14114      0.37       0.40          0          0          0           0
Execute  78466    107.84     109.89        195    1105246      26768       13139
Fetch    72200     19.88      29.78       2100     432976          0       84080
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total   164780    128.09     140.08       2295    1538222      26768       97219

Misses in library cache during parse: 4
Misses in library cache during execute: 4

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
                                             Waited    
  ----------------------------------------   ------  ----------  ------------
  SQL*Net message to client                   87649        0.00          0.09
  SQL*Net message from client                 87649        0.57       2138.67
  db file sequential read                      2295        0.26         10.80
  SQL*Net break/reset to client                1084        0.00          0.07
  log file sync                                1813        0.15         18.02
  latch: session allocation                       8        0.29          2.14
  latch: cache buffers chains                     1        0.00          0.00
  latch: library cache                            3        0.00          0.01
  log file switch completion                      1        0.97          0.97
  latch: redo writing                             1        0.04          0.04

In his book The Art and Science of Oracle Performance Tuning, Christopher Lawson outlines a systematic five-step method for solving any performance-tuning problem:²

1. Define the problem. This requires patient listening, skillful questioning, and even careful observation. “The database is slow” is an example of a poorly defined problem. “The database is slow between 10 a.m. and 11 a.m. every day” is more precise. “This report now takes twice as long as it used to take only a week ago” is another example of a precisely defined problem. Ask the user for the history of the problem. Ask what previous efforts have been made to solve the problem. Ask what changed recently in the environment—for example, software or hardware upgrades. Ask whether all users are affected or only some. Ask whether the problem occurs at specific times of the day or week. Ask whether all parts of the application are equally affected or just certain parts.
2. Investigate the problem, and collect as much pertinent evidence as possible. Examples include Statspack reports, graphs of database workload and DB time, and session traces. Study the environment, and find out what may be affecting the database—for example, other databases and applications may be competing for resources with your database.
3. Analyze the data collected in the second step, and isolate the cause of the performance problem. This is often the most challenging part of the performance-tuning exercise. If the cause of the problem is not found, go back to step 1 or step 2.
4. Solve the problem by creating a solution that addresses the root cause. Solutions are not always obvious, and, therefore, this step may require a great deal of ingenuity and creativity.
5. Implement the solution in a safe and controlled manner. Conduct an appropriate level of testing. Obtain “before” and “after” measurements, if possible, in order to quantify the performance improvement. If the expected improvement is not obtained, go back to step 2.

Oracle Database versions may change, and software tools may change, but the five performance-tuning steps never change. A problem may be simple and require only a few minutes of your time, or it may be tremendously complex and require weeks of your time, but the five steps always remain the same. A simple example follows; you will be asked to duplicate it in the “Exercises” section at the end of the chapter:

1. The users told the DBA that the problem was restricted to certain parts of the application and that there had not been a problem the previous day. On questioning the application developers, the DBA learned that there had been an application upgrade the previous night.
2. The DBA used the spreport.sql script to generate Statspack reports for a one-hour period for the previous day and the current day. The DBA also traced a number of database sessions by using the DBMS_MONITOR.SET_SQL_TRACE procedure.
3. Examination of the Statspack report for the current day showed large numbers of enq: TM - contention events; sessions were waiting, trying to lock an entire table. These events were not observed in the Statspack report for the previous day. The table in question was identified by searching through the trace files.
4. The enq: TM - contention event indicates an unindexed foreign key. If a foreign key is not indexed, Oracle must lock the entire child table when a record is deleted from the parent table in the foreign-key relationship. The DBA queried the DBA_CONSTRAINTS, DBA_CONS_COLUMNS, and DBA_IND_COLUMNS views to identify the missing index and brought this to the attention of the developers.
5. All that was left to do was to implement the solution in a safe and controlled manner. The developers followed the necessary change-control procedures before creating the necessary index.

Analyzing DB Time

The best way to analyze database performance is to find out where the database is spending time. This is powerfully summarized by the Statspack and AWR reports. To demonstrate this, I used the Swingbench tool³ to perform large numbers of transactions in my test database on my laptop. I then used the spreport.sql and awrrpt.sql scripts to generate the Statspack and AWR reports for a one-hour period; both scripts can be found in ORACLE_HOME dbmsadmin. Listing 16-2 shows the first page of the Statspack report, and Listing 16-3 shows the first page of the corresponding AWR report.

STATSPACK report for

Database       DB Id Instance  Inst Num   Startup  Time    Release  RAC
~~~~~~~~  ---------- --------- -------- --------- ----- ----------  ---
          1365223133 orcl             1 05-Jul-14 22:59 12.1.0.1.0   NO

Host Name             Platform                CPUs Cores Sockets   Memory (G)
~~~~ ---------------- ---------------------- ----- ----- ------- ------------
     localhost.locald Linux x86 64-bit           1     0       0          1.5

Snapshot       Snap Id     Snap Time         Sessions    Curs/Sess Comment
~~~~~~~~    ---------- ------------------    --------    --------- --------
Begin Snap:        111 18-Apr-15 14:00:15           2          4.5
  End Snap:        171 18-Apr-15 15:00:10           3          4.3
   Elapsed:            59.92 (mins)      Av Act Sess:          0.9
   DB time:            56.77 (mins)           DB CPU:  1.30 (mins)

Cache Sizes        Begin        End
~~~~~~~~~~~       ------        ----------
Buffer Cache:        52M        Std Block Size:        8K
Shared Pool:       172M            Log Buffer:    3,912K

Load Profile              Per Second    Per Transaction    Per Exec    Per Call
~~~~~~~~~~~~      ------------------  ----------------- ----------- -----------
      DB time(s):                1.0                0.1        0.01        0.02
       DB CPU(s):                0.0                0.0        0.00        0.00
       Redo size:           30,328.6            2,658.6
   Logical reads:            1,520.9              133.3
   Block changes:              288.9               25.3
  Physical reads:              195.8               17.2
 Physical writes:                0.1                0.0
      User calls:               43.9                3.9
          Parses:               30.6                2.7
     Hard parses:                5.3                0.5
W/A MB processed:                0.3                0.0
          Logons:                1.4                0.1
        Executes:              153.6               13.5
       Rollbacks:                0.0                0.0
    Transactions:               11.4

Instance Efficiency Indicators
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
            Buffer Nowait %:  100.00       Redo NoWait %:   99.99
            Buffer  Hit   %:   87.13  Optimal W/A Exec %:  100.00
            Library Hit   %:   93.56        Soft Parse %:   82.80
         Execute to Parse %:   80.05         Latch Hit %:  100.00
Parse CPU to Parse Elapsd %:    6.93     % Non-Parse CPU:   82.42

 Shared Pool Statistics        Begin     End
                              ------  ------
             Memory Usage %:   90.17   94.15
    % SQL with executions>1:   79.38   80.00
  % Memory for SQL w/exec>1:   74.63   79.55

Top 5 Timed Events                                                   Avg  %Total
~~~~~~~~~~~~~~~~~~                                                   wait   Call
Event                                           Waits     Time (s)   (ms)   Time
----------------------------------------- ------------ ----------- ------ ------
PL/SQL lock timer                              143,791       1,398     10   37.3
db file sequential read                        311,592       1,254      4   33.5
log file sync                                   20,819         684     33   18.2
write complete waits                               212         208    979    5.5
CPU time                                                       155           4.1

The most important part of the Statspack report is the Top 5 Timed Events section. It is preceded by details concerning the workload processed by the database. In Listing 16-2, you can see that the DB time was 56.77 minutes during an elapsed interval of 59.92 minutes. DB time is the sum of the response times of all database calls made by the connected sessions; it can be much larger than the clock time if multiple sessions are simultaneously active. Note that actual CPU usage was only 55 seconds during the entire period—just 4.1% of the total DB time. The rest of the time was spent waiting for overhead activities such as reading data from disk (db file sequential read operations) and writing redo information to the online redo logs (log file sync operations). Each db file sequential read operation retrieves one database block from disk. The average time for each operation was 4 milliseconds. The average time for each log file sync operation was 33 milliseconds—too large for comfort—but such operations accounted for only 18.2% of DB time.

Listing 16-3 shows the first page of the AWR report for the same period. The format is very similar to that of the Statspack report, but there is some variance in the numbers because the methods used by AWR are different than those of Statspack.

WORKLOAD REPOSITORY report for

DB Name         DB Id    Instance     Inst Num Startup Time    Release     RAC
------------ ----------- ------------ -------- --------------- ----------- ---
ORCL          1365223133 orcl                1 05-Jul-14 23:00 12.1.0.1.0   NO

Host Name        Platform                        CPUs Cores Sockets Memory(GB)
---------------- ------------------------------- ---- ----- ------- ----------
localhost.locald Linux x86 64-bit                   1                     1.46

              Snap Id      Snap Time      Sessions Curs/Sess  PDBs
            --------- ------------------- -------- --------- -----
Begin Snap:       164 18-Apr-15 14:00:41        42       1.8     1
  End Snap:       170 18-Apr-15 15:00:33        42       1.3     1
   Elapsed:                 59.87 (mins)
   DB Time:                 56.41 (mins)

Load Profile                    Per Second   Per Transaction  Per Exec  Per Call
~~~~~~~~~~~~~~~            ---------------   --------------- --------- ---------
             DB Time(s):               0.9               0.2      0.01      0.04
              DB CPU(s):               0.0               0.0      0.00      0.00
      Redo size (bytes):          30,844.9           5,302.4
  Logical read (blocks):           1,014.9             174.5
          Block changes:             158.9              27.3
 Physical read (blocks):             115.6              19.9
Physical write (blocks):              28.4               4.9
       Read IO requests:             103.7              17.8
      Write IO requests:              22.6               3.9
           Read IO (MB):               0.9               0.2
          Write IO (MB):               0.2               0.0
             User calls:              25.7               4.4
           Parses (SQL):              32.5               5.6
      Hard parses (SQL):               6.1               1.1
     SQL Work Area (MB):              -0.3              -0.1
                 Logons:               1.4               0.2
         Executes (SQL):             165.0              28.4
              Rollbacks:               0.0               0.0
           Transactions:               5.8

Instance Efficiency Percentages (Target 100%)
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
            Buffer Nowait %:   99.97       Redo NoWait %:   99.99
            Buffer  Hit   %:   88.61    In-memory Sort %:  100.00
            Library Hit   %:   93.58        Soft Parse %:   81.20
         Execute to Parse %:   80.32         Latch Hit %:  100.00
Parse CPU to Parse Elapsd %:    7.29     % Non-Parse CPU:   60.09

Top 10 Foreground Events by Total Wait Time
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
                                            Total Wait    Wait   % DB
Event                                 Waits Time (sec) Avg(ms)   time  Wait Class
------------------------------ ------------ ---------- ------- ------  ----------
db file sequential read             329,858       1671       5   49.4  User I/O
log file sync                        20,833      691.7      33   20.4  Commit
write complete waits                    216      224.4    1039    6.6  Configuration
cursor: pin S wait on X                 264       85.7     324    2.5  Concurrency
DB CPU                                            77.5            2.3
resmgr: cpu quantum                   3,286       76.9      23    2.3  Scheduler
read by other session                   627       31.4      50     .9  User I/O
db file parallel read                   943       22.1      23     .7  User I/O
library cache load lock                 186       19.6     106     .6  Concurrency
db file scattered read                  827       15.1      18     .4  User I/O

The best way to tune this database would seem to be to get faster disks; another alternative would be to increase the size of the buffer cache so that less data has to be read from disk. The ADDM report automatically analyzes the components of DB time and makes appropriate suggestions, some of which are shown in Listing 16-4. The ADDM script is addmrpt.sql, and it too can be found in ORACLE_HOME dbmsadmin.

Findings and Recommendations
----------------------------

Finding 1: "User I/O" wait Class
Impact is .48 active sessions, 51.59% of total activity.
--------------------------------------------------------
Wait class "User I/O" was consuming significant database time.

   No recommendations are available.

Finding 2: Top SQL Statements
Impact is .3 active sessions, 32.39% of total activity.
-------------------------------------------------------
SQL statements consuming significant database time were found. These
statements offer a good opportunity for performance improvement.

   Recommendation 1: SQL Tuning
   Estimated benefit is .16 active sessions, 17.46% of total activity.
   -------------------------------------------------------------------
   Action
      Run SQL Tuning Advisor on the SELECT statement with SQL_ID
      "c13sma6rkr27c".
      Related Object
         SQL statement with SQL_ID c13sma6rkr27c.
         SELECT PRODUCTS.PRODUCT_ID, PRODUCT_NAME, PRODUCT_DESCRIPTION,
         CATEGORY_ID, WEIGHT_CLASS, WARRANTY_PERIOD, SUPPLIER_ID,
         PRODUCT_STATUS, LIST_PRICE, MIN_PRICE, CATALOG_URL, QUANTITY_ON_HAND
         FROM PRODUCTS, INVENTORIES WHERE PRODUCTS.CATEGORY_ID = :B3 AND
         INVENTORIES.PRODUCT_ID = PRODUCTS.PRODUCT_ID AND
         INVENTORIES.WAREHOUSE_ID = :B2 AND ROWNUM < :B1
   Rationale
      The SQL statement executed in container PDB1 with database ID
      3345156736.
   Rationale
      The SQL spent 96% of its database time on CPU, I/O and Cluster waits.
      This part of database time may be improved by the SQL Tuning Advisor.
   Rationale
      Database time for this SQL was divided as follows: 100% for SQL
      execution, 0% for parsing, 0% for PL/SQL execution and 0% for Java
      execution.
   Rationale
      SQL statement with SQL_ID "c13sma6rkr27c" was executed 13518 times and
      had an average elapsed time of 0.03 seconds.
   Rationale
      I/O and Cluster wait for TABLE "SOE.INVENTORIES" with object ID 96079
      consumed 89% of the database time spent on this SQL statement.
   Rationale
      Top level calls to execute the PL/SQL statement with SQL_ID
      "0w2qpuc6u2zsp" are responsible for 100% of the database time spent on
      the SELECT statement with SQL_ID "c13sma6rkr27c".
      Related Object
         SQL statement with SQL_ID 0w2qpuc6u2zsp.
         BEGIN :1 := orderentry.neworder(:2 ,:3 ,:4 ); END;

Understanding the Oracle Wait Interface

Statspack gets its data from the Oracle wait interface—the collection of dynamic performance views that track all aspects of database activity. Performance-monitoring tools can query these tables by using SQL. Some of the most important views in the wait interface are described in the following sections.

V$SYSSTAT and V$SESSTAT

V$SESSTAT and V$SYSSTAT contain almost 400 counters describing every aspect of the workload handled by the database. V$SESSTAT contains session-level counters—almost 400 of them for each session—and V$SYSSTAT contains system-level counters, each one being the total of all the session-level counters of the same type. In other words, each row in V$SESSTAT gives you the value of a counter for one session, and each row in V$SYSSTAT gives you the total value for all sessions. Four of these counters (logons current, opened cursors current, session cursor cache current, and workarea memory allocated) represent current levels; the rest are cumulative counters that keep incrementing from the time the database was started.

Because the majority of these counters are cumulative, the way to monitor the rate of activity is to observe the values of the counters at fixed intervals and calculate the difference. This is the approach used by the Statspack report. Some of the most important counters are described here:

• CPU used by this session is the amount of CPU used by one session in the case of V$SESSTAT. It is the amount of CPU used by all sessions put together in the case of V$SYSSTAT.
• consistent gets and db block gets are the number of blocks read in consistent and current mode, respectively; current mode is used to find the most up-to-date version of a block, and consistent mode is used to find the state of a block at a prior point in time. The sum of consistent gets and db block gets is the number of logical reads performed by the database.
• physical reads is the number of blocks that are not found in the memory cache and have to be physically retrieved from the disk.
• physical writes is the number of modified blocks that are written to disk.
• user commits and user rollbacks track transaction rates.

A complete list of the workload metrics tracked in the V$SYSSTAT and V$SESSTAT views is available in Oracle Database 12c Reference.

V$SESSION_EVENT and V$SYSTEM_EVENT

Whereas V$SESSTAT and V$SYSSTAT track the workload handled by the database, V$SESSION_EVENT and V$SYSTEM_EVENT track the amount of time spent waiting in over 100 different categories—for example, waiting for I/O or waiting for a lock. All the counters are cumulative; V$SESSION_EVENT has session-level counters, and V$SYSTEM_EVENT has system-level counters. You saw some examples of these counters in the Top 5 Timed Events example (Listing 16-2) earlier in this chapter; a complete list and explanation of each wait event is provided in Oracle Database 11g Reference. Here are some more examples:

• db file sequential read tracks the amount of time spent reading single blocks from tables.
• db file scattered read tracks the amount of time spent performing full table scans.
• enq: TX - contention is the amount of time spent waiting for row locks.
• enq: TM - contention is the amount of time spent waiting for table-level locks.

Mining the Statspack Repository

Statspack gets its data by performing snapshots of the dynamic performance tables such as V$SYSSTAT and V$SYSTEM_EVENT. This data is stored in tables that mimic the structure of the dynamic performance tables; for example, the STATS$SYSSTAT table corresponds to the V$SYSSTAT view, and the STATS$SYSTEM_EVENT table corresponds to the V$SYSTEM_EVENT view.

The Statspack repository can be mined for historical data that can be graphed using tools such as Microsoft Excel. The graphs show any historical trends and repeating patterns.

In Chapter 10, you saw examples of SQL queries to mine the Statspack repository. Listing 10-8 showed an SQL query to track logical reads per second and physical reads per second over a period of time. That query is a good way to monitor trends and changes in the database workload; you can modify it to include other workload metrics. The corresponding graph is shown in Figure 10-2. Listing 10-9 showed an SQL query to extract performance information on specific SQL queries of your choice.

In Listing 16-5, you see another valuable SQL query; it provides the distribution of DB time for each available time period. It is a fairly long query, but you can download the text from the Source Code section of the Apress web site (www.apress.com). You have to specify a range of snapshots; the appropriate range can be obtained from the STATS$SNAPSHOT table. As explained earlier in this chapter, the distribution of DB time is precisely the information you need to tune the database. CPU time is obtained from the STATS$SYSSTAT table, and the wait time for each type of event is obtained from the STATS$SYSTEM_EVENT table. The classifications in the V$EVENT_NAME view are used to group events into categories such as Application, Concurrency, Commit, User IO, and System IO. The PIVOT operator is used to convert rows into columns; this makes it easy to perform further analysis on the data. The LAG function is used to compute the amount of increase in each row of data. Finally, you divide CPU time and wait time by the length of the observed interval to compute average active sessions for each category of time. The AWR analog of this query is available in the Google group for this book (https://groups.google.com/forum/#!forum/beginning-oracle-database-12c-administration).

Sample output of this query is shown in Figures 16-1 and 16-2. Each graph shows data for the same database, one week at a time. Even if you knew very little about performance tuning, you could instinctively tell which week was a good week for the database and which week was a bad week. The graph in Figure 16-1 exhibits very regular patterns, indicating database stability. The graph in Figure 16-2 is for another week in the same database, but the regular patterns are missing. I hope these examples convince you of the importance of becoming familiar with the workload and performance patterns in your database.

set linesize 132
set pagesize 10000
set tab off
set trimout on
set trimspool on
set sqlblanklines on

alter session set nls_date_format = ’yyyy/mm/dd hh24:mi’;

column aas_cpu format 999.99
column aas_other format 999.99
column aas_application format 999.99
column aas_concurrency format 999.99
column aas_commit format 999.99
column aas_user_io format 999.99
column aas_system_io format 999.99

WITH
  timed_events AS

  -- Get wait time from the STATS$SYSTEM_EVENT table.
  -- Select snapshots between start_snap_id and end_snap_id.
  -- Convert wait microseconds into seconds.
  -- Merge some wait classes into the "Other" class (wait_class# = 0).
  -- Ignore the "Idle" class (wait_class = 6).
  -- Wait classifications are those found in the V$EVENT_NAME view.

  -- Get CPU usage from the STATS$SYSSTAT table.
  -- Select snapshots between start_snap_id and end_snap_id.
  -- Convert CPU centiseconds into seconds.

  (SELECT   snap_id,
            CASE
                 WHEN wait_class# IN (0, 2, 3, 7, 10, 11, 12)
                 THEN 0
                 ELSE wait_class#
            END AS wait_class#,
            time_waited_micro / 1000000 AS time_spent
     FROM   stats$system_event NATURAL JOIN v$event_name
    WHERE   snap_id between &&start_snap_id and &&end_snap_id
      AND   wait_class# != 6

            UNION ALL

   SELECT   snap_id,
            100 as wait_class#,
            VALUE / 100 as time_spent
     FROM   stats$sysstat
    WHERE   snap_id between &&start_snap_id and &&end_snap_id
      AND   name = ’CPU used by this session’),

------------------------------------------------------------------------------------

  pivoted_data AS

  -- Create separate columns for each wait class and for CPU time.

  (SELECT   *
     FROM   (SELECT * from timed_events)
            PIVOT (SUM(time_spent)
              FOR wait_class# IN ( 0 AS other,
                                   1 AS application,
                                   4 AS concurrency,
                                   5 AS commit,
                                   8 AS user_io,
                                   9 AS system_io,
                                 100 AS cpu))),

------------------------------------------------------------------------------------

  deltas AS

  -- Use the LAG analytic function to determine the amount of increase.
  -- Partition the rows by database startup time.
  -- The STATS$SNAPSHOT view tells us when the database was started.

  (SELECT   snap_id,

            snap_time,

            (snap_time - LAG(snap_time)
              OVER (PARTITION BY startup_time ORDER BY snap_id)) * 86400
              AS snap_time_d,

            cpu - LAG (cpu)
              OVER (PARTITION BY startup_time ORDER BY snap_id)
              AS cpu_d,

            other - LAG (other)
              OVER (PARTITION BY startup_time ORDER BY snap_id)
              AS other_d,

            application - LAG (application)
              OVER (PARTITION BY startup_time ORDER BY snap_id)
              AS application_d, 

            concurrency - LAG (concurrency)
              OVER (PARTITION BY startup_time ORDER BY snap_id)
              AS concurrency_d,

            commit - LAG (commit)
              OVER (PARTITION BY startup_time ORDER BY snap_id)
              AS commit_d,

            user_io - LAG (user_io)
              OVER (PARTITION BY startup_time ORDER BY snap_id)
              AS user_io_d,

            system_io - LAG (system_io)
              OVER (PARTITION BY startup_time ORDER BY snap_id)
              AS system_io_d

     FROM   pivoted_data NATURAL JOIN stats$snapshot)

------------------------------------------------------------------------------------

  -- Compute and print Average Active Sessions for each category of time.

   SELECT   snap_id,
            snap_time,
            cpu_d / snap_time_d AS aas_cpu,
            other_d / snap_time_d AS aas_other,
            application_d / snap_time_d AS aas_application,
            concurrency_d / snap_time_d AS aas_concurrency,
            commit_d / snap_time_d AS aas_commit,
            user_io_d / snap_time_d AS aas_user_io,
            system_io_d / snap_time_d AS aas_system_io

     FROM   deltas

 ORDER BY   snap_id;

Figure 16-1. A good week for the database

Figure 16-2. A bad week for the database

It is also useful to see at a glance the top five timed events for a range of time periods. The query shown in Listing 16-6 lets you do exactly that. You can download the text of this query and the AWR analog from the Google group for this book (https://groups.google.com/forum/#!forum/beginning-oracle-database-12c-administration). Listing 16-7 shows some sample output; it is for the first six periods in the graph shown in Figure 16-1.

set linesize 132
set pagesize 10000
set tab off
set trimout on
set trimspool on
set sqlblanklines on

alter session set nls_date_format = ’mm/dd hh24:mi’;

column event format a30
column time_spent_d format 9,999,999.90
column aas format 9999.90
column percentage format 999.90

break on snap_id on snap_time skip 1

WITH

  timed_events AS

  -- Get wait time from the STATS$SYSTEM_EVENT table.
  -- Select snapshots between start_snap_id and end_snap_id.
  -- Convert wait microseconds into seconds.
  -- Ignore the "Idle" class (wait_class = 6).
  -- Wait classifications are those found in the V$EVENT_NAME view.

  -- Get CPU usage from the STATS$SYSSTAT table.
  -- Select snapshots between start_snap_id and end_snap_id.
  -- Convert CPU centiseconds into seconds.

  (SELECT   snap_id,
            event,
            time_waited_micro / 1000000 AS time_spent
     FROM   stats$system_event NATURAL JOIN v$event_name
    WHERE   snap_id between &&start_snap_id and &&end_snap_id
      AND   wait_class# != 6

            UNION ALL

   SELECT   snap_id,
            ’CPU used by this session’ AS event,
            VALUE / 100 as time_spent
     FROM   stats$sysstat
    WHERE   snap_id between &&start_snap_id and &&end_snap_id
      AND   name = ’CPU used by this session’),

------------------------------------------------------------------------------------

  deltas AS

  -- Use the LAG analytic function to determine the amount of increase.
  -- Partition the rows by database startup time. 
  -- The STATS$SNAPSHOT view tells us when the database was started.

  (SELECT   snap_id,
            snap_time,
            event,
            (snap_time – LAG (snap_time)
              OVER (PARTITION BY startup_time, event ORDER BY snap_id)) * 86400
              AS snap_time_d,
            time_spent - LAG (time_spent)
              OVER (PARTITION BY startup_time, event ORDER BY snap_id)
              AS time_spent_d
     FROM   timed_events NATURAL JOIN stats$snapshot),

------------------------------------------------------------------------------------

  ranks AS

  -- Use the RANK analytic function to rank the events.
  -- Also compute the percentage contribution of each event.

  (SELECT   snap_id,
            snap_time,
            event,
            snap_time_d,
            time_spent_d,
            RANK()
              OVER (PARTITION BY snap_id ORDER BY time_spent_d DESC)
              AS rank,
            decode(time_spent_d, 0, 0, time_spent_d / SUM(time_spent_d)
              OVER (PARTITION BY snap_id) * 100)
              AS percentage
     FROM   deltas
    WHERE   time_spent_d IS NOT NULL)

------------------------------------------------------------------------------------

  -- Compute Average Active Sessions for each category of time.
  -- List the top 5 events.

   SELECT   snap_id,
            snap_time,
            rank,
            substr(event, 1, 30) as event,
            time_spent_d,
            time_spent_d / snap_time_d as aas,
            percentage
     FROM   ranks
    WHERE   rank <= 5
 ORDER BY   snap_id,
            rank;

 SNAP SNAP_TIME    RANK EVENT                          TIME_SPENT_D    AAS PERCENT
----- ----------- ----- ------------------------------ ------------ ------ -------
 2201 01/07 01:00     1 CPU used by this session             127.05    .04   47.32
                      2 RMAN backup & recovery I/O            74.75    .02   27.84
                      3 control file parallel write           17.59    .00    6.55
                      4 db file sequential read               16.89    .00    6.29
                      5 control file sequential read          10.56    .00    3.93

 2211 01/07 02:00     1 log file sync                        269.49    .07   36.58
                      2 log file parallel write              266.31    .07   36.15
                      3 CPU used by this session             151.23    .04   20.53
                      4 db file sequential read               31.48    .01    4.27
                      5 control file parallel write           15.52    .00    2.11

 2221 01/07 03:00     1 log file parallel write              867.97    .24   31.45
                      2 CPU used by this session             653.38    .18   23.67
                      3 log file sync                        608.85    .17   22.06
                      4 db file scattered read               273.92    .08    9.93
                      5 log buffer space                     121.16    .03    4.39

 2231 01/07 04:00     1 log file parallel write            2,169.10    .60   30.36
                      2 CPU used by this session           1,362.13    .38   19.06
                      3 db file scattered read             1,308.39    .36   18.31
                      4 db file sequential read              871.71    .24   12.20
                      5 log file sequential read             606.94    .17    8.49

 2241 01/07 05:00     1 db file scattered read             3,154.11    .88   82.63
                      2 db file sequential read              264.16    .07    6.92
                      3 CPU used by this session             102.78    .03    2.69
                      4 log file parallel write              101.61    .03    2.66
                      5 control file parallel write           84.06    .02    2.20

 2251 01/07 06:00     1 db file scattered read             3,327.81    .92   71.27
                      2 CPU used by this session             827.02    .23   17.71
                      3 db file sequential read              261.75    .07    5.61
                      4 read by other session                122.51    .03    2.62
                      5 control file parallel write           58.31    .02    1.25

Using the Statspack Report

A Statspack report is generated from two snapshots of the database. These snapshots are a copy of the contents of the various dynamic performance tables that are continuously accumulating information about activity in the database. AWR and ADDM were offered as replacements for Statspack beginning with Oracle Database 10g and are no longer documented in the Oracle manuals. However, you can use AWR and ADDM only with Enterprise Edition and only if you have a license for Diagnostics Pack—an extra-cost option available only with Enterprise Edition. In my experience, very few organizations have the requisite licenses. I therefore emphasize the use of Statspack and use it a lot in my own work. Note that Oracle did make several incremental enhancements to Statspack in Oracle Database 10g and 11g, thus further increasing its usefulness and relevance. However, you will have to refer to Chapter 21 of Oracle Database 9i Performance Tuning Guide and Reference for documentation on Statspack because it is not documented in the Oracle Database 10g and 11g manuals. A useful introduction to Statspack as well as installation instructions can be found in spdoc.txt in the ORACLE_HOME dbmsadmin folder.

The Statspack report contains a wealth of other information that can help you diagnose and solve your performance problem. In Listing 16-2, you saw the first page of a sample Statspack report, of which the most interesting section was the Top 5 Timed Events section. Here is a list of other interesting sections of the Statspack report:

• SQL Ordered by CPU lists the SQL queries that consume the most CPU.
• SQL Ordered by Elapsed Time lists the SQL queries that take the longest.
• SQL Ordered by Gets lists the SQL queries that perform the most logical reads.
• SQL Ordered by Reads lists the SQL queries that perform the most physical reads.
• Instance Activity Stats lists workload data from the V$SYSSTAT dynamic performance view.
• File Read Histogram Stats lists workload and performance metrics for each file in the database.
• Segments by Logical Reads and Segments by Physical Reads show which tables and indexes have the most logical reads and physical reads. They are only available in level-7 snapshots. Refer to Chapter 21 of Oracle Database 9i Performance Tuning Guide and Reference for information on the different snapshot levels and how to change them.

Summary

Here is a short summary of the concepts touched on in this chapter:

• When a performance problem is reported, the database might not be the cause. A systematic method should be used to identify the root cause.
• The five steps for addressing any performance problem are define, investigate, analyze, solve, and implement.
• The best way to analyze database performance is to find out where the database is spending its time. This is summarized by the Top 5 Timed Events section of the Statspack report.
• Statspack gets its data from the Oracle wait interface—the collection of dynamic performance views that track all aspects of database activity. Important views include V$SYSSTAT, V$SESSTAT, V$SESSION_EVENT, and V$SYSTEM_EVENT.
• The Statspack repository can be mined for historical data that can be graphed using tools such as Microsoft Excel. This is a good way to monitor trends and changes in the database workload and database performance. You can also track performance of individual queries over time. It is also useful to see at a glance the top five timed events for a range of time periods.
• A stable database exhibits distinct repeating patterns; for example, the workload may peak during the day and subside at night. These patterns are the signature of the database. Deviations from established patterns can be a sign that something is wrong with the database; the Statspack reports for the affected periods can be analyzed and compared with the reports for baseline periods.
• The Statspack report contains a wealth of information that can help you diagnose and solve a performance problem. Examples include SQL Ordered by CPU, SQL Ordered by Elapsed Time, SQL Ordered by Gets, SQL Ordered by Reads, Instance Activity Stats, File Read Histogram Stats, Segments by Logical Reads, and Segments by Physical Reads.

Exercises

1. In this exercise, you will duplicate the locking problem described in this chapter. You will need to use the HR sample schema as well as Statspack. If you have not already installed Statspack in your test database, run the scripts spcreate.sql and spauto.sql in the $ORACLE_HOME/rdbms/admin folder. The instructions are in spdoc.txt in the same folder.
   1. Query the DBA_CONSTRAINTS and DBA_CONS_COLUMNS views, and confirm that the manager_id column of the employees table in the HR schema is a foreign key that links to the employee_id column of the same table. Use the following commands:

      SELECT constraint_name
        FROM dba_constraints
       WHERE owner = ’HR’
         AND table_name = ’EMPLOYEES’
         AND constraint_type = ’P’;
      
      SELECT constraint_name,
             owner,
             table_name
        FROM dba_constraints
       WHERE constraint_type = ’R’
         AND r_owner = ’HR’
         AND r_constraint_name = ’EMP_EMP_ID_PK’;
      
      SELECT column_name,
             position
        FROM dba_cons_columns
       WHERE owner = ’HR’
         AND constraint_name = ’EMP_EMP_ID_PK’;
      
      SELECT column_name,
             position
        FROM dba_cons_columns
       WHERE owner = ’HR’
         AND constraint_name = ’EMP_MANAGER_FK’;

   2. Drop the emp_manager_ix index on the manager_id column of the employees table. Use the command drop index hr.emp_manager_ix.
   3. Find the name of each employee’s manager. Use the following command:

        SELECT e2.first_name AS manager_first_name,
               e2.last_name AS manager_last_name,
               e1.first_name AS employee_first_name,
               e1.last_name AS employee_last_name
          FROM hr.employees e1,
               hr.employees e2
         WHERE e2.employee_id = e1.manager_id
      ORDER BY 1, 2, 3, 4;

   4. Connect to the database as the HR user, and update one of the records in the employees table. For example, issue the command update employees set phone_number=phone_number where first_name=&x2019;Alexander&x2019; and last_name=&x2019;Hunold&x2019;. Do not commit this transaction.
   5. Connect to the database again and attempt to delete the manager of the employee whose record you just updated. For example, issue the command delete from employees where first_name=&x2019;Lex&x2019; and last_name=&x2019;De Haan&x2019;. Oracle will block this command.
   6. Connect to the database as the system user. Query the v$session_wait table, and find the session ID of the blocked session. Because you know it is waiting for an enq: TM - contention event to complete, you can use the command select sid as session_id, wait_time_micro from v$session_wait where event = &x2019;enq: TM - contention&x2019;.
   7. Query the V$SESSION view, and obtain the serial number of the blocked process. Use the command select serial# as serial_num from v$session where sid=&session_id.
   8. Begin tracing the blocked session by using the DBMS_MONITOR.SESSION_TRACE_ENABLE session. Issue the command execute dbms_monitor.session_trace:enable(&session_id, &serial_num, TRUE). Refer to Oracle Database 11g PL/SQL Packages and Types Reference for a description of the session_trace:enable procedure.
   9. Generate a Statspack snapshot by using the statspack.snap procedure. Using a special version of the procedure, capture performance information for the blocked session in addition to system-wide information; issue the command execute statspack.snap(i_session_id => &session_id).
   10. Resume the first session, and issue the rollback command. This will release the blocked session, and Oracle will display the error ORA-02292: integrity constraint (HR.EMP_MANAGER_FK) violated - child record found.
   11. Identify the trace file for the second session by using the command select tracefile from v$process where addr = (select paddr from v$session where sid = &session_id). Review the trace file, and locate the lines similar to the following line:

       WAIT #4: nam=’enq: TM - contention’ ela= 855599225
       name|mode=1414332421 object #=71472
       table/partition=0 obj#=-1 tim=198871373294

   12. Confirm that the object number listed in the trace file corresponds to the employees table. Use the command select owner, object_type, object_name from dba_objects where object_id=&object_id.
   13. Perform the experiment once more, and confirm that additional wait messages appear in the trace file.
   14. Navigate to the folder where the trace file is located, and invoke the tkprof utility from the command line. You have to specify the name of the trace file and choose a name for the output file. Review the output file created by tkprof.
   15. Generate another Statspack snapshot by using the statspack.snap procedure with the same parameter used in step 9. Use the command execute statspack.snap(i_session_id => &session_id).
   16. Connect to the database as the system or perfstat user, and generate a Statspack report from the snapshots obtained in step i and step o. Run the spreport.sql script by using the command @?/rdbms/admin/spreport.sql.
   17. Review the Statspack report. In particular, review the Top 5 Timed Events section. Also pay attention to the sections of the report that provide information on the blocked session you were tracking.
   18. Connect to the database as the HR user, and re-create the index you dropped at the start at the exercise. Use the command create index hr.emp_manager_ix on hr.employees (manager_id).
2. Download the Swingbench tool, and run the Order Entry benchmark for an hour. Review the AWR, ADDM, and Statspack reports for the run. Tune the database, and attempt to improve performance.

Further Reading

• The free Oracle Database 12c Performance Tuning Guide offers a detailed and comprehensive treatment of performance-tuning methods, and the price is right.
• Chapter 11 of Oracle Database 9i Performance Tuning Guide and Reference explains how to install and use Statspack. Note that Statspack is not documented in the reference guides for Oracle Database 10g, 11g, and 12c, even though it has been upgraded for all these versions. Refer to the upgrade notes in $ORACLE_HOME/rdbms/admin/spdoc.txt in your virtual machine.

Footnotes

¹In 2007, the president of a well-known consulting company reported that only 2 of its 70 clients had licenses for Diagnostics Pack.

²This was presented in Chapter 11 as a general method of solving any performance problems; refer to the flowchart shown in Figure 11-2.

³The Swingbench tool can be downloaded from www.dominicgiles.com.