早上跟小荷 @oracleblog 探讨说利用srvctl 和sqlplus启动Oracle实例上有什么不同,大概的工作过程是怎样的。 并且他在Solaris上遇到了一个因为project设置问题导致srvctl启动失败的bug,详细过程可以参考这个帖子。
今天就简单介绍下在Oracle 11gR2中利用srvctl启动和停止Oracle instance的过程以及对应的日志查看方法。
简单来说,过程就是:srvctl->srvm (UIserver)->CRSD PE(proxy engine)->CRSD AGFW(agent framework)->agent->GIMH
1)环境是11.2.0.3,Linux64bit,两个节点的RAC
$ ./crsctl query crs activeversion Oracle Clusterware active version on the cluster is [11.2.0.3.0] [Wed Nov 30 09:11:43][crsusr@node05:/scratch/u01/11203/grid/bin] $
2)首先检查下,当前的数据库状态和资源状态
$ date; ./srvctl status database -d mynewracdb Wednesday, November 30, 2011 9:07:47 AM UTC Instance mynewrac1 is running on node node05 Instance mynewrac2 is running on node node06 [Wed Nov 30 09:07:50][crsusr@node05:/scratch/u01/11203/grid/bin] $ ./crsctl stat res -t ... ora.mynewracdb.db 1 ONLINE ONLINE node05 Open 2 ONLINE ONLINE node06 Open ora.oc4j 1 ONLINE ONLINE node05 ora.scan1.vip 1 ONLINE ONLINE node06 ora.scan2.vip 1 ONLINE ONLINE node05 ora.scan3.vip 1 ONLINE ONLINE node05 ...
3)停止数据库在节点1上的实例,查看crsd日志和agent日志
$ date; ./srvctl stop instance -d mynewracdb -i mynewrac1 Wednesday, November 30, 2011 9:08:59 AM UTC [Wed Nov 30 09:09:21][crsusr@node05:/scratch/u01/11203/grid/bin] $ ./crsctl stat res -t -------------------------------------------------------------------------------- NAME TARGET STATE SERVER STATE_DETAILS -------------------------------------------------------------------------------- Local Resources -------------------------------------------------------------------------------- ora.DB_DG.dg ONLINE ONLINE node05 ONLINE ONLINE node06 ora.LISTENER.lsnr ONLINE ONLINE node05 ONLINE ONLINE node06 ora.OCR_VD.dg ONLINE ONLINE node05 ONLINE ONLINE node06 ora.asm ONLINE ONLINE node05 Started ONLINE ONLINE node06 Started ora.gsd OFFLINE OFFLINE node05 OFFLINE OFFLINE node06 ora.net1.network ONLINE ONLINE node05 ONLINE ONLINE node06 ora.ons ONLINE ONLINE node05 ONLINE ONLINE node06 ora.registry.acfs ONLINE ONLINE node05 ONLINE ONLINE node06 -------------------------------------------------------------------------------- Cluster Resources -------------------------------------------------------------------------------- ora.LISTENER_SCAN1.lsnr 1 ONLINE ONLINE node06 ora.LISTENER_SCAN2.lsnr 1 ONLINE ONLINE node05 ora.LISTENER_SCAN3.lsnr 1 ONLINE ONLINE node05 ora.cvu 1 ONLINE ONLINE node05 ora.node05.vip 1 ONLINE ONLINE node05 ora.node06.vip 1 ONLINE ONLINE node06 ora.mynewracdb.db 1 OFFLINE OFFLINE Instance Shutdown 2 ONLINE ONLINE node06 Open ora.oc4j 1 ONLINE ONLINE node05 ora.scan1.vip 1 ONLINE ONLINE node06 ora.scan2.vip 1 ONLINE ONLINE node05 ora.scan3.vip 1 ONLINE ONLINE node05 [Wed Nov 30 09:09:45][crsusr@node05:/scratch/u01/11203/grid/bin] $ crsd.log 日志 /scratch/u01/11203/grid/log/node05/crsd crsd.log 30559 2011-11-30 09:09:02.508: [UiServer][49] CS(103727c10)set Properties ( crsusr,10330b690) ===>UI server 收到停止的命令,发给Proxy Engine 30560 2011-11-30 09:09:02.527: [UiServer][48] {1:52451:782} Sending message to PE. ctx= 1047fa450, Client PID: 16523 30561 2011-11-30 09:09:02.529: [ CRSPE][47] {1:52451:782} Processing PE command id=838. Description: [Stat Resource : 104622f50] 30562 2011-11-30 09:09:02.532: [ CRSPE][47] {1:52451:782} Expression Filter : ((TYPE == ora.database.type) AND (NAME == ora.mynewracdb.db)) 30563 2011-11-30 09:09:02.557: [UiServer][48] {1:52451:782} Done for ctx=1047fa450 30564 2011-11-30 09:09:02.678: [UiServer][49] CS(103727c10)set Properties ( crsusr,10384c290) 30565 2011-11-30 09:09:02.696: [UiServer][48] {1:52451:783} Container [ Name: UI_STOP 30566 API_HDR_VER: 30567 TextMessage[2] 30568 CLIENT: 30569 TextMessage[] 30570 CLIENT_NAME: 30571 TextMessage[/scratch/u01/11203/grid/jdk/jre/bin/sparcv9/java] 30572 CLIENT_PID: 30573 TextMessage[16523] 30574 CLIENT_PRIMARY_GROUP: 30575 TextMessage[oinstall] 30576 FILTER: 30577 TextMessage[(^A(^A(^A(^A(^A(^ANAME^Ast^Aora.mynewracdb.^A)^A&&^A(^ANAME^Aen^A.svc^A)^A)^A&&^A(^ATYPE^A==^Aora.service.type^A)^A)^A&&^A(^A(^ASTATE^A!=^AOFFLINE^A)^A||^A(^ATARGET^A!=^ AOFFLINE^A)^A)^A)^A||^A(^A(^A(^ANAME^A==^Aora.mynewracdb.db^A)^A&&^A(^ATYPE^A==^Aora.database.type^A)^A)^A&&^A(^ASTATE^A!=^AOFFLINE^A)^A)^A)^A&&^A(^ALAST_SERVER^A==^Anode05^A)^A)] 30578 FILTER_TAG: 30579 TextMessage[1] 30580 KEEP_D_TARGETS_TAG: 30581 TextMessage[1] 30582 LOCALE: 30583 TextMessage[AMERICAN_AMERICA.US7ASCII] 30584 QUEUE_TAG: 30585 TextMessage[1] 30586 ] 30587 2011-11-30 09:09:02.697: [UiServer][48] {1:52451:783} Sending message to PE. ctx= 1047fb9d0, Client PID: 16523 30588 2011-11-30 09:09:02.698: [ CRSPE][47] {1:52451:783} Cmd : 104622f50 : flags: KEEP_D_TARGETS_TAG | QUEUE_TAG 30589 2011-11-30 09:09:02.699: [ CRSPE][47] {1:52451:783} Processing PE command id=839. Description: [Stop Resource : 104622f50] 30590 2011-11-30 09:09:02.703: [ CRSPE][47] {1:52451:783} Expression Filter : ((((((NAME st ora.mynewracdb.) AND (NAME en .svc)) AND (TYPE == ora.service.type)) AND ((STATE != OFFLINE) OR (TARG ET != OFFLINE))) OR (((NAME == ora.mynewracdb.db) AND (TYPE == ora.database.type)) AND (STATE != OFFLINE))) AND (LAST_SERVER == node05)) 30591 2011-11-30 09:09:02.713: [ CRSPE][47] {1:52451:783} Expression Filter : ((((((NAME st ora.mynewracdb.) AND (NAME en .svc)) AND (TYPE == ora.service.type)) AND ((STATE != OFFLINE) OR (TARG ET != OFFLINE))) OR (((NAME == ora.mynewracdb.db) AND (TYPE == ora.database.type)) AND (STATE != OFFLINE))) AND (LAST_SERVER == node05)) 30592 2011-11-30 09:09:02.737: [ CRSPE][47] {1:52451:783} RI [ora.mynewracdb.db 1 1] new target state: [OFFLINE] old value: [ONLINE] 30593 2011-11-30 09:09:02.740: [ CRSOCR][45] {1:52451:783} Multi Write Batch processing... 30594 2011-11-30 09:09:02.742: [ CRSPE][47] {1:52451:783} RI [ora.mynewracdb.db 1 1] new internal state: [STOPPING] old value: [STABLE] ===> PE发送诶agent framework 30595 2011-11-30 09:09:02.744: [ CRSPE][47] {1:52451:783} Sending message to agfw: id = 22058 30596 2011-11-30 09:09:02.744: [ AGFW][42] {1:52451:783} Agfw Proxy Server received the message: RESOURCE_STOP[ora.mynewracdb.db 1 1] ID 4099:22058 30597 2011-11-30 09:09:02.744: [ CRSPE][47] {1:52451:783} CRS-2673: Attempting to stop 'ora.mynewracdb.db' on 'node05' 30598 30599 2011-11-30 09:09:02.745: [ AGFW][42] {1:52451:783} Agfw Proxy Server forwarding the message: RESOURCE_STOP[ora.mynewracdb.db 1 1] ID 4099:22058 to the agent /scratch/u01/11203/grid/bin/o raagent_crsusr 30600 2011-11-30 09:09:02.749: [UiServer][48] {1:52451:783} Container [ Name: ORDER 30601 MESSAGE: 30602 TextMessage[CRS-2673: Attempting to stop 'ora.mynewracdb.db' on 'node05'] 30603 MSGTYPE: 30604 TextMessage[3] 30605 OBJID: 30606 TextMessage[ora.mynewracdb.db 1 1] 30607 WAIT: 30608 TextMessage[0] 30609 ] 30610 2011-11-30 09:09:02.809: [ CRSOCR][45] {1:52451:783} Multi Write Batch done. 30611 2011-11-30 09:09:13.319: [UiServer][49] CS(10333fad0)set Properties ( crsusr,1043d8e50) 30612 2011-11-30 09:09:13.336: [UiServer][48] {1:52451:784} Container [ Name: UI_STOP 30613 API_HDR_VER: 30614 TextMessage[2] 30615 CLIENT: 30616 TextMessage[] 30617 CLIENT_NAME: 30618 TextMessage[Unknown process] 30619 CLIENT_PID: 30620 TextMessage[9788] 30621 CLIENT_PRIMARY_GROUP: 30622 TextMessage[oinstall] 30623 EVENT_TAG: 30624 TextMessage[1] 30625 FILTER: 30626 TextMessage[(^A(^A(^ANAME^A==^Aora.mynewracdb.db^A)^A&&^A(^ALAST_SERVER^A==^Anode05^A)^A)^A&&^A(^ASTATE^A!=^AOFFLINE^A)^A)^AUSR_ORA_OPI=true^AUSR_ORA_INST_NAME=mynewrac1] 30627 FILTER_TAG: 30628 TextMessage[1] 30629 FORCE_TAG: 30630 TextMessage[1] 30631 LOCALE: 30632 TextMessage[AMERICAN_AMERICA.WE8ISO8859P1] 30633 NO_WAIT_TAG: 30634 TextMessage[1] 30635 ] 30636 2011-11-30 09:09:13.337: [UiServer][48] {1:52451:784} Sending message to PE. ctx= 1047fa890, Client PID: 9788 30637 2011-11-30 09:09:13.339: [ CRSPE][47] {1:52451:784} Cmd : 104622950 : flags: EVENT_TAG | FORCE_TAG 30638 2011-11-30 09:09:13.339: [ CRSPE][47] {1:52451:784} Processing PE command id=840. Description: [Stop Resource : 104622950] 30639 2011-11-30 09:09:13.341: [ CRSPE][47] {1:52451:784} Expression Filter : (((NAME == ora.mynewracdb.db) AND (LAST_SERVER == node05)) AND (STATE != OFFLINE)) 30640 2011-11-30 09:09:13.345: [ CRSPE][47] {1:52451:784} Expression Filter : (((NAME == ora.mynewracdb.db) AND (LAST_SERVER == node05)) AND (STATE != OFFLINE)) 30641 2011-11-30 09:09:13.354: [ CRSPE][47] {1:52451:784} Attribute overrides for the command: USR_ORA_INST_NAME = mynewrac1;USR_ORA_OPI = true; ====》 PE处理完毕,发给我UIserver,并由UIserver返回给sender,也就是最终的用户UI,在这里是svrctl 30642 2011-11-30 09:09:13.367: [ CRSPE][47] {1:52451:784} PE Command [ Stop Resource : 104622950 ] has completed 30643 2011-11-30 09:09:13.368: [ CRSPE][47] {1:52451:784} UI Command [Stop Resource : 104622950] is replying to sender. agent 日志 /scratch/u01/11203/grid/log/node05/agent/crsd/oraagent_crsusr oraagent_crsusr.log ====> agent 收到PE 发来的命令,开始准备停止的命令 2011-11-30 09:09:02.759: [ AGFW][10] {1:52451:783} Agent received the message: RESOURCE_STOP[ora.mynewracdb.db 1 1] ID 4099:22059 2011-11-30 09:09:02.759: [ AGFW][10] {1:52451:783} Preparing STOP command for: ora.mynewracdb.db 1 1 2011-11-30 09:09:02.759: [ AGFW][10] {1:52451:783} ora.mynewracdb.db 1 1 state changed from: ONLINE to: STOPPING 2011-11-30 09:09:02.767: [ora.mynewracdb.db][18] {1:52451:783} [stop] (:CLSN00108:) clsn_agent::stop { 2011-11-30 09:09:02.768: [ora.mynewracdb.db][18] {1:52451:783} [stop] InstAgent::stop_option stop mode immediate option 1 2011-11-30 09:09:02.768: [ora.mynewracdb.db][18] {1:52451:783} [stop] InstAgent::stop { 2011-11-30 09:09:02.771: [ora.mynewracdb.db][18] {1:52451:783} [stop] InstAgent::stop shutdown mode: 3 2011-11-30 09:09:02.772: [ora.mynewracdb.db][18] {1:52451:783} [stop] DbAgent::preStopCbk { 2011-11-30 09:09:02.772: [ora.mynewracdb.db][18] {1:52451:783} [stop] DbAgentEventModule::stop stopping event bridge 2011-11-30 09:09:02.805: [ USRTHRD][18] {1:52451:783} CssSemaphore::release, released semaphore CLSN.AQPROC.mynewracdb.MASTER 2011-11-30 09:09:02.805: [ USRTHRD][18] {1:52451:783} AQPROC.mynewracdb CssSemMM::relinquishMastership I am no longer the master 2011-11-30 09:09:02.810: [ USRTHRD][18] {1:52451:783} WorkerThread::removeWorker total workers: 3 2011-11-30 09:09:02.819: [ USRTHRD][18] {1:52451:783} InstConnection:~InstConnection: this 014e6fd0 2011-11-30 09:09:02.820: [ora.mynewracdb.db][18] {1:52451:783} [stop] DbAgentEventModule::stop stopping rlb event bridge 2011-11-30 09:09:02.855: [ USRTHRD][18] {1:52451:783} CssSemaphore::release, released semaphore CLSN.RLB.mynewracdb.MASTER 2011-11-30 09:09:02.855: [ USRTHRD][18] {1:52451:783} RLB.mynewracdb CssSemMM::relinquishMastership I am no longer the master 2011-11-30 09:09:02.860: [ USRTHRD][18] {1:52451:783} WorkerThread::removeWorker total workers: 2 2011-11-30 09:09:02.863: [ USRTHRD][18] {1:52451:783} InstConnection:~InstConnection: this 014e6f70 2011-11-30 09:09:02.866: [ CRSCEVT][18] {1:52451:783} ClusterPublisher::disconnect Disconnected 2011-11-30 09:09:02.867: [ USRTHRD][18] {1:52451:783} Thread:DedicatedThreadstop { 2011-11-30 09:09:02.867: [ USRTHRD][18] {1:52451:783} Thread:DedicatedThreadstop } 2011-11-30 09:09:02.867: [ora.mynewracdb.db][18] {1:52451:783} [stop] DbAgent::preStopCbk } 2011-11-30 09:09:02.869: [ora.mynewracdb.db][18] {1:52451:783} [stop] ConnectionPool::getConnection 260 pConnxn 014e76f0 2011-11-30 09:09:02.869: [ora.mynewracdb.db][18] {1:52451:783} [stop] InstAgent::stop pool pConnxn 014e76f0 2011-11-30 09:09:02.870: [ora.mynewracdb.db][18] {1:52451:783} [stop] InstConnection::shutdown mode 3 2011-11-30 09:09:07.147: [ora.mynewracdb.db][18] {1:52451:783} [stop] DbAgent::stopCbk: { 2011-11-30 09:09:07.147: [ora.mynewracdb.db][18] {1:52451:783} [stop] DbAgent::stopCbk { 2011-11-30 09:09:07.148: [ora.mynewracdb.db][18] {1:52451:783} [stop] DbAgent::stopCbk close - ALTER DATABASE CLOSE NORMAL /* db agent *//* {1:52451:783} */ 2011-11-30 09:09:13.156: [ora.mynewracdb.db][18] {1:52451:783} [stop] DbAgent::stopCbk dismount - ALTER DATABASE DISMOUNT /* db agent *//* {1:52451:783} */ 2011-11-30 09:09:13.266: [ USRTHRD][18] {1:52451:783} Thread:DedicatedThreadstop { 2011-11-30 09:09:13.266: [ USRTHRD][18] {1:52451:783} Thread:DedicatedThreadstop } 2011-11-30 09:09:13.266: [ora.mynewracdb.db][18] {1:52451:783} [stop] DbAgent::stopCbk } 2011-11-30 09:09:13.266: [ora.mynewracdb.db][18] {1:52451:783} [stop] InstConnection::shutdown mode 5 2011-11-30 09:09:18.103: [ora.asm][13] {1:52451:2} [check] CrsCmd::ClscrsCmdData::stat entity 1 statflag 1 useFilter 0 2011-11-30 09:09:18.186: [ora.asm][13] {1:52451:2} [check] AsmProxyAgent::check clsagfw_res_status 0 2011-11-30 09:09:21.785: [ora.mynewracdb.db][18] {1:52451:783} [stop] ConnectionPool::releaseConnection InstConnection 014e76f0 2011-11-30 09:09:21.786: [ora.mynewracdb.db][18] {1:52451:783} [stop] ConnectionPool::stopConnection 2011-11-30 09:09:21.786: [ora.mynewracdb.db][18] {1:52451:783} [stop] ConnectionPool::removeConnection connection count 1 2011-11-30 09:09:21.786: [ora.mynewracdb.db][18] {1:52451:783} [stop] ConnectionPool::removeConnection sid mynewrac1, InstConnection 014e76f0 2011-11-30 09:09:21.787: [ USRTHRD][18] {1:52451:783} InstConnection::breakCall pConnxn:014e76f0 DetachLock:00ac96f8 m_pSvcH:01e150b0 2011-11-30 09:09:21.787: [ USRTHRD][18] {1:52451:783} InstConnection:~InstConnection: this 014e76f0 2011-11-30 09:09:21.789: [ora.mynewracdb.db][18] {1:52451:783} [stop] ConnectionPool::removeConnection delete InstConnection 014e76f0 2011-11-30 09:09:21.789: [ora.mynewracdb.db][18] {1:52451:783} [stop] ConnectionPool::removeConnection freed 1 2011-11-30 09:09:21.789: [ora.mynewracdb.db][18] {1:52451:783} [stop] ConnectionPool::stopConnection sid mynewrac1 status 1 2011-11-30 09:09:21.790: [ora.mynewracdb.db][18] {1:52451:783} [stop] InstAgent::stop db/asm 2011-11-30 09:09:21.790: [ora.mynewracdb.db][18] {1:52451:783} [stop] ConnectionPool::stopConnection 2011-11-30 09:09:21.790: [ora.mynewracdb.db][18] {1:52451:783} [stop] ConnectionPool::removeConnection connection count 0 2011-11-30 09:09:21.791: [ora.mynewracdb.db][18] {1:52451:783} [stop] ConnectionPool::removeConnection freed 0 2011-11-30 09:09:21.791: [ora.mynewracdb.db][18] {1:52451:783} [stop] ConnectionPool::stopConnection sid mynewrac1 status 1 2011-11-30 09:09:21.791: [ora.mynewracdb.db][18] {1:52451:783} [stop] InstAgent::stop: } 2011-11-30 09:09:21.792: [ora.mynewracdb.db][18] {1:52451:783} [stop] (:CLSN00108:) clsn_agent::stop } 2011-11-30 09:09:21.792: [ AGFW][18] {1:52451:783} Command: stop for resource: ora.mynewracdb.db 1 1 completed with status: SUCCESS 2011-11-30 09:09:21.795: [ AGFW][10] {1:52451:783} Agent sending reply for: RESOURCE_STOP[ora.mynewracdb.db 1 1] ID 4099:22059 2011-11-30 09:09:21.797: [ora.mynewracdb.db][9] {1:52451:783} [check] ConnectionPool::resetConnection s_statusOfConnectionMap 00ab1f68 2011-11-30 09:09:21.797: [ora.mynewracdb.db][9] {1:52451:783} [check] ConnectionPool::resetConnection sid mynewrac1 status 2 2011-11-30 09:09:21.798: [ora.mynewracdb.db][9] {1:52451:783} [check] Gimh::check condition changes to (GIMH_NEXT_NUM) 1 exists ====》注意这里的GIMH,这是instance提供的一个接口,可以直接访问到实例,这里的agent就是通过这个接口判断instance是否healthy的,决定database资源是否online或者offline等状态。 2011-11-30 09:09:21.798: [ora.mynewracdb.db][9] {1:52451:783} [check] clsnDbAgent:checkCbk clsagfw_res_status 22 2011-11-30 09:09:21.798: [ USRTHRD][9] {1:52451:783} Thread:DedicatedThreadstop { 2011-11-30 09:09:21.798: [ USRTHRD][9] {1:52451:783} Thread:DedicatedThreadstop } 2011-11-30 09:09:21.799: [ USRTHRD][9] {1:52451:783} Gimh::destructor gimh_dest_query_ctx rc=0 2011-11-30 09:09:21.800: [ USRTHRD][9] {1:52451:783} Gimh::destructor gimh_dest_inst_ctx rc=0 2011-11-30 09:09:21.800: [ora.mynewracdb.db][9] {1:52451:783} [check] ConnectionPool::stopConnection 2011-11-30 09:09:21.800: [ora.mynewracdb.db][9] {1:52451:783} [check] ConnectionPool::removeConnection connection count 0 2011-11-30 09:09:21.801: [ora.mynewracdb.db][9] {1:52451:783} [check] ConnectionPool::removeConnection freed 0 2011-11-30 09:09:21.801: [ora.mynewracdb.db][9] {1:52451:783} [check] ConnectionPool::stopConnection sid mynewrac1 status 1 2011-11-30 09:09:21.801: [ora.mynewracdb.db][9] {1:52451:783} [check] InstAgent::check checkCounter 34 prev clsagfw_res_status 2 current clsagfw_res_status 2 2011-11-30 09:09:21.803: [ AGFW][10] {1:52451:783} ora.mynewracdb.db 1 1 state changed from: STOPPING to: PLANNED_OFFLINE 2011-11-30 09:09:21.803: [ AGFW][10] {1:52451:783} ora.mynewracdb.db 1 1 state details has changed from: Open to: Instance Shutdown 2011-11-30 09:09:21.804: [ AGFW][10] {1:52451:783} Agent sending last reply for: RESOURCE_STOP[ora.mynewracdb.db 1 1] ID 4099:22059 2011-11-30 09:09:21.829: [ USRTHRD][23] ClusterSubscriber::SubscriberWorker::InternalClusterSubscriber::handleEventCBexecuting for reason 1
4)启动实例,并再次验证crsd日志和agnet日志
$ date; ./srvctl start instance -d mynewracdb -i mynewrac1 Wednesday, November 30, 2011 9:10:48 AM UTC [Wed Nov 30 09:11:25][crsusr@node05:/scratch/u01/11203/grid/bin] $ crsd 日志类似,不再贴出来,下面看看crsd agent日志: 41386 2011-11-30 09:10:33.788: [ AGFW][10] {1:52451:2} Agent received the message: AGENT_HB[Engine] ID 12293:22088 41387 2011-11-30 09:10:50.810: [ AGFW][10] {1:52451:809} Agent received the message: RESOURCE_START[ora.mynewracdb.db 1 1] ID 4098:22138 41388 2011-11-30 09:10:50.810: [ AGFW][10] {1:52451:809} Preparing START command for: ora.mynewracdb.db 1 1 41389 2011-11-30 09:10:50.810: [ AGFW][10] {1:52451:809} ora.mynewracdb.db 1 1 state changed from: PLANNED_OFFLINE to: STARTING 41390 2011-11-30 09:10:50.818: [ora.mynewracdb.db][13] {1:52451:809} [start] (:CLSN00107:) clsn_agent::start { 41391 2011-11-30 09:10:50.819: [ora.mynewracdb.db][13] {1:52451:809} [start] InstAgent::start { 41392 2011-11-30 09:10:50.819: [ora.mynewracdb.db][13] {1:52451:809} [start] ConnectionPool::stopConnection 41393 2011-11-30 09:10:50.820: [ora.mynewracdb.db][13] {1:52451:809} [start] ConnectionPool::removeConnection connection count 0 41394 2011-11-30 09:10:50.820: [ora.mynewracdb.db][13] {1:52451:809} [start] ConnectionPool::removeConnection freed 0 41395 2011-11-30 09:10:50.820: [ora.mynewracdb.db][13] {1:52451:809} [start] ConnectionPool::stopConnection sid mynewrac1 status 1 41396 2011-11-30 09:10:50.820: [ USRTHRD][13] {1:52451:809} ConnectionPool::~ConnectionPool m_oracleHome:/scratch/u02/product/dbhome_1, m_oracleSid:mynewrac1, m_usrOraEnv: 41397 2011-11-30 09:10:50.821: [ USRTHRD][13] {1:52451:809} Thread:DedicatedThreadstop { 41398 2011-11-30 09:10:50.821: [ USRTHRD][13] {1:52451:809} Thread:DedicatedThreadstop } 41399 2011-11-30 09:10:50.822: [ora.mynewracdb.db][13] {1:52451:809} [start] DbAgent:getOracleSid 13 oracle_sid = mynewrac1 41400 2011-11-30 09:10:50.822: [ora.mynewracdb.db][13] {1:52451:809} [start] DbAgent:getOracleSid oracle_sid = mynewrac1 41401 2011-11-30 09:10:50.823: [ora.mynewracdb.db][13] {1:52451:809} [start] getOracleHomeAttrib: oracle_home = /scratch/u02/product/dbhome_1 41402 2011-11-30 09:10:50.823: [ora.mynewracdb.db][13] {1:52451:809} [start] ConnectionPool::ConnectionPool 2 m_oracleHome:/scratch/u02/product/dbhome_1, m_oracleSid:mynewrac1, m_usrOraEnv: 41403 2011-11-30 09:10:50.824: [ora.mynewracdb.db][13] {1:52451:809} [start] DbAgent::setOracleSidAttrib updating GEN_USR_ORA_INST_NAME@SERVERNAME(node05) to mynewrac1 41404 2011-11-30 09:10:50.824: [ora.mynewracdb.db][13] {1:52451:809} [start] clsnUtils::setResAttrib nonPerX current value GEN_USR_ORA_INST_NAME value mynewrac1 41405 2011-11-30 09:10:50.826: [ora.mynewracdb.db][13] {1:52451:809} [start] CrsCmd::ClscrsCmdData::stat entity 1 statflag 32 useFilter 0 41406 2011-11-30 09:10:50.899: [ora.mynewracdb.db][13] {1:52451:809} [start] setResAttrib: attr GEN_USR_ORA_INST_NAME@SERVERNAME(node05) clsagfw attribVal mynewrac1 clscrs tmpAttrValue mynewrac 1 41407 2011-11-30 09:10:50.899: [ora.mynewracdb.db][13] {1:52451:809} [start] setResAttrib clsagfw_modify_attribute attr GEN_USR_ORA_INST_NAME@SERVERNAME(node05) value mynewrac1 retCode 0 41408 2011-11-30 09:10:50.900: [ora.mynewracdb.db][13] {1:52451:809} [start] sModifyConfig for mynewracdb 41409 2011-11-30 09:10:50.900: [ora.mynewracdb.db][13] {1:52451:809} [start] getOracleHomeAttrib: oracle_home = /scratch/u02/product/dbhome_1 41410 2011-11-30 09:10:50.901: [ora.mynewracdb.db][13] {1:52451:809} [start] Utils::getCrsHome crsHome /scratch/u01/11203/grid 41411 2011-11-30 09:10:50.919: [ora.mynewracdb.db][13] {1:52451:809} [start] sclsnInstAgent::sUpdateOratab oratab is /var/opt/oracle/oratab 41412 2011-11-30 09:10:50.921: [ora.mynewracdb.db][13] {1:52451:809} [start] sclsnInstAgent::sUpdateOratab CssLock 41413 2011-11-30 09:10:50.938: [ora.mynewracdb.db][13] {1:52451:809} [start] ConfigFile::getValue name mynewracdb value 41414 2011-11-30 09:10:50.962: [ora.mynewracdb.db][13] {1:52451:809} [start] ConfigFile::updateInPlace file /var/opt/oracle/oratab is updated 41415 2011-11-30 09:10:50.962: [ora.mynewracdb.db][13] {1:52451:809} [start] sclsnInstAgent::sUpdateOratab file updated with dbName mynewracdb value /scratch/u02/product/dbhome_1:N 41416 2011-11-30 09:10:50.962: [ora.mynewracdb.db][13] {1:52451:809} [start] sclsnInstAgent::sUpdateOratab CSS unlock 41417 2011-11-30 09:10:50.977: [ora.mynewracdb.db][13] {1:52451:809} [start] ConfigFile:update file is /scratch/u02/product/dbhome_1/dbs/initmynewrac1.ora not modified 41418 2011-11-30 09:10:50.985: [ora.mynewracdb.db][13] {1:52451:809} [start] Utils::getCrsHome crsHome /scratch/u01/11203/grid 41419 2011-11-30 09:10:50.985: [ora.mynewracdb.db][13] {1:52451:809} [start] crsHome = /scratch/u01/11203/grid 41420 2011-11-30 09:10:50.985: [ora.mynewracdb.db][13] {1:52451:809} [start] oracleHome = /scratch/u02/product/dbhome_1 41421 2011-11-30 09:10:50.985: [ora.mynewracdb.db][13] {1:52451:809} [start] command = '/scratch/u01/11203/grid/bin/setasmgidwrap oracle_binary_path=/scratch/u02/product/dbhome_1/bin/oracle' 41422 2011-11-30 09:10:50.986: [ora.mynewracdb.db][13] {1:52451:809} [start] start dependency = hard(ora.DB_DG.dg) weak(type:ora.listener.type,global:type:ora.scan_listener.type,uniform:ora.ons,g lobal:ora.gns) pullup(ora.DB_DG.dg) 41423 2011-11-30 09:10:50.986: [ora.mynewracdb.db][13] {1:52451:809} [start] ASM disk group dependency found 41424 2011-11-30 09:10:50.986: [ora.mynewracdb.db][13] {1:52451:809} [start] Utils:execCmd action = 1 flags = 6 ohome = /scratch/u01/11203/grid cmdname = setasmgidwrap. 41425 2011-11-30 09:10:51.245: [ora.mynewracdb.db][13] {1:52451:809} [start] execCmd ret = 0 41426 2011-11-30 09:10:51.247: [ora.mynewracdb.db][13] {1:52451:809} [start] Utils::getCrsHome crsHome /scratch/u01/11203/grid 41427 2011-11-30 09:10:51.247: [ora.mynewracdb.db][13] {1:52451:809} [start] clsnInstConnection::makeConnectStr UsrOraEnv m_oracleHome /scratch/u02/product/dbhome_1 Crshome /scratch/u01/11203/gr id 41428 2011-11-30 09:10:51.247: [ora.mynewracdb.db][13] {1:52451:809} [start] Utils::getCrsHome crsHome /scratch/u01/11203/grid 41429 2011-11-30 09:10:51.247: [ora.mynewracdb.db][13] {1:52451:809} [start] clsnInstConnection::makeConnectStr LIBRARY_PATH1 ,LD_LIBRARY_PATH= 41430 2011-11-30 09:10:51.248: [ora.mynewracdb.db][13] {1:52451:809} [start] Utils::getCrsHome crsHome /scratch/u01/11203/grid 41431 2011-11-30 09:10:51.248: [ora.mynewracdb.db][13] {1:52451:809} [start] clsnInstConnection::makeConnectStr LIBRARY_PATH2 ,LD_LIBRARY_PATH=,LD_LIBRARY_PATH_64= 41432 2011-11-30 09:10:51.248: [ora.mynewracdb.db][13] {1:52451:809} [start] makeConnectStr = (DESCRIPTION=(ADDRESS=(PROTOCOL=beq)(PROGRAM=/scratch/u02/product/dbhome_1/bin/oracle)(ARGV0=oraclemy newrac1)(ENVS='ORACLE_HOME=/scratch/u02/product/dbhome_1,ORACLE_SID=mynewrac1,LD_LIBRARY_PATH=,LD_LIBRARY_PATH_64=')(ARGS='(DESCRIPTION=(LOCAL=YES)(ADDRESS=(PROTOCOL=beq)))'))(CONNECT_DATA=(SID=myn ewrac1))) 41433 2011-11-30 09:10:51.251: [ora.mynewracdb.db][13] {1:52451:809} [start] Container:start oracle home /scratch/u02/product/dbhome_1 41434 2011-11-30 09:10:51.251: [ora.mynewracdb.db][13] {1:52451:809} [start] InstConnection::connectInt: server not attached 41435 2011-11-30 09:10:51.470: [ora.mynewracdb.db][13] {1:52451:809} [start] InstAgent::startup ... 41561 2011-11-30 09:11:25.513: [ USRTHRD][13] {1:52451:809} DbAgentEventModule::notifyDbOpen database is now open 41562 2011-11-30 09:11:25.513: [ USRTHRD][13] {1:52451:809} DbAgentEventModule::notifyDbOpen starting AQ 41563 2011-11-30 09:11:25.513: [ USRTHRD][13] {1:52451:809} DbAgentEventModule::notifyDbOpen starting RLB 41564 2011-11-30 09:11:25.514: [ CRSCEVT][13] {1:52451:809} ClusterPublisher::connect connecting 41565 2011-11-30 09:11:25.532: [ CRSCEVT][13] {1:52451:809} ClusterPublisher::connect Connected 41566 2011-11-30 09:11:25.533: [ora.mynewracdb.db][13] {1:52451:809} [start] DbAgent::startCbk: } 41567 2011-11-30 09:11:25.535: [ora.mynewracdb.db][13] {1:52451:809} [start] InstAgent::start: startConnection pool 41568 2011-11-30 09:11:25.535: [ora.mynewracdb.db][13] {1:52451:809} [start] ConnectionPool::stopConnection 41569 2011-11-30 09:11:25.535: [ora.mynewracdb.db][13] {1:52451:809} [start] ConnectionPool::removeConnection connection count 0 41570 2011-11-30 09:11:25.536: [ora.mynewracdb.db][13] {1:52451:809} [start] ConnectionPool::removeConnection freed 0 41571 2011-11-30 09:11:25.536: [ora.mynewracdb.db][13] {1:52451:809} [start] ConnectionPool::stopConnection sid mynewrac1 status 1 41572 2011-11-30 09:11:25.536: [ USRTHRD][13] {1:52451:809} ConnectionPool::~ConnectionPool m_oracleHome:/scratch/u02/product/dbhome_1, m_oracleSid:mynewrac1, m_usrOraEnv: 41573 2011-11-30 09:11:25.536: [ora.mynewracdb.db][13] {1:52451:809} [start] ConnectionPool::ConnectionPool 2 m_oracleHome:/scratch/u02/product/dbhome_1, m_oracleSid:mynewrac1, m_usrOraEnv: 41574 2011-11-30 09:11:25.537: [ora.mynewracdb.db][13] {1:52451:809} [start] ConnectionPool::startConnection s_statusOfConnectionMap 00ab1f68 41575 2011-11-30 09:11:25.537: [ora.mynewracdb.db][13] {1:52451:809} [start] ConnectionPool::startConnection sid mynewrac1 status 2 41576 2011-11-30 09:11:25.537: [ora.mynewracdb.db][13] {1:52451:809} [start] InstAgent::start release pConnxn 01b3d528 pConnxn 41577 2011-11-30 09:11:25.538: [ora.mynewracdb.db][13] {1:52451:809} [start] ConnectionPool::releaseConnection InstConnection 019bf570 41578 2011-11-30 09:11:25.539: [ora.mynewracdb.db][13] {1:52451:809} [start] InstAgent::start: } 41579 2011-11-30 09:11:25.539: [ora.mynewracdb.db][13] {1:52451:809} [start] (:CLSN00107:) clsn_agent::start } 41580 2011-11-30 09:11:25.540: [ AGFW][13] {1:52451:809} Command: start for resource: ora.mynewracdb.db 1 1 completed with status: SUCCESS 41581 2011-11-30 09:11:25.544: [ora.mynewracdb.db][9] {1:52451:809} [check] Gimh::check OH /scratch/u02/product/dbhome_1 SID mynewrac1 41582 2011-11-30 09:11:25.544: [ AGFW][10] {1:52451:809} Agent sending reply for: RESOURCE_START[ora.mynewracdb.db 1 1] ID 4098:22138 41583 2011-11-30 09:11:25.545: [ora.mynewracdb.db][9] {1:52451:809} [check] Gimh::check condition changes to (GIMH_NEXT_NUM) 9 exists 41584 2011-11-30 09:11:25.546: [ora.mynewracdb.db][9] {1:52451:809} [check] updating GEN_START_OPTIONS from to open 41585 2011-11-30 09:11:25.546: [ USRTHRD][9] {1:52451:809} Thread:DedicatedThreadstart { 41586 2011-11-30 09:11:25.547: [ USRTHRD][9] {1:52451:809} Thread:DedicatedThreadstart } 41587 2011-11-30 09:11:25.547: [ USRTHRD][2425] {1:52451:809} DbAgent::Dedicated Thread { 41588 2011-11-30 09:11:25.548: [ USRTHRD][2425] {1:52451:809} CrsCmd::ClscrsCmdData::stat entity 1 statflag 32 useFilter 0 41589 2011-11-30 09:11:25.549: [ AGFW][10] {1:52451:809} ora.mynewracdb.db 1 1 state changed from: STARTING to: ONLINE 41590 2011-11-30 09:11:25.550: [ AGFW][10] {1:52451:809} Started implicit monitor for [ora.mynewracdb.db 1 1] interval=1000 delay=1000 41591 2011-11-30 09:11:25.550: [ AGFW][10] {1:52451:809} ora.mynewracdb.db 1 1 state details has changed from: Instance Shutdown to: Open 41592 2011-11-30 09:11:25.551: [ AGFW][10] {1:52451:809} Agent sending last reply for: RESOURCE_START[ora.mynewracdb.db 1 1] ID 4098:22138
文章来的好及时!
11.2.0.3确实和现在在用的10gR2的管理方式上有了很大的不同,在我看来复杂了不少。不知oracle是基于什么考虑整出这样的一个架构来,是为了和其他的cluster资源整合么?
这个说来话长,回头我有空博一篇,介绍一下。 ^_^