Hi,
Bellow is 17 min awr report , of oracle PeopleSoft DB on 10204 instance on HPUX machine.
During this time the customers complained on poor performance.
There were 4,104.23 execution per second and 3,784.95 parses
which mean that almost any statment was parsed. since the Soft Parse %= 99.77
its seems that most of the parses are soft parse.
During those 17 min , the DB Time = 721.74 min and the "Top 5 Timed Events"
shows : "cursor: pin S wait on X" at the top of the Timed Events
Attached some details for the awr report
Could you please suggest where to focus ?
Thanks
WORKLOAD REPOSITORY report for
DB Name DB Id Instance Inst Num Release RAC Host
------------ ----------- ------------ -------- ----------- --- ------------
xxxx 2993006132 xxxx 1 10.2.0.4.0 NO xxxx
Snap Id Snap Time Sessions Curs/Sess
--------- ------------------- -------- ---------
Begin Snap: 18085 25-Mar-10 10:30:41 286 14.9
End Snap: 18086 25-Mar-10 10:48:39 301 15.1
Elapsed: 17.96 (mins)
DB Time: 721.74 (mins)
Cache Sizes
~~~~~~~~~~~ Begin End
---------- ----------
Buffer Cache: 4,448M 4,368M Std Block Size: 8K
Shared Pool Size: 2,736M 2,816M Log Buffer: 2,080K
Load Profile
~~~~~~~~~~~~ Per Second Per Transaction
--------------- ---------------
Redo size: 3,831,000.13 271,096.84
Logical reads: 164,733.47 11,657.20
Block changes: 17,757.42 1,256.59
Physical reads: 885.19 62.64
Physical writes: 504.92 35.73
User calls: 5,775.09 408.67
Parses: 3,784.95 267.84
Hard parses: 8.55 0.60
Sorts: 212.37 15.03
Logons: 0.77 0.05
Executes: 4,104.23 290.43
Transactions: 14.13
% Blocks changed per Read: 10.78 Recursive Call %: 24.14
Rollback per transaction %: 0.18 Rows per Sort: 57.86
Instance Efficiency Percentages (Target 100%)
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Buffer Nowait %: 99.98 Redo NoWait %: 99.97
Buffer Hit %: 99.47 In-memory Sort %: 100.00
Library Hit %: 99.73 Soft Parse %: 99.77
Execute to Parse %: 7.78 Latch Hit %: 99.77
Parse CPU to Parse Elapsd %: 3.06 % Non-Parse CPU: 89.23
Shared Pool Statistics Begin End
------ ------
Memory Usage %: 34.44 34.78
% SQL with executions>1: 76.52 60.40
% Memory for SQL w/exec>1: 73.75 99.18
Top 5 Timed Events Avg %Total
~~~~~~~~~~~~~~~~~~ wait Call
Event Waits Time (s) (ms) Time Wait Class
------------------------------ ------------ ----------- ------ ------ ----------
cursor: pin S wait on X 1,378,354 13,462 10 31.1 Concurrenc
db file sequential read 878,684 8,779 10 20.3 User I/O
CPU time 4,998 11.5
local write wait 2,692 2,442 907 5.6 User I/O
cursor: pin S 1,932,830 2,270 1 5.2 Other
-------------------------------------------------------------
Time Model Statistics DB/Inst: xxxx/xxxx Snaps: 18085-18086
Statistic Name Time (s) % of DB Time
------------------------------------------ ------------------ ------------
sql execute elapsed time 21,690.6 50.1
parse time elapsed 17,504.9 40.4
DB CPU 4,998.0 11.5
hard parse elapsed time 372.1 .9
connection management call elapsed time 183.9 .4
sequence load elapsed time 125.8 .3
PL/SQL execution elapsed time 89.2 .2
PL/SQL compilation elapsed time 9.2 .0
inbound PL/SQL rpc elapsed time 5.5 .0
hard parse (sharing criteria) elapsed time 5.5 .0
hard parse (bind mismatch) elapsed time 0.5 .0
failed parse elapsed time 0.1 .0
repeated bind elapsed time 0.0 .0
DB time 43,304.1 N/A
background elapsed time 3,742.3 N/A
background cpu time 114.8 N/A
-------------------------------------------------------------
Avg
%Time Total Wait wait Waits
Wait Class Waits -outs Time (s) (ms) /txn
-------------------- ---------------- ------ ---------------- ------- ---------
Concurrency 1,413,633 97.5 14,283 10 92.8
User I/O 925,010 .3 11,485 12 60.7
Other 1,984,969 .2 2,858 1 130.3
Application 1,342 46.4 1,873 1396 0.1
Configuration 12,116 63.6 1,857 153 0.8
System I/O 582,094 .0 1,444 2 38.2
Commit 17,253 .6 1,057 61 1.1
Network 6,180,701 .0 68 0 405.9
-------------------------------------------------------------
Wait Events DB/Inst: xxxx/xxxx Snaps: 18085-18086
Avg
%Time Total Wait wait Waits
Event Waits -outs Time (s) (ms) /txn
---------------------------- -------------- ------ ----------- ------- ---------
cursor: pin S wait on X 1,378,354 100.0 13,462 10 90.5
db file sequential read 878,684 .0 8,779 10 57.7
local write wait 2,692 91.2 2,442 907 0.2
cursor: pin S 1,932,830 .0 2,270 1 126.9
log file switch (checkpoint 2,669 49.1 1,510 566 0.2
enq: RO - fast object reuse 542 86.5 1,398 2580 0.0
log file sync 17,253 .6 1,057 61 1.1
control file sequential read 450,043 .0 579 1 29.6
log file parallel write 17,903 .0 558 31 1.2
enq: TX - row lock contentio 295 52.2 475 1610 0.0
buffer busy waits 7,338 4.4 348 47 0.5
buffer exterminate 322 92.5 302 938 0.0
read by other session 24,694 .0 183 7 1.6
library cache lock 59 94.9 167 2825 0.0
log file sequential read 109,494 .0 161 1 7.2
latch: cache buffers chains 18,662 .0 149 8 1.2
log buffer space 2,493 .0 139 56 0.2
Log archive I/O 3,592 .0 131 37 0.2
free buffer waits 6,420 99.1 130 20 0.4
latch free 42,812 .0 121 3 2.8
Streams capture: waiting for 845 6.0 106 125 0.1
latch: library cache 2,074 .0 96 46 0.1
db file scattered read 12,437 .0 80 6 0.8
enq: SQ - contention 150 14.0 71 471 0.0
SQL*Net more data from clien 331,961 .0 41 0 21.8
latch: shared pool 320 .0 32 100 0.0
LGWR wait for redo copy 5,307 49.1 29 5 0.3
SQL*Net more data to client 254,217 .0 17 0 16.7
control file parallel write 1,038 .0 15 14 0.1
latch: library cache lock 477 .4 14 29 0.0
latch: row cache objects 6,013 .0 10 2 0.4
SQL*Net message to client 5,587,878 .0 10 0 366.9
latch: redo allocation 1,274 .0 9 7 0.1
log file switch completion 62 .0 6 92 0.0
Streams AQ: qmn coordinator 1 100.0 5 4882 0.0
latch: cache buffers lru cha 434 .0 4 9 0.0
block change tracking buffer 111 .0 4 35 0.0
wait list latch free 135 .0 3 21 0.0
enq: TX - index contention 132 .0 2 17 0.0
latch: session allocation 139 .0 2 14 0.0
latch: object queue header o 379 .0 2 4 0.0
row cache lock 15 .0 2 107 0.0
latch: redo copy 56 .0 1 17 0.0
latch: library cache pin 184 .0 1 5 0.0
write complete waits 14 28.6 1 51 0.0
latch: redo writing 251 .0 1 3 0.0
enq: MN - contention 3 .0 1 206 0.0
enq: CF - contention 16 .0 0 23 0.0
log file single write 24 .0 0 13 0.0
os thread startup 3 .0 0 102 0.0
reliable message 66 .0 0 4 0.0
enq: JS - queue lock 2 .0 0 136 0.0
latch: cache buffer handles 46 .0 0 5 0.0
buffer deadlock 65 100.0 0 4 0.0
latch: undo global data 73 .0 0 3 0.0
change tracking file synchro 24 .0 0 6 0.0
change tracking file synchro 30 .0 0 3 0.0
kksfbc child completion 2 100.0 0 52 0.0
SQL*Net break/reset to clien 505 .0 0 0 0.0
db file parallel read 3 .0 0 30 0.0
Avg
%Time Total Wait wait Waits
Event Waits -outs Time (s) (ms) /txn
---------------------------- -------------- ------ ----------- ------- ---------
SQL*Net more data from dblin 127 .0 0 0 0.0
SQL*Net more data to dblink 319 .0 0 0 0.0
latch: enqueue hash chains 20 .0 0 2 0.0
latch: checkpoint queue latc 5 .0 0 5 0.0
SQL*Net message to dblink 6,199 .0 0 0 0.4
enq: TX - allocate ITL entry 1 .0 0 22 0.0
direct path read 5,316 .0 0 0 0.3
latch: messages 24 .0 0 1 0.0
enq: US - contention 3 .0 0 4 0.0
direct path write 1,178 .0 0 0 0.1
rdbms ipc reply 1 .0 0 1 0.0
library cache load lock 2 .0 0 0 0.0
direct path write temp 3 .0 0 0 0.0
direct path read temp 3 .0 0 0 0.0
SQL*Net message from client 5,587,890 .0 135,002 24 366.9
wait for unread message on b 7,809 21.8 3,139 402 0.5
LogMiner: client waiting for 262,604 .1 3,021 12 17.2
LogMiner: wakeup event for b 1,405,104 2.4 2,917 2 92.3
Streams AQ: qmn slave idle w 489 .0 2,650 5420 0.0
LogMiner: wakeup event for p 123,723 32.1 2,453 20 8.1
Streams AQ: waiting for time 9 55.6 1,790 198928 0.0
LogMiner: reader waiting for 45,193 51.3 1,526 34 3.0
Streams AQ: waiting for mess 297 99.3 1,052 3542 0.0
Streams AQ: qmn coordinator 470 33.8 1,050 2233 0.0
Streams AQ: delete acknowled 405 32.3 1,049 2591 0.0
jobq slave wait 379 77.8 958 2529 0.0
LogMiner: wakeup event for r 16,591 10.6 125 8 1.1
SGA: MMAN sleep for componen 3,928 99.3 35 9 0.3
SQL*Net message from dblink 6,199 .0 31 5 0.4
single-task message 108 .0 8 74 0.0
class slave wait 3 .0 0 0 0.0
-------------------------------------------------------------
Background Wait Events DB/Inst: xxxx/xxxx Snaps: 18085-18086
-> ordered by wait time desc, waits desc (idle events last)
Avg
%Time Total Wait wait Waits
Event Waits -outs Time (s) (ms) /txn
---------------------------- -------------- ------ ----------- ------- ---------
log file parallel write 17,916 .0 558 31 1.2
Log archive I/O 3,592 .0 131 37 0.2
log file sequential read 3,636 .0 47 13 0.2
events in waitclass Other 6,149 42.4 40 7 0.4
log file switch (checkpoint 30 53.3 19 619 0.0
control file parallel write 1,038 .0 15 14 0.1
db file sequential read 1,166 .0 6 5 0.1
control file sequential read 2,986 .0 6 2 0.2
latch: shared pool 4 .0 4 917 0.0
latch: library cache 5 .0 3 646 0.0
free buffer waits 160 98.8 2 10 0.0
buffer busy waits 2 .0 1 404 0.0
latch: redo writing 19 .0 0 23 0.0
log file single write 24 .0 0 13 0.0
os thread startup 3 .0 0 102 0.0
log buffer space 7 .0 0 35 0.0
latch: cache buffers chains 16 .0 0 8 0.0
log file switch completion 1 .0 0 71 0.0
latch: library cache lock 3 66.7 0 11 0.0
latch: redo copy 1 .0 0 20 0.0
direct path read 5,316 .0 0 0 0.3
latch: row cache objects 3 .0 0 1 0.0
direct path write 1,174 .0 0 0 0.1
latch: library cache pin 3 .0 0 0 0.0
rdbms ipc message 20,401 24.2 11,112 545 1.3
Streams AQ: qmn slave idle w 489 .0 2,650 5420 0.0
Streams AQ: waiting for time 9 55.6 1,790 198928 0.0
pmon timer 379 94.5 1,050 2771 0.0
Streams AQ: delete acknowled 406 32.3 1,050 2586 0.0
Streams AQ: qmn coordinator 470 33.8 1,050 2233 0.0
smon timer 146 .0 1,039 7118 0.0
SGA: MMAN sleep for componen 3,928 99.3 35 9 0.3
-------------------------------------------------------------
Operating System Statistics DB/Inst: xxxx/xxxx Snaps: 18085-18086
Statistic Total
-------------------------------- --------------------
AVG_BUSY_TIME 68,992
AVG_IDLE_TIME 37,988
AVG_IOWAIT_TIME 28,529
AVG_SYS_TIME 11,748
AVG_USER_TIME 57,214
BUSY_TIME 552,209
IDLE_TIME 304,181
IOWAIT_TIME 228,489
SYS_TIME 94,253
USER_TIME 457,956
LOAD 2
OS_CPU_WAIT_TIME 147,872,604,500
RSRC_MGR_CPU_WAIT_TIME 0
VM_IN_BYTES 49,152
VM_OUT_BYTES 0
PHYSICAL_MEMORY_BYTES 25,630,269,440
NUM_CPUS 8
NUM_CPU_SOCKETS 8