案例概述
一个X3-2 的Exadata临时客户,ORACLE原厂工程师在进行onecommand初始化的过程中,执行到第6步,calibrate检测存储节点磁盘性能时报错,后续工作无法继续。而由于一些商务上的原因,原厂的硬件工程师无法提供技术支持。
客户最终找到了我们,希望我们能帮着一起分析分析,存储节点磁盘的性能是否存在问题。在问题转给我之前,客户自己也做了大量的换盘和测试工作。目前存储节点使用calibrate检测的结果正常,但插槽0 或 插槽1 的MBPS偶尔比其它的磁盘低十几MB左右,但还是在可以接受的范围之内。
目前,客户主要有两个疑问,需要我进行解释:
1、测试过程中以前一些表现比较差的磁盘,为什么将这类磁盘更换到其它的存储节点后再次测试,性能又能恢复正常?
2、现在的插槽 0 或 插槽 1 的磁盘MBPS偶尔比其它的磁盘低十几MB左右,是否正常?
问题分析
在分析问题之前,我让客户提供了这段时间内的测试记录,同时让客户收集了相应的一些信息。
2016-11-10 13:57:48,276 [FINE] Calibrate output... 2016-11-10 13:57:48,276 [FINE] Output from cell01 . 2016-11-10 13:57:48,276 [FINE] Calibration will take a few minutes... 2016-11-10 13:57:48,276 [FINE] Error occurred during orion execution: 10219: Error completing IO 2016-11-10 13:57:48,276 [FINE] (storax_skgfr_aiowait) 2016-11-10 13:57:48,276 [FINE] ORA-27061: waiting for async I/Os failed 2016-11-10 13:57:48,276 [FINE] Linux-x86_64 Error: 5: Input/output error 2016-11-10 13:57:48,277 [FINE] Additional information: 4294967295 2016-11-10 13:57:48,277 [FINE] Additional information: 1048576 2016-11-10 13:57:48,277 [FINE] rand_ALL0_20161110_1345 2016-11-10 13:57:48,277 [FINE] Test aborted due to errors. 2016-11-10 13:57:48,277 [FINE] ORION: ORacle IO Numbers -- Version 12.1.0.2.0 2016-11-10 13:57:48,277 [FINE] Calibration will take approximately 1 minutes. 2016-11-10 13:57:48,277 [FINE] Using a large value for -cache_size may take longer. 2016-11-10 13:57:48,277 [FINE] CELL-01524: An error occurred while running CALIBRATE tests. |
以上信息是onecommand过程中报的错误,从错误日志可以看出,在调用CALIBRATE命令检测所有存储节点磁盘性能时,出现了错误。
Nov 10 13:46:13 cell01 kernel: sd 4:2:0:0: [sdq] Unhandled sense code Nov 10 13:46:13 cell01 kernel: sd 4:2:0:0: [sdq] Result: hostbyte=invalid driverbyte=DRIVER_SENSE Nov 10 13:46:13 cell01 kernel: sd 4:2:0:0: [sdq] Sense Key : Medium Error [current] Nov 10 13:46:13 cell01 kernel: sd 4:2:0:0: [sdq] Add. Sense: Unrecovered read error Nov 10 13:46:13 cell01 kernel: sd 4:2:0:0: [sdq] CDB: Read(10): 28 00 14 cd e8 00 00 08 00 00 Nov 10 13:46:13 cell01 kernel: end_request: critical target error, dev sdq, sector 349038592 |
以上信息是sundiag收集的日志,可以看出,存储节点cell01在访问/dev/sdq这块盘的时候出现了Medium Error。
以上图片是客户在测试过程中的截图,可以看出,MBPS为0,类似这种磁盘,需要直接更换掉。在问题转到我们这里之前,客户也已经将这种磁盘全部更换掉。 注意:客户更换的是SEAGATE ST360057SSUN600G 磁盘。而恰恰是这种磁盘,给后续的测试带来了性能问题。也即客户的问题1:为什么测试过程中以前一些表现比较差的磁盘,为什么将这类磁盘更换到其它的存储节点后再次测试,性能又能恢复原样?
客户的测试过程
11月28日晚上20:25:30开始,客户从操作系统层面直接调用CALIBRATE命令进行测试,循环执行55次。如下图,是客户截取的测试结果。
从上图可以看出,有部分磁盘的性能还是比较差的。由于这个案例是事后分析,当时的一些日志信息已经不完整,但还好CELL02节点的插槽5这块盘的日志保存完整,以下主要针对CELL02节点的插槽5这块盘进行分析:
name: 20:5 deviceId: 25 deviceName: /dev/sdv diskType: HardDisk enclosureDeviceId: 20 errOtherCount: 0 luns: 0_5 makeModel: "SEAGATE ST360057SSUN600G" physicalFirmware: 0B25 physicalInsertTime: 2016-11-25T13:28:34+08:00 physicalInterface: sas physicalSerial: E06TT6 physicalSize: 558.9120712280273G slotNumber: 5 status: normal |
以上信息可以看出,插槽5这块盘是2016-11-25 13:28:34刚刚更换后的SEAGATE的SAS硬盘。
Mon Nov 28 20:40:22 CST 2016 CELL02 ######### +++++++++++++++++++++++++++++++########### Calibration will take a few minutes... Aggregate random read throughput across all hard disk LUNs: 1774 MBPS Aggregate random read throughput across all flash disk LUNs: 8163 MBPS Aggregate random read IOs per second (IOPS) across all hard disk LUNs: 4765 Aggregate random read IOs per second (IOPS) across all flash disk LUNs: 122923 Calibrating hard disks (read only) ... LUN 0 on drive [20:0 ] random read throughput: 152.00 MBPS, and 402 IOPS LUN 1 on drive [20:1 ] random read throughput: 152.00 MBPS, and 405 IOPS LUN 10 on drive [20:10 ] random read throughput: 156.00 MBPS, and 406 IOPS LUN 11 on drive [20:11 ] random read throughput: 157.00 MBPS, and 396 IOPS LUN 0_2 on drive [20:2 ] random read throughput: 153.00 MBPS, and 400 IOPS LUN 0_3 on drive [20:3 ] random read throughput: 155.00 MBPS, and 396 IOPS LUN 0_4 on drive [20:4 ] random read throughput: 153.00 MBPS, and 401 IOPS LUN 0_5 on drive [20:5 ] random read throughput: 139.00 MBPS, and 416 IOPS LUN 0_6 on drive [20:6 ] random read throughput: 154.00 MBPS, and 395 IOPS LUN 0_7 on drive [20:7 ] random read throughput: 156.00 MBPS, and 400 IOPS LUN 0_8 on drive [20:8 ] random read throughput: 155.00 MBPS, and 407 IOPS LUN 0_9 on drive [20:9 ] random read throughput: 155.00 MBPS, and 398 IOPS Calibrating flash disks (read only, note that writes will be significantly slower) ... LUN 1_0 on drive [FLASH_1_0] random read throughput: 543.00 MBPS, and 33629 IOPS LUN 1_1 on drive [FLASH_1_1] random read throughput: 543.00 MBPS, and 34071 IOPS LUN 1_2 on drive [FLASH_1_2] random read throughput: 543.00 MBPS, and 33511 IOPS LUN 1_3 on drive [FLASH_1_3] random read throughput: 543.00 MBPS, and 33743 IOPS LUN 2_0 on drive [FLASH_2_0] random read throughput: 544.00 MBPS, and 43067 IOPS LUN 2_1 on drive [FLASH_2_1] random read throughput: 544.00 MBPS, and 43669 IOPS LUN 2_2 on drive [FLASH_2_2] random read throughput: 544.00 MBPS, and 44591 IOPS LUN 2_3 on drive [FLASH_2_3] random read throughput: 544.00 MBPS, and 43295 IOPS LUN 4_0 on drive [FLASH_4_0] random read throughput: 542.00 MBPS, and 39627 IOPS LUN 4_1 on drive [FLASH_4_1] random read throughput: 541.00 MBPS, and 40623 IOPS LUN 4_2 on drive [FLASH_4_2] random read throughput: 544.00 MBPS, and 40771 IOPS LUN 4_3 on drive [FLASH_4_3] random read throughput: 543.00 MBPS, and 40873 IOPS LUN 5_0 on drive [FLASH_5_0] random read throughput: 543.00 MBPS, and 37453 IOPS LUN 5_1 on drive [FLASH_5_1] random read throughput: 542.00 MBPS, and 36818 IOPS LUN 5_2 on drive [FLASH_5_2] random read throughput: 543.00 MBPS, and 35609 IOPS LUN 5_3 on drive [FLASH_5_3] random read throughput: 544.00 MBPS, and 33297 IOPS Found some bad LUNs, running tests sequentially to identify the bad LUNs... LUN 0_5 on drive [20:5 ] random read throughput: 167.00 MBPS, and 422 IOPS CALIBRATE results are within an acceptable range. Calibration has finished. |
以上信息可以看出,在2016-11-28 20:40:22时,对CEll02存储节点的磁盘做性能测试时,发现插槽5上的磁盘性能比较低。
11月29日,客户根据28日的检测结果,对一些性能偏低的硬盘进行更换,例如:将Cell07存储节点上插槽7(没有测出性能问题日立原盘)的磁盘 与Cell02存储节点上插槽5(出现性能问题的希捷硬盘)的磁盘进行互换。
更换后测试结果如下图:
我们仍然关注Cell02的 插槽5(希捷硬盘),发现它换到Cell07的插槽7后,Cell07没有出现性能问题了。同理,Cell07的 插槽7(日立硬盘)更换到Cell02的 插槽5后,Cell02也没有出现性能问题。
问题1的原因
[root@cell02 ~]# cellcli -e list metrichistory where name like CL_TEMP > Cell02_TEMP.txt
[root@cell02 ~]# more Cell02_TEMP.txt CL_TEMP cell02 22.0 C 2016-11-28T19:00:44+08:00 CL_TEMP cell02 22.0 C 2016-11-28T19:01:44+08:00 .......(略) CL_TEMP cell02 22.0 C 2016-12-05T19:49:03+08:00 CL_TEMP cell02 23.0 C 2016-12-05T19:50:03+08:00 [root@cell02 ~]#
[root@cell02 ~]# cat Cell02_TEMP.txt |awk '{if ($3<20.0) print $2 "||" $3 "||" $5}' cell02||19.0||2016-11-28T20:12:44+08:00 cell02||19.0||2016-11-28T20:17:44+08:00 [root@cell02 ~]#
[root@cell02 ~]# cat Cell02_TEMP.txt |awk '{if ($3>23.0) print $2 "||" $3 "||" $5}' |more cell02||24.0||2016-12-02T17:53:49+08:00 cell02||24.0||2016-12-02T18:24:49+08:00 cell02||24.0||2016-12-02T18:33:09+08:00 [root@cell02 ~]# |
以上的日志是事后进行分析时,让客户抓取的信息,让客户抓取Cell02存储节点的温度历史信息。可以看到,由于是事后分析,只能看到2016-11-28 至2016-12-05 这部分的数据,对温度历史信息进行过滤,我们可以看到,Cell02存储节点在2016-11-28 20点12分 和 20点17分 这两个时间点的温度只有19度, 而客户进行性能测试的时间点为20:25:30开始。
Nov 22 20:25:26 cell02 ntpd[10952]: 0.0.0.0 c016 06 restart Nov 23 17:53:45 cell02 ntpd[13021]: 0.0.0.0 c016 06 restart Dec 2 20:30:36 cell02 ntpd[12990]: 0.0.0.0 c016 06 restart |
以上是Cell02存储节点的操作系统重启信息,可以看出,11-23 至 12-2 之间,操作系统是未重启过的。
同样,让客户抓取Cell07存储节点的温度历史信息进行分析:
以上的日志是Cell07存储节点的温度历史信息。可以看到2016-11-28 至2016-12-05 这部分的数据,对温度历史信息进行过滤,我们可以看到,Cell07未出现过温度低于20度的情况。
Nov 22 13:57:20 cell07ntpd[13001]: 0.0.0.0 c016 06 restart Nov 23 17:54:02 cell07ntpd[13045]: 0.0.0.0 c016 06 restart Nov 28 18:17:47 cell07ntpd[13029]: 0.0.0.0 c016 06 restart Dec 2 20:35:56 cell07ntpd[12981]: 0.0.0.0 c016 06 restart |
以上是Cell07存储节点的操作系统重启信息,可以看出,11-23 至 12-2 之间,操作系统是重启过多次的。
结合Cell02与Cell07的历史温度信息和操作系统重启情况,正好验证了Exadata上SAS盘的一个小秘密:
问题2的原因
对于问题1,前面已经进行了完整的阐述,下面来看看问题2:现在的插槽 0 或 插槽 1 的MBPS偶尔比其它的磁盘低十几MB左右,是否正常?
1、批量运行CALIBRATE命令对所有存储节点硬盘整体测试
节点名 | 问题类型 | 硬盘 | 性能下降次数 | 总次数 |
cell01 | 性能问题 | 插槽 0 | 无 | 50 |
性能问题 | 插槽 1 | 1 | ||
cell02 | 性能问题 | 插槽 1 | 1 | 50 |
cell03 | 性能问题 | 插槽 0 | 1 | 50 |
性能问题 | 插槽 1 | 3 | ||
cell04 | 性能问题 | 插槽 0 | 2 | 50 |
性能问题 | 插槽 1 | 1 | ||
cell05 | 性能问题 | 插槽 1 | 4 | 50 |
性能问题 | 插槽 0 | 无 | ||
cell06 | 性能问题 | 插槽 0 | 无 | 50 |
cell07 | 性能问题 | 插槽 0 | 2 | 50 |
从以上测试结果可以看出:插槽0和插槽1的磁盘性能下降问题是偶尔出现,同时也只是提示信息,且CALIBRATE测试结果在ORACLE的接受范围之内, 并不像以前直接报ERROR错误。
2、批量运行CALIBRATE命令单独对插槽0和插槽1硬盘进行性能测试
节点名 | 问题类型 | 硬盘 | 性能下降次数 | 总次数 |
cell01 | 性能问题 | 插槽0 | 无 | 50 |
性能问题 | 插槽1 | 无 | ||
cell02 | 性能问题 | 插槽0 | 无 | 50 |
性能问题 | 插槽1 | 无 | ||
cell03 | 性能问题 | 插槽0 | 无 | 50 |
性能问题 | 插槽1 | 无 | ||
cell04 | 性能问题 | 插槽0 | 无 | 50 |
性能问题 | 插槽1 | 无 | ||
cell05 | 性能问题 | 插槽1 | 无 | 50 |
性能问题 | 插槽0 | 无 | ||
cell06 | 性能问题 | 插槽1 | 无 | 50 |
性能问题 | 插槽0 | 无 | ||
cell07 | 性能问题 | 插槽0 | 无 | 50 |
性能问题 | 插槽1 | 无 |
从以上测试结果可以看出:单独对所有存储节点的插槽0和插槽1硬盘进行性能测试,没有发现性能降低情况,说明硬盘没有问题。
3、通过hdparm工具对插槽0和插槽1硬盘以及其他硬盘进行性能测试
其实,在诊断Exadata上的磁盘是否出现性能问题时,可以使用hdparm工具来进行分析,其中对每个盘单独测试5次,对Timing buffered disk reads取其平均值后,进行比对。
平均值为:(177.06+178.58+175.69+178.64+177.31)/5=177.456 MB/sec
平均值为:(189.09+176.97+174.36+173.54+176.77)/5=178.146 MB/sec
平均值为:(189.25+189.66+189.72+189.80+189.53)/5=189.592 MB/sec
以上测试可以看出,插槽 0 和 插槽1 上的磁盘性能与其它盘基本一致,无太大差别,但比其它盘还是要低一些。这是由于Exadata上的插槽0和 插槽1上安装了操作系统,必然会消耗部分性能。