Re: High CPU usage

From: Gerry Miller <gerry_at_millerandbowman.com>
Date: Sat, 16 Jun 2012 15:33:33 +1000
Message-ID: <4FDC1AAD.9000500_at_millerandbowman.com>



 Hi Sriram
I am performing regression tests to determine the impact of the new indexes.

Not sure what you mean by profiling the system calls. I have had level 12 tracing on since I noticed the problem and am capturing output from vmstat, 'ps aux' , 'cat /proc/meminfo', STATSPACK and V$OPEN_CURSOR every 5 minutes.Any other suggestions would be welcome.

If I restart the database it performs well. After one such restart I created the indexes with 3 concurrent processes, two for the biggest tables and one for the rest. The last process completed after 6 hours.

Regards

Gerry

Sriram Kumar wrote: Hi gerry,
curios to know what prompted you to do the drop and recreate test. are you trying to simulate a problem?. did you restart the database between the iterations or how is it?. did you try profiling the system calls for one of the sessions?
best regards
sriram kumar

On Wed, Jun 13, 2012 at 9:40 AM, Gerry Miller <gerry_at_millerandbowman.com[1]> wrote:
 Hi
I am performing regression tests on index creation on Oracle Standard

Edition10.2.0.4 in RHEL 5.3.  The first time I created the 450 indexes it
took 16 hours.  A few days later I dropped them and recreated them and it
took 30 hours.  I did it a third time and it is still running after 50
hours,with only 320 indexes created. I enabled tracing during the second runand have found that the time is virtually all down to CPU usage. Buffer gets are about the same and a resource profile show that CPU accounts for 86% of resource usage and scattered reads 8%. There are no other significant waits and the 16 CPUs on the server are running at around 85% idle all the time, while memory usage is quite high at 97%.

Furthermore, in comparing my regression test results I have found that CPU usage is consistently and significantly higher in one result set than others. For example, consider this one tkprof output:

First Run: call     count       cpu    elapsed       disk      query
current        rows

------- ------ -------- ---------- ---------- ---------- ----------


Parse 1 0.00 0.00 0 0 0  0
Execute 1 0.00 0.00 0 0 0  0
Fetch 5 0.00 0.00 0 55 0 50
------- ------ -------- ---------- ---------- ---------- ----------


total 7 0.00 0.00 0 55 0 50
Second Run: call     count       cpu    elapsed       disk      query
current        rows

------- ------ -------- ---------- ---------- ---------- ----------


Parse 1 0.00 0.00 0 0 0  0
Execute 1 32.74 31.98 0 0 0  0
Fetch 5 0.00 0.00 0 55 0 50
------- ------ -------- ---------- ---------- ---------- ----------


total 7 32.74 31.99 0 55 0 50

This is for the same query, with the same execution plan, no ORDER BY clause and the only waits events are 5 'SQL*Net message to/from client' corresponding to the FETCHes. Why would it take 32 seconds the second time, all down to CPU, when it is doing no sorting or extra buffer gets?

In my test results find hundreds of SQL statements that have the same execution plans and comparable buffer get counts but the CPU time is MUCH higher in one run than the other.

Does anyone have any suggestions as to what might be the cause of this behaviour?

Thanks and Regards

Gerry Miller

--

http://www.freelists.org/webpage/oracle-l[2]

Received on Sat Jun 16 2012 - 00:33:33 CDT

Original text of this message