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