现象，系统经常不固定的出现登陆不了的问题（登陆时要写数据库日志），随机出现，大约20分钟自己恢复，系统压力很小。前五个等待事件全都和写有关。 应用系统后台还有17002错误，但在出问题期间，用我自己写的java测试工具能轻易的连上数据库服务器，且往数据库写数据也很快。下面是报告：
STATSPACK report forDB Name DB Id Instance Inst Num Release Cluster Host
------------ ----------- ------------ -------- ----------- ------- ------------
EIDC 2575538572 EIDC 1 9.2.0.5.0 NO db2 Snap Id Snap Time Sessions Curs/Sess Comment
------- ------------------ -------- --------- -------------------
Begin Snap: 1 12-Mar-08 11:28:29 24 8.7
End Snap: 2 12-Mar-08 11:40:05 41 5.3
Elapsed: 11.60 (mins)Cache Sizes (end)
~~~~~~~~~~~~~~~~~
Buffer Cache: 304M Std Block Size: 8K
Shared Pool Size: 512M Log Buffer: 512KLoad Profile
~~~~~~~~~~~~ Per Second Per Transaction
--------------- ---------------
Redo size: 9,661.41 40,508.07
Logical reads: 71.79 301.00
Block changes: 29.97 125.66
Physical reads: 4.00 16.78
Physical writes: 4.07 17.08
User calls: 19.74 82.75
Parses: 3.45 14.46
Hard parses: 0.03 0.13
Sorts: 1.49 6.24
Logons: 0.05 0.22
Executes: 4.59 19.25
Transactions: 0.24 % Blocks changed per Read: 41.75 Recursive Call %: 47.77
Rollback per transaction %: 0.00 Rows per Sort: 79.44Instance Efficiency Percentages (Target 100%)
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Buffer Nowait %: 100.00 Redo NoWait %: 100.00
Buffer Hit %: 100.00 In-memory Sort %: 99.90
Library Hit %: 98.89 Soft Parse %: 99.08
Execute to Parse %: 24.87 Latch Hit %: 99.99
Parse CPU to Parse Elapsd %: 83.33 % Non-Parse CPU: 97.22 Shared Pool Statistics Begin End
------ ------
Memory Usage %: 90.95 91.02
% SQL with executions>1: 52.11 52.26
% Memory for SQL w/exec>1: 53.70 54.04Top 5 Timed Events
~~~~~~~~~~~~~~~~~~ % Total
Event Waits Time (s) Ela Time
-------------------------------------------- ------------ ----------- --------
CPU time 4 65.38
log file sync 166 1 19.84
db file parallel write 46 0 5.35
control file parallel write 227 0 2.81
log file parallel write 363 0 2.01
-------------------------------------------------------------
Wait Events for DB: EIDC Instance: EIDC Snaps: 1 -2
-> s - second
-> cs - centisecond - 100th of a second
-> ms - millisecond - 1000th of a second
-> us - microsecond - 1000000th of a second
-> ordered by wait time desc, waits desc (idle events last) Avg
Total Wait wait Waits
Event Waits Timeouts Time (s) (ms) /txn
---------------------------- ------------ ---------- ---------- ------ --------
log file sync 166 1 1 7 1.0
db file parallel write 46 0 0 6 0.3
control file parallel write 227 0 0 1 1.4
log file parallel write 363 260 0 0 2.2
direct path read 65 0 0 2 0.4
process startup 4 0 0 18 0.0
local write wait 30 0 0 1 0.2
control file sequential read 166 0 0 0 1.0
LGWR wait for redo copy 6 0 0 1 0.0
direct path write 4 0 0 2 0.0
SQL*Net more data to client 17 0 0 0 0.1
SQL*Net message from client 13,685 0 7,657 560 82.4
jobq slave wait 699 667 2,037 2914 4.2
wakeup time manager 23 23 665 28913 0.1
SQL*Net more data from clien 2 0 0 141 0.0
SQL*Net message to client 13,702 0 0 0 82.5
-------------------------------------------------------------
Background Wait Events for DB: EIDC Instance: EIDC Snaps: 1 -2
-> ordered by wait time desc, waits desc (idle events last) Avg
Total Wait wait Waits
Event Waits Timeouts Time (s) (ms) /txn
---------------------------- ------------ ---------- ---------- ------ --------
db file parallel write 46 0 0 6 0.3
control file parallel write 227 0 0 1 1.4
log file parallel write 363 260 0 0 2.2
control file sequential read 92 0 0 0 0.6
LGWR wait for redo copy 6 0 0 1 0.0
rdbms ipc message 1,305 933 3,837 2940 7.9
pmon timer 231 231 677 2930 1.4
smon timer 2 2 600 ###### 0.0
-------------------------------------------------------------
SQL ordered by Gets for DB: EIDC Instance: EIDC Snaps: 1 -2
-> End Buffer Gets Threshold: 10000
-> Note that resources reported for PL/SQL includes the resources used by
all SQL statements called within the PL/SQL code. As individual SQL
statements are also reported, it is possible and valid for the summed
total % to exceed 100
Buffer Gets Executions Gets per Exec %Total Time (s) Time (s) Hash Value
--------------- ------------ -------------- ------ -------- --------- ----------
33,090 1 33,090.0 66.2 3.45 4.78 864547796
Module: SQL*Plus
BEGIN statspack.snap(i_snap_level=>6,i_modify_parameter=>'true')
; END; 24,691 1 24,691.0 49.4 0.50 0.48 2389506893
Module: SQL*Plus
INSERT INTO STATS$SQL_PLAN ( PLAN_HASH_VALUE , ID , OPERATION ,
OPTIONS , OBJECT_NODE , OBJECT# , OBJECT_OWNER , OBJECT_NAME , O
PTIMIZER , PARENT_ID , DEPTH , POSITION , SEARCH_COLUMNS , COST
, CARDINALITY , BYTES , OTHER_TAG , PARTITION_START , PARTITION_
STOP , PARTITION_ID , OTHER , DISTRIBUTION , CPU_COST , IO_COST 1,921 23 83.5 3.8 0.01 0.06 815501214
STATSPACK report forDB Name DB Id Instance Inst Num Release Cluster Host
------------ ----------- ------------ -------- ----------- ------- ------------
EIDC 2575538572 EIDC 1 9.2.0.5.0 NO db2 Snap Id Snap Time Sessions Curs/Sess Comment
------- ------------------ -------- --------- -------------------
Begin Snap: 1 12-Mar-08 11:28:29 24 8.7
End Snap: 2 12-Mar-08 11:40:05 41 5.3
Elapsed: 11.60 (mins)Cache Sizes (end)
~~~~~~~~~~~~~~~~~
Buffer Cache: 304M Std Block Size: 8K
Shared Pool Size: 512M Log Buffer: 512KLoad Profile
~~~~~~~~~~~~ Per Second Per Transaction
--------------- ---------------
Redo size: 9,661.41 40,508.07
Logical reads: 71.79 301.00
Block changes: 29.97 125.66
Physical reads: 4.00 16.78
Physical writes: 4.07 17.08
User calls: 19.74 82.75
Parses: 3.45 14.46
Hard parses: 0.03 0.13
Sorts: 1.49 6.24
Logons: 0.05 0.22
Executes: 4.59 19.25
Transactions: 0.24 % Blocks changed per Read: 41.75 Recursive Call %: 47.77
Rollback per transaction %: 0.00 Rows per Sort: 79.44Instance Efficiency Percentages (Target 100%)
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Buffer Nowait %: 100.00 Redo NoWait %: 100.00
Buffer Hit %: 100.00 In-memory Sort %: 99.90
Library Hit %: 98.89 Soft Parse %: 99.08
Execute to Parse %: 24.87 Latch Hit %: 99.99
Parse CPU to Parse Elapsd %: 83.33 % Non-Parse CPU: 97.22 Shared Pool Statistics Begin End
------ ------
Memory Usage %: 90.95 91.02
% SQL with executions>1: 52.11 52.26
% Memory for SQL w/exec>1: 53.70 54.04Top 5 Timed Events
~~~~~~~~~~~~~~~~~~ % Total
Event Waits Time (s) Ela Time
-------------------------------------------- ------------ ----------- --------
CPU time 4 65.38
log file sync 166 1 19.84
db file parallel write 46 0 5.35
control file parallel write 227 0 2.81
log file parallel write 363 0 2.01
-------------------------------------------------------------
Wait Events for DB: EIDC Instance: EIDC Snaps: 1 -2
-> s - second
-> cs - centisecond - 100th of a second
-> ms - millisecond - 1000th of a second
-> us - microsecond - 1000000th of a second
-> ordered by wait time desc, waits desc (idle events last) Avg
Total Wait wait Waits
Event Waits Timeouts Time (s) (ms) /txn
---------------------------- ------------ ---------- ---------- ------ --------
log file sync 166 1 1 7 1.0
db file parallel write 46 0 0 6 0.3
control file parallel write 227 0 0 1 1.4
log file parallel write 363 260 0 0 2.2
direct path read 65 0 0 2 0.4
process startup 4 0 0 18 0.0
local write wait 30 0 0 1 0.2
control file sequential read 166 0 0 0 1.0
LGWR wait for redo copy 6 0 0 1 0.0
direct path write 4 0 0 2 0.0
SQL*Net more data to client 17 0 0 0 0.1
SQL*Net message from client 13,685 0 7,657 560 82.4
jobq slave wait 699 667 2,037 2914 4.2
wakeup time manager 23 23 665 28913 0.1
SQL*Net more data from clien 2 0 0 141 0.0
SQL*Net message to client 13,702 0 0 0 82.5
-------------------------------------------------------------
Background Wait Events for DB: EIDC Instance: EIDC Snaps: 1 -2
-> ordered by wait time desc, waits desc (idle events last) Avg
Total Wait wait Waits
Event Waits Timeouts Time (s) (ms) /txn
---------------------------- ------------ ---------- ---------- ------ --------
db file parallel write 46 0 0 6 0.3
control file parallel write 227 0 0 1 1.4
log file parallel write 363 260 0 0 2.2
control file sequential read 92 0 0 0 0.6
LGWR wait for redo copy 6 0 0 1 0.0
rdbms ipc message 1,305 933 3,837 2940 7.9
pmon timer 231 231 677 2930 1.4
smon timer 2 2 600 ###### 0.0
-------------------------------------------------------------
SQL ordered by Gets for DB: EIDC Instance: EIDC Snaps: 1 -2
-> End Buffer Gets Threshold: 10000
-> Note that resources reported for PL/SQL includes the resources used by
all SQL statements called within the PL/SQL code. As individual SQL
statements are also reported, it is possible and valid for the summed
total % to exceed 100
Buffer Gets Executions Gets per Exec %Total Time (s) Time (s) Hash Value
--------------- ------------ -------------- ------ -------- --------- ----------
33,090 1 33,090.0 66.2 3.45 4.78 864547796
Module: SQL*Plus
BEGIN statspack.snap(i_snap_level=>6,i_modify_parameter=>'true')
; END; 24,691 1 24,691.0 49.4 0.50 0.48 2389506893
Module: SQL*Plus
INSERT INTO STATS$SQL_PLAN ( PLAN_HASH_VALUE , ID , OPERATION ,
OPTIONS , OBJECT_NODE , OBJECT# , OBJECT_OWNER , OBJECT_NAME , O
PTIMIZER , PARENT_ID , DEPTH , POSITION , SEARCH_COLUMNS , COST
, CARDINALITY , BYTES , OTHER_TAG , PARTITION_START , PARTITION_
STOP , PARTITION_ID , OTHER , DISTRIBUTION , CPU_COST , IO_COST 1,921 23 83.5 3.8 0.01 0.06 815501214
不应该高于90%,过高会使共享池外部的组件老化，如果SQL语句被再次执行，这将使得SQL语句被硬解析。
TOP5 EVENT
log file sync
说明任何时候一个事物提交时，它将通知LGWR将LOG_BUFFER写入日志文件，如果此部分占用时间较长，应减少COMMIT的次数，建议将重做日志放到较快的磁盘上进行存储。
解决方法：加大内存，应多使用绑定变量。
将你的log buffer 开到3m吧。
每秒执行的SQL只有5条不到.
SQL ordered by Gets中排第一第二的竟然是statspack自身的SQL.
这个statspack几乎没有什么价值. 发现不了什么问题.把statspack的时间做长一点, 选在性能高峰期做. 这样才可能定位到性能问题.