Thinking Out Loud

November 12, 2017

opatchauto Hell

Filed under: 12c — mdinh @ 8:10 pm

I have been investigating new opatchauto apply for 12.1 RAC system.

Was overjoyed to see services relocated to instance2 when instance1 was being patched.

The joy became dismay to find relocated services on instance2 were stopped to perform datapatch.

I am definitely not an expert, but why shutdown services running on other instances?

What if services are manually relocated, would they still be shutdown?

From Oplan:

In-Place Patching: Apply Patch to Existing Oracle HomesIn this option, the patch will be applied directly to the specified Oracle Homes. 
This is the least time-consuming option. 
The procedures available for this option are outlined below.

    Rolling Mode: Apply Patch to Each Node In A Cluster Sequentially Resources running on each node in the cluster will be stopped, patched and then restarted, one at a time in sequence. 
      By patching only one node at a time, this approach ensures that multi-instance databases remain available during the patching process, but it will take longer to complete.

        Apply Patch In-Place using OPatch Auto Command in Rolling Mode:
            Advantages: No downtime while patching; fewer patching steps.
            Disadvantages: May be time consuming; less-than-optimal diagnosability of issues during patching; slower recovery from failures.
            Total number of steps required: 29
                During the full availability of services: 23
                During the partial availability of services: 6 

Step 2: Patch Apply Phase (Limited services will be available)

Instance orclcdb1 is running on node racnode-dc1-1 with online services DBA_TEST,testsvc11,testsvc12,testsvc13,testsvc14,testsvc15. Instance status: Open.

What does Oracle mean by limited? The services are shutdown and not restarted!

Update: services run on correct instance when restarted.

[oracle@racnode-dc1-1 ~]$ srvctl start service -d orclcdb
PRCD-1133 : Failed to start services for database
CRS-5702: Resource 'ora.orclcdb.testsvc26.svc' is already running on 'racnode-dc1-2'
CRS-5702: Resource 'ora.orclcdb.testsvc27.svc' is already running on 'racnode-dc1-2'
CRS-5702: Resource 'ora.orclcdb.testsvc28.svc' is already running on 'racnode-dc1-2'
CRS-5702: Resource 'ora.orclcdb.testsvc29.svc' is already running on 'racnode-dc1-2'

[oracle@racnode-dc1-1 ~]$ date; srvctl status database -d orclcdb -v
Sun Nov 12 21:17:52 CET 2017
Instance orclcdb1 is running on node racnode-dc1-1 with online services DBA_TEST,testsvc11,testsvc12,testsvc13,testsvc14,testsvc15. Instance status: Open.
Instance orclcdb2 is running on node racnode-dc1-2 with online services testsvc26,testsvc27,testsvc28,testsvc29. Instance status: Open.
[oracle@racnode-dc1-1 ~]$

[root@racnode-dc1-1 ~]# $GRID_HOME/OPatch/opatchauto apply /sf_OracleSoftware/12.1.0.2_PatchSet_Linux_x64/OCT2017PSU/26635880


OPatchauto session is initiated at Sun Nov 12 18:07:15 2017

System initialization log file is /u01/app/12.1.0.2/grid/cfgtoollogs/opatchautodb/systemconfig2017-11-12_06-08-14PM.log.

Session log file is /u01/app/12.1.0.2/grid/cfgtoollogs/opatchauto/opatchauto2017-11-12_06-09-00PM.log
The id for this session is YKRN


Executing OPatch prereq operations to verify patch applicability on home /u01/app/12.1.0.2/grid

Executing OPatch prereq operations to verify patch applicability on home /u01/app/oracle/12.1.0.2/db1
Patch applicability verified successfully on home /u01/app/oracle/12.1.0.2/db1

Patch applicability verified successfully on home /u01/app/12.1.0.2/grid


Verifying SQL patch applicability on home /u01/app/oracle/12.1.0.2/db1
SQL patch applicability verified successfully on home /u01/app/oracle/12.1.0.2/db1


Preparing to bring down database service on home /u01/app/oracle/12.1.0.2/db1
Successfully prepared home /u01/app/oracle/12.1.0.2/db1 to bring down database service


Bringing down CRS service on home /u01/app/12.1.0.2/grid
Prepatch operation log file location: /u01/app/12.1.0.2/grid/cfgtoollogs/crsconfig/crspatch_racnode-dc1-1_2017-11-12_06-20-39PM.log
CRS service brought down successfully on home /u01/app/12.1.0.2/grid


Performing prepatch operation on home /u01/app/oracle/12.1.0.2/db1
Perpatch operation completed successfully on home /u01/app/oracle/12.1.0.2/db1


Start applying binary patch on home /u01/app/oracle/12.1.0.2/db1
Binary patch applied successfully on home /u01/app/oracle/12.1.0.2/db1


Performing postpatch operation on home /u01/app/oracle/12.1.0.2/db1
Postpatch operation completed successfully on home /u01/app/oracle/12.1.0.2/db1


Start applying binary patch on home /u01/app/12.1.0.2/grid

Binary patch applied successfully on home /u01/app/12.1.0.2/grid


Starting CRS service on home /u01/app/12.1.0.2/grid
Postpatch operation log file location: /u01/app/12.1.0.2/grid/cfgtoollogs/crsconfig/crspatch_racnode-dc1-1_2017-11-12_07-20-43PM.log
CRS service started successfully on home /u01/app/12.1.0.2/grid


Preparing home /u01/app/oracle/12.1.0.2/db1 after database service restarted
Prepared home /u01/app/oracle/12.1.0.2/db1 successfully after database service restarted


Trying to apply SQL patch on home /u01/app/oracle/12.1.0.2/db1
SQL patch applied successfully on home /u01/app/oracle/12.1.0.2/db1

OPatchAuto successful.

--------------------------------Summary--------------------------------

Patching is completed successfully. Please find the summary as follows:

Host:racnode-dc1-1
RAC Home:/u01/app/oracle/12.1.0.2/db1
Summary:

==Following patches were SKIPPED:

Patch: /sf_OracleSoftware/12.1.0.2_PatchSet_Linux_x64/OCT2017PSU/26635880/21436941
Reason: This patch is not applicable to this specified target type - "rac_database"

Patch: /sf_OracleSoftware/12.1.0.2_PatchSet_Linux_x64/OCT2017PSU/26635880/26392164
Reason: This patch is not applicable to this specified target type - "rac_database"


==Following patches were SUCCESSFULLY applied:

Patch: /sf_OracleSoftware/12.1.0.2_PatchSet_Linux_x64/OCT2017PSU/26635880/26392192
Log: /u01/app/oracle/12.1.0.2/db1/cfgtoollogs/opatchauto/core/opatch/opatch2017-11-12_18-22-11PM_1.log

Patch: /sf_OracleSoftware/12.1.0.2_PatchSet_Linux_x64/OCT2017PSU/26635880/26717470
Log: /u01/app/oracle/12.1.0.2/db1/cfgtoollogs/opatchauto/core/opatch/opatch2017-11-12_18-22-11PM_1.log


Host:racnode-dc1-1
CRS Home:/u01/app/12.1.0.2/grid
Summary:

==Following patches were SUCCESSFULLY applied:

Patch: /sf_OracleSoftware/12.1.0.2_PatchSet_Linux_x64/OCT2017PSU/26635880/21436941
Log: /u01/app/12.1.0.2/grid/cfgtoollogs/opatchauto/core/opatch/opatch2017-11-12_18-46-41PM_1.log

Patch: /sf_OracleSoftware/12.1.0.2_PatchSet_Linux_x64/OCT2017PSU/26635880/26392164
Log: /u01/app/12.1.0.2/grid/cfgtoollogs/opatchauto/core/opatch/opatch2017-11-12_18-46-41PM_1.log

Patch: /sf_OracleSoftware/12.1.0.2_PatchSet_Linux_x64/OCT2017PSU/26635880/26392192
Log: /u01/app/12.1.0.2/grid/cfgtoollogs/opatchauto/core/opatch/opatch2017-11-12_18-46-41PM_1.log

Patch: /sf_OracleSoftware/12.1.0.2_PatchSet_Linux_x64/OCT2017PSU/26635880/26717470
Log: /u01/app/12.1.0.2/grid/cfgtoollogs/opatchauto/core/opatch/opatch2017-11-12_18-46-41PM_1.log

OPatchauto session completed at Sun Nov 12 19:34:26 2017
Time taken to complete the session 87 minutes, 11 seconds
[root@racnode-dc1-1 ~]#

[root@racnode-dc1-1 opatchauto]# grep -A8 “Executing command as” opatchauto2017-11-12_06-09-00PM.log


Executing command as oracle:
 /u01/app/12.1.0.2/grid/OPatch/opatchauto  apply /sf_OracleSoftware/12.1.0.2_PatchSet_Linux_x64/OCT2017PSU/26635880 -oh /u01/app/12.1.0.2/grid -target_type cluster -binary -invPtrLoc /u01/app/12.1.0.2/grid/oraInst.loc -jre /u01/app/12.1.0.2/grid/OPatch/jre -persistresult /u01/app/12.1.0.2/grid/OPatch/auto/dbsessioninfo/sessionresult_analyze_racnode-dc1-1_crs.ser -analyze -online
2017-11-12 18:09:24,734 INFO  [53] com.oracle.glcm.patch.auto.db.integration.controller.action.OPatchAutoBinaryAction -
Executing command as oracle:
 /u01/app/oracle/12.1.0.2/db1/OPatch/opatchauto  apply /sf_OracleSoftware/12.1.0.2_PatchSet_Linux_x64/OCT2017PSU/26635880 -oh /u01/app/oracle/12.1.0.2/db1 -target_type rac_database -binary -invPtrLoc /u01/app/12.1.0.2/grid/oraInst.loc -jre /u01/app/12.1.0.2/grid/OPatch/jre -persistresult /u01/app/oracle/12.1.0.2/db1/OPatch/auto/dbsessioninfo/sessionresult_analyze_racnode-dc1-1_rac.ser -analyze -online
2017-11-12 18:12:45,263 INFO  [53] com.oracle.glcm.patch.auto.db.integration.controller.action.OPatchAutoBinaryAction - Opatchcore binary return code=0
2017-11-12 18:12:45,265 INFO  [53] com.oracle.glcm.patch.auto.db.integration.controller.action.OPatchAutoBinaryAction - Opatchcore binary output=Oracle Home : /u01/app/oracle/12.1.0.2/db1

OPatchAuto binary patching Tool
Copyright (c)2014, Oracle Corporation. All rights reserved.

OPatchauto Version : 13.9.3.0.0
--
Executing command as oracle:
 /bin/sh -c 'cd /u01/app/oracle/12.1.0.2/db1; ORACLE_HOME=/u01/app/oracle/12.1.0.2/db1 ORACLE_SID=orclcdb1 /u01/app/oracle/12.1.0.2/db1/OPatch/datapatch -prereq -verbose'
2017-11-12 18:19:52,146 INFO  [85] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - COMMAND Looks like this: /bin/sh -c 'cd /u01/app/oracle/12.1.0.2/db1; ORACLE_HOME=/u01/app/oracle/12.1.0.2/db1 ORACLE_SID=orclcdb1 /u01/app/oracle/12.1.0.2/db1/OPatch/datapatch -prereq -verbose'
2017-11-12 18:20:20,415 INFO  [85] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - status: 0
2017-11-12 18:20:20,415 INFO  [85] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Successfully executed the above command.

2017-11-12 18:20:20,415 INFO  [85] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Output from the command:
2017-11-12 18:20:20,415 INFO  [85] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - SQL Patching tool version 12.1.0.2.0 Production on Sun Nov 12 18:19:52 2017
Copyright (c) 2012, 2017, Oracle.  All rights reserved.
--
Executing command as oracle:
 /bin/sh -c 'echo "DECLARE l_count NUMBER(4) :=0; BEGIN SELECT count(*) INTO l_count FROM CDB_PDBS; IF l_count >1 then EXECUTE IMMEDIATE '\''alter pluggable database ALL SAVE STATE'\''; END IF; commit; END;" > /tmp/OraDB12Home1_oracle_orclcdb1.sql'
2017-11-12 18:20:23,665 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - COMMAND Looks like this: /bin/sh -c 'echo "DECLARE l_count NUMBER(4) :=0; BEGIN SELECT count(*) INTO l_count FROM CDB_PDBS; IF l_count >1 then EXECUTE IMMEDIATE '\''alter pluggable database ALL SAVE STATE'\''; END IF; commit; END;" > /tmp/OraDB12Home1_oracle_orclcdb1.sql'
2017-11-12 18:20:23,771 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - status: 0
2017-11-12 18:20:23,771 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Successfully executed the above command.

2017-11-12 18:20:23,771 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Output from the command:
2017-11-12 18:20:23,771 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor -
2017-11-12 18:20:23,771 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Command executed successfully.
--
Executing command as oracle:
 /bin/sh -c 'echo "/" >> /tmp/OraDB12Home1_oracle_orclcdb1.sql'
2017-11-12 18:20:23,772 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - COMMAND Looks like this: /bin/sh -c 'echo "/" >> /tmp/OraDB12Home1_oracle_orclcdb1.sql'
2017-11-12 18:20:23,873 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - status: 0
2017-11-12 18:20:23,873 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Successfully executed the above command.

2017-11-12 18:20:23,873 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Output from the command:
2017-11-12 18:20:23,873 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor -
2017-11-12 18:20:23,873 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Command executed successfully.
--
Executing command as oracle:
 /bin/sh -c 'echo "EXIT;" >> /tmp/OraDB12Home1_oracle_orclcdb1.sql'
2017-11-12 18:20:23,873 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - COMMAND Looks like this: /bin/sh -c 'echo "EXIT;" >> /tmp/OraDB12Home1_oracle_orclcdb1.sql'
2017-11-12 18:20:23,958 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - status: 0
2017-11-12 18:20:23,958 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Successfully executed the above command.

2017-11-12 18:20:23,958 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Output from the command:
2017-11-12 18:20:23,958 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor -
2017-11-12 18:20:23,958 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Command executed successfully.
--
Executing command as oracle:
 /bin/sh -c 'cd /u01/app/oracle/12.1.0.2/db1 ; ORACLE_HOME=/u01/app/oracle/12.1.0.2/db1 ORACLE_SID=orclcdb1 /u01/app/oracle/12.1.0.2/db1/bin/sqlplus / as sysdba @/tmp/OraDB12Home1_oracle_orclcdb1.sql'
2017-11-12 18:20:23,958 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - COMMAND Looks like this: /bin/sh -c 'cd /u01/app/oracle/12.1.0.2/db1 ; ORACLE_HOME=/u01/app/oracle/12.1.0.2/db1 ORACLE_SID=orclcdb1 /u01/app/oracle/12.1.0.2/db1/bin/sqlplus / as sysdba @/tmp/OraDB12Home1_oracle_orclcdb1.sql'
2017-11-12 18:20:24,268 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - status: 0
2017-11-12 18:20:24,268 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Successfully executed the above command.

2017-11-12 18:20:24,268 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Output from the command:
2017-11-12 18:20:24,268 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor -
SQL*Plus: Release 12.1.0.2.0 Production on Sun Nov 12 18:20:24 2017
--

Executing command as oracle:
 /bin/sh -c 'ORACLE_HOME=/u01/app/oracle/12.1.0.2/db1 /u01/app/oracle/12.1.0.2/db1/bin/srvctl relocate service -d orclcdb -s DBA_TEST -i orclcdb1 -t orclcdb2'
2017-11-12 18:20:24,269 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - COMMAND Looks like this: /bin/sh -c 'ORACLE_HOME=/u01/app/oracle/12.1.0.2/db1 /u01/app/oracle/12.1.0.2/db1/bin/srvctl relocate service -d orclcdb -s DBA_TEST -i orclcdb1 -t orclcdb2'
2017-11-12 18:20:26,771 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - status: 0
2017-11-12 18:20:26,771 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Successfully executed the above command.

2017-11-12 18:20:26,771 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Output from the command:
2017-11-12 18:20:26,809 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor -
2017-11-12 18:20:26,809 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Command executed successfully.
--
Executing command as oracle:
 /bin/sh -c 'ORACLE_HOME=/u01/app/oracle/12.1.0.2/db1 /u01/app/oracle/12.1.0.2/db1/bin/srvctl relocate service -d orclcdb -s testsvc11 -i orclcdb1 -t orclcdb2'
2017-11-12 18:20:26,809 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - COMMAND Looks like this: /bin/sh -c 'ORACLE_HOME=/u01/app/oracle/12.1.0.2/db1 /u01/app/oracle/12.1.0.2/db1/bin/srvctl relocate service -d orclcdb -s testsvc11 -i orclcdb1 -t orclcdb2'
2017-11-12 18:20:28,931 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - status: 0
2017-11-12 18:20:28,932 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Successfully executed the above command.

2017-11-12 18:20:28,932 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Output from the command:
2017-11-12 18:20:28,932 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor -
2017-11-12 18:20:28,932 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Command executed successfully.
--
Executing command as oracle:
 /bin/sh -c 'ORACLE_HOME=/u01/app/oracle/12.1.0.2/db1 /u01/app/oracle/12.1.0.2/db1/bin/srvctl relocate service -d orclcdb -s testsvc12 -i orclcdb1 -t orclcdb2'
2017-11-12 18:20:28,932 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - COMMAND Looks like this: /bin/sh -c 'ORACLE_HOME=/u01/app/oracle/12.1.0.2/db1 /u01/app/oracle/12.1.0.2/db1/bin/srvctl relocate service -d orclcdb -s testsvc12 -i orclcdb1 -t orclcdb2'
2017-11-12 18:20:31,027 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - status: 0
2017-11-12 18:20:31,027 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Successfully executed the above command.

2017-11-12 18:20:31,027 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Output from the command:
2017-11-12 18:20:31,027 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor -
2017-11-12 18:20:31,027 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Command executed successfully.
--
Executing command as oracle:
 /bin/sh -c 'ORACLE_HOME=/u01/app/oracle/12.1.0.2/db1 /u01/app/oracle/12.1.0.2/db1/bin/srvctl relocate service -d orclcdb -s testsvc13 -i orclcdb1 -t orclcdb2'
2017-11-12 18:20:31,027 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - COMMAND Looks like this: /bin/sh -c 'ORACLE_HOME=/u01/app/oracle/12.1.0.2/db1 /u01/app/oracle/12.1.0.2/db1/bin/srvctl relocate service -d orclcdb -s testsvc13 -i orclcdb1 -t orclcdb2'
2017-11-12 18:20:33,346 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - status: 0
2017-11-12 18:20:33,346 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Successfully executed the above command.

2017-11-12 18:20:33,346 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Output from the command:
2017-11-12 18:20:33,346 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor -
2017-11-12 18:20:33,346 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Command executed successfully.
--
Executing command as oracle:
 /bin/sh -c 'ORACLE_HOME=/u01/app/oracle/12.1.0.2/db1 /u01/app/oracle/12.1.0.2/db1/bin/srvctl relocate service -d orclcdb -s testsvc14 -i orclcdb1 -t orclcdb2'
2017-11-12 18:20:33,346 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - COMMAND Looks like this: /bin/sh -c 'ORACLE_HOME=/u01/app/oracle/12.1.0.2/db1 /u01/app/oracle/12.1.0.2/db1/bin/srvctl relocate service -d orclcdb -s testsvc14 -i orclcdb1 -t orclcdb2'
2017-11-12 18:20:35,327 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - status: 0
2017-11-12 18:20:35,328 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Successfully executed the above command.

2017-11-12 18:20:35,328 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Output from the command:
2017-11-12 18:20:35,328 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor -
2017-11-12 18:20:35,328 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Command executed successfully.
--
Executing command as oracle:
 /bin/sh -c 'ORACLE_HOME=/u01/app/oracle/12.1.0.2/db1 /u01/app/oracle/12.1.0.2/db1/bin/srvctl relocate service -d orclcdb -s testsvc15 -i orclcdb1 -t orclcdb2'
2017-11-12 18:20:35,328 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - COMMAND Looks like this: /bin/sh -c 'ORACLE_HOME=/u01/app/oracle/12.1.0.2/db1 /u01/app/oracle/12.1.0.2/db1/bin/srvctl relocate service -d orclcdb -s testsvc15 -i orclcdb1 -t orclcdb2'
2017-11-12 18:20:37,885 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - status: 0
2017-11-12 18:20:37,885 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Successfully executed the above command.

2017-11-12 18:20:37,885 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Output from the command:
2017-11-12 18:20:37,885 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor -
2017-11-12 18:20:37,885 INFO  [125] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Command executed successfully.

--
Executing command as root:
 /u01/app/12.1.0.2/grid/perl/bin/perl -I/u01/app/12.1.0.2/grid/perl/lib -I/u01/app/12.1.0.2/grid/OPatch/auto/dbtmp/bootstrap_racnode-dc1-1/patchwork/crs/install /u01/app/12.1.0.2/grid/OPatch/auto/dbtmp/bootstrap_racnode-dc1-1/patchwork/crs/install/rootcrs.pl -prepatch
2017-11-12 18:20:38,384 INFO  [206] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - COMMAND Looks like this: /u01/app/12.1.0.2/grid/perl/bin/perl -I/u01/app/12.1.0.2/grid/perl/lib -I/u01/app/12.1.0.2/grid/OPatch/auto/dbtmp/bootstrap_racnode-dc1-1/patchwork/crs/install /u01/app/12.1.0.2/grid/OPatch/auto/dbtmp/bootstrap_racnode-dc1-1/patchwork/crs/install/rootcrs.pl -prepatch
2017-11-12 18:22:05,710 INFO  [206] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - status: 0
2017-11-12 18:22:05,711 INFO  [206] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Successfully executed the above command.

2017-11-12 18:22:05,711 INFO  [206] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Output from the command:
2017-11-12 18:22:05,711 INFO  [206] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Using configuration parameter file: /u01/app/12.1.0.2/grid/OPatch/auto/dbtmp/bootstrap_racnode-dc1-1/patchwork/crs/install/crsconfig_params
Oracle Clusterware active version on the cluster is [12.1.0.2.0]. The cluster upgrade state is [NORMAL]. The cluster active patch level is [0].
--
Executing command as oracle:
 /sf_OracleSoftware/12.1.0.2_PatchSet_Linux_x64/OCT2017PSU/26635880/26392192/custom/scripts/prepatch.sh -dbhome /u01/app/oracle/12.1.0.2/db1
2017-11-12 18:22:05,758 INFO  [224] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - COMMAND Looks like this: /sf_OracleSoftware/12.1.0.2_PatchSet_Linux_x64/OCT2017PSU/26635880/26392192/custom/scripts/prepatch.sh -dbhome /u01/app/oracle/12.1.0.2/db1
2017-11-12 18:22:05,793 INFO  [224] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - status: 0
2017-11-12 18:22:05,793 INFO  [224] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Successfully executed the above command.

2017-11-12 18:22:05,793 INFO  [224] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Output from the command:
2017-11-12 18:22:05,793 INFO  [224] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - /sf_OracleSoftware/12.1.0.2_PatchSet_Linux_x64/OCT2017PSU/26635880/26392192/custom/scripts/prepatch.sh completed successfully.

--
Executing command as oracle:
 /u01/app/oracle/12.1.0.2/db1/OPatch/opatchauto  apply /sf_OracleSoftware/12.1.0.2_PatchSet_Linux_x64/OCT2017PSU/26635880 -oh /u01/app/oracle/12.1.0.2/db1 -target_type rac_database -binary -invPtrLoc /u01/app/12.1.0.2/grid/oraInst.loc -jre /u01/app/12.1.0.2/grid/OPatch/jre -persistresult /u01/app/oracle/12.1.0.2/db1/OPatch/auto/dbsessioninfo/sessionresult_racnode-dc1-1_rac.ser -analyzedresult /u01/app/oracle/12.1.0.2/db1/OPatch/auto/dbsessioninfo/sessionresult_analyze_racnode-dc1-1_rac.ser
2017-11-12 18:46:34,790 INFO  [238] com.oracle.glcm.patch.auto.db.integration.controller.action.OPatchAutoBinaryAction - Opatchcore binary return code=0
2017-11-12 18:46:34,801 INFO  [238] com.oracle.glcm.patch.auto.db.integration.controller.action.OPatchAutoBinaryAction - Opatchcore binary output=Oracle Home : /u01/app/oracle/12.1.0.2/db1

OPatchAuto binary patching Tool
Copyright (c)2014, Oracle Corporation. All rights reserved.

OPatchauto Version : 13.9.3.0.0
--
Executing command as oracle:
 /sf_OracleSoftware/12.1.0.2_PatchSet_Linux_x64/OCT2017PSU/26635880/26392192/custom/scripts/postpatch.sh -dbhome /u01/app/oracle/12.1.0.2/db1
2017-11-12 18:46:35,048 INFO  [281] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - COMMAND Looks like this: /sf_OracleSoftware/12.1.0.2_PatchSet_Linux_x64/OCT2017PSU/26635880/26392192/custom/scripts/postpatch.sh -dbhome /u01/app/oracle/12.1.0.2/db1
2017-11-12 18:46:35,337 INFO  [281] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - status: 0
2017-11-12 18:46:35,337 INFO  [281] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Successfully executed the above command.

2017-11-12 18:46:35,337 INFO  [281] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Output from the command:
2017-11-12 18:46:35,337 INFO  [281] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Reading /u01/app/oracle/12.1.0.2/db1/install/params.ora..
Reading /u01/app/oracle/12.1.0.2/db1/install/params.ora..
--
Executing command as oracle:
 /u01/app/12.1.0.2/grid/OPatch/opatchauto  apply /sf_OracleSoftware/12.1.0.2_PatchSet_Linux_x64/OCT2017PSU/26635880 -oh /u01/app/12.1.0.2/grid -target_type cluster -binary -invPtrLoc /u01/app/12.1.0.2/grid/oraInst.loc -jre /u01/app/12.1.0.2/grid/OPatch/jre -persistresult /u01/app/12.1.0.2/grid/OPatch/auto/dbsessioninfo/sessionresult_racnode-dc1-1_crs.ser -analyzedresult /u01/app/12.1.0.2/grid/OPatch/auto/dbsessioninfo/sessionresult_analyze_racnode-dc1-1_crs.ser
2017-11-12 19:20:43,366 INFO  [361] com.oracle.glcm.patch.auto.db.integration.controller.action.OPatchAutoBinaryAction - Opatchcore binary return code=0
2017-11-12 19:20:43,369 INFO  [361] com.oracle.glcm.patch.auto.db.integration.controller.action.OPatchAutoBinaryAction - Opatchcore binary output=Oracle Home : /u01/app/12.1.0.2/grid

OPatchAuto binary patching Tool
Copyright (c)2014, Oracle Corporation. All rights reserved.

OPatchauto Version : 13.9.3.0.0
--
Executing command as root:
 /u01/app/12.1.0.2/grid/rdbms/install/rootadd_rdbms.sh
2017-11-12 19:20:43,522 INFO  [414] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - COMMAND Looks like this: /u01/app/12.1.0.2/grid/rdbms/install/rootadd_rdbms.sh
2017-11-12 19:20:43,574 INFO  [414] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - status: 0
2017-11-12 19:20:43,574 INFO  [414] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Successfully executed the above command.

2017-11-12 19:20:43,574 INFO  [414] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Output from the command:
2017-11-12 19:20:43,574 INFO  [414] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor -
2017-11-12 19:20:43,574 INFO  [414] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Command executed successfully.
--
Executing command as root:
 /u01/app/12.1.0.2/grid/perl/bin/perl -I/u01/app/12.1.0.2/grid/perl/lib -I/u01/app/12.1.0.2/grid/OPatch/auto/dbtmp/bootstrap_racnode-dc1-1/patchwork/crs/install /u01/app/12.1.0.2/grid/OPatch/auto/dbtmp/bootstrap_racnode-dc1-1/patchwork/crs/install/rootcrs.pl -postpatch
2017-11-12 19:20:43,574 INFO  [414] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - COMMAND Looks like this: /u01/app/12.1.0.2/grid/perl/bin/perl -I/u01/app/12.1.0.2/grid/perl/lib -I/u01/app/12.1.0.2/grid/OPatch/auto/dbtmp/bootstrap_racnode-dc1-1/patchwork/crs/install /u01/app/12.1.0.2/grid/OPatch/auto/dbtmp/bootstrap_racnode-dc1-1/patchwork/crs/install/rootcrs.pl -postpatch
2017-11-12 19:33:19,090 INFO  [414] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - status: 0
2017-11-12 19:33:19,097 INFO  [414] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Successfully executed the above command.

2017-11-12 19:33:19,098 INFO  [414] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Output from the command:
2017-11-12 19:33:19,098 INFO  [414] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Using configuration parameter file: /u01/app/12.1.0.2/grid/OPatch/auto/dbtmp/bootstrap_racnode-dc1-1/patchwork/crs/install/crsconfig_params
2017/11/12 19:20:51 CLSRSC-4015: Performing install or upgrade action for Oracle Trace File Analyzer (TFA) Collector.
--

Executing command as oracle:
 /bin/sh -c 'ORACLE_HOME=/u01/app/oracle/12.1.0.2/db1 /u01/app/oracle/12.1.0.2/db1/bin/srvctl stop service -d orclcdb -s DBA_TEST -i orclcdb2'
2017-11-12 19:33:19,393 INFO  [454] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - COMMAND Looks like this: /bin/sh -c 'ORACLE_HOME=/u01/app/oracle/12.1.0.2/db1 /u01/app/oracle/12.1.0.2/db1/bin/srvctl stop service -d orclcdb -s DBA_TEST -i orclcdb2'
2017-11-12 19:33:20,976 INFO  [454] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - status: 0
2017-11-12 19:33:20,977 INFO  [454] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Successfully executed the above command.

2017-11-12 19:33:20,980 INFO  [454] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Output from the command:
2017-11-12 19:33:20,980 INFO  [454] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor -
2017-11-12 19:33:20,980 INFO  [454] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Command executed successfully.
--
Executing command as oracle:
 /bin/sh -c 'ORACLE_HOME=/u01/app/oracle/12.1.0.2/db1 /u01/app/oracle/12.1.0.2/db1/bin/srvctl stop service -d orclcdb -s testsvc11 -i orclcdb2'
2017-11-12 19:33:20,980 INFO  [454] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - COMMAND Looks like this: /bin/sh -c 'ORACLE_HOME=/u01/app/oracle/12.1.0.2/db1 /u01/app/oracle/12.1.0.2/db1/bin/srvctl stop service -d orclcdb -s testsvc11 -i orclcdb2'
2017-11-12 19:33:22,262 INFO  [454] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - status: 0
2017-11-12 19:33:22,262 INFO  [454] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Successfully executed the above command.

2017-11-12 19:33:22,262 INFO  [454] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Output from the command:
2017-11-12 19:33:22,263 INFO  [454] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor -
2017-11-12 19:33:22,263 INFO  [454] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Command executed successfully.
--
Executing command as oracle:
 /bin/sh -c 'ORACLE_HOME=/u01/app/oracle/12.1.0.2/db1 /u01/app/oracle/12.1.0.2/db1/bin/srvctl stop service -d orclcdb -s testsvc12 -i orclcdb2'
2017-11-12 19:33:22,263 INFO  [454] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - COMMAND Looks like this: /bin/sh -c 'ORACLE_HOME=/u01/app/oracle/12.1.0.2/db1 /u01/app/oracle/12.1.0.2/db1/bin/srvctl stop service -d orclcdb -s testsvc12 -i orclcdb2'
2017-11-12 19:33:23,539 INFO  [454] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - status: 0
2017-11-12 19:33:23,539 INFO  [454] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Successfully executed the above command.

2017-11-12 19:33:23,539 INFO  [454] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Output from the command:
2017-11-12 19:33:23,539 INFO  [454] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor -
2017-11-12 19:33:23,540 INFO  [454] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Command executed successfully.
--
Executing command as oracle:
 /bin/sh -c 'ORACLE_HOME=/u01/app/oracle/12.1.0.2/db1 /u01/app/oracle/12.1.0.2/db1/bin/srvctl stop service -d orclcdb -s testsvc13 -i orclcdb2'
2017-11-12 19:33:23,540 INFO  [454] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - COMMAND Looks like this: /bin/sh -c 'ORACLE_HOME=/u01/app/oracle/12.1.0.2/db1 /u01/app/oracle/12.1.0.2/db1/bin/srvctl stop service -d orclcdb -s testsvc13 -i orclcdb2'
2017-11-12 19:33:24,764 INFO  [454] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - status: 0
2017-11-12 19:33:24,764 INFO  [454] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Successfully executed the above command.

2017-11-12 19:33:24,764 INFO  [454] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Output from the command:
2017-11-12 19:33:24,764 INFO  [454] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor -
2017-11-12 19:33:24,764 INFO  [454] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Command executed successfully.
--
Executing command as oracle:
 /bin/sh -c 'ORACLE_HOME=/u01/app/oracle/12.1.0.2/db1 /u01/app/oracle/12.1.0.2/db1/bin/srvctl stop service -d orclcdb -s testsvc14 -i orclcdb2'
2017-11-12 19:33:24,764 INFO  [454] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - COMMAND Looks like this: /bin/sh -c 'ORACLE_HOME=/u01/app/oracle/12.1.0.2/db1 /u01/app/oracle/12.1.0.2/db1/bin/srvctl stop service -d orclcdb -s testsvc14 -i orclcdb2'
2017-11-12 19:33:26,003 INFO  [454] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - status: 0
2017-11-12 19:33:26,003 INFO  [454] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Successfully executed the above command.

2017-11-12 19:33:26,003 INFO  [454] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Output from the command:
2017-11-12 19:33:26,003 INFO  [454] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor -
2017-11-12 19:33:26,003 INFO  [454] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Command executed successfully.
--
Executing command as oracle:
 /bin/sh -c 'ORACLE_HOME=/u01/app/oracle/12.1.0.2/db1 /u01/app/oracle/12.1.0.2/db1/bin/srvctl stop service -d orclcdb -s testsvc15 -i orclcdb2'
2017-11-12 19:33:26,004 INFO  [454] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - COMMAND Looks like this: /bin/sh -c 'ORACLE_HOME=/u01/app/oracle/12.1.0.2/db1 /u01/app/oracle/12.1.0.2/db1/bin/srvctl stop service -d orclcdb -s testsvc15 -i orclcdb2'
2017-11-12 19:33:27,227 INFO  [454] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - status: 0
2017-11-12 19:33:27,228 INFO  [454] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Successfully executed the above command.

2017-11-12 19:33:27,228 INFO  [454] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Output from the command:
2017-11-12 19:33:27,228 INFO  [454] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor -
2017-11-12 19:33:27,228 INFO  [454] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Command executed successfully.

--
Executing command as oracle:
 /bin/sh -c 'cd /u01/app/oracle/12.1.0.2/db1;ORACLE_HOME=/u01/app/oracle/12.1.0.2/db1 ORACLE_SID=orclcdb1 /u01/app/oracle/12.1.0.2/db1/OPatch/datapatch -verbose'
2017-11-12 19:33:28,659 INFO  [524] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - COMMAND Looks like this: /bin/sh -c 'cd /u01/app/oracle/12.1.0.2/db1;ORACLE_HOME=/u01/app/oracle/12.1.0.2/db1 ORACLE_SID=orclcdb1 /u01/app/oracle/12.1.0.2/db1/OPatch/datapatch -verbose'
2017-11-12 19:34:26,362 INFO  [524] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - status: 0
2017-11-12 19:34:26,362 INFO  [524] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Successfully executed the above command.

2017-11-12 19:34:26,362 INFO  [524] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - Output from the command:
2017-11-12 19:34:26,362 INFO  [524] com.oracle.glcm.patch.auto.db.product.executor.PatchingStepExecutor - SQL Patching tool version 12.1.0.2.0 Production on Sun Nov 12 19:33:29 2017
Copyright (c) 2012, 2017, Oracle.  All rights reserved.
[root@racnode-dc1-1 opatchauto]#
Advertisements

Leave a Comment »

No comments yet.

RSS feed for comments on this post. TrackBack URI

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s

Blog at WordPress.com.

%d bloggers like this: