rac 上面 global cache cr request 太大

[复制链接]
查看11 | 回复5 | 2008-2-13 12:43:03 | 显示全部楼层 |阅读模式
大家好,我是linux ,做的rac ,2个节点,做了statspack,发现
global cache cr request
请大家帮助分析一下。谢谢!
以下是其中一个的
statspack部分内容,多谢了
Top 5 Timed Events
~~~~~~~~~~~~~~~~~~
% Total
Event
WaitsTime (s) Ela Time
-------------------------------------------- ------------ ----------- --------
PL/SQL lock timer
6,59738,07971.12
CPU time
4,995 9.33
db file scattered read
907,327 4,047 7.56
db file sequential read
417,822 1,654 3.09
global cache cr request
4,473,161 1,523 2.84

-------------------------------------------------------------
Cluster Statistics for DB: sidInstance: sid2Snaps: 341 -382
Global Cache Service - Workload Characteristics
-----------------------------------------------
Ave global cache get time (ms):
0.3
Ave global cache convert time (ms):
0.8
Ave build time for CR block (ms):
0.0
Ave flush time for CR block (ms):
0.8
Ave send time for CR block (ms):
0.0
Ave time to process CR block request (ms):
0.8
Ave receive time for CR block (ms):
0.7
Ave pin time for current block (ms):
0.1
Ave flush time for current block (ms):
0.1
Ave send time for current block (ms):
0.0
Ave time to process current block request (ms):
0.3
Ave receive time for current block (ms):
0.8
Global cache hit ratio:
3.3
Ratio of current block defers:
0.0
% of messages sent for buffer gets:
3.4
% of remote buffer gets:
0.1
Ratio of I/O for coherence:
1.0
Ratio of local vs remote work:
22.6
Ratio of fusion vs physical writes:
0.1
Global Enqueue Service Statistics
---------------------------------
Ave global lock get time (ms):
0.1
Ave global lock convert time (ms):
0.0
Ratio of global lock gets vs global lock releases: 1.0
GCS and GES Messaging statistics
--------------------------------
Ave message sent queue time (ms):
0.2
Ave message sent queue time on ksxp (ms):
0.2
Ave message received queue time (ms):
0.0
Ave GCS message process time (ms):
0.0
Ave GES message process time (ms):
0.0
% of direct sent messages:
10.4
% of indirect sent messages:
47.6
% of flow controlled messages:
42.0

-------------------------------------------------------------
GES Statistics for DB: sidInstance: sid2Snaps: 341 -382
Statistic
Total per Secondper Trans
--------------------------------- ---------------- ------------ ------------
dynamically allocated gcs resourc
0
0.0
0.0
dynamically allocated gcs shadows
0
0.0
0.0
flow control messages received
3
0.0
0.0
flow control messages sent
1
0.0
0.0
gcs ast xid
0
0.0
0.0
gcs blocked converts
200,772
2.8
1.1
gcs blocked cr converts
110,242
1.5
0.6
gcs compatible basts
2
0.0
0.0
gcs compatible cr basts (global)
12,236
0.2
0.1
gcs compatible cr basts (local)
59,135
0.8
0.3
gcs cr basts to PIs
0
0.0
0.0
gcs cr serve without current lock
0
0.0
0.0
gcs error msgs
0
0.0
0.0
gcs flush pi msgs
64,864
0.9
0.3
gcs forward cr to pinged instance
0
0.0
0.0
gcs immediate (compatible) conver
9,149
0.1
0.0
gcs immediate (null) converts
51,426
0.7
0.3
gcs immediate cr (compatible) con 78,737
1.1
0.4
gcs immediate cr (null) converts 8,249,707115.0 43.5
gcs msgs process time(ms)
106,329
1.5
0.6
gcs msgs received
10,218,737142.4 53.9
gcs out-of-order msgs
0
0.0
0.0
gcs pings refused
8,907
0.1
0.0
gcs queued converts
11
0.0
0.0
gcs recovery claim msgs
0
0.0
0.0
gcs refuse xid
0
0.0
0.0
gcs retry convert request
0
0.0
0.0
gcs side channel msgs actual
45,496
0.6
0.2
gcs side channel msgs logical
3,955,759 55.1 20.9
gcs write notification msgs
2,534
0.0
0.0
gcs write request msgs
104,107
1.5
0.5
gcs writes refused
19
0.0
0.0
ges msgs process time(ms)
3,747
0.1
0.0
ges msgs received
274,468
3.8
1.4
global posts dropped
0
0.0
0.0
global posts queue time
0
0.0
0.0
global posts queued
0
0.0
0.0
global posts requested
0
0.0
0.0
global posts sent
0
0.0
0.0
implicit batch messages received 563,815
7.9
3.0
implicit batch messages sent
434,926
6.1
2.3
lmd msg send time(ms)
878
0.0
0.0
lms(s) msg send time(ms)
45
0.0
0.0
messages flow controlled
3,460,794 48.2 18.3
messages received actual
3,089,534 43.1 16.3
messages received logical
10,492,170146.2 55.4
messages sent directly
856,097 11.9
4.5
messages sent indirectly
3,915,898 54.6 20.7
msgs causing lmd to send msgs
95,259
1.3
0.5
msgs causing lms(s) to send msgs 102,359
1.4
0.5
msgs received queue time (ms)
399,426
5.6
2.1
msgs received queued
10,492,727146.2 55.4
msgs sent queue time (ms)
826,911 11.5
4.4
msgs sent queue time on ksxp (ms)
432,366
6.0
2.3
msgs sent queued
3,916,433 54.6 20.7
msgs sent queued on ksxp
2,426,985 33.8 12.8
GES Statistics for DB: sidInstance: sid2Snaps: 341 -382
Statistic
Total per Secondper Trans
--------------------------------- ---------------- ------------ ------------
process batch messages received
1,213,803 16.9
6.4
process batch messages sent
875,611 12.2
4.6

-------------------------------------------------------------
Wait Events for DB: sidInstance: sid2Snaps: 341 -382
-> 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 waitWaits
Event
Waits Timeouts Time (s) (ms) /txn
---------------------------- ------------ ---------- ---------- ------ --------
PL/SQL lock timer
6,5976,597 38,079 57720.0
db file scattered read
907,327
04,04744.8
db file sequential read 417,822
01,65442.2
global cache cr request 4,473,161728,0051,5230 23.6
SQL*Net break/reset to clien105,658
075470.6
library cache pin
1,9712437243670.0
DFS lock handle
31,064551318 100.2
log file sync
28,651 7816460.2
control file parallel write28,778
013450.2
name-service call wait
5381351342480.0
control file sequential read116,114
012710.6
PX Deq: Parse Reply
1,708541 93 550.0
process startup
334
0 812430.0
PX qref latch
96 80 798210.0
IPC send completion sync
168,477 50,929 7200.9
db file parallel read
9,890
0 7170.1
global cache null to x
134,982 67,544 7110.7
global cache open x
255,763124,202 6801.4
log file sequential read
3,395
0 65 190.0
enqueue
51,504 39 4010.3
PX Deq: Execute Reply
2,108790 38 180.0
log file switch completion
290
6 321100.0
PX Deq Credit: send blkd 12,427993 3120.1
buffer busy waits
6,475
0 2740.0
buffer busy global CR
3,514
0 2670.0
PX Deq Credit: need buffer 19,656 16 2310.1
library cache lock
138,461
0 1200.7
PX Deq: Msg Fragment
10,7133,692 1010.1
latch free
3,0241,617
830.0
log file switch (checkpoint
12
6
86280.0
global cache s to x
49,037 12,398
600.3
log file parallel write 258,747258,133
301.4
PX Deq: reap credit
385,460277,286
302.0
global cache open s
12,1116,048
300.1
KJC: Wait for msg sends to c6,059 17
300.0
kksfbc child completion
148148
3 190.0
buffer busy global cache
63
0
2 390.0
global cache busy
61
0
2 390.0
log buffer space
4
1
25400.0
row cache lock
18,457
0
200.1
CGS wait for IPC msg
237,400232,400
101.3
PX Deq: Join ACK
1,945668
110.0
ksxr poll remote instances139,645 99,423
100.7
log file single write
540
0
110.0
SQL*Net more data to client33,661
0
100.2
global cache null to s
2,2521,126
100.0
PX Deq: Signal ACK
1,529714
000.0
global cache freelist wait
1
1
02040.0
direct path read
135,355
0
000.7
Wait Events for DB: sidInstance: sid2Snaps: 341 -382
-> 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 waitWaits
Event
Waits Timeouts Time (s) (ms) /txn
---------------------------- ------------ ---------- ---------- ------ --------
local write wait
57
0
030.0
LGWR wait for redo copy
7,123
0
000.0
db file parallel write
10,454
0
000.1
db file single write
86
0
010.0
undo segment extension
52,216 52,213
000.3
direct path write
18,743
0
000.1
library cache load lock
5
0
030.0
ges inquiry response
152
0
000.0
async disk IO
4,247
0
000.0
slave TJ process wait
1
1
0 120.0
PX Deq: Table Q Sample
22
4
000.0
PX Deq: Table Q qref
31 16
000.0
kjctssqmg: quick message sen 15
4
000.0
direct path read (lob)
6
0
000.0
lock escalate retry
23 22
000.0
buffer deadlock
5
5
000.0
SQL*Net message from client 1,934,950
02,281,163 1179 10.2
pipe get
191,628191,628770,435 40201.0
queue messages
73,651 73,444524,855 71260.4
gcs remote message
4,549,0971,679,696139,821 31 24.0
ges remote message
1,789,4071,499,174 70,061 399.4
wakeup time manager
2,2852,285 67,317294610.0
PX Idle Wait
22,997 20,738 51,248 22280.1
jobq slave wait
3,6583,595 10,907 29820.0
PX Deq: Execution Msg
38,563 17,9188,1642120.2
PX Deq: Table Q Normal
25,603 27 1610.1
SQL*Net message to client 1,934,933
0
20 10.2
SQL*Net more data from clien6,650
0
200.0

-------------------------------------------------------------
Background Wait Events for DB: sidInstance: sid2Snaps: 341 -382
-> ordered by wait time desc, waits desc (idle events last)

Avg

Total Wait waitWaits
Event
Waits Timeouts Time (s) (ms) /txn
---------------------------- ------------ ---------- ---------- ------ --------
db file scattered read
59,390
050280.3
control file parallel write28,770
013450.2
control file sequential read109,530
012210.6
log file sync
858 68 81 940.0
log file sequential read
3,395
0 65 190.0
global cache cr request 228,586
0 5601.2
process startup
133
0 513820.0
db file parallel read
4,054
0 3690.0
enqueue
9,046 36 2930.0
db file sequential read
19,354
0 1610.1
DFS lock handle
12,371
3 1110.1
log file parallel write 258,747258,133
301.4
CGS wait for IPC msg
237,399232,399
101.3
ksxr poll remote instances139,617 99,409
100.7
log file single write
540
0
110.0
latch free
565119
110.0
direct path read
127,008
0
000.7
LGWR wait for redo copy
7,123
0
000.0
db file parallel write
10,454
0
000.1
db file single write
82
0
010.0
global cache open x
389
0
000.0
buffer busy waits
64
0
000.0
direct path write
18,635
0
000.1
ges inquiry response
152
0
000.0
row cache lock
26
0
000.0
async disk IO
4,225
0
000.0
global cache null to x
38
0
000.0
KJC: Wait for msg sends to c
8
0
010.0
library cache lock
77
0
000.0
global cache s to x
56
0
000.0
kjctssqmg: quick message sen 15
4
000.0
global cache open s
4
0
000.0
rdbms ipc message
1,282,045706,220540,9544226.8
gcs remote message
4,549,0941,679,692139,821 31 24.0
ges remote message
1,789,3911,499,172 70,061 399.4
pmon timer
24,172 24,168 70,039 28980.1
smon timer
469179 67,562 ######0.0
回复

使用道具 举报

千问 | 2008-2-13 12:43:03 | 显示全部楼层
你提到的global cache cr request 并不算太严重,请检查系统中是否有
'buffer busy due to global cache' or 'global cache lock busy'
这样的等待事件出现
你的Oracle的版本是??
另外你需要重点关注如下2个wait event:
PL/SQL lock timer 6,597 38,079 71.12
db file scattered read 907,327 4,047 7.56



回复

使用道具 举报

千问 | 2008-2-13 12:43:03 | 显示全部楼层
查看一下v$latch,v$latch_children,看有没有library cache lock/pin的?
还有,把统计SQL语句的那些STATSPACK信息放上来看看。
PL/SQL LOCK TIMER很可能是SHAREDPOOL里面有LOCK/PIN。
回复

使用道具 举报

千问 | 2008-2-13 12:43:03 | 显示全部楼层
'buffer busy due to global cache' or 'global cache lock busy'
是在statspack报告里么
有global cache busy
buffer busy global cache
只有这2个还不高都是60多

我的数据库db 9204

PL/SQL lock timer 6,597 38,079 71.12 ,这主要是什么事件呀?
另外,但是一样的系统,在测试环境就比正式环境快很多,唯一的区别就算正式环境是rac。
回复

使用道具 举报

千问 | 2008-2-13 12:43:03 | 显示全部楼层
最初由 shashouwang 发布
[B]
PL/SQL lock timer 6,597 38,079 71.12 ,这主要是什么事件呀?
另外,但是一样的系统,在测试环境就比正式环境快很多,唯一的区别就算正式环境是rac。 [/B]

检查你的pl/sql应用中是否有使用dbms_lock.sleep休眠的
回复

使用道具 举报

千问 | 2008-2-13 12:43:03 | 显示全部楼层
最初由 shashouwang 发布
[B]'buffer busy due to global cache' or 'global cache lock busy'
是在statspack报告里么
有global cache busy
buffer busy global cache
只有这2个还不高都是60多

我的数据库db 9204
[/B]

我只能猜测,你有可能遇到了bug,但不一定,你提供的信息太少,建议你到metalink上自己查一下,或提供更完整的信息咨询Oracle工程师.
最好提供版本+平台,补丁列表+alert错误/警告信息+hang/wait现象
.
有一个bug,你可以参考一下看看是不是和你的现象一样
Bug 3588448Waits for 'global cache cr request' on RAC if UDP overflow occurs
回复

使用道具 举报

您需要登录后才可以回帖 登录 | 立即注册

本版积分规则

主题

0

回帖

4882万

积分

论坛元老

Rank: 8Rank: 8

积分
48824836
热门排行