A Small Statspack Success

I'll warn you up front that this is going to be spectacularly lacking in detail but it's a simple and true example from the other week of the kind of thing I find Statspack useful for.

One of the developers scuttled round to my desk one late shift very concerned about a production feed that had slowed to a crawl the day before. He'd spent most of this day going round in circles trying to persuade DBAs that something was wrong and was at the end of his tether ('Network problems' indeed!). These days I'm in the development team so I don't do production, but I could tell he was fed up so I said I'd take a quick look.

All of our databases have 15 minute snapshots going back 30 days so I asked him when the problem had first occurred and ran two reports for 30 minute intervals at the same time on two days - the day before the problem and the day of the problem. This would be adequate because this feed runs throughout the day.

As usual with Statspack, there was a ton of information and I suppose the skill comes in deciding where to look. Most of the time I'll look at the timed event profile at the start of the report and the SQL ordered by gets at the very least.

Here's the start of the SQL ordered by gets statement for the good day.

  Buffer Gets    Executions  Gets per Exec  %Total Time (s)  Time (s) Hash Value
--------------- ------------ -------------- ------ -------- --------- ----------
     15,480,730          127      121,895.5   28.0   117.44    289.69  169133436
Module: JDBC Thin Client
Select teamname AS rs_Team, teammanagername AS rs_TeamManager, S
tatus AS rs_Status, RESOURCETYPECODE AS rs_ResourceTypeCode, reg
ioncode AS rs_RegionCode, PayrollNumber AS rs_PayrollNumber, par
tyid AS rs_PartyId, managercontactnumber AS rs_ManagerContactNum
ber, ismanager AS rs_IsManager, installername AS rs_Name, idno A

      5,311,261        6,914          768.2    9.6   204.55   3533.63 2400602673
Module: JDBC Thin Client
Select username AS rs_UserLogin, taskdescription AS rs_TaskDescr
iption, productname AS rs_ProductName, PortfolioOwnerName AS rs_
PortfolioOwnerName, PortfolioId AS rs_PortfolioId, partynumber A
S rs_PartyNumber, partyid AS rs_PartyId, offeringname AS rs_Offe
ringName, jobid AS rs_JobID, intrctnstatecode AS rs_State, inter

      2,484,342          813        3,055.8    4.5    38.95     40.08  425417216
Module: JDBC Thin Client
Select SERVICECODE AS rs_ServiceCode, JOBTYPE AS rs_JobType, FMS
PRODUCTCODE AS rs_FmsProductCode, BUNDLENAME AS rs_BundleName, B
UNDLEID AS rs_BundleID from V_BSBINSTALLBUNDLEPICKER

And this is from the bad day. I've highlighted the two statements that have appeared that weren't there before.

  Buffer Gets    Executions  Gets per Exec  %Total Time (s)  Time (s) Hash Value
--------------- ------------ -------------- ------ -------- --------- ----------
     10,116,721           84      120,437.2   21.4    73.15     80.26  169133436
Module: JDBC Thin Client
Select teamname AS rs_Team, teammanagername AS rs_TeamManager, S
tatus AS rs_Status, RESOURCETYPECODE AS rs_ResourceTypeCode, reg
ioncode AS rs_RegionCode, PayrollNumber AS rs_PayrollNumber, par
tyid AS rs_PartyId, managercontactnumber AS rs_ManagerContactNum
ber, ismanager AS rs_IsManager, installername AS rs_Name, idno A

      9,682,739          280       34,581.2   20.5   820.43   1744.27  404442202
Module: JDBC Thin Client
BEGIN ISR_SCMS_EXTRACT.ISR_VS_PUT_SCMS_RESULTS(:1); END;

      9,678,951           52      186,133.7   20.5   819.86   1733.18 1081636089
Module: JDBC Thin Client
UPDATE VS_CONTROL_SUBSCRIBER_IDS SET SCMS_EXTRACT_REQUIRED = 'E'
 WHERE SCMS_EXTRACT_REQUIRED = 'S' AND SCMS_REQUEST_DATE <= SYSD
ATE - :B1
      2,738,922        3,887          704.6    5.8    99.47   1544.92 2400602673
Module: JDBC Thin Client
Select username AS rs_UserLogin, taskdescription AS rs_TaskDescr
iption, productname AS rs_ProductName, PortfolioOwnerName AS rs_
PortfolioOwnerName, PortfolioId AS rs_PortfolioId, partynumber A
S rs_PartyNumber, partyid AS rs_PartyId, offeringname AS rs_Offe
ringName, jobid AS rs_JobID, intrctnstatecode AS rs_State, inter

Now, and this is very important, because I was working together with the developer I could ask the simple question - 'do those statements look like they're anything to do with your job?' He recognised them instantly. Performance tuning always works best when it involves people with application knowledge, not just DBAs. Next I went back to look at the Statspack report for the good day, found those statements and could see that they were performing much more work on the bad day.

Now Statspack hasn't told me why the statement is performing more work, but it very quickly narrowed down what I needed to look at. It turned out that the UPDATE statement wasn't using an index that it had been previously.

Better still, because we save all of our object statistics for the CBO for at least 30 days, we could see which statistics had changed and investigate why Oracle was picking a different execution plan.

I would say this illustrated two benefits of Statspack. First, it's able to narrow your scope in some cases. Second, it's very low cost and quick to use. People had been looking at this problem for a *day*. The entire process of spotting the problem statement took less than 10 minutes and then maybe another 10 minutes narrowing down the change in the statistics that was causing the problem. If it's so quick to use (maybe in experienced hands) there isn't much cost if it turns out to be of no use. i.e. I think it's worth a try. That might not be a very rigorous or scientific statement but I'll do whatever it takes to solve business problems.

(Actually - updated later - the thing it most illustrates is that Statspack can show a change in behaviour after the fact as long as you have it switched on everywhere)

This was on Oracle 9.2.0.7. Had it been on 10g, we would probably have used AWR.