Know GCS AND GES structure size in shared pool

RAC环境中共享池很大一部分被gcs和ges资源所占用,一般来说这些资源对象都是永久的(perm)的,所以我们无法期待LRU或flush shared_pool操作能够清理这些资源。

在使用大缓存(large buffer cache)的RAC实例环境中,查询v$sgastat内存动态性能视图时总是能发现’gcs resources’、’gcs shadows’、’ ges resource’、’ges enqueues ‘这些组件占用了共享池中的大量内存,为了避免shared pool出现著名的ORA-04031错误,Oracle推荐在RAC环境中设置较大的shared_pool_size初始化参数,此外显示地设置较大的GCS和GES资源结构的初始化分配数(INITIAL_ALLOCATION)也有利于避免ORA-4031。

这些控制GES和GCS资源结构初始化分配数量的参数主要包括:

  • _gcs_resources  number of gcs resources to be allocated GCS Resources Number of GCS resource structures determined by
    _gcs_resources parameter
    Stored in segmented array
    Externalized in X$KJBR
    Number of free GCS resource structures in X$KJBRFX
  • _gcs_shadow_locks number of pcm shadow locks to be allocated GCS Enqueues (Shadows/Clients) Number of GCS enqueue structures determined by  _gcs_shadow_locks parameter Stored in segmented array
    Externalized in X$KJBL
    Number of free GCS enqueue structures in X$KJBLFX
  • _lm_ress number of resources configured for cluster database LM_RESS controls the number of resources that can be locked by each lock manager instance. These resources include lock resources allocated for DML, DDL (data dictionary locks), data dictionary, and library cache locks plus the file and log management locks. Stored in heap
    Externalized in X$KJIRFT
  • _lm_locks number of enqueues configured for cluster database Stored in segmented array
    Externalized in X$KJILKFT

为了更好地在RAC环境中设置shared_pool_size共享池的大小(手动设置该参数并不会disable AMM or ASMM),我们很有必要评估大量初始化分配的全局资源本身将占用shared pool多大的空间。

我们可以通过v$resource_limit视图了解这些GES、GCS全局资源的分配情况:

SQL> select * from v$version;

BANNER
--------------------------------------------------------------------------------
Oracle Database 11g Enterprise Edition Release 11.2.0.2.0 - 64bit Production
PL/SQL Release 11.2.0.2.0 - Production
CORE    11.2.0.2.0      Production
TNS for Linux: Version 11.2.0.2.0 - Production
NLSRTL Version 11.2.0.2.0 - Production

SQL> select * from global_name;

GLOBAL_NAME
--------------------------------------------------------------------------------
www.askmaclean.com



SQL> select * from v$resource_limit where resource_name in ('gcs_resources', 'gcs_shadows','ges_ress','ges_locks'); 

RESOURCE_NAME                  CURRENT_UTILIZATION MAX_UTILIZATION INITIAL_ALLOCATION        LIMIT_VALUE
------------------------------ ------------------- --------------- ------------------------- ------------------
ges_ress                                      7223            7486    1000000                 UNLIMITED
ges_locks                                     4944            5027    1000000                 UNLIMITED
gcs_resources                                 4021            4021     114466                    114466
gcs_shadows                                   3925            3925     114466                    114466

可以通过v$sgastat视图了解这些全局资源占用了多少空间:

select *
  from v$sgastat
 where name in
       ('ges resource ', 'ges enqueues', 'gcs resources', 'gcs shadows');

POOL         NAME                            BYTES
------------ -------------------------- ----------
shared pool  gcs resources                16483232
shared pool  gcs shadows                  11904560
shared pool  ges enqueues                 47809680
shared pool  ges resource                288405768

单个gcs_resources结构大约占用120 bytes
单个gcs_shadows 结构大约占用72 bytes
单个ges_resource 结构大约占用288 bytes

我们可以使用一下初步估算GES、GCS资源结构将至少占用多大的共享池资源:

‘gcs_resources’ = initial_allocation * 120 bytes = “_gcs_resources parameter” * 120 bytes
‘gcs_shadows’ = initial_allocation * 72 bytes = “_gcs_shadow_locks parameter” * 72 bytes
‘ges_resource’= initial_allocation * 288 bytes = “_lm_ress parameter ” * 288 bytes

注意这里计算出的仅仅是理论的最小值,实际值因为内存分配的机制所以必然会远大于计算值

如上例中 gcs resources = 114466 * 120 =13735920 << 实际值的16483232
gcs_shadows = 114466 * 72 = 8241552 << 实际值的11904560
ges_resource = 1000000 * 288 = 288000000 < 实际的288405768

一般来说我们将计算值 * 160% 后可以得出一个较为客观的估算值。

注意以上公式只是为我们在RAC环境中调优共享池的大小提供参考的依据。当我们观察v$resource_limit视图并认为需要提高GES、GSC资源的初始化分配数目时,可以参照上述方式估算出必要的shared_pool_size或sga_target大小。

了解你所不知道的SMON功能(六):Instance Recovery

SMON的作用还包括RAC环境中的Instance Recovery,注意虽然Instance Recovery可以翻做实例恢复,但实际上和我们口头所说的实例恢复是不同的。我们口头语言所说的实例恢复很大程度上是指Crash Recovery崩溃恢复,Instance Recovery与Crash Recovery是存在区别的:针对单实例(single instance)或者RAC中所有节点全部崩溃后的恢复,我们称之为Crash Recovery。而对于RAC中的某一个节点失败,存活节点(surviving instance)试图对失败节点线程上redo做应用的情况,我们称之为Instance Recovery。对于Crash Recovery更多的内容可见<还原真实的cache recovery>一文。

现象

Instance Recovery期间分别存在cache recovery和ges/gcs remaster2个recovery stage,注意这2个舞台的恢复是同时进行的。cache recovery的主角是存活节点上的SMON进程,SMON负责分发redo给slave进程。而实施ges/gcs remaster的是RAC专有进程LMON。

整个Reconfiuration的过程如下图:
rac_instance_recovery_reconfiguration
 
注意以上Crash Detected时数据库进入部分可用(Partial Availability)状态,从Freeze Lockdb开始None Availability,到IR applies redo即前滚时转换为Partial Availability,待前滚完成后会实施回滚,但是此时数据库已经进入完全可用(Full Availability)状态了,如下图:
 
oracledatabase12g_instance_recovery

The graphic illustrates the degree of database availability during each step of Oracle instance recovery: 

A.         Real Application Clusters is running on multiple nodes.

B.         Node failure is detected.

C.         The enqueue part of the GRD is reconfigured; resource management is redistributed to the surviving nodes. This operation occurs relatively quickly.

D.        The cache part of the GRD is reconfigured and SMON reads the redo log of the failed instance to identify the database blocks that it needs to recover.

E.         SMON issues the GRD requests to obtain all the database blocks it needs for recovery. After the requests are complete, all other blocks are accessible.

F.         The Oracle server performs roll forward recovery. Redo logs of the failed threads are applied to the database, and blocks are available right after their recovery is completed.

G.        The Oracle server performs rollback recovery. Undo blocks are applied to the database for all uncommitted transactions.

H.        Instance recovery is complete and all data is accessible.

Note: The dashed line represents the blocks identified in step 2 in the previous slide. Also, the dotted steps represent the ones identified in the previous slide.

我们来实际观察一下Instance Recovery的过程:

INST 1:
SQL> select * from v$version;
BANNER
--------------------------------------------------------------------------------
Oracle Database 11g Enterprise Edition Release 11.2.0.2.0 - 64bit Production
PL/SQL Release 11.2.0.2.0 - Production
CORE    11.2.0.2.0      Production
TNS for Linux: Version 11.2.0.2.0 - Production
NLSRTL Version 11.2.0.2.0 - Production
SQL> select * from global_name;
GLOBAL_NAME
--------------------------------------------------------------------------------
www.askmaclean.com
SQL> alter system set event='10426 trace name context forever,level 12' scope=spfile;  -- 10426 event Reconfiguration trace event
System altered.
SQL> startup force;
ORACLE instance started.
INST 2:
SQL> shutdown abort
ORACLE instance shut down.

=============================================================
========================alert.log============================
Reconfiguration started (old inc 4, new inc 6)
List of instances:
1 (myinst: 1)
 Global Resource Directory frozen
* dead instance detected - domain 0 invalid = TRUE
Communication channels reestablished
Master broadcasted resource hash value bitmaps
Non-local Process blocks cleaned out
LMS 0: 0 GCS shadows cancelled, 0 closed, 0 Xw survived
Set master node info
Submitted all remote-enqueue requests
Dwn-cvts replayed, VALBLKs dubious
All grantable enqueues granted
 Post SMON to start 1st pass IR
Instance recovery: looking for dead threads
Beginning instance recovery of 1 threads
parallel recovery started with 2 processes                 --2 recovery slave
Submitted all GCS remote-cache requests
Post SMON to start 1st pass IR
Fix write in gcs resources
Reconfiguration complete
Started redo scan
Completed redo scan
read 88 KB redo, 82 data blocks need recovery
Started redo application at
Thread 2: logseq 374, block 2, scn 54624376
Recovery of Online Redo Log: Thread 2 Group 4 Seq 374 Reading mem 0
Mem# 0: +DATA/prod/onlinelog/group_4.271.747100549
Mem# 1: +DATA/prod/onlinelog/group_4.272.747100553
Completed redo application of 0.07MB
Completed instance recovery at
Thread 2: logseq 374, block 178, scn 54646382
73 data blocks read, 83 data blocks written, 88 redo k-bytes read
Thread 2 advanced to log sequence 375 (thread recovery)
Redo thread 2 internally disabled at seq 375 (SMON)
ARC3: Creating local archive destination LOG_ARCHIVE_DEST_1: '/s01/arch/2_374_747100216.dbf' (thread 2 sequence 374) (PROD1)
Setting Resource Manager plan SCHEDULER[0x310B]:DEFAULT_MAINTENANCE_PLAN via scheduler window
Setting Resource Manager plan DEFAULT_MAINTENANCE_PLAN via parameter
ARC3: Closing local archive destination LOG_ARCHIVE_DEST_1: '/s01/arch/2_374_747100216.dbf' (PROD1)
2011-06-27 22:19:29.280000 +08:00
Archived Log entry 792 added for thread 2 sequence 374 ID 0x9790ab2 dest 1:
ARC0: Creating local archive destination LOG_ARCHIVE_DEST_1: '/s01/arch/2_375_747100216.dbf' (thread 2 sequence 375) (PROD1)
2011-06-27 22:19:30.336000 +08:00
ARC0: Archiving disabled thread 2 sequence 375
ARC0: Closing local archive destination LOG_ARCHIVE_DEST_1: '/s01/arch/2_375_747100216.dbf' (PROD1)
Archived Log entry 793 added for thread 2 sequence 375 ID 0x9790ab2 dest 1:
minact-scn: Master considers inst:2 dead

==================================================================
===========================smon trace begin=======================

*** 2011-06-27 22:19:28.279
2011-06-27 22:19:28.279849 : Start recovery for domain=0, valid=0, flags=0x0
Successfully allocated 2 recovery slaves
Using 67 overflow buffers per recovery slave
Thread 2 checkpoint: logseq 374, block 2, scn 54624376
cache-low rba: logseq 374, block 2
on-disk rba: logseq 374, block 178, scn 54626382
start recovery at logseq 374, block 2, scn 54624376
Instance recovery not required for thread 1
*** 2011-06-27 22:19:28.487
Started writing zeroblks thread 2 seq 374 blocks 178-185
*** 2011-06-27 22:19:28.487
Completed writing zeroblks thread 2 seq 374
==== Redo read statistics for thread 2 ====
Total physical reads (from disk and memory): 4096Kb
-- Redo read_disk statistics --
Read rate (ASYNC): 88Kb in 0.18s => 0.48 Mb/sec
Longest record: 8Kb, moves: 0/186 (0%)
Longest LWN: 33Kb, moves: 0/47 (0%), moved: 0Mb
Last redo scn: 0x0000.0341884d (54626381)
----------------------------------------------
----- Recovery Hash Table Statistics ---------
Hash table buckets = 262144
Longest hash chain = 1
Average hash chain = 82/82 = 1.0
Max compares per lookup = 1
Avg compares per lookup = 248/330 = 0.8
----------------------------------------------
*** 2011-06-27 22:19:28.489
KCRA: start recovery claims for 82 data blocks
*** 2011-06-27 22:19:28.526
KCRA: blocks processed = 82/82, claimed = 81, eliminated = 1
2011-06-27 22:19:28.526088 : Validate domain 0
**************** BEGIN RECOVERY HA STATS  ****************

I'm the recovery instance
smon posted (1278500359646), recovery started 0.027 secs,(1278500359673)
domain validated 0.242 secs (1278500359888)
claims opened 70, claims converted 11, claims preread 0
****************  END RECOVERY HA STATS  *****************
2011-06-27 22:19:28.526668 : Validated domain 0, flags = 0x0
*** 2011-06-27 22:19:28.556
Recovery of Online Redo Log: Thread 2 Group 4 Seq 374 Reading mem 0
*** 2011-06-27 22:19:28.560
Completed redo application of 0.07MB
*** 2011-06-27 22:19:28.569
Completed recovery checkpoint
----- Recovery Hash Table Statistics ---------
Hash table buckets = 262144
Longest hash chain = 1
Average hash chain = 82/82 = 1.0
Max compares per lookup = 1
Avg compares per lookup = 330/330 = 1.0
----------------------------------------------
*** 2011-06-27 22:19:28.572 5401 krsg.c
Acquiring RECOVERY INFO PING latch from [krsg.c:5401] IX0
*** 2011-06-27 22:19:28.572 5401 krsg.c
Successfully acquired RECOVERY INFO PING latch IX+
*** 2011-06-27 22:19:28.572 5406 krsg.c
Freeing RECOVERY INFO PING latch from [krsg.c:5406] IX0
*** 2011-06-27 22:19:28.572 5406 krsg.c
Successfully freed RECOVERY INFO PING latch IX-
krss_sched_work: Prod archiver request from process SMON (function:0x2000)
krss_find_arc: Evaluating ARC3 to receive message (flags 0x0)
krss_find_arc: Evaluating ARC0 to receive message (flags 0x0)
krss_find_arc: Evaluating ARC1 to receive message (flags 0xc)
krss_find_arc: Evaluating ARC2 to receive message (flags 0x2)
krss_find_arc: Selecting ARC2 to receive REC PING message
*** 2011-06-27 22:19:28.572 3093 krsv.c
krsv_send_msg: Sending message to process ARC2
*** 2011-06-27 22:19:28.572 1819 krss.c
krss_send_arc: Sent message to ARC2 (message:0x2000)
Recovery sets nab of thread 2 seq 374 to 178 with 8 zeroblks
Retrieving log 4
pre-aal: xlno:4 flno:0 arf:0 arb:2 arh:2 art:4
Updating log 3 thread 2 sequence 375
Previous log 3 thread 2 sequence 0
Updating log 4 thread 2 sequence 374
Previous log 4 thread 2 sequence 374
post-aal: xlno:4 flno:0 arf:3 arb:2 arh:2 art:3
krss_sched_work: Prod archiver request from process SMON (function:0x1)
krss_find_arc: Evaluating ARC3 to receive message (flags 0x0)
krss_find_arc: Selecting ARC3 to receive message
*** 2011-06-27 22:19:28.589 3093 krsv.c
krsv_send_msg: Sending message to process ARC3
*** 2011-06-27 22:19:28.589 1819 krss.c
krss_send_arc: Sent message to ARC3 (message:0x1)
Retrieving log 2
Kicking thread 1 to switch logfile
Retrieving log 4
Retrieving log 3
krss_sched_work: Prod archiver request from process SMON (function:0x1)
krss_find_arc: Evaluating ARC0 to receive message (flags 0x0)
krss_find_arc: Selecting ARC0 to receive message
*** 2011-06-27 22:19:28.599 3093 krsv.c
krsv_send_msg: Sending message to process ARC0
*** 2011-06-27 22:19:28.599 1819 krss.c
krss_send_arc: Sent message to ARC0 (message:0x1)
*** 2011-06-27 22:19:28.599 838 krsv.c
krsv_dpga: Waiting for pending I/O to complete
*** 2011-06-27 22:19:29.304
krss_sched_work: Prod archiver request from process SMON (function:0x1)
krss_find_arc: Evaluating ARC1 to receive message (flags 0xc)
krss_find_arc: Selecting ARC1 to receive message
*** 2011-06-27 22:19:29.304 3093 krsv.c
krsv_send_msg: Sending message to process ARC1
*** 2011-06-27 22:19:29.304 1819 krss.c
krss_send_arc: Sent message to ARC1 (message:0x1)
SMON[INST-TXN-RECO]:about to recover undo segment 11 status:3 inst:2
SMON[INST-TXN-RECO]: mark undo segment 11 as available status:2 ret:0
SMON[INST-TXN-RECO]:about to recover undo segment 12 status:3 inst:2
SMON[INST-TXN-RECO]: mark undo segment 12 as available status:2 ret:0
SMON[INST-TXN-RECO]:about to recover undo segment 13 status:3 inst:2
SMON[INST-TXN-RECO]: mark undo segment 13 as available status:2 ret:0
SMON[INST-TXN-RECO]:about to recover undo segment 14 status:3 inst:2
SMON[INST-TXN-RECO]: mark undo segment 14 as available status:2 ret:0
SMON[INST-TXN-RECO]:about to recover undo segment 15 status:3 inst:2
SMON[INST-TXN-RECO]: mark undo segment 15 as available status:2 ret:0
SMON[INST-TXN-RECO]:about to recover undo segment 16 status:3 inst:2
SMON[INST-TXN-RECO]: mark undo segment 16 as available status:2 ret:0
SMON[INST-TXN-RECO]:about to recover undo segment 17 status:3 inst:2
SMON[INST-TXN-RECO]: mark undo segment 17 as available status:2 ret:0
SMON[INST-TXN-RECO]:about to recover undo segment 18 status:3 inst:2
SMON[INST-TXN-RECO]: mark undo segment 18 as available status:2 ret:0
SMON[INST-TXN-RECO]:about to recover undo segment 19 status:3 inst:2
SMON[INST-TXN-RECO]: mark undo segment 19 as available status:2 ret:0
SMON[INST-TXN-RECO]:about to recover undo segment 20 status:3 inst:2
SMON[INST-TXN-RECO]: mark undo segment 20 as available status:2 ret:0
*** 2011-06-27 22:19:43.299
* kju_tsn_aff_drm_pending TRACEUD: called with tsn x2, dissolve 0
* kju_tsn_aff_drm_pending TRACEUD: tsn_pkey = x2.1
* >> RM REQ QS ---:
single window RM request queue is empty
multi-window RM request queue is empty
* Global DRM state ---:
There is no dynamic remastering
RM lock state = 0
pkey 2.1 undo 1 stat 0 masters[32768, 1->1] reminc 4 RM# 1
flg x0 type x0 afftime x36e6e3a8
nreplays by lms 0 = 0
* kju_tsn_aff_drm_pending TRACEUD: matching request not found on swin queue
* kju_tsn_aff_drm_pending TRACEUD: pp found, stat x0
* kju_tsn_aff_drm_pending TRACEUD: 2 return true
*** 2011-06-27 22:22:18.333
* kju_tsn_aff_drm_pending TRACEUD: called with tsn x2, dissolve 0
* kju_tsn_aff_drm_pending TRACEUD: tsn_pkey = x2.1
* >> RM REQ QS ---:
single window RM request queue is empty
multi-window RM request queue is empty
* Global DRM state ---:
There is no dynamic remastering
RM lock state = 0
pkey 2.1 undo 1 stat 0 masters[32768, 1->1] reminc 4 RM# 1
flg x0 type x0 afftime x36e6e3a8
nreplays by lms 0 = 0
* kju_tsn_aff_drm_pending TRACEUD: matching request not found on swin queue
* kju_tsn_aff_drm_pending TRACEUD: pp found, stat x0
* kju_tsn_aff_drm_pending TRACEUD: 2 return true
*** 2011-06-27 22:24:53.365
* kju_tsn_aff_drm_pending TRACEUD: called with tsn x2, dissolve 0
* kju_tsn_aff_drm_pending TRACEUD: tsn_pkey = x2.1
* >> RM REQ QS ---:
single window RM request queue is empty
multi-window RM request queue is empty
* Global DRM state ---:
There is no dynamic remastering
RM lock state = 0
pkey 2.1 undo 1 stat 0 masters[32768, 1->1] reminc 4 RM# 1
flg x0 type x0 afftime x36e6e3a8
nreplays by lms 0 = 0
* kju_tsn_aff_drm_pending TRACEUD: matching request not found on swin queue
* kju_tsn_aff_drm_pending TRACEUD: pp found, stat x0
* kju_tsn_aff_drm_pending TRACEUD: 2 return true
========================================================================
==============================lmon trace begin==========================
 *** 2011-06-27 22:19:27.748
kjxgmpoll reconfig instance map: 1
*** 2011-06-27 22:19:27.748
kjxgmrcfg: Reconfiguration started, type 1
CGS/IMR TIMEOUTS:
CSS recovery timeout = 31 sec (Total CSS waittime = 65)
IMR Reconfig timeout = 75 sec
CGS rcfg timeout = 85 sec
kjxgmcs: Setting state to 4 0.
*** 2011-06-27 22:19:27.759
Name Service frozen
kjxgmcs: Setting state to 4 1.
kjxgrdecidever: No old version members in the cluster
kjxgrssvote: reconfig bitmap chksum 0x2137452d cnt 1 master 1 ret 0
kjxgrpropmsg: SSMEMI: inst 1 - no disk vote
kjxgrpropmsg: SSVOTE: Master indicates no Disk Voting
2011-06-27 22:19:27.760783 : kjxgrDiskVote: nonblocking method is chosen
kjxggpoll: change poll time to 50 ms
2011-06-27 22:19:27.918847 : kjxgrDiskVote: Obtained RR update lock for sequence 5, RR seq 4
2011-06-27 22:19:28.023160 : kjxgrDiskVote: derive membership from CSS (no disk votes)
2011-06-27 22:19:28.023240 : proposed membership: 1
*** 2011-06-27 22:19:28.081
2011-06-27 22:19:28.081952 : kjxgrDiskVote: new membership is updated by inst 1, seq 6
2011-06-27 22:19:28.082073 : kjxgrDiskVote: bitmap: 1
CGS/IMR TIMEOUTS:
CSS recovery timeout = 31 sec (Total CSS waittime = 65)
IMR Reconfig timeout = 75 sec
CGS rcfg timeout = 85 sec
kjxgmmeminfo: can not invalidate inst 2
kjxgmps: proposing substate 2
kjxgmcs: Setting state to 6 2.
kjfmSendAbortInstMsg: send an abort message to instance 2
kjfmuin: inst bitmap 1
kjfmmhi: received msg from inst 1 (inc 2)
Performed the unique instance identification check
kjxgmps: proposing substate 3
kjxgmcs: Setting state to 6 3.
Name Service recovery started
Deleted all dead-instance name entries
kjxgmps: proposing substate 4
kjxgmcs: Setting state to 6 4.
Multicasted all local name entries for publish
Replayed all pending requests
kjxgmps: proposing substate 5
kjxgmcs: Setting state to 6 5.
Name Service normal
Name Service recovery done
*** 2011-06-27 22:19:28.191
kjxgmps: proposing substate 6
kjxgmcs: Setting state to 6 6.
kjxgmcs: total reconfig time 0.432 seconds (from 2895072218 to 2895072650)
kjxggpoll: change poll time to 600 ms
kjfmact: call ksimdic on instance (2)
2011-06-27 22:19:28.211846 :
********* kjfcrfg() called, BEGIN LMON RCFG *********
2011-06-27 22:19:28.211906 : * Begin lmon rcfg step KJGA_RCFG_BEGIN
* kjfcrfg: Resource broadcasting disabled
* kjfcrfg: kjfcqiora returned success
kjfcrfg: DRM window size = 4096->4096 (min lognb = 15)
2011-06-27 22:19:28.211954 :
Reconfiguration started (old inc 4, new inc 6)
TIMEOUTS:
Local health check timeout: 70 sec
Rcfg process freeze timeout: 70 sec
Remote health check timeout: 140 sec
Defer Queue timeout: 163 secs
CGS rcfg timeout: 85 sec
Synchronization timeout: 248 sec
DLM rcfg timeout: 744 sec
List of instances:
1 (myinst: 1)
Undo tsn affinity 1
OMF 0
2011-06-27 22:19:28.212394 : * Begin lmon rcfg step KJGA_RCFG_FREEZE

*** 2011-06-27 22:19:28.233
* published: inc 6, isnested 0, rora req 0,
rora start 0, rora invalid 0, (roram 32767), isrcvinst 1,
(rcvinst 1), isdbopen 1, drh 0, (myinst 1)
thread 1, isdbmounted 1, sid hash x0
* kjfcrfg: published bigns successfully
* Force-published at step 3
2011-06-27 22:19:28.233575 :  Global Resource Directory frozen
* roram 32767, rcvinst 1
* kjfc_thread_qry: instance 1 flag 3 thread 1 sid 0
* kjfcrfg: queried bigns successfully
inst 1
* kjfcrfg: single_instance_kjga = TRUE
asby init, 0/1/x2
asby returns, 0/1/x2/false
* Domain maps before reconfiguration:
*   DOMAIN 0 (valid 1): 1 2
* End of domain mappings
* dead instance detected - domain 0 invalid = TRUE
* Domain maps after recomputation:
*   DOMAIN 0 (valid 0): 1
* End of domain mappings
2011-06-27 22:19:28.235110 : * Begin lmon rcfg step KJGA_RCFG_COMM
2011-06-27 22:19:28.235242 : GSIPC:KSXPCB: msg 0xd8b84550 status 34, type 2, dest 2, rcvr 0
2011-06-27 22:19:28.235339 : GSIPC:KSXPCB: msg 0xd8b80180 status 34, type 2, dest 2, rcvr 1
Active Sendback Threshold = 50 %
Communication channels reestablished
2011-06-27 22:19:28.240076 : * Begin lmon rcfg step KJGA_RCFG_EXCHANGE
2011-06-27 22:19:28.240192 : * Begin lmon rcfg step KJGA_RCFG_ENQCLEANUP
Master broadcasted resource hash value bitmaps
2011-06-27 22:19:28.251474 :
Non-local Process blocks cleaned out
2011-06-27 22:19:28.251822 : * Begin lmon rcfg step KJGA_RCFG_CLEANUP
2011-06-27 22:19:28.265220 : * Begin lmon rcfg step KJGA_RCFG_TIMERQ
2011-06-27 22:19:28.265308 : * Begin lmon rcfg step KJGA_RCFG_DDQ
2011-06-27 22:19:28.265393 : * Begin lmon rcfg step KJGA_RCFG_SETMASTER
2011-06-27 22:19:28.271551 :
Set master node info
2011-06-27 22:19:28.271931 : * Begin lmon rcfg step KJGA_RCFG_ENQREPLAY
2011-06-27 22:19:28.275490 :  Submitted all remote-enqueue requests
2011-06-27 22:19:28.275596 : * Begin lmon rcfg step KJGA_RCFG_ENQDUBIOUS
Dwn-cvts replayed, VALBLKs dubious
2011-06-27 22:19:28.277223 : * Begin lmon rcfg step KJGA_RCFG_ENQGRANT
All grantable enqueues granted
2011-06-27 22:19:28.277992 : * Begin lmon rcfg step KJGA_RCFG_PCMREPLAY
2011-06-27 22:19:28.279234 :
2011-06-27 22:19:28.279255 :  Post SMON to start 1st pass IR               --SMON posted by LMON
2011-06-27 22:19:28.307890 :  Submitted all GCS cache requests             --IR acquires all gcs resource needed for recovery
2011-06-27 22:19:28.308038 : * Begin lmon rcfg step KJGA_RCFG_FIXWRITES
Post SMON to start 1st pass IR
Fix write in gcs resources
2011-06-27 22:19:28.313508 : * Begin lmon rcfg step KJGA_RCFG_END
2011-06-27 22:19:28.313720 :
2011-06-27 22:19:28.313733 :
Reconfiguration complete
*   domain 0 valid?: 0
* kjfcrfg: ask RMS0 to do pnp work
**************** BEGIN DLM RCFG HA STATS  ****************
Total dlm rcfg time (inc 6): 0.100 secs (1278500359581, 1278500359681)
Begin step .........: 0.001 secs (1278500359581, 1278500359582)
Freeze step ........: 0.020 secs (1278500359582, 1278500359602)
Remap step .........: 0.002 secs (1278500359602, 1278500359604)
Comm step ..........: 0.005 secs (1278500359604, 1278500359609)
Sync 1 step ........: 0.000 secs (0, 0)
Exchange step ......: 0.000 secs (1278500359609, 1278500359609)
Sync 2 step ........: 0.000 secs (0, 0)
Enqueue cleanup step: 0.011 secs (1278500359609, 1278500359620)
Sync pcm1 step .....: 0.000 secs (0, 0)
Cleanup step .......: 0.013 secs (1278500359620, 1278500359633)
Timerq step ........: 0.000 secs (1278500359633, 1278500359633)
Ddq step ...........: 0.000 secs (1278500359633, 1278500359633)
Set master step ....: 0.006 secs (1278500359633, 1278500359639)
Sync 3 step ........: 0.000 secs (0, 0)
Enqueue replay step : 0.004 secs (1278500359639, 1278500359643)
Sync 4 step ........: 0.000 secs (0, 0)
Enqueue dubious step: 0.001 secs (1278500359643, 1278500359644)
Sync 5 step ........: 0.000 secs (0, 0)
Enqueue grant step .: 0.001 secs (1278500359644, 1278500359645)
Sync 6 step ........: 0.000 secs (0, 0)
PCM replay step ....: 0.030 secs (1278500359645, 1278500359675)
Sync 7 step ........: 0.000 secs (0, 0)
Fixwrt replay step .: 0.003 secs (1278500359675, 1278500359678)
Sync 8 step ........: 0.000 secs (0, 0)
End step ...........: 0.001 secs (1278500359680, 1278500359681)
Number of replayed enqueues sent / received .......: 0 / 0
Number of replayed fusion locks sent / received ...: 0 / 0
Number of enqueues mastered before / after rcfg ...: 2217 / 2941
Number of fusion locks mastered before / after rcfg: 3120 / 5747
****************  END DLM RCFG HA STATS  *****************
*** 2011-06-27 22:19:36.589
kjxgfipccb: msg 0x0x7ff526139320, mbo 0x0x7ff526139310, type 19, ack 0, ref 0, stat 34
=====================================================================
============================lms trace begin==========================

*** 2011-06-27 22:38:54.663
2011-06-27 22:38:54.663764 :  0 GCS shadows cancelled, 0 closed, 0 Xw survived
2011-06-27 22:38:54.673539 :  5230 GCS resources traversed, 0 cancelled
2011-06-27 22:38:54.707671 :  9322 GCS shadows traversed, 0 replayed, 0 duplicates,
5183 not replayed, dissolve 0 timeout 0 RCFG(10) lms 0 finished replaying gcs resources
2011-06-27 22:38:54.709132 :  0 write requests issued in 384 GCS resources        --check past image
 0 PIs marked suspect, 0 flush PI msgs
2011-06-27 22:38:54.709520 :  0 write requests issued in 273 GCS resources
1 PIs marked suspect, 0 flush PI msgs
2011-06-27 22:38:54.709842 :  0 write requests issued in 281 GCS resources
0 PIs marked suspect, 0 flush PI msgs
2011-06-27 22:38:54.710159 :  0 write requests issued in 233 GCS resources
0 PIs marked suspect, 0 flush PI msgs
2011-06-27 22:38:54.710531 :  0 write requests issued in 350 GCS resources
lms 0 finished fixing gcs write protocol

Instance Recovery和普通的Crash Recovery最大的区别在于实例恢复过程中的GRD Frozen和对GES/GCS资源的Remaster,这部分工作主要由LMON进程完成,可以从以上trace中发现一些KJGA_RCFG_*形式的Reconfiguration步骤,它们的含义:

Reconfiguration Steps:
1.    KJGA_RCFG_BEGIN
LMON continuously polling for reconfiguration event. Once cgs reports a change in cluster membership,
LMON starts reconfiguration
2.    KJGA_RCFG_FREEZE
All processes acknowledges to the reconfiguration freeze before LMON continue 
3.    KJGA_RCFG_REMAP
Updates new instance map (kjfchsu), re-distributes resource mastership. Invalidate recovery domains
if reconfiguration is caused by instance death.
4.    KJGA_RCFG_COMM
Reinitialize communication channel
5.    KJGA_RCFG_EXCHANGE
Exchange of master information of gcs, ges and file affinity master
6.    KJGA_RCFG_ENQCLEANUP
Delete remote dead gcs/ges locks. Cancel converting gcs requests. 
7.    KJGA_RCFG_CLEANUP
Cleanup/remove ges resources
8.    KJGA_RCFG_TIMERQ
Restore relative timeout for enqueue locks on timeout queue
9.    KJGA_RCFG_DDQ
Clean out enqueue locks on deadlock queue
10.  KJGA_RCFG_SETMASTER
Update master info for each enqueue resources that need to be remastered.
11.  KJGA_RCFG_REPLAY
Replay enqueue locks
12.  KJGA_RCFG_ENQDUBIOUS
Invalidates ges resources without established value
13.  KJGA_RCFG_ENQGRANT
Grants all grantable ges lock requests
14.  KJGA_RCFG_REPLAY2
Enqueue reconfiguration complete. Post SMON to start instance recovery.  Starts replaying gcs resources.
15.  KJGA_RCFG_FIXWRITES2
Fix write state of gcs resources
16.  KJGA_RCFG_END
Unfreeze lock database

Instance Recovery相关的诊断事件
我们无法禁止Instance Recovery的发生,事实上一旦出现Instance Crash那么Instance Recovery就是必须的。
与Instance Recovery相关的诊断事件主要有10426和29717等:

    10426 – Reconfiguration trace event
10425 – Enqueue operations
10432 – Fusion activity
10429 – IPC tracing
oerr ora 10425
10425, 00000, "enable global enqueue operations event trace"
// *Document: NO
// *Cause:
// *Action: Dump trace for global enqueue operations.
oerr ora 10426
10426, 00000, "enable ges/gcs reconfiguration event trace"
// *Document: NO
// *Cause:
// *Action: Dump trace for ges/gcs reconfiguration.
oerr ora 10430
10430, 00000, "enable ges/gcs dynamic remastering event trace"
// *Document: NO
// *Cause:
// *Action: Dump trace for ges/gcs dynamic remastering.
oerr ora 10401
10401, 00000, "turn on IPC (ksxp) debugging"
// *Cause:
// *Action: Enables debugging code for IPC service layer (ksxp)
oerr ora 10708
10708, 00000, "print out trace information from the RAC buffer cache"
// *Cause: N/A
// *Action: THIS IS NOT A USER ERROR NUMBER/MESSAGE.  THIS DOES NOT NEED TO BE
//          TRANSLATED OR DOCUMENTED. IT IS USED ONLY FOR DEBUGGING.
oerr ora 29717
29717, 00000, "enable global resource directory freeze/unfreeze event trace"
// *Document: NO
// *Cause:
// *Action: Dump trace for global resource directory freeze/unfreeze.
diag RAC INSTANCE SHUTDOWN LMON
LMON will dump more informations to trace during reconfig and freeze.
event="10426 trace name context forever, level 8"
event="29717 trace name context forever, level 5"
or
event="10426 trace name context forever, level 12"
event="10430 trace name context forever, level 12"
event="10401 trace name context forever, level 8"
event="10046 trace name context forever, level 8"
event="10708 trace name context forever, level 15"
event="29717 trace name context forever, level 5"
see 29717  grd frozen trace

alter system set event='29717 trace name context forever, level 5' scope=spfile;
=========================================================================
============================lmon trace begin=============================
********* kjfcrfg() called, BEGIN LMON RCFG *********
2011-06-27 23:13:16.693089 : * Begin lmon rcfg step KJGA_RCFG_BEGIN
* kjfcrfg: Resource broadcasting disabled
* kjfcrfg: kjfcqiora returned success
kjfcrfg: DRM window size = 4096->4096 (min lognb = 15)
2011-06-27 23:13:16.693219 :
Reconfiguration started (old inc 4, new inc 6)
TIMEOUTS:
Local health check timeout: 70 sec
Rcfg process freeze timeout: 70 sec
Remote health check timeout: 140 sec
Defer Queue timeout: 163 secs
CGS rcfg timeout: 85 sec
Synchronization timeout: 248 sec
DLM rcfg timeout: 744 sec
List of instances:
1 (myinst: 1)
Undo tsn affinity 1
OMF 0
[FDB][start]
2011-06-27 23:13:16.701320 : * Begin lmon rcfg step KJGA_RCFG_FREEZE
[FACK][18711 not frozen]          --fack means acknowledge in advance
[FACK][18713 not frozen]
[FACK][18719 not frozen]
[FACK][18721 not frozen]
[FACK][18723 not frozen]
[FACK][18729 not frozen]
[FACK][18739 not frozen]
[FACK][18743 not frozen]
[FACK][18745 not frozen]
[FACK][18747 not frozen]
[FACK][18749 not frozen]
[FACK][18751 not frozen]
[FACK][18753 not frozen]
[FACK][18755 not frozen]
[FACK][18757 not frozen]
[FACK][18759 not frozen]
[FACK][18763 not frozen]
[FACK][18765 not frozen]
[FACK][18767 not frozen]
[FACK][18769 not frozen]
[FACK][18771 not frozen]
[FACK][18775 not frozen]
[FACK][18777 not frozen]
[FACK][18816 not frozen]
[FACK][18812 not frozen]
[FACK][18818 not frozen]
[FACK][18820 not frozen]
[FACK][18824 not frozen]
[FACK][18826 not frozen]
[FACK][18830 not frozen]
[FACK][18835 not frozen]
[FACK][18842 not frozen]
[FACK][18860 not frozen]
[FACK][18865 not frozen]
[FACK][18881 not frozen]
[FACK][18883 not frozen]
[FACK][18909 not frozen]
*** 2011-06-27 23:13:16.724
* published: inc 6, isnested 0, rora req 0,
rora start 0, rora invalid 0, (roram 32767), isrcvinst 0,
(rcvinst 32767), isdbopen 1, drh 0, (myinst 1)
thread 1, isdbmounted 1, sid hash x0
* kjfcrfg: published bigns successfully
* Force-published at step 3
2011-06-27 23:13:16.724764 :  Global Resource Directory frozen
* kjfc_qry_bigns: noone has the rcvinst established yet, set it to the highest open instance = 1
* roram 32767, rcvinst 1
* kjfc_thread_qry: instance 1 flag 3 thread 1 sid 0
* kjfcrfg: queried bigns successfully

=====================================================================
==========================lmd0 trace begin===========================
*** 2011-06-27 23:13:16.700
[FFCLI][frozen]
[FUFCLI][normal]

Under the Hoods of Cache Fusion, GES, GRD and GCS

•If I have a 100MB database, I can have a 100 MB buffer cache and I never have to go to the disk, right?
•How does Cache Fusion know where to get the block from?
•I’m confused about Global Cache Service (GCS), Global Resource Directory (GRD) and Global Enqueue Service (GES)
•We will understand how all these actually work

[Read more…]

Find Past Image in RAC Global Cache

Instance 1:

Start dump data blocks tsn: 0 file#:1 minblk 95753 maxblk 95753
Block dump from cache:
Dump of buffer cache at level 4 for tsn=0, rdba=4290057
BH (0x8df55108) file#: 1 rdba: 0x00417609 (1/95753) class: 1 ba: 0x8dc86000
set: 6 pool: 3 bsz: 8192 bsi: 0 sflg: 2 pwc: 58,28
dbwrid: 0 obj: 84318 objn: 84318 tsn: 0 afn: 1 hint: f
hash: [0x8df54308,0xd6cb7438] lru: [0x96ecccd8,0xd6e9a080]
ckptq: [NULL] fileq: [NULL] objq: [0xcedd4f18,0xcedd4f18] objaq: [0x96eccd10,0xcedd4f08]
use: [0xd6e1ee70,0xd6e1ee70] wait: [NULL]
st: READING md: EXCL tch: 0 le: 0x7bfa6000                  reading gc,associated with lock element 0x7bfa6000
flags: only_sequential_access
cr pin refcnt: 0 sh pin refcnt: 0
BH (0x8df54258) file#: 1 rdba: 0x00417609 (1/95753) class: 1 ba: 0x8dc72000
set: 6 pool: 3 bsz: 8192 bsi: 0 sflg: 2 pwc: 58,28
dbwrid: 0 obj: 84318 objn: 84318 tsn: 0 afn: 1 hint: f
hash: [0x96eccca0,0x8df551b8] lru: [0xd6e9a080,0x8df54a98]
lru-flags: moved_to_tail
ckptq: [NULL] fileq: [NULL] objq: [NULL] objaq: [NULL]
use: [0xd6e22f30,0xd6e22f30] wait: [NULL]
st: CR md: SHR tch: 0 le: (nil)
cr: [scn: 0x0.ac6456],[xid: 0x0.0.0],[uba: 0x0.0.0],[cls: 0x0.ac6456],[sfl: 0x2],[lc: 0x0.ac6451]
flags: only_sequential_access
cr pin refcnt: 0 sh pin refcnt: 0
BH (0x96eccbf0) file#: 1 rdba: 0x00417609 (1/95753) class: 1 ba: 0x960ec000
set: 6 pool: 3 bsz: 8192 bsi: 0 sflg: 2 pwc: 58,28
dbwrid: 0 obj: 84318 objn: 84318 tsn: 0 afn: 1 hint: f
hash: [0x8df54a60,0x8df54308] lru: [0x8df547a8,0x8df551f0]
obj-flags: object_ckpt_list
ckptq: [0x8eecba50,0x8df54ca0] fileq: [0xd6eb8370,0x8df679c8] objq: [0xcedd4f28,0xcedd4f28] objaq: [0xcedd4f08,0x8df55228]
  st: PI md: NULL tch: 1 le: 0x7bfa6000                        -- Past Image
cr: [scn: 0x0.ac6452],[xid: 0x0],[uba: 0x0],[cls: 0x0.ac6452],[sfl: 0x0]
flags: buffer_dirty remote_transfered
LRBA: [0x132.a1c.0] LSCN: [0x0.abb823] HSCN: [0x0.ac6451] HSUB: [2]
cr pin refcnt: 0 sh pin refcnt: 0
BH (0x8df549b0) file#: 1 rdba: 0x00417609 (1/95753) class: 1 ba: 0x8dc7c000
set: 6 pool: 3 bsz: 8192 bsi: 0 sflg: 2 pwc: 58,28
dbwrid: 0 obj: 84318 objn: 84318 tsn: 0 afn: 1 hint: f
hash: [0x8df53ea0,0x96eccca0] lru: [0x8df54340,0x8df544b8]
lru-flags: moved_to_tail
ckptq: [NULL] fileq: [NULL] objq: [NULL] objaq: [NULL]
st: CR md: NULL tch: 1 le: (nil)
cr: [scn: 0x0.ac643a],[xid: 0x0.0.0],[uba: 0x0.0.0],[cls: 0x0.ac643a],[sfl: 0x0],[lc: 0x0.0]
flags: remote_transfered
cr pin refcnt: 0 sh pin refcnt: 0
BH (0x8df53df0) file#: 1 rdba: 0x00417609 (1/95753) class: 1 ba: 0x8dc6c000
set: 6 pool: 3 bsz: 8192 bsi: 0 sflg: 2 pwc: 58,28
dbwrid: 0 obj: 84318 objn: 84318 tsn: 0 afn: 1 hint: f
hash: [0x8df54480,0x8df54a60] lru: [0x8df544b8,0x8df541c8]
lru-flags: moved_to_tail
ckptq: [NULL] fileq: [NULL] objq: [NULL] objaq: [NULL]
st: CR md: NULL tch: 1 le: (nil)
cr: [scn: 0x0.ac642a],[xid: 0x0.0.0],[uba: 0x0.0.0],[cls: 0x0.ac642a],[sfl: 0x2],[lc: 0x0.ac6426]
flags: only_sequential_access
cr pin refcnt: 0 sh pin refcnt: 0
BH (0x8df543d0) file#: 1 rdba: 0x00417609 (1/95753) class: 1 ba: 0x8dc74000
set: 6 pool: 3 bsz: 8192 bsi: 0 sflg: 2 pwc: 58,28
dbwrid: 0 obj: 84318 objn: 84318 tsn: 0 afn: 1 hint: f
hash: [0x8df54190,0x8df53ea0] lru: [0x8df54a98,0x8df53ed8]
lru-flags: moved_to_tail
ckptq: [NULL] fileq: [NULL] objq: [NULL] objaq: [NULL]
st: CR md: NULL tch: 1 le: (nil)
cr: [scn: 0x0.ac6427],[xid: 0x0.0.0],[uba: 0x0.0.0],[cls: 0x0.ac6427],[sfl: 0x0],[lc: 0x0.0]
flags: remote_transfered
cr pin refcnt: 0 sh pin refcnt: 0
BH (0x8df540e0) file#: 1 rdba: 0x00417609 (1/95753) class: 1 ba: 0x8dc70000
set: 6 pool: 3 bsz: 8192 bsi: 0 sflg: 2 pwc: 58,28
dbwrid: 0 obj: 84318 objn: 84318 tsn: 0 afn: 1 hint: f
hash: [0x92ec39c0,0x8df54480] lru: [0x8df53ed8,0x8eecc870]
lru-flags: moved_to_tail
ckptq: [NULL] fileq: [NULL] objq: [NULL] objaq: [NULL]
st: CR md: NULL tch: 1 le: (nil)
cr: [scn: 0x0.ac641a],[xid: 0x0.0.0],[uba: 0x0.0.0],[cls: 0x0.ac641a],[sfl: 0x0],[lc: 0x0.0]
flags: remote_transfered
cr pin refcnt: 0 sh pin refcnt: 0
Block dump from disk:
buffer tsn: 0 rdba: 0x00417609 (1/95753)
scn: 0x0000.00abb7cf seq: 0x01 flg: 0x06 tail: 0xb7cf0601
frmt: 0x02 chkval: 0xeab4 type: 0x06=trans data
Hex dump of block: st=0, typ_found=1
Dump of memory from 0x00007F85F7BA9A00 to 0x00007F85F7BABA00
7F85F7BA9A00 0000A206 00417609 00ABB7CF 06010000  [.....vA.........]
7F85F7BA9A10 0000EAB4 00000001 0001495E 00ABB7CE  [........^I......]
7F85F7BA9A20 00000000 00030002 00000000 00080012  [................]
7F85F7BA9A30 00000AE2 01804A41 0009010A 00002001  [....AJ....... ..]
7F85F7BA9A40 00ABB7CF 000B0011 00000822 01804BA9  [........"....K..]
7F85F7BA9A50 001200BD 00008000 00ABB7CD 00010100  [................]
7F85F7BA9A60 0014FFFF 1F830376 00001F83 03760001  [....v.........v.]
7F85F7BA9A70 2C000000 0401002C 641E57C3 0301002C  [...,,....W.d,...]
7F85F7BA9A80 2C1E57C3 C3040100 2C641D57 C3030100  [.W.,....W.d,....]
7F85F7BA9A90 002C1D57 57C30401 002C641C 57C30301  [W.,....W.d,....W]
7F85F7BA9AA0 01002C1C 1B57C304 01002C64 1B57C303  [.,....W.d,....W.]
7F85F7BA9AB0 0401002C 641A57C3 0301002C 2C1A57C3  [,....W.d,....W.,]
7F85F7BA9AC0 C3040100 2C641957 C3030100 002C1957  [....W.d,....W.,.]
7F85F7BA9AD0 57C30401 002C6418 57C30301 01002C18  [...W.d,....W.,..]
7F85F7BA9AE0 1757C304 01002C64 1757C303 0401002C  [..W.d,....W.,...]
7F85F7BA9AF0 641657C3 0301002C 2C1657C3 C3040100  [.W.d,....W.,....]
7F85F7BA9B00 00000000 00000000 00000000 00000000  [................]
Repeat 44 times
7F85F7BA9DD0 012C0000 5CC30401 002C3B0B 5CC30301  [..,....\.;,....\]
7F85F7BA9DE0 01002C0B 0A5CC304 01002C64 0A5CC303  [.,....\.d,....\.]
7F85F7BA9DF0 0401002C 64095CC3 0301002C 2C095CC3  [,....\.d,....\.,]
7F85F7BA9E00 C3040100 2C64085C C3030100 002C085C  [....\.d,....\.,.]
7F85F7BA9E10 5CC30401 002C6407 5CC30301 01002C07  [...\.d,....\.,..]
7F85F7BA9E20 065CC304 01002C64 065CC303 0401002C  [..\.d,....\.,...]
7F85F7BA9E30 64055CC3 0301002C 2C055CC3 C3040100  [.\.d,....\.,....]
7F85F7BA9E40 2C64045C C3030100 002C045C 5CC30401  [\.d,....\.,....\]
7F85F7BA9E50 002C6403 5CC30301 01002C03 025CC304  [.d,....\.,....\.]
7F85F7BA9E60 01002C64 025CC303 0401002C 64015CC3  [d,....\.,....\.d]
7F85F7BA9E70 0201002C 002C5CC3 5BC30401 002C6464  [,....\,....[dd,.]
7F85F7BA9E80 5BC30301 01002C64 635BC304 01002C64  [...[d,....[cd,..]
7F85F7BA9E90 635BC303 0401002C 64625BC3 0301002C  [..[c,....[bd,...]
7F85F7BA9EA0 2C625BC3 C3040100 2C64615B C3030100  [.[b,....[ad,....]
7F85F7BA9EB0 002C615B 5BC30401 002C6460 5BC30301  [[a,....[`d,....[]
7F85F7BA9EC0 01002C60 5F5BC304 01002C64 5F5BC303  [`,....[_d,....[_]
7F85F7BA9ED0 0401002C 645E5BC3 0301002C 2C5E5BC3  [,....[^d,....[^,]
7F85F7BA9EE0 C3040100 2C645D5B C3030100 002C5D5B  [....[]d,....[],.]
7F85F7BA9EF0 5BC30401 002C645C 5BC30301 01002C5C  [...[\d,....[\,..]
7F85F7BA9F00 5B5BC304 01002C64 5B5BC303 0401002C  [..[[d,....[[,...]
7F85F7BA9F10 645A5BC3 0301002C 2C5A5BC3 C3040100  [.[Zd,....[Z,....]
7F85F7BA9F20 2C64595B C3030100 002C595B 5BC30401  [[Yd,....[Y,....[]
7F85F7BA9F30 002C6458 5BC30301 01002C58 575BC304  [Xd,....[X,....[W]
7F85F7BA9F40 01002C64 575BC303 0401002C 64565BC3  [d,....[W,....[Vd]
7F85F7BA9F50 0301002C 2C565BC3 C3040100 2C64555B  [,....[V,....[Ud,]
7F85F7BA9F60 C3030100 002C555B 5BC30401 002C6454  [....[U,....[Td,.]
7F85F7BA9F70 5BC30301 01002C54 535BC304 01002C64  [...[T,....[Sd,..]
7F85F7BA9F80 535BC303 0401002C 64525BC3 0301002C  [..[S,....[Rd,...]
7F85F7BA9F90 2C525BC3 C3040100 2C64515B C3030100  [.[R,....[Qd,....]
7F85F7BA9FA0 002C515B 5BC30401 002C6450 5BC30301  [[Q,....[Pd,....[]
7F85F7BA9FB0 01002C50 4F5BC304 01002C64 4F5BC303  [P,....[Od,....[O]
7F85F7BA9FC0 0401002C 644E5BC3 0301002C 2C4E5BC3  [,....[Nd,....[N,]
7F85F7BA9FD0 C3040100 2C644D5B C3030100 002C4D5B  [....[Md,....[M,.]
7F85F7BA9FE0 5BC30401 002C644C 5BC30301 01002C4C  [...[Ld,....[L,..]
7F85F7BA9FF0 4B5BC304 01002C64 4B5BC303 0401002C  [..[Kd,....[K,...]
7F85F7BAA000 644A5BC3 0301002C 2C4A5BC3 C3040100  [.[Jd,....[J,....]
7F85F7BAA010 2C64495B C3030100 002C495B 5BC30401  [[Id,....[I,....[]
7F85F7BAA020 002C6448 5BC30301 01002C48 475BC304  [Hd,....[H,....[G]
7F85F7BAA030 01002C64 475BC303 0401002C 64465BC3  [d,....[G,....[Fd]
7F85F7BAA040 0301002C 2C465BC3 C3040100 2C64455B  [,....[F,....[Ed,]
7F85F7BAA050 C3030100 002C455B 5BC30401 002C6444  [....[E,....[Dd,.]
7F85F7BAA060 5BC30301 01002C44 435BC304 01002C64  [...[D,....[Cd,..]
7F85F7BAA070 435BC303 0401002C 64425BC3 0301002C  [..[C,....[Bd,...]
7F85F7BAA080 2C425BC3 C3040100 2C64415B C3030100  [.[B,....[Ad,....]
7F85F7BAA090 002C415B 5BC30401 002C6440 5BC30301  [[A,....[@d,....[]
7F85F7BAA0A0 01002C40 3F5BC304 01002C64 3F5BC303  [@,....[?d,....[?]
7F85F7BAA0B0 0401002C 643E5BC3 0301002C 2C3E5BC3  [,....[>d,....[>,]
7F85F7BAA0C0 C3040100 2C643D5B C3030100 002C3D5B  [....[=d,....[=,.]
7F85F7BAA0D0 5BC30401 002C643C 5BC30301 01002C3C  [...[d,....Z>,....Z]
7F85F7BAA6A0 002C643D 5AC30301 01002C3D 3C5AC304  [=d,....Z=,....Z<]
7F85F7BAA6B0 01002C64 3C5AC303 0401002C 643B5AC3  [d,....Z<,....Z;d]
7F85F7BAAC70 59C30301 01002C3E 3D59C304 01002C64  [...Y>,....Y=d,..]
7F85F7BAAC80 3D59C303 0401002C 643C59C3 0301002C  [..Y=,....Yd,....X>]
7F85F7BAB250 0401002C 643D58C3 0301002C 2C3D58C3  [,....X=d,....X=,]
7F85F7BAB260 C3040100 2C643C58 C3030100 002C3C58  [....Xd,....W>,....]
7F85F7BAB830 2C643D57 C3030100 002C3D57 57C30401  [W=d,....W=,....W]
7F85F7BAB840 002C643C 57C30301 01002C3C 3B57C304  [1, wm 32768, RMno 0, reminc 62, dom 0]
Block header dump:  0x00417609
Object id on Block? Y
seg/obj: 0x1495e  csc: 0x00.abb7ce  itc: 2  flg: O  typ: 1 - DATA
fsl: 0  fnx: 0x0 ver: 0x01
Itl           Xid                  Uba         Flag  Lck        Scn/Fsc
0x01   0x0012.008.00000ae2  0x01804a41.010a.09  --U-    1  fsc 0x0000.00abb7cf
0x02   0x0011.00b.00000822  0x01804ba9.00bd.12  C---    0  scn 0x0000.00abb7cd
bdba: 0x00417609
data_block_dump,data header at 0x7f85f7ba9a5c
===============
tsiz: 0x1fa0
hsiz: 0x14
pbl: 0x7f85f7ba9a5c
76543210
flag=--------
ntab=1
nrow=1
frre=-1
fsbo=0x14
fseo=0x376
avsp=0x1f83
tosp=0x1f83
0xe:pti[0]	nrow=1	offs=0
0x12:pri[0]	offs=0x376
block_row_dump:
tab 0, row 0, @0x376
tl: 8 fb: --H-FL-- lb: 0x1  cc: 1
col  0: [ 4]  c3 5c 0b 3b
end_of_block_dump
GLOBAL CACHE ELEMENT DUMP (address: 0x7bfa6000):          --lock element
id1: 0x17609 id2: 0x1 pkey: OBJ#84318 block: (1/95753)
  lock: NG rls: 0x0 acq: 0x3 latch: 7                     -- NULL GLOBAL
flags: 0x20 fair: 0 recovery: 0 fpin: 'ktswh23: ktsfbkl'
bscn: 0x0.ac6451 bctx: (nil) write: 0 scan: 0xd000005
lcp: 0xd36ce7a0 lnk: [0xd36ce7f8,0xd36ce7f8] lch: [0x96eccd20,0x8df55238]
seq: 34524 hist: 17 146:6 14 8 324 50 38 231 230 227 21 37:2 145:0
LIST OF BUFFERS LINKED TO THIS GLOBAL CACHE ELEMENT:
flg: 0x00080000 state: READING tsn: 0 tsh: 0 mode: EXCL
pin: 'kduwh01: kdusru'
addr: 0x8df55108 obj: 84318 cls: DATA bscn: 0x0.0
flg: 0x08000001 state: PI tsn: 0 tsh: 1
addr: 0x96eccbf0 obj: 84318 cls: DATA bscn: 0x0.ac6451
piscn: 0x0.ac6452 clscn: 0x0.ac6452
GCS SHADOW 0x7bfa6078,1 resp[0xcfe5c5e0,0x17609.1] pkey 84318.0
grant 0 cvt 2 mdrole 0xc8 st 0x101 lst 0xc0 CONVERTQ rl G1
master 1 owner 1 sid 0 remote[(nil),0] hist 0x88149530f062c288
history 0x8.0x5.0xb.0x3.0xf.0x26.0x25.0xa.0x8.0x1.
cflag 0x0 sender 0 flags 0x10 replay# 0 abast (nil).x0.1 dbmap (nil)
disk: 0x0000.00000000 write request: 0x0000.00000000
pi scn: 0x0000.00ac6452 sq[0xcfe5c620,0xcfe5c620]
msgseq 0x0 updseq 0x0 reqids[22469,0,0] infop 0xcee3d880 lockseq x187
GCS SHADOW END
GCS RESOURCE 0xcfe5c5e0 hashq [0xdb595658,0xcfe62578] name[0x17609.1] pkey 84318.0
grant 0xcecec160 cvt 0x7bfa6078 send 0xcecec160@1,3 write (nil),0@65536
flag 0x10002 mdrole 0x42 mode 2 scan 0.232 role GLOBAL
disk: 0x0000.00abb7cf write: 0x0000.00000000 cnt 0x0 hist 0xd7
xid 0x0000.000.00000000 sid 0 pkwait 0s rmacks 0
refpcnt 0 weak: 0x0000.00000000
pkey 84318.0
hv 119 [stat 0x0, 1->1, wm 32768, RMno 0, reminc 62, dom 0]
kjga st 0x4, step 0.0.0, cinc 64, rmno 15, flags 0x0
lb 0, hb 0, myb 32449, drmb 32449, apifrz 0
GCS SHADOW 0xcecec160,3 resp[0xcfe5c5e0,0x17609.1] pkey 84318.0
grant 2 cvt 0 mdrole 0xc2 st 0x100 lst 0x40 GRANTQ rl G1
master 1 owner 2 sid 0 remote[0x61f98bf8,43] hist 0x887299f0510e4126
history 0x26.0x2.0x39.0x8.0x5.0x3e.0x26.0x39.0x8.0x1.
cflag 0x0 sender 0 flags 0x10 replay# 0 abast (nil).x0.1 dbmap (nil)
disk: 0x0000.00000000 write request: 0x0000.00000000
pi scn: 0x0000.00ac6450 sq[0xcfe5c610,0xcfe5c610]
msgseq 0x292b updseq 0x0 reqids[19172,0,0] infop (nil) lockseq xc4
GCS SHADOW END
GCS SHADOW 0x7bfa6078,1 resp[0xcfe5c5e0,0x17609.1] pkey 84318.0
grant 0 cvt 2 mdrole 0xc8 st 0x101 lst 0xc0 CONVERTQ rl G1
master 1 owner 1 sid 0 remote[(nil),0] hist 0x88149530f062c288
history 0x8.0x5.0xb.0x3.0xf.0x26.0x25.0xa.0x8.0x1.
cflag 0x0 sender 0 flags 0x10 replay# 0 abast (nil).x0.1 dbmap (nil)
disk: 0x0000.00000000 write request: 0x0000.00000000
pi scn: 0x0000.00ac6452 sq[0xcfe5c620,0xcfe5c620]
msgseq 0x0 updseq 0x0 reqids[22469,0,0] infop 0xcee3d880 lockseq x187
GCS SHADOW END
GCS RESOURCE END
2011-06-22 20:51:21.737794 : kjbmbassert [0x17609.1]
2011-06-22 20:51:21.738025 : kjbmsassert(0x17609.1)(2)
End dump data blocks tsn: 0 file#: 1 minblk 95753 maxblk 95753

Instance 2:

Start dump data blocks tsn: 0 file#:1 minblk 95753 maxblk 95753
Block dump from cache:
Dump of buffer cache at level 4 for tsn=0, rdba=4290057
BH (0xafed7940) file#: 1 rdba: 0x00417609 (1/95753) class: 1 ba: 0xaf1d8000
set: 5 pool: 3 bsz: 8192 bsi: 0 sflg: 2 pwc: 15,19
dbwrid: 0 obj: 84318 objn: 84318 tsn: 0 afn: 1 hint: f
hash: [0xafed7410,0xd9fb48e0] lru: [0xaff06738,0xd52c01d8]
obj-flags: object_ckpt_list
ckptq: [0xd52c3d30,0xafed3d08] fileq: [0xd52c3d50,0xaff06660] objq: [0xaff06760,0xcb9c1060] objaq: [0xaff06770,0xcb9c1040]
  st: XCURRENT md: NULL tch: 1 le: 0x61f98b80
flags: buffer_dirty remote_transfered
LRBA: [0x55.f6e1.0] LSCN: [0x0.97bdb9] HSCN: [0x0.97bdc9] HSUB: [1]
cr pin refcnt: 0 sh pin refcnt: 0
BH (0xafed7360) file#: 1 rdba: 0x00417609 (1/95753) class: 1 ba: 0xaf1d0000
set: 5 pool: 3 bsz: 8192 bsi: 0 sflg: 2 pwc: 15,19
dbwrid: 0 obj: 84318 objn: 84318 tsn: 0 afn: 1 hint: f
hash: [0xafed7298,0xafed79f0] lru: [0xd52c01d8,0xafed72d0]
lru-flags: moved_to_tail
ckptq: [NULL] fileq: [NULL] objq: [NULL] objaq: [NULL]
st: CR md: NULL tch: 1 le: (nil)
cr: [scn: 0x0.97bdc7],[xid: 0x0.0.0],[uba: 0x0.0.0],[cls: 0x0.97bdc7],[sfl: 0x0],[lc: 0x0.97bdc7]
flags: remote_transfered
cr pin refcnt: 0 sh pin refcnt: 0
BH (0xafed71e8) file#: 1 rdba: 0x00417609 (1/95753) class: 1 ba: 0xaf1ce000
set: 5 pool: 3 bsz: 8192 bsi: 0 sflg: 2 pwc: 15,19
dbwrid: 0 obj: 84318 objn: 84318 tsn: 0 afn: 1 hint: f
hash: [0xafed9460,0xafed7410] lru: [0xafed7448,0xafed9498]
lru-flags: moved_to_tail
ckptq: [NULL] fileq: [NULL] objq: [NULL] objaq: [NULL]
st: CR md: NULL tch: 1 le: (nil)
cr: [scn: 0x0.97bdc5],[xid: 0x0.0.0],[uba: 0x0.0.0],[cls: 0x0.97bdc5],[sfl: 0x0],[lc: 0x0.97bdc5]
flags: remote_transfered
cr pin refcnt: 0 sh pin refcnt: 0
BH (0xafed93b0) file#: 1 rdba: 0x00417609 (1/95753) class: 1 ba: 0xaf1fc000
set: 5 pool: 3 bsz: 8192 bsi: 0 sflg: 2 pwc: 15,19
dbwrid: 0 obj: 84318 objn: 84318 tsn: 0 afn: 1 hint: f
hash: [0xb0f18b48,0xafed7298] lru: [0xafed72d0,0xb0f18b80]
lru-flags: moved_to_tail
ckptq: [NULL] fileq: [NULL] objq: [NULL] objaq: [NULL]
st: CR md: NULL tch: 1 le: (nil)
cr: [scn: 0x0.97bdc3],[xid: 0x0.0.0],[uba: 0x0.0.0],[cls: 0x0.97bdc3],[sfl: 0x0],[lc: 0x0.97bdc3]
flags: remote_transfered
cr pin refcnt: 0 sh pin refcnt: 0
BH (0xb0f18a98) file#: 1 rdba: 0x00417609 (1/95753) class: 1 ba: 0xb0762000
set: 5 pool: 3 bsz: 8192 bsi: 0 sflg: 2 pwc: 15,19
dbwrid: 0 obj: 84318 objn: 84318 tsn: 0 afn: 1 hint: f
hash: [0xafed8148,0xafed9460] lru: [0xafed9498,0xafed8180]
lru-flags: moved_to_tail
ckptq: [NULL] fileq: [NULL] objq: [NULL] objaq: [NULL]
st: CR md: NULL tch: 1 le: (nil)
cr: [scn: 0x0.97bdc1],[xid: 0x0.0.0],[uba: 0x0.0.0],[cls: 0x0.97bdc1],[sfl: 0x0],[lc: 0x0.97bdc1]
flags: remote_transfered
cr pin refcnt: 0 sh pin refcnt: 0
BH (0xafed8098) file#: 1 rdba: 0x00417609 (1/95753) class: 1 ba: 0xaf1e2000
set: 5 pool: 3 bsz: 8192 bsi: 0 sflg: 2 pwc: 15,19
dbwrid: 0 obj: 84318 objn: 84318 tsn: 0 afn: 1 hint: f
hash: [0xaff06700,0xb0f18b48] lru: [0xb0f18b80,0xafef6d88]
lru-flags: moved_to_tail
ckptq: [NULL] fileq: [NULL] objq: [NULL] objaq: [NULL]
st: CR md: NULL tch: 1 le: (nil)
cr: [scn: 0x0.97bdbf],[xid: 0x0.0.0],[uba: 0x0.0.0],[cls: 0x0.97bdbf],[sfl: 0x0],[lc: 0x0.97bdbe]
flags: remote_transfered
cr pin refcnt: 0 sh pin refcnt: 0
BH (0xaff06650) file#: 1 rdba: 0x00417609 (1/95753) class: 1 ba: 0xaf5d4000
set: 5 pool: 3 bsz: 8192 bsi: 0 sflg: 2 pwc: 15,19
dbwrid: 0 obj: 84318 objn: 84318 tsn: 0 afn: 1 hint: f
hash: [0xd9fb48e0,0xafed8148] lru: [0xafed3b00,0xafed7a28]
obj-flags: object_ckpt_list
ckptq: [0xafed8f48,0xafed96a0] fileq: [0xafed7950,0xd52c3d50] objq: [0xcb9c1060,0xafed7a50] objaq: [0xb5ecd178,0xafed7a60]
  st: PI md: NULL tch: 1 le: 0x61f98b80               --Past Image
cr: [scn: 0x0.97bdb4],[xid: 0x0],[uba: 0x0],[cls: 0x0.97bdb4],[sfl: 0x0]
flags: buffer_dirty remote_transfered
LRBA: [0x55.d365.0] LSCN: [0x0.978da0] HSCN: [0x0.97bdaf] HSUB: [1]
cr pin refcnt: 0 sh pin refcnt: 0
Block dump from disk:
buffer tsn: 0 rdba: 0x00417609 (1/95753)
scn: 0x0000.00978d91 seq: 0x01 flg: 0x06 tail: 0x8d910601
frmt: 0x02 chkval: 0x81cc type: 0x06=trans data
Hex dump of block: st=0, typ_found=1
Dump of memory from 0x00002AB4A7A4EA00 to 0x00002AB4A7A50A00
2AB4A7A4EA00 0000A206 00417609 00978D91 06010000  [.....vA.........]
2AB4A7A4EA10 000081CC 00000001 0001495E 00978D8F  [........^I......]
2AB4A7A4EA20 00000000 00030002 00000000 000C0014  [................]
2AB4A7A4EA30 00000391 01801B5D 001300D0 00002001  [....]........ ..]
2AB4A7A4EA40 00978D91 00210005 000010CF 00C0829C  [......!.........]
2AB4A7A4EA50 00270376 00008000 00978D8D 00010100  [v.'.............]
2AB4A7A4EA60 0014FFFF 1F8317E5 00001F83 17E50001  [................]
2AB4A7A4EA70 2C000000 C3040100 2C642D21 C3030100  [...,....!-d,....]
2AB4A7A4EA80 002C2D21 21C30401 002C642C 21C30301  [!-,....!,d,....!]
2AB4A7A4EA90 01002C2C 2B21C304 01002C64 2B21C303  [,,....!+d,....!+]
2AB4A7A4EAA0 0401002C 642A21C3 0301002C 2C2A21C3  [,....!*d,....!*,]
2AB4A7A4EAB0 C3040100 2C642921 C3030100 002C2921  [....!)d,....!),.]
2AB4A7A4EAC0 21C30401 002C6428 21C30301 01002C28  [...!(d,....!(,..]
2AB4A7A4EAD0 2721C304 01002C64 2721C303 0401002C  [..!'d,....!',...]
2AB4A7A4EAE0 642621C3 0301002C 2C2621C3 C3040100  [.!&d,....!&,....]
2AB4A7A4EAF0 2C642521 C3030100 002C2521 21C30401  [!%d,....!%,....!]
2AB4A7A4EB00 00000000 00000000 00000000 00000000  [................]
Repeat 371 times
2AB4A7A50240 01012C00 4D22C304 01002C5F 4D22C303  [.,...."M_,...."M]
2AB4A7A50250 0401002C 644C22C3 0301002C 2C4C22C3  [,...."Ld,...."L,]
2AB4A7A50260 C3040100 2C644B22 C3030100 002C4B22  [...."Kd,...."K,.]
2AB4A7A50270 22C30401 002C644A 22C30301 01002C4A  [..."Jd,...."J,..]
2AB4A7A50280 4922C304 01002C64 4922C303 0401002C  [.."Id,...."I,...]
2AB4A7A50290 644822C3 0301002C 2C4822C3 C3040100  [."Hd,...."H,....]
2AB4A7A502A0 2C644722 C3030100 002C4722 22C30401  ["Gd,...."G,...."]
2AB4A7A502B0 002C6446 22C30301 01002C46 4522C304  [Fd,...."F,...."E]
2AB4A7A502C0 01002C64 4522C303 0401002C 644422C3  [d,...."E,...."Dd]
2AB4A7A502D0 0301002C 2C4422C3 C3040100 2C644322  [,...."D,...."Cd,]
2AB4A7A502E0 C3030100 002C4322 22C30401 002C6442  [...."C,...."Bd,.]
2AB4A7A502F0 22C30301 01002C42 4122C304 01002C64  [..."B,...."Ad,..]
2AB4A7A50300 4122C303 0401002C 644022C3 0301002C  [.."A,...."@d,...]
2AB4A7A50310 2C4022C3 C3040100 2C643F22 C3030100  [."@,...."?d,....]
2AB4A7A50320 002C3F22 22C30401 002C643E 22C30301  ["?,....">d,...."]
2AB4A7A50330 01002C3E 3D22C304 01002C64 3D22C303  [>,...."=d,...."=]
2AB4A7A50340 0401002C 643C22C3 0301002C 2C3C22C3  [,...."d,....!>,...]
2AB4A7A50910 643D21C3 0301002C 2C3D21C3 C3040100  [.!=d,....!=,....]
2AB4A7A50920 2C643C21 C3030100 002C3C21 21C30401  [!1, wm 32768, RMno 0, reminc 62, dom 0]
Block header dump:  0x00417609
Object id on Block? Y
seg/obj: 0x1495e  csc: 0x00.978d8f  itc: 2  flg: O  typ: 1 - DATA
fsl: 0  fnx: 0x0 ver: 0x01
Itl           Xid                  Uba         Flag  Lck        Scn/Fsc
0x01   0x0014.00c.00000391  0x01801b5d.00d0.13  --U-    1  fsc 0x0000.00978d91
0x02   0x0005.021.000010cf  0x00c0829c.0376.27  C---    0  scn 0x0000.00978d8d
bdba: 0x00417609
data_block_dump,data header at 0x2ab4a7a4ea5c
===============
tsiz: 0x1fa0
hsiz: 0x14
pbl: 0x2ab4a7a4ea5c
76543210
flag=--------
ntab=1
nrow=1
frre=-1
fsbo=0x14
fseo=0x17e5
avsp=0x1f83
tosp=0x1f83
0xe:pti[0]	nrow=1	offs=0
0x12:pri[0]	offs=0x17e5
block_row_dump:
tab 0, row 0, @0x17e5
tl: 8 fb: --H-FL-- lb: 0x1  cc: 1
col  0: [ 4]  c3 22 4d 5f
end_of_block_dump
GLOBAL CACHE ELEMENT DUMP (address: 0x61f98b80):                  --lock element
id1: 0x17609 id2: 0x1 pkey: OBJ#84318 block: (1/95753)
  lock: XG rls: 0x0 acq: 0x0 latch: 7                           exclusive global
flags: 0x20 fair: 0 recovery: 0 fpin: 'kduwh01: kdusru'
bscn: 0x0.97bafa bctx: (nil) write: 0 scan: 0x0
lcp: (nil) lnk: [NULL] lch: [0xaff06780,0xafed94e0]
seq: 40651 hist: 58 58 58 58 58 58 58 58 58 58 58 58 58 58 58 58
58 58 58 58
LIST OF BUFFERS LINKED TO THIS GLOBAL CACHE ELEMENT:
flg: 0x08000001 state: XCURRENT tsn: 0 tsh: 1 mode: SHR
addr: 0xafed93b0 obj: 84318 cls: DATA
flg: 0x08000001 state: PI tsn: 0 tsh: 1
addr: 0xaff06650 obj: 84318 cls: DATA
piscn: 0x0.97bdb4 clscn: 0x0.97bdb4
 GCS CLIENT 0x61f98bf8,42 resp[(nil),0x17609.1] pkey 84318.0       only client here,
grant 2 cvt 0 mdrole 0xc2 st 0x100 lst 0x20 GRANTQ rl G1
master 1 owner 2 sid 0 remote[0xcecec160,2] hist 0x8f0a41e071e1483c
history 0x3c.0x10.0x5.0xf.0x7.0x3c.0x10.0x5.0xf.0x1.
cflag 0x0 sender 1 flags 0x0 replay# 0 abast (nil).x0.1 dbmap (nil)
disk: 0x0000.00978d9a write request: 0x0000.00000000
pi scn: 0x0000.0097bdb4 sq[(nil),(nil)]
msgseq 0x291c updseq 0x0 reqids[7233,0,0] infop (nil) lockseq xbd
pkey 84318.0
hv 119 [stat 0x0, 1->1, wm 32768, RMno 0, reminc 62, dom 0]
kjga st 0x4, step 0.0.0, cinc 64, rmno 15, flags 0x0
lb 0, hb 0, myb 61121, drmb 32449, apifrz 0
GCS CLIENT END
2011-06-22 20:34:29.243634 : kjbmbassert [0x17609.1]
2011-06-22 20:34:29.243804 : kjbmsassert(0x17609.1)(1)
End dump data blocks tsn: 0 file#: 1 minblk 95753 maxblk 95753
0x7bfa6000

The cache fusion technology evolves various background processes such as the GCS processes (identified by LMSn) and GES daemon (identified by LMD).

The global cache service (GCS) and global enqueue service (GES) handle the management of the cluster piece of the database software. A global cache element is an Oracle-specific data structure representing a cache fusion resource. There is a 1:1 corresponding relationship between a global cache element and a cache fusion resource in the GCS.

Oracle RAC uses a messaging mechanism to maintain resource statuses. Both GCS and GES use messages containing information to ensure that the current block image can be located. These messages also identify block copies being retained by any specific instance for use by the recovery mechanisms. The recovery-specific information contains sequence numbers to identify the order of changes made to that block since it was read from disk. The global resource directory (GRD) is a repository of information about the current status of resources shared by the instances. The GRD contains two groups of resources: enqueue resources, managed by the GES, and buffer cache resources, managed by the GCS. GCS and GES maintain the contents of the GRD.

The LMSn are the processes that handle remote GCS messages. Oracle RAC software provides for up to 10 GCS processes. The number of LMSn processes varies depending on the number of CPU’s on the node. Oracle by default starts one LMS process for every two CPU’s. LMD is the resource-agent process that manages GES resource requests, such as deadlock detection of GES requests.

GES and GCS

The GES coordinates enqueues that are shared globally.

The GCS is the controlling mechanism that implements cache fusion. It is responsible for block transfers between instances. In RAC, the cache fusion technology manages resources at the global level identified by a three-character lock structure.

Three characters are required to distinguish resources. The first characterizes a traditional resource type: N (Null), S (Shared), or X (Exclusive).

The second represents a role. There are two roles:

  • Local (L): The blocks associated with the resource can be manipulated without further reference to GCS or other instances. For example, when a resource is acquired for the first time, it is acquired with a local role.
  • Global (G): The blocks covered by the resource might not be usable without further information from the GCS or other nodes. For example, if the resource is acquired and it already has dirty buffers on a remote instance, then it takes on a global resource role.

If the resource is in exclusive mode and has a local role, then the following rules apply:

  • Only one instance can have the resource in exclusive mode.
  • All unwritten changes must be in local cache.
  • At checkpoint, instances can write changed blocks to disk without confirmation from GCS.
Mode Definition Description
NL0 Null local 0 The same as N in Oracle OPS with no past image
SL0 Shared local 0 The same as S in Oracle OPS with no past image
XL0 Exclusive local 0 The same as X in Oracle OPS with no past image
NG0 Null global 0 Global N lock and the Instance owns current block image.
SG0 Shared global 0 Instance owns current block image and the resource can be shared with the other nodes, there is no past image. Can write current image.
XG0 Exclusive global 0 Instance owns current block image for modification. Can write current image.
NG1 Null global 1 Instance owns past block image. Can write PI image.
SG1 Shared global 1 Instance owns past block image and the resource can be shared with the other nodes. Can write current and PI images.
XG1 Exclusive global 1 Instance owns past block image for modification. Can write current and PI images.

Writing Block and Recovery Considerations

For recovery purposes, instances that have past images will keep these past images in their buffer cache until notified by the master instance of the resource to release them. A block written record (BWR) is placed in its redo log buffer when an instance writes a block covered by a global resource or when it is told it can free a PI buffer. This record indicates to the recovery process that redo information for the block is not needed at this time. Although the BWR makes recovery more efficient, the instance does not force a flush of the log buffer after creating it because it is not essential for accurate recovery.

Each block PI has a system change number (SCN). Instances regularly synchronize their SCNs, and PI SCN is guaranteed to be later than the previous modification performed on this block and earlier than modifications performed by the next instance. When a write completes, the writer updates the GRD with write completion and the new SCN information. The GCS requests instances to flush all PIs having earlier SCNs than the one in the block written to disk.

Checkpoints are more involved on RAC instances and generate more work. When a checkpoint occurs:

  • The GCS notifies all nodes with PI blocks that the checkpoint occurred.
  • The node with the most current PI will write dirty blocks to disk.
  • Resources are updated accordingly (global resources are changed to local, etc).
  • The Global Resource Directory is modified to reflect the resource changes.

This is important to understand since the impact too many checkpoints have on a RAC system is greater than that of a standalone system. Checkpoints generate interconnect traffic and require each node with PI blocks to modify the GRD within the shared pool.

沪ICP备14014813号

沪公网安备 31010802001379号