{"id":1612,"date":"2010-09-12T12:00:00","date_gmt":"2010-09-12T12:00:00","guid":{"rendered":"http:\/\/orcldoug.com\/blog\/?p=1612"},"modified":"2010-09-12T12:00:00","modified_gmt":"2010-09-12T12:00:00","slug":"that-pictures-demo-in-full","status":"publish","type":"post","link":"http:\/\/orcldoug.com\/blog\/2010\/09\/12\/that-pictures-demo-in-full\/","title":{"rendered":"That Pictures demo in full"},"content":{"rendered":"<p><em>Note &#8211; features in this post require the Diagnostics Pack license<\/p>\n<p><\/em>With so many potential technical posts in my pile, it was initially difficult to decide where to start again but I figured I should avoid the stats series until I&#8217;m back into the swing of things &#128521; Instead I decided to fulfill a commitment I made to myself (and others, whether they knew about it or not) almost three months ago.<\/p>\n<p>When I gave <a href=\"http:\/\/18.133.199.212\/?p=1607\">the evening demo session in the Amis offices<\/a> I think the 2 hours went pretty well but, as usual with the OEM presentations, I got a little carried away and didn&#8217;t conclude the demo properly. (This is also the demo I *would* have done at Hotsos last year if the damn thing had worked first time &#128521;) It was a shame because as well as showing the neat and useful side of OEM Performance Pages, it also illustrates one of the common pitfalls in interpreting what the graphs are showing you.<\/p>\n<p>I began by running a 4 concurrent user Sales Order Entry (SOE) test using <a href=\"http:\/\/dominicgiles.com\/swingbench.html\">Dominic Giles&#8217; Swingbench utility<\/a>. I won&#8217;t got into the details of the SOE test because I don&#8217;t think it&#8217;s particularly relevant here but you can always download and\/or read about Swingbench for yourself at Dominics website.<\/p>\n<p>I ran the test for a fixed period of 5 minutes using no think-time delay.<\/p>\n<p><!-- s9ymdb:303 --><!-- s9ymdb:307 --><img loading=\"lazy\" decoding=\"async\" alt=\"\" class=\"serendipity_image_center\" height=\"425\" src=\"https:\/\/i0.wp.com\/18.133.199.212\/wp-content\/uploads\/recovered\/pic_demo8.png?resize=250%2C425\" width=\"250\" data-recalc-dims=\"1\" \/><\/p>\n<p>Using the capability to look at ASH data in the recent past, the OEM Top Activity page looks like this.<\/p>\n<p><!-- s9ymdb:308 --><img loading=\"lazy\" decoding=\"async\" alt=\"\" class=\"serendipity_image_center\" height=\"640\" src=\"https:\/\/i0.wp.com\/18.133.199.212\/wp-content\/uploads\/recovered\/pic_demo9.png?resize=640%2C640\" width=\"640\" data-recalc-dims=\"1\" \/><\/p>\n<p>&#8211; There was a fairly consistent average of 4-5 active sessions over the 5 minutes period and, looking at the Top Sessions panel in the bottom right of the screen, these were four SOE sessions of similar activity levels and the LGWR process. <\/p>\n<p>&#8211; The majority of time was spent on User I\/O, System I\/O and Commit Wait Class activity, with a little CPU.<\/p>\n<p>&#8211; Three PL\/SQL blocks were responsible for most of the Commit activity.<\/p>\n<p>&#8211; The LGWR process was responsible for most of the System I\/O activity.<\/p>\n<p>I&#8217;ll leave it there for now and won&#8217;t drill down into any more detail. <\/p>\n<p>In terms of optimising the performance of this test, what might I consider doing? <\/p>\n<p>The most important aspect is to optimise the application to reduce the resource consumption to the minimum required to achieve our objectives. There&#8217;s a whole bunch of User I\/O activity that could perhaps be eliminated? But I&#8217;m going to ask you to accept the big assumption here that this application has been optimised and that I&#8217;m just using a Swingbench test as an illustration of the type of system-wide problem you could see. In that case, my eye is drawn to the Commit activity.<\/p>\n<p>When I&#8217;m teaching this stuff, I&#8217;m usually deliberately simplistic (at least at the end of the process) and highlight that what I&#8217;m interested in &#8216;tuning&#8217; is whatever most sessions are waiting on according to the ASH samples this screen uses. I used to explain how I&#8217;d look for the biggest areas of colour, drill down into those and identify what&#8217;s going on. Sadly, I later heard that someone (I think it was JB at Oracle*) had already come up with a nifty acronym for this &#8211; COBS. Click on the Big Stuff! One day I will come up with a nifty acronym for something too, but you shouldn&#8217;t hold your breath waiting.<\/p>\n<p>So, if I click on the big stuff here, I can see that the Commit Class waits are log file sync. <\/p>\n<p><!-- s9ymdb:309 --><img loading=\"lazy\" decoding=\"async\" alt=\"\" class=\"serendipity_image_center\" height=\"640\" src=\"https:\/\/i0.wp.com\/18.133.199.212\/wp-content\/uploads\/recovered\/pic_demo10.png?resize=640%2C640\" width=\"640\" data-recalc-dims=\"1\" \/><\/p>\n<p>How might I reduce the time that sessions are waiting for log file sync? Here are a few reasons why the test sessions might be waiting on log file sync more often or for longer than I&#8217;d like. <\/p>\n<p>&#8211; Application design &#8211; committing too frequently<br \/>&#8211; CPU starvation<br \/>&#8211; Slow I\/O to online redo log files<\/p>\n<p>Whether waits are predominantly the result of CPU overload or slow I\/O can be determined by looking at the underlying log file parallel write wait times on the LGWR process but that&#8217;s a bigger subject for another time.<\/p>\n<p>You can look into all of these in more depth &#8211; and should &#8211; but as this is designed to be a fun demo of the pretty pictures (it used to be &#8216;the USB stick demo&#8217;), I&#8217;ll simply try to eliminate that activity and re-run the same test. Here&#8217;s how Top Activity looks now.<\/p>\n<p><!-- s9ymdb:310 --><img loading=\"lazy\" decoding=\"async\" alt=\"\" class=\"serendipity_image_center\" height=\"640\" src=\"https:\/\/i0.wp.com\/18.133.199.212\/wp-content\/uploads\/recovered\/pic_demo11.png?resize=640%2C640\" width=\"640\" data-recalc-dims=\"1\" \/><\/p>\n<p>Oh. Maybe that wasn&#8217;t what you expected? OK, the LGWR activity has disappeared, but it seems the system is almost as busy as it was before but that the main bottleneck is now User I\/O activity. That&#8217;s often the way, though &#8211; you eliminate one bottleneck in a system and it just shows up somewhere else. It must be good to get rid of log file sync waits though, right? User I\/O seems like more productive work and I&#8217;ve managed to make the LGWR activity disappear completely. <\/p>\n<p>But then if you were to look at this graph in terms of <a href=\"http:\/\/www.oracle.com\/technetwork\/database\/features\/manageability\/diag-techniques-presentation-ow07-128491.pdf\">Average Active Sessions or DB Time<\/a> or (as it&#8217;s more likely to be expressed) how big that spike looks, the two tests would look similarly busy from a system-wide perspective. They were but the real question is &#8211; busy doing *what*? There&#8217;s some important information missing here and Swingbench is able to provide it. <\/p>\n<p><!-- s9ymdb:311 --><img loading=\"lazy\" decoding=\"async\" alt=\"\" class=\"serendipity_image_center\" height=\"273\" src=\"https:\/\/i0.wp.com\/18.133.199.212\/wp-content\/uploads\/recovered\/pic_demo12.png?resize=413%2C273\" width=\"413\" data-recalc-dims=\"1\" \/><\/p>\n<p>TotalCompletedTransactions 22,868<\/p>\n<p>Mmmm, so I wonder what that value was for the first run?<\/p>\n<p><!-- s9ymdb:312 --><img loading=\"lazy\" decoding=\"async\" alt=\"\" class=\"serendipity_image_center\" height=\"274\" src=\"https:\/\/i0.wp.com\/18.133.199.212\/wp-content\/uploads\/recovered\/pic_demo13.png?resize=410%2C274\" width=\"410\" data-recalc-dims=\"1\" \/><\/p>\n<p>TotalCompletedTransactions 12,232<\/p>\n<p>Woo-hoo! *That&#8217;s* what I call tuning a benchmark &#8211; processing almost twice the number of transactions in the same 5 minute period.<\/p>\n<p>So it turns out that the sessions in the database *were* just as busy during the second run (not too surprising seeing as the test has no user think time so keeps hammering the database with as many requests as it can handle) but that they were busy doing the more productive work of reading and processing data rather than just waiting for COMMITs to complete.<\/p>\n<p>I raised this issue of DB Time not showing activity details with Graham Wood* at Oracle in relation to a previous blog post. I think he made the point to me that that&#8217;s why the OEM Performance Home Page is *not* the Top Activity page. If I take a look at that home page, it shows me the same information as the Swingbench results output did, albeit not as clearly<\/p>\n<p><!-- s9ymdb:313 --><img loading=\"lazy\" decoding=\"async\" alt=\"\" class=\"serendipity_image_center\" height=\"300\" src=\"https:\/\/i0.wp.com\/18.133.199.212\/wp-content\/uploads\/recovered\/pic_demo14.png?resize=640%2C300\" width=\"640\" data-recalc-dims=\"1\" \/><\/p>\n<p>Looking at the Throughput graph, I can see that the second test processesd around double the number of Transactions per second for the same test running on the same system.<\/p>\n<p>To wrap up (and be a little defensive) &#8230;<\/p>\n<p>&#8211; Yes, I could have traced one or more sessions and generated a complete and detailed response time profile that should have lead me to the same conclusion.<\/p>\n<p>&#8211; Yes, as this is a controlled test environment and I&#8217;m the only &#8216;user&#8217;, AWR\/Statspack would have been an even more powerful analysis tool in the right hands.<\/p>\n<p>&#8211; The Top Activity page is not the most appropriate tool for this job but it is handy for illustrating concepts. <\/p>\n<p>&#8211; Lest I seem a slavish pictures fan, I&#8217;m showing how people might misuse or misundersand ASH\/Top Activity. In this case, the Home Performance Page is a much better tool because we&#8217;re looking at system-wide data and not drilling into session or SQL details.<\/p>\n<p>Oh, and what is my Top Secret Magic Silver Bullet Tuning Tip for OLTP-type applications? (only to be used by Advanced Oracle Performance Wizards)<\/p>\n<pre>alter system set commit_write='BATCH, NOWAIT';<\/pre>\n<p>Done! In fact, why not just use this on all of your systems, just in case people are waiting on log file sync?<\/p>\n<p>(Leaves space below for angry responses and my withering humorous retorts)<\/p>\n<p>* This is not name-dropping, this is giving due credit to the people who really know what they&#8217;re talking about<\/p>\n","protected":false},"excerpt":{"rendered":"<p>Note &#8211; features in this post require the Diagnostics Pack license With so many potential technical posts in my pile, it was initially difficult to decide where to start again but I figured I should avoid the stats series until I&#8217;m back into the swing of things &#128521; Instead I decided to fulfill a commitment&hellip; <a class=\"more-link\" href=\"http:\/\/orcldoug.com\/blog\/2010\/09\/12\/that-pictures-demo-in-full\/\">Continue reading <span class=\"screen-reader-text\">That Pictures demo in full<\/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-1612","post","type-post","status-publish","format-standard","hentry","category-uncategorized","entry"],"jetpack_featured_media_url":"","jetpack-related-posts":[{"id":1029,"url":"http:\/\/orcldoug.com\/blog\/2006\/07\/21\/steve-cain-rip\/","url_meta":{"origin":1612,"position":0},"title":"Steve Cain RIP","date":"July 21, 2006","format":false,"excerpt":"Yesterday I received the sad news that Steve Cain died from cancer.I worked with Steve at Imagine Software for a while and hung around him for a few years more. In some ways, he was one of a number of surrogate big brothers I picked up, because most of them\u2026","rel":"","context":"With 5 comments","img":{"alt_text":"","src":"","width":0,"height":0},"classes":[]},{"id":922,"url":"http:\/\/orcldoug.com\/blog\/2005\/10\/31\/ukoug-2005-day-1\/","url_meta":{"origin":1612,"position":1},"title":"UKOUG 2005 &#8211; Day 1","date":"October 31, 2005","format":false,"excerpt":"Well, after a power cut in Central Birmingham that delayed the start of the conference by about an hour, things are moving along nicely. The presentations that I've attended so far are :-Tom Kyte's SQL techniques. As excellent as I expected and I preferred Tom's presentation technique to last years\u2026","rel":"","context":"Similar post","img":{"alt_text":"","src":"","width":0,"height":0},"classes":[]},{"id":1406,"url":"http:\/\/orcldoug.com\/blog\/2008\/04\/27\/upcoming-events\/","url_meta":{"origin":1612,"position":2},"title":"Upcoming Events","date":"April 27, 2008","format":false,"excerpt":"I'll be presenting at a few events in the next couple of months.30th April - OUG Scotland DBA SIG Meeting.This one is the easiest for me to travel to, being just on the out-skirts of Edinburgh, and is always a well-organised event with a decent agenda, thanks to the local\u2026","rel":"","context":"Similar post","img":{"alt_text":"","src":"","width":0,"height":0},"classes":[]},{"id":1587,"url":"http:\/\/orcldoug.com\/blog\/2010\/03\/16\/hotsos-2010-summary\/","url_meta":{"origin":1612,"position":3},"title":"Hotsos 2010 &#8211; Summary","date":"March 16, 2010","format":false,"excerpt":"[One thing that's great about jet-lag is that it allows you to catch up on blogging and all the email that's built up while you've been away at the conference. Not much else you can do at 2:30 in the morning.]I'm glad I went to the Hotsos Symposium again this\u2026","rel":"","context":"Similar post","img":{"alt_text":"","src":"","width":0,"height":0},"classes":[]},{"id":1607,"url":"http:\/\/orcldoug.com\/blog\/2010\/06\/23\/a-good-weekend\/","url_meta":{"origin":1612,"position":4},"title":"A Good Weekend","date":"June 23, 2010","format":false,"excerpt":"OK, so it's more personal stuff but I had an excellent end to last weekend so I don't care \ud83d\ude09 Skip over this one if you don't care what's going on in my life. That's cool.I finished work on Thursday lunchtime and then made what seemed a ridiculously long 'short'\u2026","rel":"","context":"With 2 comments","img":{"alt_text":"More Cuddly Toys","src":"https:\/\/i0.wp.com\/18.133.199.212\/wp-content\/uploads\/recovered\/amis_cuddly.jpg?resize=350%2C200","width":350,"height":200},"classes":[]},{"id":1487,"url":"http:\/\/orcldoug.com\/blog\/2009\/04\/20\/diagnosing-locking-problems-using-ash-part-6\/","url_meta":{"origin":1612,"position":5},"title":"Diagnosing Locking Problems using ASH \u2013 Part 6","date":"April 20, 2009","format":false,"excerpt":"\"Toto, I've a feeling we're not in Kansas any more.\"What started as a simple write-up of a course demo gone wrong (or right, depending the way you look at these things) has grown arms and legs and staggered away from the original intention to talk about ASH. so I thought\u2026","rel":"","context":"With 1 comment","img":{"alt_text":"","src":"","width":0,"height":0},"classes":[]}],"_links":{"self":[{"href":"http:\/\/orcldoug.com\/blog\/wp-json\/wp\/v2\/posts\/1612","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=1612"}],"version-history":[{"count":0,"href":"http:\/\/orcldoug.com\/blog\/wp-json\/wp\/v2\/posts\/1612\/revisions"}],"wp:attachment":[{"href":"http:\/\/orcldoug.com\/blog\/wp-json\/wp\/v2\/media?parent=1612"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"http:\/\/orcldoug.com\/blog\/wp-json\/wp\/v2\/categories?post=1612"},{"taxonomy":"post_tag","embeddable":true,"href":"http:\/\/orcldoug.com\/blog\/wp-json\/wp\/v2\/tags?post=1612"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}