Oracle FAQ Your Portal to the Oracle Knowledge Grid
HOME | ASK QUESTION | ADD INFO | SEARCH | E-MAIL US
 

Home -> Community -> Mailing Lists -> Oracle-L -> pmon timer

pmon timer

From: Kevin Tsay <ktsay_at_mailbox.sjc2.mfn.com>
Date: Tue, 27 May 2003 16:49:50 -0800
Message-ID: <F001.005A3BE0.20030527164950@fatcity.com>


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: ktsay_at_mailbox.sjc2.mfn.com

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: ListGuru_at_fatcity.com (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).
Received on Tue May 27 2003 - 19:49:50 CDT

Original text of this message

HOME | ASK QUESTION | ADD INFO | SEARCH | E-MAIL US