Database Shutdown With crsctl

I noticed something for the first time tonight when I was playing around in the Enkitec lab - something that I have been doing wrong for a while.  When working in the lab, I often rely on the crsctl command to shut down the entire cluster stack for me.  It's really easy to use "crsctl stop cluster -all" followed by "dcli -l root -g ~/dbs_group /u01/app/11.2.0.4/grid/bin/crsctl stop crs" to get everything down quickly.  As it turns out, that's not really the best course of action.

Let's start by looking at our dbm01 database to see how it is configured.

[enkdb01:oracle:dbm011] /home/oracle
> srvctl config database -d dbm01
Database unique name: dbm01
Database name: dbm01
Oracle home: /u01/app/oracle/product/11.2.0.4/dbhome_1
Oracle user: oracle
Spfile: +DATA/dbm01/spfiledbm01.ora
Domain:
Start options: open
Stop options: immediate
Database role: PRIMARY
Management policy: AUTOMATIC
Server pools: dbm01
Database instances: dbm011,dbm012
Disk Groups: DATA,RECO
Mount point paths:
Services: ANDY,martin,soe
Type: RAC
Database is administrator managed

As you can see, we have this database configured to use a "shutdown immediate" when the database is shut down. When we issue a simple "srvctl stop database -d dbm01" we get the following in the third line of the alert log snippet below:

Sun Apr 06 18:50:05 2014
ALTER SYSTEM SET service_names='SYS$SYS.SCHEDULER$_EVENT_QUEUE.DBM01' SCOPE=MEMORY SID='dbm011';
Shutting down instance (immediate)
Shutting down instance: further logons disabled
Sun Apr 06 18:50:05 2014
Stopping background process CJQ0
Stopping background process QMNC
Stopping background process MMNL
Stopping background process MMON
License high water mark = 16
ALTER DATABASE CLOSE NORMAL /* db agent *//* {1:971:290} */
Sun Apr 06 18:50:11 2014
SMON: disabling tx recovery
Stopping background process RCBG
SMON: disabling cache recovery
Sun Apr 06 18:50:13 2014
Block change tracking service stopping.
NOTE: Deferred communication with ASM instance
NOTE: deferred map free for map id 51
Stopping background process CTWR
Sun Apr 06 18:50:14 2014
NOTE: Deferred communication with ASM instance
NOTE: deferred map free for map id 32
Redo thread 1 internally disabled at seq 445 (LGWR)
Shutting down archive processes
Archiving is disabled
Sun Apr 06 18:50:14 2014
ARCH shutting down
ARC2: Archival stopped
Sun Apr 06 18:50:14 2014
ARCH shutting down
Sun Apr 06 18:50:14 2014
ARC3: Becoming the 'no FAL' ARCH
ARC0: Archival stopped
ARC3: Becoming the 'no SRL' ARCHSun Apr 06 18:50:14 2014

ARCH shutting down
ARC3: Archiving disabled
ARCH shutting down
ARC1: Archival stopped
ARC3: Archival stopped
Sun Apr 06 18:50:14 2014
NOTE: Deferred communication with ASM instance
Thread 1 closed at log sequence 445
Successful close of redo thread 1
Sun Apr 06 18:50:15 2014
NOTE: Deferred communication with ASM instance
NOTE: deferred map free for map id 4
Sun Apr 06 18:50:16 2014
Completed: ALTER DATABASE CLOSE NORMAL /* db agent *//* {1:971:290} */

This is what you would expect. The database is receiving a shutdown immediate command from srvctl. Now, let's try this as part of stopping the clusterware stack:

[root@enkdb01 ~]# crsctl stop cluster -all
CRS-2673: Attempting to stop 'ora.crsd' on 'enkdb01'
CRS-2790: Starting shutdown of Cluster Ready Services-managed resources on 'enkdb01'
CRS-2673: Attempting to stop 'ora.LISTENER_SCAN3.lsnr' on 'enkdb01'
CRS-2673: Attempting to stop 'ora.LISTENER_SCAN2.lsnr' on 'enkdb01'
CRS-2673: Attempting to stop 'ora.oc4j' on 'enkdb01'
CRS-2673: Attempting to stop 'ora.LISTENER.lsnr' on 'enkdb01'
CRS-2673: Attempting to stop 'ora.dbm01.andy.svc' on 'enkdb01'
CRS-2673: Attempting to stop 'ora.dbm01.soe.svc' on 'enkdb01'
CRS-2673: Attempting to stop 'ora.dbm01.martin.svc' on 'enkdb01'
CRS-2673: Attempting to stop 'ora.cvu' on 'enkdb01'
CRS-2677: Stop of 'ora.dbm01.andy.svc' on 'enkdb01' succeeded
CRS-2677: Stop of 'ora.dbm01.martin.svc' on 'enkdb01' succeeded
CRS-2677: Stop of 'ora.cvu' on 'enkdb01' succeeded
CRS-2677: Stop of 'ora.LISTENER_SCAN3.lsnr' on 'enkdb01' succeeded
CRS-2673: Attempting to stop 'ora.scan3.vip' on 'enkdb01'
CRS-2677: Stop of 'ora.LISTENER_SCAN2.lsnr' on 'enkdb01' succeeded
CRS-2673: Attempting to stop 'ora.scan2.vip' on 'enkdb01'
CRS-2677: Stop of 'ora.LISTENER.lsnr' on 'enkdb01' succeeded
CRS-2677: Stop of 'ora.scan3.vip' on 'enkdb01' succeeded
CRS-2677: Stop of 'ora.scan2.vip' on 'enkdb01' succeeded
CRS-2677: Stop of 'ora.dbm01.soe.svc' on 'enkdb01' succeeded
CRS-2673: Attempting to stop 'ora.enkdb01.vip' on 'enkdb01'
CRS-2672: Attempting to start 'ora.dbm01.andy.svc' on 'enkdb02'
CRS-2672: Attempting to start 'ora.dbm01.martin.svc' on 'enkdb02'
CRS-2676: Start of 'ora.dbm01.andy.svc' on 'enkdb02' succeeded
CRS-2676: Start of 'ora.dbm01.martin.svc' on 'enkdb02' succeeded
CRS-2672: Attempting to start 'ora.dbm01.martin_preconnect.svc' on 'enkdb02'
CRS-2674: Start of 'ora.dbm01.martin_preconnect.svc' on 'enkdb02' failed
CRS-2673: Attempting to stop 'ora.crsd' on 'enkdb02'
CRS-2790: Starting shutdown of Cluster Ready Services-managed resources on 'enkdb02'
CRS-2673: Attempting to stop 'ora.LISTENER_SCAN1.lsnr' on 'enkdb02'
CRS-2677: Stop of 'ora.enkdb01.vip' on 'enkdb01' succeeded
CRS-2673: Attempting to stop 'ora.registry.acfs' on 'enkdb01'
CRS-2673: Attempting to stop 'ora.DBFS_DG.dg' on 'enkdb01'
CRS-2673: Attempting to stop 'ora.blah.db' on 'enkdb01'
CRS-2673: Attempting to stop 'ora.colvin.db' on 'enkdb01'
CRS-2673: Attempting to stop 'ora.dbm01.db' on 'enkdb01'
CRS-2673: Attempting to stop 'ora.LISTENER.lsnr' on 'enkdb02'
CRS-2673: Attempting to stop 'ora.dbm01.andy.svc' on 'enkdb02'
CRS-2673: Attempting to stop 'ora.dbm01.martin.svc' on 'enkdb02'
CRS-2677: Stop of 'ora.LISTENER_SCAN1.lsnr' on 'enkdb02' succeeded
CRS-2673: Attempting to stop 'ora.scan1.vip' on 'enkdb02'
CRS-2677: Stop of 'ora.LISTENER.lsnr' on 'enkdb02' succeeded
CRS-2677: Stop of 'ora.oc4j' on 'enkdb01' succeeded
CRS-2677: Stop of 'ora.dbm01.andy.svc' on 'enkdb02' succeeded
CRS-2677: Stop of 'ora.dbm01.martin.svc' on 'enkdb02' succeeded
CRS-2673: Attempting to stop 'ora.enkdb02.vip' on 'enkdb02'
CRS-2673: Attempting to stop 'ora.DBFS_DG.dg' on 'enkdb02'
CRS-2673: Attempting to stop 'ora.blah.db' on 'enkdb02'
CRS-2673: Attempting to stop 'ora.colvin.db' on 'enkdb02'
CRS-2673: Attempting to stop 'ora.dbm01.db' on 'enkdb02'
CRS-2677: Stop of 'ora.registry.acfs' on 'enkdb01' succeeded
CRS-2677: Stop of 'ora.blah.db' on 'enkdb01' succeeded
CRS-2677: Stop of 'ora.scan1.vip' on 'enkdb02' succeeded
CRS-2677: Stop of 'ora.colvin.db' on 'enkdb01' succeeded
CRS-2677: Stop of 'ora.colvin.db' on 'enkdb02' succeeded
CRS-2677: Stop of 'ora.enkdb02.vip' on 'enkdb02' succeeded
CRS-2677: Stop of 'ora.blah.db' on 'enkdb02' succeeded
CRS-2677: Stop of 'ora.dbm01.db' on 'enkdb01' succeeded
CRS-2673: Attempting to stop 'ora.RECO.dg' on 'enkdb01'
CRS-2673: Attempting to stop 'ora.DATA.dg' on 'enkdb01'
CRS-2677: Stop of 'ora.RECO.dg' on 'enkdb01' succeeded
CRS-2677: Stop of 'ora.DATA.dg' on 'enkdb01' succeeded
CRS-2677: Stop of 'ora.dbm01.db' on 'enkdb02' succeeded
CRS-2673: Attempting to stop 'ora.RECO.dg' on 'enkdb02'
CRS-2673: Attempting to stop 'ora.DATA.dg' on 'enkdb02'
CRS-2677: Stop of 'ora.RECO.dg' on 'enkdb02' succeeded
CRS-2677: Stop of 'ora.DATA.dg' on 'enkdb02' succeeded
CRS-2677: Stop of 'ora.DBFS_DG.dg' on 'enkdb01' succeeded
CRS-2673: Attempting to stop 'ora.asm' on 'enkdb01'
CRS-2677: Stop of 'ora.asm' on 'enkdb01' succeeded
CRS-2677: Stop of 'ora.DBFS_DG.dg' on 'enkdb02' succeeded
CRS-2673: Attempting to stop 'ora.asm' on 'enkdb02'
CRS-2677: Stop of 'ora.asm' on 'enkdb02' succeeded
CRS-2673: Attempting to stop 'ora.ons' on 'enkdb02'
CRS-2677: Stop of 'ora.ons' on 'enkdb02' succeeded
CRS-2673: Attempting to stop 'ora.net1.network' on 'enkdb02'
CRS-2677: Stop of 'ora.net1.network' on 'enkdb02' succeeded
CRS-2792: Shutdown of Cluster Ready Services-managed resources on 'enkdb02' has completed
CRS-2673: Attempting to stop 'ora.ons' on 'enkdb01'
CRS-2677: Stop of 'ora.ons' on 'enkdb01' succeeded
CRS-2673: Attempting to stop 'ora.net1.network' on 'enkdb01'
CRS-2677: Stop of 'ora.net1.network' on 'enkdb01' succeeded
CRS-2792: Shutdown of Cluster Ready Services-managed resources on 'enkdb01' has completed
CRS-2677: Stop of 'ora.crsd' on 'enkdb02' succeeded
CRS-2673: Attempting to stop 'ora.ctssd' on 'enkdb02'
CRS-2673: Attempting to stop 'ora.evmd' on 'enkdb02'
CRS-2673: Attempting to stop 'ora.asm' on 'enkdb02'
CRS-2677: Stop of 'ora.crsd' on 'enkdb01' succeeded
CRS-2673: Attempting to stop 'ora.ctssd' on 'enkdb01'
CRS-2673: Attempting to stop 'ora.evmd' on 'enkdb01'
CRS-2673: Attempting to stop 'ora.asm' on 'enkdb01'
CRS-2677: Stop of 'ora.evmd' on 'enkdb01' succeeded
CRS-2677: Stop of 'ora.evmd' on 'enkdb02' succeeded
CRS-2677: Stop of 'ora.ctssd' on 'enkdb01' succeeded
CRS-2677: Stop of 'ora.ctssd' on 'enkdb02' succeeded
CRS-2677: Stop of 'ora.asm' on 'enkdb02' succeeded
CRS-2673: Attempting to stop 'ora.cluster_interconnect.haip' on 'enkdb02'
CRS-2677: Stop of 'ora.asm' on 'enkdb01' succeeded
CRS-2673: Attempting to stop 'ora.cluster_interconnect.haip' on 'enkdb01'
CRS-2677: Stop of 'ora.cluster_interconnect.haip' on 'enkdb01' succeeded
CRS-2673: Attempting to stop 'ora.cssd' on 'enkdb01'
CRS-2677: Stop of 'ora.cluster_interconnect.haip' on 'enkdb02' succeeded
CRS-2673: Attempting to stop 'ora.cssd' on 'enkdb02'
CRS-2677: Stop of 'ora.cssd' on 'enkdb01' succeeded
CRS-2673: Attempting to stop 'ora.diskmon' on 'enkdb01'
CRS-2677: Stop of 'ora.cssd' on 'enkdb02' succeeded
CRS-2673: Attempting to stop 'ora.diskmon' on 'enkdb02'
CRS-2677: Stop of 'ora.diskmon' on 'enkdb02' succeeded
CRS-2677: Stop of 'ora.diskmon' on 'enkdb01' succeeded

This command stops CRS resources on each of the nodes in the cluster, including the dbm01 database. To look in the alert log, we can see that the database received a "shutdown abort" command.  Once again, the third line tells us what we want to know:

Sun Apr 06 19:02:11 2014
ALTER SYSTEM SET service_names='SYS$SYS.SCHEDULER$_EVENT_QUEUE.DBM01' SCOPE=MEMORY SID='dbm011';
Shutting down instance (abort)
License high water mark = 9
USER (ospid: 51156): terminating the instance
Instance terminated by USER, pid = 51156
Sun Apr 06 19:02:16 2014
Instance shutdown complete

As it turns out, Oracle says that this is expected behavior. In MOS note #1274270.1, Oracle makes their case for crsctl issuing a shutdown abort when shutting down:

Before shutting down a cluster, it's best to utilize srvctl to stop database instances.  In order to shut down everything in a home, use the "srvctl stop home" command:

[enkdb01:oracle:dbm011] /home/oracle
> srvctl stop home -o /u01/app/oracle/product/11.2.0.4/dbhome_1 -s ~/stophome_11.2.0.4.txt -n enkdb01

The file ~/stophome_11.2.0.4.txt is used to designate all of the resources that were shut down by this command:

[enkdb01:oracle:dbm011] /home/oracle
> cat ~/stophome_11.2.0.4.txt
db-colvin
svc-ANDY
svc-soe
db-dbm01

From looking at this, we can see that the colvin and dbm01 databases were shut down along with the ANDY and soe services. When we want to start the resources up, change the above command from "srvctl stop home" to "srvctl start home"

[enkdb01:oracle:dbm011] /home/oracle
> srvctl start home -o /u01/app/oracle/product/11.2.0.4/dbhome_1 -s ~/stophome_11.2.0.4.txt -n enkdb01