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