CRSD agent start the database as Restrict Mode (Doc ID 2175526.1)

Last updated on SEPTEMBER 18, 2016

Applies to:

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

Symptoms

The instance restarted with restrict mode.

$oracle_Base/diag/rdbms/DI0DB/DI0DB1/trace/alert_DI0DB1.log:

compatible = "12.0.0"
log_archive_dest_1 = "LOCATION=/orarac/oraarch01/DI0DB/arch
MANDATORY"
log_archive_dest_2 = "SERVICE=DI0STDB.FTH.KORDOBA.DE
VALID_FOR=(ONLINE_LOGFILES,PRIMARY_ROLE) DB_UNIQUE_NAME=DI0STDB"
log_archive_dest_state_1 = "ENABLE"
log_archive_dest_state_2 = "ENABLE"
log_archive_dest_state_3 = "DEFER"
log_archive_config = "DG_CONFIG=(DI0DB,DI0STDB)"                                                                                                               
log_archive_format = "DI0DB_log_r%r_t%t_s%s.arc"

..

Sun Feb 21 10:40:09 2016
License high water mark = 392
Sun Feb 21 10:40:13 2016
Instance terminated by LMHB, pid = 24784
Sun Feb 21 10:40:13 2016
USER (ospid: 15036): terminating the instance                                                              -----> Instance got terminated
Sun Feb 21 10:40:13 2016
Instance terminated by USER, pid = 15036
Sun Feb 21 10:40:15 2016
Starting ORACLE instance (restrict) (OS id: 15118)                                                       -----> Instance started in restrict mode
Instance starting with restriction mode

 

CRS agent logs,

$oracle_base/diag/crs/<nodename>/crs/trace/crsd_oraagent_oracle.trc:

 

2016-02-21 11:40:08.265170 :CLSDYNAM:35: [ora.di0db.db]{1:15335:7860} [check] ConnectionPool::stopConnection

2016-02-21 11:40:08.265223 :CLSDYNAM:35: [ora.di0db.db]{1:15335:7860} [check] ConnectionPool::removeConnection connection count 0
2016-02-21 11:40:08.265265 :CLSDYNAM:35: [ora.di0db.db]{1:15335:7860} [check] ConnectionPool::removeConnection freed 0
2016-02-21 11:40:08.265281 :CLSDYNAM:35: [ora.di0db.db]{1:15335:7860} [check] ConnectionPool::stopConnection sid DI0DB2 status 1
2016-02-21 11:40:08.265691 : AGFW:9: {1:15335:7860} ora.di0db.db 2 1 state changed from: ONLINE to: FAILED                                        
2016-02-21 11:40:08.265796 : AGFW:9: {1:15335:7860} ora.di0db.db 2 1 state details has changed from: Open to: Abnormal Termination  

..

2016-02-21 11:40:13.429632 :CLSDYNAM:35: [ora.di0db.db]{0:9:21} [clean] (:CLSN00106:) clsn_agent::clean }
2016-02-21 11:40:13.429651 : AGFW:35: {0:9:21} Command: clean for resource: ora.di0db.db 2 1 completed with status: SUCCESS 

..
2016-02-21 11:40:13.432101 :CLSDYNAM:35: [ora.di0db.db]{0:9:21} [check] ConnectionPool::stopConnection sid DI0DB2 status 1
2016-02-21 11:40:13.432454 : AGFW:9: {0:9:21} ora.di0db.db 2 1 state changed from: CLEANING to: PLANNED_OFFLINE 
2016-02-21 11:40:13.432520 : AGFW:9: {0:9:21} ora.di0db.db 2 1 state details has changed from: Abnormal Termination to: Instance Shutdown

..

2016-02-21 11:40:13.441534 : AGFW:9: {0:9:21} Preparing START command for: ora.di0db.db 2 1
2016-02-21 11:40:13.441549 : AGFW:9: {0:9:21} ora.di0db.db 2 1 state changed from: PLANNED_OFFLINE to: STARTING

..

2016-02-21 11:40:14.812475 :CLSDYNAM:35: [ora.di0db.db]{0:9:21} [start] InstConnection:connectInt connected
2016-02-21 11:40:14.812533 :CLSDYNAM:35: [ora.di0db.db]{0:9:21} [start] InstAgent::startup restrict                             -----> CRS initiated startup restrict

 ..

016-02-21 11:41:34.399162 :CLSDYNAM:35: [ora.di0db.db]{0:9:21} [start] (:CLSN00107:) clsn_agent::start }
2016-02-21 11:41:34.399181 : AGFW:35: {0:9:21} Command: start for resource: ora.di0db.db 2 1 completed with status: SUCCESS 
2016-02-21 11:41:34.399862 :CLSDYNAM:35: [ora.di0db.db]{0:9:21} [check] InstAgent::checkState gimh oracleSid:DI0DB2
2016-02-21 11:41:34.399881 :CLSDYNAM:35: [ora.di0db.db]{0:9:21} [check] Gimh::constructor ohome:/oracle/system/dbms1210 sid:DI0DB2
2016-02-21 11:41:34.399969 : AGFW:9: {0:9:21} Agent sending reply for: RESOURCE_START[ora.di0db.db 2 1] ID 4098:1648743
2016-02-21 11:41:34.400020 :CLSDYNAM:35: [ora.di0db.db]{0:9:21} [check] Gimh::check OH /oracle/system/dbms1210 SID DI0DB2
2016-02-21 11:41:34.400697 :CLSDYNAM:35: [ora.di0db.db]{0:9:21} [check] Gimh::check condition changes to (GIMH_NEXT_NUM) 9(Open),14(Restricted Access) exists <<<<<<<<<<<<<<<<
2016-02-21 11:41:34.400734 :CLSDYNAM:35: [ora.di0db.db]{0:9:21} [check] DbAgent:checkCbk 10 state partial shutdownBegin:0 GIMH 14(Restricted Access)
2016-02-21 11:41:34.401535 : AGFW:9: {0:9:21} ora.di0db.db 2 1 state changed from: STARTING to: PARTIAL 
2016-02-21 11:41:34.401610 : AGFW:9: {0:9:21} Started implicit monitor for [ora.di0db.db 2 1] interval=1000 delay=1000
2016-02-21 11:41:34.401676 : AGFW:9: {0:9:21} ora.di0db.db 2 1 state details has changed from: Instance Shutdown to: Restricted Access
2016-02-21 11:41:34.401745 :CLSDYNAM:35: [ora.di0db.db]{0:9:21} [res_attr_modified] clsn_agent::modify {
2016-02-21 11:41:34.401846 :CLSDYNAM:35: [ora.di0db.db]{0:9:21} [res_attr_modified] getNewResAttrib: attribute GEN_AUDIT_FILE_DEST new value /orarac/oracle/admin/entities/DI0DB/DI0DB2/adump
len 48
2016-02-21 11:41:34.401852 : AGFW:9: {0:9:21} Agent sending last reply for: RESOURCE_START[ora.di0db.db 2 1] ID 4098:1648743
2016-02-21 11:41:34.401919 :CLSDYNAM:35: [ora.di0db.db]{0:9:21} [res_attr_modified] clsn_agent::modify }
2016-02-21 11:41:34.401934 : AGFW:35: {0:9:21} Command: res_attr_modified for resource: ora.di0db.db 2 1 completed with status: SUCCESS 

..
2016-02-21 11:41:34.593457 : USRTHRD:11: Processing the event CRS_RESOURCE_STATE_CHANGE
2016-02-21 11:41:34.594192 : USRTHRD:11: Processing the event NO-OP
2016-02-21 11:41:34.595647 : USRTHRD:11: Processing the event NO-OP
2016-02-21 11:41:35.403203 :CLSDYNAM:29: [ora.di0db.db]{0:9:21} [check] DbAgent:checkCbk 10 state partial shutdownBegin:0 GIMH 14(Restricted Access)
2016-02-21 11:41:36.403279 :CLSDYNAM:28: [ora.di0db.db]{0:9:21} [check] DbAgent:checkCbk 10 state partial shutdownBegin:0 GIMH 14(Restricted Access)
2016-02-21 11:41:37.403084 :CLSDYNAM:21: [ora.di0db.db]{0:9:21} [check] DbAgent:checkCbk 10 state partial shutdownBegin:0 GIMH 14(Restricted Access)
2016-02-21 11:41:38.403018 :CLSDYNAM:37: [ora.di0db.db]{0:9:21} [check] DbAgent:checkCbk 10 state partial shutdownBegin:0 GIMH 14(Restricted Access)
2016-02-21 11:41:39.403762 :CLSDYNAM:27: [ora.di0db.db]{0:9:21} [check] DbAgent:checkCbk 10 state partial shutdownBegin:0 GIMH 14(Restricted Access)
2016-02-21 11:41:40.153340 : USRTHRD:33: {1:15335:37548} CssData::CssGroupEvent groupname:mgmtdbpub lastGev:0

 

Note that db alert log/ crsd logs showing different times as CRS has a timezone issue (CRS Time 11:40 maps to DB time 10:40) this should not a problem for database.Instance terminated around 10:40:13 and immediately CRS initiated to start the database restrict mode within 1 second "11:40:14"

 

 

Cause

Sign In with your My Oracle Support account

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

My Oracle Support provides customers with access to over a
Million Knowledge Articles and hundreds of Community platforms