Linux

由於單驅動器讀取錯誤,軟體 RAID-1 出現核心故障

  • October 21, 2013

我在兩個相同的希捷 1GB 驅動器上執行 Fedora 19(核心 3.11.3-201.fc19.x86_64)和軟體 RAID-1(mdadm)設置:

# cat /proc/mdstat 
Personalities : [raid1] 
md1 : active raid1 sdb3[1] sda3[0]
     973827010 blocks super 1.2 [2/2] [UU]

unused devices: <none>

最近,兩個驅動器之一出現了一些錯誤:smartd 檢測到“1 目前無法讀取(待處理)扇區”和“1 離線不可糾正扇區”。RAID 陣列“重新安排”了一些扇區。然後大約一天后,核心產生了各種 I/O 消息/異常:

Oct 18 06:39:20 x smartd[461]: Device: /dev/sdb [SAT], 1 Currently unreadable (pending) sectors
Oct 18 06:39:20 x smartd[461]: Device: /dev/sdb [SAT], 1 Offline uncorrectable sectors
...
Oct 18 07:09:20 x smartd[461]: Device: /dev/sdb [SAT], 1 Currently unreadable (pending) sectors
Oct 18 07:09:20 x smartd[461]: Device: /dev/sdb [SAT], 1 Offline uncorrectable sectors
...
Oct 18 07:30:28 x kernel: [467502.192792] md/raid1:md1: sdb3: rescheduling sector 1849689328
Oct 18 07:30:28 x kernel: [467502.192822] md/raid1:md1: sdb3: rescheduling sector 1849689336
Oct 18 07:30:28 x kernel: [467502.192846] md/raid1:md1: sdb3: rescheduling sector 1849689344
Oct 18 07:30:28 x kernel: [467502.192870] md/raid1:md1: sdb3: rescheduling sector 1849689352
Oct 18 07:30:28 x kernel: [467502.192895] md/raid1:md1: sdb3: rescheduling sector 1849689360
Oct 18 07:30:28 x kernel: [467502.192919] md/raid1:md1: sdb3: rescheduling sector 1849689368
Oct 18 07:30:28 x kernel: [467502.192943] md/raid1:md1: sdb3: rescheduling sector 1849689376
Oct 18 07:30:28 x kernel: [467502.192966] md/raid1:md1: sdb3: rescheduling sector 1849689384
Oct 18 07:30:28 x kernel: [467502.192991] md/raid1:md1: sdb3: rescheduling sector 1849689392
Oct 18 07:30:28 x kernel: [467502.193035] md/raid1:md1: sdb3: rescheduling sector 1849689400
...
Oct 19 06:26:08 x kernel: [550035.944191] ata3.01: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 19 06:26:08 x kernel: [550035.944224] ata3.01: BMDMA stat 0x64
Oct 19 06:26:08 x kernel: [550035.944248] ata3.01: failed command: READ DMA EXT
Oct 19 06:26:08 x kernel: [550035.944274] ata3.01: cmd 25/00:08:15:fb:9c/00:00:6c:00:00/f0 tag 0 dma 4096 in
Oct 19 06:26:08 x kernel: [550035.944274]          res 51/40:00:1c:fb:9c/40:00:6c:00:00/10 Emask 0x9 (media error)
Oct 19 06:26:08 x kernel: [550035.944322] ata3.01: status: { DRDY ERR }
Oct 19 06:26:08 x kernel: [550035.944340] ata3.01: error: { UNC }
Oct 19 06:26:08 x kernel: [550036.573438] ata3.00: configured for UDMA/133
Oct 19 06:26:08 x kernel: [550036.621444] ata3.01: configured for UDMA/133
Oct 19 06:26:08 x kernel: [550036.621507] sd 2:0:1:0: [sdb] Unhandled sense code
Oct 19 06:26:08 x kernel: [550036.621516] sd 2:0:1:0: [sdb]  
Oct 19 06:26:08 x kernel: [550036.621523] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
Oct 19 06:26:08 x kernel: [550036.621530] sd 2:0:1:0: [sdb]  
Oct 19 06:26:08 x kernel: [550036.621537] Sense Key : Medium Error [current] [descriptor]
Oct 19 06:26:08 x kernel: [550036.621555] Descriptor sense data with sense descriptors (in hex):
Oct 19 06:26:08 x kernel: [550036.621562]         72 03 11 04 00 00 00 0c 00 0a 80 00 00 00 00 00 
Oct 19 06:26:08 x kernel: [550036.621606]         6c 9c fb 1c 
Oct 19 06:26:08 x kernel: [550036.621626] sd 2:0:1:0: [sdb]  
Oct 19 06:26:08 x kernel: [550036.621638] Add. Sense: Unrecovered read error - auto reallocate failed
Oct 19 06:26:08 x kernel: [550036.621646] sd 2:0:1:0: [sdb] CDB: 
Oct 19 06:26:08 x kernel: [550036.621653] Read(10): 28 00 6c 9c fb 15 00 00 08 00
Oct 19 06:26:08 x kernel: [550036.621692] end_request: I/O error, dev sdb, sector 1822227228
Oct 19 06:26:08 x kernel: [550036.621719] raid1_end_read_request: 9 callbacks suppressed
Oct 19 06:26:08 x kernel: [550036.621727] md/raid1:md1: sdb3: rescheduling sector 1816361448
Oct 19 06:26:08 x kernel: [550036.621782] ata3: EH complete
Oct 19 06:26:08 x kernel: [550041.155637] ata3.01: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Oct 19 06:26:08 x kernel: [550041.155669] ata3.01: BMDMA stat 0x64
Oct 19 06:26:08 x kernel: [550041.155694] ata3.01: failed command: READ DMA EXT
Oct 19 06:26:08 x kernel: [550041.155719] ata3.01: cmd 25/00:08:15:fb:9c/00:00:6c:00:00/f0 tag 0 dma 4096 in
Oct 19 06:26:08 x kernel: [550041.155719]          res 51/40:00:1c:fb:9c/40:00:6c:00:00/10 Emask 0x9 (media error)
Oct 19 06:26:08 x kernel: [550041.155767] ata3.01: status: { DRDY ERR }
Oct 19 06:26:08 x kernel: [550041.155785] ata3.01: error: { UNC }
Oct 19 06:26:08 x kernel: [550041.343437] ata3.00: configured for UDMA/133
Oct 19 06:26:08 x kernel: [550041.391438] ata3.01: configured for UDMA/133
Oct 19 06:26:08 x kernel: [550041.391501] sd 2:0:1:0: [sdb] Unhandled sense code
Oct 19 06:26:08 x kernel: [550041.391510] sd 2:0:1:0: [sdb]  
Oct 19 06:26:08 x kernel: [550041.391517] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE
Oct 19 06:26:08 x kernel: [550041.391525] sd 2:0:1:0: [sdb]  
Oct 19 06:26:08 x kernel: [550041.391532] Sense Key : Medium Error [current] [descriptor]
Oct 19 06:26:08 x kernel: [550041.391546] Descriptor sense data with sense descriptors (in hex):
Oct 19 06:26:08 x kernel: [550041.391553]         72 03 11 04 00 00 00 0c 00 0a 80 00 00 00 00 00 
Oct 19 06:26:08 x kernel: [550041.391596]         6c 9c fb 1c 
Oct 19 06:26:08 x kernel: [550041.391616] sd 2:0:1:0: [sdb]  
Oct 19 06:26:08 x kernel: [550041.391624] Add. Sense: Unrecovered read error - auto reallocate failed
Oct 19 06:26:08 x kernel: [550041.391636] sd 2:0:1:0: [sdb] CDB: 
Oct 19 06:26:08 x kernel: [550041.391643] Read(10): 28 00 6c 9c fb 15 00 00 08 00
Oct 19 06:26:08 x kernel: [550041.391681] end_request: I/O error, dev sdb, sector 1822227228
Oct 19 06:26:08 x kernel: [550041.391737] ata3: EH complete
Oct 19 06:26:08 x kernel: [550041.409686] md/raid1:md1: read error corrected (8 sectors at 1816363496 on sdb3)
Oct 19 06:26:08 x kernel: [550041.409705] handle_read_error: 9 callbacks suppressed
Oct 19 06:26:08 x kernel: [550041.409709] md/raid1:md1: redirecting sector 1816361448 to other mirror: sda3

電腦繼續將一些條目記錄到 syslog 中,直到大約一個小時後,最終完全沒有響應。syslog 中沒有記錄“核心錯誤”。電腦必須重新啟動,此時 RAID 陣列處於重新同步狀態。重新同步後,一切正常,驅動器似乎工作正常。

我還注意到所有重新安排的扇區正好相隔 8 個扇區,這對我來說似乎很奇怪。

最後,在重新啟動後大約一兩天后,但在 raid 重新同步完成之後,驅動器重置了不可讀(待處理)和離線不可糾正的扇區計數,我認為這是正常的,因為驅動器使這些扇區離線並重新映射它們:

Oct 20 01:05:42 x kernel: [    2.186400] md: bind<sda3>
Oct 20 01:05:42 x kernel: [    2.204826] md: bind<sdb3>
Oct 20 01:05:42 x kernel: [    2.209618] md: raid1 personality registered for level 1
Oct 20 01:05:42 x kernel: [    2.210079] md/raid1:md1: not clean -- starting background reconstruction
Oct 20 01:05:42 x kernel: [    2.210087] md/raid1:md1: active with 2 out of 2 mirrors
Oct 20 01:05:42 x kernel: [    2.210122] md1: detected capacity change from 0 to 997198858240
Oct 20 01:05:42 x kernel: [    2.210903] md: resync of RAID array md1
Oct 20 01:05:42 x kernel: [    2.210911] md: minimum _guaranteed_  speed: 1000 KB/sec/disk.
Oct 20 01:05:42 x kernel: [    2.210915] md: using maximum available idle IO bandwidth (but not more than 200000 KB/sec) for resync.
Oct 20 01:05:42 x kernel: [    2.210920] md: using 128k window, over a total of 973827010k.
Oct 20 01:05:42 x kernel: [    2.241676]  md1: unknown partition table
...
Oct 20 06:33:10 x kernel: [19672.235467] md: md1: resync done.
...
Oct 21 05:35:50 x smartd[455]: Device: /dev/sdb [SAT], No more Currently unreadable (pending) sectors, warning condition reset after 1 email
Oct 21 05:35:50 x smartd[455]: Device: /dev/sdb [SAT], No more Offline uncorrectable sectors, warning condition reset after 1 email

smartctl -a /dev/sdb現在顯示

ID# ATTRIBUTE_NAME          FLAG     VALUE WORST THRESH TYPE      UPDATED  WHEN_FAILED RAW_VALUE
...
 5 Reallocated_Sector_Ct   0x0033   096   096   036    Pre-fail  Always       -       195
...
197 Current_Pending_Sector  0x0012   100   100   000    Old_age   Always       -       0
198 Offline_Uncorrectable   0x0010   100   100   000    Old_age   Offline      -       0
...

出現了一些問題:

  1. 為什麼所有重新安排的扇區正好相隔 8 個?

  2. 為什麼核心會變得無響應並需要重新啟動?這不應該正是RAID-1 在系統不會崩潰的情況下處理的情況嗎?

  3. 為什麼在 RAID 重新同步完成 23 小時後才會重置不可讀和離線不可糾正計數?

  1. 為什麼所有重新安排的扇區正好相隔 8 個?

行業數量的這種差距是可以預料的,問題是這些差距會有多大(4k 或更大)。8x 512 字節是 4k,這是大多數文件系統使用的扇區大小。所以文件系統可能請求從 RAID 讀取 4k,RAID 要求該/dev/sdb數據。該讀取的第一個扇區失敗(這是您在日誌中看到的扇區號),RAID 切換到/dev/sda並從那里為 4k 提供服務。然後文件系統請求讀取下一個 4k,回到/dev/sdb扇區號 +8 再次失敗,這又是您在日誌中看到的內容……

  1. 為什麼核心會變得無響應並需要重新啟動?

不應該正常發生。問題是重新分配的情況大約是你能得到的最昂貴的。每次讀取失敗,都必須重定向到另一個磁碟,必須在原始磁碟上重寫,等等。如果它同時填滿您的日誌文件,又會導致新的寫入請求,而這些請求又必須重新分配再次等等。在這種情況下,將磁碟完全踢出會更便宜。

這也是其他硬體(例如 SATA 控制器)如何處理故障驅動器的問題。如果控制器本身出現問題,它將更加損害性能。

如果沒有日誌條目,就很難準確判斷發生了什麼;這是 Linux 核心的一個弱點,當事情真的惡化時,沒有直接的解決方案來保存這些最後的消息。

  1. 為什麼在 RAID 重新同步完成 23 小時後才會重置不可讀和離線不可糾正計數?

某些值僅在您進行離線數據收集(UPDATED Offline 列)時才會更新,這可能需要一些時間。如果磁碟設置為自動執行此操作,則取決於磁碟,例如每四個小時一次。如果您不想依賴磁碟,則應使用 smartmontools 進行設置。

引用自:https://unix.stackexchange.com/questions/97033