在我开始之前,先简单声明一下。我基本上是一个被迫担任系统管理员角色的开发人员,所以如果我说了一些愚蠢的话或者看起来我不知道自己在做什么,我提前道歉。
因此,我们主服务器上的一个 HDD 遇到了问题。/dev/sda
有两个分区,一个安装为/
,另一个用作 PostgreSQL 数据驱动器(/dev/sda2
)。
$ df -h
Filesystem Size Used Avail Use% Mounted on
rootfs 92G 13G 75G 14% /
udev 10M 0 10M 0% /dev
tmpfs 1.6G 12M 1.6G 1% /run
/dev/disk/by-uuid/8ffca87a-ffe4-4c39-ab30-352b61f039f8 92G 13G 75G 14% /
tmpfs 5.0M 0 5.0M 0% /run/lock
tmpfs 3.2G 0 3.2G 0% /run/shm
/dev/sda2 826G 66G 719G 9% /var/lib/data/vol1
/dev/sdb1 917G 75G 797G 9% /var/lib/data/vol2
(由于某种原因,/dev/sda1 使用其 UUID 挂载)
最近,它开始经历 100% IO R/W 间隔,在此期间系统实际上被阻塞并且无法执行最简单的任务。
dmesg 的简短摘录:
[6554534.743764] INFO: task /usr/bin/monito:29408 blocked for more than 120 seconds.
[6554534.743828] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[6554534.743889] /usr/bin/monito D ffff88041fcd3780 0 29408 1 0x00000000
[6554534.743891] ffff880101906780 0000000000000082 ffff880100000000 ffff88040f2c0100
[6554534.743893] 0000000000013780 ffff880187b45fd8 ffff880187b45fd8 ffff880101906780
[6554534.743895] 0000000000000246 000000018134fb39 ffff88041ffc8328 ffff88039bac2dd8
[6554534.743896] Call Trace:
[6554534.743899] [<ffffffffa019e660>] ? do_get_write_access+0x1ad/0x36a [jbd2]
...
我们知道这是由 PostgreSQL 查询触发的。以下是发生这种情况时的 iotop 输出:
22609 be/4 postgres 441.12 K/s 0.00 B/s 0.00 % 98.46 % postgres: db_name~a_1 127.0.0.1(33183) SELECT
24359 be/4 postgres 988.02 K/s 0.00 B/s 0.00 % 98.22 % postgres: db_name~a_1 127.0.0.1(34194) SELECT
你可能会想:“只要优化你的数据库就行了。这有什么秘密吗?”但是,请考虑以下三件事:
同一应用程序的另一个实例在 上运行相同的数据库模式
/dev/sdb
,负载相似。那里的 I/O 压力正常,很少超过 10-20%。查看该列表中两个 PostgreSQL 进程的综合吞吐量。它勉强超过 1MB/s。对于数据库进程来说,这似乎太低了(数据库进程应该优化为尽可能连续)。
无论 HDD 上的负载是多少,它都不应该像这里一样完全阻塞,以至于产生内核错误并且只需
ls
一分钟才能完成。
我从这一切得出的结论是/dev/sda
硬盘出现故障,需要更换。问题就在这里。在联系主机公司之前,我需要提供一些证据来证明硬盘确实出现故障。然而……
smartctl /dev/sda --all
smartctl 5.41 2011-06-09 r3365 [x86_64-linux-3.2.0-4-amd64] (local build)
Copyright (C) 2002-11 by Bruce Allen, http://smartmontools.sourceforge.net
=== START OF INFORMATION SECTION ===
Device Model: WDC WD1003FBYZ-010FB0
...
=== START OF READ SMART DATA SECTION ===
SMART overall-health self-assessment test result: PASSED
...
SMART Attributes Data Structure revision number: 16
Vendor Specific SMART Attributes with Thresholds:
ID# ATTRIBUTE_NAME FLAG VALUE WORST THRESH TYPE UPDATED WHEN_FAILED RAW_VALUE
1 Raw_Read_Error_Rate 0x002f 200 200 051 Pre-fail Always - 0
3 Spin_Up_Time 0x0027 100 253 021 Pre-fail Always - 0
4 Start_Stop_Count 0x0032 100 100 000 Old_age Always - 2
5 Reallocated_Sector_Ct 0x0033 200 200 140 Pre-fail Always - 0
7 Seek_Error_Rate 0x002e 100 253 000 Old_age Always - 0
9 Power_On_Hours 0x0032 098 098 000 Old_age Always - 2114
10 Spin_Retry_Count 0x0032 100 253 000 Old_age Always - 0
11 Calibration_Retry_Count 0x0032 100 253 000 Old_age Always - 0
12 Power_Cycle_Count 0x0032 100 100 000 Old_age Always - 2
192 Power-Off_Retract_Count 0x0032 200 200 000 Old_age Always - 2
193 Load_Cycle_Count 0x0032 200 200 000 Old_age Always - 9
194 Temperature_Celsius 0x0022 112 109 000 Old_age Always - 35
196 Reallocated_Event_Count 0x0032 200 200 000 Old_age Always - 0
197 Current_Pending_Sector 0x0032 200 200 000 Old_age Always - 0
198 Offline_Uncorrectable 0x0030 100 253 000 Old_age Offline - 0
199 UDMA_CRC_Error_Count 0x0032 200 200 000 Old_age Always - 0
200 Multi_Zone_Error_Rate 0x0008 200 200 000 Old_age Offline - 0
SMART Error Log Version: 1
No Errors Logged
SMART Self-test log structure revision number 1
Num Test_Description Status Remaining LifeTime(hours) LBA_of_first_error
# 1 Extended offline Completed without error 00% 2108 -
...
(截断输出,如果我删减太多,请给我留言)
如您所见,smartctl 显示一切正常。我甚至进行了全面测试,没有发现任何错误。
所以我对此感到很困惑。所有迹象都表明硬盘出现故障,但 SMART 监控却没有检测到任何异常。
我的问题:
- 我的诊断正确吗?驱动器真的出现故障了吗?
- 如果是,我如何获得有关此问题的一些报告,以便我可以向托管公司展示以便他们同意更换它?
- 如果不是,下一个最有可能的罪魁祸首是谁?
更新 1
根据 Baruch 的建议,我执行了磁盘扫描。不幸的是,它没有找到任何可以指出的东西。
diskscan /dev/sda
diskscan version HEAD
I: Validating path /dev/sda
I: Opened disk /dev/sda sector size 512 num bytes 1000204885504
I: Scanning disk /dev/sda in 65536 byte steps
I: Scan started at: Sun Aug 31 04:21:33 2014
Access time histogram:
1: 14138808
10: 923503
100: 183268
500: 15944
1000: 436
2000: 1
3000: 0
4000: 0
5000: 0
6000: 0
7000: 0
8000: 0
9000: 0
10000: 0
15000: 0
20000: 0
25000: 0
30000: 0
above that: 0
1290 |
|
| ^
|
|
1075 |
|
| ^
|
|
860 | ^
| ^ ^
|
| ^ ^ ^ ^ ^
| ^ ^^ ^ ^
645 | ^^ ^ ^ ^^^ ^ ^ ^ ^^^^^ ^^ ^
| ^ ^ ^ ^ ^ ^ ^^^ ^
| ^ ^ ^ ^ ^ ^ ^^
| ^ ^ ^ ^
| ^ ^ ^ ^
430 | ^ ^^^ ^ ^ ^
|
| ^ ^ ^^
|
|
215 |
|
|
| **********************************************************************
| ______________________________________________________________________
+-----------------------------------------------------------------------
Conclusion: passed
I: Scan ended at: Sun Aug 31 09:22:34 2014
I: Scan took 18061 second
I: Closed disk /dev/sda
我还更新了我的部分备份,并且准备在继续之前进行完整备份。
下一步:
我安装了 iosnoop 脚本(Baruch 建议)。我可以让它收集延迟,但我不知道如何让它生成任何对托管公司可操作的信息。
Baruch 的第三个建议目前还超出我的理解范围。我会进一步研究,如果发现什么,我会更新。
如果到明天我还没想出什么办法,我建议还是再买一个磁盘,把 sda 转移到那里。这样我们就知道是磁盘问题还是其他问题,然后继续下一步。
更新2
已执行smartctl -x
。没什么可看的,但是这里有一个粘贴箱并取得圆满成果。
按照 Baruch 的说明启用详细 scsi 日志记录。我的 /var/log/messages 中出现了很多类似这样的内容:
Aug 31 15:28:07 swfemail kernel: [7539683.491379] sd 0:0:0:0: [sda] Send:
Aug 31 15:28:07 swfemail kernel: [7539683.491382] sd 0:0:0:0: [sda] CDB: Write(10): 2a 00 01 3f ce 80 00 00 10 00
Aug 31 15:28:07 swfemail kernel: [7539683.491526] sd 0:0:0:0: [sda] Send:
Aug 31 15:28:07 swfemail kernel: [7539683.491528] sd 0:0:0:0: [sda] CDB: Synchronize Cache(10): 35 00 00 00 00 00 00 00 00 00
Aug 31 15:28:08 swfemail kernel: [7539684.411573] sd 0:0:0:0: [sda] Send:
Aug 31 15:28:08 swfemail kernel: [7539684.411576] sd 0:0:0:0: [sda] CDB: Write(10): 2a 00 01 b6 da d0 00 00 08 00
Aug 31 15:28:08 swfemail kernel: [7539684.411597] sd 0:0:0:0: [sda] Send:
Aug 31 15:28:08 swfemail kernel: [7539684.411598] sd 0:0:0:0: [sda] CDB: Write(10): 2a 00 01 b6 ba d0 00 00 08 00
Aug 31 15:28:08 swfemail kernel: [7539684.411639] sd 0:0:0:0: [sda] Send:
Aug 31 15:28:08 swfemail kernel: [7539684.411639] sd 0:0:0:0: [sda] CDB: Write(10): 2a 00 05 c6 18 88 00 00 a8 00
Aug 31 15:28:08 swfemail kernel: [7539684.412056] sd 0:0:0:0: [sda] Send:
Aug 31 15:28:08 swfemail kernel: [7539684.412057] sd 0:0:0:0: [sda] CDB: Synchronize Cache(10): 35 00 00 00 00 00 00 00 00 00
到目前为止没有什么特别有用的,但磁盘已进入“安静”阶段。一旦它再次开始阻塞,我将尝试捕获输出。
我后来才想到检查一下旧的内核错误消息。没有直接的错误信息。只有一堆超时警告。
更新 3
尝试在 100% 压力时间窗口内读取 scsi 日志。没有 ERROR 或 TIMEOUT 条目 :-(
我们添加了另一个硬盘。目前我正在用它进行克隆dd if=/dev/sda of=/dev/sdc bs=32M
(稍后我将在离线状态下使用 rsync 再进行一次)。我预计今天结束前可以完成。
我将在几天后再次更新结果。
更新 4
由于托管公司的问题,我们无法完全切换到新磁盘。在问题解决之前,我们妥协了,只将数据库移动到新磁盘。这是当前的布局(仅相关设备):
/dev/sdc1 92G 23G 65G 26% /
/dev/sdb1 917G 170G 701G 20% /var/lib/data/vol2
/dev/sda2 826G 71G 714G 9% /var/lib/data/vol1
/dev/sdc
是(潜在的)坏磁盘。/dev/sda
是现在具有数据库的新磁盘。
下一步是监控情况,看看 100% 使用率是否会再次出现。我将在几天内更新(并希望发布可接受的答案)。
答案1
您很可能遇到了磁盘问题。磁盘出现故障,一种相当常见的故障方法是由于磁盘上某些有问题的区域的重试次数增加而导致延迟增加,这些区域在受到攻击时会引起其他 IO 等待它们的连锁反应,如果受影响区域有多个 IO,您会看到这样的问题,因为会有多个 IO 阻塞超过 10 秒。
我建议使用以下方法测试磁盘磁盘扫描它会显示整个磁盘的延迟图。它可以在只读模式下工作,因此完全不会造成破坏。您还可以要求它修复可读但速度很慢的区域,但首先测试磁盘以查看其行为方式。
问题可能是间歇性的,因此磁盘扫描程序不会注意到。您可以运行iosnoop收集所有 IO 及其延迟的历史记录。该脚本会增加一些开销,但效果很好。如果问题不经常发生,则可能需要编写一些脚本来进行更长的日志记录会话。
您可以增加 scsi 子系统日志记录级别,以尝试从内核获取更多信息,如果您使用 LSI SAS HBA 访问磁盘,则可以增加 mpt2sas 驱动程序的日志记录级别,以便从中获取更多信息。两者都可以帮助查看内核中是否存在超时和中止。检查您是否可以在内核中看到与超时和中止有关的日志消息,它们可能可以作为另一个线索。
编辑1:
要启用 SCSI 调试日志记录,您可以使用以下命令:echo 9411 > /proc/sys/dev/scsi/logging_level
您可能需要为 sys 文件使用不同的位置。
还可以尝试使用 -x 选项运行 smartctl,如果有的话,它将显示最后几个错误。