导航：首页 > 数据库 >

Evmd进程不断重启原因深究

发表于：2024-12-03 作者：千家信息网编辑

千家信息网最后更新 2024年12月03日，客户现场环境，全国性7*24小时在线系统，HP-ux B11.31 for Oracle 10.2.0.4 RAC双节点集群。客户于6月7日做了主机层面硬件变更，数据库未做任何参数更改。启动起来后发现

千家信息网最后更新 2024年12月03日Evmd进程不断重启原因深究

客户现场环境，全国性7*24小时在线系统，HP-ux B11.31 for Oracle 10.2.0.4 RAC双节点集群。

客户于6月7日做了主机层面硬件变更，数据库未做任何参数更改。启动起来后发现evmd进程一直在不断重启。evmd：事件管理守护进程。此进程还负责启动racgevt进程以管理FAN服务器端调用。各log也都有相应体现；

ocssd进程log：

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

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

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

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

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

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

)

[ CSSD]2016-06-07 04:02:38.904 [1] >TRACE: clssnmNMInitialize: misscount set to (600)

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

[ CSSD]2016-06-07 04:02:40.978 [13] >TRACE: clssnmConnComplete: node 2, essdb4, con(6000000000251ed0), probcon(6000000000251ed0), ninfcon(0000000000000000), node unique 1465243343, prev unique 0, msg unique 1465243343 node state 0

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

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

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

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

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

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

[ CSSD]2016-06-07 04:02:43.568 [13] >TRACE: clssnmHandleSync: Acknowledging sync: src[2] srcName[essdb4] seq[1] sync[1]

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

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

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

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

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

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

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

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

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

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

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

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

[ CSSD]2016-06-07 04:02:43.624 [17] >TRACE: clssgmInitialRecv: (6000000000ad6ed0) accepted a new connection from node 2 born at 1 active (2, 2), vers (10,3,1,2)

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

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

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

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

[ CSSD]2016-06-07 04:02: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:02:43.631 [21] >TRACE: clssgmReconfigThread: completed for reconfig(1), with status(1)

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

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

evmd日志：

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

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

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

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

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

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

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

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

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

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

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

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

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

2016-06-07 04:02:51.130: [ EVMD][1] ENV Logging level for Module: EVMEVT 0

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

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

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

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

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

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

2016-06-07 04:02:51.142: [ EVMD][1] ENV Logging level for Module: OCRAPI 0

2016-06-07 04:02:51.144: [ EVMD][1] ENV Logging level for Module: OCRUTL 0

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

2016-06-07 04:02:51.148: [ EVMD][1] ENV Logging level for Module: OCRCLI 0

2016-06-07 04:02:51.149: [ EVMD][1] ENV Logging level for Module: CSSCLNT 0

2016-06-07 04:02:51.150: [ 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:02:51.162: [ EVMD][1] Authorization database built successfully.

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

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

2016-06-07 04:02:54.539: [ EVMD][1] ENV Logging level for Module: EVMEVT 0

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

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

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

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

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

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

2016-06-07 04:02:54.551: [ EVMD][1] ENV Logging level for Module: OCRAPI 0

2016-06-07 04:02:54.552: [ EVMD][1] ENV Logging level for Module: OCRUTL 0

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

2016-06-07 04:02:54.556: [ EVMD][1] ENV Logging level for Module: OCRCLI 0

2016-06-07 04:02:54.558: [ EVMD][1] ENV Logging level for Module: CSSCLNT 0

2016-06-07 04:02: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:02:54.574: [ EVMD][1] Authorization database built successfully.

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

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

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

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

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

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

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

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

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

alert日志：

2016-06-07 04:02:44.208

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

2016-06-07 04:02:47.748

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

2016-06-07 04:02:51.151

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

2016-06-07 04:02:54.559

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

2016-06-07 04:02:57.988

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

2016-06-07 04:03:01.329

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

2016-06-07 04:03:04.720

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

2016-06-07 04:03:08.117

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

2016-06-07 04:03:11.435

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

主机的CPU资源也使用的特别紧张，基本上是evmlogger进程占用的top 5

怀疑是OCR方面的问题，试着看看权限

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 2011年5月18日 /dev/essdb2vg1/rdb2vg1_512_ocr
essdb3_oracle[/oraclelog/admin/essdb2/bdump]$ll /dev/essdb2vg2/rdb2vg2_512_ocr
crw-r----- 1 root oinstall 128 0x0300bc 2011年5月18日 /dev/essdb2vg2/rdb2vg2_512_ocr