12 Nov How I Finished a Recovery From an Active Duplicate After Facing Errors ORA-19909 and ORA-01110
The other day I was doing a database cloning in 11.2.0.4, from an active duplicate and got the following error ORA-19909: datafile 1 belongs to an orphan incarnation and ORA-01110: data file 1.
This is a blog post on how I solved these errors. It is worth mentioning that what I did here applies to 12c,18c and 19c databases as well.
I first verified that I had the password file from the target database, that I also had the corresponding TNS entries for it and as well I created a listener for this task only. The creation of the listener was a requirement from the client that I was working with, else I could have worked with the SCAN listener.
Next I verified that I could connect to the target and auxiliary databases correctly and created the script below to use for this refresh.
##################################################################
## Connectivity Test
##################################################################
oracle $ ls $ORACLE_HOME/dbs/orapwSTG*
/u01/app/oracle/product/11.2.0.4/dbhome_3/dbs/orapwSTG1
oracle $ rman TARGET sys/********@PROD AUXILIARY sys/********@STG_STATIC
connected to target database: PROD (DBID=3874882083)
connected to auxiliary database: STG (not mounted)
##################################################################
## STG_STATIC TNS Entry
##################################################################
STG_STATIC =
(DESCRIPTION =
(ADDRESS_LIST =
(ADDRESS = (PROTOCOL = TCP)(HOST = auxiliarydbadm01)(PORT = 1523))
)
(CONNECT_DATA =
(SERVICE_NAME = STG1)
(UR=A)
)
)
##################################################################
## PROD TNS Entry
##################################################################
PROD =
(DESCRIPTION =
(ADDRESS_LIST =
(ADDRESS = (PROTOCOL = TCP)(HOST = prod_scan)(PORT = 1521))
)
(CONNECT_DATA =
(SERVICE_NAME = PROD1)
)
)
##################################################################
## Listener used
##################################################################
LISTENER_REFRESH =
(DESCRIPTION_LIST =
(DESCRIPTION =
(ADDRESS = (PROTOCOL = TCP)(HOST = auxiliarydbadm01)(PORT = 1523))
)
)
SID_LIST_LISTENER_REFRESH =
(SID_LIST =
(SID_DESC =
(ORACLE_HOME = /u01/app/oracle/product/11.2.0.4/dbhome_3)
(SID_NAME = QA1)
)
(SID_DESC =
(ORACLE_HOME = /u01/app/oracle/product/11.2.0.4/dbhome_3)
(SID_NAME = STG1)
)
(SID_DESC =
(ORACLE_HOME = /u01/app/oracle/product/11.2.0.4/dbhome_3)
(SID_NAME = RFSH1)
)
)
ADR_BASE_LISTENER = /u01/app/oracle
##################################################################
## recover_from_prod.sh
##################################################################
oracle $ cat recover_from_prod.sh
#!/bin/bash
export NLS_DATE_FORMAT='DD-MON-YYYY HH24:MI:SS'
export ORACLE_SID=STG1
export ORAENV_ASK=NO
. /usr/local/bin/oraenv
rman TARGET sys/********@PROD AUXILIARY sys/********@STG_STATIC <<endofrman
run {
allocate channel prmy1 type disk;
allocate channel prmy2 type disk;
allocate channel prmy3 type disk;
allocate channel prmy4 type disk;
allocate channel prmy5 type disk;
allocate channel prmy6 type disk;
allocate auxiliary channel aux1 type disk;
allocate auxiliary channel aux2 type disk;
allocate auxiliary channel aux3 type disk;
allocate auxiliary channel aux4 type disk;
allocate auxiliary channel aux5 type disk;
allocate auxiliary channel aux6 type disk;
DUPLICATE TARGET DATABASE TO 'STG' FROM ACTIVE DATABASE NOFILENAMECHECK;
}
endofrman
I knew that this duplicate was going to take a while as this was a 35 TB database.
SQL> SELECT
( SELECT SUM(bytes)/power(1024,4) data_size FROM dba_data_files
) +
( SELECT NVL(SUM(bytes),0)/power(1024,4) temp_size FROM dba_temp_files
) +
( SELECT SUM(bytes)/power(1024,4) redo_size FROM sys.v_$log
) +
(SELECT SUM(BLOCK_SIZE*FILE_SIZE_BLKS)/power(1024,3) controlfile_size
FROM v$controlfile
) "Database Size in TB"
FROM dual;
Database Size in TB
-------------------
35.1021405
Even though it took a while, the restore for the duplicate database went ok, but when the recovery process started to happen, I got the following errors
oracle $ tail -100 recover_from_prod.log ... Starting recover at 09-NOV-2020 08:27:59 starting media recovery media recovery failed Oracle instance started ... RMAN-11003: failure during parse/execution of SQL statement: alter database recover if needed start until change 281698833114 using backup controlfile ORA-00283: recovery session canceled due to errors ORA-19909: datafile 1 belongs to an orphan incarnation ORA-01110: data file 1: '+DATAC2/stg/datafile/system.636.1056008579'
These errors primarily happen because there are other files in the ASM diskgroup that have the same DBID as the auxiliary database that I was cloning.
As the way that RMAN works for an active duplicate is, if you are using ASM disk groups, is that it catalogs everything under the disk group that db_recovery_file_dest parameter is set to if the log_archive_dest_1. parameter is not set.
This was true in my case as in the same cluster there is a standby running called proddr for the target database that I was cloning.
##################################################################
## db_recovery_file_dest and log_archive_dest_1 parameter values
##################################################################
oracle $ echo "
> show parameter log_archive_dest_1;
> " | sqlplus -s -L / as sysdba
NAME TYPE VALUE
------------------------------------ ----------- ------------------------------
log_archive_dest_1 string
...
oracle $ echo "
> show parameter db_recovery_file_dest;
> " | sqlplus -s -L / as sysdba
NAME TYPE VALUE
------------------------------------ ----------- ------------------------------
db_recovery_file_dest string +RECOC2
db_recovery_file_dest_size big integer 20000G
##################################################################
## From the recover_from_prod.log
##################################################################
...
"+RECOC1/prod/archivelog/2020_11_09/thread_2_seq_535909.41715.1056009955" auxiliary format
"+RECOC2" ;
catalog clone start with "+RECOC2";
switch clone datafile all;
}
...
List of Cataloged Files
=======================
File Name: +RECOC2/proddr/CONTROLFILE/current.7901.1022257521
File Name: +RECOC2/stg/archivelog/2020_11_09/thread_2_seq_535877.5618.1056010749
...
File Name: +RECOC2/proddr/archivelog/2020_11_07/thread_2_seq_535588.2240.1055891307
File Name: +RECOC2/proddr/archivelog/2020_11_07/thread_1_seq_567337.8034.1055892763
..
datafile 1 switched to datafile copy
input datafile copy RECID=67 STAMP=1056011218 file name=+DATAC2/stg/datafile/system.636.1056008579
...
datafile 133 switched to datafile copy
input datafile copy RECID=198 STAMP=1056011261 file name=+DATAC2/stg/datafile/aud_tbs.451.1056009851
datafile 134 switched to datafile copy
input datafile copy RECID=199 STAMP=1056011262 file name=+DATAC2/stg/datafile/revenue_ods2.622.1055987265
contents of Memory Script:
{
set until scn 281698833114;
recover
clone database
delete archivelog
;
}
So now that I have investigated the error, I proceeded to fix the error.
The first thing I did was try to open STG database in mount mode to see the contents of the control file, as from the log above I did see that the datafile copy had switched and updated the control file, and this will help me in doing a faster recovery of this process.
SQL> startup mount; ORACLE instance started. Total System Global Area 2.5655E+10 bytes Fixed Size 2265224 bytes Variable Size 1.0402E+10 bytes Database Buffers 1.5099E+10 bytes Redo Buffers 151113728 bytes * ERROR at line 1: ORA-01103: database name 'PROD' in control file is not 'STG'
From the error above, I see that the control file has the incorrect database name and what I have to do is to recreate the control file for this.
To avoid going to ASM or the recover log I have to gather all the datafiles and their location, I created instead a small parameter file that only includes the control file, the block size, the same compatible parameter and the name of the target database as database PROD which is shown in the error ORA-01103 above.
Once I have the database PROD up, I just backup that database control file to trace.
oracle $ cat initprod.ora DB_NAME=PROD DB_UNIQUE_NAME=PROD DB_BLOCK_SIZE=8192 *.control_files='/home/oracle/working/antunez/STG/control02.ctl' *.compatible='11.2.0.4.0' SQL> startup mount pfile='/home/oracle/working/antunez/initprod.ora'; ORACLE instance started. Total System Global Area 513642496 bytes Fixed Size 2254624 bytes Variable Size 402655456 bytes Database Buffers 100663296 bytes Redo Buffers 8069120 bytes Database mounted. SQL> alter database backup controlfile to trace as '/home/oracle/working/antunez/stg.sql'; Database altered. SQL> shutdown abort ORACLE instance shut down.
Now that I have the control file trace with the proper datafile location, I modify it to leave only the section of RESETLOGS and change the line of CREATE CONTROL FILE to use the SET command.
Once I have done that, I run the creation of the control file in STG database.
oracle $ cat /home/oracle/working/antunez/stg.sql
CREATE CONTROLFILE REUSE SET DATABASE "STG" RESETLOGS FORCE LOGGING ARCHIVELOG
MAXLOGFILES 192
MAXLOGMEMBERS 3
MAXDATAFILES 1024
MAXINSTANCES 32
MAXLOGHISTORY 149504
LOGFILE
GROUP 11 (
'+DATAC2/stg/onlinelog/group_11.3162.914669717',
...
'+DATAC2/stg/datafile/sysaux.454.1056009483',
'+DATAC2/stg/datafile/users.448.1056009331',
'+DATAC2/stg/datafile/users.455.1056009819'
CHARACTER SET AL32UTF8
;
oracle $ . oraenv <<< STG1
SQL> startup nomount;
ORACLE instance started.
Total System Global Area 2.5655E+10 bytes
Fixed Size 2265224 bytes
Variable Size 1.0402E+10 bytes
Database Buffers 1.5099E+10 bytes
Redo Buffers 151113728 bytes
SQL> @/home/oracle/working/antunez/stg.sql
Control file created.
SQL> select open_mode from v$database;
OPEN_MODE
--------------------
MOUNTED
What I needed now are the archived redo logs that were going to be used for the recovery, as some of the archivelogs were not copied.
RMAN thought that they were already in place for the recovery due to them being in the auxiliary host for the proddr standby database. So I did the below to find the range of archived redo logs that I was going to need.
If you remember the script that I used I set the NLS environment variable to this export NLS_DATE_FORMAT='DD-MON-YYYY HH24:MI:SS', this was so that in the log I would have the details of the times down to seconds from the RMAN output, and it came useful for this.
I extracted from the log the until scn and the Starting Duplicate Db output. From this I obtained from the target database called PROD the range of archived redo log sequences that I was going to need.
oracle $ cat recover_from_prod.log | egrep "Starting Duplicate Db at | scn"
Starting Duplicate Db at 08-NOV-2020 17:07:35
set until scn 281698833114;
oracle $ sqlplus sys/****@PROD as sysdba
...
SQL> select name from v$database;
NAME
---------
PROD
SQL> col scn format 999999999999999999999
SQL> select timestamp_to_scn(to_timestamp('08-11-2020 17:07:34','dd-mm-yyyy hh24:mi:ss')) scn from dual;
SCN
----------------------
281674037748
SQL> select distinct thread#, sequence#, status, first_time, next_time, first_change#, next_change# from v$archived_log
where 281674037748 between first_change# and next_change# order by 1,2;
THREAD# SEQUENCE# S FIRST_TIME NEXT_TIME FIRST_CHANGE# NEXT_CHANGE#
---------- ---------- - ------------------- ------------------- ------------- ------------
1 567552 A 2020-11-08 17:04:19 2020-11-08 17:07:37 2.8167E+11 2.8167E+11
2 535731 A 2020-11-08 17:05:00 2020-11-08 17:07:36 2.8167E+11 2.8167E+11
SQL> select distinct thread#, sequence#, status, first_time, next_time, first_change#, next_change# from v$archived_log
where 281698833114 between first_change# and next_change# order by 1,2;
THREAD# SEQUENCE# S FIRST_TIME NEXT_TIME FIRST_CHANGE# NEXT_CHANGE#
---------- ---------- - ------------------- ------------------- ------------- ------------
1 567681 A 2020-11-09 08:05:54 2020-11-09 08:06:09 2.8170E+11 2.8170E+11
1 567682 A 2020-11-09 08:06:09 2020-11-09 08:10:27 2.8170E+11 2.8170E+11
2 535910 A 2020-11-09 08:05:54 2020-11-09 08:06:09 2.8170E+11 2.8170E+11
With the data above, now I went and ran the following to backup copy command so that I could obtain the archived redo logs necessary for this recovery.
Do notice that I did it to a different location that the current db_recovery_file_dest and that I had to connect to both PROD and STG databases for this command.
oracle $ rman TARGET sys/********@PROD AUXILIARY sys/********@STG_STATIC
RMAN> run {
backup as copy archivelog from sequence 567552 until sequence 567682 thread 1 auxiliary format '/u02/pythian/STG/%t_%s_%r.arc';
backup as copy archivelog from sequence 535731 until sequence 535910 thread 2 auxiliary format '/u02/pythian/STG/%t_%s_%r.arc';
}
Once the copy of the archived redo logs were restored, now I registered them to the control file of the STG database.
oracle $ . oraenv <<< STG1 oracle $ rman target / connected to target database: STG (DBID=3874882083, not open) RMAN> catalog start with '/u02/pythian/STG/; cataloging files... cataloging done List of Cataloged Files ======================= ... File Name: /u02/pythian/STG/1056028905_128319_904050853.arc File Name: /u02/pythian/STG/1056030309_128439_904050853.arc
The last thing that I needed to do is to recover the STG database to the SCN found in the recover log. Making sure that I don’t connect to the target database called PROD, I am only connecting to the database called STG.
oracle $ . oraenv <<< STG1
oracle $ rman target /
connected to target database: STG (DBID=3874882083, not open)
RMAN> run {
set until scn 281698833114;
recover database;
}
executing command: SET until clause
Starting recover at 09-NOV-20
allocated channel: ORA_DISK_1
channel ORA_DISK_1: SID=3142 device type=DISK
starting media recovery
archived log for thread 1 with sequence 567626 is already on disk as file /u02/pythian/STG/1056029933_128385_904050853.arc
archived log for thread 1 with sequence 567627 is already on disk as file /u02/pythian/STG/1056029940_128386_904050853.arc
archived log for thread 1 with sequence 567628 is already on disk as file /u02/pythian/STG/1056029941_128387_904050853.arc
archived log for thread 1 with sequence 567629 is already on disk as file /u02/pythian/STG/1056029942_128388_904050853.arc
archived log for thread 1 with sequence 567630 is already on disk as file /u02/pythian/STG/1056029943_128389_904050853.arc
archived log for thread 1 with sequence 567631 is already on disk as file /u02/pythian/STG/1056029945_128390_904050853.arc
archived log for thread 1 with sequence 567632 is already on disk as file /u02/pythian/STG/1056029952_128391_904050853.arc
...
archived log file name=/u02/pythian/STG/1056028890_128318_904050853.arc thread=2 sequence=535909
archived log file name=/u02/pythian/STG/1056030309_128439_904050853.arc thread=1 sequence=567680
archived log file name=/u02/pythian/STG/1056030310_128440_904050853.arc thread=1 sequence=567681
archived log file name=/u02/pythian/STG/1056028905_128319_904050853.arc thread=2 sequence=535910
media recovery complete, elapsed time: 00:06:35
Finished recover at 09-NOV-20
After this I just needed to open it as resetlogs, also what I wanted after this is for the cloned database to have a new DBID and at the end bring it up as a RAC database. Verifying as well the database and instance status using verify_data_dictionary_11g.sql
RMAN> alter database open resetlogs;
using target database control file instead of recovery catalog
database opened
RMAN> delete archivelog all;
...
Deleted 353 objects
RMAN> shutdown immediate
database shutdown
RMAN> STARTUP MOUNT
database mounted
RMAN> exit
oracle $ nid target=sys/*******
DBNEWID: Release 11.2.0.4.0 - Production on Mon Nov 9 14:34:22 2020
Copyright (c) 1982, 2011, Oracle and/or its affiliates. All rights reserved.
Connected to database STG (DBID=3874882083)
Connected to server version 11.2.0
Control Files in database:
+DATAC2/stg/controlfile/control01.ctl
+RECOC2/stg/controlfile/control02.ctl
Change database ID of database STG? (Y/[N]) => Y
Proceeding with operation
Changing database ID from 3874882083 to 1490626863
Control File +DATAC2/stg/controlfile/control01.ctl - modified
Control File +RECOC2/stg/controlfile/control02.ctl - modified
Datafile +DATAC2/stg/datafile/system.636.105600857 - dbid changed
...
Datafile +DATAC2/stg/datafile/revenue_ods2.622.105598726 - dbid changed
Control File +DATAC2/stg/controlfile/control01.ctl - dbid changed
Control File +RECOC2/stg/controlfile/control02.ctl - dbid changed
Instance shut down
Database ID for database STG changed to 1490626863.
All previous backups and archived redo logs for this database are unusable.
Database is not aware of previous backups and archived logs in Recovery Area.
Database has been shutdown, open database with RESETLOGS option.
Succesfully changed database ID.
DBNEWID - Completed succesfully.
oracle $ sqlplus / as sysdba
...
SQL> startup mount
ORACLE instance started.
Total System Global Area 1.6034E+11 bytes
Fixed Size 2261848 bytes
Variable Size 2.5233E+10 bytes
Database Buffers 1.3475E+11 bytes
Redo Buffers 352444416 bytes
Database mounted.
SQL> ALTER DATABASE OPEN RESETLOGS;
Database altered.
SQL> ALTER SYSTEM SET cluster_database=TRUE SCOPE=spfile;
SQL> shutdown immediate
Database closed.
Database dismounted.
ORACLE instance shut down.
oracle $ srvctl start database -d STG
oracle $ srvctl status database -d STG
Instance STG1 is running on node auxiliarydbadm01
Instance STG2 is running on node auxiliarydbadm02
oracle $ sqlplus / as sysdba
SQL> @verify_data_dictionary_11g.sql
DATABASE NAME
=============
DBNAME
---------------
STG
================================================================================================
== Oracle Instance Information
================================================================================================
-- IP Address 1**.***.***.30
Cpu_Count 24 | Host_Name auxiliarydbadm01
Instance_Name STG1 | Database_Status ACTIVE
Status OPEN | Startup_Time 09-11-2020 14:43
Version 11.2.0.4.0 | Instance_Role PRIMARY_INSTANCE
Database log mode ARCHIVELOG
Background Dump Dest /u01_diag/app/oracle/diag/diag/rdbms/stg/STG1/trace
Spfile +DATAC2/stg/parameterfile/spfilestg.ora
Redo size (Gb) 1.953125
Redo size (Gb) .09765625
-- Database Space (Gb) 35367.70 | SGA (Gb) 149.3303 --
-- Nb. Datafiles 133 | Nb. Tempfiles 15 --
DBA_REGISTRY CONTENTS
================================================================
COMP_ID COMP_NAME VERSION Status
-------------------- ---------------------------------------- --------------- --------------------------------------------------
OWB OWB 11.2.0.4.0 VALID
APEX Oracle Application Express 3.2.1.00.12 VALID
EM Oracle Enterprise Manager 11.2.0.4.0 VALID
AMD OLAP Catalog 11.2.0.4.0 VALID
SDO Spatial 11.2.0.4.0 VALID
ORDIM Oracle Multimedia 11.2.0.4.0 VALID
XDB Oracle XML Database 11.2.0.4.0 VALID
CONTEXT Oracle Text 11.2.0.4.0 VALID
EXF Oracle Expression Filter 11.2.0.4.0 VALID
RUL Oracle Rules Manager 11.2.0.4.0 VALID
OWM Oracle Workspace Manager 11.2.0.4.0 VALID
CATALOG Oracle Database Catalog Views 11.2.0.4.0 VALID
CATPROC Oracle Database Packages and Types 11.2.0.4.0 VALID
JAVAVM JServer JAVA Virtual Machine 11.2.0.4.0 VALID
XML Oracle XDK 11.2.0.4.0 VALID
CATJAVA Oracle Database Java Packages 11.2.0.4.0 VALID
APS OLAP Analytic Workspace 11.2.0.4.0 VALID
XOQ Oracle OLAP API 11.2.0.4.0 VALID
RAC Oracle Real Application Clusters 11.2.0.4.0 VALID
19 rows selected.
LIST APPLIED PATCHES
=======================
ACTION_TIME ID ACTION VERSION BUNDLE COMMENTS
------------------------------ ---------- ------------------------------ --------------- ------------------------ --------------
24-AUG-13 12.03.45.119862 PM 0 APPLY 11.2.0.4 PSU Patchset 11.2.0.2.0
17-FEB-16 01.17.34.459872 PM 0 jvmpsu.sql 11.2.0.4 RAN jvmpsu.sql
17-FEB-16 01.18.26.518633 PM 20 APPLY 11.2.0.4 EXA BP20
24-JUN-17 05.01.00.394556 AM 0 jvmpsu.sql 11.2.0.4 RAN jvmpsu.sql
24-JUN-17 05.01.00.414355 AM 0 APPLY 11.2.0.4 OJVM PSU post-instal
24-JUN-17 05.01.00.416012 AM 25434033 APPLY Patch 25434033 appli
24-JUN-17 05.01.23.110902 AM 170418 APPLY 11.2.0.4 EXA BP170418
24-JAN-19 07.48.56.741239 PM 180717 APPLY 11.2.0.4 EXA BP180717
24-JAN-19 09.00.45.442572 PM 0 jvmpsu.sql 11.2.0.4 RAN jvmpsu.sql
24-JAN-19 09.00.45.707068 PM 0 APPLY 11.2.0.4 OJVM PSU post-instal
24-JAN-19 09.00.45.709711 PM 27923163 APPLY Patch 27923163 appli
11 rows selected.
LIST APPLIED SQL PATCHES
=======================
COMMENTS ACTION ACTION_DATE VERSION
------------------------------------------------------------ ------------------------------ -------------------- ---------------
RAN jvmpsu.sql jvmpsu.sql 17/02/16 13:17:34 11.2.0.4.5OJVMB
P
BP20 APPLY 17/02/16 13:18:26 11.2.0.4
BP180717 APPLY 24/01/19 19:48:56 11.2.0.4
RAN jvmpsu.sql jvmpsu.sql 24/01/19 21:00:45 11.2.0.4.180717
OJVMPSU
OJVM PSU post-install APPLY 24/01/19 21:00:45 11.2.0.4.180717
OJVMPSU
Patch 27923163 applied APPLY 24/01/19 21:00:45
OJVM PSU post-install APPLY 24/06/17 05:01:00 11.2.0.4.170418
OJVMPSU
RAN jvmpsu.sql jvmpsu.sql 24/06/17 05:01:00 11.2.0.4.170418
OJVMPSU
Patch 25434033 applied APPLY 24/06/17 05:01:00
BP170418 APPLY 24/06/17 05:01:23 11.2.0.4
Patchset 11.2.0.2.0 APPLY 24/08/13 12:03:45 11.2.0.4
11 rows selected.
COUNT OF INVALID OBJECTS
========================
COUNT(*)
----------
0
1 row selected.
INVALID OBJECTS GROUPED BY OBJECT TYPE AND OWNER
================================================
no rows selected
LIST OF SYS INVALID OBJECTS
=======================
no rows selected
Hope this blog post helps you if you are ever facing the errors ORA-19909 and ORA-01110 as for me it took me a while to solve this and this would have come in handy in this situation.
Sorry, the comment form is closed at this time.