Response time = Service time + Wait timehtml
Snap Id
|
Snap Time
|
Sessions
|
Cursors/Session
|
|
Begin Snap:
|
9820
|
13-2月 -12 08:00:17前端 |
735
|
89.3
|
End Snap:
|
9821
|
13-2月 -12 09:00:13linux |
965
|
92.3
|
Elapsed:
|
59.93 (mins)
|
|||
DB Time:
|
437.53 (mins)
|
Snap Id
|
Snap Time
|
Sessions
|
Cursors/Session
|
|
Begin Snap:
|
571
|
31-May-10 08:00:16
|
472
|
56.9
|
End Snap:
|
572
|
31-May-10 09:00:17
|
307
|
50.1
|
Elapsed:
|
60.02 (mins)
|
|||
DB Time:
|
1,139.42 (mins)
|
Cpu time/ (Elapsed time * CPU cores)sql
Event
|
Waits
|
Time(s)
|
Avg Wait(ms)
|
% Total Call Time
|
Wait Class
|
latch: cache buffers chains
|
76,560
|
33,283
|
435
|
48.7
|
Concurrency
|
CPU time
|
23,129
|
33.8
|
|||
log file sync
|
28,057
|
2,754
|
98
|
4.0
|
Commit
|
db file sequential read
|
312,477
|
2,169
|
7
|
3.2
|
User I/O
|
log file parallel write
|
24,580
|
633
|
26
|
.9
|
System I/O
|
在awr中,Time Model Statistics用於回答「到底前臺進程消耗了多少時間?」,「語句解析消耗了多少時間?」等諸如此類的問題,咱們來看一個例子:數據庫
Statistic Name
|
Time (s)
|
% of DB Time
|
connection management call elapsed time
|
21,708.46
|
15.22
|
sql execute elapsed time
|
21,596.44
|
15.14
|
parse time elapsed
|
17,648.50
|
12.37
|
hard parse elapsed time
|
9,081.89
|
6.37
|
hard parse (sharing criteria) elapsed time
|
4,158.48
|
2.92
|
hard parse (bind mismatch) elapsed time
|
3,189.62
|
2.24
|
PL/SQL execution elapsed time
|
2,362.21
|
1.66
|
DB CPU
|
2,311.28
|
1.62
|
PL/SQL compilation elapsed time
|
145.25
|
0.10
|
failed parse elapsed time
|
89.78
|
0.06
|
sequence load elapsed time
|
69.16
|
0.05
|
repeated bind elapsed time
|
0.21
|
0.00
|
DB time
|
142,622.31
|
|
background elapsed time
|
4,871.65
|
|
background cpu time
|
22.41
|
咱們看到,真於用於sql執行的時間(sql execute elapsed time)只佔到了15.14%;這個比率是很是低的,做來一個相對正常的系統,這一比率不該低於90%甚至更高!咱們看到用於鏈接管理(connection management call elapsed time)的時間爲15%,用於sql解析(parse time elapsed)的時爲12.37%,且其中硬解析sql(hard parse elapsed time)的時間爲6.37%。從這幾個方面來看,咱們能夠做一些合理的推測:緩存
NUM_LCPUS
|
0
|
NUM_VCPUS
|
0
|
AVG_BUSY_TIME
|
149,127
|
AVG_IDLE_TIME
|
211,742
|
AVG_IOWAIT_TIME
|
40,260
|
AVG_SYS_TIME
|
14,015
|
AVG_USER_TIME
|
135,004
|
BUSY_TIME
|
2,387,903
|
IDLE_TIME
|
3,389,758
|
IOWAIT_TIME
|
646,085
|
SYS_TIME
|
225,900
|
USER_TIME
|
2,162,003
|
LOAD
|
0
|
OS_CPU_WAIT_TIME
|
2,474,600
|
RSRC_MGR_CPU_WAIT_TIME
|
0
|
PHYSICAL_MEMORY_BYTES
|
49,123,688,448
|
NUM_CPUS
|
16
|
NUM_CPU_CORES
|
8
|
Event
|
Waits
|
Time(s)
|
Avg Wait(ms)
|
% Total Call Time
|
Wait Class
|
CPU time
|
17,217
|
54.5
|
|||
db file sequential read
|
1,155,423
|
8,422
|
7
|
26.6
|
User I/O
|
db file scattered read
|
30,541
|
660
|
22
|
2.1
|
User I/O
|
gc current block 2-way
|
900,865
|
538
|
1
|
1.7
|
Cluster
|
gc cr grant 2-way
|
467,627
|
244
|
1
|
.8
|
Cluster
|
對於IO類型的等待事件來講,好比常見的db file sequential read平均等待時間通常不要超過10ms,這是根據當前硬盤的機械結構、轉速等得出的一個經驗值,由於單塊10000轉的普通磁盤,尋道時間在7-10ms左右。固然,若是考慮存儲緩存、文件系統緩存、IO大小等狀況,這個值通常在4-7ms之間;同時必須是IO系統在正常的iops(每秒的io次數,用於衡量存儲併發吞量)下才有意義。若是超過經驗值不少,就要分析具體的緣由了,多是存儲的緩存功能沒有啓用、raid組中的磁盤損壞、不合理的raid級別等各類緣由;固然也有多是系統io負載過大,存儲的負擔較重,若是是這種狀況就須要給合應用的io量(物理讀與邏輯讀),特別是sql的io狀況來分析了。服務器
Event
|
Waits
|
Time(s)
|
Avg wait (ms)
|
% DB time
|
Wait Class
|
db file sequential read
|
561,555
|
37,163
|
66
|
34.73
|
User I/O
|
read by other session
|
405,945
|
20,251
|
50
|
18.92
|
User I/O
|
log file sync
|
30,655
|
15,101
|
493
|
14.11
|
Commit
|
direct path read
|
171,963
|
12,254
|
71
|
11.45
|
User I/O
|
DB CPU
|
9,907
|
9.26
|
前面談的都是「時間」,下面咱們來談一下次數,同時做爲本文的結束。首先,一些latch相關的等待事件,與latch中的sleep的次數相一致!好比library cache lock/pin、latch:shared pool等。好比:網絡
Event
|
Waits
|
%Time -outssession |
Total Wait Time (s)架構 |
Avg wait (ms) |
Waits /txn |
rdbms ipc reply |
1,622
|
0.00
|
1
|
0
|
0.05
|
latch: cache buffers chains |
3,941
|
0.00
|
1
|
0
|
0.12
|
Latch Name |
Get Requests |
Misses
|
Sleeps
|
Spin Gets |
Sleep1
|
Sleep2
|
Sleep3
|
cache buffers chains |
3,686,756,120
|
7,504,592
|
3,941
|
7,505,392
|
0
|
0
|
Event
|
Waits
|
Time(s)
|
Avg Wait(ms) |
% Total Call Time |
Wait Class |
CPU time |
|
17,217
|
|
54.5
|
|
db file sequential read |
1,155,423
|
8,422
|
7
|
26.6
|
User I/O |
db file scattered read |
30,541
|
660
|
22
|
2.1
|
User I/O |
gc current block 2-way |
900,865
|
538
|
1
|
1.7
|
Cluster
|
gc cr grant 2-way |
467,627
|
244
|
1
|
.8
|
Cluster
|
Operating System Statistics
Statistic
|
Total
|
NUM_LCPUS
|
0
|
NUM_VCPUS
|
0
|
AVG_BUSY_TIME
|
149,127
|
AVG_IDLE_TIME
|
211,742
|
AVG_IOWAIT_TIME
|
40,260
|
AVG_SYS_TIME
|
14,015
|
AVG_USER_TIME
|
135,004
|
BUSY_TIME
|
2,387,903
|
IDLE_TIME
|
3,389,758
|
IOWAIT_TIME
|
646,085
|
SYS_TIME
|
225,900
|
USER_TIME
|
2,162,003
|
LOAD
|
0
|
OS_CPU_WAIT_TIME
|
2,474,600
|
RSRC_MGR_CPU_WAIT_TIME
|
0
|
PHYSICAL_MEMORY_BYTES
|
49,123,688,448
|
NUM_CPUS
|
16
|
NUM_CPU_CORES
|
8
|
Avg global enqueue get time (ms):
|
2.5
|
Avg global cache cr block receive time (ms):
|
172.2
|
Avg global cache current block receive time (ms):
|
6.6
|
Avg global cache cr block build time (ms):
|
0.0
|
Avg global cache cr block send time (ms):
|
0.0
|
Global cache log flushes for cr blocks served %:
|
13.6
|
Avg global cache cr block flush time (ms):
|
0.8
|
Avg global cache current block pin time (ms):
|
0.2
|
Avg global cache current block send time (ms):
|
0.0
|
Global cache log flushes for current blocks served %:
|
0.3
|
Avg global cache current block flush time (ms):
|
3.2
|
這些值的官方數字從幾ms到10ms不等,但咱們這裏的Avg global cache cr block receive time (ms)達到了驚人的172.2ms,這個指標表示,Oracle實例接收全局的CR塊(一致性讀數據塊)的平均時間,這表示RAC中,各個節點間的熱塊急用是至關嚴重,須要在底層打散IO或者調整應用,減小總的IO量,並下降各個節點訪問相同數據塊的機率。具體的打散IO熱點的技術,請參照其餘文檔。