Monday, December 22, 2014

Data Guard and Oracle Restart, aka relink always !!!

During my early years with PC I love to play "Leisure Suit Larry" (especially part 1 to 3 which has running on CGA or Hercules graphics card). Author of this games, Al Lowe had a good sense of humor and every time you failed your mission or stuck in a place - there was an pop up on the screen "Al says: save early, save often". After today fight with Oracle I should remember a next saying - "Relink after, relink always".

Let me explain what what happen today.

There used to be old Oracle bug in 11.2g which I described here. Basically Oracle Restart was not aware of role changes and could open a database in wrong mode after role switch. I created a workaround for it but I was really waiting for a patch. During a UKOUG 2014 I was speaking with Oracle Data Guard Product Manager - Larry Carpenter - and I learned that patch is ready. I asked @UweHesse for details and I got my numbers back - patch 15986647 and it is included in latest PSU 11.2.0.4.4.

After I got this information I was happy - I just applied this PSU last week, so let's test it.

The first run looked OK - after switchover Oracle Restart displayed proper role and start-up option on new primary
agent/ohasd/oraagent_grid/oraagent_grid.log
2014-12-22 09:02:36.511: [    AGFW][2057]{0:0:44372} Agent received the message: RESOURCE_MODIFY_ATTR[ora.apppre11.db 1 1] ID 4355:617901
2014-12-22 09:02:36.513: [ora.apppre11.db][9207]{0:0:44372} [res_attr_modified] clsn_agent::modify {
2014-12-22 09:02:36.513: [ora.apppre11.db][9207]{0:0:44372} [res_attr_modified] clsn_agent::modify }
2014-12-22 09:02:36.513: [    AGFW][9207]{0:0:44372} Command: res_attr_modified for resource: ora.apppre11.db 1 1 completed with status: SUCCESS
2014-12-22 09:02:36.516: [    AGFW][2057]{0:0:44372} Attribute: ROLE for resource ora.apppre11.db modified to: PRIMARY
2014-12-22 09:02:36.516: [    AGFW][2057]{0:0:44372} Attribute: USR_ORA_OPEN_MODE for resource ora.apppre11.db modified to: open
2014-12-22 09:02:36.516: [    AGFW][2057]{0:0:44372}  config version updated to : 69 for ora.apppre11.db 1 1
2014-12-22 09:02:36.516: [    AGFW][2057]{0:0:44372} Agent sending last reply for: RESOURCE_MODIFY_ATTR[ora.apppre11.db 1 1] ID 4355:617901
2014-12-22 09:02:36.663: [    AGFW][2057]{0:0:44374} Agent received the message: RESOURCE_MODIFY_ATTR[ora.apppre11.apppre_adf.svc 1 1] ID 4355:617914
but only proper role on the new standby.
agent/ohasd/oraagent_grid/oraagent_grid.log

2014-12-22 09:03:10.420: [    AGFW][2057]{0:0:11369} Agent received the message: RESOURCE_MODIFY_ATTR[ora.apppre21.db 1 1] ID 4355:189787
2014-12-22 09:03:10.423: [ora.apppre21.db][2412]{0:0:11369} [res_attr_modified] clsn_agent::modify {
2014-12-22 09:03:10.424: [ora.apppre21.db][2412]{0:0:11369} [res_attr_modified] clsn_agent::modify }
2014-12-22 09:03:10.424: [    AGFW][2412]{0:0:11369} Command: res_attr_modified for resource: ora.apppre21.db 1 1 completed with status: SUCCESS
2014-12-22 09:03:10.424: [    AGFW][2057]{0:0:11369} Attribute: ROLE for resource ora.apppre21.db modified to: PHYSICAL_STANDBY
2014-12-22 09:03:10.424: [    AGFW][2057]{0:0:11369}  config version updated to : 142 for ora.apppre21.db 1 1
2014-12-22 09:03:10.424: [    AGFW][2057]{0:0:11369} Agent sending last reply for: RESOURCE_MODIFY_ATTR[ora.apppre21.db 1 1] ID 4355:189787
Start up option was still open instead of mount. Hmmm, I was sure that both nodes are same but again I reconfigure Data Guard Broker and Oracle Restart - no change - issue was resolved on the one server only.  Then I decided to double check if I have this PSU installed, and I found out that everything was in order in terms of PSU.
-bash-3.2$ /u01/app/oracle/product/11.2.0/dbhome_1/OPatch/opatch lsinventory
Oracle Interim Patch Installer version 11.2.0.3.6
Copyright (c) 2013, Oracle Corporation.  All rights reserved.


Oracle Home       : /u01/app/oracle/product/11.2.0/dbhome_1
Central Inventory : /u01/app/oraInventory
   from           : /u01/app/oracle/product/11.2.0/dbhome_1/oraInst.loc
OPatch version    : 11.2.0.3.6
OUI version       : 11.2.0.4.0
Log file location : /u01/app/oracle/product/11.2.0/dbhome_1/cfgtoollogs/opatch/opatch2014-12-22_15-08-59PM_1.log

Lsinventory Output file location : /u01/app/oracle/product/11.2.0/dbhome_1/cfgtoollogs/opatch/lsinv/lsinventory2014-12-22_15-08-59PM.txt

--------------------------------------------------------------------------------
Installed Top-level Products (1):

Oracle Database 11g                                                  11.2.0.4.0
There are 1 product(s) installed in this Oracle Home.


Interim patches (3) :

Patch  18235390     : applied on Mon Dec 22 14:54:02 GMT 2014
Unique Patch ID:  18349043
   Created on 4 Dec 2014, 18:50:09 hrs PST8PDT
   Bugs fixed:
     18235390

Patch  19121549     : applied on Mon Nov 17 14:06:54 GMT 2014
Unique Patch ID:  18060349
Patch description:  "OCW Patch Set Update : 11.2.0.4.4 (19121549)"
   Created on 7 Oct 2014, 03:38:04 hrs PST8PDT
   Bugs fixed:
     18328800, 18691572, 14525998, 18187697, 18348155, 17516024, 17387214
     17750548, 17617807, 17551223, 14671408, 14207615, 18272135, 18180541
     17292250, 17378618, 17500165, 18875012, 18464784, 17065496, 18848125
     13991403, 17955615, 14693336, 17273020, 17238586, 17089344, 17405605
     17531342, 17155238, 17159489, 18053580, 16543190, 17039197, 16317771
     17947785, 10052729, 16281493, 18346135, 17481314, 18199185, 18399991
     18024089, 18428146, 18352845, 18352846, 17391726, 18414137, 17001914
     17927970, 14378120, 16346413, 17305100, 15832129, 15986647, 16901346
     18068871, 17985714, 18536826, 16206997, 18752378, 16876500, 16429265
     18343490, 18336452, 16613232, 17273003, 19276791, 12928658, 18226143
     17172091, 18229842, 18053631, 16867761, 18231837, 15869775, 17483479
     18729166, 17405302, 15920201, 18709496

Patch  19121551     : applied on Mon Nov 17 14:05:34 GMT 2014
Unique Patch ID:  17971200
Patch description:  "Database Patch Set Update : 11.2.0.4.4 (19121551)"
   Created on 9 Oct 2014, 13:06:55 hrs PST8PDT
Sub-patch  18522509; "Database Patch Set Update : 11.2.0.4.3 (18522509)"
Sub-patch  18031668; "Database Patch Set Update : 11.2.0.4.2 (18031668)"
Sub-patch  17478514; "Database Patch Set Update : 11.2.0.4.1 (17478514)"
   Bugs fixed:
     16929165, 16220077, 17235750, 17468141, 18191164, 17006183, 16315398
     17501491, 13955826, 17288409, 12905058, 17446237, 17375354, 16992075
     16855292, 17050888, 17546973, 18554871, 17726838, 17614134, 9756271
     18673325, 17227277, 17232014, 13853126, 17545847, 17390160, 18096714
     12747740, 17016369, 17786518, 19271443, 10136473, 16785708, 17311728
     18018515, 16268425, 17610798, 18280813, 17082359, 17783588, 14245531
     18094246, 13866822, 17477958, 16943711, 18673304, 18031668, 19463897
     19463893, 19211724, 13498382, 16450169, 17397545, 17786278, 17767676
     14458214, 19289642, 17622427, 17824637, 17716305, 16399083, 18744139
     14852021, 19727057, 17242746, 17174582, 18277454, 13645875, 14084247
     17551709, 17393683, 17614227, 17705023, 17883081, 16042673, 18996843
     16285691, 17393915, 16228604, 17655634, 17596908, 17600719, 16180763
     17754782, 17323222, 18264060, 17325413, 17343514, 17865671, 16613964
     17811447, 16069901, 17390431, 16494615, 16043574, 17006570, 17027426
     14602788, 17080436, 18673342, 17186905, 17011832, 17394950, 13944971
     17752121, 17284817, 17811456, 17238511, 17239687, 17042658, 14764829
     17602269, 17672719, 17891946, 17205719, 18262334, 16721594, 17071721
     14565184, 17265217, 17389192, 17761775, 16360112, 17982555, 17842825
     19121551, 16837842, 18139690, 17313525, 18203837, 18203838, 18203835
     18436307, 17546761, 17721717, 17344412, 17787259, 16472716, 17346671
     17588480, 13364795, 14657740, 11733603, 17811438, 19466309, 17040527
     17037130, 17088068, 17612828, 18180390, 17449815, 19458377, 19554106
     18973907, 18230522, 19544839, 17811429, 16863422, 17237521, 17951233
     17752995, 16392068, 17437634, 14338435, 13609098, 17332800, 18199537
     17465741, 17441661, 18522509, 18061914, 14133975, 17570240, 16692232
     18247991, 18328509, 16956380, 17587063, 19049453, 16618694, 17586955
     18009564, 14285317, 16542886, 17341326, 17571306, 17036973, 18641419
     16524926, 17297939, 17478145, 17040764, 17299889, 16912439, 15861775
     14054676, 13951456, 17267114, 16850630, 17648596, 14010183, 17296856
     17478514, 16875449, 18681862, 14829250, 17385178, 17443671, 16731148
     16314254, 17165204, 15979965, 19584068, 17381384, 17892268, 16198143



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

OPatch succeeded.
 
But on one server I was testing patch for OEM (18235390) to allow it to monitor tablespaces without ORA-1000 errors.Is it possible that my OEM patch add anything special ?
I was thinking about that for a while but I was not sure. So I did simple test - installed this patch on standby server and ... yes - Oracle Restart issue has been fixed. 
 
Strange, very strange - what this patch did that Data Guard was fixed ? Well it did one important thing - it relinked oracle binaries again.
 
Lucky enough I got one more pair with latest PSU ready for test.I run test with PSU installed and bug was still there. OK - so let's relink - and it was it
 

2014-12-22 14:33:40.942: [    AGFW][2057]{0:0:12827} Agent received the message: RESOURCE_MODIFY_ATTR[ora.apppre21.db 1 1] ID 4355:199223
2014-12-22 14:33:40.944: [ora.apppre21.db][9494]{0:0:12827} [res_attr_modified] clsn_agent::modify {
2014-12-22 14:33:40.945: [ora.apppre21.db][9494]{0:0:12827} [res_attr_modified] clsn_agent::modify }
2014-12-22 14:33:40.945: [    AGFW][9494]{0:0:12827} Command: res_attr_modified for resource: ora.apppre21.db 1 1 completed with status: SUCCESS
2014-12-22 14:33:40.946: [    AGFW][2057]{0:0:12827} Attribute: ROLE for resource ora.apppre21.db modified to: PHYSICAL_STANDBY
2014-12-22 14:33:40.946: [    AGFW][2057]{0:0:12827} Attribute: USR_ORA_OPEN_MODE for resource ora.apppre21.db modified to: mount
2014-12-22 14:33:40.946: [    AGFW][2057]{0:0:12827}  config version updated to : 153 for ora.apppre21.db 1 1
2014-12-22 14:33:40.946: [    AGFW][2057]{0:0:12827} Agent sending last reply for: RESOURCE_MODIFY_ATTR[ora.apppre21.db 1 1] ID 4355:199223
 
This is quite strange and a little bit scary. I have installed all PSU using opatch auto from Grid Infrastructure Home and there was no errors but relinking Oracle Home actually fix a problem which was included in the patch. 
 
So remember "Relink after (patch), relink always"
 
regards,
Marcin