Oracle备份恢复:Rman Backup缓慢问题一例

近日客户报多套10g的数据库在使用NBU磁带备份时出现RMAN FULL BACKUP十分缓慢的问题，这些数据库中最大一个的达到2.61T，该数据库在一个月前地全库0级备份耗时在3-4个小时，而在最近猛涨到17个小时。客户之前已经向Symantec提交了服务请求，但暂时没有得到结论。希望我们从Oracle角度分析该备份速度变慢问题。 我们首先分析了备份信息的动态视图V$rman_backup_job_details:

	OUTPUT_DEVICE	INPUT_TYPE	ELAPSED_SECONDS	INPUT_BYTES_DISPLAY	INPUT_BYTES_PER_SEC	OUTPUT_BYTES_PER_SEC
17	SBT_TAPE	DB INCR	62078	2.61T	44.08M	18.10M

以上可以确认在对2.61T大小的数据库执行全库磁带备份时耗费了62078s，这里还显示了backup时每秒的读取IO为44M，每秒的写出IO为18M；这里不能因为简单的output io per second<input io per second，而断论写出能力存在瓶颈；备份时对数据文件的读取和写出backup piece到备份介质上的操作是一个整体，CPU、Input IO、Output IO任何一环都可能成为备份的瓶颈；譬如因为对数据文件的读取IO存在瓶颈，那么相应的写出IO也会慢下来；又譬如当RMAN与备份服务器之间的IO带宽存在瓶颈，那么相应的读取IO也会不得不慢下来。具体是哪一个环节出现了问题，我们需要求助于其他的RMAN动态性能视图，如: V$BACKUP_SYNC_IO Displays rows when the I/O is synchronous to the process (or thread on some platforms) performing the backup. V$BACKUP_ASYNC_IO Displays rows when the I/O is asynchronous to the process (or thread on some platforms) performing the backup. 以上2个视图的区别在于一个汇聚了使用同步IO执行RMAN备份恢复操作的性能信息，而另一个是异步IO的。 因为客户使用默认配置disk_async_io为true，故而我们首先关注input IO的性能信息，这些信息存放在V$backup_async_io视图中；而对于磁带设备未启用slaves IO模拟的异步IO(tape_asynch_io=true但是backup_tape_io_slaves为默认的false)，所以与磁带设备相关的output IO的性能信息存放在v$backup_sync_io视图中。

DEVICE	OPEN_TIME	ELAPSED	BYTES/S	IO_COUNT	READY	long_waits	LONG_WAIT_TIME_TOTAL	LONG_WAIT_TIME_MAX
DISK	4/4	388900	372827681	2765564	2074114	90028	231181	53
DISK	4/5	753900	192323498	2765564	2074114	90028	178548	41
DISK	4/6	369000	392934106	2765564	2074114	90028	243507	41
DISK	4/7	405100	357918255	2765564	2074114	90028	268117	73
DISK	4/8	347900	416765407	2765564	2074114	90028	183543	77
DISK	4/9	395800	366328159	2765564	2074114	90028	255399	48
DISK	4/10	428400	338451646	2765564	2074114	90028	268544	45
DISK	4/11	413200	350901949	2765564	2074114	90028	269857	42
DISK	4/12	735400	197161661	2765564	2074114	90028	169016	34
DISK	4/13	410000	353640696	2765564	2074114	90028	283607	60
DISK	4/14	408300	355113116	2765564	2074114	90028	279012	38
DISK	4/15	442700	327519054	2765564	2074114	90028	308744	605
DISK	4/16	393000	368938130	2765564	2074114	90028	251509	205
DISK	4/17	423100	342691291	2765564	2074114	90028	273868	42
DISK	4/18	375600	386029513	2765564	2074114	90028	230859	328
DISK	4/19	721200	201043657	2765564	2074114	90028	191753	162
DISK	4/20	401000	361577769	2765564	2074114	90028	272852	147
DISK	4/21	346600	418328578	2765564	2074114	90028	209569	109
DISK	4/22	400500	362029177	2765564	2074114	90028	265060	112
DISK	4/23	402400	360319794	2765564	2074114	90028	259008	594
DISK	4/24	449600	322492627	2765564	2074114	90028	274202	64
DISK	4/25	413900	350308493	2765564	2074114	90028	269380	230
DISK	4/26	748600	193685126	2765564	2074114	90028	177477	105
DISK	4/27	389900	371871468	2765564	2074114	90028	261200	38
DISK	4/28	383800	377781879	2765564	2074114	90028	241870	158
DISK	4/29	403700	359159488	2765564	2074114	90028	266135	212
DISK	4/30	390600	371205031	2765564	2074114	90028	248161	340
DISK	5/1	463600	312753851	2765564	2074114	90028	271247	39
DISK	5/2	419900	345302894	2765564	2074114	90028	255042	117
DISK	5/3	705700	205459381	2765564	2074114	90028	173043	189
DISK	5/4	418400	346540835	2765564	2074114	90028	291614	47
DISK	5/5	357400	405687424	2765564	2074114	90028	222676	188
DISK	5/6	421400	344073767	2765564	2074114	90028	285860	95
DISK	5/7	405100	357918255	2765564	2074114	90028	263761	38
DISK	5/8	381500	380059463	2765564	2074114	90028	203510	210
DISK	5/9	918400	157875311	2765564	2074114	90028	221293	37
DISK	5/10	3378600	42915020	2765564	2074114	90028	142211	36
DISK	5/11	559900	258961753	2765564	2074114	90028	252911	174
DISK	5/12	622500	232919976	2765564	2074114	90028	241495	40
DISK	5/13	626700	231359000	2765564	2074114	90028	237973	41
DISK	5/14	802000	180788884	2765564	2074114	90028	231283	42
DISK	5/15	601200	241172131	2765564	2074114	90028	209418	40
DISK	5/16	1387800	104476643	2765564	2074114	90028	211878	36

这里我们关心的几个时间指标包括:ELAPSED(Input IO的总耗时)、LONG_WAIT_TIME_TOTAL(长IO的总等待时间)、LONG_WAIT_TIME_MAX(最长一次的IO等待时间)的单位均为百分之一秒，该视图的具体定义参考这里。 从以上chart中(由于列宽的原因只截取了部分数据)我们可以看到从4/4到5/16之间备份的Input IO总耗时(elapsed)虽然间歇性的暴涨到过33786s，但其他IO指标:IO总数、READY IO总数、LONG IO WAIT的次数、LONG IO WAIT的总耗时、最长LONG IO WAIT均没有出现大的变化；基本可以判定在备份期间对数据文件的读取不存在瓶颈，为了进一步诊断需要分析备份输出的IO性能状况:

DEVICE	date	ELAPSED	BYTES	BYTES/S	IO_COUNT	IO_TIME_TOTAL	IO_TIME_MAX	DISCRETE_BYTES_PER_SECOND
SBT_TAPE	4/5	754900	584663433216	77449123	2230314	440365	2600	132767916
SBT_TAPE	4/5	703900	553432907776	78623797	2111179	381135	5800	145206530
SBT_TAPE	4/12	736400	588200542208	79875142	2243807	433298	3400	135749655
SBT_TAPE	4/12	692300	556839731200	80433299	2124175	369237	2600	150808216
SBT_TAPE	4/19	722200	591873179648	81954193	2257817	395904	3400	149499166
SBT_TAPE	4/19	829000	561043210240	67677106	2140210	510746	2801	109847793
SBT_TAPE	4/26	749600	596010598400	79510485	2273600	435940	2600	136718493
SBT_TAPE	4/26	700300	565171191808	80704154	2155957	377019	2800	149905228
SBT_TAPE	5/3	706800	600177377280	84914739	2289495	396965	5800	151191510
SBT_TAPE	5/3	712500	569155518464	79881476	2171156	392324	5800	145072827
SBT_TAPE	5/10	3379700	604452159488	17884787	2305802	3093781	2802	19537652
SBT_TAPE	5/10	2798400	573396746240	20490164	2187335	2524296	2801	22715115
SBT_TAPE	5/17		428095307776		1633054	2216291	5800	19315844

可以从以上chart中可以发现到5/3为止的output io总耗时还处于合理范围内(为7068+7125)s，约为4小时。而到了5/10时输出IO的总耗时达到了(33797+29784)s，约为17.6小时。研究其他IO统计信息可以发现5/10的IO_TIME_TOTAL总数为(30937+25242)s，IO_TIME_TOTAL代表了某个IO等待的总耗时，单位为百分之一秒。从另一个IO性能指标DISCRETE_BYTES_PER_SECOND来看，在5/10备份文件的平均传输率急剧下降。 综合上述现象，诱发客户环境中的RMAN全库备份缓慢的主要原因是备份文件输出IO性能在一段时间内急剧下降，瓶颈应当存在于RMAN与NBU备份服务器之间，与数据库读取性能没有关系。给客户的建议是复查数据库服务器到NBU备份服务器间的网络带宽是否正常，NBU服务器的性能是否正常，磁带库的写出性能是否正常。 这个case后续经过对NBU的复查发现原因是虚拟磁带库VTL的存储电池过期，导致读写数据时直接从磁盘上进行，而不经过缓存，故影响了数据库全备份的速度。由于VTL存储电池过期信息需要从串口直接访问其存储才能确认问题，所以在问题发生之初无法从VTL的管理界面中获取该信息。 这个case告诉我们不仅是raid卡的冲放电、存储的ups电池过期会引发严重的IO性能问题，VTL的存储电池过期也可能给数据库备份造成麻烦，要让系统7*24时刻正常运行，有太多指标需要我们去关注，良好的规范很重要，同时很多时候我们不得不和硬件打交道。