db performance slow
699139Oct 27 2010 — edited Oct 28 2010we are facing slow database problem, when database is started its performance is much better but gradually it slows down.
Bind variables are not used in application code, ADDM indicates hard parses on such queries.
Following are setup details:
OS = Windows server 2003 64bit, Server RAM 16 GB
DB Ver = 10g 64 bit (10.2.0.1.0)
Database is ASM based. Currently database size is 189GB where as tablespace detail is as below
Tablespace Size(MB) Used(MB)
SYSAUX 1,264.0 362.9
SYSTEM 3,552.0 515.2
TEMP 6,257.0 976.0
UNDOTBS1 7,634.0 3.1
USERS 175,269.5 95,261.6
Database is in no-archive log mode.
SGA Component Current Allocation (MB)
Shared Pool 464
Buffer Cache 10752
Large Pool 16
Java Pool 16
Other 16
Total SGA size is 11GB and PGA size is 2GB.
Also review the statspack report below.
STATSPACK
============================
Snapshot Snap Id Snap Time Sessions Curs/Sess Comment
~~~~~~~~ ---------- ------------------ -------- --------- -------------------
Begin Snap: 1 26-Oct-10 12:25:08 153 59.0
End Snap: 21 26-Oct-10 12:57:02 173 54.6
Elapsed: 31.90 (mins)
Cache Sizes Begin End
~~~~~~~~~~~ ---------- ----------
Buffer Cache: 10,720M Std Block Size: 8K
Shared Pool Size: 496M Log Buffer: 13,967K
Load Profile Per Second Per Transaction
~~~~~~~~~~~~ --------------- ---------------
Redo size: 66,071.58 13,496.37
Logical reads: 42,163.00 8,612.59
Block changes: 147.77 30.19
Physical reads: 2,799.12 571.77
Physical writes: 10.08 2.06
User calls: 192.84 39.39
Parses: 74.55 15.23
Hard parses: 8.36 1.71
Sorts: 12.29 2.51
Logons: 0.23 0.05
Executes: 104.03 21.25
Transactions: 4.90
% Blocks changed per Read: 0.35 Recursive Call %: 61.54
Rollback per transaction %: 0.35 Rows per Sort: 34.10
Instance Efficiency Percentages
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Buffer Nowait %: 97.33 Redo NoWait %: 99.98
Buffer Hit %: 93.36 In-memory Sort %: 100.00
Library Hit %: 94.13 Soft Parse %: 88.78
Execute to Parse %: 28.34 Latch Hit %: 96.14
Parse CPU to Parse Elapsd %: 96.57 % Non-Parse CPU: 97.56
Shared Pool Statistics Begin End
------ ------
Memory Usage %: 86.97 90.00
% SQL with executions>1: 46.06 48.60
% Memory for SQL w/exec>1: 49.30 49.36
Top 5 Timed Events Avg %Total
~~~~~~~~~~~~~~~~~~ wait Call
Event Waits Time (s) (ms) Time
----------------------------------------- ------------ ----------- ------ ------
read by other session 2,166,074 1,599 1 35.7
db file scattered read 943,759 973 1 21.7
CPU time 889 19.8
db file sequential read 924,530 817 1 18.2
log file sync 9,307 98 11 2.2
-------------------------------------------------------------
Host CPU (CPUs: 8)
~~~~~~~~ Load Average
Begin End User System Idle WIO WCPU
------- ------- ------- ------- ------- ------- --------
6.06 1.09 92.85
Instance CPU
~~~~~~~~~~~~
% of total CPU for Instance: 5.93
% of busy CPU for Instance: 82.93
%DB time waiting for CPU - Resource Mgr:
Memory Statistics Begin End
~~~~~~~~~~~~~~~~~ ------------ ------------
Host Mem (MB): 16,382.6 16,382.6
SGA use (MB): 11,264.0 11,264.0
PGA use (MB): 589.5 660.9
% Host Mem used for SGA+PGA: 72.4 72.8
-------------------------------------------------------------
Time Model System Stats DB/Inst: CIBSPROD/cibsprod Snaps: 1-21
-> Ordered by % of DB time desc, Statistic name
Statistic Time (s) % of DB time
----------------------------------- -------------------- ------------
sql execute elapsed time 4,179.3 97.2
DB CPU 902.0 21.0
parse time elapsed 24.0 .6
hard parse elapsed time 18.5 .4
sequence load elapsed time 1.4 .0
PL/SQL execution elapsed time 1.0 .0
connection management call elapsed 0.8 .0
hard parse (sharing criteria) elaps 0.6 .0
hard parse (bind mismatch) elapsed 0.5 .0
PL/SQL compilation elapsed time 0.3 .0
repeated bind elapsed time 0.1 .0
failed parse elapsed time 0.0 .0
DB time 4,300.9
background elapsed time 99.5
background cpu time 6.0
-------------------------------------------------------------
Wait Events DB/Inst: CIBSPROD/cibsprod Snaps: 1-21
-> s - second, cs - centisecond, ms - millisecond, us - microsecond
-> %Timeouts: value of 0 indicates value was < .5%. Value of null is truly 0
-> Only events with Total Wait Time (s) >= .001 are shown
-> ordered by Total Wait Time desc, Waits desc (idle events last)
Avg
%Time Total Wait wait Waits
Event Waits -outs Time (s) (ms) /txn
--------------------------------- ------------ ------ ---------- ------ --------
read by other session 2,166,074 0 1,599 1 231.2
db file scattered read 943,759 0 973 1 100.7
db file sequential read 924,530 0 817 1 98.7
log file sync 9,307 0 98 11 1.0
log file parallel write 9,292 0 77 8 1.0
db file parallel write 2,637 0 13 5 0.3
control file sequential read 4,563 0 6 1 0.5
control file parallel write 766 0 3 4 0.1
db file parallel read 20 0 2 99 0.0
log file switch completion 15 7 2 126 0.0
log file switch (checkpoint incom 4 0 2 396 0.0
enq: TX - row lock contention 56 0 1 18 0.0
direct path read 92 0 1 6 0.0
latch: cache buffers chains 59,167 0 0 0 6.3
log buffer space 5 0 0 30 0.0
os thread startup 29 0 0 4 0.0
SQL*Net more data to client 3,272 0 0 0 0.3
latch: shared pool 294 0 0 0 0.0
enq: CF - contention 2 0 0 44 0.0
log file sequential read 12 0 0 5 0.0
latch: library cache 295 0 0 0 0.0
SQL*Net break/reset to client 218 0 0 0 0.0
latch free 89 0 0 0 0.0
library cache load lock 10 0 0 1 0.0
direct path write 92 0 0 0 0.0
log file single write 12 0 0 0 0.0
buffer busy waits 29 0 0 0 0.0
SQL*Net message from client 278,372 0 180,519 648 29.7
wait for unread message on broadc 1,913 100 1,913 1000 0.2
Streams AQ: qmn slave idle wait 68 0 1,913 28126 0.0
Streams AQ: qmn coordinator idle 141 52 1,913 13564 0.0
ASM background timer 383 0 1,911 4990 0.0
Streams AQ: waiting for messages 382 100 1,907 4993 0.0
virtual circuit status 64 100 1,892 29561 0.0
Streams AQ: waiting for time mana 35 63 1,825 52155 0.0
class slave wait 14 100 1,811 ###### 0.0
jobq slave wait 589 100 1,764 2995 0.1
SQL*Net message to client 278,388 0 0 0 29.7
SQL*Net more data from client 706 0 0 0 0.1
-------------------------------------------------------------
Background Wait Events DB/Inst: CIBSPROD/cibsprod Snaps: 1-21
-> %Timeouts: value of 0 indicates value was < .5%. Value of null is truly 0
-> Only events with Total Wait Time (s) >= .001 are shown
-> ordered by Total 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 9,292 0 77 8 1.0
db file parallel write 2,637 0 13 5 0.3
control file parallel write 766 0 3 4 0.1
control file sequential read 276 0 2 7 0.0
direct path read 92 0 1 6 0.0
log file switch (checkpoint incom 1 0 0 426 0.0
os thread startup 29 0 0 4 0.0
events in waitclass Other 54 0 0 2 0.0
log file sequential read 12 0 0 5 0.0
direct path write 92 0 0 0 0.0
log file single write 12 0 0 0 0.0
db file scattered read 1 0 0 2 0.0
latch: library cache 3 0 0 0 0.0
rdbms ipc message 15,910 43 18,916 1189 1.7
pmon timer 846 100 1,914 2262 0.1
Streams AQ: qmn slave idle wait 68 0 1,913 28126 0.0
Streams AQ: qmn coordinator idle 141 52 1,913 13564 0.0
ASM background timer 383 0 1,911 4990 0.0
Streams AQ: waiting for time mana 35 63 1,825 52155 0.0
class slave wait 14 100 1,811 ###### 0.0
smon timer 6 100 1,552 ###### 0.0
-------------------------------------------------------------
Wait Event Histogram DB/Inst: CIBSPROD/cibsprod Snaps: 1-21
-> Total Waits - units: K is 1000, M is 1000000, G is 1000000000
-> % of Waits - column heading: <=1s is truly <1024ms, >1s is truly >=1024ms
-> % of Waits - value: .0 indicates value was <.05%, null is truly 0
-> Ordered by Event (idle events last)
Total ----------------- % of Waits ------------------
Event Waits <1ms <2ms <4ms <8ms <16ms <32ms <=1s >1s
-------------------------- ----- ----- ----- ----- ----- ----- ----- ----- -----
LGWR wait for redo copy 52 100.0
SQL*Net break/reset to cli 218 100.0
SQL*Net more data to clien 3272 100.0
buffer busy waits 29 100.0
control file parallel writ 766 46.9 48.2 3.8 .7 .1 .3 .1
control file sequential re 4563 85.6 4.0 3.7 3.5 2.0 .8 .3
db file parallel read 20 5.0 5.0 15.0 75.0
db file parallel write 2637 61.5 9.6 9.8 9.0 5.1 1.9 3.0
db file scattered read 943K 89.2 4.5 1.6 2.6 1.3 .8 .0
db file sequential read 924K 90.8 1.3 2.9 3.3 1.2 .6 .0
direct path read 92 73.9 1.1 1.1 7.6 3.3 5.4 7.6
direct path write 92 98.9 1.1
enq: CF - contention 2 50.0 50.0
enq: SQ - contention 1 100.0
enq: TX - row lock content 56 67.9 1.8 1.8 3.6 5.4 1.8 17.9
latch free 88 96.6 3.4
latch: In memory undo latc 8 100.0
latch: cache buffers chain 55K 100.0 .0
latch: library cache 292 98.3 1.7
latch: shared pool 266 94.0 4.9 1.1
library cache load lock 10 70.0 20.0 10.0
log buffer space 5 20.0 20.0 20.0 40.0
log file parallel write 9292 61.9 8.0 2.0 6.6 9.0 6.7 5.7 .1
log file sequential read 12 50.0 8.3 8.3 16.7 16.7
log file single write 12 100.0
log file switch (checkpoin 4 100.0
log file switch completion 15 6.7 93.3
log file sync 9304 52.6 9.4 2.9 9.2 11.1 8.1 6.7
os thread startup 29 75.9 24.1
read by other session 2159K 92.5 2.3 1.8 2.2 .7 .4 .0
ASM background timer 383 100.0
SQL*Net message from clien 278K 68.5 5.2 4.1 3.1 3.3 3.5 9.7 2.6
SQL*Net message to client 278K 100.0
SQL*Net more data from cli 706 99.9 .1
Streams AQ: qmn coordinato 141 48.2 51.8
Streams AQ: qmn slave idle 68 100.0
Streams AQ: waiting for me 382 100.0
Streams AQ: waiting for ti 35 37.1 22.9 40.0
class slave wait 14 100.0
dispatcher timer 32 100.0
jobq slave wait 589 100.0
pmon timer 846 24.3 .2 75.4
rdbms ipc message 15K 8.8 5.8 9.6 8.1 4.7 5.1 27.8 30.1
smon timer 6 100.0
virtual circuit status 64 100.0
wait for unread message on 1913 100.0
-------------------------------------------------------------
Instance Activity Stats DB/Inst: CIBSPROD/cibsprod Snaps: 1-21
-> Statistics with absolute values (should not be diffed)
Statistic Begin Value End Value
--------------------------------- --------------- ---------------
logons current 153 173
opened cursors current 9,032 9,445
session cursor cache count 49,548 52,457
-------------------------------------------------------------
Instance Activity Stats DB/Inst: CIBSPROD/cibsprod Snaps: 1-21
-> Statistics identified by '(derived)' come from sources other than SYSSTAT
Statistic Total per Hour
--------------------------------- ------------------ ---------
log switches (derived) 3 5.64
-------------------------------------------------------------
OS Statistics DB/Inst: CIBSPROD/cibsprod Snaps: 1-21
-> ordered by statistic type (CPU use, Virtual Memory, Hardware Config), Name
Statistic Total
------------------------- ----------------------
BUSY_TIME 109,478
IDLE_TIME 1,421,548
SYS_TIME 16,665
USER_TIME 92,813
VM_IN_BYTES ######################
VM_OUT_BYTES ######################
PHYSICAL_MEMORY_BYTES 17,178,415,104
NUM_CPUS 8
NUM_CPU_CORES 2
-------------------------------------------------------------
Tablespace IO Stats DB/Inst: CIBSPROD/cibsprod Snaps: 1-21
->ordered by IOs (Reads + Writes) desc
Tablespace
------------------------------
Av Av Av Av Buffer Av Buf
Reads Reads/s Rd(ms) Blks/Rd Writes Writes/s Waits Wt(ms)
-------------- ------- ------ ------- ------------ -------- ---------- ------
USERS
2,075,469 1,084 1.1 3.8 89,196 47 2,174,394 0.7
UNDOTBS1
106 0 40.3 1.0 38,141 20 40 0.0
SYSAUX
5,179 3 4.5 3.5 20,007 10 0 0.0
SYSTEM
9,865 5 2.8 1.3 3,479 2 1 0.0
-------------------------------------------------------------
Buffer Pool Statistics DB/Inst: CIBSPROD/cibsprod Snaps: 1-21
-> Standard block size Pools D: default, K: keep, R: recycle
-> Default Pools for other block sizes: 2k, 4k, 8k, 16k, 32k
-> Buffers: the number of buffers. Units of K, M, G are divided by 1000
Free Writ Buffer
Pool Buffer Physical Physical Buffer Comp Busy
P Buffers Hit% Gets Reads Writes Waits Wait Waits
--- ------- ---- -------------- ------------ ----------- ------- ---- ----------
D 1329K 93 80,634,047 5,357,233 19,204 0 0 2,165,599
-------------------------------------------------------------
Instance Recovery Stats DB/Inst: CIBSPROD/cibsprod Snaps: 1-21
-> B: Begin snapshot, E: End snapshot
Targt Estd Log File Log Ckpt Log Ckpt
MTTR MTTR Recovery Actual Target Size Timeout Interval
(s) (s) Estd IOs Redo Blks Redo Blks Redo Blks Redo Blks Redo Blks
- ----- ----- ---------- --------- --------- ---------- --------- ------------
B 0 52 2960 29956 70739 184320 70739
E 0 25 620 4636 184320 184320 252677
-------------------------------------------------------------
Buffer wait Statistics DB/Inst: CIBSPROD/cibsprod Snaps: 1-21
-> ordered by wait time desc, waits desc
Class Waits Total Wait Time (s) Avg Time (ms)
---------------------- ----------- ------------------- -------------
data block 2,156,623 1,602 1
undo header 1 0 0
1st level bmb 1 0 0
-------------------------------------------------------------
PGA Aggr Target Stats DB/Inst: CIBSPROD/cibsprod Snaps: 1-21
-> B: Begin snap E: End snap (rows identified with B or E contain data
which is absolute i.e. not diffed over the interval)
-> PGA cache hit % - percentage of W/A (WorkArea) data processed only in-memory
-> Auto PGA Target - actual workarea memory target
-> W/A PGA Used - amount of memory used for all Workareas (manual + auto)
-> %PGA W/A Mem - percentage of PGA memory allocated to workareas
-> %Auto W/A Mem - percentage of workarea memory controlled by Auto Mem Mgmt
-> %Man W/A Mem - percentage of workarea memory under manual control
PGA Cache Hit % W/A MB Processed Extra W/A MB Read/Written
--------------- ---------------- -------------------------
100.0 1,253 0
%PGA %Auto %Man
PGA Aggr Auto PGA PGA Mem W/A PGA W/A W/A W/A Global Mem
Target(M) Target(M) Alloc(M) Used(M) Mem Mem Mem Bound(K)
- --------- --------- ---------- ---------- ------ ------ ------ ----------
B 2,048 1,580 589.5 0.0 .0 .0 .0 209,710
E 2,048 1,549 660.9 0.0 .0 .0 .0 209,710
-------------------------------------------------------------
PGA Aggr Target Histogram DB/Inst: CIBSPROD/cibsprod Snaps: 1-21
-> Optimal Executions are purely in-memory operations
Low High
Optimal Optimal Total Execs Optimal Execs 1-Pass Execs M-Pass Execs
------- ------- -------------- ------------- ------------ ------------
2K 4K 20,629 20,629 0 0
64K 128K 16 16 0 0
128K 256K 2 2 0 0
256K 512K 94 94 0 0
512K 1024K 1,261 1,261 0 0
1M 2M 28 28 0 0
8M 16M 3 3 0 0
16M 32M 3 3 0 0
128M 256M 1 1 0 0
-------------------------------------------------------------
PGA Memory Advisory DB/Inst: CIBSPROD/cibsprod End Snap: 21
-> When using Auto Memory Mgmt, minimally choose a pga_aggregate_target value
where Estd PGA Overalloc Count is 0
Estd Extra Estd PGA Estd PGA
PGA Target Size W/A MB W/A MB Read/ Cache Overalloc
Est (MB) Factr Processed Written to Disk Hit % Count
---------- ------- ---------------- ---------------- -------- ----------
256 0.1 15,914.7 1,656.9 91.0 120
512 0.3 15,914.7 464.5 97.0 0
1,024 0.5 15,914.7 464.5 97.0 0
1,536 0.8 15,914.7 464.5 97.0 0
2,048 1.0 15,914.7 0.0 100.0 0
2,458 1.2 15,914.7 0.0 100.0 0
2,867 1.4 15,914.7 0.0 100.0 0
3,277 1.6 15,914.7 0.0 100.0 0
3,686 1.8 15,914.7 0.0 100.0 0
4,096 2.0 15,914.7 0.0 100.0 0
6,144 3.0 15,914.7 0.0 100.0 0
8,192 4.0 15,914.7 0.0 100.0 0
12,288 6.0 15,914.7 0.0 100.0 0
16,384 8.0 15,914.7 0.0 100.0 0
-------------------------------------------------------------
Process Memory Summary Stats DB/Inst: CIBSPROD/cibsprod Snaps: 1-21
-> B: Begin snap E: End snap
-> All rows below contain absolute values (i.e. not diffed over the interval)
-> Max Alloc is Maximum PGA Allocation size at snapshot time
Hist Max Alloc is the Historical Max Allocation for still-connected processes
-> Num Procs or Allocs: For Begin/End snapshot lines, it is the number of
processes. For Category lines, it is the number of allocations
-> ordered by Begin/End snapshot, Alloc (MB) desc
Hist Num
Avg Std Dev Max Max Procs
Alloc Used Freeabl Alloc Alloc Alloc Alloc or
Category (MB) (MB) (MB) (MB) (MB) (MB) (MB) Allocs
- -------- --------- --------- -------- -------- ------- ------- ------ ------
B -------- 589.5 295.0 77.4 3.8 5.5 62 152 155
Other 481.9 3.1 5.0 58 58 155
Freeable 77.4 .0 .8 .5 5 94
SQL 28.4 13.0 .2 .2 1 144 138
PL/SQL 1.8 1.1 .0 .0 0 0 153
E -------- 661.0 326.9 85.1 3.8 5.2 62 152 175
Other 544.5 3.1 4.8 58 58 175
Freeable 85.1 .0 .8 .5 5 106
SQL 29.4 13.5 .2 .2 1 144 158
PL/SQL 2.1 1.3 .0 .0 0 0 173
-------------------------------------------------------------
Latch Sleep breakdown DB/Inst: CIBSPROD/cibsprod Snaps: 1-21
-> ordered by misses desc
Get Spin
Latch Name Requests Misses Sleeps Gets
-------------------------- --------------- ------------ ----------- -----------
cache buffers chains 167,550,579 8,217,279 59,189 8,158,598
simulator lru latch 7,699,816 408,023 87 407,937
library cache 11,482,321 2,254 295 1,962
shared pool 622,308 718 294 452
kks stats 62,237 23 2 21
In memory undo latch 51,597 19 8 11
-------------------------------------------------------------
Library Cache Activity DB/Inst: CIBSPROD/cibsprod Snaps: 1-21
->"Pct Misses" should be very low
Get Pct Pin Pct Invali-
Namespace Requests Miss Requests Miss Reloads dations
--------------- ------------ ------ -------------- ------ ---------- --------
SQL AREA 15,868 90.3 254,630 12.2 1,839 0
TABLE/PROCEDURE 17,065 0.8 346,754 1.3 2,360 0
BODY 370 1.1 2,797 1.6 40 0
TRIGGER 8 25.0 218 5.0 7 0
CLUSTER 71 0.0 110 3.6 4 0
-------------------------------------------------------------
Rule Sets DB/Inst: CIBSPROD/cibsprod Snaps: 1-21
-> * indicates Rule Set activity (re)started between Begin/End snaps
-> Top 25 ordered by Evaluations desc
No-SQL SQL
Rule * Eval/sec Reloads/sec Eval % Eval %
----------------------------------- - ------------ ----------- ------ ------
SYS.ALERT_QUE_R 0 0 0 0
-------------------------------------------------------------
regards,
asim