Oracle RAC备库启动service报"ORA-16000: database open for read-only access"

 

Oracle RAC备库启动service报"ORA-16000: database open for read-only access"

 

还是2019.03.01那天的事了,当时在KFT客户就遇到这个问题,最近在规整一些资料看到当时待整理的文档,就抽空做做实验整理下。

报错信息如下,ADG备库:

[oracle@xxxprdoradb01 ~]$ srvctl start service -d xxxdbdr2 -s xxxdbcss
PRCD-1084 : Failed to start service xxxdbcss
PRCR-1079 : Failed to start resource ora.xxxdbdr2.xxxdbcss.svc
CRS-5017: The resource action "ora.xxxdbdr2.xxxdbcss.svc start" encountered the following error: 
ORA-16000: database open for read-only access
ORA-06512: at "SYS.DBMS_SERVICE", line 433
ORA-06512: at "SYS.DBMS_SERVICE", line 304
ORA-06512: at line 1
. For details refer to "(:CLSN00107:)" in "/u01/oracle/grid/110203/log/xxxprdoradb01/agent/crsd/oraagent_oracle/oraagent_oracle.log".

CRS-2674: Start of 'ora.xxxdbdr2.xxxdbcss.svc' on 'xxxprdoradb01' failed
CRS-5017: The resource action "ora.xxxdbdr2.xxxdbcss.svc start" encountered the following error: 
ORA-16000: database open for read-only access
ORA-06512: at "SYS.DBMS_SERVICE", line 433
ORA-06512: at "SYS.DBMS_SERVICE", line 304
ORA-06512: at line 1
. For details refer to "(:CLSN00107:)" in "/u01/oracle/grid/110203/log/xxxprdoradb02/agent/crsd/oraagent_oracle/oraagent_oracle.log".

CRS-2674: Start of 'ora.xxxdbdr2.xxxdbcss.svc' on 'xxxprdoradb02' failed
CRS-2632: There are no more servers to try to place resource 'ora.xxxdbdr2.xxxdbcss.svc' on that would satisfy its placement policy

其中,/u01/oracle/grid/110203/log/xxxprdoradb01/agent/crsd/oraagent_oracle/oraagent_oracle.log文件相关内容如下:

2019-03-01 19:55:48.191: [    AGFW][3892311808] {1:14336:11864} Agent received the message: AGENT_HB[Engine] ID 12293:2664818
2019-03-01 19:55:49.300: [ USRTHRD][3758094080] ClusterSubscriber::SubscriberWorker::InternalClusterSubscriber::handleEventCBexecuting for reason 1
2019-03-01 19:55:49.300: [ USRTHRD][3758094080] event type is CRS_ACTION_FAILURE
2019-03-01 19:55:49.300: [ USRTHRD][3758094080] bodylen = 538
2019-03-01 19:55:49.300: [ USRTHRD][3758094080] {1:14338:56597} -----------BodyBlock----------
2019-03-01 19:55:49.300: [ USRTHRD][3758094080] {1:14338:56597}  ACTION='1'
2019-03-01 19:55:49.300: [ USRTHRD][3758094080] {1:14338:56597}  CLS_TINT='{1:14336:56597}'
2019-03-01 19:55:49.300: [ USRTHRD][3758094080] {1:14338:56597}  CURRENT_STATE='OFFLINE'
2019-03-01 19:55:49.300: [ USRTHRD][3758094080] {1:14338:56597}  DB_UNIQUE_NAME='xxxdbdr2'
2019-03-01 19:55:49.300: [ USRTHRD][3758094080] {1:14338:56597}  INSTANCE_NAME='xxxdb2'
2019-03-01 19:55:49.300: [ USRTHRD][3758094080] {1:14338:56597}  NAME='ora.xxxdbdr2.xxxdbcss.svc'
2019-03-01 19:55:49.300: [ USRTHRD][3758094080] {1:14338:56597}  NUMBER_OF_ATTEMPTS='0'
2019-03-01 19:55:49.300: [ USRTHRD][3758094080] {1:14338:56597}  REASON='USER_ACTION'
2019-03-01 19:55:49.300: [ USRTHRD][3758094080] {1:14338:56597}  RESOURCE_CLASS='service'
2019-03-01 19:55:49.300: [ USRTHRD][3758094080] {1:14338:56597}  RESOURCE_INCARNATION_NUMBER='0'
2019-03-01 19:55:49.300: [ USRTHRD][3758094080] {1:14338:56597}  RESOURCE_LOCATION='xxxprdoradb02'
2019-03-01 19:55:49.300: [ USRTHRD][3758094080] {1:14338:56597}  SEQUENCE_NUMBER='1400583'
2019-03-01 19:55:49.300: [ USRTHRD][3758094080] {1:14338:56597}  SERVICE_NAME=''
2019-03-01 19:55:49.300: [ USRTHRD][3758094080] {1:14338:56597}  TARGET_STATE='ONLINE'
2019-03-01 19:55:49.300: [ USRTHRD][3758094080] {1:14338:56597}  TIMESTAMP='2019-03-01 19:55:49'
2019-03-01 19:55:49.300: [ USRTHRD][3758094080] {1:14338:56597}  TYPE='ora.service.type'
2019-03-01 19:55:49.300: [ USRTHRD][3758094080] {1:14338:56597}  USER='oracle'
2019-03-01 19:55:49.300: [ USRTHRD][3758094080] {1:14338:56597}  Version='11.2.0.3.0'
2019-03-01 19:55:49.301: [ USRTHRD][3758094080] {1:14338:56597}  CLUSTER_NAME='xxxdb01-scan'
2019-03-01 19:55:49.301: [ USRTHRD][3758094080] {1:14338:56597}  DB_UNIQUE_NAME='xxxdbdr2'
2019-03-01 19:55:49.301: [ USRTHRD][3758094080] {1:14338:56597}  ORACLE_CLUSTERWARE.SUBCOMPONENT='CRSD'
2019-03-01 19:55:49.301: [ USRTHRD][3758094080] {1:14338:56597}  RESOURCE_CLASS='service'
2019-03-01 19:55:49.301: [ USRTHRD][3758094080] {1:14338:56597}  SERVICE_NAME=''
2019-03-01 19:55:49.301: [ USRTHRD][3758094080] {1:14338:56597} DbAgentEventModule::LsnrRegSubscriber::handleEvent {
2019-03-01 19:55:49.301: [ USRTHRD][3758094080] {1:14338:56597} DbAgentEventModule::LsnrRegSubscriber::handleEvent }
2019-03-01 19:55:49.316: [    AGFW][3892311808] {1:14336:56597} Agent received the message: RESOURCE_START[ora.xxxdbdr2.xxxdbcss.svc 1 1] ID 4098:2664821
2019-03-01 19:55:49.316: [    AGFW][3892311808] {1:14336:56597} Preparing START command for: ora.xxxdbdr2.xxxdbcss.svc 1 1
2019-03-01 19:55:49.317: [    AGFW][3892311808] {1:14336:56597} ora.xxxdbdr2.xxxdbcss.svc 1 1 state changed from: OFFLINE to: STARTING
2019-03-01 19:55:49.318: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [start] (:CLSN00107:) clsn_agent::start {
2019-03-01 19:55:49.318: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [start] SvcAgent::getSvcName SERVICE_NAME xxxdbcss
2019-03-01 19:55:49.318: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [start] SvcAgent::start: enter { 
2019-03-01 19:55:49.318: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [start] SvcAgent::start m_pConnxn lost
2019-03-01 19:55:49.318: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [start] SvcAgent::refresh
2019-03-01 19:55:49.318: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [start] SvcAgent::getSvcName SERVICE_NAME xxxdbcss
2019-03-01 19:55:49.318: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [start] ConnectionPool::ConnectionPool 2 m_oracleHome:/u01/oracle/oracle/product/110203, m_oracleSid:xxxdb2, m_usrOraEnv:
2019-03-01 19:55:49.318: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [start] ConnectionPool::getConnection 260 pConnxn ac0b52e0
2019-03-01 19:55:49.319: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [start] SvcAgent::start: query network name of xxxdbcss
2019-03-01 19:55:49.319: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [start] SvcAgent::execSql 2  xxxdbcss
2019-03-01 19:55:49.319: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [start] SvcAgent::execSql:QUERY_SVC_STMT m_defineCount 11 m_resServiceName xxxdbcss
2019-03-01 19:55:49.320: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [start] SvcAgent::execSql:QUERY_SVC_STMT result 
m_dbServiceName xxxdbcss 
m_dbNetworkName xxxdbcss 
m_dbRlbGoal NONE 
m_dbDtp 0 
m_dbAqHaNotification 0 
m_dbFailoverMethod NONE 
m_dbFailoverType NONE 
m_dbFailoverRetries 0 
m_dbFailoverDelay 0 
m_dbClbGoal LONG 
m_dbEdition 

2019-03-01 19:55:49.320: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [start] SvcAgent::getAndSetBindVal placeholder :goal_name attrib RLB_GOAL value NONE
2019-03-01 19:55:49.320: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [start] SvcAgent::getAndSetBindVal placeholder :dtp attrib DTP value 0
2019-03-01 19:55:49.320: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [start] SvcAgent::getAndSetBindVal placeholder :aq_ha_notification attrib AQ_HA_NOTIFICATION value 0
2019-03-01 19:55:49.320: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [start] SvcAgent::getAndSetBindVal placeholder :failover_method attrib FAILOVER_METHOD value NONE
2019-03-01 19:55:49.320: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [start] SvcAgent::getAndSetBindVal placeholder :failover_type attrib FAILOVER_TYPE value SESSION
2019-03-01 19:55:49.320: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [start] SvcAgent::getAndSetBindVal placeholder :failover_retries attrib FAILOVER_RETRIES value 0
2019-03-01 19:55:49.320: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [start] SvcAgent::setBindVal placeHolder :failover_retries value 0 value length 1 intValue 0
2019-03-01 19:55:49.320: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [start] SvcAgent::getAndSetBindVal placeholder :failover_delay attrib FAILOVER_DELAY value 0
2019-03-01 19:55:49.320: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [start] SvcAgent::setBindVal placeHolder :failover_delay value 0 value length 1 intValue 0
2019-03-01 19:55:49.320: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [start] SvcAgent::getAndSetBindVal placeholder :clb_goal_name attrib CLB_GOAL value LONG
2019-03-01 19:55:49.320: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [start] SvcAgent::getAndSetBindVal placeholder :edition attrib EDITION value 
2019-03-01 19:55:49.320: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [start] SvcAgent::bindResValues 
m_resServiceName xxxdbcss 
m_resNetworkName xxxdbcss 
m_resRlbGoal NONE 
m_resDtp 0 
m_resAqHaNotification 0 
m_resFailoverMethod NONE 
m_resFailoverType SESSION 
m_resFailoverRetries 0 
m_resFailoverDelay 0 
m_resIntFailoverRetries 0 
m_resIntFailoverDelay 0 
m_resClbGoal LONG 
m_resEdition  
2019-03-01 19:55:49.320: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [start] SvcAgent::execSql 3  xxxdbcss
2019-03-01 19:55:49.320: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [start] SvcAgent::execSql:MODIFY_SVC_STMT m_bindCount 11 m_resServiceName xxxdbcss
2019-03-01 19:55:49.325: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [start] ORA-16000: database open for read-only access
ORA-06512: at "SYS.DBMS_SERVICE", line 433
ORA-06512: at "SYS.DBMS_SERVICE", line 304
ORA-06512: at line 1

2019-03-01 19:55:49.325: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [start] SvcAgent::execSql action 3 error ORA-16000: database open for read-only access
ORA-06512: at "SYS.DBMS_SERVICE", line 433
ORA-06512: at "SYS.DBMS_SERVICE", line 304
ORA-06512: at line 1

2019-03-01 19:55:49.326: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [start] InstConnection::connectInt: server not attached
2019-03-01 19:55:49.376: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [start] InstConnection:connectInt connected
2019-03-01 19:55:49.377: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [start] SvcAgent::execSql:MODIFY_SVC_STMT m_bindCount 11 m_resServiceName xxxdbcss
2019-03-01 19:55:49.380: [CLSFRAME][502269728] TM [MultiThread] is changing desired thread # to 5. Current # is 4
2019-03-01 19:55:49.381: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [start] ORA-16000: database open for read-only access
ORA-06512: at "SYS.DBMS_SERVICE", line 433
ORA-06512: at "SYS.DBMS_SERVICE", line 304
ORA-06512: at line 1

2019-03-01 19:55:49.381: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [start] SvcAgent::execSql action 3 error ORA-16000: database open for read-only access
ORA-06512: at "SYS.DBMS_SERVICE", line 433
ORA-06512: at "SYS.DBMS_SERVICE", line 304
ORA-06512: at line 1

2019-03-01 19:55:49.382: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [start] ConnectionPool::releaseConnection InstConnection ac0b52e0
2019-03-01 19:55:49.382: [   AGENT][2885678848] {1:14336:56597} UserErrorException: Locale is 
2019-03-01 19:55:49.382: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [start] clsnUtils::error Exception type=2 string=
CRS-5017: The resource action "ora.xxxdbdr2.xxxdbcss.svc start" encountered the following error: 
ORA-16000: database open for read-only access
ORA-06512: at "SYS.DBMS_SERVICE", line 433
ORA-06512: at "SYS.DBMS_SERVICE", line 304
ORA-06512: at line 1
. For details refer to "(:CLSN00107:)" in "/u01/oracle/grid/110203/log/xxxprdoradb02/agent/crsd/oraagent_oracle/oraagent_oracle.log".

2019-03-01 19:55:49.382: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [start] (:CLSN00107:) clsn_agent::start }
2019-03-01 19:55:49.382: [    AGFW][2885678848] {1:14336:56597} Command: start for resource: ora.xxxdbdr2.xxxdbcss.svc 1 1 completed with status: FAIL
2019-03-01 19:55:49.383: [    AGFW][3892311808] {1:14336:56597} Agent sending reply for: RESOURCE_START[ora.xxxdbdr2.xxxdbcss.svc 1 1] ID 4098:2664821
2019-03-01 19:55:49.383: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [check] isCheckDone m_isCheckDone ac056eb8 1
2019-03-01 19:55:49.383: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [check] DbAgent::isFailed m_lastState 0
2019-03-01 19:55:49.383: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [check] SvcAgent::refresh
2019-03-01 19:55:49.383: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [check] SvcAgent::getSvcName SERVICE_NAME xxxdbcss
2019-03-01 19:55:49.383: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [check] ConnectionPool::getConnection 260 pConnxn ac0b52e0
2019-03-01 19:55:49.383: [    AGFW][3892311808] {1:14336:56597} Agent sending reply for: RESOURCE_START[ora.xxxdbdr2.xxxdbcss.svc 1 1] ID 4098:2664821
2019-03-01 19:55:49.384: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [check] SvcAgent::check OCI error 1403
2019-03-01 19:55:49.384: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [check] ConnectionPool::releaseConnection InstConnection ac0b52e0
2019-03-01 19:55:49.384: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [check] SvcAgent::check 4 ret 1
2019-03-01 19:55:49.384: [ USRTHRD][2885678848] {1:14336:56597} ConnectionPool::~ConnectionPool m_oracleHome:/u01/oracle/oracle/product/110203, m_oracleSid:xxxdb2, m_usrOraEnv:
2019-03-01 19:55:49.384: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [check] SvcAgent::check ret:1 exit }
2019-03-01 19:55:49.385: [    AGFW][3892311808] {1:14336:56597} ora.xxxdbdr2.xxxdbcss.svc 1 1 state changed from: STARTING to: OFFLINE
2019-03-01 19:55:49.385: [    AGFW][3892311808] {1:14336:56597} Agent sending last reply for: RESOURCE_START[ora.xxxdbdr2.xxxdbcss.svc 1 1] ID 4098:2664821
2019-03-01 19:55:49.396: [    AGFW][3892311808] {1:14336:56597} Agent received the message: RESOURCE_CLEAN[ora.xxxdbdr2.xxxdbcss.svc 1 1] ID 4100:2664826
2019-03-01 19:55:49.396: [    AGFW][3892311808] {1:14336:56597} Preparing CLEAN command for: ora.xxxdbdr2.xxxdbcss.svc 1 1
2019-03-01 19:55:49.396: [    AGFW][3892311808] {1:14336:56597} ora.xxxdbdr2.xxxdbcss.svc 1 1 state changed from: OFFLINE to: CLEANING
2019-03-01 19:55:49.396: [ USRTHRD][3758094080] {1:14338:56597} ClusterSubscriber::SubscriberWorker::InternalClusterSubscriber::handleEventCBexecuting for reason 1
2019-03-01 19:55:49.396: [ USRTHRD][3758094080] {1:14338:56597} event type is CRS_ACTION_FAILURE
2019-03-01 19:55:49.396: [ USRTHRD][3758094080] {1:14338:56597} bodylen = 538
2019-03-01 19:55:49.396: [ USRTHRD][3758094080] {1:14338:56597} -----------BodyBlock----------
2019-03-01 19:55:49.396: [ USRTHRD][3758094080] {1:14338:56597}  ACTION='1'
2019-03-01 19:55:49.396: [ USRTHRD][3758094080] {1:14338:56597}  CLS_TINT='{1:14336:56597}'
2019-03-01 19:55:49.396: [ USRTHRD][3758094080] {1:14338:56597}  CURRENT_STATE='OFFLINE'
2019-03-01 19:55:49.396: [ USRTHRD][3758094080] {1:14338:56597}  DB_UNIQUE_NAME='xxxdbdr2'
2019-03-01 19:55:49.396: [ USRTHRD][3758094080] {1:14338:56597}  INSTANCE_NAME='xxxdb1'
2019-03-01 19:55:49.397: [ USRTHRD][3758094080] {1:14338:56597}  NAME='ora.xxxdbdr2.xxxdbcss.svc'
2019-03-01 19:55:49.397: [ USRTHRD][3758094080] {1:14338:56597}  NUMBER_OF_ATTEMPTS='0'
2019-03-01 19:55:49.397: [ USRTHRD][3758094080] {1:14338:56597}  REASON='USER_ACTION'
2019-03-01 19:55:49.397: [ USRTHRD][3758094080] {1:14338:56597}  RESOURCE_CLASS='service'
2019-03-01 19:55:49.397: [ USRTHRD][3758094080] {1:14338:56597}  RESOURCE_INCARNATION_NUMBER='0'
2019-03-01 19:55:49.397: [ USRTHRD][3758094080] {1:14338:56597}  RESOURCE_LOCATION='xxxprdoradb01'
2019-03-01 19:55:49.397: [ USRTHRD][3758094080] {1:14338:56597}  SEQUENCE_NUMBER='1400584'
2019-03-01 19:55:49.397: [ USRTHRD][3758094080] {1:14338:56597}  SERVICE_NAME=''
2019-03-01 19:55:49.397: [ USRTHRD][3758094080] {1:14338:56597}  TARGET_STATE='ONLINE'
2019-03-01 19:55:49.397: [ USRTHRD][3758094080] {1:14338:56597}  TIMESTAMP='2019-03-01 19:55:49'
2019-03-01 19:55:49.397: [ USRTHRD][3758094080] {1:14338:56597}  TYPE='ora.service.type'
2019-03-01 19:55:49.397: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [clean] (:CLSN00106:) clsn_agent::clean {
2019-03-01 19:55:49.397: [ USRTHRD][3758094080] {1:14338:56597}  USER='oracle'
2019-03-01 19:55:49.397: [ USRTHRD][3758094080] {1:14338:56597}  Version='11.2.0.3.0'
2019-03-01 19:55:49.397: [ USRTHRD][3758094080] {1:14338:56597}  CLUSTER_NAME='xxxdb01-scan'
2019-03-01 19:55:49.397: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [clean] clean {
2019-03-01 19:55:49.397: [ USRTHRD][3758094080] {1:14338:56597}  DB_UNIQUE_NAME='xxxdbdr2'
2019-03-01 19:55:49.397: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [clean] SvcAgent::stop: enter { 
2019-03-01 19:55:49.397: [ USRTHRD][3758094080] {1:14338:56597}  ORACLE_CLUSTERWARE.SUBCOMPONENT='CRSD'
2019-03-01 19:55:49.397: [ USRTHRD][3758094080] {1:14338:56597}  RESOURCE_CLASS='service'
2019-03-01 19:55:49.397: [ USRTHRD][3758094080] {1:14338:56597}  SERVICE_NAME=''
2019-03-01 19:55:49.397: [ USRTHRD][3758094080] {1:14338:56597} DbAgentEventModule::LsnrRegSubscriber::handleEvent {
2019-03-01 19:55:49.397: [ USRTHRD][3758094080] {1:14338:56597} DbAgentEventModule::LsnrRegSubscriber::handleEvent }
2019-03-01 19:55:49.397: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [clean] DbAgent::isFailed m_lastState 0
2019-03-01 19:55:49.397: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [clean] SvcAgent::stop m_pConnxn lost
2019-03-01 19:55:49.397: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [clean] SvcAgent::refresh
2019-03-01 19:55:49.397: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [clean] SvcAgent::getSvcName SERVICE_NAME xxxdbcss
2019-03-01 19:55:49.397: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [clean] ConnectionPool::ConnectionPool 2 m_oracleHome:/u01/oracle/oracle/product/110203, m_oracleSid:xxxdb2, m_usrOraEnv:
2019-03-01 19:55:49.397: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [clean] ConnectionPool::getConnection 260 pConnxn ac0b52e0
2019-03-01 19:55:49.398: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [clean] SvcAgent::stop: stopping xxxdbcss
2019-03-01 19:55:49.399: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [clean] ORA-44311: service xxxdbcss not running
ORA-06512: at "SYS.DBMS_SYS_ERROR", line 86
ORA-06512: at "SYS.DBMS_SERVICE", line 466
ORA-06512: at "SYS.DBMS_SERVICE", line 400
ORA-06512: at line 1

2019-03-01 19:55:49.399: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [clean] SvcAgent::stop: ignoring OCI error 44311 }
2019-03-01 19:55:49.399: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [clean] ConnectionPool::releaseConnection InstConnection ac0b52e0
2019-03-01 19:55:49.399: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [clean] SvcAgent::stop: m_pConnxn 00000000m_pConnectionPool a40149b0
2019-03-01 19:55:49.399: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [clean] SvcAgent::stop: } 
2019-03-01 19:55:49.399: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [clean] clean  }
2019-03-01 19:55:49.399: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [clean] (:CLSN00106:) clsn_agent::clean }
2019-03-01 19:55:49.399: [    AGFW][2885678848] {1:14336:56597} Command: clean for resource: ora.xxxdbdr2.xxxdbcss.svc 1 1 completed with status: SUCCESS
2019-03-01 19:55:49.400: [    AGFW][3892311808] {1:14336:56597} Agent sending reply for: RESOURCE_CLEAN[ora.xxxdbdr2.xxxdbcss.svc 1 1] ID 4100:2664826
2019-03-01 19:55:49.400: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [check] isCheckDone m_isCheckDone ac056eb8 1
2019-03-01 19:55:49.400: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [check] DbAgent::isFailed m_lastState 0
2019-03-01 19:55:49.400: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [check] SvcAgent::refresh
2019-03-01 19:55:49.400: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [check] SvcAgent::getSvcName SERVICE_NAME xxxdbcss
2019-03-01 19:55:49.400: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [check] ConnectionPool::getConnection 260 pConnxn ac0b52e0
2019-03-01 19:55:49.401: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [check] SvcAgent::check OCI error 1403
2019-03-01 19:55:49.401: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [check] ConnectionPool::releaseConnection InstConnection ac0b52e0
2019-03-01 19:55:49.401: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [check] SvcAgent::check 4 ret 1
2019-03-01 19:55:49.401: [ USRTHRD][2885678848] {1:14336:56597} ConnectionPool::~ConnectionPool m_oracleHome:/u01/oracle/oracle/product/110203, m_oracleSid:xxxdb2, m_usrOraEnv:
2019-03-01 19:55:49.401: [ora.xxxdbdr2.xxxdbcss.svc][2885678848] {1:14336:56597} [check] SvcAgent::check ret:1 exit }
2019-03-01 19:55:49.401: [    AGFW][3892311808] {1:14336:56597} ora.xxxdbdr2.xxxdbcss.svc 1 1 state changed from: CLEANING to: OFFLINE
2019-03-01 19:55:49.401: [    AGFW][3892311808] {1:14336:56597} Agent sending last reply for: RESOURCE_CLEAN[ora.xxxdbdr2.xxxdbcss.svc 1 1] ID 4100:2664826
View Code

 

2019.03.05进行了问题复现,原因是主库通过srvctl添加的service和备库添加的service名字一样但是个别细节属性定义不同。比如主库添加了服务名s_test:

srvctl add service -d zkm -s s_test -e SELECT -m BASIC -w 10 -z 15 -r zkm1,zkm2

 

 备库同步添加服务名s_test:个别属性不同于主库

srvctl add service -d zkmstd -s s_test -e none -m none  -w 10 -z 15 -r zkm

 

这个时候使用“srvctl start service -d zkmstd -s s_test”启动则会由一样的报错。

此刻修改为属性均一致:

srvctl modify service -d zkmstd -s s_test -e select -m basic -w 10 -z 15

再次启动则正常。防。

 

当在主备环境中以完全相同的方式定义服务时,可以启动 dataguard 环境中的服务,(-r,-a可以不同)请参阅参考:

http://docs.oracle.com/cd/E11882_01/server.112/e40771/sofo.htm#DGBKR3548

如果主备定义服务存在差异,引起报错的根本原因是,

主库中:通过srvctl add service的时候并不会修改在数据库中修改数据库的数据字段表,但是,将新增的service启动的时候,会在表service$中添加记录,这时候你查询dba_services能够查询到服务的信息。

而备库的表service$的数据是同主库同步过来的,备库定义的服务名中由属性存在差异的时候,服务的启动需要更改数据库中的该值,但这是在只读状态下无法完成的,因此报错:ORA-16000: database open for read-only access

上边的oraagent_oracle.log日志也可以看到如下关键字:

MODIFY_SVC_STMT 

 当你在备库使用srvctl add service添加一个主库当前也没有的服务名并试图在备库启动的时候,oraagent_oracle.log日志的关键字就不是modify_svc_stmt了,而是create_svc_stmt。但是报错类似ORA-44317: database open read-only。

至此。

 

参考文档:

https://www.cnblogs.com/PiscesCanon/p/18191840

Service Startup Results ORA-16000 ORA-06512 on Active Data Guard When Attached With Edition (文档 ID 2169426.1)

http://docs.oracle.com/cd/E11882_01/server.112/e40771/sofo.htm#DGBKR3548

posted @ 2024-05-14 17:46  PiscesCanon  阅读(116)  评论(0编辑  收藏  举报