{"id":1432,"date":"2008-09-01T12:00:00","date_gmt":"2008-09-01T12:00:00","guid":{"rendered":"http:\/\/orcldoug.com\/blog\/?p=1432"},"modified":"2008-09-01T12:00:00","modified_gmt":"2008-09-01T12:00:00","slug":"time-matters-db-cpu","status":"publish","type":"post","link":"http:\/\/orcldoug.com\/blog\/2008\/09\/01\/time-matters-db-cpu\/","title":{"rendered":"Time Matters – DB CPU"},"content":{"rendered":"

In his comment<\/a> on the last post, John Beresniewicz mentioned the following property of DB CPU :-<\/p>\n

“… ‘DB time’
\nfully contains ‘DB CPU’ and both are measured values (which means
\nin particular that ‘DB CPU’ is not inflated by runq time)<\/em>“<\/p>\n

I’d like to talk about the end of that sentence in particular. About a year and a half ago, I wrote a paper<\/a> (that’s a PDF link) about building response time profiles for sessions that use Parallel Execution. One of the problems I highlighted in that paper was that PX jobs are prone to overload the available CPU resources simply because of the number of PX slave processes that are running concurrently. It’s mentioned first in the section on “More Lost Time<\/em>” on page 4 but most of the rest of the paper goes on to discuss this particular problem. I wasn’t very successful coming up with any solutions beyond my usual approach of combining Oracle and O\/S tools.<\/p>\n

Essentially, as the queue of runnable processes that are waiting to execute on a CPU grows (I’ll just refer to it as the run queue from now on), the Oracle server connection processes appear to lose time because they’re unable to get on to a CPU in order to record the end time of an event. In the Response Time profilers I’ve seen, this time is recorded as unaccounted-for and it’s what JB’s referring to when he talks about runq time. Actually, time spent in the run queue is not the only cause of unaccounted-for time but it’s the one I’ll focus on here. (Here’s another plug for Cary and Jeff’s book<\/a> – other reasons are discussed in chapter 7 on Oracle Kernel Timings.)<\/p>\n

As JB stated, DB CPU does not<\/em> include this time spent waiting in the run queue but the ASH<\/a> samples for the session are aware that the server connection process is on the CPU or<\/em> in the run queue. As a consequence, you can see apparently contradictory graphs in the various OEM (DB Control or Grid Control) Performance pages. Although I’ve tried this with the PX tests and confirmed the same behaviour, I’m going to use Swingbench<\/a> for the examples here to continue the approach so far and so that you can try them out yourself if you want. (I might post PX examples later.)<\/p>\n

Swingbench is supplied with several example applications, one of which is the Sales History (SH) application which uses the SH example schema supplied with recent versions of Oracle. The key attribute of this test for my purpose is that it’s read only and CPU intensive, so that the limited I\/O bandwidth on a home PC isn’t the bottleneck.<\/p>\n

I ran 8 concurrent sessions of the SH application for a total duration of 5 minutes with no delay between transactions, which was pretty unrealistic but I was only interested in over-loading the single dual-core CPU in the PC. Soon after the test started, this was how the database instance’s home page looked.<\/p>\n

\"\"<\/p>\n

CPU is at 100% and there are about 7 sessions active in the database on average, just under 2 of which are running on the CPU, while the rest are waiting. That looks about right. Now, if we look at the performance page at the end of the test, the results are quite different.<\/p>\n

\"\"<\/p>\n

It looks like there were only ever about 2 sessions active on average! However, there are a couple of hints as to what’s going on. If we look at the graph above as well as the Average Active Sessions graph, we can see that the Host’s run queue is far in excess of the two available CPU cores.<\/p>\n

\"\"<\/p>\n

Things become even more interesting if we look at the Top Activity screen for the same period.<\/p>\n

\"\"<\/p>\n

In that view, the sessions waiting in the run queue are<\/span> shown, so there’s an average of about 7 active sessions during the test. Take a good look at the difference in the key text for the two graphs as well. The Average Active Sessions graph on the Performance Home page shows ‘CPU Used’, whereas the Top Activity page shows ‘CPU’. It’s a small but significant and appropriate difference. The first graph shows you the average number of sessions that are actually using CPU and is related to DB CPU in the Time Model Stats, but the Top Activity screen is really showing ‘CPU + Wait for CPU’, which is the event you’ll see throughout an ASH report covering the same period. e.g.<\/p>\n

Top Sessions<\/p>\n