我们的文章会在微信公众号IT民工的龙马人生和博客网站( www.htz.pw )同步更新 ，欢迎关注收藏，也欢迎大家转载，但是请在文章开始地方标注文章出处，谢谢！
由于博客中有大量代码，通过页面浏览效果更佳。
学习笔记：一次RMAN还原慢的分析
下面是模拟同事在客户现场遇到的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 ProductionPL/SQL Release 11.2.0.3.0 – ProductionCORE 11.2.0.3.0 ProductionTNS for 64-bit Windows: Version 11.2.0.3.0 – ProductionNLSRTL Version 11.2.0.3.0 – Productionwww.htz.pw > host uname -awindows32 luoping 2.6.1 7601 i686-pc Intel unknown MinGW
2，测试数据创建
这里创建了多个表空间，用于模拟生产环境
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;2.2 创建测试表
create table htz.htz01 tablespace htz01 as select * from dba_objects;.……………….create table htz.htz25 tablespace htz25 as select * from dba_objects;
2.3 配置归档
SQL> shutdown immediate;Database closed.Database dismounted.ORACLE instance shut down.SQL> startup mount;ORACLE instance started.Total System Global Area 392495104 bytesFixed Size 2255544 bytesVariable Size 155190600 bytesDatabase Buffers 226492416 bytesRedo Buffers 8556544 bytesDatabase mounted.SQL> alter database archivelog;Database altered.SQL> alter database open;Database altered.
2.4 配置备份脚本
由于备份脚本的内容太多，就不贴出来了，只贴了rman的命令
RUN {ALLOCATE CHANNEL ch00 TYPE DISK;ALLOCATE CHANNEL ch01 TYPE DISK;BACKUPINCREMENTAL Level=0FORMAT ‘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 logsALLOCATE CHANNEL ch00 TYPE DISK;BACKUPFILESPERSET 20FORMAT ‘d:\shell\arch-s%s-p%p-t%t’ARCHIVELOG ALL;RELEASE CHANNEL ch00;ALLOCATE CHANNEL ch00 TYPE DISK;BACKUPFORMAT ‘d:\shell\cntrl_p_t’CURRENT CONTROLFILE;RELEASE CHANNEL ch00;}d:\shell>hot_database.cmdRMAN> 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.cmdRecovery Manager: Release 11.2.0.3.0 – Production on Sun Sep 21 23:53:06 2014Copyright (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 catalogRMAN> 2> 3> 4> 5> 6> 7> 8> 9> 10> 11> 12> 13> 14> 15> 16> 17> 18> 19> 20> 21> 22> 23>allocated channel: ch00channel ch00: SID=134 device type=DISKallocated channel: ch01channel ch01: SID=199 device type=DISKStarting backup at 2014-09-21:23:53:07channel ch00: starting incremental level 0 datafile backup setchannel ch00: specifying datafile(s) in backup setinput datafile file number=00001 name=D:\APP\LUOPING\ORADATA\HTZ\SYSTEM01.DBFinput datafile file number=00012 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ08.DBFinput datafile file number=00014 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ10.DBFinput datafile file number=00016 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ12.DBFinput datafile file number=00018 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ14.DBFinput datafile file number=00020 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ16.DBFinput datafile file number=00022 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ18.DBFinput datafile file number=00023 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ19.DBFinput datafile file number=00024 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ20.DBFinput datafile file number=00025 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ21.DBFinput datafile file number=00026 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ22.DBFinput datafile file number=00027 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ23.DBFinput datafile file number=00028 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ24.DBFinput datafile file number=00029 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ25.DBFchannel ch00: starting piece 1 at 2014-09-21:23:53:07channel ch01: starting incremental level 0 datafile backup setchannel ch01: specifying datafile(s) in backup setinput datafile file number=00002 name=D:\APP\LUOPING\ORADATA\HTZ\SYSAUX01.DBFinput datafile file number=00003 name=D:\APP\LUOPING\ORADATA\HTZ\UNDOTBS01.DBFinput datafile file number=00004 name=D:\APP\LUOPING\ORADATA\HTZ\USERS01.DBFinput datafile file number=00005 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ01.DBFinput datafile file number=00006 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ02.DBFinput datafile file number=00007 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ03.DBFinput datafile file number=00008 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ04.DBFinput datafile file number=00009 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ05.DBFinput datafile file number=00010 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ06.DBFinput datafile file number=00011 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ07.DBFinput datafile file number=00013 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ09.DBFinput datafile file number=00015 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ11.DBFinput datafile file number=00017 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ13.DBFinput datafile file number=00019 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ15.DBFinput datafile file number=00021 name=D:\APP\LUOPING\ORADATA\HTZ\HTZ17.DBFchannel ch01: starting piece 1 at 2014-09-21:23:53:08channel ch00: finished piece 1 at 2014-09-21:23:53:23piece handle=D:\SHELL\BK_U0FPJ3JF3_S15_P1_T858901987 tag=TAG20140921T235307 comment=NONEchannel ch00: backup set complete, elapsed time: 00:00:16channel ch00: starting incremental level 0 datafile backup setchannel ch00: specifying datafile(s) in backup setchannel ch01: finished piece 1 at 2014-09-21:23:53:23piece handle=D:\SHELL\BK_U0GPJ3JF3_S16_P1_T858901987 tag=TAG20140921T235307 comment=NONEchannel ch01: backup set complete, elapsed time: 00:00:15channel ch01: starting incremental level 0 datafile backup setchannel ch01: specifying datafile(s) in backup setincluding current SPFILE in backup setchannel ch01: starting piece 1 at 2014-09-21:23:53:23including current control file in backup setchannel ch00: starting piece 1 at 2014-09-21:23:53:24channel ch01: finished piece 1 at 2014-09-21:23:53:24piece handle=D:\SHELL\BK_U0IPJ3JFJ_S18_P1_T858902003 tag=TAG20140921T235307 comment=NONEchannel ch01: backup set complete, elapsed time: 00:00:01channel ch00: finished piece 1 at 2014-09-21:23:53:25piece handle=D:\SHELL\BK_U0HPJ3JFJ_S17_P1_T858902003 tag=TAG20140921T235307 comment=NONEchannel ch00: backup set complete, elapsed time: 00:00:01Finished backup at 2014-09-21:23:53:25
通过日志，可以看到生成了2个备份片的信息
3，还原测试
同样由于还原脚本内容太多，这里只贴了还原命令
3.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.cmdRecovery Manager: Release 11.2.0.3.0 – Production on Sun Sep 21 23:59:14 2014Copyright (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 catalogRMAN> 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: ch00channel ch00: SID=129 device type=DISKallocated channel: ch01channel ch01: SID=192 device type=DISKStarting restore at 2014-09-21:23:59:15channel ch00: starting datafile backup set restorechannel ch00: specifying datafile(s) to restore from backup setchannel ch00: restoring datafile 00001 to D:\APP\LUOPING\ORADATA\HTZ\SYSTEM01.DBFchannel ch00: reading from backup piece D:\SHELL\BK_U0FPJ3JF3_S15_P1_T858901987channel ch00: piece handle=D:\SHELL\BK_U0FPJ3JF3_S15_P1_T858901987 tag=TAG20140921T235307channel ch00: restored backup piece 1channel ch00: restore complete, elapsed time: 00:00:07Finished restore at 2014-09-21:23:59:23……channel ch00: starting datafile backup set restorechannel ch00: specifying datafile(s) to restore from backup setchannel ch00: restoring datafile 00007 to D:\APP\LUOPING\ORADATA\HTZ\HTZ03.DBFchannel ch00: reading from backup piece D:\SHELL\BK_U0GPJ3JF3_S16_P1_T858901987channel ch00: piece handle=D:\SHELL\BK_U0GPJ3JF3_S16_P1_T858901987 tag=TAG20140921T235307channel ch00: restored backup piece 1channel ch00: restore complete, elapsed time: 00:00:01Finished restore at 2014-09-21:23:59:32Starting restore at 2014-09-21:23:59:32channel ch00: starting datafile backup set restorechannel ch00: specifying datafile(s) to restore from backup setchannel ch00: restoring datafile 00008 to D:\APP\LUOPING\ORADATA\HTZ\HTZ04.DBFchannel ch00: reading from backup piece D:\SHELL\BK_U0GPJ3JF3_S16_P1_T858901987channel ch00: piece handle=D:\SHELL\BK_U0GPJ3JF3_S16_P1_T858901987 tag=TAG20140921T235307channel ch00: restored backup piece 1channel ch00: restore complete, elapsed time: 00:00:01Finished restore at 2014-09-21:23:59:33Starting restore at 2014-09-21:23:59:33channel ch00: starting datafile backup set restorechannel ch00: specifying datafile(s) to restore from backup setchannel ch00: restoring datafile 00009 to D:\APP\LUOPING\ORADATA\HTZ\HTZ05.DBFchannel ch00: reading from backup piece D:\SHELL\BK_U0GPJ3JF3_S16_P1_T858901987channel ch00: piece handle=D:\SHELL\BK_U0GPJ3JF3_S16_P1_T858901987 tag=TAG20140921T235307channel ch00: restored backup piece 1channel ch00: restore complete, elapsed time: 00:00:01Finished restore at 2014-09-21:23:59:34Starting restore at 2014-09-21:23:59:34channel ch00: starting datafile backup set restorechannel ch00: specifying datafile(s) to restore from backup setchannel ch00: restoring datafile 00010 to D:\APP\LUOPING\ORADATA\HTZ\HTZ06.DBFchannel ch00: reading from backup piece D:\SHELL\BK_U0GPJ3JF3_S16_P1_T858901987channel ch00: piece handle=D:\SHELL\BK_U0GPJ3JF3_S16_P1_T858901987 tag=TAG20140921T235307channel ch00: restored backup piece 1channel ch00: restore complete, elapsed time: 00:00:01Finished restore at 2014-09-21:23:59:35Starting restore at 2014-09-21:23:59:35channel ch00: starting datafile backup set restorechannel ch00: specifying datafile(s) to restore from backup setchannel ch00: restoring datafile 00011 to D:\APP\LUOPING\ORADATA\HTZ\HTZ07.DBFchannel ch00: reading from backup piece D:\SHELL\BK_U0GPJ3JF3_S16_P1_T858901987channel ch00: piece handle=D:\SHELL\BK_U0GPJ3JF3_S16_P1_T858901987 tag=TAG20140921T235307channel ch00: restored backup piece 1channel ch00: restore complete, elapsed time: 00:00:01Finished restore at 2014-09-21:23:59:36Starting restore at 2014-09-21:23:59:36channel ch00: starting datafile backup set restorechannel ch00: specifying datafile(s) to restore from backup setchannel ch00: restoring datafile 00012 to D:\APP\LUOPING\ORADATA\HTZ\HTZ08.DBFchannel ch00: reading from backup piece D:\SHELL\BK_U0FPJ3JF3_S15_P1_T858901987channel ch00: piece handle=D:\SHELL\BK_U0FPJ3JF3_S15_P1_T858901987 tag=TAG20140921T235307channel ch00: restored backup piece 1channel ch00: restore complete, elapsed time: 00:00:01Finished restore at 2014-09-21:23:59:37Starting restore at 2014-09-21:23:59:37channel ch00: starting datafile backup set restorechannel ch00: specifying datafile(s) to restore from backup setchannel ch00: restoring datafile 00013 to D:\APP\LUOPING\ORADATA\HTZ\HTZ09.DBFchannel ch00: reading from backup piece D:\SHELL\BK_U0GPJ3JF3_S16_P1_T858901987channel ch00: piece handle=D:\SHELL\BK_U0GPJ3JF3_S16_P1_T858901987 tag=TAG20140921T235307channel ch00: restored backup piece 1channel ch00: restore complete, elapsed time: 00:00:01Finished restore at 2014-09-21:23:59:39Starting restore at 2014-09-21:23:59:39channel ch00: starting datafile backup set restorechannel ch00: specifying datafile(s) to restore from backup setchannel ch00: restoring datafile 00014 to D:\APP\LUOPING\ORADATA\HTZ\HTZ10.DBFchannel ch00: reading from backup piece D:\SHELL\BK_U0FPJ3JF3_S15_P1_T858901987channel ch00: piece handle=D:\SHELL\BK_U0FPJ3JF3_S15_P1_T858901987 tag=TAG20140921T235307channel ch00: restored backup piece 1channel ch00: restore complete, elapsed time: 00:00:01Finished restore at 2014-09-21:23:59:40Starting restore at 2014-09-21:23:59:40channel ch00: starting datafile backup set restorechannel ch00: specifying datafile(s) to restore from backup setchannel ch00: restoring datafile 00015 to D:\APP\LUOPING\ORADATA\HTZ\HTZ11.DBFchannel ch00: reading from backup piece D:\SHELL\BK_U0GPJ3JF3_S16_P1_T858901987channel ch00: piece handle=D:\SHELL\BK_U0GPJ3JF3_S16_P1_T858901987 tag=TAG20140921T235307channel ch00: restored backup piece 1channel ch00: restore complete, elapsed time: 00:00:01Finished restore at 2014-09-21:23:59:41…………………..
3.2 其中一个备份片来看
channel ch00: reading from backup piece D:\SHELL\BK_U0FPJ3JF3_S15_P1_T858901987channel ch00: reading from backup piece D:\SHELL\BK_U0FPJ3JF3_S15_P1_T858901987channel ch00: reading from backup piece D:\SHELL\BK_U0FPJ3JF3_S15_P1_T858901987channel ch00: reading from backup piece D:\SHELL\BK_U0FPJ3JF3_S15_P1_T858901987channel ch00: reading from backup piece D:\SHELL\BK_U0FPJ3JF3_S15_P1_T858901987channel ch00: reading from backup piece D:\SHELL\BK_U0FPJ3JF3_S15_P1_T858901987channel ch00: reading from backup piece D:\SHELL\BK_U0FPJ3JF3_S15_P1_T858901987channel ch00: reading from backup piece D:\SHELL\BK_U0FPJ3JF3_S15_P1_T858901987channel ch00: reading from backup piece D:\SHELL\BK_U0FPJ3JF3_S15_P1_T858901987channel ch00: reading from backup piece D:\SHELL\BK_U0FPJ3JF3_S15_P1_T858901987channel ch00: reading from backup piece D:\SHELL\BK_U0FPJ3JF3_S15_P1_T858901987channel ch00: reading from backup piece D:\SHELL\BK_U0FPJ3JF3_S15_P1_T858901987channel ch00: reading from backup piece D:\SHELL\BK_U0FPJ3JF3_S15_P1_T858901987channel ch00: reading from backup piece D:\SHELL\BK_U0FPJ3JF3_S15_P1_T858901987
在整个还原中，读了这么多次备份片，因为每一个restore命令就会去读还原片的信息，这就是慢的原因所在了。特别是在生产环境中，都是备份到磁带中的，还原不慢才怪。
下面计算一下还原的时间
Starting restore at 2014-09-21:23:59:15Finished restore at 2014-09-21:23:59:57
第一次还原使用了42S的时间，因为BUFFER的影响，多次测试，时间都差不多。
4, 使用一条命令来还原
RUN {ALLOCATE CHANNEL ch00 TYPE DISK;ALLOCATE CHANNEL ch01 TYPE DISK;RESTORE DATABASE;RELEASE CHANNEL ch00;RELEASE CHANNEL ch01;}d:\shell>restore.cmdRMAN> 2> 3> 4> 5> 6> 7> RMAN> LOGMSGDATERMAN_LOG_FILE
后台日志内容如下：
cript name: restore.cmdRecovery Manager: Release 11.2.0.3.0 – Production on Mon Sep 22 00:06:23 2014Copyright (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 catalogRMAN> 2> 3> 4> 5> 6> 7>allocated channel: ch00channel ch00: SID=129 device type=DISKallocated channel: ch01channel ch01: SID=191 device type=DISKStarting restore at 2014-09-22:00:06:24………………..
还原的时间，每一次测试
Starting restore at 2014-09-22:00:35:51Finished restore at 2014-09-22:00:36:07
第二次测试
Starting restore at 2014-09-22:00:37:06Finished restore at 2014-09-22:00:37:23
这里看到两次的时间都不到20S，远远小于之前的时间。
5，实验总结
在做rman还原的时候，尽量把命令写在一个restore命令中，减少对相同备份片进行重复的读取工作。另外整个实验需要注意的是：没有考虑一个数据文件写到一个备份片的情况。
------------------作者介绍-----------------------
姓名：黄廷忠
现就职：Oracle中国高级服务团队
曾就职：OceanBase、云和恩墨、东方龙马等
电话、微信、QQ：18081072613
个人博客: (http://www.htz.pw)
CSDN地址: (https://blog.csdn.net/wwwhtzpw)
博客园地址: (https://www.cnblogs.com/www-htz-pw)
