Re: It takes long time to restore a database.

3GISSMORACLE · ‎2011-06-14

Hi ,

SMO version :3.1

Oracle :10.2.0

OS : Hp-UX

I've tried to restore a test-database with 5Gb . Everything works well except that it takes about 5 min to restore a very small database. Can you please help me to solve this problem ?

Restore Plan:
Preview:

The following components will be restored completely via: fast restore
/SMO_data

Analysis:

All components will be restored via optimal restore mechanisms.

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

Below is a summary of operation configuration(Before restore) :

Restore conf info :

Restore control file No

Reroore datafiles or tablespaces : YES

Retore shutdown or database if necessary : YES

Recovery to Perform :No Logs

Use Backup Controlfile : No

Restore Source Location Use local storage for the retore

Volume Restore Conf Info

Perform volume restore ,overriding if an overriable volume restore is possible

Logfile after restore

--[ INFO] SMO-13046: Operation GUID 8a2aa0b2308dee8f01308dee97ea0001 starting on Profile TESTSMO

--[ INFO] SMO-07431: Saving starting state of the database: TESTSMO(SHUTDOWN).

--[ INFO] ORACLE-20000: Changing state for database instance TESTSMO from SHUTDOWN to STARTED.

--[ INFO] SMO-07431: Saving starting state of the database: TESTSMO(SHUTDOWN).

--[ INFO] SMO-07127: Locked database for SnapManager operations - created lock file "/SMO/oracle/product/10.2.0/dbs/.sm_lock_TESTSMO" on host stodb08.networklogon.net.

--[ INFO] ORACLE-20000: Changing state for database instance TESTSMO from STARTED to MOUNTED.

--[ INFO] ORACLE-20009: Attempting to reconnect to instance TESTSMO after shutdown/startup.

--[ INFO] ORACLE-20011: Reconnect to instance TESTSMO successful.

--[ INFO] SMO-07200: Beginning restore of database "TESTSMO".

--[ INFO] SD-00022: Querying for snapshot stona01:/vol/test_SMO_data&colon;smo_testsmo_testsmo_f_h_1_8a2aa0b23088f755013088f75f220001_0.

--[ INFO] SD-00023: Finished querying for snapshot stona01:/vol/test_SMO_data&colon;smo_testsmo_testsmo_f_h_1_8a2aa0b23088f755013088f75f220001_0.

--[ INFO] SD-00016: Discovering storage resources for /SMO_data.

--[ INFO] SD-00017: Finished storage discovery for /SMO_data.

--[ INFO] SD-00016: Discovering storage resources for /controlredo.

--[ INFO] SD-00017: Finished storage discovery for /controlredo.

--[ INFO] SD-00016: Discovering storage resources for /archive.

--[ INFO] SD-00017: Finished storage discovery for /archive.

--[ INFO] SD-00040: Beginning to discover filesystem(s) upon host volume group vgnetapp_orafile.

--[ INFO] SD-00041: Finished discovering filesystem(s) upon host volume group vgnetapp_orafile.

--[ INFO] SD-00040: Beginning to discover filesystem(s) upon host volume group vgnetapp_archive.

--[ INFO] SD-00041: Finished discovering filesystem(s) upon host volume group vgnetapp_archive.

--[ INFO] SD-00040: Beginning to discover filesystem(s) upon host volume group vgnetapp_SMO_data.

--[ INFO] SD-00041: Finished discovering filesystem(s) upon host volume group vgnetapp_SMO_data.

--[ INFO] SD-00052: Beginning preview of volume restore of [stona01:/vol/test_SMO_data] (with host-side resources [vgnetapp_SMO_data]) from snapshots [[smo_testsmo_testsmo_f_h_1_8a2aa0b23088f755013088f75f220001_0]]

--[ INFO] SD-10030: Waiting for SnapDrive job (running)

--[ INFO] SD-10030: Waiting for SnapDrive job (completed)

--[ INFO] SD-00053: Finished preview of volume restore of [stona01:/vol/test_SMO_data] (with host-side resources [vgnetapp_SMO_data]) from snapshots [[smo_testsmo_testsmo_f_h_1_8a2aa0b23088f755013088f75f220001_0]]

--[ INFO] SD-00054: Beginning volume restore of [stona01:/vol/test_SMO_data] (with host-side resources [vgnetapp_SMO_data]) from snapshots [[smo_testsmo_testsmo_f_h_1_8a2aa0b23088f755013088f75f220001_0]]

--[ INFO] SD-10030: Waiting for SnapDrive job (running)

--[ INFO] SD-10030: Waiting for SnapDrive job (completed)

--[ INFO] SD-00055: Finished volume restore of [stona01:/vol/test_SMO_data] (with host-side resources [vgnetapp_SMO_data]) from snapshots [[smo_testsmo_testsmo_f_h_1_8a2aa0b23088f755013088f75f220001_0]]

--[ INFO] ORACLE-30008: Beginning recovery process for database TESTSMO.

--[ INFO] ORACLE-30010: Database recovery point objective: latest committed transaction for the incarnation

--[ INFO] ORACLE-30017: Recovery point objective of latest committed transaction for the incarnation reached after applying archived/online redo logs [/controlredo/TESTSMO/redo02.log].

--[ INFO] ORACLE-20000: Changing state for database instance TESTSMO from MOUNTED to OPEN.

--[ INFO] ORACLE-20032: Opening database TESTSMO with NORESETLOGS option.

--[ INFO] SMO-07131: Unlocked database for SnapManager operations - removed lock file "/SMO/oracle/product/10.2.0/dbs/.sm_lock_TESTSMO" on host stodb08.networklogon.net.

--[ INFO] SMO-07433: Returning the database to its initial state: TESTSMO(SHUTDOWN).

--[ INFO] ORACLE-20000: Changing state for database instance TESTSMO from OPEN to SHUTDOWN.

--[ INFO] SMO-13048: Backup Restore Operation Status: SUCCESS

--[ INFO] SMO-13049: Elapsed Time: 0:05:30.136

--[ INFO] Operation Id [8a2aa0b2308dee8f01308dee97ea0001] succeeded.

Best regard

Tien

thomas_glodde · ‎2011-06-14

Seems its waiting for SnapDrive to get its job done. you might want to check /var/log/sd-trace.log for any outputs. I have seen it in the past that snapdrive operations might take plenty of time if DNS/IP/Hostname stuff is messed up or not properly resolveable.

3GISSMORACLE · ‎2011-06-14

Hi Thomas,

I've haven't installed Protection Manager yet into the server. Can you please show me how to configure SnapDrive so that I can user it for SnapManager ?

[ INFO] SMO-17101: SnapManager Server internal RMI registry started on port 2721 5.

[ INFO] SMO-13048: Status Operation Status: SUCCESS

[ INFO] SMO-13049: Elapsed Time: 0:00:00.186

[ INFO] SMO-13048: Status Operation Status: SUCCESS

[ INFO] SMO-13049: Elapsed Time: 0:00:00.149

[ERROR] SMO-05500: Unable to list the protection policies for the following reason: SMO-01602: Protection Manager product is not installed or SnapDrive is not configured to use it. Please install Protection Manager and/or configure SnapDrive.

[ERROR] SMO-13032: Cannot perform operation: Protection Policy List. Root cause: SMO-05500: Unable to list the protection policies for the following reason: SMO-01602: Protection Manager product is not installed or SnapDrive is not configured to use it. Please install Protection Manager and/or configure SnapDrive.

[ INFO] SMO-13039: Successfully aborted operation: Protection Policy List

[ERROR] SMO-13048: Protection Policy List Operation Status: FAILED

[ INFO] SMO-13049: Elapsed Time: 0:00:08.354

[ INFO] SMO-13048: Status Operation Status: SUCCESS

[ INFO] SMO-13049: Elapsed Time: 0:00:00.104

[ INFO] SMO-13048: Status Operation Status: SUCCESS

[ INFO] SMO-13049: Elapsed Time: 0:00:00.197

[ INFO] SMO-13048: Status Operation Status: SUCCESS

[ INFO] SMO-13049: Elapsed Time: 0:00:00.104

[ INFO] SMO-13048: Status Operation Status: SUCCESS

[ INFO] SMO-13049: Elapsed Time: 0:00:00.112

[ INFO] SMO-13048: Status Operation Status: SUCCESS

[ INFO] SMO-13049: Elapsed Time: 0:00:00.121

[ERROR] SMO-05500: Unable to list the protection policies for the following reason: SMO-01602: Protection Manager product is not installed or SnapDrive is not configured to use it. Please install Protection Manager and/or configure SnapDrive.

[ERROR] SMO-13032: Cannot perform operation: Protection Policy List. Root cause: SMO-05500: Unable to list the protection policies for the following reason: SMO-01602: Protection Manager product is not installed or SnapDrive is not configured to use it. Please install Protection Manager and/or configure SnapDrive.

[ INFO] SMO-13039: Successfully aborted operation: Protection Policy List

[ERROR] SMO-13048: Protection Policy List Operation Status: FAILED

[ INFO] SMO-13049: Elapsed Time: 0:00:04.118

[ INFO] SMO-13048: Status Operation Status: SUCCESS

[ INFO] SMO-13049: Elapsed Time: 0:00:00.100

[ INFO] SMO-13048: Status Operation Status: SUCCESS

[ INFO] SMO-13049: Elapsed Time: 0:00:00.117

[ INFO] SMO-13048: Status Operation Status: SUCCESS

[ INFO] SMO-13049: Elapsed Time: 0:00:00.134

[ INFO] SMO-13048: Status Operation Status: SUCCESS

[ INFO] SMO-13049: Elapsed Time: 0:00:00.099

Best Regard

Tien

jakub_wartak · ‎2011-06-15

Hi,

It's typical time for a restore from local snaps (5-10-15 minutes) depending on the scale of deployment. If everything is working ok, then there should be no copying of the data involved, and that means it is also going to be same time for large databases (1TB and larger). However if SMO would start doing a old fashion copy then it takes a lot of time; same for restores from SnapVault (copying is involved, depends on the size of the data to be copied).

-Jakub.

3GISSMORACLE · ‎2011-06-16

Hi Jakub,

I'm sorry for not replying you immediatly. I've restored with 3 test-databases with the different sizes : 5Gb , 14 Gb and 127Gb . The result is exact as you said . It take about 5 min to restore these databases and no copying was involved while volume were restoring .

Thank you for your support on the recent days .

Have a nice day!!!

Best regard

Tien

thomas_glodde · ‎2011-06-16

Jakub,

you have ProtectionManager installed? According to the log, Tiens installation seems to timeout on the PM stuff, same might happen for you, it might speed up the restore if configured properly? afaik restores for our customers usualy do not take that long unless its a massive RAC environment.

How long does a backup take for you guys usualy? In our customers environment its usualy between 1-3 minutes for a full hotbackup.

Regards,

Thomas

3GISSMORACLE · ‎2011-06-17

Hi Thomas ,

For my test-databases it takes 2 min to take full hotbackup of databases without ProtectionManager installation. If I installed it I wonder if it'd speed up the restore/backup time ?

Regards

Tien

jcosta · ‎2011-07-13

the time to backup really depends on a number of factors:

the OS (snapdrive for windows is faster than SDU)

the protocol (nfs will always be faster that block protocols)

rman integration enabled vs not enabled

protection manager integration

the number of LUNs and path's for those luns, as SDU will enumerate them in order to find all required objects to backup/restore.

on windows platforms I can easily see ~2minutes withouth RMAN

on linux - NFS - and FC - roughly the same amount of time

on other unixs with FC, times increase as the number of filesystems and luns increase.

typically hpux is the slowest as its is common to have ~50-100 luns on a hpux-host with 2-4 paths.

jakub_wartak · ‎2011-06-17

Well, IMHO it is not really an error - it just an indication that DFM is not configured in "snapdrive config list" output. The biggest factors contributing to fast restore time from local snaps in my enviorniment were always:

a) operations at the LVM level [Snapdrive]

b) discovery of the LUNs after storage disconnects [Snapdrive]

c) processing "speed" of the CPUs vs number of FlexVols/LUNs on the storage [Snapdrive]

d) host name resolution times

e) logging level of SMSAP/SDU

f) size of the Oracle active redo log files (in resetlogs operations that needs to be overwritten)

Of course if we start talking about restores from SnapVault relationships, it's a different story then due to the copying from remote storage controller.

-J.