My Oracle Support Banner

srvctl Fails to Start Database but sqlplus Works Fine as Instance Health Check is Incorrect (Doc ID 1504777.1)

Last updated on JULY 24, 2023

Applies to:

Oracle Database - Enterprise Edition - Version 11.2.0.1 and later
Oracle Database Cloud Schema Service - Version N/A and later
Oracle Database Exadata Cloud Machine - Version N/A and later
Oracle Database Exadata Express Cloud Service - Version N/A and later
Oracle Cloud Infrastructure - Database Service - Version N/A and later
Information in this document applies to any platform.

Symptoms

11gR2 srvctl fails to start database/instance but sqlplus starts fine.

 

Output of "srvctl start database" or "srvctl start instance" 

PRCR-1013 : Failed to start resource ora.<DBNAME>.db
PRCR-1064 : Failed to start resource ora.<DBNAME>.db on node <hostname>
CRS-2674: Start of 'ora.<DBNAME>.db' on '<hostname>' failed

 

Case 1:
2012-11-04 02:48:42.833: [ora.<DBNAME>.db][1112095040] {4:5459:372} [start] Utils::getCrsHome crsHome /ocw/grid
2012-11-04 02:48:42.833: [ora.<DBNAME>.db][1112095040] {4:5459:372} [start] clsnInstConnection::makeConnectStr LIBRARY_PATH1 ,LD_LIBRARY_PATH=
2012-11-04 02:48:42.833: [ora.<DBNAME>.db][1112095040] {4:5459:372} [start] makeConnectStr = (DESCRIPTION=(ADDRESS=(PROTOCOL=beq)(PROGRAM=<ORACLE_HOME/bin/or
acle)(ARGV0=oraclexxxx)(ENVS='ORACLE_HOME=/oracle/db/11203,ORACLE_SID=<SID>,LD_LIBRARY_PATH=')(ARGS='(DESCRIPTION=(LOCAL=YES)(ADDRESS=(PROTOCOL=beq)))'))(CONNECT_DATA=(SID=S
E1003)))
2012-11-04 02:48:42.833: [ora.<DBNAME>.db][1112095040] {4:5459:372} [start] Container:start oracle home <ORACLE_HOME>
2012-11-04 02:48:42.833: [ora.<DBNAME>.db][1112095040] {4:5459:372} [start] InstConnection::connectInt: server not attached
2012-11-04 02:48:43.684: [ora.<DBNAME>.db][1112095040] {4:5459:372} [start] InstAgent::startup
2012-11-04 02:48:43.693: [ora.<DBNAME>.db][1112095040] {4:5459:372} [start] ORA-01012: not logged on
2012-11-04 02:48:43.693: [ora.<DBNAME>.db][1112095040] {4:5459:372} [start] InstAgent::start: 1 errcode 1012
2012-11-04 02:48:43.693: [ora.<DBNAME>.db][1112095040] {4:5459:372} [start] ConnectionPool::resetConnection s_statusOfConnectionMap 00a907a0
2012-11-04 02:48:43.693: [ora.<DBNAME>.db][1112095040] {4:5459:372} [start] ConnectionPool::resetConnection sid <SID> status 2
2012-11-04 02:48:43.693: [ora.<DBNAME>.db][1112095040] {4:5459:372} [start] Gimh::check OH <ORACLE_HOME> SID <SID>
2012-11-04 02:48:43.693: [ora.<DBNAME>.db][1112095040] {4:5459:372} [start] Gimh::check condition changes to (GIMH_NEXT_NUM) 1 exists
2012-11-04 02:48:43.693: [ora.<DBNAME>.db][1112095040] {4:5459:372} [start] clsnDbAgent:checkCbk clsagfw_res_status 22
2012-11-04 02:48:43.694: [ora.<DBNAME>.db][1112095040] {4:5459:372} [start] ConnectionPool::stopConnection
2012-11-04 02:48:43.694: [ora.<DBNAME>.db][1112095040] {4:5459:372} [start] ConnectionPool::removeConnection connection count 0
2012-11-04 02:48:43.694: [ora.<DBNAME>.db][1112095040] {4:5459:372} [start] ConnectionPool::removeConnection freed 0
2012-11-04 02:48:43.694: [ora.<DBNAME>.db][1112095040] {4:5459:372} [start] ConnectionPool::stopConnection sid <SID> status 1
2012-11-04 02:48:43.694: [ora.<DBNAME>.db][1112095040] {4:5459:372} [start] InstAgent::check checkCounter 0 prev clsagfw_res_status 2 current clsagfw_res_status 2
2012-11-04 02:48:43.694: [ora.<DBNAME>.db][1112095040] {4:5459:372} [start] InstAgent::start not logged on check state details Instance Shutdown
2012-11-04 02:48:43.694: [ora.<DBNAME>.db][1112095040] {4:5459:372} [start] InstAgent::start: ORA-1012 error state is Instance Shutdown
2012-11-04 02:48:43.694: [ora.<DBNAME>.db][1112095040] {4:5459:372} [start] InstAgent::start: 2 errcode 1012
2012-11-04 02:48:43.694: [ora.<DBNAME>.db][1112095040] {4:5459:372} [start] InstAgent::start exception }
2012-11-04 02:48:43.695: [ora.<DBNAME>.db][1112095040] {4:5459:372} [start] clsnUtils::error Exception type=2 string=
CRS-5017: The resource action "ora.<DBNAME>.db start" encountered the following error:
2012-11-04 02:48:43.695: [ora.<DBNAME>.db][1112095040] {4:5459:372} [start] (:CLSN00107:) clsn_agent::start }
2012-11-04 02:48:43.695: [ AGFW][1112095040] {4:5459:372} Command: start for resource: ora.<DBNAME>.db 1 1 completed with status: FAIL
2012-11-04 02:48:43.696: [ora.<DBNAME>.db][1112095040] {4:5459:372} [check] ConnectionPool::resetConnection s_statusOfConnectionMap 00a907a0
2012-11-04 02:48:43.696: [ora.<DBNAME>.db][1112095040] {4:5459:372} [check] ConnectionPool::resetConnection sid <SID> status 2
2012-11-04 02:48:43.696: [ora.<DBNAME>.db][1112095040] {4:5459:372} [check] Gimh::check OH <ORACLE_HOME> SID <SID>
2012-11-04 02:48:43.696: [ora.<DBNAME>.db][1112095040] {4:5459:372} [check] Gimh::check condition changes to (GIMH_NEXT_NUM) 1 exists
2012-11-04 02:48:43.696: [ora.<DBNAME>.db][1112095040] {4:5459:372} [check] clsnDbAgent:checkCbk clsagfw_res_status 22
2012-11-04 02:48:43.696: [ AGFW][1092651328] {4:5459:372} Agent sending reply for: RESOURCE_START[ora.<DBNAME>.db 1 1] ID 4098:2384
2012-11-04 02:48:43.696: [ora.<DBNAME>.db][1112095040] {4:5459:372} [check] ConnectionPool::stopConnection
2012-11-04 02:48:43.696: [ora.<DBNAME>.db][1112095040] {4:5459:372} [check] ConnectionPool::removeConnection connection count 0
2012-11-04 02:48:43.696: [ora.<DBNAME>.db][1112095040] {4:5459:372} [check] ConnectionPool::removeConnection freed 0
2012-11-04 02:48:43.696: [ora.<DBNAME>.db][1112095040] {4:5459:372} [check] ConnectionPool::stopConnection sid <SID> status 1
2012-11-04 02:48:43.696: [ora.<DBNAME>.db][1112095040] {4:5459:372} [check] InstAgent::check checkCounter 0 prev clsagfw_res_status 2 current clsagfw_res_status 2
2012-11-04 02:48:43.697: [ AGFW][1092651328] {4:5459:372} Agent sending reply for: RESOURCE_START[ora.<DBNAME>.db 1 1] ID 4098:2384
2012-11-04 02:48:43.697: [ AGFW][1092651328] {4:5459:372} ora.<DBNAME>.db 1 1 state changed from: STARTING to: PLANNED_OFFLINE
2012-11-04 02:48:43.697: [ AGFW][1092651328] {4:5459:372} Agent sending last reply for: RESOURCE_START[ora.<DBNAME>.db 1 1] ID 4098:2384
2012-11-04 02:48:43.702: [ USRTHRD][1094752576] {4:5467:372} NAME='ora.<DBNAME>.db'
2012-11-04 02:48:43.703: [ AGFW][1092651328] {4:5459:372} Agent received the message: RESOURCE_CLEAN[ora.<DBNAME>.db 1 1] ID 4100:2395
2012-11-04 02:48:43.704: [ AGFW][1092651328] {4:5459:372} Preparing CLEAN command for: ora.<DBNAME>.db 1 1
2012-11-04 02:48:43.704: [ AGFW][1092651328] {4:5459:372} ora.<DBNAME>.db 1 1 state changed from: PLANNED_OFFLINE to: CLEANING

 

2012-11-04 09:48:01.274: [UiServer][1174600000] {3:33482:3505} Container [
Name: ORDER
MESSAGE:
TextMessage[CRS-2672: Attempting to start 'ora.<DBNAME>.db' on '<hostname>']
MSGTYPE:
TextMessage[3]
OBJID:
TextMessage[ora.<DBNAME>.db 1 1]
WAIT:
TextMessage[0]
]
2012-11-04 09:48:01.274: [ COMMCRS][1174600000]clscsendx: (0x180a800) Connection not active

2012-11-04 09:48:01.274: [UiServer][1174600000] {3:33482:3505} CS(0x2aaaab273580)Error sending msg over socket.6
2012-11-04 09:48:01.275: [UiServer][1174600000] {3:33482:3505} Communication exception sending reply back to client.FatalCommsException : Failed to send response to client. (File: clsMessageStream.cpp, line: 275

2012-11-04 09:48:01.275: [ CRSPE][1172498752] {3:33482:3505} PE Command [ Start Resource : 0x2aaaabc7f720 ] has completed

 

SMR is corrupted and will be recreated. All Health Check clients should disconnect and reconnect to the instance.
WARNING: Could not create SMR

 

Case 2:

2013-04-14 11:24:13.726: [ora.racdb.db][1177999680] {2:17464:2} [check] Gimh::check OH /oracle/db/11201 SID racdb1
2013-04-14 11:24:13.748: [ora.racdb.db][1177999680] {2:17464:2} [check] Gimh::check condition changes to (GIMH_NEXT_NUM) 0,19 exists
2013-04-14 11:24:13.748: [ora.racdb.db][1177999680] {2:17464:2} [check] (:CLSN00007:)DbAgent::check failed gimh state 0
2013-04-14 11:24:13.748: [ora.racdb.db][1177999680] {2:17464:2} [check] clsnDbAgent:checkCbk 20 clsagfw_res_status 19
2013-04-14 11:24:13.748: [ora.racdb.db][1177999680] {2:17464:2} [check] clsnDbAgent:checkCbk clsagfw_res_status 22
2013-04-14 11:24:13.748: [ USRTHRD][1177999680] {2:17464:2} Thread:DedicatedThreadstart {
2013-04-14 11:24:13.748: [ USRTHRD][1177999680] {2:17464:2} Thread:DedicatedThreadstart }
2013-04-14 11:24:13.748: [ora.racdb.db][1177999680] {2:17464:2} [check] ConnectionPool::startConnection s_statusOfConnectionMap 00a87d90
2013-04-14 11:24:13.748: [ USRTHRD][1146530112] {2:17464:2} DbAgent::Dedicated Thread {
2013-04-14 11:24:13.748: [ USRTHRD][1146530112] {2:17464:2} DbAgent::DThread getConnxn
2013-04-14 11:24:13.748: [ USRTHRD][1146530112] {2:17464:2} InstConnection::initMutex AttachLock 00a82400 DetachLock 00a82418
2013-04-14 11:24:13.748: [ora.racdb.db][1177999680] {2:17464:2} [check] ConnectionPool::startConnection sid racdb1 status 2
2013-04-14 11:24:13.748: [ora.racdb.db][1177999680] {2:17464:2} [check] InstAgent::check checkCounter 0 prev clsagfw_res_status 51 current clsagfw_res_status 4
2013-04-14 11:24:13.749: [ AGFW][1188489536] {2:17464:2} ora.<dbname>.db 2 1 state changed from: UNKNOWN to: PARTIAL
2013-04-14 11:24:13.749: [ AGFW][1188489536] {2:17464:2} Started implicit monitor for [ora.racdb.db 2 1] interval=1000 delay=1000
2013-04-14 11:24:13.749: [ AGFW][1188489536] {2:17464:2} ora.<dbname>.db 2 1 state details has changed from: to: Startup Initiated

 

 

 



Changes

 

Cause

To view full details, sign in with your My Oracle Support account.

Don't have a My Oracle Support account? Click to get started!

In this Document
Symptoms
 Case 1:
 Case 2:
Changes
Cause
Solution
References


My Oracle Support provides customers with access to over a million knowledge articles and a vibrant support community of peers and Oracle experts.