Dear Lister:
I'm using one of Steve Adams's scripts to break down
the components of foreground response time.
I found the pmon timer is taking about 63.59% out of other components.
Although some of the tuning documents suggesting ignore this event but
it still took a lots of time.
Any thoughts ?
Thanks
--Kevin
SQL> @response_time_breakdown.sql
MAJOR MINOR WAIT_EVENT SECONDS
PCT
-------- ------------- ---------------------------------------- ------------
------
CPU time parsing n/a 304
.00%
reloads n/a 600
.00%
execution n/a 153134
.00%
disk I/O normal I/O db file sequential read 5582765477
21.15%
full scans db file scattered read 352191089
1.33%
direct I/O direct path read 528732282
2.00%
direct path write 14689646
.06%
direct path write (lob) 7054
.00%
other I/O db file parallel read 6502322
.02%
control file parallel write 2702081
.01%
MAJOR MINOR WAIT_EVENT SECONDS
PCT
-------- ------------- ---------------------------------------- ------------
------
disk I/O other I/O control file single write 2354364
.01%
control file sequential read 2279481
.01%
db file single write 226882
.00%
log file sequential read 143206
.00%
control file heartbeat 40064
.00%
waits DBWn writes rdbms ipc reply 1398034
.01%
free buffer waits 797265
.00%
write complete waits 50271
.00%
local write wait 2587
.00%
LGWR writes log buffer space 10779368
.04%
MAJOR MINOR WAIT_EVENT SECONDS
PCT
-------- ------------- ---------------------------------------- ------------
------
waits LGWR writes log file switch completion 1383243
.01%
enqueue locks enqueue 5205620
.02%
other locks PX Deq Credit: send blkd 126584654
.48%
PX Deq Credit: need buffer 22686486
.09%
PX qref latch 6746743
.03%
buffer busy waits 3070154
.01%
latch free 738973
.00%
library cache pin 19493
.00%
undo segment extension 988
.00%
library cache lock 301
.00%
library cache load lock 100
.00%
MAJOR MINOR WAIT_EVENT SECONDS
PCT
-------- ------------- ---------------------------------------- ------------
------
waits other locks buffer deadlock 1
.00%
latency commits log file sync 7397468
.03%
network SQL*Net more data to client 22293948
.08%
SQL*Net more data from client 5173274
.02%
SQL*Net message to client 340244
.00%
SQL*Net break/reset to client 8152
.00%
SQL*Net more data to dblink 23
.00%
SQL*Net message to dblink 23
.00%
process ctl process startup 108286
.00%
PX Deq: Signal ACK 100629
.00%
MAJOR MINOR WAIT_EVENT SECONDS
PCT
-------- ------------- ---------------------------------------- ------------
------
latency process ctl PX Deq: Join ACK 6684
.00%
PX Deq: Msg Fragment 1002
.00%
global locks wait for a undo record 9470
.00%
misc pmon timer 16780800644
63.59%
async disk IO 1981734344
7.51%
jobq slave wait 919593160
3.48%
switch logfile command 29456
.00%
refresh controlfile command 44
.00%
reliable message 28
.00%
instance state change 2
.00%
============================================================================
=======
----------------------------------------------------------------------------
---
--
-- Script: response_time_breakdown.sql
-- Purpose: to report the components of foreground response time in % terms
-- For: 8.1.6
--
-- Copyright: (c) Ixora Pty Ltd
-- Author: Steve Adams
--
----------------------------------------------------------------------------
---
@save_sqlplus_settings
column major format a8
column minor format a13
column wait_event format a40 trunc
column seconds format 9999999
column pct format a6 justify right
break on major skip 1 on minor
select
substr(n_major, 3) major,
substr(n_minor, 3) minor,
wait_event,
round(time/100) seconds,
substr(to_char(100 * ratio_to_report(time) over (), '99.00'), 2) || '%'
pct
from
(
select /*+ ordered use_hash(b) */
'1 CPU time' n_major,
decode(t.ksusdnam,
'redo size', '2 reloads',
'parse time cpu', '1 parsing',
'3 execution'
) n_minor,
'n/a' wait_event,
decode(t.ksusdnam,
'redo size', nvl(r.time, 0),
'parse time cpu', t.ksusgstv - nvl(b.time, 0),
t.ksusgstv - nvl(b.time, 0) - nvl(r.time, 0)
) time
from
sys.x_$ksusgsta t,
(
select /*+ ordered use_nl(s) */ -- star query: few rows from d and b
s.ksusestn, -- statistic#
sum(s.ksusestv) time -- time used by backgrounds
from
sys.x_$ksusd d, -- statname
sys.x_$ksuse b, -- session
sys.x_$ksbdp p, -- background process
sys.x_$ksusesta s -- sesstat
where
d.ksusdnam in (
'parse time cpu',
'CPU used when call started') and
b.ksspaown = p.ksbdppro and
s.ksusestn = d.indx and
s.indx = b.indx
group by
s.ksusestn
) b,
(
select /*+ no_merge */
ksusgstv * -- parse cpu time *
kglstrld / -- SQL AREA reloads /
greatest(1, kglstget - kglstght) -- SQL AREA misses
time
from
sys.x_$kglst k,
sys.x_$ksusgsta g
where
k.indx = 0 and
g.ksusdnam = 'parse time cpu'
) r
where
t.ksusdnam in (
'redo size', -- arbitrary: to get a row to replace
'parse time cpu', -- with the 'reload cpu time'
'CPU used when call started') and
b.ksusestn (+) = t.indx
union all
select
decode(n_minor,
'1 normal I/O', '2 disk I/O',
'2 full scans', '2 disk I/O',
'3 direct I/O', '2 disk I/O',
'4 BFILE reads', '2 disk I/O',
'5 other I/O', '2 disk I/O',
'1 DBWn writes', '3 waits',
'2 LGWR writes', '3 waits',
'3 ARCn writes', '3 waits',
'4 enqueue locks', '3 waits',
'5 PCM locks', '3 waits',
'6 other locks', '3 waits',
'1 commits', '4 latency',
'2 network', '4 latency',
'3 file ops', '4 latency',
'4 process ctl', '4 latency',
'5 global locks', '4 latency',
'6 misc', '4 latency'
) n_major,
n_minor,
wait_event,
time
from
(
select /*+ ordered use_hash(b) use_nl(d) */
decode(
d.kslednam,
-- disk I/O
'db file sequential read', '1 normal I/O',
'db file scattered read', '2 full scans',
'BFILE read', '4 BFILE reads',
'KOLF: Register LFI read', '4 BFILE reads',
'log file sequential read', '5 other I/O',
'log file single write', '5 other I/O',
-- resource waits
'checkpoint completed', '1 DBWn writes',
'free buffer waits', '1 DBWn writes',
'write complete waits', '1 DBWn writes',
'local write wait', '1 DBWn writes',
'log file switch (checkpoint incomplete)', '1 DBWn writes',
'rdbms ipc reply', '1 DBWn writes',
'log file switch (archiving needed)', '3 ARCn writes',
'enqueue', '4 enqueue locks',
'buffer busy due to global cache', '5 PCM locks',
'global cache cr request', '5 PCM locks',
'global cache lock cleanup', '5 PCM locks',
'global cache lock null to s', '5 PCM locks',
'global cache lock null to x', '5 PCM locks',
'global cache lock s to x', '5 PCM locks',
'lock element cleanup', '5 PCM locks',
'checkpoint range buffer not saved', '6 other locks',
'dupl. cluster key', '6 other locks',
'PX Deq Credit: free buffer', '6 other locks',
'PX Deq Credit: need buffer', '6 other locks',
'PX Deq Credit: send blkd', '6 other locks',
'PX qref latch', '6 other locks',
'Wait for credit - free buffer', '6 other locks',
'Wait for credit - need buffer to send', '6 other locks',
'Wait for credit - send blocked', '6 other locks',
'global cache freelist wait', '6 other locks',
'global cache lock busy', '6 other locks',
'index block split', '6 other locks',
'lock element waits', '6 other locks',
'parallel query qref latch', '6 other locks',
'pipe put', '6 other locks',
'rdbms ipc message block', '6 other locks',
'row cache lock', '6 other locks',
'sort segment request', '6 other locks',
'transaction', '6 other locks',
'unbound tx', '6 other locks',
-- routine waits
'log file sync', '1 commits',
'name-service call wait', '2 network',
'Test if message present', '4 process ctl',
'process startup', '4 process ctl',
'read SCN lock', '5 global locks',
decode(substr(d.kslednam, 1, instr(d.kslednam, ' ')),
-- disk I/O
'direct ', '3 direct I/O',
'control ', '5 other I/O',
'db ', '5 other I/O',
-- resource waits
'log ', '2 LGWR writes',
'buffer ', '6 other locks',
'free ', '6 other locks',
'latch ', '6 other locks',
'library ', '6 other locks',
'undo ', '6 other locks',
-- routine waits
'SQL*Net ', '2 network',
'BFILE ', '3 file ops',
'KOLF: ', '3 file ops',
'file ', '3 file ops',
'KXFQ: ', '4 process ctl',
'KXFX: ', '4 process ctl',
'PX ', '4 process ctl',
'Wait ', '4 process ctl',
'inactive ', '4 process ctl',
'multiple ', '4 process ctl',
'parallel ', '4 process ctl',
'DFS ', '5 global locks',
'batched ', '5 global locks',
'on-going ', '5 global locks',
'global ', '5 global locks',
'wait ', '5 global locks',
'writes ', '5 global locks',
'6 misc'
)
) n_minor,
d.kslednam wait_event, -- event name
i.kslestim - nvl(b.time, 0) time -- non-background time
from
sys.x_$kslei i, -- system events
(
select /*+ ordered use_hash(e) */ -- no fixed index on e
e.kslesenm, -- event number
sum(e.kslestim) time -- time waited by backgrounds
from
sys.x_$ksuse s, -- sessions
sys.x_$ksbdp b, -- backgrounds
sys.x_$ksles e -- session events
where
s.ksspaown = b.ksbdppro and -- background session
e.kslessid = s.indx
group by
e.kslesenm
having
sum(e.kslestim) > 0
) b,
sys.x_$ksled d
where
i.kslestim > 0 and
b.kslesenm (+) = i.indx and
nvl(b.time, 0) < i.kslestim and
d.indx = i.indx and
d.kslednam not in (
'Null event',
'KXFQ: Dequeue Range Keys - Slave',
'KXFQ: Dequeuing samples',
'KXFQ: kxfqdeq - dequeue from specific qref',
'KXFQ: kxfqdeq - normal deqeue',
'KXFX: Execution Message Dequeue - Slave',
'KXFX: Parse Reply Dequeue - Query Coord',
'KXFX: Reply Message Dequeue - Query Coord',
'PAR RECOV : Dequeue msg - Slave',
'PAR RECOV : Wait for reply - Query Coord',
'Parallel Query Idle Wait - Slaves',
'PL/SQL lock timer',
'PX Deq: Execute Reply',
'PX Deq: Execution Msg',
'PX Deq: Index Merge Execute',
'PX Deq: Index Merge Reply',
'PX Deq: Par Recov Change Vector',
'PX Deq: Par Recov Execute',
'PX Deq: Par Recov Reply',
'PX Deq: Parse Reply',
'PX Deq: Table Q Get Keys',
'PX Deq: Table Q Normal',
'PX Deq: Table Q Sample',
'PX Deq: Table Q qref',
'PX Deq: Txn Recovery Reply',
'PX Deq: Txn Recovery Start',
'PX Deque wait',
'PX Idle Wait',
'Replication Dequeue',
'Replication Dequeue ',
'SQL*Net message from client',
'SQL*Net message from dblink',
'debugger command',
'dispatcher timer',
'parallel query dequeue wait',
'pipe get',
'queue messages',
'rdbms ipc message',
'secondary event',
'single-task message',
'slave wait',
'virtual circuit status'
) and
d.kslednam not like 'resmgr:%'
)
)
order by
n_major,
n_minor,
time desc
/
@restore_sqlplus_settings
--
Please see the official ORACLE-L FAQ: http://www.orafaq.net
--
Author: Kevin Tsay
INET: [EMAIL PROTECTED]
Fat City Network Services -- 858-538-5051 http://www.fatcity.com
San Diego, California -- Mailing list and web hosting services
---------------------------------------------------------------------
To REMOVE yourself from this mailing list, send an E-Mail message
to: [EMAIL PROTECTED] (note EXACT spelling of 'ListGuru') and in
the message BODY, include a line containing: UNSUB ORACLE-L
(or the name of mailing list you want to be removed from). You may
also send the HELP command for other information (like subscribing).
