« iPhoneの可能性を拡張するポータブルプリンタ:KINGJIM Rolto | トップページ | マスキングテープのイベント:『mt store in ならまち』に行ってきた »

2014年8月21日 (木)

【Linux】eSATA/USB接続用外付けRAID箱CG-HDC4EU3500のクラッシュとデータのサルベージ

京都では,大文字が終わると夏も終わりという感じですが,未だに京都は灼熱地獄の日々が続いています.空調を切ると,我が書斎は熱中症アラームがチカチカ点滅し続ける状況を何とかしたいと思う今日この頃ですが,皆様におかれましては如何お過ごしでしょうか.

少しでも涼をとるために…って訳ではないのですが,今回は背筋が凍るような話をしようと思います.

ICT系と超常現象は結構親和性が高かったりします.そのため,電気・電波業界の人は電電宮へお参りに行ったりしていますし,開発系の人でも験を担いだりする人が結構多かったりするわけです.無神論者・葬式仏教徒な人でも,結構『何か』の存在を信じていたりします.

で,うちの職場には,本人は何も悪いことをしていないのに周りでよく物が壊れる人がいます.急に物が動かなくなったり,ケーブルが断線したり.つい先日は,4本のネジで固く止められていたモニタ台が突如として割れ,凄まじい音を立ててモニタが卓上に落下していました.まだ購入して何年も経っていないのに….何かが居るのかも….

そう言えば,今は亡き月刊アスキーで連載されていたYoのけそうぶみのYo女史も,静電気バチバチ系(?)で,しょっちゅうケーブルを断線させていたなんてエピソードが載っていましたね.

まぁそれは良いとして,真にオソロシイ話は,こんな話です.

深夜残業中,誰も居ないはずの部屋から,ジーコロ,ジーコロ,カコーン,カコーンという音が….音源を探すと,ファイルサーバのディスクの方から….

更にはRAID化していなかったり,バックアップを怠けたりしていたら,真っ青になるほどの恐怖を覚えることでしょう.

***

と,いうことで,本エントリーは,自宅鯖に接続して使用していたCG-HDC4EU3500内のディスクが昇天なされまして,ハードRAID特有の,『にっちもさっちも行かない』状態で絶讃放置されていた状態のRAIDアレイからのデータサルベージをした際の記録です.

なお,自宅鯖に接続し,設定した際のエントリーはこちら.使用開始から4年ですか….

何が起きていたのか

自宅鯖の稼働状況はちょこちょこHotSaNICで見ていたのだけど,ディスクの空き容量が厳しい以外は絶好調.しかし,ある日システムログを久しぶりに見たところ,怪しげな物が記録されていました.

最初は

May 18 14:28:16 hogehoge kernel: ata10.00: status: { DRDY ERR }
May 18 14:28:16 hogehoge kernel: ata10.00: error: { ABRT }
May 18 14:28:16 hogehoge kernel: ata10.00: configured for UDMA/100
May 18 14:28:16 hogehoge kernel: ata10: EH complete

とか出ていて,

May 18 14:28:16 hogehoge kernel: sdi: Current [descriptor]: sense key: Aborted Command
May 18 14:28:16 hogehoge kernel:     Add. Sense: No additional sense information
May 18 14:28:16 hogehoge kernel:
May 18 14:28:16 hogehoge kernel: Descriptor sense data with sense descriptors (in hex):
May 18 14:28:16 hogehoge kernel:         72 0b 00 00 00 00 00 0c 00 0a 80 00 00 00 00 01
May 18 14:28:16 hogehoge kernel:         23 04 00 4a
May 18 14:28:16 hogehoge kernel: end_request: I/O error, dev sdi, sector 4882432074
May 18 14:28:16 hogehoge kernel: ata10: EH complete
May 18 14:28:16 hogehoge kernel: EXT3-fs error (device sdi1): ext3_get_inode_loc: unable to read inode block - inode=305152124, block=610304005
May 18 14:28:16 hogehoge kernel: Aborting journal on device sdi1.
May 18 14:28:16 hogehoge kernel: ata10.00: limiting speed to UDMA/66:PIO4
May 18 14:28:16 hogehoge kernel: ata10.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6
May 18 14:28:16 hogehoge kernel: ata10.00: BMDMA2 stat 0xc0001

と,なってトラブルが深刻化し,

May 29 16:47:01 hogehoge smartd[4261]: Device: /dev/sdi, No such device, open() failed

のように,最終的にアクセス出来なくなっていました.

マウントが外れただけかと思って手動で再マウントを試したのですが,エラーが出てマウント出来ず.

ご臨終のようです.調子が悪くなってから10日後くらいにお亡くなりになり,そして発見されたときには死後1ヶ月以上経過していた模様です.

更にログを見ると,

May 29 16:47:01 hogehoge smartd[4261]: Sending warning via mail to root ...

と,このように,ダイイングメッセージを残そうとしていた模様.

しかし,自宅鯖はsendmailをマトモに設定してない&使っていないので,root宛のメールを読んでいませんでした….会社の鯖とかはしっかり設定しているのですが,紺屋の白袴状態.

ぶっ飛んだディスクからのデータサルベージを仕事で何度かやったことがあるのですが,実に骨が折れる作業です.しかし今回は,何だかクラッシュしてスッキリした感じが.『あっ,これが断捨離?』なんて言葉がふと脳裏に浮かびます.

いやいや,売られた喧嘩は買わないといけません.エンジニアとしては,ハイそうですかと引き下がるわけには行きません.誰から/何から喧嘩を売られたかは不明ですが,目の前に困難が横たわっているわけで,これは美味しいネタです 困難は乗り越えなければなりません.

そこで完全復活は無理にしても,このようなときに行える諸々の手順を試すことにしました.

状況を知る

と,いうことで,まずは/dev/sdi1がどのディスクかを見てみると…

CN(1)Val(e0e0625)
ata10: hard resetting link
ata10: SATA link up 1.5 Gbps (SStatus 113 SControl 310)
ata10.00: ATA-7: H/W RAID5, 0956, max UDMA/133
ata10.00: 11720785920 sectors, multi 1: LBA48
ata10.00: configured for UDMA/100
ata10: EH complete
  Vendor: ATA       Model: H/W RAID5         Rev: 0956
  Type:   Direct-Access                      ANSI SCSI revision: 05
sdi : very big device. try to use READ CAPACITY(16).
SCSI device sdi: 11720785920 512-byte hdwr sectors (6001042 MB)
sdi: Write Protect is off

冒頭で既に書いてしまいましたが,お亡くなりになったのは外付けRAIDです.幻をレポートし続けているHotSaNICによると,ほぼ6TB使い切っていたようで,中にはデータ山盛りだった模様です.さてさてどうしたものか.

次にパーティション情報を見てみましょうか.

[root@hogehoge~]# parted /dev/sdi
GNU Parted 1.8.1
/dev/sdi を使用
GNU Parted へようこそ! コマンド一覧を見るには 'help' と入力してください。
(parted) p
エラー: /dev/sdi を開けません。ディスクラベルが認識できません。
(parted) q

パーティションテーブルすら読むことが出来ないようです.この状態を一言で表すと,『ボロボロ』.一時撤退.

そもそもCG-HDC4EU3500はディスクが故障した際には自動的にアラームを出し,そしてホットスワップしてオートリビルドも可能なハードRAIDの箱です.

ところが筐体を見ると,ディスク全てがOKステータス(赤でなく青LED点灯)になっています.

何らかのエラーが出ているのであれば,問題のあるディスクをオフラインにしてアラーム鳴らして欲しいなぁとか思うのですが,スピンドルが回っていないとか,コントロール基板が壊れたとかいったもっと深刻な症状にならないと,この自動的なエラー認識は働かないようです.ダメじゃん….

問題のディスクを探す

と,いうことで,問題のディスクを探すためにRAID Boxの電源を一旦落とし,一本ずつ抜いて,Winマシンでステータスを見ることにしました.あまり手間を掛けたくないので,今回は単純にSMART値でディスクヘルスをチェックすることにします.

SMARTを見るために用意したのは,玄人志向のUSB接続でもSMART値を読める箱であるところの,GW3.5AA-SUP3/MBです.ファンを内蔵していないので常用は厳しいですが,USB 3.0対応であり,ちょっとした作業に便利&SMART読みが出来るので,1台持って置いて損はない箱です.安いし.それとSMARTを読むためのソフトはCrystal DiskInfoを使用.

4本全てを取っ替え引っ替え試したところ,4本中3本が『注意』状態でした.SMART的に問題なしだったのはたったの1台です.

図1.Disk1

1

図2.Disk2

2

図3.Disk3

3

図4.Disk4

4

SMARTで主に見るべきなのは,05,C5,C6です.ディスク上のセクタが読めない/書けない等のトラブルが発生したときは,ディスク上に予め用意されている『予備』のセクタへの大体処理が行われます.この処理が行われること自体は問題ではありません.しかし,ディスクが壊れ始めるときは大抵,最初は僅かだった不良セクタが急激に増えます.

『回復不可能なセクタ数』を表すC6を見て頂くと分かる通り,Disk3だけ異様に悪い値を示しており,かなり深刻な状態であることが分かります.おそらく今回の原因はこれでしょう.

では,このディスクを交換し,リビルドしましょう.

まずは抜いたときと同じ順番でRAID BOXの各スロットにディスクを再び挿し直し(←重要),通電後に問題のディスクを抜いてエラー状態にします.そして同じ容量の新しいディスクを抜いたスロットに挿します.するとオートリビルドが開始されます.

よく言われることですが,RAID5はリビルド中にもう1台ディスクがクラッシュして全損という事故が起きる可能性があるので(*),祈りましょう.

(*)同じロットのディスクを同じような環境で動かした場合,故障時期が同時期になると予想される(個人的経験則からは,この仮説はネガティブだけど).リビルドのようにディスクに激しくアクセスしている最中は事故が起きすく,そしてRAID5は2本ディスクが死ぬとアレイがお亡くなりになるので,データ全損となる.

6TBで約6時間くらいかかったでしょうか.無事に終了.きっと私の日頃の行いが良いからでしょう.

次にパーティションテーブルが飛んでいましたので,これを作り直します.パーティション構成は当初の構成と同じにして中身は弄らないので,データは保全される筈です.

[root@hogehoge~]# parted /dev/sdi
GNU Parted 1.8.1
/dev/sdi を使用
GNU Parted へようこそ! コマンド一覧を見るには 'help' と入力してください。
(parted) mklabel gpt
(parted) p
モデル: ATA H/W RAID5 (scsi)
ディスク /dev/sdi: 6001GB
セクタサイズ (論理/物理): 512B/512B
パーティションテーブル: gpt
番号  開始  終了  サイズ  ファイルシステム  名前  フラグ
(parted) mkpart
パーティションの名前?  []? ext_raid0
ファイルシステムの種類?  [ext2]? ext3
開始? 0
終了? -0
(parted) p
モデル: ATA H/W RAID5 (scsi)
ディスク /dev/sdi: 6001GB
セクタサイズ (論理/物理): 512B/512B
パーティションテーブル: gpt
番号  開始    終了    サイズ  ファイルシステム  名前       フラグ
1    17.4kB  6001GB  6001GB                    ext_raid0
(parted) q
通知: 必要であれば /etc/fstab を更新するのを忘れないようにしてください。

うまく行ったようです.

では,マウントしてみましょう.

[root@hogehoge~]# mount /dev/sdi1 /export/e-raid0/
mount: ファイルシステムタイプを指定する必要があります

あらら.やはり一筋縄ではいきませんね.

安易にfsckをかけると中身を破壊してしまう可能性があるのですが,今回は『そんときはそんとき』と,吹っ切れているので,容赦なくfsckをかけます.なお,fsckはread onlyでマウント中か,アンマウント状態でかけるようにしましょう.
[root@hogehoge~]# fsck /dev/sdi1
fsck 1.39 (29-May-2006)
WARNING: bad format on line 12 of /etc/fstab
e2fsck 1.39 (29-May-2006)
Couldn't find ext2 superblock, trying backup blocks...
Found invalid V2 journal superblock fields (from V1 journal).
Clearing fields beyond the V1 journal superblock...
eraid0: recovering journal
fsck.ext2: unable to set superblock flags on eraid0

superblockすら死んでます.本格的に死んでますな.

仕方ないので,superblockのバックアップの位置を探します.

[root@hogehoge~]# mkfs.ext3 -n /dev/sdi1
mke2fs 1.39 (29-May-2006)
Filesystem label=
OS type: Linux
Block size=4096 (log=2)
Fragment size=4096 (log=2)
732561408 inodes, 1465098231 blocks
73254911 blocks (5.00%) reserved for the super user
First data block=0
Maximum filesystem blocks=0
44712 block groups
32768 blocks per group, 32768 fragments per group
16384 inodes per group
Superblock backups stored on blocks:
 32768, 98304, 163840, 229376, 294912, 819200, 884736, 1605632, 2654208,
        4096000, 7962624, 11239424, 20480000, 23887872, 71663616, 78675968,
        102400000, 214990848, 512000000, 550731776, 644972544
32768です.数値を控えておきましょう.

では,この位置をパラメータで指定して,fsckをかけてみましょう.

[root@hogehoge~]# fsck.ext3 -b 32768 -B 4096 /dev/sdi1
e2fsck 1.39 (29-May-2006)
eraid0: recovering journal
fsck.ext3: unable to set superblock flags on eraid0
ぐはっ(吐血).superblockのバックアップも死んでる感じです.
仕方が無いので,『スーパーブロックもそのバックアップも壊れてしまった』ときに使用する,『スーパーブロックとグループディスクリプタのみを書き出す』という"-S"オプションを使用し,ファイルシステムの情報を書き換えます.

[root@hogehoge~]# mke2fs -S /dev/sdi1
mke2fs 1.39 (29-May-2006)
Filesystem label=
OS type: Linux
Block size=4096 (log=2)
Fragment size=4096 (log=2)
732561408 inodes, 1465098231 blocks
73254911 blocks (5.00%) reserved for the super user
First data block=0
Maximum filesystem blocks=0
44712 block groups
32768 blocks per group, 32768 fragments per group
16384 inodes per group
Superblock backups stored on blocks:
        32768, 98304, 163840, 229376, 294912, 819200, 884736, 1605632, 2654208,
        4096000, 7962624, 11239424, 20480000, 23887872, 71663616, 78675968,
        102400000, 214990848, 512000000, 550731776, 644972544
Writing superblocks and filesystem accounting information: done
This filesystem will be automatically checked every 27 mounts or
180 days, whichever comes first.  Use tune2fs -c or -i to override.
そして次にようやくfsck.今度は動き始めました.

[root@hogehoge~]# fsck.ext3 -y /dev/sdi1
e2fsck 1.39 (29-May-2006)
/dev/sdi1 contains a file system with errors, check forced.
Pass 1: Checking inodes, blocks, and sizes
Deleted inode 42906110 has zero dtime.  Fix? yes
Deleted inode 42906111 has zero dtime.  Fix? yes
Deleted inode 42906112 has zero dtime.  Fix? yes
<中略>
Inode 305152009 has illegal block(s).  Clear? yes
Illegal block #7 (2081250044) in inode 305152009.  CLEARED.
Illegal block #1036 (3845149766) in inode 305152009.  CLEARED.
Illegal block #1037 (2926040531) in inode 305152009.  CLEARED.
Illegal block #1038 (3060581738) in inode 305152009.  CLEARED.
Illegal block #1040 (2743836195) in inode 305152009.  CLEARED.
Illegal block #1041 (4147987451) in inode 305152009.  CLEARED.
Illegal block #1042 (1720466494) in inode 305152009.  CLEARED.
Illegal block #1043 (2481105696) in inode 305152009.  CLEARED.
Illegal block #1044 (3855218448) in inode 305152009.  CLEARED.
Illegal block #1046 (1595608553) in inode 305152009.  CLEARED.
Illegal block #1047 (3145724297) in inode 305152009.  CLEARED.
Too many illegal blocks in inode 305152009.
Clear inode? yes
Inode 305152010 has illegal block(s).  Clear? yes
Illegal block #7 (2081250044) in inode 305152010.  CLEARED.
Illegal block #1049 (2223827004) in inode 305152010.  CLEARED.
Illegal block #1050 (4222253250) in inode 305152010.  CLEARED.
Illegal block #1051 (3765987324) in inode 305152010.  CLEARED.
<中略>
Inode 407945221 is in use, but has dtime set.  Fix? yes
Inode 407945221 has imagic flag set.  Clear? yes
Inode 407945222 is in use, but has dtime set.  Fix? yes
Inode 407945222 has imagic flag set.  Clear? yes
Inode 407945223 is in use, but has dtime set.  Fix? yes
Inode 407945223 has imagic flag set.  Clear? yes
Inode 407945224 is in use, but has dtime set.  Fix? yes
Inode 407945224 has imagic flag set.  Clear? yes
Inode 407945229 is in use, but has dtime set.  Fix? yes
<中略>
Inode 407945221 has compression flag set on filesystem without compression support.  Clear? yes
Inode 407945221 has INDEX_FL flag set but is not a directory.
Clear HTree index? yes
Inode 407945221, i_size is 12534206790605292868, should be 0.  Fix? yes
Inode 407945221, i_blocks is 4294967287, should be 0.  Fix? yes
Inode 407945222 has compression flag set on filesystem without compression support.  Clear? yes
Inode 407945222 has INDEX_FL flag set but is not a directory.
Clear HTree index? yes
<中略>
Free inodes count wrong for group #42370 (16384, counted=16326).
Fix? yes
Free inodes count wrong (732561428, counted=732558986).
Fix? yes
/dev/sdi1: ***** FILE SYSTEM WAS MODIFIED *****
/dev/sdi1: 2422/732561408 files (0.5% non-contiguous), 1423610927/1465098231 blocks

永遠と思えるような凄まじい時間が経過した後に,fsckが終了しました.幸いにして,途中でエラーで落ちることもありませんでした.

データサルベージ

予め断っておきますが,手間を掛けてでも少しでも多くのファイルをサルベージをする場合は,fsckの-nオプションを使ってまずは被害状況を確認のみした後に対策を考えるべきです.今回のように,いきなりfsckをかけるのは,あまり褒められた方法ではありません.
私は『まぁ消えたら消えたでしゃーない』という方針だったので,一気にやりました.基本的には『fsckは最後の手段』と考えて置いて下さい.fsckはディスク上のデータを書き換えてしまいますので,一度やったらundoが出来ません.データを完全に破壊してしまう可能性もあります.

気を取り直して,マウントしてみましょう.

でも一応安全を考慮して,readonlyでマウントします.このようにしたのは,裏で動いているプログラムが何かの拍子でディスクに書き込んでしまい,それがディスクエラーを誘発し,結果,RAIDアレイが再びオフラインに…という悪夢は防ぐためです.

[root@hogehoge~]# mount -o ro /dev/sdi1 /export/e-raid0/

容量を見てみましょう.
[root@hogehoge~]# df /dev/sdi1
Filesystem           1K-ブロック    使用   使用可 使用% マウント位置
/dev/sdi1            5768434164 5602484948         0 100% /export/e-raid0

素晴らしい:-P.あり得ない数字になっています.

が,一応エラー無しでマウント出来ています.そして中をlsすると,元あったフォルダが一応見えています.

次に,fsckが復旧に失敗したデータの断片を確認してみましょう.
[root@hogehoge~]# cd /export/e-raid0/lost+found
[root@hogehoge~]# ls
#140853526  #140853901  #151732270  #367247415  #563265548  #607928341  #692289541
#140853529  #140853902  #151732271  #367247416  #563265549  #607928342  #692289542
#140853541  #140853903  #151732272  #367247417  #563265550  #607928343  #692289543
#140853547  #140853904  #151732273  #367247418  #563265551  #607928344  #692289544
#140853617  #140853905  #151732274  #367247419  #563265552  #607928345
#140853618  #140853906  #151732275  #367247420  #563265553  #607928346
#140853619  #140853907  #151732276  #367247421  #563265554  #607928347
#140853620  #140853908  #151732277  #367247422  #563265555  #607928348
#140853621  #140853909  #151732278  #458145795  #563265556  #607928349
<略>
[root@hogehoge lost+found]# ls|wc
     877     877    9647
壊れたファイルの断片の数が凄まじい状態です.流石に今回は,中身を確認してつなぎ合わせて一つのファイルに…というモチベーションもガッツもないので,これらは放棄.合掌.

この後,生きているファイルをフォルダ単位で安全な別の所にコピーして行きました.しかしディスク上に地雷が残っていたようで,『このファイルに触るとエラーでオフラインになる』という所があり,ここを避けながらチマチマとコピーを実施.

その際に出たエラーはこんな感じ.

Jul  1 6:24:06 hogehoge kernel: ata10.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Jul  1 6:24:06 hogehoge kernel: ata10.00: BMDMA2 stat 0xd0009
Jul  1 6:24:06 hogehoge kernel: ata10.00: cmd 25/00:00:52:8a:4f/00:01:d9:01:00/e0 tag 0 dma
131072 in
Jul  1 6:24:06 hogehoge kernel:          res 51/04:00:52:8a:4f/00:01:d9:01:00/f0 Emask 0x1 (device error)
Jul  1 6:24:06 hogehoge kernel: ata10.00: status: { DRDY ERR }
Jul  1 6:24:06 hogehoge kernel: ata10.00: error: { ABRT }
Jul  1 6:24:06 hogehoge kernel: ata10.00: configured for UDMA/33
Jul  1 6:24:06 hogehoge kernel: ata10: EH complete
Jul  1 6:24:10 hogehoge kernel: ata10.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0
Jul  1 6:24:10 hogehoge kernel: ata10.00: BMDMA2 stat 0xd0009
Jul  1 6:24:10 hogehoge kernel: ata10.00: cmd 25/00:00:52:8b:4f/00:01:d9:01:00/e0 tag 0 dma 131072 in
Jul  1 6:24:10 hogehoge kernel:          res 51/04:00:52:8b:4f/00:01:d9:01:00/f0 Emask 0x1 (device error)

当初出ていたと同じような感じで,今回深刻なエラーから回復したものの,完全にトラブルの原因を排除したわけではないということです.つまりこのRAID BOXを,この状態で使い続けるのは大変危険ってことですな.

戦果と教訓など

『この中で重要かな』と思っていた部分は,概ねサルベージ出来ました.容量で言うと,全体の7~8割は救出できた感じです.発生した症状から考えると,実にラッキーでした.

教訓としては,『ハードRAIDはやっぱり信用置けねぇ』って所でしょうか.

mdを使用したSoftRAIDであれば問題の検知が容易で,操作も楽で,こんな苦労する必要がありません.近々,起動ディスクの交換とSoftRAIDのディスクの交換を採り上げる予定ですが,全部ソフト的に直接コントロールする方がトラブル対応が楽ですし確実です.

そしてバックアップは大事

例えばGoogleDriveは1TBを月々$9.99で使えますし,本当に大切なデータは,二重,三重,更には広域な事故に備えてクラウドにもってのが安心です.Googleからののぞき見対策としては,暗号化して保存するという手があります.

ただし,パーソナル向けの数TB~数十TBのそこそこ高速かつ廉価なバックアップソリューションって中々無いので,大容量データ持ちな人は今後も自衛するしか無いでしょうね….

と,いうことで,残暑厳しい今日この頃ですが,ディスクの保全にはくれぐれもご注意下さい.また,ディスクトラブルが発生してGoogleの検索で飛んで来られた皆様におかれましては,我が屍を乗り越えて行って下さい.幸運をお祈りします.

|

« iPhoneの可能性を拡張するポータブルプリンタ:KINGJIM Rolto | トップページ | マスキングテープのイベント:『mt store in ならまち』に行ってきた »

コメント

コメントを書く



(ウェブ上には掲載しません)


コメントは記事投稿者が公開するまで表示されません。



トラックバック

この記事のトラックバックURL:
http://app.cocolog-nifty.com/t/trackback/198640/60180010

この記事へのトラックバック一覧です: 【Linux】eSATA/USB接続用外付けRAID箱CG-HDC4EU3500のクラッシュとデータのサルベージ:

« iPhoneの可能性を拡張するポータブルプリンタ:KINGJIM Rolto | トップページ | マスキングテープのイベント:『mt store in ならまち』に行ってきた »