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