My Oracle Support Banner

CRS-5021: Check of storage failed seen after 12.1 to 12.2 rootupgrade.sh Completed Successfully (Doc ID 2450030.1)

Last updated on AUGUST 09, 2020

Applies to:

Oracle Database - Enterprise Edition - Version 12.1.0.1 and later
Information in this document applies to any platform.

Symptoms

While upgrading the GI from 12.1 to 12.2, the following errors occurred in rootcrs logs in first node. However rootupgrade.sh completed successfully on first node.

rootcrs log:

/ee/oracle/12.2/rootupgrade.sh
Performing root user operation.

The following environment variables are set as:
ORACLE_OWNER= crsusr
ORACLE_HOME= /ee/oracle/12.2

Enter the full pathname of the local bin directory: [/usr/local/bin]:
The contents of "dbhome" have not changed. No need to overwrite.
The contents of "oraenv" have not changed. No need to overwrite.
The contents of "coraenv" have not changed. No need to overwrite.

Entries will be added to the /etc/oratab file as needed by
Database Configuration Assistant when a database is created
Finished running generic part of root script.
Now product-specific root actions will be performed.
/ee/oracle/12.2/clone/rootpre.sh output will be logged in
/ee/oracle/12.2/install/root_rac_2016-10-17_00-05-20.log

Checking if group services should be configured....
Nothing to configure.
Relinking oracle with rac_on option
Using configuration parameter file:
/ee/oracle/12.2/crs/install/crsconfig_params The log of current session can be found at:
/ee/oracle/base/crsdata/rac3/crsconfig/rootcrs_rac3_2016-10-17_00-06-37AM.log
2016/10/17 00:06:47 CLSRSC-595: Executing upgrade step 1 of 19: 'UpgradeTFA'.
2016/10/17 00:06:48 CLSRSC-4015: Performing install or upgrade action for
Oracle Trace File Analyzer (TFA) Collector.
2016/10/17 00:11:44 CLSRSC-4003: Successfully patched Oracle Trace File
Analyzer (TFA) Collector.
2016/10/17 00:11:44 CLSRSC-595: Executing upgrade step 2 of 19: 'ValidateEnv'.
2016/10/17 00:12:47 CLSRSC-595: Executing upgrade step 3 of 19: 'GenSiteGUIDs'.
2016/10/17 00:12:52 CLSRSC-595: Executing upgrade step 4 of 19: 'GetOldConfig'.
2016/10/17 00:12:53 CLSRSC-464: Starting retrieval of the cluster configuration data
2016/10/17 00:13:28 CLSRSC-515: Starting OCR manual backup.
......
CRS-2673: Attempting to stop 'ora.ctssd' on 'rac3'
CRS-2673: Attempting to stop 'ora.evmd' on 'rac3'
CRS-2677: Stop of 'ora.evmd' on 'rac3' succeeded
CRS-2677: Stop of 'ora.ctssd' on 'rac3' succeeded
CRS-2673: Attempting to stop 'ora.cssd' on 'rac3'
CRS-2677: Stop of 'ora.cssd' on 'rac3' succeeded
CRS-2673: Attempting to stop 'ora.gipcd' on 'rac3'
CRS-2677: Stop of 'ora.gipcd' on 'rac3' succeeded
CRS-2793: Shutdown of Oracle High Availability Services-managed resources on 'rac3' has completed
CRS-4133: Oracle High Availability Services has been stopped.
CRS-4123: Starting Oracle High Availability Services-managed resources
CRS-2672: Attempting to start 'ora.mdnsd' on 'rac3'
CRS-2672: Attempting to start 'ora.evmd' on 'rac3'
CRS-2676: Start of 'ora.mdnsd' on 'rac3' succeeded
CRS-2676: Start of 'ora.evmd' on 'rac3' succeeded
CRS-2672: Attempting to start 'ora.gpnpd' on 'rac3'
CRS-2676: Start of 'ora.gpnpd' on 'rac3' succeeded
CRS-2672: Attempting to start 'ora.gipcd' on 'rac3'
CRS-2676: Start of 'ora.gipcd' on 'rac3' succeeded
CRS-2672: Attempting to start 'ora.cssdmonitor' on 'rac3'
CRS-2676: Start of 'ora.cssdmonitor' on 'rac3' succeeded
CRS-2672: Attempting to start 'ora.cssd' on 'rac3'
CRS-2672: Attempting to start 'ora.diskmon' on 'rac3'
CRS-2676: Start of 'ora.diskmon' on 'rac3' succeeded
CRS-2676: Start of 'ora.cssd' on 'rac3' succeeded
CRS-2672: Attempting to start 'ora.cluster_interconnect.haip' on 'rac3'
CRS-2672: Attempting to start 'ora.ctssd' on 'rac3'
CRS-2676: Start of 'ora.ctssd' on 'rac3' succeeded
CRS-2676: Start of 'ora.cluster_interconnect.haip' on 'rac3' succeeded
CRS-2672: Attempting to start 'ora.asm' on 'rac3'
CRS-5021: Check of storage failed: details at "(:CLSN00117:)" in "/ee/oracle/base/diag/crs/rac3/crs/trace/ohasd_orarootagent_root.trc" <<<<<<<<<==!
CRS-2676: Start of 'ora.asm' on 'rac3' succeeded
CRS-2672: Attempting to start 'ora.storage' on 'rac3'
CRS-2676: Start of 'ora.storage' on 'rac3' succeeded
CRS-2672: Attempting to start 'ora.crf' on 'rac3'
CRS-2676: Start of 'ora.crf' on 'rac3' succeeded
CRS-2672: Attempting to start 'ora.crsd' on 'rac3'
CRS-2676: Start of 'ora.crsd' on 'rac3' succeeded
CRS-6017: Processing resource auto-start for servers: rac3
CRS-2673: Attempting to stop 'ora.rac3.vip' on 'rwsbp14'
CRS-2672: Attempting to start 'ora.ons' on 'rac3'
CRS-2677: Stop of 'ora.rac3.vip' on 'rwsbp14' succeeded
CRS-2672: Attempting to start 'ora.rac3.vip' on 'rac3'
CRS-2676: Start of 'ora.rac3.vip' on 'rac3' succeeded
CRS-2672: Attempting to start 'ora.LISTENER.lsnr' on 'rac3'
CRS-2676: Start of 'ora.ons' on 'rac3' succeeded
CRS-2676: Start of 'ora.LISTENER.lsnr' on 'rac3' succeeded
CRS-6016: Resource auto-start has completed for server rac3
CRS-6024: Completed start of Oracle Cluster Ready Services-managed resources
CRS-4123: Oracle High Availability Services has been started.
2016/10/17 00:37:40 CLSRSC-343: Successfully started Oracle Clusterware stack
2016/10/17 00:37:40 CLSRSC-595: Executing upgrade step 18 of 19: 'UpgradeNode'.
2016/10/17 00:37:52 CLSRSC-474: Initiating upgrade of resource types
2016/10/17 00:40:10 CLSRSC-482: Running command: 'srvctl upgrade model -s 12.1.0.2.0 -d 12.2.0.1.0 -p first'
2016/10/17 00:40:10 CLSRSC-475: Upgrade of resource types successfully initiated.
2016/10/17 00:46:04 CLSRSC-595: Executing upgrade step 19 of 19: 'PostUpgrade'.
2016/10/17 00:46:53 CLSRSC-325: Configure Oracle Grid Infrastructure for a Cluster ... succeeded

alert log:

2016-10-17 00:35:55.723 [OHASD(11206862)]CRS-1301: Oracle High Availability Service started on node rac3.

2016-10-17 00:35:56.961 [ORAROOTAGENT(3080218)]CRS-8500: Oracle Clusterware ORAROOTAGENT process is starting with operating system process ID 3080218

2016-10-17 00:35:57.313 [ORAAGENT(5177736)]CRS-8500: Oracle Clusterware ORAAGENT process is starting with operating system process ID 5177736

2016-10-17 00:35:57.866 [CSSDAGENT(3736220)]CRS-8500: Oracle Clusterware CSSDAGENT process is starting with operating system process ID 3736220

2016-10-17 00:35:57.904 [CSSDMONITOR(6553912)]CRS-8500: Oracle Clusterware CSSDMONITOR process is starting with operating system process ID 6553912

2016-10-17 00:35:59.109 [ORAAGENT(14353076)]CRS-8500: Oracle Clusterware ORAAGENT process is starting with operating system process ID 14353076

2016-10-17 00:35:59.553 [MDNSD(6226530)]CRS-8500: Oracle Clusterware MDNSD process is starting with operating system process ID 6226530

2016-10-17 00:35:59.566 [EVMD(3408466)]CRS-8500: Oracle Clusterware EVMD process is starting with operating system process ID 3408466

2016-10-17 00:36:00.828 [GPNPD(5177742)]CRS-8500: Oracle Clusterware GPNPD process is starting with operating system process ID 5177742

2016-10-17 00:36:01.663 [GPNPD(5177742)]CRS-2328: GPNPD started on node rac3.

2016-10-17 00:36:01.941 [GIPCD(4194854)]CRS-8500: Oracle Clusterware GIPCD process is starting with operating system process ID 4194854

2016-10-17 00:36:12.520 [CSSDMONITOR(4325820)]CRS-8500: Oracle Clusterware CSSDMONITOR process is starting with operating system process ID 4325820

2016-10-17 00:36:13.393 [CSSDAGENT(8257628)]CRS-8500: Oracle Clusterware CSSDAGENT process is starting with operating system process ID 8257628

2016-10-17 00:36:14.221 [OCSSD(6553930)]CRS-8500: Oracle Clusterware OCSSD process is starting with operating system process ID 6553930

2016-10-17 00:36:15.317 [OCSSD(6553930)]CRS-1713: CSSD daemon is started in hub mode

2016-10-17 00:36:24.369 [OCSSD(6553930)]CRS-1707: Lease acquisition for node rac3 number 1 completed

2016-10-17 00:36:25.584 [OCSSD(6553930)]CRS-1605: CSSD voting file is online: /dev/css10; details in /ee/oracle/base/diag/crs/rac3/crs/trace/ocssd.trc.

2016-10-17 00:36:25.779 [OCSSD(6553930)]CRS-1605: CSSD voting file is online: /dev/css11; details in /ee/oracle/base/diag/crs/rac3/crs/trace/ocssd.trc.

2016-10-17 00:36:25.967 [OCSSD(6553930)]CRS-1605: CSSD voting file is online: /dev/css12; details in /ee/oracle/base/diag/crs/rac3/crs/trace/ocssd.trc.

2016-10-17 00:36:27.965 [OCSSD(6553930)]CRS-1601: CSSD Reconfiguration complete. Active nodes are rac3 rac4 rac5 rac6 .

2016-10-17 00:36:30.388 [OCSSD(6553930)]CRS-1720: Cluster Synchronization Services daemon (CSSD) is ready for operation.

2016-10-17 00:36:30.519 [OCTSSD(3342974)]CRS-8500: Oracle Clusterware OCTSSD process is starting with operating system process ID 3342974

2016-10-17 00:36:31.204 [OCTSSD(3342974)]CRS-2403: The Cluster Time Synchronization Service on host rac3 is in observer mode.

2016-10-17 00:36:32.536 [OCTSSD(3342974)]CRS-2407: The new Cluster Time Synchronization Service reference node is host rac6.

2016-10-17 00:36:32.538 [OCTSSD(3342974)]CRS-2401: The Cluster Time Synchronization Service started on host rac3.

2016-10-17 00:36:32.547 [OCTSSD(3342974)]CRS-2412: The Cluster Time Synchronization Service detects that the local time is significantly different from the mean cluster time. Details in /ee/oracle/base/diag/crs/rac3/crs/trace/octssd.trc.

2016-10-17 00:36:58.505 [ORAROOTAGENT(3080218)]CRS-5021: Check of storage failed: details at "(:CLSN00117:)" in "/ee/oracle/base/diag/crs/rac3/crs/trace/ohasd_orarootagent_root.trc"

2016-10-17 00:37:02.653 [ORAROOTAGENT(3080218)]CRS-5019: All OCR locations are on ASM disk groups [DATA], and none of these disk groups are mounted. Details are at "(:CLSN00140:)" in "/ee/oracle/base/diag/crs/rac3/crs/trace/ohasd_orarootagent_root.trc".

2016-10-17 00:37:12.142 [OSYSMOND(9896228)]CRS-8500: Oracle Clusterware OSYSMOND process is starting with operating system process ID 9896228

2016-10-17 00:37:13.741 [CRSD(11993612)]CRS-8500: Oracle Clusterware CRSD process is starting with operating system process ID 11993612

2016-10-17 00:37:16.765 [CRSD(11993612)]CRS-1012: The OCR service started on node rac3.

2016-10-17 00:37:18.712 [CRSD(11993612)]CRS-1201: CRSD started on node rac3.

ohasd_orarootagent_root.trc:

2016-10-17 00:35:57.992 : AGFW:2057: {0:0:2} Agent received the message: RESOURCE_PROBE[ora.storage 1 1] ID 4097:104

2016-10-17 00:35:57.993 : AGFW:2057: {0:0:2} Preparing CHECK command for: ora.storage 1 1

2016-10-17 00:35:57.993 :CLSDYNAM:3086: [ora.gipcd]{0:0:2} [check] Agent::getResAgent resname:ora.gipcd version:12.1.0.1.0

2016-10-17 00:35:57.994 :CLSDYNAM:2315: [ ora.crf]{0:0:2} [check] Process id 6291794 translated to cssdmonitor

2016-10-17 00:35:57.996 :CLSDYNAM:2315: [ ora.crf]{0:0:2} [check] DaemonAgent::clsdmAndPidChecks 040 adjusted timeout:48000

2016-10-17 00:35:57.996 :CLSDYNAM:2572: [ora.ctssd]{0:0:2} [check] Process id 3866968 translated to aioserver

2016-10-17 00:35:57.996 :CLSDYNAM:3086: [ora.gipcd]{0:0:2} [check] Agent::Agent pAgent:111835d50 &m_resName:111835f20 resname:ora.gipcd

2016-10-17 00:35:58.001 :CLSDYNAM:1800: [ora.crsd]{0:0:2} [check] Agent::setResType setResType type:ora.crs.type

2016-10-17 00:35:58.002 :CLSDYNAM:2572: [ora.ctssd]{0:0:2} [check] DaemonAgent::clsdmAndPidChecks 040 adjusted timeout:48000

2016-10-17 00:35:58.004 : CLSDMC:2315: Connecting to ipc://rac3_MOND

2016-10-17 00:35:58.005 :CLSDYNAM:3086: [ora.gipcd]{0:0:2} [check] adding state dumper of res:ora.gipcd

2016-10-17 00:35:58.005 :CLSFRAME:1: TM [MultiThread] is changing desired thread # to 9. Current # is 7

2016-10-17 00:35:58.005 : AGFW:2057: {0:0:2} ora.diskmon 1 1 state changed from: rac3 to: PLANNED_OFFLINE

2016-10-17 00:35:58.006 : CLSDMC:2315: Error: gipcWait for gipcConnect - ret_gipcreqinfo=gipcretConnectionRefused, type_gipcreqinfo=gipcreqtypeConnect

2016-10-17 00:35:58.006 : AGFW:2057: {0:0:2} RECYCLE_AGENT attribute not found

2016-10-17 00:35:58.006 :CLSDYNAM:2315: [ ora.crf][ALERT]{0:0:2} [check] ClsdmClient::sendMessage clsdmc_send error rmsg:0 ecode:-7 errbuf:

2016-10-17 00:35:58.007 :CLSDYNAM:2315: [ ora.crf]{0:0:2} [check] DaemonAgent::clsdmCheck 040 sendMessage excp:

2016-10-17 00:35:58.007 :CLSDYNAM:3086: [ora.gipcd]{0:0:2} [check] __IS_HASD_AGENT=TRUE

2016-10-17 00:35:58.011 :CLSFRAME:1: TM [MultiThread] is changing desired thread # to 10. Current # is 9

2016-10-17 00:35:58.012 : AGFW:2057: {0:0:2} Agent sending last reply for: RESOURCE_PROBE[ora.diskmon 1 1] ID 4097:101

2016-10-17 00:35:58.013 : CLSDMC:2572: Connecting to ipc://rac3_CTSSD

2016-10-17 00:35:58.015 : CLSDMC:2572: Error: gipcWait for gipcConnect - ret_gipcreqinfo=gipcretConnectionRefused, type_gipcreqinfo=gipcreqtypeConnect

2016-10-17 00:35:58.016 :CLSDYNAM:2572: [ora.ctssd][ALERT]{0:0:2} [check] ClsdmClient::sendMessage clsdmc_send error rmsg:0 ecode:-7 errbuf:

2016-10-17 00:35:58.016 :CLSDYNAM:3086: [ora.gipcd]{0:0:2} [check] Agent::setResType setResType type:ora.gipc.type

2016-10-17 00:35:58.018 :CLSDYNAM:2572: [ora.ctssd]{0:0:2} [check] DaemonAgent::clsdmCheck 040 sendMessage excp:

2016-10-17 00:35:58.018 :CLSDYNAM:2829: [ora.cluster_interconnect.haip]{0:0:2} [check] Agent::getResAgent resname:ora.cluster_interconnect.haip version:

2016-10-17 00:35:58.021 :CLSDYNAM:2829: [ora.cluster_interconnect.haip]{0:0:2} [check] Agent::getAgent for __IS_HASD_AGENT = TRUE

2016-10-17 00:35:58.021 : USRTHRD:2315: {0:0:2} Thread:[DaemonCheck:crf] thread constructor exit this:10dd0a30 m_pThnd:0 m_thndMX:10dd0a50, m_stopMX:10dd0e98 m_tintMX:10dd0d90 m_postMX:10dd0c88

2016-10-17 00:35:58.022 : USRTHRD:2572: {0:0:2} Thread:[DaemonCheck:ctssd] thread constructor exit this:119c7c30 m_pThnd:0 m_thndMX:119c7c50, m_stopMX:119c8098 m_tintMX:119c7f90 m_postMX:119c7e88

2016-10-17 00:35:58.022 :CLSDYNAM:2829: [ora.cluster_interconnect.haip]{0:0:2} [check] Agent::Agent pAgent:1119c96f0 &m_resName:1119c98c0 resname:ora.cluster_interconnect.haip

2016-10-17 00:35:58.025 :CLSDYNAM:2315: [ ora.crf]{0:0:2} [check] Check return = 1, state detail = NULL

2016-10-17 00:35:58.026 :CLSDYNAM:3086: [ora.gipcd]{0:0:2} [check] DaemonAgent::updatePidCache 000 entry

2016-10-17 00:35:58.030 :CLSDYNAM:3086: [ora.gipcd]{0:0:2} [check] DaemonAgent::generateFilePath 000 entry

2016-10-17 00:35:58.030 : CSSCLNT:1800: clsssterm: terminating context (110db6b30)

2016-10-17 00:35:58.033 :CLSDYNAM:2572: [ora.ctssd]{0:0:2} [check] Check return = 1, state detail = NULL

2016-10-17 00:35:58.033 :CLSDYNAM:1800: [ora.crsd]{0:0:2} [check] Css::Css clsssinit() error, rc = 3

2016-10-17 00:35:58.033 :CLSDYNAM:2315: [ ora.crf]{0:0:2} [check] (:CLSN00109:) Agent::commonCheck check failed action:0109 retval:1

2016-10-17 00:35:58.033 : AGFW:2057: {0:0:2} Agent received the message: RESOURCE_DELETE[ora.diskmon 1 1] ID 4358:165

2016-10-17 00:35:58.033 :CLSDYNAM:3343: [ora.storage]{0:0:2} [check] Agent::getResAgent resname:ora.storage version:12.1.0.1.0

2016-10-17 00:35:58.034 :CLSDYNAM:1800: [ora.crsd]{0:0:2} [check] Css::Css Error in constructor. All subsequent functions will fail.

2016-10-17 00:35:58.035 :CLSDYNAM:2315: [ ora.crf]{0:0:2} [check] Agent::doStateDump Default Agent Dump

2016-10-17 00:35:58.035 : AGFW:2057: {0:0:2} ora.diskmon 1 1 marked as deleted.

2016-10-17 00:35:58.035 :CLSDYNAM:2829: [ora.cluster_interconnect.haip]{0:0:2} [check] adding state dumper of res:ora.cluster_interconnect.haip

2016-10-17 00:35:58.036 :CLSDYNAM:1800: [ora.crsd]{0:0:2} [check] Error getting Css Misscount value

2016-10-17 00:35:58.037 :CLSDYNAM:3086: [ora.gipcd]{0:0:2} [check] DaemonAgent::generateFilePathFromPname returns /ee/oracle/base/crsdata/rwsbp13/output/gipcd.pid

2016-10-17 00:35:58.037 :CLSDYNAM:3343: [ora.storage]{0:0:2} [check] Agent::Agent pAgent:110dd1bf0 &m_resName:110dd1dc0 resname:ora.storage

2016-10-17 00:35:58.037 :CLSDYNAM:2572: [ora.ctssd]{0:0:2} [check] (:CLSN00109:) Agent::commonCheck check failed action:0109 retval:1

2016-10-17 00:35:58.037 : AGFW:2057: {0:0:2} Agent sending last reply for: RESOURCE_DELETE[ora.diskmon 1 1] ID 4358:165

2016-10-17 00:35:58.038 :CLSDYNAM:2572: [ora.ctssd]{0:0:2} [check] Agent::doStateDump Default Agent Dump

2016-10-17 00:35:58.040 :CLSDYNAM:2315: [ ora.crf]{0:0:2} [check] Agent::doStateDump last call info:

2016-10-17 00:35:58.041 :CLSDYNAM:2572: [ora.ctssd]{0:0:2} [check] Agent::doStateDump last call info:

2016-10-17 00:35:58.041 :CLSDYNAM:2315: [ ora.crf]{0:0:2} [check] Time:10/17/2016 00:35:57.762 Tint:{0:0:2} action:104 resname:ora.crf lastCall:DaemonAgent::generateClsdmTimeOut use script timeout

2016-10-17 00:35:58.041 :CLSDYNAM:2572: [ora.ctssd]{0:0:2} [check] Time:10/17/2016 00:35:57.973 Tint:{0:0:2} action:104 resname:ora.ctssd lastCall:DaemonAgent::generateClsdmTimeOut use script timeout

2016-10-17 00:35:58.042 :CLSDYNAM:2572: [ora.ctssd]{0:0:2} [check] Time:10/17/2016 00:35:57.974 Tint:{0:0:2} action:104 resname:ora.ctssd lastCall:DaemonAgent::generateClsdmTimeOut timeout:60

2016-10-17 00:35:58.042 :CLSDYNAM:2572: [ora.ctssd]{0:0:2} [check] Time:10/17/2016 00:35:57.974 Tint:{0:0:2} action:104 resname:ora.ctssd lastCall:DaemonAgent::generateClsdmTimeOut resName:ora.ctssd timeout*800 ms:48000

..

2016-10-17 00:35:58.106 : CLSDMC:3086: Error: gipcWait for gipcConnect - ret_gipcreqinfo=gipcretConnectionRefused, type_gipcreqinfo=gipcreqtypeConnect

2016-10-17 00:35:58.106 :CLSDYNAM:1800: [ora.crsd]{0:0:2} [check] Time:10/17/2016 00:35:58.57 Tint:{0:0:2} action:104 resname:ora.crsd lastCall:DaemonAgent::generateClsdmTimeOut timeout:60

2016-10-17 00:35:58.107 : AGFW:2057: {0:0:2} ora.storage 1 1 state changed from: rac3 to: OFFLINE

..

2016-10-17 00:36:58.311 : GPNP:3086: clsgpnp_dbmsGetItem_profile: [at clsgpnp_dbms.c:399] Result: (0) CLSGPNP_OK. (:GPNP00401:)got ASM-Profile.Mode='remote'

2016-10-17 00:36:58.449 : CSSCLNT:3086: clsssinit: initialized context: (111da80d0) flags 0x115

2016-10-17 00:36:58.468 : CSSCLNT:3086: clsssinit: initialized context: (111da85b0) flags 0x104

2016-10-17 00:36:58.469 : CSSCLNT:3086: clsssterm: terminating context (111da85b0)

2016-10-17 00:36:58.470 :CLSDYNAM:3086: [ora.storage]{0:0:2} [check] StorageAgent::parsekgforetcodes retcode = 15, kgfoCheckMount(DATA12102), flag 4

2016-10-17 00:36:58.470 :CLSDYNAM:3086: [ora.storage]{0:0:2} [check] (:CLSN00117:) category: 0, operation: kgfocmucss5, loc: kgfoinit, OS error: 0, other: failed to connect to ASM

2016-10-17 00:36:58.502 :CLSDYNAM:3086: [ora.storage]{0:0:2} [check] clsnUtils::error Exception type=2 string=

CRS-5021: Check of storage failed: details at "(:CLSN00117:)" in "/ee/oracle/base/diag/crs/rac3/crs/trace/ohasd_orarootagent_root.trc"

2016-10-17 00:36:58.505 : AGFW:3086: {0:0:2} Sending background msg for resid ora.storage 1 1

2016-10-17 00:36:58.505 : AGFW:3086: {0:0:2} Agent sending message to PE: AGENT_BACKGROUNDMSG_TOPE[] ID 28675:123

2016-10-17 00:36:58.506 :CLSDYNAM:3086: [ora.storage]{0:0:2} [check] StorageAgent::check kgfo returncode 3

2016-10-17 00:36:58.506 :CLSDYNAM:3086: [ora.storage]{0:0:2} [check] (:CLSN00140:)StorageAgent::parsekgforretcodes OCR dgName DATA state 3

2016-10-17 00:36:58.506 : CSSCLNT:3086: clsssterm: terminating context (111da80d0)

2016-10-17 00:36:58.508 : AGFW:2057: {0:0:2} ora.storage 1 1 state changed from: OFFLINE to: rac3

crsd.trc:

2016-10-17 00:35:27.748 : AGFW:11309: {0:5:3} Agfw Proxy Server sending the last reply to PE for message:RESOURCE_PROBE[ora.ACFS.dg rac3 1] ID 4097:6615

2016-10-17 00:35:27.759 : AGFW:11309: {1:35993:90} Agfw Proxy Server received the message: RESOURCE_STOP[ora.asm rac3 1] ID 4099:6619

2016-10-17 00:35:27.759 : AGFW:11309: {1:35993:90} Agfw Proxy Server forwarding the message: RESOURCE_STOP[ora.asm rac3 1] ID 4099:6619 to the agent /ee/oracle/12.2/bin/oraagent_crsusr

2016-10-17 00:35:27.765 :UiServer:13365: {1:35993:90} Container [ Name: ORDER

MESSAGE:

TextMessage[CRS-2677: Stop of 'ora.ACFS.dg' on 'rac3' succeeded]

MSGTYPE:

TextMessage[3]

OBJID:

TextMessage[ora.asm rac3 1]

WAIT:

TextMessage[0]

]

2016-10-17 00:35:27.769 : AGFW:11309: {0:5:3} Agfw Proxy Server received the message: RESOURCE_PROBE[ora.DATA.dg rac3 1] ID 4097:6620

2016-10-17 00:35:27.770 : AGFW:11309: {0:5:3} Agfw Proxy Server forwarding the message: RESOURCE_PROBE[ora.DATA.dg rac3 1] ID 4097:6620 to the agent /ee/oracle/12.2/bin/oraagent_crsusr

2016-10-17 00:35:27.782 : AGFW:11309: {0:5:3} Received the reply to the message: RESOURCE_PROBE[ora.DATA.dg rac3 1] ID 4097:543 from the agent /ee/oracle/12.2/bin/oraagent_crsusr

2016-10-17 00:35:27.782 : AGFW:11309: {0:5:3} ora.DATA.dg rac3 1 received state from probe request. Old state = PLANNED_OFFLINE, New state = PLANNED_OFFLINE

2016-10-17 00:35:27.783 : AGFW:11309: {0:5:3} Agfw Proxy Server sending the last reply to PE for message:RESOURCE_PROBE[ora.DATA.dg rac3 1] ID 4097:6620

2016-10-17 00:35:27.791 : AGFW:11309: {1:35993:90} Received the reply to the message: RESOURCE_STOP[ora.asm rac3 1] ID 4099:541 from the agent /ee/oracle/12.2/bin/oraagent_crsusr

2016-10-17 00:35:27.794 : AGFW:11309: {1:35993:90} Agfw Proxy Server sending the reply to PE for message:RESOURCE_STOP[ora.asm rac3 1] ID 4099:6619

2016-10-17 00:35:27.794 : AGFW:11309: {0:5:3} Agfw Proxy Server received the message: CMD_COMPLETED[Proxy] ID 20482:6623

2016-10-17 00:35:27.794 : AGFW:11309: {0:5:3} Agfw Proxy Server replying to the message: CMD_COMPLETED[Proxy] ID 20482:6623

2016-10-17 00:35:27.795 :UiServer:13365: {1:35993:90} Container [ Name: ORDER

MESSAGE:

TextMessage[CRS-2677: Stop of 'ora.DATA.dg' on 'rac3' succeeded]

MSGTYPE:

TextMessage[3]

OBJID:

TextMessage[ora.asm rac3 1]

WAIT:

TextMessage[0]

]

2016-10-17 00:35:27.799 : AGFW:11309: {1:35993:90} Received the reply to the message: RESOURCE_STOP[ora.asm rac3 1] ID 4099:541 from the agent /ee/oracle/12.2/bin/oraagent_crsusr

2016-10-17 00:35:27.801 : AGFW:11309: {1:35993:90} Agfw Proxy Server sending the last reply to PE for message:RESOURCE_STOP[ora.asm rac3 1] ID 4099:6619

2016-10-17 00:35:27.801 : AGFW:11309: {1:35993:90} Agfw Proxy Server received the message: AGENT_SHUTDOWN_REQUEST[Proxy] ID 20486:89

2016-10-17 00:35:27.801 : AGFW:11309: {1:35993:90} Verifying msg agentname = /ee/oracle/12.2/bin/oraagent_crsusr

2016-10-17 00:35:27.803 : AGFW:11309: {1:35993:90} Shutdown request received from /ee/oracle/12.2/bin/oraagent_crsusr

2016-10-17 00:35:27.805 : AGFW:11309: {1:35993:90} Agfw Proxy Server replying to the message: AGENT_SHUTDOWN_REQUEST[Proxy] ID 20486:89

2016-10-17 00:35:27.812 : CRSCOMM:10538: IpcL: connection to member 5 has been removed

2016-10-17 00:35:27.812 :CLSFRAME:10538: Removing IPC Member:{Relative|Node:0|Process:5|Type:3}

2016-10-17 00:35:27.812 :CLSFRAME:10538: Disconnected from AGENT process: {Relative|Node:0|Process:5|Type:3}

2016-10-17 00:35:27.814 : AGFW:11309: {0:5:3} Agfw received reply from PE for resource state change for ora.asm rac3 1

2016-10-17 00:35:27.814 : AGFW:11309: {1:35993:122} Agfw Proxy Server received process disconnected notification, count=1

2016-10-17 00:35:27.814 : AGFW:11309: {1:35993:122} /ee/oracle/12.2/bin/oraagent_crsusr disconnected.

2016-10-17 00:35:27.814 : AGFW:11309: {1:35993:122} Agent /ee/oracle/12.2/bin/oraagent_crsusr[8585900] stopped!

2016-10-17 00:35:27.814 : CRSCOMM:11309: {1:35993:122} IpcL: removeConnection: Member 5 does not exist in pending connections.

2016-10-17 00:35:27.836 :UiServer:13365: {1:35993:90} Container [ Name: ORDER

MESSAGE:

TextMessage[CRS-2673: Attempting to stop 'ora.asm' on 'rac3']

MSGTYPE:

TextMessage[3]

OBJID:

TextMessage[ora.asm rac3 1]

WAIT:

TextMessage[0]

]

2016-10-17 00:35:27.837 : AGFW:11309: {1:35993:90} Agfw Proxy Server received the message: RESOURCE_STOP[ora.net1.network rac3 1] ID 4099:6631

2016-10-17 00:35:27.838 : AGFW:11309: {1:35993:90} Agfw Proxy Server forwarding the message: RESOURCE_STOP[ora.net1.network rac3 1] ID 4099:6631 to the agent /ee/oracle/12.2/bin/orarootagent_root

2016-10-17 00:35:27.852 : AGFW:11309: {1:35993:90} Received the reply to the message: RESOURCE_STOP[ora.net1.network rac3 1] ID 4099:562 from the agent /ee/oracle/12.2/bin/orarootagent_root

2016-10-17 00:35:27.853 : AGFW:11309: {1:35993:90} Agfw Proxy Server sending the reply to PE for message:RESOURCE_STOP[ora.net1.network rac3 1] ID 4099:6631

2016-10-17 00:35:27.854 : AGFW:11309: {1:35993:90} Received the reply to the message: RESOURCE_STOP[ora.net1.network rac3 1] ID 4099:562 from the agent /ee/oracle/12.2/bin/orarootagent_root

2016-10-17 00:35:27.855 : AGFW:11309: {1:35993:90} Agfw Proxy Server sending the last reply to PE for message:RESOURCE_STOP[ora.net1.network rac3 1] ID 4099:6631

2016-10-17 00:35:27.858 :UiServer:13365: {1:35993:90} Container [ Name: ORDER

MESSAGE:

TextMessage[CRS-2677: Stop of 'ora.asm' on 'rac3' succeeded]

crsctl command output:

$ crsctl stat res -t

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

Name Target State Server State details

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

Local Resources

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

ora.storage

1 ONLINE OFFLINE rac3 

 

 

 

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
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.