excessive db block gets and cpu usage
- From: krishna sarabu <ksarabu@xxxxxxxxx>
- To: oracle-l@xxxxxxxxxxxxx
- Date: Tue, 28 Jul 2009 06:20:32 -0700 (PDT)
Hi,
The database version is 10.2.0.3.
I have started noticing excessive db block gets for frequent ddls and/or txn
commits and that was causing CPU spike.
A simple test case, to truncate empty table in 100 iterations caused 2 million
db block gets and the 10046 trace trace revealed nothing. It's just burning
CPU, and no waits. I've turned-off "_dml_monitoring_enabled"=false and that did
not help. fyi, attaching below the 10046 trace (taken when
"_dml_monitoring_enabled" was set to default "true").
Not sure if we have any internal event to help tracing current reads. Can
anyone please help me to identify the root cause?
Thanks in advance.
********************************************************************************
truncate table testme
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 100 0.04 0.06 0 0 0 0
Execute 100 43.16 43.56 31 6436 2177931 0
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 200 43.20 43.63 31 6436 2177931 0
Misses in library cache during parse: 100
Optimizer mode: ALL_ROWS
Parsing user id: 160 (recursive depth: 1)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
db file sequential read 6 0.00 0.01
reliable message 1 0.00 0.00
enq: RO - fast object reuse 1 0.00 0.00
local write wait 3 0.00 0.00
log file sync 13 0.04 0.11
rdbms ipc reply 112 0.07 0.21
********************************************************************************
update sys.mon_mods$ set inserts = inserts + :ins, updates = updates + :upd,
deletes = deletes + :del, flags = (decode(bitand(flags, :flag), :flag,
flags, flags + :flag)), drop_segments = drop_segments + :dropseg, timestamp
= :time
where
obj# = :objn
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 100 0.01 0.00 0 0 0 0
Execute 100 35.90 35.25 0 607 1979473 100
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 200 35.91 35.26 0 607 1979473 100
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: CHOOSE
Parsing user id: SYS (recursive depth: 2)
Rows Row Source Operation
------- ---------------------------------------------------
1 UPDATE MON_MODS$ (cr=1 pr=0 pw=0 time=417 us)
1 INDEX UNIQUE SCAN I_MON_MODS$_OBJ (cr=1 pr=0 pw=0 time=13 us)(object
id 483)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
rdbms ipc reply 110 0.01 0.13
********************************************************************************
begin
for i in 1..100 loop
execute immediate 'truncate table testme';
end loop;
end;
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.04 0.02 0 0 0 1
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.04 0.03 0 0 0 1
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 160
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 2 0.00 0.00
SQL*Net message from client 2 0.00 0.00
*****************************************************************************
Rgds,
Krishna
--
//www.freelists.org/webpage/oracle-l
Other related posts:
