Database Software

Announcement

For appeals, questions and feedback about Oracle Forums, please email oracle-forums-moderators_us@oracle.com. Technical questions should be asked in the appropriate category. Thank you!

Database fails to start in RAC cluster 12c

Mallik SJan 19 2017 — edited Jan 20 2017

HI All,

I have 2 node RAC cluster setup (ASM) on RHEL 7.2 and single 12c Database installed.One instance is running in 1 node and can be start/stopped without issue ,when i start other instance in second node ,it fails with following error.

Database instance is not coming up in second node

[oracle@rhelrac2 trace]$ srvctl status database -d racdb1 -v

Instance racdb11 is not running on node rhelrac2

Instance racdb12 is running on node rhelrac1. Instance status: Open.

[oracle@rhelrac2 ~]$ srvctl start database -d racdb1

PRCR-1079 : Failed to start resource ora.racdb1.db

CRS-5017: The resource action "ora.racdb1.db start" encountered the following error:

ORA-01078: failure in processing system parameters

ORA-01565: error in identifying file '+DBDISK/racdb1/spfileracdb1.ora'

ORA-17503: ksfdopn:2 Failed to open file +DBDISK/racdb1/spfileracdb1.ora

ORA-01034: ORACLE not available

ORA-27123: unable to attach to shared memory segment

Linux-x86_64 Error: 2: No such file or directory

Additional information: 2667

Additional information: 1380122625

Additional information: 1614807040

. For details refer to "(:CLSN00107:)" in "/u01/app/grid/diag/crs/rhelrac2/crs/trace/crsd_oraagent_oracle.trc".

CRS-2674: Start of 'ora.racdb1.db' on 'rhelrac2' failed

CRS-2632: There are no more servers to try to place resource 'ora.racdb1.db' on that would satisfy its placement policy

Error seen in crsd logs

[oracle@rhelrac2 ~]$ vi "/u01/app/grid/diag/crs/rhelrac2/crs/trace/crsd_oraagent_oracle.trc"

2017-01-19 04:15:16.843508 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] DbAgent:getOracleSid 13 oracle_sid = racdb11

2017-01-19 04:15:16.843517 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] DbAgent:getOracleSid oracle_sid = racdb11

2017-01-19 04:15:16.843544 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] Utils::getOracleHomeAttrib oracle_home:/u01/app/oracle/product/12.1.0/dbhome_1

2017-01-19 04:15:16.843601 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConnectionPool::ConnectionPool 2 m_oracleHome:/u01/app/oracle/product/12.1.0/dbhome_1, m_oracleSid:racdb11, m_usrOraEnv: m_instanceType:1 m_instanceVersion:12.1.0.2.0

2017-01-19 04:15:16.843656 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] DbAgent::refresh: m_dbType:RAC

2017-01-19 04:15:16.843681 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] Agent::setResType setResType type:ora.database.type

2017-01-19 04:15:16.843730 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] InstAgent::start {

2017-01-19 04:15:16.843765 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConnectionPool::stopConnection

2017-01-19 04:15:16.843779 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConnectionPool::removeConnection connection count 0

2017-01-19 04:15:16.843788 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConnectionPool::removeConnection freed 0

2017-01-19 04:15:16.843793 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConnectionPool::stopConnection sid racdb11 status 1

2017-01-19 04:15:16.843808 : USRTHRD:369252096: {1:64351:50917} ConnectionPool::~ConnectionPool m_oracleHome:/u01/app/oracle/product/12.1.0/dbhome_1, m_oracleSid:racdb11, m_usrOraEnv:

2017-01-19 04:15:16.843847 : USRTHRD:369252096: {1:64351:50917} DbAgent::DedicatedThread::stop entry

2017-01-19 04:15:16.843852 : USRTHRD:369252096: {1:64351:50917} DbAgent::DedicatedThread::abortConnxn entry

2017-01-19 04:15:16.843857 : USRTHRD:369252096: {1:64351:50917} DbAgent::DedicatedThread::abortConnxn exit

2017-01-19 04:15:16.843863 : USRTHRD:369252096: {1:64351:50917} Thread:DedicatedThread stop {

2017-01-19 04:15:16.843868 : USRTHRD:369252096: {1:64351:50917} Thread:DedicatedThread Thread stop:thread acquire lock:f0023348

2017-01-19 04:15:16.843872 : USRTHRD:369252096: {1:64351:50917} Thread:DedicatedThread stop release thndMx:f0023348 }

2017-01-19 04:15:16.843877 : USRTHRD:369252096: {1:64351:50917} DbAgent::DedicatedThread::stop exit

2017-01-19 04:15:16.843891 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] clsnUtils::cmdIdIsStart CmdId:257

2017-01-19 04:15:16.843907 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] DbAgent:getOracleSid 13 oracle_sid = racdb11

2017-01-19 04:15:16.843913 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] DbAgent:getOracleSid oracle_sid = racdb11

2017-01-19 04:15:16.843930 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] Utils::getOracleHomeAttrib oracle_home:/u01/app/oracle/product/12.1.0/dbhome_1

2017-01-19 04:15:16.843980 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConnectionPool::ConnectionPool 2 m_oracleHome:/u01/app/oracle/product/12.1.0/dbhome_1, m_oracleSid:racdb11, m_usrOraEnv: m_instanceType:1 m_instanceVersion:12.1.0.2.0

2017-01-19 04:15:16.843996 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] DbAgent::refresh: m_dbType:RAC

2017-01-19 04:15:16.844506 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] DbAgent::setOracleSidAttrib updating GEN_USR_ORA_INST_NAME@SERVERNAME(rhelrac2) to racdb11

2017-01-19 04:15:16.844526 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] clsnUtils::setResAttrib nonPerX current value GEN_USR_ORA_INST_NAME value racdb11

2017-01-19 04:15:16.886963 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] setResAttrib: attr GEN_USR_ORA_INST_NAME@SERVERNAME(rhelrac2) clsagfw attribVal racdb11 clscrs tmpAttrValue racdb11

2017-01-19 04:15:16.886986 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] setResAttrib clsagfw_modify_attribute attr GEN_USR_ORA_INST_NAME@SERVERNAME(rhelrac2) value racdb11 retCode 0

2017-01-19 04:15:16.886997 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] getResAttrib: attrib name USR_ORA_OPI value false len 5

2017-01-19 04:15:16.887019 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] sclsnInstAgent::sGetStartupComment entry

2017-01-19 04:15:16.887047 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] Utils::getOracleHomeAttrib oracle_home:/u01/app/oracle/product/12.1.0/dbhome_1

2017-01-19 04:15:16.887159 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] sclsnInstAgent::sInitFile pathname:/u01/app/oracle/product/12.1.0/dbhome_1/srvm/admin/ backupPath:/u01/app/oracle/product/12.1.0/dbhome_1/srvm/admin/ filename:orastart.rhelrac2 pConfigF:0x7f4ef00231f0

2017-01-19 04:15:16.887292 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::ConfigFile constructor name:orastart.rhelrac2

2017-01-19 04:15:16.891200 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::parse mmap name:racdb1 nameWithCase:racdb1 value:/u01/app/oracle/product/12.1.0/dbhome_1:N comment:line added by Agent StartCompleted

2017-01-19 04:15:16.895790 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::getAltName this:0x7f4ef00537d0

2017-01-19 04:15:16.895801 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile:getAltName altName:

2017-01-19 04:15:16.895807 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] sclsnInstAgent::sInitFile dbname:racdb1 altName:

2017-01-19 04:15:16.895822 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::getComment name:racdb1 comment:line added by Agent StartCompleted

2017-01-19 04:15:16.895829 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::getAltName this:0x7f4ef00537d0

2017-01-19 04:15:16.895834 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile:getAltName altName:

2017-01-19 04:15:16.895840 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::getAltName this:0x7f4ef00537d0

2017-01-19 04:15:16.895845 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile:getAltName altName:

2017-01-19 04:15:16.895851 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::getComment name: comment:

2017-01-19 04:15:16.895858 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] sclsnInstAgent::sInitFile exit dbname:racdb1 startup comment:line added by Agent StartCompleted startup altName: comment:

2017-01-19 04:15:16.895867 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::getAltEntry altEntry:

2017-01-19 04:15:16.895874 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] sclsnInstAgent::sGetStartupComment asmEntry: m_dbName:racdb1

2017-01-19 04:15:16.895881 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::getComment name:racdb1 comment:line added by Agent StartCompleted

2017-01-19 04:15:16.895888 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] sclsnInstAgent::sGetStartupComment dbName comment:line added by Agent StartCompleted

2017-01-19 04:15:16.895907 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] InstAgent::checkState gimh oracleSid:racdb11

2017-01-19 04:15:16.895914 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] Gimh::constructor ohome:/u01/app/oracle/product/12.1.0/dbhome_1 sid:racdb11

2017-01-19 04:15:16.895952 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConnectionPool::resetConnection s_statusOfConnectionMap 00f3aed8

2017-01-19 04:15:16.895959 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConnectionPool::resetConnection sid racdb11 status 2

2017-01-19 04:15:16.895982 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] Gimh::check OH /u01/app/oracle/product/12.1.0/dbhome_1 SID racdb11

2017-01-19 04:15:16.896051 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] Gimh::check condition changes to (GIMH_NEXT_NUM) 0(Abnormal Termination) exists

2017-01-19 04:15:16.896060 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] (:CLSN00007:)DbAgent::checkCbk failed gimh state 0(Abnormal Termination)

2017-01-19 04:15:16.896175 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] DbAgent:checkCbk planned offline or failed ret 5

2017-01-19 04:15:16.896259 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] DbAgent:checkCbk shutdown reset s_PDBStatusMap

2017-01-19 04:15:16.896357 : USRTHRD:369252096: {1:64351:50917} Gimh::destructor gimh_dest_query_ctx rc=0

2017-01-19 04:15:16.896392 : USRTHRD:369252096: {1:64351:50917} Gimh::destructor gimh_dest_inst_ctx rc=0

2017-01-19 04:15:16.896415 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConnectionPool::stopConnection

2017-01-19 04:15:16.896429 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConnectionPool::removeConnection connection count 0

2017-01-19 04:15:16.896436 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConnectionPool::removeConnection freed 0

2017-01-19 04:15:16.896441 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConnectionPool::stopConnection sid racdb11 status 1

2017-01-19 04:15:16.896480 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] InstAgent::start 1 writing configFile startOption:StartOption[2]

2017-01-19 04:15:16.896486 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] sModifyConfig for racdb1

2017-01-19 04:15:16.896504 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] sclsnInstAgent::sUpdateFile entry { path:/etc file:oratab pConfigF:0x7f4ef00231e8

2017-01-19 04:15:16.896522 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] Utils::getOracleHomeAttrib oracle_home:/u01/app/oracle/product/12.1.0/dbhome_1

2017-01-19 04:15:16.896614 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] sclsnInstAgent::sInitFile pathname:/etc backupPath:/u01/app/oracle/product/12.1.0/dbhome_1/srvm/admin/ filename:oratab pConfigF:0x7f4ef00231e8

2017-01-19 04:15:16.897003 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::ConfigFile constructor name:oratab

2017-01-19 04:15:16.900649 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::parse mmap name:-mgmtdb nameWithCase:-MGMTDB value:/u01/app/12c/grid:N comment:line added by Agent

2017-01-19 04:15:16.900669 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::parse mmap name:+asm1 nameWithCase:+ASM1 value:/u01/app/12c/grid:N comment:line added by Agent

2017-01-19 04:15:16.900682 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::parse mmap name:racdb1 nameWithCase:racdb1 value:/u01/app/oracle/product/12.1.0/dbhome_1:N comment:line added by Agent

2017-01-19 04:15:16.905128 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::getAltName this:0x7f4ef006ab60

2017-01-19 04:15:16.905139 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile:getAltName altName:

2017-01-19 04:15:16.905146 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] sclsnInstAgent::sInitFile dbname:racdb1 altName:

2017-01-19 04:15:16.905157 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::getComment name:racdb1 comment:line added by Agent

2017-01-19 04:15:16.905164 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::getAltName this:0x7f4ef006ab60

2017-01-19 04:15:16.905169 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile:getAltName altName:

2017-01-19 04:15:16.905175 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::getAltName this:0x7f4ef006ab60

2017-01-19 04:15:16.905193 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile:getAltName altName:

2017-01-19 04:15:16.905202 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::getComment name: comment:

2017-01-19 04:15:16.905209 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] sclsnInstAgent::sInitFile exit dbname:racdb1 startup comment:line added by Agent startup altName: comment:

2017-01-19 04:15:16.905218 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::getAltName this:0x7f4ef006ab60

2017-01-19 04:15:16.905224 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile:getAltName altName:

2017-01-19 04:15:16.905229 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] sclsnInstAgent::sUpdateFile dbname:racdb1 altName:

2017-01-19 04:15:16.905236 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] sclsnInstAgent::sUpdateFile remove dbName:racdb1

2017-01-19 04:15:16.905310 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::parse mmap name:-mgmtdb nameWithCase:-MGMTDB value:/u01/app/12c/grid:N comment:line added by Agent

2017-01-19 04:15:16.905323 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::parse mmap name:+asm1 nameWithCase:+ASM1 value:/u01/app/12c/grid:N comment:line added by Agent

2017-01-19 04:15:16.905331 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::getValue name racdb1 value

2017-01-19 04:15:16.908403 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] at the end Insert newstr racdb1:/u01/app/oracle/product/12.1.0/dbhome_1:N # line added by Agent

2017-01-19 04:15:16.908435 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::parse mmap name:-mgmtdb nameWithCase:-MGMTDB value:/u01/app/12c/grid:N comment:line added by Agent

2017-01-19 04:15:16.908448 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::parse mmap name:+asm1 nameWithCase:+ASM1 value:/u01/app/12c/grid:N comment:line added by Agent

2017-01-19 04:15:16.908460 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::parse mmap name:racdb1 nameWithCase:racdb1 value:/u01/app/oracle/product/12.1.0/dbhome_1:N comment:line added by Agent

2017-01-19 04:15:16.917243 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::parse mmap name:-mgmtdb nameWithCase:-MGMTDB value:/u01/app/12c/grid:N comment:line added by Agent

2017-01-19 04:15:16.917262 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::parse mmap name:+asm1 nameWithCase:+ASM1 value:/u01/app/12c/grid:N comment:line added by Agent

2017-01-19 04:15:16.917274 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::parse mmap name:racdb1 nameWithCase:racdb1 value:/u01/app/oracle/product/12.1.0/dbhome_1:N comment:line added by Agent

2017-01-19 04:15:16.917282 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::updateInPlace file /etc/oratab is updated

2017-01-19 04:15:16.917296 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] sclsnInstAgent::sUpdateFile file updated with dbName racdb1 m_configValue /u01/app/oracle/product/12.1.0/dbhome_1:N

2017-01-19 04:15:16.921971 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] sclsnInstAgent::sUpdateFile entry { path: file:orastart.rhelrac2 pConfigF:0x7f4ef00231f0

2017-01-19 04:15:16.921983 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::getAltName this:0x7f4ef00537d0

2017-01-19 04:15:16.921989 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile:getAltName altName:

2017-01-19 04:15:16.921995 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] sclsnInstAgent::sUpdateFile dbname:racdb1 altName:

2017-01-19 04:15:16.922002 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] sclsnInstAgent::sUpdateFile remove dbName:racdb1

2017-01-19 04:15:16.922021 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::getValue name racdb1 value

2017-01-19 04:15:16.924997 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] at the end Insert newstr racdb1:/u01/app/oracle/product/12.1.0/dbhome_1:N # line added by AgentStartOption[2]

2017-01-19 04:15:16.925021 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::parse mmap name:racdb1 nameWithCase:racdb1 value:/u01/app/oracle/product/12.1.0/dbhome_1:N comment:line added by AgentStartOption[2]

2017-01-19 04:15:16.933974 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::parse mmap name:racdb1 nameWithCase:racdb1 value:/u01/app/oracle/product/12.1.0/dbhome_1:N comment:line added by AgentStartOption[2]

2017-01-19 04:15:16.933987 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::updateInPlace file /u01/app/oracle/product/12.1.0/dbhome_1/srvm/admin/orastart.rhelrac2 is updated

2017-01-19 04:15:16.933995 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] sclsnInstAgent::sUpdateFile file updated with dbName racdb1 m_configValue /u01/app/oracle/product/12.1.0/dbhome_1:N

2017-01-19 04:15:16.937892 : USRTHRD:369252096: {1:64351:50917} AgentEventModule::isUseEvm version: 12.1.0.2.0

2017-01-19 04:15:16.937915 : USRTHRD:369252096: {1:64351:50917} AgentEventModule::isUseEvm True

2017-01-19 04:15:16.937979 : USRTHRD:369252096: {1:64351:50917} Worker::schedule thread 'EventBridgesEvm' not already created. Creating

2017-01-19 04:15:16.938010 : USRTHRD:369252096: {1:64351:50917} Worker::schedule adding worker 'DBAGENT-racdb1' to thread 'EventBridgesEvm'

2017-01-19 04:15:16.938020 : USRTHRD:369252096: {1:64351:50917} WorkerThread::addWorker starting self

2017-01-19 04:15:16.938026 : USRTHRD:369252096: {1:64351:50917} Thread:EventBridgesEvm start { acquire thndMX:f00666c0

2017-01-19 04:15:16.938031 : USRTHRD:369252096: {1:64351:50917} Thread:EventBridgesEvm start pThnd:f00694a0

2017-01-19 04:15:16.938077 : USRTHRD:369252096: {1:64351:50917} Thread:EventBridgesEvm start 2 release thndMX:f00666c0 }

2017-01-19 04:15:16.938563 : USRTHRD:365049600: {1:64351:50917} Thread:EventBridgesEvm run {

2017-01-19 04:15:16.939138 : USRTHRD:369252096: {1:64351:50917} WorkerThread::addWorker waiting for thread to start

2017-01-19 04:15:16.939152 : USRTHRD:369252096: {1:64351:50917} WorkerThread::addWorker total workers: 1

2017-01-19 04:15:16.939216 : USRTHRD:369252096: {1:64351:50917} Worker::schedule thread 'EventBridgesRlb' not already created. Creating

2017-01-19 04:15:16.939229 : USRTHRD:369252096: {1:64351:50917} Worker::schedule adding worker 'RLB-racdb1' to thread 'EventBridgesRlb'

2017-01-19 04:15:16.939238 : USRTHRD:369252096: {1:64351:50917} WorkerThread::addWorker starting self

2017-01-19 04:15:16.939243 : USRTHRD:369252096: {1:64351:50917} Thread:EventBridgesRlb start { acquire thndMX:f0063900

2017-01-19 04:15:16.939248 : USRTHRD:369252096: {1:64351:50917} Thread:EventBridgesRlb start pThnd:f0066770

2017-01-19 04:15:16.939296 : USRTHRD:369252096: {1:64351:50917} Thread:EventBridgesRlb start 2 release thndMX:f0063900 }

2017-01-19 04:15:16.939561 : USRTHRD:362948352: {1:64351:50917} Thread:EventBridgesRlb run {

2017-01-19 04:15:16.940372 : USRTHRD:369252096: {1:64351:50917} WorkerThread::addWorker waiting for thread to start

2017-01-19 04:15:16.940384 : USRTHRD:369252096: {1:64351:50917} WorkerThread::addWorker total workers: 1

2017-01-19 04:15:16.940435 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] DbAgentEventModule::keepRunning starting event subscriber

2017-01-19 04:15:16.940456 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] DbAgentEventModule::keepRunning starting event bridge

2017-01-19 04:15:16.940548 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] crsHome = /u01/app/12c/grid

2017-01-19 04:15:16.940555 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] oracleHome = /u01/app/oracle/product/12.1.0/dbhome_1

2017-01-19 04:15:16.940562 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] command = '/u01/app/12c/grid/bin/setasmgidwrap oracle_binary_path=/u01/app/oracle/product/12.1.0/dbhome_1/bin/oracle'

2017-01-19 04:15:16.940575 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] start dependency = hard(ora.DBDISK.dg) pullup(ora.DBDISK.dg) weak(type:ora.listener.type, global:type:ora.scan_listener.type, uniform:ora.ons, global:ora.gns, ora.ARCDISK.dg)

2017-01-19 04:15:16.940584 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ASM disk group dependency found

2017-01-19 04:15:16.940596 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] Utils:execCmd action = 1 flags = 6 ohome = /u01/app/12c/grid cmdname = setasmgidwrap.

2017-01-19 04:15:16.941576 : CLSCEVT:365049600: clsce_subscribe 0x7f4ef0066a80 filter='(^CRS_RESOURCE_STATE_CHANGE.*((RESOURCE_LOCATION='rhelrac2'.*TYPE='ora\.(cluster_vip.*|network)\.type')|(TYPE='ora\.database\.type')|(DB_UNIQUE_NAME='racdb1.*'.*TYPE='ora\.service\.type)))|(^CRS_SERVER_STATE_CHANGE)', flags=1, handler=0xa4b772, arg=0x7f4ef0064350

2017-01-19 04:15:16.941903 : CLSCEVT:375555840: clsce_subscribe 0x7f4ef0024790 filter='(^CRS_RESOURCE_STATE_CHANGE.*RESOURCE_CLASS='(scan_listener|listener)')|(^CRS_RESOURCE_PROFILE_CHANGE.*RESOURCE_CLASS='(scan_listener|listener|scan_vip|vip)')', flags=1, handler=0xa4b772, arg=0x7f4ef0029a20

2017-01-19 04:15:16.987989 : CLSCEVT:365049600: (:CLSCE0022:)clsce_subscribe 0x7f4ef0066a80 successfully subscribed : 1

2017-01-19 04:15:16.989375 : CLSCEVT:375555840: (:CLSCE0022:)clsce_subscribe 0x7f4ef0024790 successfully subscribed : 0

2017-01-19 04:15:17.069963 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] execCmd ret = 0

2017-01-19 04:15:17.070012 : USRTHRD:369252096: {1:64351:50917} InstConnection::initMutex AttachLock 00f31fd0 DetachLock 00f31fe8

2017-01-19 04:15:17.070056 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] DbAgent:getConnection oracleHome:/u01/app/oracle/product/12.1.0/dbhome_1 oracleSid:racdb11 usrOraEnv: resVersion:12.1.0.2.0

2017-01-19 04:15:17.070380 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] InstConnection:InstConnection: init:f0060830 oracleHome:/u01/app/oracle/product/12.1.0/dbhome_1 oracleSid:racdb11 instanceType:1 instanceVersion:12.1.0.2.0

2017-01-19 04:15:17.070592 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] clsnInstConnection::makeConnectStr UsrOraEnv ,ORACLE_BASE= m_oracleHome /u01/app/oracle/product/12.1.0/dbhome_1 Crshome /u01/app/12c/grid

2017-01-19 04:15:17.070651 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] makeConnectStr = (DESCRIPTION=(ADDRESS=(PROTOCOL=beq)(PROGRAM=/u01/app/oracle/product/12.1.0/dbhome_1/bin/oracle)(ARGV0=oracleracdb11)(ENVS='ORACLE_HOME=/u01/app/oracle/product/12.1.0/dbhome_1,ORACLE_SID=racdb11,LD_LIBRARY_PATH=,ORACLE_BASE=')(ARGS='(DESCRIPTION=(LOCAL=YES)(ADDRESS=(PROTOCOL=beq)))')(CONNECT_DATA=(SID=racdb11))))

2017-01-19 04:15:17.074641 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] Container:start oracle home /u01/app/oracle/product/12.1.0/dbhome_1

2017-01-19 04:15:17.074705 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] InstConnection::connectInt: server not attached

2017-01-19 04:15:18.124665 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] InstConnection:connectInt connected

2017-01-19 04:15:18.124697 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] InstAgent::startup

2017-01-19 04:15:18.473300 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ORA-01078: failure in processing system parameters

ORA-01565: error in identifying file '+DBDISK/racdb1/spfileracdb1.ora'

ORA-17503: ksfdopn:2 Failed to open file +DBDISK/racdb1/spfileracdb1.ora

ORA-01034: ORACLE not available

ORA-27123: unable to attach to shared memory segment

Linux-x86_64 Error: 2: No such file or directory

Additional information: 2667

Additional information: 1380122625

Additional information: 1614807040

2017-01-19 04:15:18.473505 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] InstAgent::start: 1 errcode 1078

2017-01-19 04:15:18.473519 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] InstAgent::start: untrapped error

2017-01-19 04:15:18.473548 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] InstAgent::start: 2 errcode 1078

2017-01-19 04:15:18.473563 : USRTHRD:369252096: {1:64351:50917} InstConnection:~InstConnection: this f0060830

2017-01-19 04:15:18.474102 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] clean {

2017-01-19 04:15:18.474124 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] InstAgent::stop_option stop mode immediate option 1

2017-01-19 04:15:18.474131 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] InstAgent::stop {

2017-01-19 04:15:18.474142 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] getResAttrib: attrib name USR_ORA_OPI value false len 5

2017-01-19 04:15:18.474172 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] InstAgent::stop original reason system do shutdown abort

2017-01-19 04:15:18.474248 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] InstAgent::checkState gimh oracleSid:racdb11

2017-01-19 04:15:18.474256 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] Gimh::constructor ohome:/u01/app/oracle/product/12.1.0/dbhome_1 sid:racdb11

2017-01-19 04:15:18.474294 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConnectionPool::resetConnection s_statusOfConnectionMap 00f3aed8

2017-01-19 04:15:18.474301 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConnectionPool::resetConnection sid racdb11 status 2

2017-01-19 04:15:18.474327 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] Gimh::check OH /u01/app/oracle/product/12.1.0/dbhome_1 SID racdb11

2017-01-19 04:15:18.474384 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] Gimh::check condition changes to (GIMH_NEXT_NUM) 0(Abnormal Termination) exists

2017-01-19 04:15:18.475438 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] (:CLSN00007:)DbAgent::checkCbk failed gimh state 0(Abnormal Termination)

2017-01-19 04:15:18.475480 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] DbAgent:checkCbk planned offline or failed ret 5

2017-01-19 04:15:18.475493 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] DbAgentEventModule::stop Forcing stop because of clean

2017-01-19 04:15:18.475509 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] DbAgentEventModule::stop stopping event bridge

2017-01-19 04:15:18.475606 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] DbAgent:checkCbk shutdown reset s_PDBStatusMap

2017-01-19 04:15:18.475648 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] (:CLSN00007:)InstAgent::checkState return unplanned offline

2017-01-19 04:15:18.475675 : USRTHRD:369252096: {1:64351:50917} Gimh::destructor gimh_dest_query_ctx rc=0

2017-01-19 04:15:18.477546 : CLSCEVT:365049600: (:CLSCE0028:)clsce_unsubscribe 0x7f4ef0066a80 successfully unsubscribed : 1

2017-01-19 04:15:18.479798 : USRTHRD:369252096: {1:64351:50917} Gimh::destructor gimh_dest_inst_ctx rc=0

2017-01-19 04:15:18.479836 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConnectionPool::stopConnection

2017-01-19 04:15:18.479852 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConnectionPool::removeConnection connection count 0

2017-01-19 04:15:18.479864 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConnectionPool::removeConnection freed 0

2017-01-19 04:15:18.479870 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConnectionPool::stopConnection sid racdb11 status 1

2017-01-19 04:15:18.479880 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] InstAgent::checkState 1 prev clsagfw_res_status 5 current clsagfw_res_status 1

2017-01-19 04:15:18.479938 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] InstAgent::stop shutdown mode: 4

2017-01-19 04:15:18.479956 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] DbAgent::preStopCbk {

2017-01-19 04:15:18.479964 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] DbAgentEventModule::stop Forcing stop because of clean

2017-01-19 04:15:18.479980 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] DbAgent::preStopCbk dThread stop

2017-01-19 04:15:18.479986 : USRTHRD:369252096: {1:64351:50917} DbAgent::DedicatedThread::stop entry

2017-01-19 04:15:18.479991 : USRTHRD:369252096: {1:64351:50917} DbAgent::DedicatedThread::abortConnxn entry

2017-01-19 04:15:18.479997 : USRTHRD:369252096: {1:64351:50917} DbAgent::DedicatedThread::abortConnxn exit

2017-01-19 04:15:18.480003 : USRTHRD:369252096: {1:64351:50917} Thread:DedicatedThread stop {

2017-01-19 04:15:18.480008 : USRTHRD:369252096: {1:64351:50917} Thread:DedicatedThread Thread stop:thread acquire lock:f0023348

2017-01-19 04:15:18.480013 : USRTHRD:369252096: {1:64351:50917} Thread:DedicatedThread stop release thndMx:f0023348 }

2017-01-19 04:15:18.480019 : USRTHRD:369252096: {1:64351:50917} DbAgent::DedicatedThread::stop exit

2017-01-19 04:15:18.480024 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] DbAgent::preStopCbk dThread stopped

2017-01-19 04:15:18.480030 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] DbAgent::preStopCbk }

2017-01-19 04:15:18.480045 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConnectionPool::getConnection 160 ERROR sid racdb11 pool status 1

2017-01-19 04:15:18.480059 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] InstAgent::stop pool pConnxn 00000000

2017-01-19 04:15:18.480079 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] DbAgent:getConnection oracleHome:/u01/app/oracle/product/12.1.0/dbhome_1 oracleSid:racdb11 usrOraEnv: resVersion:12.1.0.2.0

2017-01-19 04:15:18.480099 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] InstConnection:InstConnection: init:f0056cf0 oracleHome:/u01/app/oracle/product/12.1.0/dbhome_1 oracleSid:racdb11 instanceType:1 instanceVersion:12.1.0.2.0

2017-01-19 04:15:18.480305 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] clsnInstConnection::makeConnectStr UsrOraEnv ,ORACLE_BASE= m_oracleHome /u01/app/oracle/product/12.1.0/dbhome_1 Crshome /u01/app/12c/grid

2017-01-19 04:15:18.480330 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] makeConnectStr = (DESCRIPTION=(ADDRESS=(PROTOCOL=beq)(PROGRAM=/u01/app/oracle/product/12.1.0/dbhome_1/bin/oracle)(ARGV0=oracleracdb11)(ENVS='ORACLE_HOME=/u01/app/oracle/product/12.1.0/dbhome_1,ORACLE_SID=racdb11,LD_LIBRARY_PATH=,ORACLE_BASE=')(ARGS='(DESCRIPTION=(LOCAL=YES)(ADDRESS=(PROTOCOL=beq)))')(CONNECT_DATA=(SID=racdb11))))

2017-01-19 04:15:18.485041 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] InstAgent::stop non pool pConnxn 1 f0056cf0

2017-01-19 04:15:18.485076 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] InstConnection::connectInt: server not attached

2017-01-19 04:15:19.510066 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] InstConnection:connectInt connected

2017-01-19 04:15:19.510382 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] InstConnection::shutdown mode 4

2017-01-19 04:15:19.511966 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ORA-01034: ORACLE not available

Process ID: 0

Session ID: 0 Serial number: 0

2017-01-19 04:15:19.512400 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] InstConnection::disassociateEdition OCI error 1034

2017-01-19 04:15:19.512535 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConnectionPool::removeConnection connection count 1

2017-01-19 04:15:19.512549 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConnectionPool::removeConnection sid racdb11, InstConnection f0056cf0

2017-01-19 04:15:19.512565 : USRTHRD:369252096: {1:64351:50917} InstConnection::breakCall pConnxn:f0056cf0 DetachLock:00f31fe8 m_pSrvH:f00ec980, m_pSvcH:f0155678

2017-01-19 04:15:19.512606 : USRTHRD:369252096: {1:64351:50917} InstConnection:~InstConnection: this f0056cf0

2017-01-19 04:15:19.513487 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConnectionPool::removeConnection delete InstConnection f0056cf0

2017-01-19 04:15:19.513512 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConnectionPool::removeConnection freed 1

2017-01-19 04:15:19.513535 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConnectionPool::stopConnection

2017-01-19 04:15:19.513560 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConnectionPool::removeConnection connection count 0

2017-01-19 04:15:19.513573 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConnectionPool::removeConnection freed 0

2017-01-19 04:15:19.513584 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConnectionPool::stopConnection sid racdb11 status 1

2017-01-19 04:15:19.513604 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] InstAgent::stop db/asm

2017-01-19 04:15:19.513614 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConnectionPool::stopConnection

2017-01-19 04:15:19.513634 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConnectionPool::removeConnection connection count 0

2017-01-19 04:15:19.513646 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConnectionPool::removeConnection freed 0

2017-01-19 04:15:19.513657 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConnectionPool::stopConnection sid racdb11 status 1

2017-01-19 04:15:19.513739 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] getResAttrib: attrib name USR_ORA_OPI value false len 5

2017-01-19 04:15:19.513778 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] InstAgent::stop Container->stop, isShutdown = 0

2017-01-19 04:15:19.513841 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] InstAgent::stop calling initCssData

2017-01-19 04:15:19.513887 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] CssData Constructor groupName:DBRACDB1 cssRegistrationType:0 memno:-1

2017-01-19 04:15:19.513902 : USRTHRD:369252096: {1:64351:50917} CssData::initMutex &m_cssDataLock:f00b5308

2017-01-19 04:15:19.513962 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] CssGroup::regis registration of groupName:DBRACDB1 mbrid:-1 m_grpNum:-1 regType:0 succeeded

2017-01-19 04:15:19.513979 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] CssData::Constructor regis succeeded groupName:DBRACDB1 memno:-1

2017-01-19 04:15:19.513992 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] CssData::Constructor m_pCssGroup:f0053e90 group DBRACDB1

2017-01-19 04:15:19.514009 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] InstAgent::init m_groupName:DBRACDB1 m_pCssData f00b3240

2017-01-19 04:15:19.514021 : USRTHRD:369252096: {1:64351:50917} CssData Destructor groupName:DBRACDB1

2017-01-19 04:15:19.514036 : USRTHRD:369252096: {1:64351:50917} CssGroup::dereg default regType:0

2017-01-19 04:15:19.514066 : USRTHRD:369252096: {1:64351:50917} CssData::destroyMutex &m_cssDataLock:f00b5308

2017-01-19 04:15:19.514076 : USRTHRD:369252096: {1:64351:50917} CssData::Destructor

2017-01-19 04:15:19.514095 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] InstAgent::stop prev clsagfw_res_status 1 current clsagfw_res_status 2

2017-01-19 04:15:19.514107 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] InstAgent::stop m_prevState:2 }

2017-01-19 04:15:19.514142 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] clean }

2017-01-19 04:15:19.514154 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] InstAgent::start exception }

2017-01-19 04:15:19.514376 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] InstAgent::start 2.1 writing configFile startOption: StartCompleted

2017-01-19 04:15:19.514397 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] sModifyConfig for racdb1

2017-01-19 04:15:19.514434 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] sclsnInstAgent::sUpdateFile entry { path:/etc file:oratab pConfigF:0x7f4ef00231e8

2017-01-19 04:15:19.514448 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::getAltName this:0x7f4ef006ab60

2017-01-19 04:15:19.514460 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile:getAltName altName:

2017-01-19 04:15:19.514472 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] sclsnInstAgent::sUpdateFile dbname:racdb1 altName:

2017-01-19 04:15:19.514485 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] sclsnInstAgent::sUpdateFile remove dbName:racdb1

2017-01-19 04:15:19.514633 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::parse mmap name:-mgmtdb nameWithCase:-MGMTDB value:/u01/app/12c/grid:N comment:line added by Agent

2017-01-19 04:15:19.514659 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::parse mmap name:+asm1 nameWithCase:+ASM1 value:/u01/app/12c/grid:N comment:line added by Agent

2017-01-19 04:15:19.514675 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::getValue name racdb1 value

2017-01-19 04:15:19.521810 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] at the end Insert newstr racdb1:/u01/app/oracle/product/12.1.0/dbhome_1:N # line added by Agent

2017-01-19 04:15:19.524002 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::parse mmap name:-mgmtdb nameWithCase:-MGMTDB value:/u01/app/12c/grid:N comment:line added by Agent

2017-01-19 04:15:19.524038 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::parse mmap name:+asm1 nameWithCase:+ASM1 value:/u01/app/12c/grid:N comment:line added by Agent

2017-01-19 04:15:19.524066 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::parse mmap name:racdb1 nameWithCase:racdb1 value:/u01/app/oracle/product/12.1.0/dbhome_1:N comment:line added by Agent

2017-01-19 04:15:19.536023 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::parse mmap name:-mgmtdb nameWithCase:-MGMTDB value:/u01/app/12c/grid:N comment:line added by Agent

2017-01-19 04:15:19.536059 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::parse mmap name:+asm1 nameWithCase:+ASM1 value:/u01/app/12c/grid:N comment:line added by Agent

2017-01-19 04:15:19.536086 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::parse mmap name:racdb1 nameWithCase:racdb1 value:/u01/app/oracle/product/12.1.0/dbhome_1:N comment:line added by Agent

2017-01-19 04:15:19.536102 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::updateInPlace file /etc/oratab is updated

2017-01-19 04:15:19.536117 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] sclsnInstAgent::sUpdateFile file updated with dbName racdb1 m_configValue /u01/app/oracle/product/12.1.0/dbhome_1:N

2017-01-19 04:15:19.552583 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] sclsnInstAgent::sUpdateFile entry { path: file:orastart.rhelrac2 pConfigF:0x7f4ef00231f0

2017-01-19 04:15:19.552606 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::getAltName this:0x7f4ef00537d0

2017-01-19 04:15:19.552619 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile:getAltName altName:

2017-01-19 04:15:19.552640 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] sclsnInstAgent::sUpdateFile dbname:racdb1 altName:

2017-01-19 04:15:19.552654 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] sclsnInstAgent::sUpdateFile remove dbName:racdb1

2017-01-19 04:15:19.552693 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::getValue name racdb1 value

2017-01-19 04:15:19.558846 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] at the end Insert newstr racdb1:/u01/app/oracle/product/12.1.0/dbhome_1:N # line added by Agent StartCompleted

2017-01-19 04:15:19.558894 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::parse mmap name:racdb1 nameWithCase:racdb1 value:/u01/app/oracle/product/12.1.0/dbhome_1:N comment:line added by Agent StartCompleted

2017-01-19 04:15:19.560197 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::parse mmap name:racdb1 nameWithCase:racdb1 value:/u01/app/oracle/product/12.1.0/dbhome_1:N comment:line added by Agent StartCompleted

2017-01-19 04:15:19.560232 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] ConfigFile::updateInPlace file /u01/app/oracle/product/12.1.0/dbhome_1/srvm/admin/orastart.rhelrac2 is updated

2017-01-19 04:15:19.560247 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] sclsnInstAgent::sUpdateFile file updated with dbName racdb1 m_configValue /u01/app/oracle/product/12.1.0/dbhome_1:N

2017-01-19 04:15:19.568515 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] Agent::commonStart Exception OCIException

2017-01-19 04:15:19.569283 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] clsnUtils::error Exception type=2 string=

CRS-5017: The resource action "ora.racdb1.db start" encountered the following error:

ORA-01078: failure in processing system parameters

ORA-01565: error in identifying file '+DBDISK/racdb1/spfileracdb1.ora'

ORA-17503: ksfdopn:2 Failed to open file +DBDISK/racdb1/spfileracdb1.ora

ORA-01034: ORACLE not available

ORA-27123: unable to attach to shared memory segment

Linux-x86_64 Error: 2: No such file or directory

Additional information: 2667

Additional information: 1380122625

Additional information: 1614807040

. For details refer to "(:CLSN00107:)" in "/u01/app/grid/diag/crs/rhelrac2/crs/trace/crsd_oraagent_oracle.trc".

2017-01-19 04:15:19.569534 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [start] (:CLSN00107:) clsn_agent::start }

2017-01-19 04:15:19.569553 : AGFW:369252096: {1:64351:50917} Command: start for resource: ora.racdb1.db 1 1 completed with status: FAIL

2017-01-19 04:15:19.571021 :CLSFRAME:537265792: TM [MultiThread] is changing desired thread # to 3. Current # is 2

2017-01-19 04:15:19.571479 : AGFW:367150848: {1:64351:50917} Agent sending reply for: RESOURCE_START[ora.racdb1.db 1 1] ID 4098:335569

2017-01-19 04:15:19.571925 : AGFW:367150848: {1:64351:50917} Agent sending reply for: RESOURCE_START[ora.racdb1.db 1 1] ID 4098:335569

2017-01-19 04:15:19.572044 :CLSFRAME:537265792: TM [MultiThread] is changing desired thread # to 4. Current # is 3

2017-01-19 04:15:19.582231 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [check] InstAgent::checkState gimh oracleSid:racdb11

2017-01-19 04:15:19.582253 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [check] Gimh::constructor ohome:/u01/app/oracle/product/12.1.0/dbhome_1 sid:racdb11

2017-01-19 04:15:19.582612 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [check] ConnectionPool::resetConnection s_statusOfConnectionMap 00f3aed8

2017-01-19 04:15:19.582630 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [check] ConnectionPool::resetConnection sid racdb11 status 2

2017-01-19 04:15:19.582685 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [check] Gimh::check OH /u01/app/oracle/product/12.1.0/dbhome_1 SID racdb11

2017-01-19 04:15:19.582772 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [check] Gimh::check condition changes to (GIMH_NEXT_NUM) 0(Abnormal Termination) exists

2017-01-19 04:15:19.582791 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [check] (:CLSN00007:)DbAgent::checkCbk failed gimh state 0(Abnormal Termination)

2017-01-19 04:15:19.582826 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [check] DbAgent:checkCbk planned offline or failed ret 5

2017-01-19 04:15:19.582944 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [check] DbAgent:checkCbk shutdown reset s_PDBStatusMap

2017-01-19 04:15:19.583020 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [check] (:CLSN00007:)InstAgent::checkState return unplanned offline

2017-01-19 04:15:19.583065 : USRTHRD:369252096: {1:64351:50917} Gimh::destructor gimh_dest_query_ctx rc=0

2017-01-19 04:15:19.583114 : USRTHRD:369252096: {1:64351:50917} Gimh::destructor gimh_dest_inst_ctx rc=0

2017-01-19 04:15:19.583156 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [check] ConnectionPool::stopConnection

2017-01-19 04:15:19.583208 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [check] ConnectionPool::removeConnection connection count 0

2017-01-19 04:15:19.583223 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [check] ConnectionPool::removeConnection freed 0

2017-01-19 04:15:19.583235 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [check] ConnectionPool::stopConnection sid racdb11 status 1

2017-01-19 04:15:19.583255 :CLSDYNAM:369252096: [ora.racdb1.db]{1:64351:50917} [check] InstAgent::checkState 1 prev clsagfw_res_status 5 current clsagfw_res_status 1

2017-01-19 04:15:19.583688 : AGFW:367150848: {1:64351:50917} ora.racdb1.db 1 1 state changed from: STARTING to: OFFLINE

[oracle@rhelrac2 ~]$ srvctl start instance -i racdb11 -d racdb1

PRCR-1013 : Failed to start resource ora.racdb1.db

PRCR-1064 : Failed to start resource ora.racdb1.db on node rhelrac2

CRS-5017: The resource action "ora.racdb1.db start" encountered the following error:

ORA-01078: failure in processing system parameters

ORA-01565: error in identifying file '+DBDISK/racdb1/spfileracdb1.ora'

ORA-17503: ksfdopn:2 Failed to open file +DBDISK/racdb1/spfileracdb1.ora

ORA-01034: ORACLE not available

ORA-27123: unable to attach to shared memory segment

Linux-x86_64 Error: 2: No such file or directory

Additional information: 2667

Additional information: 1380122625

Additional information: 1614807040

. For details refer to "(:CLSN00107:)" in "/u01/app/grid/diag/crs/rhelrac2/crs/trace/crsd_oraagent_oracle.trc".

CRS-2674: Start of 'ora.racdb1.db' on 'rhelrac2' failed

[root@rhelrac1 ~]# crsctl stat res -t

--------------------------------------------------------------------------------

Name Target State Server State details

--------------------------------------------------------------------------------

Local Resources

--------------------------------------------------------------------------------

ora.ARCDISK.dg

ONLINE ONLINE rhelrac1 STABLE

ONLINE ONLINE rhelrac2 STABLE

ora.DATA.dg

ONLINE ONLINE rhelrac1 STABLE

ONLINE ONLINE rhelrac2 STABLE

ora.DBDISK.dg

ONLINE ONLINE rhelrac1 STABLE

ONLINE ONLINE rhelrac2 STABLE

ora.LISTENER.lsnr

ONLINE ONLINE rhelrac1 STABLE

ONLINE ONLINE rhelrac2 STABLE

ora.asm

ONLINE ONLINE rhelrac1 Started,STABLE

ONLINE ONLINE rhelrac2 Started,STABLE

ora.net1.network

ONLINE ONLINE rhelrac1 STABLE

ONLINE ONLINE rhelrac2 STABLE

ora.ons

ONLINE ONLINE rhelrac1 STABLE

ONLINE ONLINE rhelrac2 STABLE

--------------------------------------------------------------------------------

Cluster Resources

--------------------------------------------------------------------------------

ora.LISTENER_SCAN1.lsnr

1 ONLINE ONLINE rhelrac2 STABLE

ora.LISTENER_SCAN2.lsnr

1 ONLINE ONLINE rhelrac2 STABLE

ora.MGMTLSNR

1 ONLINE ONLINE rhelrac1 169.254.225.104,STAB

ora.cvu

1 ONLINE ONLINE rhelrac1 STABLE

ora.mgmtdb

1 OFFLINE OFFLINE STABLE

ora.oc4j

1 ONLINE ONLINE rhelrac1 STABLE

ora.racdb1.db

1 ONLINE OFFLINE STABLE

2 ONLINE ONLINE rhelrac1 Open,STABLE

ora.rhelrac1.vip

1 ONLINE ONLINE rhelrac1 STABLE

ora.rhelrac2.vip

1 ONLINE ONLINE rhelrac2 STABLE

ora.scan1.vip

1 ONLINE ONLINE rhelrac2 STABLE

ora.scan2.vip

1 ONLINE ONLINE rhelrac2 STABLE

--------------------------------------------------------------------------------

Please help in getting issue resolved.

Thanks,

Mallik S

This post has been answered by Mallik S on Jan 20 2017

Jump to Answer

Locked Post

New comments cannot be posted to this locked post.

Locked on Feb 17 2017

Added on Jan 19 2017

#performance-availability, #rac-asm-clusterware-installation

6 comments

7,704 views