{"id":1153,"date":"2006-12-01T12:00:00","date_gmt":"2006-12-01T12:00:00","guid":{"rendered":"http:\/\/orcldoug.com\/blog\/?p=1153"},"modified":"2006-12-01T12:00:00","modified_gmt":"2006-12-01T12:00:00","slug":"a-small-statspack-success","status":"publish","type":"post","link":"http:\/\/orcldoug.com\/blog\/2006\/12\/01\/a-small-statspack-success\/","title":{"rendered":"A Small Statspack Success"},"content":{"rendered":"<p>I&#8217;ll warn you up front that this is going to be spectacularly lacking in detail but it&#8217;s a simple and true example from the other week of the kind of thing I find Statspack useful for.<\/p>\n<p>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&#8217;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 (&#8216;Network problems&#8217; indeed!). These days I&#8217;m in the development team so I don&#8217;t <i>do<\/i> production, but I could tell he was fed up so I said I&#8217;d take a <i>quick<\/i> look.<\/p>\n<p>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 &#8211; the day before the problem and the day of the problem. This would be adequate because this feed runs throughout the day.<\/p>\n<p>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&#8217;ll look at the timed event profile at the start of the report and the SQL ordered by gets at the very least.<\/p>\n<p>Here&#8217;s the start of the SQL ordered by gets statement for the good day.<\/p>\n<pre><code><\/code><p>  Buffer Gets    Executions  Gets per Exec  %Total Time (s)  Time (s) Hash Value<br\/>--------------- ------------ -------------- ------ -------- --------- ----------<br\/>     15,480,730          127      121,895.5   28.0   117.44    289.69  169133436<br\/>Module: JDBC Thin Client<br\/>Select teamname AS rs_Team, teammanagername AS rs_TeamManager, S<br\/>tatus AS rs_Status, RESOURCETYPECODE AS rs_ResourceTypeCode, reg<br\/>ioncode AS rs_RegionCode, PayrollNumber AS rs_PayrollNumber, par<br\/>tyid AS rs_PartyId, managercontactnumber AS rs_ManagerContactNum<br\/>ber, ismanager AS rs_IsManager, installername AS rs_Name, idno A<br\/><br\/>      5,311,261        6,914          768.2    9.6   204.55   3533.63 2400602673<br\/>Module: JDBC Thin Client<br\/>Select username AS rs_UserLogin, taskdescription AS rs_TaskDescr<br\/>iption, productname AS rs_ProductName, PortfolioOwnerName AS rs_<br\/>PortfolioOwnerName, PortfolioId AS rs_PortfolioId, partynumber A<br\/>S rs_PartyNumber, partyid AS rs_PartyId, offeringname AS rs_Offe<br\/>ringName, jobid AS rs_JobID, intrctnstatecode AS rs_State, inter<br\/><br\/>      2,484,342          813        3,055.8    4.5    38.95     40.08  425417216<br\/>Module: JDBC Thin Client<br\/>Select SERVICECODE AS rs_ServiceCode, JOBTYPE AS rs_JobType, FMS<br\/>PRODUCTCODE AS rs_FmsProductCode, BUNDLENAME AS rs_BundleName, B<br\/>UNDLEID AS rs_BundleID from V_BSBINSTALLBUNDLEPICKER<\/p><\/pre>\n<p>And this is from the bad day. I&#8217;ve highlighted the two statements that have appeared that weren&#8217;t there before.<\/p>\n<pre><code><\/code><p><\/p><p>  Buffer Gets    Executions  Gets per Exec  %Total Time (s)  Time (s) Hash Value<br\/>--------------- ------------ -------------- ------ -------- --------- ----------<br\/>     10,116,721           84      120,437.2   21.4    73.15     80.26  169133436<br\/>Module: JDBC Thin Client<br\/>Select teamname AS rs_Team, teammanagername AS rs_TeamManager, S<br\/>tatus AS rs_Status, RESOURCETYPECODE AS rs_ResourceTypeCode, reg<br\/>ioncode AS rs_RegionCode, PayrollNumber AS rs_PayrollNumber, par<br\/>tyid AS rs_PartyId, managercontactnumber AS rs_ManagerContactNum<br\/>ber, ismanager AS rs_IsManager, installername AS rs_Name, idno A<br\/><br\/><b>      9,682,739          280       34,581.2   20.5   820.43   1744.27  404442202<br\/>Module: JDBC Thin Client<br\/>BEGIN ISR_SCMS_EXTRACT.ISR_VS_PUT_SCMS_RESULTS(:1); END;<br\/><br\/>      9,678,951           52      186,133.7   20.5   819.86   1733.18 1081636089<br\/>Module: JDBC Thin Client<br\/>UPDATE VS_CONTROL_SUBSCRIBER_IDS SET SCMS_EXTRACT_REQUIRED = 'E'<br\/> WHERE SCMS_EXTRACT_REQUIRED = 'S' AND SCMS_REQUEST_DATE &lt;= SYSD<br\/>ATE - :B1<\/b><br\/>      2,738,922        3,887          704.6    5.8    99.47   1544.92 2400602673<br\/>Module: JDBC Thin Client<br\/>Select username AS rs_UserLogin, taskdescription AS rs_TaskDescr<br\/>iption, productname AS rs_ProductName, PortfolioOwnerName AS rs_<br\/>PortfolioOwnerName, PortfolioId AS rs_PortfolioId, partynumber A<br\/>S rs_PartyNumber, partyid AS rs_PartyId, offeringname AS rs_Offe<br\/>ringName, jobid AS rs_JobID, intrctnstatecode AS rs_State, inter<\/p><\/pre>\n<p>Now, and this is very important, because I was working together with the developer I could ask the simple question &#8211; &#8216;do those statements look like they&#8217;re anything to do with your job?&#8217; 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.<\/p>\n<p>Now Statspack hasn&#8217;t told me <b>why<\/b> 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&#8217;t using an index that it had been previously.<\/p>\n<p>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.<\/p>\n<p>I would say this illustrated two benefits of Statspack. First, it&#8217;s able to narrow your scope <i>in some cases<\/i>. Second, it&#8217;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&#8217;s so quick to use (maybe in experienced hands) there isn&#8217;t much cost if it turns out to be of no use. i.e. I think it&#8217;s worth a try. That might not be a very rigorous or scientific statement but I&#8217;ll do whatever it takes to solve business problems.<\/p>\n<p>(Actually &#8211; updated later &#8211; the thing it most illustrates is that Statspack can show a <i>change<\/i> in behaviour <i>after the fact<\/i> as long as you have it switched on everywhere)<\/p>\n<p>This was on Oracle 9.2.0.7. Had it been on 10g, we would probably have used AWR.<\/p>\n","protected":false},"excerpt":{"rendered":"<p>I&#8217;ll warn you up front that this is going to be spectacularly lacking in detail but it&#8217;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&hellip; <a class=\"more-link\" href=\"http:\/\/orcldoug.com\/blog\/2006\/12\/01\/a-small-statspack-success\/\">Continue reading <span class=\"screen-reader-text\">A Small Statspack Success<\/span><\/a><\/p>\n","protected":false},"author":1,"featured_media":0,"comment_status":"open","ping_status":"closed","sticky":false,"template":"","format":"standard","meta":{"footnotes":""},"categories":[1],"tags":[],"class_list":["post-1153","post","type-post","status-publish","format-standard","hentry","category-uncategorized","entry"],"jetpack_featured_media_url":"","jetpack-related-posts":[{"id":1155,"url":"http:\/\/orcldoug.com\/blog\/2006\/12\/06\/a-more-complex-statspack-example-part-1\/","url_meta":{"origin":1153,"position":0},"title":"A More Complex Statspack Example &#8211; Part 1","date":"December 6, 2006","format":false,"excerpt":"Following on from the last Statspack example, up popped an example at work this week of another common reason I use Statspack - comparing the performance of different environments. It's also a nice illustration of some of Statspack's limitations.Because a Statspack report contains a lot of information and this particular\u2026","rel":"","context":"With 8 comments","img":{"alt_text":"","src":"","width":0,"height":0},"classes":[]},{"id":1159,"url":"http:\/\/orcldoug.com\/blog\/2006\/12\/11\/a-more-complex-statspack-example-summary\/","url_meta":{"origin":1153,"position":1},"title":"A More Complex Statspack Example &#8211; Summary","date":"December 11, 2006","format":false,"excerpt":"Looking back at the three blogs (and hopefully the comments, where others have made some very useful contributions), it's all quite unsatisfactory, isn't it? We haven't solved the problem. All we've proved is that the tests aren't equivalent, although I think there's value in that negative result because I was\u2026","rel":"","context":"With 3 comments","img":{"alt_text":"","src":"","width":0,"height":0},"classes":[]},{"id":1428,"url":"http:\/\/orcldoug.com\/blog\/2008\/08\/14\/time-matters-an-infinite-capacity-for-waiting\/","url_meta":{"origin":1153,"position":2},"title":"Time Matters &#8211; An Infinite Capacity for Waiting*","date":"August 14, 2008","format":false,"excerpt":"When I was teaching the 10g Performance class at my last customer site, I remarked that the total number of seconds you see in the \"Top 5 Timed Events\" section of a Statspack or AWR report will often be greater than the total number of seconds between the snapshot intervals.\u2026","rel":"","context":"With 6 comments","img":{"alt_text":"","src":"","width":0,"height":0},"classes":[]},{"id":1156,"url":"http:\/\/orcldoug.com\/blog\/2006\/12\/07\/a-more-complex-statspack-example-part-2\/","url_meta":{"origin":1153,"position":3},"title":"A More Complex Statspack Example &#8211; Part 2","date":"December 7, 2006","format":false,"excerpt":"So far we're barely into the comparison of the Statspack reports from the two different test environments and they look quite different already.Next up, the Instance Efficiency Percentages. I have to confess that I rarely find these very useful because the numbers are always near 100% on most databases I\u2026","rel":"","context":"With 13 comments","img":{"alt_text":"","src":"","width":0,"height":0},"classes":[]},{"id":1050,"url":"http:\/\/orcldoug.com\/blog\/2006\/08\/10\/historical-perspective-part-2\/","url_meta":{"origin":1153,"position":4},"title":"Historical Perspective (Part 2)","date":"August 10, 2006","format":false,"excerpt":"Let's look at items 2 and 3 from the list in my previous blog1) You know you have a performance problem and can re-create it by running a specific part of the application, be it a user interaction or batch job.2) You have an intermittent but recurring performance problem which\u2026","rel":"","context":"Similar post","img":{"alt_text":"","src":"","width":0,"height":0},"classes":[]},{"id":1719,"url":"http:\/\/orcldoug.com\/blog\/2014\/07\/24\/recurring-conversations-awr-intervals-part-2\/","url_meta":{"origin":1153,"position":5},"title":"Recurring Conversations: AWR Intervals (Part 2)","date":"July 24, 2014","format":false,"excerpt":"(Reminder, just in case we still need it, that the use of features in this post require Diagnostics Pack license.) Damn me for taking so long to write blog posts these days. By the time I get around to them, certain very knowledgeable people have commented on part 1 and\u2026","rel":"","context":"Similar post","img":{"alt_text":"","src":"","width":0,"height":0},"classes":[]}],"_links":{"self":[{"href":"http:\/\/orcldoug.com\/blog\/wp-json\/wp\/v2\/posts\/1153","targetHints":{"allow":["GET"]}}],"collection":[{"href":"http:\/\/orcldoug.com\/blog\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"http:\/\/orcldoug.com\/blog\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"http:\/\/orcldoug.com\/blog\/wp-json\/wp\/v2\/users\/1"}],"replies":[{"embeddable":true,"href":"http:\/\/orcldoug.com\/blog\/wp-json\/wp\/v2\/comments?post=1153"}],"version-history":[{"count":0,"href":"http:\/\/orcldoug.com\/blog\/wp-json\/wp\/v2\/posts\/1153\/revisions"}],"wp:attachment":[{"href":"http:\/\/orcldoug.com\/blog\/wp-json\/wp\/v2\/media?parent=1153"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"http:\/\/orcldoug.com\/blog\/wp-json\/wp\/v2\/categories?post=1153"},{"taxonomy":"post_tag","embeddable":true,"href":"http:\/\/orcldoug.com\/blog\/wp-json\/wp\/v2\/tags?post=1153"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}