原文链接:点击打开链接
下面是模拟同事在客户现场遇到的RMAN还原慢的情况,同事也只能在旁边干着急。因为备份与还原是由其它的备份工程师在操作,但是由于备份工程师的ORACLE技术能力,导致在还原数据库速度很慢。我们知道,RMAN备份与还原也是可以通过配置参数来提到性能,如果是通过备份软件,还可以通过调用备份软件的BUFFER来实现,多路复用等机制来优化,如果数据文件存放在ASM环境中,现在ORACLE可以自动优化RMAN相关的ORACLE参数。然后,这次同事遇到的RMAN还原慢的主要原因不是由于RMAN的参数,下面我们通过模拟要证明,是什么原因导致整个备份速度慢。
这里将备份集存放在磁盘上,没有模拟磁带的情况。
1,环境介绍
www.htz.pw > select * from v$version;
BANNER ——————————————————————————– Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 – 64bit Production PL/SQL Release 11.2.0.3.0 – Production CORE 11.2.0.3.0 Production TNS for 64-bit Windows: Version 11.2.0.3.0 – Production NLSRTL Version 11.2.0.3.0 – Production www.htz.pw > host uname -a windows32 luoping 2.6.1 7601 i686-pc Intel unknown MinGW |
2,测试数据创建
这里创建了多个表空间,用于模拟生产环境
1,创建多个表空间 create tablespace htz01 datafile ‘D:\APP\LUOPING\ORADATA\HTZ\HTZ01.DBF’ size 10M; .………… create tablespace htz25 datafile ‘D:\APP\LUOPING\ORADATA\HTZ\HTZ25.DBF’ size 10M;
创建测试表 create table htz.htz01 tablespace htz01 as select * from dba_objects; .………………. create table htz.htz25 tablespace htz25 as select * from dba_objects; |
3,配置归档
SQL> shutdown immediate; Database closed. Database dismounted. ORACLE instance shut down. SQL> startup mount; ORACLE instance started.
Total System Global Area 392495104 bytes Fixed Size 2255544 bytes Variable Size 155190600 bytes Database Buffers 226492416 bytes Redo Buffers 8556544 bytes Database mounted. SQL> alter database archivelog; Database altered. SQL> alter database open; Database altered. |
4,配置备份脚本
由于备份脚本的内容太多,就不贴出来了,只贴了rman的命令
RUN { ALLOCATE CHANNEL ch00 TYPE DISK; ALLOCATE CHANNEL ch01 TYPE DISK; BACKUP INCREMENTAL Level=0 FORMAT ‘d:\shell\bk_u%u_s%s_p%p_t%t’ DATABASE; sql ‘alter system archive log current’; RELEASE CHANNEL ch00; RELEASE CHANNEL ch01; # Backup all archive logs ALLOCATE CHANNEL ch00 TYPE DISK; BACKUP FILESPERSET 20 FORMAT ‘d:\shell\arch-s%s-p%p-t%t’ ARCHIVELOG ALL; RELEASE CHANNEL ch00; ALLOCATE CHANNEL ch00 TYPE DISK; BACKUP FORMAT ‘d:\shell\cntrl_p_t’ CURRENT CONTROLFILE; RELEASE CHANNEL ch00; }
d:\shell>hot_database.cmd RMAN> 2> 3> 4> 5> 6> 7> 8> 9> 10> 11> 12> 13> 14> 15> 16> 17> 18> 19> 20> 21> 22> 23> RMAN> LOGMSGDATERMAN_LOG_FILE |
rman备份日志输出内容
==== started on 2014/09/21 周日 23:53 ==== Script name: hot_database.cmd
Recovery Manager: Release 11.2.0.3.0 – Production on Sun Sep 21 23:53:06 2014
Copyright (c) 1982, 2011, Oracle and/or its affiliates. All rights reserved.
connected to target database: HTZ (DBID=1913545637) using target database control file instead of recovery catalog
RMAN> 2> 3> 4> 5> 6> 7> 8> 9> 10> 11> 12> 13> 14> 15> 16> 17> 18> 19> 20> 21> 22> 23> allocated channel: ch00 channel ch00: SID=134 device type=DISK
allocated channel: ch01 channel ch01: SID=199 device type=DISK
Starting backup at 2014-09-21:23:53:07 channel ch00: starting incremental level 0 datafile backup set channel ch00: specifying datafile(s) in backup set input datafile file number=00001 name=D:\APP\LUOPING\ORADATA\HTZ\SYSTEM01.DBF input datafile file number=00012 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ08.DBF input datafile file number=00014 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ10.DBF input datafile file number=00016 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ12.DBF input datafile file number=00018 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ14.DBF input datafile file number=00020 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ16.DBF input datafile file number=00022 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ18.DBF input datafile file number=00023 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ19.DBF input datafile file number=00024 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ20.DBF input datafile file number=00025 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ21.DBF input datafile file number=00026 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ22.DBF input datafile file number=00027 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ23.DBF input datafile file number=00028 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ24.DBF input datafile file number=00029 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ25.DBF channel ch00: starting piece 1 at 2014-09-21:23:53:07 channel ch01: starting incremental level 0 datafile backup set channel ch01: specifying datafile(s) in backup set input datafile file number=00002 name=D:\APP\LUOPING\ORADATA\HTZ\SYSAUX01.DBF input datafile file number=00003 name=D:\APP\LUOPING\ORADATA\HTZ\UNDOTBS01.DBF input datafile file number=00004 name=D:\APP\LUOPING\ORADATA\HTZ\USERS01.DBF input datafile file number=00005 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ01.DBF input datafile file number=00006 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ02.DBF input datafile file number=00007 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ03.DBF input datafile file number=00008 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ04.DBF input datafile file number=00009 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ05.DBF input datafile file number=00010 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ06.DBF input datafile file number=00011 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ07.DBF input datafile file number=00013 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ09.DBF input datafile file number=00015 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ11.DBF input datafile file number=00017 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ13.DBF input datafile file number=00019 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ15.DBF input datafile file number=00021 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ17.DBF channel ch01: starting piece 1 at 2014-09-21:23:53:08 channel ch00: finished piece 1 at 2014-09-21:23:53:23 piece handle=D:\SHELL\BK_U0FPJ3JF3_S15_P1_T858901987 tag=TAG20140921T235307 comment=NONE channel ch00: backup set complete, elapsed time: 00:00:16 channel ch00: starting incremental level 0 datafile backup set channel ch00: specifying datafile(s) in backup set channel ch01: finished piece 1 at 2014-09-21:23:53:23 piece handle=D:\SHELL\BK_U0GPJ3JF3_S16_P1_T858901987 tag=TAG20140921T235307 comment=NONE channel ch01: backup set complete, elapsed time: 00:00:15 channel ch01: starting incremental level 0 datafile backup set channel ch01: specifying datafile(s) in backup set including current SPFILE in backup set channel ch01: starting piece 1 at 2014-09-21:23:53:23 including current control file in backup set channel ch00: starting piece 1 at 2014-09-21:23:53:24 channel ch01: finished piece 1 at 2014-09-21:23:53:24 piece handle=D:\SHELL\BK_U0IPJ3JFJ_S18_P1_T858902003 tag=TAG20140921T235307 comment=NONE channel ch01: backup set complete, elapsed time: 00:00:01 channel ch00: finished piece 1 at 2014-09-21:23:53:25 piece handle=D:\SHELL\BK_U0HPJ3JFJ_S17_P1_T858902003 tag=TAG20140921T235307 comment=NONE channel ch00: backup set complete, elapsed time: 00:00:01 Finished backup at 2014-09-21:23:53:25 |
通过日志,可以看到生成了2个备份片的信息
5,还原测试
同样由于还原脚本内容太多,这里只贴了还原命令
5.1 备份工程师还原脚本模拟
RUN { ALLOCATE CHANNEL ch00 TYPE DISK; ALLOCATE CHANNEL ch01 TYPE DISK; RESTORE DATAFILE 1 ; RESTORE DATAFILE 2 ; RESTORE DATAFILE 3 ; RESTORE DATAFILE 4 ; RESTORE DATAFILE 5 ; RESTORE DATAFILE 6 ; RESTORE DATAFILE 7 ; RESTORE DATAFILE 8 ; RESTORE DATAFILE 9 ; RESTORE DATAFILE 10; RESTORE DATAFILE 11; RESTORE DATAFILE 12; RESTORE DATAFILE 13; RESTORE DATAFILE 14; RESTORE DATAFILE 15; RESTORE DATAFILE 16; RESTORE DATAFILE 17; RESTORE DATAFILE 18; RESTORE DATAFILE 19; RESTORE DATAFILE 20; RESTORE DATAFILE 21; RESTORE DATAFILE 22; RESTORE DATAFILE 23; RESTORE DATAFILE 24; RESTORE DATAFILE 25; RESTORE DATAFILE 26; RESTORE DATAFILE 27; RESTORE DATAFILE 28; RESTORE DATAFILE 29; RELEASE CHANNEL ch00; RELEASE CHANNEL ch01; } d:\shell>restore.cmd RMAN> 2> 3> 4> 5> 6> 7> 8> 9> 10> 11> 12> 13> 14> 15> 16> 17> 18> 19> 20> 21> 22> 23> 24> 25> 26> 27> 28> 29> 30> 31> 32> 33> 34> 35> RMAN> LOGMSGDATERMAN_LOG_FILE |
这里可以看到,每个数据文件都是一个单独的restore来还原。
下面来看看生成的日志内容
==== started on 2014/09/21 周日 23:59 ==== Script name: restore.cmd
Recovery Manager: Release 11.2.0.3.0 – Production on Sun Sep 21 23:59:14 2014
Copyright (c) 1982, 2011, Oracle and/or its affiliates. All rights reserved.
connected to target database: HTZ (DBID=1913545637, not open) using target database control file instead of recovery catalog
RMAN> 2> 3> 4> 5> 6> 7> 8> 9> 10> 11> 12> 13> 14> 15> 16> 17> 18> 19> 20> 21> 22> 23> 24> 25> 26> 27> 28> 29> 30> 31> 32> 33> 34> 35> allocated channel: ch00 channel ch00: SID=129 device type=DISK
allocated channel: ch01 channel ch01: SID=192 device type=DISK
Starting restore at 2014-09-21:23:59:15
channel ch00: starting datafile backup set restore channel ch00: specifying datafile(s) to restore from backup set channel ch00: restoring datafile 00001 to D:\APP\LUOPING\ORADATA\HTZ\SYSTEM01.DBF channel ch00: reading from backup piece D:\SHELL\BK_U0FPJ3JF3_S15_P1_T858901987 channel ch00: piece handle=D:\SHELL\BK_U0FPJ3JF3_S15_P1_T858901987 tag=TAG20140921T235307 channel ch00: restored backup piece 1 channel ch00: restore complete, elapsed time: 00:00:07 Finished restore at 2014-09-21:23:59:23
…… channel ch00: starting datafile backup set restore channel ch00: specifying datafile(s) to restore from backup set channel ch00: restoring datafile 00007 to D:\APP\LUOPING\ORADATA\HTZ\HTZ03.DBF channel ch00: reading from backup piece D:\SHELL\BK_U0GPJ3JF3_S16_P1_T858901987 channel ch00: piece handle=D:\SHELL\BK_U0GPJ3JF3_S16_P1_T858901987 tag=TAG20140921T235307 channel ch00: restored backup piece 1 channel ch00: restore complete, elapsed time: 00:00:01 Finished restore at 2014-09-21:23:59:32
Starting restore at 2014-09-21:23:59:32
channel ch00: starting datafile backup set restore channel ch00: specifying datafile(s) to restore from backup set channel ch00: restoring datafile 00008 to D:\APP\LUOPING\ORADATA\HTZ\HTZ04.DBF channel ch00: reading from backup piece D:\SHELL\BK_U0GPJ3JF3_S16_P1_T858901987 channel ch00: piece handle=D:\SHELL\BK_U0GPJ3JF3_S16_P1_T858901987 tag=TAG20140921T235307 channel ch00: restored backup piece 1 channel ch00: restore complete, elapsed time: 00:00:01 Finished restore at 2014-09-21:23:59:33
Starting restore at 2014-09-21:23:59:33
channel ch00: starting datafile backup set restore channel ch00: specifying datafile(s) to restore from backup set channel ch00: restoring datafile 00009 to D:\APP\LUOPING\ORADATA\HTZ\HTZ05.DBF channel ch00: reading from backup piece D:\SHELL\BK_U0GPJ3JF3_S16_P1_T858901987 channel ch00: piece handle=D:\SHELL\BK_U0GPJ3JF3_S16_P1_T858901987 tag=TAG20140921T235307 channel ch00: restored backup piece 1 channel ch00: restore complete, elapsed time: 00:00:01 Finished restore at 2014-09-21:23:59:34
Starting restore at 2014-09-21:23:59:34
channel ch00: starting datafile backup set restore channel ch00: specifying datafile(s) to restore from backup set channel ch00: restoring datafile 00010 to D:\APP\LUOPING\ORADATA\HTZ\HTZ06.DBF channel ch00: reading from backup piece D:\SHELL\BK_U0GPJ3JF3_S16_P1_T858901987 channel ch00: piece handle=D:\SHELL\BK_U0GPJ3JF3_S16_P1_T858901987 tag=TAG20140921T235307 channel ch00: restored backup piece 1 channel ch00: restore complete, elapsed time: 00:00:01 Finished restore at 2014-09-21:23:59:35
Starting restore at 2014-09-21:23:59:35
channel ch00: starting datafile backup set restore channel ch00: specifying datafile(s) to restore from backup set channel ch00: restoring datafile 00011 to D:\APP\LUOPING\ORADATA\HTZ\HTZ07.DBF channel ch00: reading from backup piece D:\SHELL\BK_U0GPJ3JF3_S16_P1_T858901987 channel ch00: piece handle=D:\SHELL\BK_U0GPJ3JF3_S16_P1_T858901987 tag=TAG20140921T235307 channel ch00: restored backup piece 1 channel ch00: restore complete, elapsed time: 00:00:01 Finished restore at 2014-09-21:23:59:36
Starting restore at 2014-09-21:23:59:36
channel ch00: starting datafile backup set restore channel ch00: specifying datafile(s) to restore from backup set channel ch00: restoring datafile 00012 to D:\APP\LUOPING\ORADATA\HTZ\HTZ08.DBF channel ch00: reading from backup piece D:\SHELL\BK_U0FPJ3JF3_S15_P1_T858901987 channel ch00: piece handle=D:\SHELL\BK_U0FPJ3JF3_S15_P1_T858901987 tag=TAG20140921T235307 channel ch00: restored backup piece 1 channel ch00: restore complete, elapsed time: 00:00:01 Finished restore at 2014-09-21:23:59:37
Starting restore at 2014-09-21:23:59:37
channel ch00: starting datafile backup set restore channel ch00: specifying datafile(s) to restore from backup set channel ch00: restoring datafile 00013 to D:\APP\LUOPING\ORADATA\HTZ\HTZ09.DBF channel ch00: reading from backup piece D:\SHELL\BK_U0GPJ3JF3_S16_P1_T858901987 channel ch00: piece handle=D:\SHELL\BK_U0GPJ3JF3_S16_P1_T858901987 tag=TAG20140921T235307 channel ch00: restored backup piece 1 channel ch00: restore complete, elapsed time: 00:00:01 Finished restore at 2014-09-21:23:59:39
Starting restore at 2014-09-21:23:59:39
channel ch00: starting datafile backup set restore channel ch00: specifying datafile(s) to restore from backup set channel ch00: restoring datafile 00014 to D:\APP\LUOPING\ORADATA\HTZ\HTZ10.DBF channel ch00: reading from backup piece D:\SHELL\BK_U0FPJ3JF3_S15_P1_T858901987 channel ch00: piece handle=D:\SHELL\BK_U0FPJ3JF3_S15_P1_T858901987 tag=TAG20140921T235307 channel ch00: restored backup piece 1 channel ch00: restore complete, elapsed time: 00:00:01 Finished restore at 2014-09-21:23:59:40
Starting restore at 2014-09-21:23:59:40
channel ch00: starting datafile backup set restore channel ch00: specifying datafile(s) to restore from backup set channel ch00: restoring datafile 00015 to D:\APP\LUOPING\ORADATA\HTZ\HTZ11.DBF channel ch00: reading from backup piece D:\SHELL\BK_U0GPJ3JF3_S16_P1_T858901987 channel ch00: piece handle=D:\SHELL\BK_U0GPJ3JF3_S16_P1_T858901987 tag=TAG20140921T235307 channel ch00: restored backup piece 1 channel ch00: restore complete, elapsed time: 00:00:01 Finished restore at 2014-09-21:23:59:41 ………………….. |
其中一个备份片来看
channel ch00: reading from backup piece D:\SHELL\BK_U0FPJ3JF3_S15_P1_T858901987 channel ch00: reading from backup piece D:\SHELL\BK_U0FPJ3JF3_S15_P1_T858901987 channel ch00: reading from backup piece D:\SHELL\BK_U0FPJ3JF3_S15_P1_T858901987 channel ch00: reading from backup piece D:\SHELL\BK_U0FPJ3JF3_S15_P1_T858901987 channel ch00: reading from backup piece D:\SHELL\BK_U0FPJ3JF3_S15_P1_T858901987 channel ch00: reading from backup piece D:\SHELL\BK_U0FPJ3JF3_S15_P1_T858901987 channel ch00: reading from backup piece D:\SHELL\BK_U0FPJ3JF3_S15_P1_T858901987 channel ch00: reading from backup piece D:\SHELL\BK_U0FPJ3JF3_S15_P1_T858901987 channel ch00: reading from backup piece D:\SHELL\BK_U0FPJ3JF3_S15_P1_T858901987 channel ch00: reading from backup piece D:\SHELL\BK_U0FPJ3JF3_S15_P1_T858901987 channel ch00: reading from backup piece D:\SHELL\BK_U0FPJ3JF3_S15_P1_T858901987 channel ch00: reading from backup piece D:\SHELL\BK_U0FPJ3JF3_S15_P1_T858901987 channel ch00: reading from backup piece D:\SHELL\BK_U0FPJ3JF3_S15_P1_T858901987 channel ch00: reading from backup piece D:\SHELL\BK_U0FPJ3JF3_S15_P1_T858901987 |
在整个还原中,读了这么多次备份片,因为每一个restore命令就会去读还原片的信息,这就是慢的原因所在了。特别是在生产环境中,都是备份到磁带中的,还原不慢才怪。
下面计算一下还原的时间
Starting restore at 2014-09-21:23:59:15 Finished restore at 2014-09-21:23:59:57 |
第一次还原使用了42S的时间,因为BUFFER的影响,多次测试,时间都差不多。
5.2 使用一条命令来还原
RUN { ALLOCATE CHANNEL ch00 TYPE DISK; ALLOCATE CHANNEL ch01 TYPE DISK; RESTORE DATABASE; RELEASE CHANNEL ch00; RELEASE CHANNEL ch01; } d:\shell>restore.cmd RMAN> 2> 3> 4> 5> 6> 7> RMAN> LOGMSGDATERMAN_LOG_FILE |
后台日志内容如下:
cript name: restore.cmd
Recovery Manager: Release 11.2.0.3.0 – Production on Mon Sep 22 00:06:23 2014
Copyright (c) 1982, 2011, Oracle and/or its affiliates. All rights reserved.
connected to target database: HTZ (DBID=1913545637, not open) using target database control file instead of recovery catalog
RMAN> 2> 3> 4> 5> 6> 7> allocated channel: ch00 channel ch00: SID=129 device type=DISK
allocated channel: ch01 channel ch01: SID=191 device type=DISK
Starting restore at 2014-09-22:00:06:24 ……………….. |
还原的时间,每一次测试
Starting restore at 2014-09-22:00:35:51 Finished restore at 2014-09-22:00:36:07 |
第二次测试
Starting restore at 2014-09-22:00:37:06 Finished restore at 2014-09-22:00:37:23 |
这里看到两次的时间都不到20S,远远小于之前的时间。
6,实验总结
在做rman还原的时候,尽量把命令写在一个restore命令中,减少对相同备份片进行重复的读取工作。另外整个实验需要注意的是:没有考虑一个数据文件写到一个备份片的情况。