Pythian Blog: Technical Track

Duplication: divide et impera

For me, every Monday morning starts with the same routine. I refresh some QA databases from PeopleSoft production one. Even though the process is almost fully automated (all commands are automatically generated) it takes several hours to perform the final steps because DUPLICATE FROM ACTIVE DATABASE performs image copies to the destination server. I am so happy now because the DUPLICATE mechanism in #DB12C has been changed. It now uses PULL method and backup sets over the network to perform duplication from an active database. This will shorten the time of the operation since "USING COMPRESSED BACKUPSET" and "SECTION SIZE" can now be used to optimize the process. I wanted to start the post and provide results of duplicate and output for the operation. However, the real functionality of new features sometimes deviates from what is claimed. The reasons for the discrepancies can vary, from version restrictions to bugs, but the bottom line is that the results are not what's expected. That's why many DBAs are very careful about new features. No, not afraid, just careful. They need to make 100% sure that what was claimed is working properly, without problems, so it can be properly implemented on the systems they support and care about. There are no plans that I am aware of yet to implement a 12c database on any servers; however, I decided to test duplication on an active database to see how compressed backup sets and section size clauses influence the process...in case I am asked about it one day... I started with a 12c 2 nodes RAC database. The duplication without compression and usage of section size went well, but failed due to a missing log error with section size and compression. I thought it might be because I used an easy naming connection instead of TNS, but I tested it with TNS and got the same result. I decided to test it for a standalone database - got the same result. It was failing on recovery of the duplicated database every time I used either COMPRESSED BACKUPSET and/or SECTION SIZE clauses independent of the type of connection string I was using - ASM or file system - but duplication with the clauses worked without any issues. Even though I haven't resolved the issue, the story isn't over. I created SR on MOS, uploaded the required trace and log files, and am waiting for their response. I hope someone made it work, but I have not heard yet that anyone has. It will definitely work one day and the error I have been receiving will be overcome: [code]RMAN-06402: Oracle instance shut down RMAN-00571: =========================================================== RMAN-00569: =============== ERROR MESSAGE STACK FOLLOWS =============== RMAN-00571: =========================================================== RMAN-03002: failure of Duplicate Db command at 09/08/2013 20:14:10 RMAN-05501: aborting duplication of target database RMAN-03015: error occurred in stored script Memory Script RMAN-06053: unable to perform media recovery because of missing log RMAN-06025: no backup of archived log for thread 1 with sequence 67 and starting SCN of 2178389 found to restore[/code] And I will be able to perform active duplication of 12c databases with compressed and section size to receive the output similar to the one without the clauses: [code][oracle@r121 ~]$ rman target sys/sys_pwd@t12 auxiliary sys/sys_pwd@c12 Recovery Manager: Release 12.1.0.1.0 - Production on Fri Sep 6 11:47:06 2013 Copyright (c) 1982, 2013, Oracle and/or its affiliates. All rights reserved. connected to target database: T12 (DBID=1222223202) connected to auxiliary database: T12 (not mounted) RMAN> duplicate target database to c12 from active database spfile parameter_value_convert 't12', 'c12' set db_file_name_convert 't12', 'c12' set log_file_name_convert 't12', 'c12' nofilenamecheck;2> 3> 4> 5> 6> Starting Duplicate Db at 06-SEP-13 using target database control file instead of recovery catalog allocated channel: ORA_AUX_DISK_1 channel ORA_AUX_DISK_1: SID=21 device type=DISK current log archived contents of Memory Script: { restore clone from service 't12' spfile to '/u01/app/oracle/product/12.1.0/dbhome_2/dbs/spfilec12.ora'; sql clone "alter system set spfile= ''/u01/app/oracle/product/12.1.0/dbhome_2/dbs/spfilec12.ora''"; } executing Memory Script Starting restore at 06-SEP-13 using channel ORA_AUX_DISK_1 channel ORA_AUX_DISK_1: starting datafile backup set restore channel ORA_AUX_DISK_1: using network backup set from service t12 channel ORA_AUX_DISK_1: restoring SPFILE output file name=/u01/app/oracle/product/12.1.0/dbhome_2/dbs/spfilec12.ora channel ORA_AUX_DISK_1: restore complete, elapsed time: 00:00:03 Finished restore at 06-SEP-13 sql statement: alter system set spfile= ''/u01/app/oracle/product/12.1.0/dbhome_2/dbs/spfilec12.ora'' contents of Memory Script: { sql clone "alter system set db_name = ''C12'' comment= ''duplicate'' scope=spfile"; sql clone "alter system set audit_file_dest = ''/u01/app/oracle/admin/c12/adump'' comment= '''' scope=spfile"; sql clone "alter system set control_files = ''/u01/oradata/c12/control01.ctl'', ''/u01/app/oracle/fast_recovery_area/c12/control02.ctl'' comment= '''' scope=spfile"; sql clone "alter system set dispatchers = ''(PROTOCOL=TCP) (SERVICE=c12XDB)'' comment= '''' scope=spfile"; sql clone "alter system set db_file_name_convert = ''t12'', ''c12'' comment= '''' scope=spfile"; sql clone "alter system set log_file_name_convert = ''t12'', ''c12'' comment= '''' scope=spfile"; shutdown clone immediate; startup clone nomount; } executing Memory Script sql statement: alter system set db_name = ''C12'' comment= ''duplicate'' scope=spfile sql statement: alter system set audit_file_dest = ''/u01/app/oracle/admin/c12/adump'' comment= '''' scope=spfile sql statement: alter system set control_files = ''/u01/oradata/c12/control01.ctl'', ''/u01/app/oracle/fast_recovery_area/c12/control02.ctl'' comment= '''' scope=spfile sql statement: alter system set dispatchers = ''(PROTOCOL=TCP) (SERVICE=c12XDB)'' comment= '''' scope=spfile sql statement: alter system set db_file_name_convert = ''t12'', ''c12'' comment= '''' scope=spfile sql statement: alter system set log_file_name_convert = ''t12'', ''c12'' comment= '''' scope=spfile Oracle instance shut down connected to auxiliary database (not started) Oracle instance started Total System Global Area 626327552 bytes Fixed Size 2291472 bytes Variable Size 507513072 bytes Database Buffers 113246208 bytes Redo Buffers 3276800 bytes contents of Memory Script: { sql clone "alter system set db_name = ''T12'' comment= ''Modified by RMAN duplicate'' scope=spfile"; sql clone "alter system set db_unique_name = ''C12'' comment= ''Modified by RMAN duplicate'' scope=spfile"; shutdown clone immediate; startup clone force nomount restore clone from service 't12' primary controlfile; alter clone database mount; } executing Memory Script sql statement: alter system set db_name = ''T12'' comment= ''Modified by RMAN duplicate'' scope=spfile sql statement: alter system set db_unique_name = ''C12'' comment= ''Modified by RMAN duplicate'' scope=spfile Oracle instance shut down Oracle instance started Total System Global Area 626327552 bytes Fixed Size 2291472 bytes Variable Size 507513072 bytes Database Buffers 113246208 bytes Redo Buffers 3276800 bytes Starting restore at 06-SEP-13 allocated channel: ORA_AUX_DISK_1 channel ORA_AUX_DISK_1: SID=19 device type=DISK channel ORA_AUX_DISK_1: starting datafile backup set restore channel ORA_AUX_DISK_1: using network backup set from service t12 channel ORA_AUX_DISK_1: restoring control file channel ORA_AUX_DISK_1: restore complete, elapsed time: 00:00:15 output file name=/u01/oradata/c12/control01.ctl output file name=/u01/app/oracle/fast_recovery_area/c12/control02.ctl Finished restore at 06-SEP-13 database mounted contents of Memory Script: { set newname for datafile 1 to "/u01/oradata/c12/system01.dbf"; set newname for datafile 2 to "/u01/oradata/c12/test01.dbf"; set newname for datafile 3 to "/u01/oradata/c12/sysaux01.dbf"; set newname for datafile 4 to "/u01/oradata/c12/undotbs01.dbf"; set newname for datafile 6 to "/u01/oradata/c12/users01.dbf"; restore from service 't12' clone database ; sql 'alter system archive log current'; } executing Memory Script executing command: SET NEWNAME executing command: SET NEWNAME executing command: SET NEWNAME executing command: SET NEWNAME executing command: SET NEWNAME Starting restore at 06-SEP-13 using channel ORA_AUX_DISK_1 channel ORA_AUX_DISK_1: starting datafile backup set restore channel ORA_AUX_DISK_1: using network backup set from service t12 channel ORA_AUX_DISK_1: specifying datafile(s) to restore from backup set channel ORA_AUX_DISK_1: restoring datafile 00001 to /u01/oradata/c12/system01.dbf channel ORA_AUX_DISK_1: restore complete, elapsed time: 00:01:35 channel ORA_AUX_DISK_1: starting datafile backup set restore channel ORA_AUX_DISK_1: using network backup set from service t12 channel ORA_AUX_DISK_1: specifying datafile(s) to restore from backup set channel ORA_AUX_DISK_1: restoring datafile 00002 to /u01/oradata/c12/test01.dbf channel ORA_AUX_DISK_1: restore complete, elapsed time: 00:03:55 channel ORA_AUX_DISK_1: starting datafile backup set restore channel ORA_AUX_DISK_1: using network backup set from service t12 channel ORA_AUX_DISK_1: specifying datafile(s) to restore from backup set channel ORA_AUX_DISK_1: restoring datafile 00003 to /u01/oradata/c12/sysaux01.dbf channel ORA_AUX_DISK_1: restore complete, elapsed time: 00:01:16 channel ORA_AUX_DISK_1: starting datafile backup set restore channel ORA_AUX_DISK_1: using network backup set from service t12 channel ORA_AUX_DISK_1: specifying datafile(s) to restore from backup set channel ORA_AUX_DISK_1: restoring datafile 00004 to /u01/oradata/c12/undotbs01.dbf channel ORA_AUX_DISK_1: restore complete, elapsed time: 00:00:07 channel ORA_AUX_DISK_1: starting datafile backup set restore channel ORA_AUX_DISK_1: using network backup set from service t12 channel ORA_AUX_DISK_1: specifying datafile(s) to restore from backup set channel ORA_AUX_DISK_1: restoring datafile 00006 to /u01/oradata/c12/users01.dbf channel ORA_AUX_DISK_1: restore complete, elapsed time: 00:00:07 Finished restore at 06-SEP-13 sql statement: alter system archive log current current log archived contents of Memory Script: { restore clone force from service 't12' archivelog from scn 2035520; switch clone datafile all; } executing Memory Script Starting restore at 06-SEP-13 using channel ORA_AUX_DISK_1 channel ORA_AUX_DISK_1: starting archived log restore to default destination channel ORA_AUX_DISK_1: using network backup set from service t12 channel ORA_AUX_DISK_1: restoring archived log archived log thread=1 sequence=57 channel ORA_AUX_DISK_1: restore complete, elapsed time: 00:00:01 channel ORA_AUX_DISK_1: starting archived log restore to default destination channel ORA_AUX_DISK_1: using network backup set from service t12 channel ORA_AUX_DISK_1: restoring archived log archived log thread=1 sequence=58 channel ORA_AUX_DISK_1: restore complete, elapsed time: 00:00:01 Finished restore at 06-SEP-13 datafile 1 switched to datafile copy input datafile copy RECID=6 STAMP=825422144 file name=/u01/oradata/c12/system01.dbf datafile 2 switched to datafile copy input datafile copy RECID=7 STAMP=825422144 file name=/u01/oradata/c12/test01.dbf datafile 3 switched to datafile copy input datafile copy RECID=8 STAMP=825422145 file name=/u01/oradata/c12/sysaux01.dbf datafile 4 switched to datafile copy input datafile copy RECID=9 STAMP=825422145 file name=/u01/oradata/c12/undotbs01.dbf datafile 6 switched to datafile copy input datafile copy RECID=10 STAMP=825422145 file name=/u01/oradata/c12/users01.dbf contents of Memory Script: { set until scn 2035798; recover clone database delete archivelog ; } executing Memory Script executing command: SET until clause Starting recover at 06-SEP-13 using channel ORA_AUX_DISK_1 starting media recovery archived log for thread 1 with sequence 57 is already on disk as file /u01/oradata/arch/1_57_825025894.dbf archived log for thread 1 with sequence 58 is already on disk as file /u01/oradata/arch/1_58_825025894.dbf archived log file name=/u01/oradata/arch/1_57_825025894.dbf thread=1 sequence=57 archived log file name=/u01/oradata/arch/1_58_825025894.dbf thread=1 sequence=58 media recovery complete, elapsed time: 00:00:01 Finished recover at 06-SEP-13 Oracle instance started Total System Global Area 626327552 bytes Fixed Size 2291472 bytes Variable Size 507513072 bytes Database Buffers 113246208 bytes Redo Buffers 3276800 bytes contents of Memory Script: { sql clone "alter system set db_name = ''C12'' comment= ''Reset to original value by RMAN'' scope=spfile"; sql clone "alter system reset db_unique_name scope=spfile"; } executing Memory Script sql statement: alter system set db_name = ''C12'' comment= ''Reset to original value by RMAN'' scope=spfile sql statement: alter system reset db_unique_name scope=spfile Oracle instance started Total System Global Area 626327552 bytes Fixed Size 2291472 bytes Variable Size 507513072 bytes Database Buffers 113246208 bytes Redo Buffers 3276800 bytes sql statement: CREATE CONTROLFILE REUSE SET DATABASE "C12" RESETLOGS ARCHIVELOG MAXLOGFILES 16 MAXLOGMEMBERS 3 MAXDATAFILES 100 MAXINSTANCES 8 MAXLOGHISTORY 292 LOGFILE GROUP 1 ( '/u01/oradata/c12/redo01.log' ) SIZE 50 M REUSE, GROUP 2 ( '/u01/oradata/c12/redo02.log' ) SIZE 50 M REUSE, GROUP 3 ( '/u01/oradata/c12/redo03.log' ) SIZE 50 M REUSE DATAFILE '/u01/oradata/c12/system01.dbf' CHARACTER SET WE8MSWIN1252 contents of Memory Script: { set newname for tempfile 1 to "/u01/oradata/c12/temp01.dbf"; switch clone tempfile all; catalog clone datafilecopy "/u01/oradata/c12/test01.dbf", "/u01/oradata/c12/sysaux01.dbf", "/u01/oradata/c12/undotbs01.dbf", "/u01/oradata/c12/users01.dbf"; switch clone datafile all; } executing Memory Script executing command: SET NEWNAME renamed tempfile 1 to /u01/oradata/c12/temp01.dbf in control file cataloged datafile copy datafile copy file name=/u01/oradata/c12/test01.dbf RECID=1 STAMP=825422173 cataloged datafile copy datafile copy file name=/u01/oradata/c12/sysaux01.dbf RECID=2 STAMP=825422173 cataloged datafile copy datafile copy file name=/u01/oradata/c12/undotbs01.dbf RECID=3 STAMP=825422174 cataloged datafile copy datafile copy file name=/u01/oradata/c12/users01.dbf RECID=4 STAMP=825422174 datafile 2 switched to datafile copy input datafile copy RECID=1 STAMP=825422173 file name=/u01/oradata/c12/test01.dbf datafile 3 switched to datafile copy input datafile copy RECID=2 STAMP=825422173 file name=/u01/oradata/c12/sysaux01.dbf datafile 4 switched to datafile copy input datafile copy RECID=3 STAMP=825422174 file name=/u01/oradata/c12/undotbs01.dbf datafile 6 switched to datafile copy input datafile copy RECID=4 STAMP=825422174 file name=/u01/oradata/c12/users01.dbf contents of Memory Script: { Alter clone database open resetlogs; } executing Memory Script database opened Finished Duplicate Db at 06-SEP-13 [/code] As you can see, the duplication has been nicely done and PULL method was used to get backup sets over the network from the source database. I assume with SDU set to its maximum value of 2Mb in #DB12C it can increase the speed of duplication and decrease the time I need to wait to complete post clone steps. Thank you for reading the post and I hope to update it soon with a response from Oracle Support. On another note, how many of you who blog bring such "unresolved" issues to the public? Do you think it's worth publishing or better to wait until the issue has been resolved, post successful solutions, and leave it for investigation on support sites and within communities? Happy duplicating!

No Comments Yet

Let us know what you think

Subscribe by email