01 Problem with PENRITH2

Overview

PENRITH2 goes into a reboot loop whenever the VM image is started. I have to complete my OCM practice without a fully operational cluster.

Build History

I followed the same steps as with PENRITH1 :

• 01 Build PENRITH1 VM Image
• 02 Install PENRITH1 OS Image
• 03 Install Oracle Validated RPM
• 04 Oracle Clusterware Preinstallation Tasks
• 05 Set Up Shared Disk Storage
• 06 Installing Oracle Clusterware
• 07 Oracle Clusterware Postinstallation Procedures
• 08 Install ASM Software
• 09 Install Oracle Database Software

Problem Status

Summary

The startup of PENRITH2 causes the PENRITH to become unstable and causes PENRITH1 to reboot as well.

There is insufficient data to diagnose the problem.

PENRITH1

The alert log for PENRITH1 , /u01/app/crs/product/11.1.0/crs/log/penrith1/alertpenrith1.log , shows the first occurrence of the problem as:

2012-01-02 01:11:18.625
[client(17937)]CRS-1006:The OCR location /u03/ocr is inaccessible. Details in /u01/app/crs/product/11.1.0/crs/log/penrith1/client/ocrconfig_17937.log.
2012-01-02 01:11:18.626
[client(17937)]CRS-1006:The OCR location /u02/ocr is inaccessible. Details in /u01/app/crs/product/11.1.0/crs/log/penrith1/client/ocrconfig_17937.log.
2012-01-02 01:11:18.861
[client(17937)]CRS-1013:The OCR at /u02/ocr, /u03/ocr was successfully formatted using version 2. Ignore earlier CRS-1006 messages if any.
2012-01-02 01:12:29.423
[client(18013)]CRS-1801:Cluster penrith_cluster configured with nodes penrith1 penrith2 .
2012-01-02 01:13:22.700
[cssd(19409)]CRS-1605:CSSD voting file is online: /u04/voting. Details in /u01/app/crs/product/11.1.0/crs/log/penrith1/cssd/ocssd.log.
2012-01-02 01:13:23.448
[cssd(19409)]CRS-1605:CSSD voting file is online: /u05/voting. Details in /u01/app/crs/product/11.1.0/crs/log/penrith1/cssd/ocssd.log.
2012-01-02 01:13:38.103
[cssd(19409)]CRS-1605:CSSD voting file is online: /u06/voting. Details in /u01/app/crs/product/11.1.0/crs/log/penrith1/cssd/ocssd.log.
[cssd(19409)]CRS-1601:CSSD Reconfiguration complete. Active nodes are penrith1 .
2012-01-02 01:36:38.869
[evmd(18855)]CRS-1401:EVMD started on node penrith1.
[cssd(19409)]CRS-1601:CSSD Reconfiguration complete. Active nodes are penrith1 penrith2 .
2012-01-02 01:36:39.818
[crsd(18818)]CRS-1005:The OCR upgrade was completed. Version has changed from 185599488 to 185599488. Details in /u01/app/crs/product/11.1.0
/crs/log/penrith1/crsd/crsd.log. 2012-01-02 01:36:39.847
[crsd(18818)]CRS-1012:The OCR service started on node penrith1.
2012-01-02 01:36:40.954
[crsd(18818)]CRS-1201:CRSD started on node penrith1.
2012-01-02 04:11:01.252
[cssd(19409)]CRS-1612:node penrith2 (2) at 50% heartbeat fatal, eviction in 14.148 seconds
2012-01-02 04:11:02.356
[cssd(19409)]CRS-1612:node penrith2 (2) at 50% heartbeat fatal, eviction in 13.138 seconds
2012-01-02 04:11:09.383
[cssd(19409)]CRS-1611:node penrith2 (2) at 75% heartbeat fatal, eviction in 6.148 seconds
2012-01-02 04:11:13.413
[cssd(19409)]CRS-1610:node penrith2 (2) at 90% heartbeat fatal, eviction in 2.148 seconds
2012-01-02 04:11:14.419
[cssd(19409)]CRS-1610:node penrith2 (2) at 90% heartbeat fatal, eviction in 1.148 seconds
2012-01-02 04:11:15.427
[cssd(19409)]CRS-1610:node penrith2 (2) at 90% heartbeat fatal, eviction in 0.148 seconds
2012-01-02 04:11:16.560
[cssd(19409)]CRS-1607:CSSD evicting node penrith2. Details in /u01/app/crs/product/11.1.0/crs/log/penrith1/cssd/ocssd.log.
[cssd(19409)]CRS-1601:CSSD Reconfiguration complete. Active nodes are penrith1 .

The log, /u01/app/crs/product/11.1.0/crs/log/penrith1/cssd/ocssd.log , shows, in part, at the time of the eviction:

[ CSSD]2012-01-02 01:36:37.988 [3059735440] >USER: clssnmHandleUpdate: SYNC(220929445) from node(1) completed
[ CSSD]2012-01-02 01:36:37.988 [3059735440] >USER: clssnmHandleUpdate: NODE 1 (penrith1) IS ACTIVE MEMBER OF CLUSTER
[ CSSD]2012-01-02 01:36:37.988 [3059735440] >USER: clssnmHandleUpdate: NODE 2 (penrith2) IS ACTIVE MEMBER OF CLUSTER
[ CSSD]2012-01-02 01:36:37.988 [3059735440] >TRACE: clssnmHandleUpdate: diskTimeout set to (200000)ms
[ CSSD]2012-01-02 01:36:37.988 [2933058448] >TRACE: clssgmReconfigThread: started for reconfig (220929445)
[ CSSD]2012-01-02 01:36:37.989 [2933058448] >USER: NMEVENT_RECONFIG [00][00][00][06]
[ CSSD]2012-01-02 01:36:37.989 [2933058448] >TRACE: clssgmEstablishConnections: 2 nodes in cluster incarn 220929445
[ CSSD]2012-01-02 01:36:38.017 [2964528016] >TRACE: clssnmWaitForAcks: done, msg type(15)
[ CSSD]2012-01-02 01:36:38.017 [2964528016] >TRACE: clssnmDoSyncUpdate: Sync 220929445 complete!
[ CSSD]2012-01-02 01:36:38.018 [145591184] >TRACE: clssnmvFatalCheck: fatal 1, sclsfatal 0
[ CSSD]2012-01-02 01:36:38.018 [94346128] >TRACE: clssnmvFatalCheck: fatal 1, sclsfatal 0
[ CSSD]2012-01-02 01:36:38.018 [104835984] >TRACE: clssnmvFatalCheck: fatal 1, sclsfatal 0
[ CSSD]2012-01-02 01:36:38.311 [3070225296] >TRACE: clssnmFatalThread: Fatal mode enabled
[ CSSD]2012-01-02 01:36:38.478 [3059735440] >TRACE: clssnmSendFatalOn: req to syncLeader(1)
[ CSSD]2012-01-02 01:36:38.485 [145591184] >TRACE: clssnmvFatalOnUpdate: handling req from 1 in op 2
[ CSSD]2012-01-02 01:36:38.485 [94346128] >TRACE: clssnmvFatalOnUpdate: handling req from 1 in op 2
[ CSSD]2012-01-02 01:36:38.485 [104835984] >TRACE: clssnmvFatalOnUpdate: handling req from 1 in op 2
[ CSSD]2012-01-02 01:36:38.752 [2996263824] >TRACE: clssgmInitialRecv: (0xa00daa0) accepted a new connection from node 2 born at 220929445 active (2, 2), vers (11,1,1,2)
[ CSSD]2012-01-02 01:36:38.752 [2996263824] >TRACE: clssgmInitialRecv: conns done (2/2)
[ CSSD]2012-01-02 01:36:38.752 [2933058448] >TRACE: clssgmEstablishMasterNode: MASTER for 220929445 is node(1) birth(220929444)
[ CSSD]2012-01-02 01:36:38.752 [2933058448] >TRACE: clssgmMasterCMSync: Synchronizing group/lock status
[ CSSD]2012-01-02 01:36:38.793 [2933058448] >TRACE: clssgmMasterSendDBDone: group/lock status synchronization complete
[ CSSD]CLSS-3000: reconfiguration successful, incarnation 220929445 with 2 nodes

[ CSSD]CLSS-3001: local node number 1, master node number 1

[ CSSD]2012-01-02 01:36:38.975 [2933058448] >TRACE: clssgmReconfigThread: completed for reconfig(220929445), with status(1)
[ CSSD]2012-01-02 01:36:40.110 [145591184] >TRACE: clssnmvFatalOnUpdate: handling req from 2 in op 2
[ CSSD]2012-01-02 01:36:40.110 [94346128] >TRACE: clssnmvFatalOnUpdate: handling req from 2 in op 2
[ CSSD]2012-01-02 01:36:40.110 [104835984] >TRACE: clssnmvFatalOnUpdate: handling req from 2 in op 2
[ CSSD]2012-01-02 04:11:01.232 [2985507728] >WARNING: clssnmPollingThread: node penrith2 (2) at 50% heartbeat fatal, eviction in 14.660 seconds
[ CSSD]2012-01-02 04:11:01.232 [2985507728] >TRACE: clssnmPollingThread: node penrith2 (2) is impending reconfig, flag 1037, misstime 15340
[ CSSD]2012-01-02 04:11:01.233 [2985507728] >TRACE: clssnmPollingThread: diskTimeout set to (27000)ms impending reconfig status(1)
[ CSSD]2012-01-02 04:11:02.356 [2985507728] >WARNING: clssnmPollingThread: node penrith2 (2) at 50% heartbeat fatal, eviction in 13.650 seconds
[ CSSD]2012-01-02 04:11:09.383 [2985507728] >WARNING: clssnmPollingThread: node penrith2 (2) at 75% heartbeat fatal, eviction in 6.660 seconds
[ CSSD]2012-01-02 04:11:13.413 [2985507728] >WARNING: clssnmPollingThread: node penrith2 (2) at 90% heartbeat fatal, eviction in 2.660 seconds
[ CSSD]2012-01-02 04:11:14.419 [2985507728] >WARNING: clssnmPollingThread: node penrith2 (2) at 90% heartbeat fatal, eviction in 1.660 seconds
[ CSSD]2012-01-02 04:11:15.427 [2985507728] >WARNING: clssnmPollingThread: node penrith2 (2) at 90% heartbeat fatal, eviction in 0.660 seconds
[ CSSD]2012-01-02 04:11:16.090 [2985507728] >TRACE: clssnmPollingThread: Eviction started for node penrith2 (2), flags 0x040d, state 3, wt4c 0
[ CSSD]2012-01-02 04:11:16.114 [2964528016] >TRACE: clssnmDoSyncUpdate: Initiating sync 220929446
[ CSSD]2012-01-02 04:11:16.114 [2964528016] >TRACE: clssnmDoSyncUpdate: diskTimeout set to (27000)ms
[ CSSD]2012-01-02 04:11:16.114 [2964528016] >TRACE: clssnmSetupAckWait: Ack message type (11)
[ CSSD]2012-01-02 04:11:16.114 [2964528016] >TRACE: clssnmSetupAckWait: node(1) is ALIVE
[ CSSD]2012-01-02 04:11:16.118 [2964528016] >TRACE: clssnmSendSync: syncSeqNo(220929446)
[ CSSD]2012-01-02 04:11:16.134 [2964528016] >TRACE: clssnmWaitForAcks: Ack message type(11), ackCount(1)
[ CSSD]2012-01-02 04:11:16.134 [3059735440] >TRACE: clssnmHandleSync: diskTimeout set to (27000)ms
[ CSSD]2012-01-02 04:11:16.148 [3059735440] >TRACE: clssnmHandleSync: Acknowledging sync: src[1] srcName[penrith1] seq[10] sync[220929446]
[ CSSD]2012-01-02 04:11:16.183 [3086924272] >USER: NMEVENT_SUSPEND [00][00][00][06]
[ CSSD]2012-01-02 04:11:16.183 [2964528016] >TRACE: clssnmWaitForAcks: done, msg type(11)
[ CSSD]2012-01-02 04:11:16.183 [2964528016] >TRACE: clssnmNeedConfReq: No configuration to change
[ CSSD]2012-01-02 04:11:16.183 [2964528016] >TRACE: clssnmDoSyncUpdate: Terminating node 2, penrith2, misstime(30000) state(5)
[ CSSD]2012-01-02 04:11:16.183 [2964528016] >TRACE: clssnmSetupAckWait: Ack message type (13)
[ CSSD]2012-01-02 04:11:16.183 [2964528016] >TRACE: clssnmSetupAckWait: node(1) is ACTIVE
[ CSSD]2012-01-02 04:11:16.183 [2964528016] >TRACE: clssnmSendVote: syncSeqNo(220929446)
[ CSSD]2012-01-02 04:11:16.184 [2964528016] >TRACE: clssnmWaitForAcks: Ack message type(13), ackCount(1)
[ CSSD]2012-01-02 04:11:16.184 [3059735440] >TRACE: clssnmSendVoteInfo: node(1) syncSeqNo(220929446)
[ CSSD]2012-01-02 04:11:16.184 [2964528016] >TRACE: clssnmWaitForAcks: done, msg type(13)
[ CSSD]2012-01-02 04:11:16.184 [2964528016] >TRACE: clssnmCheckDskInfo: Checking disk info...
[ CSSD]2012-01-02 04:11:16.502 [2964528016] >TRACE: clssnmEvict: Start
[ CSSD]2012-01-02 04:11:16.502 [2964528016] >TRACE: clssnmEvict: Evicting node 2, penrith2, birth 220929445, death 220929446, impendingrcfg 1, stateflags 0x40d
[ CSSD]2012-01-02 04:11:16.502 [2964528016] >TRACE: clssnmEvict: Fencing node 2, penrith2, with SAGE
[ CSSD]2012-01-02 04:11:16.560 [2964528016] >TRACE: clssnmSendShutdown: req to node 2, kill time 26050974
[ CSSD]2012-01-02 04:11:16.602 [2964528016] >TRACE: clssnmDiscHelper: penrith2, node(2) connection failed, con (0x9f07a38), probe((nil))
[ CSSD]2012-01-02 04:11:16.602 [2964528016] >TRACE: clssnmWaitOnEvictions: Start
[ CSSD]2012-01-02 04:11:16.602 [2964528016] >TRACE: clssnmWaitOnEvictions: node 2, undead 0, reqid 0
[ CSSD]2012-01-02 04:11:16.602 [2964528016] >WARNING: clssnmWaitOnEvictions: no killecho, node 2, undead 0, misstime 30000, cur 26050974, LAT 26036314
[ CSSD]2012-01-02 04:11:17.623 [2964528016] >WARNING: clssnmWaitOnEvictions: no killecho, node 2, undead 0, misstime 30000, cur 26051964, LAT 26036314
[ CSSD]2012-01-02 04:11:18.628 [2964528016] >WARNING: clssnmWaitOnEvictions: no killecho, node 2, undead 0, misstime 30000, cur 26052964, LAT 26036314
[ CSSD]2012-01-02 04:11:19.634 [2964528016] >WARNING: clssnmWaitOnEvictions: no killecho, node 2, undead 0, misstime 30000, cur 26053964, LAT 26036314
[ CSSD]2012-01-02 04:11:20.640 [2964528016] >WARNING: clssnmWaitOnEvictions: no killecho, node 2, undead 0, misstime 30000, cur 26054964, LAT 26036314
[ CSSD]2012-01-02 04:11:21.648 [2964528016] >WARNING: clssnmWaitOnEvictions: no killecho, node 2, undead 0, misstime 30000, cur 26055964, LAT 26036314
[ CSSD]2012-01-02 04:11:22.659 [2964528016] >WARNING: clssnmWaitOnEvictions: no killecho, node 2, undead 0, misstime 30000, cur 26056974, LAT 26036314
[ CSSD]2012-01-02 04:11:23.662 [2964528016] >WARNING: clssnmWaitOnEvictions: no killecho, node 2, undead 0, misstime 30000, cur 26057974, LAT 26036314
[ CSSD]2012-01-02 04:11:24.668 [2964528016] >WARNING: clssnmWaitOnEvictions: no killecho, node 2, undead 0, misstime 30000, cur 26058974, LAT 26036314
[ CSSD]2012-01-02 04:11:25.670 [2964528016] >WARNING: clssnmWaitOnEvictions: no killecho, node 2, undead 0, misstime 30000, cur 26059974, LAT 26036314
[ CSSD]2012-01-02 04:11:26.675 [2964528016] >WARNING: clssnmWaitOnEvictions: no killecho, node 2, undead 0, misstime 30000, cur 26060974, LAT 26036314
[ CSSD]2012-01-02 04:11:27.679 [2964528016] >WARNING: clssnmWaitOnEvictions: no killecho, node 2, undead 0, misstime 30000, cur 26061974, LAT 26036314
[ CSSD]2012-01-02 04:11:28.689 [2964528016] >WARNING: clssnmWaitOnEvictions: no killecho, node 2, undead 0, misstime 30000, cur 26062984, LAT 26036314
[ CSSD]2012-01-02 04:11:29.697 [2964528016] >WARNING: clssnmWaitOnEvictions: no killecho, node 2, undead 0, misstime 30000, cur 26063984, LAT 26036314
[ CSSD]2012-01-02 04:11:30.704 [2964528016] >WARNING: clssnmWaitOnEvictions: no killecho, node 2, undead 0, misstime 30000, cur 26064984, LAT 26036314
[ CSSD]2012-01-02 04:11:31.711 [2964528016] >WARNING: clssnmWaitOnEvictions: no killecho, node 2, undead 0, misstime 30000, cur 26065984, LAT 26036314
[ CSSD]2012-01-02 04:11:32.043 [2964528016] >TRACE: clssnmSetupAckWait: Ack message type (15)
[ CSSD]2012-01-02 04:11:32.043 [2964528016] >TRACE: clssnmSetupAckWait: node(1) is ACTIVE
[ CSSD]2012-01-02 04:11:32.043 [2964528016] >TRACE: clssnmSendUpdate: syncSeqNo(220929446)
[ CSSD]2012-01-02 04:11:32.263 [2964528016] >TRACE: clssnmWaitForAcks: Ack message type(15), ackCount(1)
[ CSSD]2012-01-02 04:11:32.281 [3059735440] >TRACE: clssnmUpdateNodeState: node 0, state (0/0) unique (0/0) prevConuni(0) birth (0/0) (old/new)
[ CSSD]2012-01-02 04:11:32.281 [3059735440] >TRACE: clssnmUpdateNodeState: node 1, state (3/3) unique (1325427174/1325427174) prevConuni(0) birth (220929444/220929444) (old/new)
[ CSSD]2012-01-02 04:11:32.281 [3059735440] >TRACE: clssnmUpdateNodeState: node 2, state (5/0) unique (1325428585/1325428585) prevConuni(1325428585) birth (220929445/220929445) (old/new)
[ CSSD]2012-01-02 04:11:32.281 [3059735440] >TRACE: clssnmDeactivateNode: node 2 (penrith2) left cluster

The file, /u01/app/crs/product/11.1.0/crs/log/penrith1/client/ocrconfig_17937.log , is uploaded as an attachment for future reference.

PENRITH2

I was able to get into single-user mode by using the procedure from Changing Runlevels at Boot Time .

The startup parameters are as follows:

/var/log/messages shows the last restart to be at around 16:33:40 on 6 January 2012:

I turned off iptables for both PENRITH1 and PENRITH2 , while in multiuser GUI mode ( runlevel 5 ) as follows:

/sbin/chkconfig --level 5 iptables off

This would solve the network heartbeat problem, but it does not solve the reboot problem.