近日客户报多套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时刻正常运行,有太多指标需要我们去关注,良好的规范很重要,同时很多时候我们不得不和硬件打交道。