Pages

Thursday 19 April 2018

After standby was setup, recovery failed with error ORA-00308,ORA-17503 and ORA-15045

After standby was setup, recovery failed with error ORA-00308,ORA-17503 and ORA-15045.

SQL> recover standby database;
ORA-00279: change 78501137 generated at  needed for thread 1
ORA-00289: suggestion : +TESTPDB_DATA
ORA-00280: change 78501137 for thread 1 is in sequence #38114


Specify log: {=suggested | filename | AUTO | CANCEL}
auto
ORA-00308: cannot open archived log '+TESTPDB_DATA'
ORA-17503: ksfdopn:2 Failed to open file +TESTPDB_DATA
ORA-15045: ASM file name '+TESTPDB_DATA' is not in reference form


ORA-00308: cannot open archived log '+TESTPDB_DATA'
ORA-17503: ksfdopn:2 Failed to open file +TESTPDB_DATA
ORA-15045: ASM file name '+TESTPDB_DATA' is not in reference form


ORA-01547: warning: RECOVER succeeded but OPEN RESETLOGS would get error below
ORA-01152: file 1 was not restored from a sufficiently old backup
ORA-01110: data file 1: '+GUYSDDD6_DATA/SANGAMDP/DATAFILE/system.279.960261095'




1. Check the status v$managed_standby on DR, only arch process was running

SQL> select PROCESS,PID,STATUS,THREAD#,SEQUENCE# from v$managed_standby;

PROCESS   PID                      STATUS          THREAD#  SEQUENCE#
--------- ------------------------ ------------ ---------- ----------
ARCH      112962                   CLOSING               1      38124
ARCH      112965                   CONNECTED             0          0
ARCH      112967                   CONNECTED             0          0
ARCH      112969                   CONNECTED             0          0
ARCH      112971                   CONNECTED             0          0
ARCH      112973                   CONNECTED             0          0


2. Checked the v$dataguard_status on DR, it gave the below information.

SQL> select dest_id,message from v$dataguard_status;

   DEST_ID
----------
MESSAGE
--------------------------------------------------------------------------------
         0
ARC0: Archival started

         0
ARC1: Archival started

         0
ARC2: Archival started


...
...
...


ARC2: Becoming the active heartbeat ARCH

         0
ARCj: Archival started

         0
Error 12154 received logging on to the standby


   DEST_ID
----------
MESSAGE
--------------------------------------------------------------------------------
         0
FAL[client, ARC5]: Error 12154 connecting to sangamdp for fetching gap sequence


25 rows selected.



Solution:

sangamdp is the standby database here. As per above message, primary is failing to connect to standby database.so possible reason, tns entry is missing in the primary nodes. so copy standby connection string on all nodes if it's RAC.


Standby TNS entry:
sangamdp =(DESCRIPTION =(ADDRESS_LIST =(ADDRESS=(PROTOCOL= TCP)(HOST=scan-sangam-db.com)(PORT = 1521)))(CONNECT_DATA =(SERVER = DEDICATED)(SERVICE_NAME = sangamdp)))


Once done, check the v$dataguard_status and v$managed_standby views.


SQL> select PROCESS,PID,STATUS,THREAD#,SEQUENCE# from v$managed_standby;

PROCESS   PID                      STATUS          THREAD#  SEQUENCE#
--------- ------------------------ ------------ ---------- ----------
ARCH      112962                   CLOSING               1      38124
ARCH      112965                   CONNECTED             0          0
ARCH      112967                   CONNECTED             0          0
ARCH      112969                   CONNECTED             0          0
....
....
ARCH      113000                   CONNECTED             0          0
ARCH      113002                   CONNECTED             0          0
RFS       138923                   IDLE                  0          0
RFS       138727                   IDLE                  0          0

PROCESS   PID                      STATUS          THREAD#  SEQUENCE#
--------- ------------------------ ------------ ---------- ----------
RFS       138729                   IDLE                  0          0
RFS       138731                   IDLE                  0          0



SQL> select dest_id,message from v$dataguard_status;

   DEST_ID
----------
MESSAGE
--------------------------------------------------------------------------------
         0
ARC0: Archival started

         0
ARC1: Archival started

         0
ARC2: Archival started

....
....
ARC0: Beginning to archive thread 1 sequence 38124 (78521200-78522852)


   DEST_ID
----------
MESSAGE
--------------------------------------------------------------------------------
         0
ARC0: Completed archiving thread 1 sequence 38124 (0-0)

         0
RFS[13]: Assigned to RFS process (PID:3960)

         0
RFS[14]: Assigned to RFS process (PID:3964)

....
....
RFS[20]: Assigned to RFS process (PID:4119)

         0
RFS[21]: Assigned to RFS process (PID:4186)

         0
ARC1: Beginning to archive thread 2 sequence 38155 (78521195-78523909)


   DEST_ID
----------
MESSAGE
--------------------------------------------------------------------------------
         0
ARC1: Completed archiving thread 2 sequence 38155 (0-0)


52 rows selected.

.....


Now RFS process is working.. Now try manual recovery



SQL> recover standby database;
ORA-00279: change 78501137 generated at 11/17/2017 03:04:46 needed for thread 1
ORA-00289: suggestion :
+TESTPDB_DATA/SANGAMDP/ARCHIVELOG/2017_11_17/thread_1_seq_38114.1957.960267717
ORA-00280: change 78501137 for thread 1 is in sequence #38114


Specify log: {=suggested | filename | AUTO | CANCEL}
auto
ORA-00279: change 78501137 generated at 11/17/2017 03:04:44 needed for thread 2
ORA-00289: suggestion :
+TESTPDB_DATA/SANGAMDP/ARCHIVELOG/2017_11_17/thread_2_seq_38148.1969.960268039
ORA-00280: change 78501137 for thread 2 is in sequence #38148


ORA-00279: change 78503518 generated at 11/17/2017 03:21:21 needed for thread 1
ORA-00289: suggestion :
+TESTPDB_DATA/SANGAMDP/ARCHIVELOG/2017_11_17/thread_1_seq_38115.1959.960267717
ORA-00280: change 78503518 for thread 1 is in sequence #38115
ORA-00278: log file
'+TESTPDB_DATA/SANGAMDP/ARCHIVELOG/2017_11_17/thread_1_seq_38114.1957.960267717'
no longer needed for this recovery
...
....
ORA-00279: change 78522852 generated at 11/17/2017 05:01:53 needed for thread 1
ORA-00289: suggestion : +TESTPDB_DATA
ORA-00280: change 78522852 for thread 1 is in sequence #38125
ORA-00278: log file
'+TESTPDB_DATA/SANGAMDP/ARCHIVELOG/2017_11_17/thread_1_seq_38124.1964.960267723'
no longer needed for this recovery


ORA-16145: archival for thread# 1 sequence# 38125 in progress





Now it's working fine.


Once manual recovery is done, keep the database in management mode.

Recover managed standby database disconnect from session;


SQL> SQL> recover managed standby database disconnect from session;
Media recovery complete.
SQL>
SQL> select PROCESS,PID,STATUS,THREAD#,SEQUENCE# from v$managed_standby;

PROCESS   PID                      STATUS          THREAD#  SEQUENCE#
--------- ------------------------ ------------ ---------- ----------
ARCH      112962                   CLOSING               1      38124
ARCH      112965                   CLOSING               2      38155
ARCH      112967                   CONNECTED             0          0
....
....
....
RFS       4119                     IDLE                  2      38156
RFS       4186                     IDLE                  0          0
MRP0      43199                    APPLYING_LOG          2      38156

44 rows selected.

ORA-04024: self-deadlock detected while trying to mutex pin cursor 0x1FDB2F8C8

We got below error while staring the database on 12.1.0.2 oracle cluster.

oracle@oracle-sangam1_testdb1:/backup_prod/testdb_upgrade_backup>srvctl   start database -d testdb
PRCR-1079 : Failed to start resource ora.testdb.db
CRS-5017: The resource action "ora.testdb.db start" encountered the following error:
ORA-01092: ORACLE instance terminated. Disconnection forced
ORA-04024: self-deadlock detected while trying to mutex pin cursor 0x1FDB2F8C8
Process ID: 125154
Session ID: 98 Serial number: 57029
. For details refer to "(:CLSN00107:)" in "/opt/oracle/product/base/diag/crs/pwdbl0927pp02/crs/trace/crsd_oraagent_oracle.trc".

CRS-2674: Start of 'ora.testdb.db' on 'pwdbl0927pp02' failed
CRS-2632: There are no more servers to try to place resource 'ora.testdb.db' on that would satisfy its placement policy
oracle@oracle-sangam1_testdb1:/backup_prod/testdb_upgrade_backup>srvctl status database -d testdb
Instance testdb1 is running on node oracle-sangam1
Instance testdb2 is not running on node pwdbl0927pp02
oracle@oracle-sangam1_testdb1:/backup_prod/testdb_upgrade_backup>

Solution:
Set below hidden parameter and restart instances.

alter system set “_fix_control”=’9550277:ON’;


alter system set  "_fix_control"='9550277:ON' scope=spfile;

System altered.

oracle@oracle-sangam1_testdb1:/backup_prod/testdb_upgrade_backup>srvctl status    database -d testdb
Instance testdb1 is running on node oracle-sangam1
Instance testdb2 is running on node oracle-sangam2
oracle@oracle-sangam1_testdb1:/backup_prod/testdb_upgrade_backup>


or

apply patch Patch 21372829 on 12.1.0.2 environment.

Note:Please consult Oracle support before setting hidden parameter

Oracle ASM is not up post kernel upgrade.

Recently we upgraded RHEL kernel from 3.10.0-514.16.1.el7.x86_64  to 3.10.0-693.17.1.el7.x86_64.  After kernel upgrade, ASM didn't come up.

Tried to mount the /dev/oracleasm/disks and got the below error.

[root@ip-test.sangam.com ~]# oracleasm init
Loading module "oracleasm": failed
Unable to load module "oracleasm"
[root@ip-test.sangam.com ~]#

I could see below error on /var/log/messages and /dev/oracleasm/disks file system was not accessible.

Apr 19 09:15:17 ip-test.sangam.com pushy-client: INFO: [ip-test.sangam.com] Incarnation ID: 5ead5023-2bc7-4079-911a-de1689b56405
Apr 19 09:15:17 ip-test.sangam.com pushy-client: INFO: [ip-test.sangam.com] Allowing fallback to unencrypted connection: true
Apr 19 09:15:17 ip-test.sangam.com pushy-client: INFO: [ip-test.sangam.com] Starting client ...
Apr 19 09:15:17 ip-test.sangam.com pushy-client: INFO: [ip-test.sangam.com] Retrieving configuration from https://giscinchef.corporate.ge.com/organizations/power-water//pushy/config/ip-test.sangam.com: ...
Apr 19 09:15:17 ip-test.sangam.com pushy-client: ERROR: Error connecting to https://giscinchef.corporate.ge.com/organizations/power-water/pushy/config/ip-test.sangam.com?ccpk=GAFx%25WSpj%3D-%3DIA%3E83VOtoy%231u-I4B%5EVYLf31%26W%5Dn&version=2.0, retry 1/5
Apr 19 09:15:21 ip-test.sangam.com modprobe: FATAL: Module oracleasm not found.
Apr 19 09:15:22 ip-test.sangam.com pushy-client: ERROR: Error connecting to https://giscinchef.corporate.ge.com/organizations/power-water/pushy/config/ip-test.sangam.com?ccpk=GAFx%25WSpj%3D-%3DIA%3E83VOtoy%231u-I4B%5EVYLf31%26W%5Dn&version=2.0, retry 2/5




Reason: On system we had below oracleasm module or rpms.

[root@ip-test.sangam.com ~]# rpm -qa|grep oracleasm
kmod-oracleasm-2.0.8-17.el7.x86_64
oracleasm-support-2.1.8-3.el7.x86_64
oracleasmlib-2.0.12-1.el7.x86_64

[root@ip-test.sangam.com ~]# uname -r
3.10.0-693.17.1.el7.x86_64
[root@ip-test.sangam.com ~]# uname -a
Linux ip-test.sangam.com.ec2.internal 3.10.0-693.17.1.el7.x86_64 #1 SMP Sun Jan 14 10:36:03 EST 2018 x86_64 x86_64 x86_64 GNU/Linux
[root@ip-test.sangam.com ~]# cat /etc/release
NAME="Red Hat Enterprise Linux Server"
VERSION="7.3 (Maipo)"
ID="rhel"
ID_LIKE="fedora"
VERSION_ID="7.3"
PRETTY_NAME="Red Hat Enterprise Linux Server 7.3 (Maipo)"



However for 3.10.0-693.17.1.el7.x86_64, we need to have latest oracleasm kernel module kmod-oracleasm-2.0.8-19.el7.x86_64.

Solution: Install the kmod-oracleasm-2.0.8-19.el7.x86_64 and restart oracleasm module.

[root@ip-test.sangam.com ~]# yum install kmod-oracleasm-2.0.8-19.el7.x86_64
Loaded plugins: 010-prune-by-regex, amazon-id, fastestmirror, rhui-lb, search-disabled-repos
Loading mirror speeds from cached hostfile
Resolving Dependencies
There are unfinished transactions remaining. You might consider running yum-complete-transaction, or "yum-complete-transaction --cleanup-only" and "yum history redo last", first to finish them. If those don't work you'll have to try removing/installing packages by hand (maybe package-cleanup can help).
--> Running transaction check
---> Package kmod-oracleasm.x86_64 0:2.0.8-17.el7 will be updated
---> Package kmod-oracleasm.x86_64 0:2.0.8-19.el7 will be an update
--> Finished Dependency Resolution

Dependencies Resolved

=======================================================================================================================================================================
 Package                                   Arch                              Version                                   Repository                                 Size
=======================================================================================================================================================================
Updating:
 kmod-oracleasm                            x86_64                            2
 .....
 ....
 ....
 Running transaction
  Updating   : kmod-oracleasm-2.0.8-19.el7.x86_64                                                                                                                  1/2
  Cleanup    : kmod-oracleasm-2.0.8-17.el7.x86_64                                                                                                                  2/2


  Verifying  : kmod-oracleasm-2.0.8-19.el7.x86_64                                                                                                                  1/2
  Verifying  : kmod-oracleasm-2.0.8-17.el7.x86_64                                                                                                                  2/2

Updated:
  kmod-oracleasm.x86_64 0:2.0.8-19.el7

Complete!
[root@ip-test.sangam.com ~]#


[root@ip-test.sangam.com ~]# oracleasm init
Loading module "oracleasm": oracleasm
Configuring "oracleasm" to use device physical block size
Mounting ASMlib driver filesystem: /dev/oracleasm
[root@ip-test.sangam.com ~]#

[root@ip-test.sangam.com ~]# /etc/init.d/oracleasm stop
Stopping oracleasm (via systemctl):                        [  OK  ]
[root@ip-test.sangam.com ~]# /etc/init.d/oracleasm start
Starting oracleasm (via systemctl):                        [  OK  ]
[root@ip-test.sangam.com ~]#

[root@ip-test.sangam.com ~]# oracleasm scandisks
Reloading disk partitions: done
Cleaning any stale ASM disks...
Scanning system for ASM disks...
Instantiating disk "TEST09_T1_256_DATA003"
Instantiating disk "TEST10_T1_256_DATA004"

...