Shulou(Shulou.com)06/01 Report--

Customer site environment, national 7-hour 24-hour online system, HP-ux B11.31 for Oracle 10.2.0.4 RAC two-node cluster.

The customer made hardware changes at the host level on June 7, and no parameter changes were made to the database. After starting up, I found that the evmd process was constantly restarting. Evmd: event management daemon. This process is also responsible for starting the racgevt process to manage FAN server-side calls. Each log is also reflected accordingly.

Ocssd process log:

[CSSD] 2016-06-07 04 Copyright 02Switzerland 28.853 > USER: Copyright 2016, Oracle version 10.2.0.4.0

[clsdmt] Listening to (ADDRESS= (PROTOCOL=ipc) (KEY=essdb3DBG_CSSD))

[CSSD] 2016-06-07 04 CSS daemon log for node essdb3 02CSS daemon log for node essdb3 28.853 > USER: number 1, in cluster crs

[CSSD] 2016-06-07 04 clssscmain 02Switzerland 28.868 [1] > TRACE: clssscmain: local-only set to false

[CSSD] 2016-06-07 04 clssnmReadNodeInfo 02Switzerland 28.876 [1] > TRACE: clssnmReadNodeInfo: added node 1 (essdb3) to cluster

[CSSD] 2016-06-07 04 clssnmReadNodeInfo 02 added node 28.881 [1] > clssnmReadNodeInfo: added node 2 (essdb4) to cluster

[CSSD] 2016-06-07 04 clssnm_skgxninit 02Switzerland 28.887 [5] > TRACE: clssnm_skgxninit: initialized skgxn version (2/0/Hewlett-Packard SKGXN

)

[CSSD] 2016-06-07 04 clssnmNMInitialize 0215 38.904 > TRACE: clssnmNMInitialize: misscount set to

[CSSD] 2016-06-07 04 clssnmNMInitialize: Network heartbeat thresholds are: impending reconfig 300000 ms, reconfig start (misscount) 600000 ms

[CSSD] 2016-06-07 04 clssnmDiskStateChange 02 to 38.908 [1] > TRACE: state from 1 to 2 disk (0//dev/essdb2vg1/rdb2vg1_512_votk)

[CSSD] 2016-06-07 04 clssnmvDPT 02 spawned for disk 38.909 [6] > clssnmvDPT: spawned for disk 0 (/ dev/essdb2vg1/rdb2vg1_512_votk)

[CSSD] 2016-06-07 04 clssnmDiskStateChange 02Switzerland 38.910 [1] > TRACE: clssnmDiskStateChange: state from 1 to 2 disk (1//dev/essdb2vg2/rdb2vg2_512_votk)

[CSSD] 2016-06-07 04 clssnmvDPT 02 spawned for disk 38.911 [7] > clssnmvDPT: spawned for disk 1 (/ dev/essdb2vg2/rdb2vg2_512_votk)

[CSSD] 2016-06-07 04 clssnmDiskStateChange 02 to 38.915 [1] > TRACE: state from 1 to 2 disk (2//dev/essdb2vg3/rdb2vg3_512_votk)

[CSSD] 2016-06-07 04 clssnmvDPT 02 spawned for disk 38.915 [8] > clssnmvDPT: spawned for disk 2 (/ dev/essdb2vg3/rdb2vg3_512_votk)

[CSSD] 2016-06-07 04 clssnmDiskStateChange 02 to 40.926 [6] > TRACE: state from 2 to 4 disk (0//dev/essdb2vg1/rdb2vg1_512_votk)

[CSSD] 2016-06-07 04 clssnmvKillBlockThread 02 spawned for disk 40.927 [9] > TRACE: spawned for disk 0 (/ dev/essdb2vg1/rdb2vg1_512_votk) initial sleep interval (1000) ms

[CSSD] 2016-06-07 04 TRACE: clssnmReadDskHeartbeat: node (2) is down. Rcfg (1) wrtcnt (6) LATS (1433998) Disk lastSeqNo (6)

[CSSD] 2016-06-07 04 clssnmDiskStateChange 02 to 40.928 [7] > TRACE: state from 2 to 4 disk (1//dev/essdb2vg2/rdb2vg2_512_votk)

[CSSD] 2016-06-07 04 clssnmvKillBlockThread 02 spawned for disk 40.929 [10] > TRACE: spawned for disk 1 (/ dev/essdb2vg2/rdb2vg2_512_votk) initial sleep interval (1000) ms

[CSSD] 2016-06-07 04 TRACE: clssnmReadDskHeartbeat: node (2) is down. Rcfg (1) wrtcnt (6) LATS (1434001) Disk lastSeqNo (6)

[CSSD] 2016-06-07 04 clssnmDiskStateChange 02 to 40.932 [8] > TRACE: state from 2 to 4 disk (2//dev/essdb2vg3/rdb2vg3_512_votk)

[CSSD] 2016-06-07 04 clssnmvKillBlockThread 02Switzerland 40.933 [11] > TRACE: clssnmvKillBlockThread: spawned for disk 2 (/ dev/essdb2vg3/rdb2vg3_512_votk) initial sleep interval (1000) ms

[CSSD] 2016-06-07 04 TRACE: clssnmReadDskHeartbeat: node (2) is down. Rcfg (1) wrtcnt (6) LATS (1434005) Disk lastSeqNo (6)

[CSSD] 2016-06-07 04 clssnmFatalInit 02Switzerland 40.943 [1] > TRACE: clssnmFatalInit: fatal mode enabled

[CSSD] 2016-06-07 04 clssnmClusterListener clssnmClusterListener: Listening on (ADDRESS= (PROTOCOL=tcp) (HOST=essdb3-priv) (PORT=49895))

[CSSD] 2016-06-07 04 clssnmClusterListener 02clssnmClusterListener 40.977 [13] > clssnmClusterListener: Probing node essdb4 (2), probcon (6000000000251ed0)

[CSSD] 2016-06-07 04 clssnmConnComplete clssnmConnComplete: MSGSRC 2, type 6, node 2, flags 0x0001, con 6000000000251ed0, probe 6000000000251ed0

[CSSD] 2016-06-07 04 clssnmConnComplete: node 2, essdb4, con (6000000000251ed0), probcon (6000000000251ed0), ninfcon (00000000000000), node unique 1465243343, prev unique 0, msg unique 1465243343 node state 0

[CSSD] 2016-06-07 04 clssnmConnComplete: connected to node 2 (con 6000000000251ed0), ninfcon (6000000000251ed0), state (0), flag

[CSSD] 2016-06-07 04 clssgmclientlsnr clssgmclientlsnr: listening on (ADDRESS= (PROTOCOL=ipc) (KEY=Oracle_CSS_LclLstnr_crs_1))

[CSSD] 2016-06-07 04 clssgmclientlsnr clssgmclientlsnr: listening on (ADDRESS= (PROTOCOL=ipc) (KEY=OCSSD_LL_essdb3_crs))

[CSSD] 2016-06-07 04 clssgmPeerListener clssgmPeerListener: Listening on (ADDRESS= (PROTOCOL=tcp) (DEV=27) (HOST=192.168.1.3) (PORT=49894))

[CSSD] 2016-06-07 04 clssnmHandleSync 02 diskTimeout set to 43.568 [13] > clssnmHandleSync: diskTimeout set to (597000) ms

[CSSD] 2016-06-07 04 clssnmRcfgMgrThread 02clssnmRcfgMgrThread 43.568 [20] > clssnmRcfgMgrThread: initial lastleader (2) unique (1465243343)

[CSSD] 2016-06-07 04 clssnmHandleSync: Acknowledging sync: src [2] srcName [essdb4] seq [1] sync [1]

[CSSD] 2016-06-07 04 clssnmSendVoteInfo 02 node 43.569 [13] > clssnmSendVoteInfo: node (2) syncSeqNo (1)

[CSSD] 2016-06-07 04 clssnmUpdateNodeState 02Switzerland 43.570 [13] > TRACE: clssnmUpdateNodeState: node 0, state (0max 0) unique (0max 0) prevConuni (0) birth (0max 0) (old/new)

[CSSD] 2016-06-07 04 clssnmUpdateNodeState 02Switzerland 43.570 [13] > TRACE: clssnmUpdateNodeState: node 1, state (1) unique (1465243348) prevConuni (0) birth (0) (old/new)

[CSSD] 2016-06-07 04 clssnmUpdateNodeState 02VR 43.570 [13] > TRACE: clssnmUpdateNodeState: node 2, state (1 birth 3) unique (1465243343 ax 1465243343) prevConuni (0) birth (0 Accord 1) (old/new)

[CSSD] 2016-06-07 04 clssnmHandleUpdate 02 clssnmHandleUpdate 43.570 [13] > clssnmHandleUpdate: SYNC (1) from node (2) completed

[CSSD] 2016-06-07 04 clssnmHandleUpdate 02 NODE 43.570 [13] > clssnmHandleUpdate: NODE 1 (essdb3) IS ACTIVE MEMBER OF CLUSTER

[CSSD] 2016-06-07 04 clssnmHandleUpdate 02 NODE 43.570 [13] > clssnmHandleUpdate: NODE 2 (essdb4) IS ACTIVE MEMBER OF CLUSTER

[CSSD] 2016-06-07 04 clssnmHandleUpdate 02 diskTimeout set to 43.570 [13] > clssnmHandleUpdate: diskTimeout set to (597000) ms

[CSSD] 2016-06-07 04 NMEVENT_SUSPEND 02Switzerland 43.620 [1] > USER: NMEVENT_SUSPEND [00] [00] [00] [00]

[CSSD] 2016-06-07 04 clssgmReconfigThread 02clssgmReconfigThread 43.622 [21] > clssgmReconfigThread: started for reconfig (1)

[CSSD] 2016-06-07 04 NMEVENT_RECONFIG 02bureau 43.622 [21] > USER: NMEVENT_RECONFIG [00] [00] [06]

[CSSD] 2016-06-07 04 clssgmEstablishConnections 02 nodes in cluster incarn 43.622 [21] > clssgmEstablishConnections: 2 nodes in cluster incarn 1

[CSSD] 2016-06-07 04 clssgmInitialRecv clssgmInitialRecv: (6000000000ad6ed0) accepted a new connection from node 2 born at 1 active (2,2), vers

[CSSD] 2016-06-07 04 clssgmInitialRecv 02Switzerland 43.624 [17] > TRACE: clssgmInitialRecv: conns done (2Accord 2)

[CSSD] 2016-06-07 04 clssgmEstablishMasterNode 02clssgmEstablishMasterNode 43.624 [21] > clssgmEstablishMasterNode: MASTER for 1 is node (1) birth (1)

[CSSD] 2016-06-07 04 clssgmChangeMasterNode 02 requeued 43.624 [21] > clssgmChangeMasterNode: requeued 0 RPCs

[CSSD] 2016-06-07 04 clssgmMasterCMSync 02Switzerland 43.624 [21] > TRACE: clssgmMasterCMSync: Synchronizing group/lock status

[CSSD] 2016-06-07 04 clssgmMasterSendDBDone 02Switzerland 43.624 [21] > TRACE: clssgmMasterSendDBDone: group/lock status synchronization complete

[CSSD] CLSS-3000: reconfiguration successful, incarnation 1 with 2 nodes

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

[CSSD] 2016-06-07 04 clssgmReconfigThread 02VR 43.631 [21] > TRACE: clssgmReconfigThread: completed for reconfig (1), with status (1)

[CSSD] 2016-06-07 04 clssgmCommonAddMember 02clssgmCommonAddMember 43.751 [14] > clsomon joined (1/0x1000000/#CSS_CLSSOMON)

[CSSD] 2016-06-07 04 clssgmAssignMemberNo 08Switzerland 21.574 [17] > WARNING: clssgmAssignMemberNo (): grock (CRSDMAIN) memberNo (2) already assigned

Evmd log:

2016-06-07 04 02V 51.086: [EVMD] [1] EVMD Starting

2016-06-07 04Partition 02Vero 51.086: [EVMD] [1]

Oracle Database 10g CRS Release 10.2.0.4.0 Production Copyright 1996, 2007, Oracle. All rights reserved

2016-06-07 04 02V 51.086: [EVMD] [1] Initializing OCR

2016-06-07 04 02V 51.108: [EVMD] [1] Active Version from OCR:10.2.0.4.0

2016-06-07 04 02V 51.108: [EVMD] [1] Active Version and Software Version are same

2016-06-07 04 02V 51.108: [EVMD] [1] Initializing Diagnostics Settings

2016-06-07 04 allcomp 02 allcomp 51.112: [EVMD] [1]

2016-06-07 04 default 0215: [EVMD] [1] ENV Logging level for Module: default 0

2016-06-07 04 COMMCRS 02 COMMCRS 51.117: [EVMD] [1]

2016-06-07 04 COMMNS 02 COMMNS 51.119: [EVMD] [1]

2016-06-07 04 EVMD 02 EVMD 51.122: [EVMD] [1]

2016-06-07 04 EVMDMAIN 02 ENV Logging level for Module 51.125: [EVMD] [1]

2016-06-07 04 EVMCOMM 02 ENV Logging level for Module 51.127: [EVMD] [1]

2016-06-07 04 EVMEVT 02 EVMEVT 51.130: [EVMD] [1]

2016-06-07 04 EVMAPP 02 ENV Logging level for Module 51.132: [EVMD] [1]

2016-06-07 04 ENV Logging level for Module 02 EVMAGENT 51.133: [EVMD] [1]

2016-06-07 04 CRSOCR 02 CRSOCR 51.135: [EVMD] [1]

2016-06-07 04 CLUCLS 02 CLUCLS 51.136: [EVMD] [1]

2016-06-07 04 OCRRAW 02 OCRRAW 51.138: [EVMD] [1]

2016-06-07 04 OCROSD 02 OCROSD 51.141: [EVMD] [1]

2016-06-07 04 OCRAPI 02 OCRAPI 51.142: [EVMD] [1]

2016-06-07 04 OCRUTL 02 OCRUTL 51.144: [EVMD] [1]

2016-06-07 04 OCRMSG 02 OCRMSG 51.146: [EVMD] [1]

2016-06-07 04 OCRCLI 02 OCRCLI 51.148: [EVMD] [1]

2016-06-07 04 CSSCLNT 02 CSSCLNT 51.149: [EVMD] [1]

2016-06-07 04 oracle/product/10.2/crs/evm/init/essdb3.pid 02 Creating pidfile 51.150: [EVMD] [1]

[clsdmt] [4] Listening to (ADDRESS= (PROTOCOL=ipc) (KEY=essdb3DBG_EVMD))

2016-06-07 04 02 Authorization database built successfully 51.162: [EVMD] [1].

2016-06-07 04 EVM Listening on 02 EVM Listening on 53.370: [EVMEVT] [1] [ENTER]

2016-06-07 04 Address already in use 02 COMMCRS: [COMMCRS] [6] clsclisten: Address already in use: (ADDRESS= (PROTOCOL=tcp) (HOST=essdb3-priv) (PORT=49897))

2016-06-07 04 02V 53.393: [EVMAPP] [1] EVMD Started

2016-06-07 04 Address already in use 02 Address already in use 53.393: [COMMCRS] [9] clsclisten: (ADDRESS= (PROTOCOL=tcp) (HOST=essdb3-priv) (PORT=49898))

2016-06-07 04 listening at 02V 53.396: [EVMEVT] [12] Default port busy, listening at (ADDRESS= (PROTOCOL=tcp) (HOST=192.168.1.3) (PORT=49905))

2016-06-07 04 Response message returned with failure keyname 02 Response message returned with failure keyname 53.397: [OCRCLI] [12] proac_set_value: Response message returned with failure keyname = [SYSTEM.evm.cevmport.essdb3], retcode = 5

2016-06-07 04 EVMD exiting 02 EVMD exiting: [EVMEVT] [12] [PANIC]. Couldn't update OCR key rc = 5

2016-06-07 04 EVMD exiting 02 EVMD exiting: [EVMD] [12] [PANIC].

2016-06-07 04 02V 53.398: [EVMD] [12] Done.

2016-06-07 04 0215 54.500: [EVMD] [1] EVMD Starting

2016-06-07 04Partition 02Discovery 54.501: [EVMD] [1]

Oracle Database 10g CRS Release 10.2.0.4.0 Production Copyright 1996, 2007, Oracle. All rights reserved

2016-06-07 04 02V 54.501: [EVMD] [1] Initializing OCR

2016-06-07 04 02V 54.522: [EVMD] [1] Active Version from OCR:10.2.0.4.0

2016-06-07 04 02V 54.522: [EVMD] [1] Active Version and Software Version are same

2016-06-07 04 02V 54.523: [EVMD] [1] Initializing Diagnostics Settings

2016-06-07 04 allcomp 02V 54.526: [EVMD] [1] ENV Logging level for Module: allcomp 0

2016-06-07 04 default 02V 54.528: [EVMD] [1] ENV Logging level for Module: default 0

2016-06-07 04 COMMCRS 0215 54.530: [EVMD] [1] ENV Logging level for Module: COMMCRS 0

2016-06-07 04 COMMNS 0215 54.531: [EVMD] [1] ENV Logging level for Module: COMMNS 0

2016-06-07 04 EVMD 02 EVMD 54.533: [EVMD] [1]

2016-06-07 04 EVMDMAIN 02 EVMDMAIN 54.534: [EVMD] [1]

2016-06-07 04 EVMCOMM 0215 54.536: [EVMD] [1] ENV Logging level for Module: EVMCOMM 0

2016-06-07 04 EVMEVT 02 EVMEVT 54.539: [EVMD] [1]

2016-06-07 04 EVMAPP 02V 54.541: [EVMD] [1] ENV Logging level for Module: EVMAPP 0

2016-06-07 04 EVMAGENT 02V 54.543: [EVMD] [1] ENV Logging level for Module: EVMAGENT 0

2016-06-07 04 CRSOCR 02V 54.544: [EVMD] [1] ENV Logging level for Module: CRSOCR 0

2016-06-07 04 CLUCLS 02V 54.546: [EVMD] [1] ENV Logging level for Module: CLUCLS 0

2016-06-07 04 OCRRAW 0215 54.548: [EVMD] [1] ENV Logging level for Module: OCRRAW 0

2016-06-07 04 OCROSD 02V 54.549: [EVMD] [1] ENV Logging level for Module: OCROSD 0

2016-06-07 04 OCRAPI 02 OCRAPI 54.551: [EVMD] [1]

2016-06-07 04 OCRUTL 02 OCRUTL 54.552: [EVMD] [1]

2016-06-07 04 OCRMSG 0215 54.554: [EVMD] [1] ENV Logging level for Module: OCRMSG 0

2016-06-07 04 OCRCLI 02 OCRCLI 54.556: [EVMD] [1]

2016-06-07 04 CSSCLNT 02 CSSCLNT 54.558: [EVMD] [1]

2016-06-07 04 oracle/product/10.2/crs/evm/init/essdb3.pid 02lo 54.559: [EVMD] [1] Creating pidfile / oracle/product/10.2/crs/evm/init/essdb3.pid

[clsdmt] [4] Listening to (ADDRESS= (PROTOCOL=ipc) (KEY=essdb3DBG_EVMD))

2016-06-07 04 02V 54.574: [EVMD] [1] Authorization database built successfully.

2016-06-07 04 EVM Listening on 02 EVM Listening on 56.731: [EVMEVT] [1] [ENTER]

2016-06-07 04 Address already in use 02 COMMCRS: [COMMCRS] [6] clsclisten: Address already in use: (ADDRESS= (PROTOCOL=tcp) (HOST=essdb3-priv) (PORT=49897))

2016-06-07 04 Address already in use 02 Address already in use: [COMMCRS] [9] clsclisten: (ADDRESS= (PROTOCOL=tcp) (HOST=essdb3-priv) (PORT=49898))

2016-06-07 04 02V 56.759: [EVMAPP] [1] EVMD Started

2016-06-07 04 listening at 02 EVMEVT: [EVMEVT] [12] Default port busy, listening at (ADDRESS= (PROTOCOL=tcp) (HOST=192.168.1.3) (PORT=49907))

2016-06-07 04 Response message returned with failure keyname 02V 56.767: [OCRCLI] [12] proac_set_value: Response message returned with failure keyname = [SYSTEM.evm.cevmport.essdb3], retcode = 5

2016-06-07 04 EVMD exiting 02 EVMD exiting: [EVMEVT] [12] [PANIC] Couldn't update OCR key rc = 5

2016-06-07 04 EVMD exiting 02 EVMD exiting: [EVMD] [12] [PANIC]

2016-06-07 04 02V 56.768: [EVMD] [12] Done.

Alert log:

2016-06-07 04purl 02purl 44.208

[evmd (9218)] CRS-1401:EVMD started on node essdb3.

2016-06-07 04For 02purl 47.748

[evmd (9682)] CRS-1401:EVMD started on node essdb3.

2016-06-07 04For 02purl 51.151

[evmd (9788)] CRS-1401:EVMD started on node essdb3.

2016-06-07 04purl 02purl 54.559

[evmd (9894)] CRS-1401:EVMD started on node essdb3.

2016-06-07 04Disc 02VOV 57.988

[evmd (10005)] CRS-1401:EVMD started on node essdb3.

2016-06-07 04For 03WR 01.329

[evmd (10111)] CRS-1401:EVMD started on node essdb3.

2016-06-07 04Disc 03VOUL 04.720

[evmd (10222)] CRS-1401:EVMD started on node essdb3.

2016-06-07 04 purl 03 purl 08.117

[evmd (10339)] CRS-1401:EVMD started on node essdb3.

2016-06-07 04 purl 03purl 11.435

[evmd (10447)] CRS-1401:EVMD started on node essdb3.

The CPU resources of the host are also very tight, which is basically top 5 occupied by the evmlogger process.

It is suspected that it is an OCR problem. Try to see the permissions.

Essdb3_ Oracle [/ oraclelog/admin/essdb2/bdump] $ocrcheck

Status of Oracle Cluster Registry is as follows:

Version: 2

Total space (kbytes): 524044

Used space (kbytes): 4372

Available space (kbytes): 519672

ID: 1612984325

Device/File Name: / dev/essdb2vg1/rdb2vg1_512_ocr

Device/File integrity check succeeded

Device/File Name: / dev/essdb2vg2/rdb2vg2_512_ocr

Device/File integrity check succeeded

Cluster registry integrity check succeeded

Essdb3_ Oracle [/ oraclelog/admin/essdb2/bdump] $ll / dev/essdb2vg1/rdb2vg1_512_ocr

Crw-r- 1 root oinstall 128 0x0200bc 18 May 2011 / dev/essdb2vg1/rdb2vg1_512_ocr

Essdb3_ Oracle [/ oraclelog/admin/essdb2/bdump] $ll / dev/essdb2vg2/rdb2vg2_512_ocr

Crw-r- 1 root oinstall 128 0x0300bc 18 May 2011 / dev/essdb2vg2/rdb2vg2_512_ocr

By analyzing the evmd log of the essdb3 node, it is found that the evmd process has been unable to start. The following error message that the default port of the evmd process is occupied repeatedly appears as follows:

2016-06-07 04 Address already in use 02 COMMCRS: [COMMCRS] [6] clsclisten: Address already in use: (ADDRESS= (PROTOCOL=tcp) (HOST=essdb3-priv) (PORT=49897))

2016-06-07 04 Address already in use 02 Address already in use: [COMMCRS] [9] clsclisten: (ADDRESS= (PROTOCOL=tcp) (HOST=essdb3-priv) (PORT=49898))

Log information Oracle Bug 8200527 describes the same, BUG 8200527 information, as follows:

MOS document EVMD Coredumps When Starting Up (Doc ID 1091803.1) information, with the following recommendations:

Check the processes occupying port 4989749898 and restart the cluster. Evmd is back to normal and is not rebooting

Welcome to subscribe "Shulou Technology Information " to get latest news, interesting things and hot topics in the IT industry, and controls the hottest and latest Internet news, technology news and IT industry trends.