Poor performance of PSPMSESSIONS_VW view affects Performance Monitor System Monitor Component

The System Performance Monitor component (PSPMSYSHEALTH; navigation: PeopleTools -> Performance Monitor -> System Performance) gives an overview of each system monitored by the PeopleSoft Performance Monitor. However, the poor performance of the view PSPMSESSIONS_VW can severely affect this component, to the extent that as transaction history builds up the component will not respond within the timeout.

Below is an extract from a PeopleTools trace. What happened is that the query ran until the Tuxedo service timed out. Tuxedo terminated application server process 31944, and spawned a new process (ID 3598). The user session received an error.

PSAPPSRV.31944 (70)   1-783    11.38.38    0.000072
Cur#1.31944.PMONITOR RC=0 Dur=0.000040 COM
Stmt=select count(*) from pspmsessions_vw where pm_agentid = :1
PSAPPSRV.31944 (70)   1-784    11.38.38    0.000008
Cur#1.31944.PMONITOR RC=0 Dur=0.000001 
Bind-1 type=19 length=3 value=689
PSAPPSRV.3598 (112)   1-132    11.42.39  314.495972
Cur#1.3598.PMONITOR RC=0 Dur=0.000095 COM
Stmt=SELECT VERSION FROM PSVERSION WHERE OBJECTTYPENAME = 'SYS'

Even when each query finishes within a reasonable amount of time, the query can be run several times by the component.

This is the definition of PSPMSESSIONS_VW delivered by PeopleSoft.

SELECT T3.PM_CONTEXT_VALUE1
,      T3.PM_AGENTID
,      T3.PM_AGENT_STRT_DTTM
FROM   PSPMTRANSHIST T3
WHERE  T3.PM_TRANS_DEFN_ID = 116
AND    PM_TRANS_STATUS = '1'
AND    PM_TRANS_DURATION <> 0
AND    T3.PM_CONTEXT_VALUE1 IN (
SELECT T.PM_CONTEXT_VALUE1
FROM   PSPMTRANSHIST T
WHERE  T.PM_TRANS_DEFN_SET = 1
AND    T.PM_TRANS_DEFN_ID = 109
AND    T.PM_MON_STRT_DTTM > %TimeAdd(%CurrentDateTimeIn, -720)
AND    T.PM_PARENT_INST_ID <> PM_TOP_INST_ID
AND    T.PM_CONTEXT_VALUE1 NOT IN (
 SELECT T2.PM_CONTEXT_VALUE1
 FROM   PSPMTRANSHIST T2
 WHERE  T2.PM_TRANS_DEFN_SET = 1
 AND    T2.PM_TRANS_DEFN_ID = 108
 AND    T2.PM_CONTEXT_VALUE1 = T.PM_CONTEXT_VALUE1
 AND    T2.PM_MON_STRT_DTTM > %TimeAdd(%CurrentDateTimeIn, -720)))

Firstly, accurate object statistics are required on the transaction history table and its indexes.

An additional index is required on PSPMTRANSHIST:

CREATE INDEX PSPPSPMTRANSHIST ON PSPMTRANSHIST
(PM_TRANS_DEFN_SET
,PM_TRANS_DEFN_ID
,PM_CONTEXT_VALUE1
,PM_MON_STRT_DTTM)
TABLESPACE PSINDEX PCTFREE 0
PARALLEL NOLOGGING COMPRESS 3
/
ALTER INDEX PSPPSPMTRANSHIST NOPARALLEL LOGGING
/

Finally, I have changed the view.

• The IN() operators have been changed to WHERE EXISTS(). The new index supports the efficient execution of these sub-queries.
• The sub-queries are now both correlated back to the main query on T3.
• The ROWNUM criteria have been added to restrict the number of rows the sub-queries can return.

SELECT T3.PM_CONTEXT_VALUE1 /*Session ID*/
,      T3.PM_AGENTID
,      T3.PM_AGENT_STRT_DTTM
FROM   PSPMTRANSHIST T3
WHERE  T3.PM_TRANS_DEFN_ID = 116 /*Redirect after login*/
AND    T3.PM_TRANS_DEFN_SET = 1 /*added*/
AND    T3.PM_TRANS_STATUS = '1'
AND    T3.PM_TRANS_DURATION <> 0
AND EXISTS(
SELECT 'x'
FROM   PSPMTRANSHIST T
WHERE  T.PM_TRANS_DEFN_SET = 1
AND    T.PM_TRANS_DEFN_ID = 109 /*User Session Began*/
AND    T.PM_MON_STRT_DTTM > %TimeAdd(%CurrentDateTimeIn, -720)
AND    T.PM_PARENT_INST_ID <> T.PM_TOP_INST_ID
AND    T.PM_CONTEXT_VALUE1 = T3.PM_CONTEXT_VALUE1
AND NOT EXISTS(
 SELECT 'x'
 FROM   PSPMTRANSHIST T2
 WHERE  T2.PM_TRANS_DEFN_SET = 1
 AND    T2.PM_TRANS_DEFN_ID = 108 /*User Session Ended*/
 AND    T2.PM_MON_STRT_DTTM > %TimeAdd(%CurrentDateTimeIn, -720)
 AND    T2.PM_CONTEXT_VALUE1 = T3.PM_CONTEXT_VALUE1
 AND    ROWNUM <= 1)
 AND    ROWNUM <= 1)

The effect of these changes is a significant improvement in the performance of the query. I ran a test query for a single agent on a system with over 3 million rows on PSPMTRANSHIST:

• Original: 24895 consistent gets
  
• New Index: 22547 consistent gets
  
• and View Changes: 85 consistent gets

Your mileage may vary, but for me this made the difference between the component being usable and not.

Row Migration can Aggravate Contention on Cache Buffers Chains Latch

One of my customers has an Oracle based system with a large number of concurrent users. For time to time, the users would report that the system would 'grind to a halt'. Examination of AWR data showed lots of time spent waiting on latch: cache buffers chains (I discussed how to graph AWR data in Excel in a previous blog entry, which is how I produced this graph of database wait events).

They system had been able to go for weeks without an incident. More recently, as more users have been migrated onto the system, we would a series of days with spikes on this wait event, though they were normally quite short-lived. The incident shown in this chart was unusual in that it lasted most of a day. The chart also shows that a reasonable amount of time was lost on db file sequential read, this is consistent with blocks being loaded into the buffer cache, requiring access to the cache buffer chains, and hence requiring access to the latch that protects these chain.

Using a similar technique I was graph the number of database sessions over time, and I found a similar series of spikes.

By eye I could see that the spikes in the latch contention seemed to correspond to the spikes in the number of concurrent user sessions, and they had roughly the same shape.

I then graphed time waited for this latch against the number of concurrent user sessions and I got a strong, and surprisingly linear, correlation.

It is very clear that whenever we had more than about 90 concurrent user sessions, the system also lost time waiting on the cache buffers chains latch. Basically, this application won't scale any further!

So, why was the latch being held for such a long time? The buffer cache is 1Gb (with a block size of 8Kb), so it is large, but not excessively so. At this point somebody (and I can't claim the credit for this) thought to check for migrated rows on the tables involved in the longest running SQL statements during the periods of high latch contention, and discovered that a number of the most heavily use tables had a significant quantity of migrated rows.

A row migrates when the data is updated and there is no free space left in the data block to store the new data values. Oracle puts the row into a new block, but it does not update the indexes to point to the new block. Instead, it puts a forwarding pointer into the original block. Therefore, to read the data from a migrated row requires visits to two blocks. When retrieving data into the buffer cache your process need to update two buffer blocks, and must acquire the buffer chains latch twice. Row migration causes poor performance because Oracle must do twice as much work.

There are two factors that come together to cause row migration:

• A process inserts a row, and then subsequently updates columns on that row, often from null to not null values, but sometimes with just more data. In my case, the application was storing XML structures in a clob (and most of the clobs were small enough to be stored in-line with the rest of the row).
• There is insufficient free space left in the data blocks to allow for the subsequent updates to be stored in the original data block.

In this particular case, I was dealing with a third-party packaged application. So there was no possibility to change the way the application inserts and updats the data. However, we could and did rebuild the object to eliminate migration of existing rows and set a realistic PCTFREE to reserve free space for future rows.

This chart shows the same data as the first one, except that I have changed the scale on the y-axis. The tables with the worst row migration were reorganised on the Tuesday night and the system ran on Wednesday under a normal load without any problem.

Contention on the buffer cache chains latch fell to trivial levels, just 408 seconds in 24 hours. Interestingly, the amount of db file sequential read also fell by 70%. This is due to better cache efficiency. Since eliminating much of the row migration, fewer blocks need to be loaded into cache, and so blocks stay in the buffer cache for longer.

This is a real-life example of:

• why it is important, sometimes critically so, to set physical attributes on tables properly;
  
• why it is necessary to understand how your application is updating the database;
• and what are the potential implications of not doing so!
  

Graphing AWR Data in Excel

I often use data collected by the Oracle Automatic Workload Repository (AWR) to help to diagnose performance problems. However, I often work on performance problems with application teams, rather than the DBAs.  It is surprising how often that I don't have access to Oracle Enterprise Manager.

Somebody might say that the system was slow at a particular time. I want to get an overview of the database at that time, and I might also want to compare it to another time when the system wasn't slow. Later I may generate AWR reports using particular pairs of snapshots, but I need something to direct me to when an issue occurred, and hence which snapshots to compare.

When dealing with performance problems the question is nearly always the same. "How long did I spend doing what?". Amongst lots of metrics, AWR collects snapshots of how much time system-wide has been spent waiting on each wait event.

To give me an overview of that data, I have created an excel spreadsheet that will query the AWR repository and retrieve that data for up to a week into am Excel pivot table, and will then graph the top wait events. Click on the thumbnail on the left to see an example.

For me, this approach has a number of advantages:

• First; don't drown in numbers. The eye is very good at picking out patterns and irregularities. You can then drill into the numbers behind the chart.
  
• The chart provides a quick overview of the behaviour of the database. You can quickly see if there is anything to examine in more detail, or whether the database is exhibiting its normal characteristics.
  
• The AWR data is extracted into the spreadsheet, so I can keep a copy of the spreadsheet for reference. I generally like to collect AWR snapshots every 15 minutes. One week of data, at that frequency, turns into about 6Mb of spreadsheet.
• Excel charts can easily be put into documents, presentations or e-mails. Excel is very flexible, it is easy to format the chart to show only what is important.
• It's free (that is to say that you won't need to go and buy anything else). All you need is Excel and an Oracle client.

Over time I have produced a variety of spreadsheets that collect all sorts of metrics from the Oracle database and others that collect specific metrics from PeopleSoft applications.

To be fair, AWR's forerunner, Statspack collects a lot of similar data to AWR, the essential difference being that AWR is a licensed option. This technique could also be used to extract data from the statspack repository, but most of my customers are licensed for AWR.

You can download a sample Excel workbook and query from my website. Go to one of the sheets with data and 'Refresh Data'. The first time you will probably be prompted to select and ODBC source. You will be prompted for the login credentials.

In a subsequent blog posting I will discuss a real example of where this technique helped me to resolve a problem.

It is fairly straightforward to create spreadsheets that query databases, but here are some links that should help to get you going if you are not familiar with the process.

• From the Microsoft website: 'Use Microsoft Query to retrieve external data'. This is based on Excel 2007, but it explains how Excel calls MSQuery which then calls the ODBC driver. However, I recommend that you do not use the Query Wizard. I prefer to get the query working in SQL*Plus and then I copy it into MSQuery
• Querying External Data in Excel. This is a straightforward recipe for using MSQuery.

Update 16.6.2010: I have released a new version with an adjustment to the query used in the spreadsheet.  AWR snapshots happen at slightly different times on different RAC nodes, although they have the same SNAP_ID.  This was causing multiple rows for the same snapshot in the pivot tables, and so the charts did not show correctly aggregated wait events across RAC nodes.