月別アーカイブ: 2018年9月

Mikeforce server downed again.

2件の返信

今月初めは平成30（2018）年9月1日に発生したサーバ障害は、その週明けにはなんとか復旧できたのだけれど、残念ながら未だ「致命的な問題」が残っていたようで再びダウンしてしまった。正確にはHDD故障で重要なパーティションをマウントできなくなり、ウェブサービスは勿論、システムサービスの類が軒並み停止してしまったという次第 :$。

最初の障害でサーバが強制Shutdownした際、HDD内のLVMである /var パーティションで何か処理していたのだろうか。リモートからサーバにログインできないことに気づいた時はなんとなく嫌な予感がしたが :|。
で帰宅して調べてみると、案の定、朝まで動いていたサーバは最後にアクセスしてから数時間後に突然、次のようなHDD読み取りエラーが発生していた：

[711805.660457] sd 25:0:0:0: [sdh] FAILED Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE
[711805.660465] sd 25:0:0:0: [sdh] Sense Key : Hardware Error [current]
[711805.660468] sd 25:0:0:0: [sdh] Add. Sense: No additional sense information
[711805.660471] sd 25:0:0:0: [sdh] CDB: 
[711805.660473] Read(10): 28 00 0f a9 6b 10 00 00 10 00
[711805.660484] blk_update_request: I/O error, dev sdh, sector 262761232
[711822.460908] sd 25:0:0:0: [sdh] FAILED Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE
[711822.460916] sd 25:0:0:0: [sdh] Sense Key : Hardware Error [current]
[711822.460919] sd 25:0:0:0: [sdh] Add. Sense: No additional sense information
[711822.460922] sd 25:0:0:0: [sdh] CDB: 
[711822.460924] Read(10): 28 00 0f a9 6b 10 00 00 10 00
[711822.460936] blk_update_request: I/O error, dev sdh, sector 262761232
[711822.460982] XFS (dm-0): metadata I/O error: block 0xfa1bb10 ("xlog_recover_do..(read#2)") error 5 numblks 16
[711822.478620] XFS (dm-0): log mount/recovery failed: error -5
[711822.478680] XFS (dm-0): log mount failed
[711827.723684] XFS (dm-0): Mounting V4 Filesystem
[711827.866409] XFS (dm-0): Starting recovery (logdev: internal)
[711830.994951] sd 25:0:0:0: [sdh] FAILED Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE
[711830.994959] sd 25:0:0:0: [sdh] Sense Key : Hardware Error [current]
[711830.994962] sd 25:0:0:0: [sdh] Add. Sense: No additional sense information
[711830.994965] sd 25:0:0:0: [sdh] CDB: 
[711830.994967] Read(10): 28 00 0f a9 6b 10 00 00 10 00
[711830.994979] blk_update_request: I/O error, dev sdh, sector 262761232
[711847.817378] sd 25:0:0:0: [sdh] FAILED Result: hostbyte=DID_ERROR driverbyte=DRIVER_SENSE
[711847.817386] sd 25:0:0:0: [sdh] Sense Key : Hardware Error [current]
[711847.817390] sd 25:0:0:0: [sdh] Add. Sense: No additional sense information
[711847.817393] sd 25:0:0:0: [sdh] CDB: 
[711847.817395] Read(10): 28 00 0f a9 6b 10 00 00 10 00
[711847.817406] blk_update_request: I/O error, dev sdh, sector 262761232
[711847.817480] XFS (dm-0): metadata I/O error: block 0xfa1bb10 ("xlog_recover_do..(read#2)") error 5 numblks 16
[711847.839055] XFS (dm-0): log mount/recovery failed: error -5
[711847.839111] XFS (dm-0): log mount

このI/OエラーによってLVMの /var パーティションが読み込めなくなった。このパーティションが読み込めなくなるのはシステムとして致命的である :$。例えばゲートウェイ+ルータ機能、ブログなどのＤＢシステム、SSHなどランタイムサービスの他、apt パッケージシステムが動かない等、かなり厳しい状況だった。
特にHDD内にあるブログやウェブのデータが逝ってしまったことで、最初は心が折れそうになってしまった ;(。

1日ほど塞ぎこんでしまったが、ゲートウェイ機能を復旧させないと、いつまでたってもインターネットに接続できないので、ひとまずHDDを新調してシステムの全復旧を行うことにした。それに、かなり古いけどブログのDBのバックアップが残っていた ;) ので、時間はかかるけどブログの方は再び書いていけば、いつか元に戻るであろうと前向きに考えることにした :D。

ということで、まずは新規のSSD（120GB）とHDD（3TB）を注文、到着するまでの間は既存のHDDからデータの吸い上げ。この時、I/OエラーがでていたHDDについては重要なデータがストアされており、色々試すことで結局は負荷をかけてハードウェアの寿命が縮んでしまいそうなので、GNU Ddrescue なるツールでddイメージを安全かつ堅実に抜き出すことにした。これは本当に素晴らしいツール：

  • 不良セクタをスキップして、良好データをまず先に復旧する
  • これによりHDDに不必要な負荷をかけることがないため、最終的に復旧できるデータ量が大きい
  • 不良セクタはログに記録できる
  • 別ツールであるddrescureviewを使うとGTK+ベースの GUI 上にセクタのマップを表示することができる

I/OエラーがでたパーティションはLVMボリュームで容量は 500GB であったが、Ddrescue は特に問題なかった。このサイズのrawイメージを保存できる空きHDDを用意して、玄人志向のHDDスタンド経由でDdrescureを実行した：

$ sudo ddrescue -n -v /dev/mikeforce-vg/vgroup-var_lv ./back-vgroup-var_lv.img back-vgroup-var_lv.log 
GNU ddrescue 1.19
About to copy 536870 MBytes from /dev/mikeforce-vg/vgroup-var_lv to ./back-vgroup-var_lv.img.
 Starting positions: infile = 0 B, outfile = 0 B
 Copy block size: 128 sectors Initial skip size: 128 sectors
Sector size: 512 Bytes

Press Ctrl-C to interrupt
rescued: 536870 MB, errsize: 12288 B, current rate: 1686 B/s
 ipos: 268691 MB, errors: 3, average rate: 16525 kB/s
 opos: 268691 MB, run time: 9.02 h, successful read: 0 s ago
Finished

500GBのrawイメージを9時間ほどかけて取得、不良セクタは12KBと予想外に少なかった ;)。この後、XFSのfschkであるxfs_repairでファイルシステムを補修してからloopbackでマウントしてみたら、見事にパーティションを読み込むことができた：

$ sudo xfs_repair -L -f /opt/back-vgroup-var_lv.img
Phase 1 - find and verify superblock...
Cannot get host filesystem geometry.
Repair may fail if there is a sector size mismatch between
the image and the host filesystem.
Phase 2 - using internal log
 - zero log...
ALERT: The filesystem has valuable metadata changes in a log which is being
destroyed because the -L option was used.
 - scan filesystem freespace and inode maps...
out-of-order bno btree record 46 (98638 1) block 1/4
block (1,98638-98638) multiply claimed by bno space tree, state - 1
out-of-order bno btree record 47 (225432 1) block 1/4
block (1,225432-225432) multiply claimed by bno space tree, state - 1
out-of-order bno btree record 48 (292435 2) block 1/4
block (1,292435-292435) multiply claimed by bno space tree, state - 1
out-of-order bno btree record 174 (324055 3) block 1/4
block (1,324055-324055) multiply claimed by bno space tree, state - 1
out-of-order bno btree record 175 (324059 2) block 1/4
block (1,324059-324059) multiply claimed by bno space tree, state - 1
out-of-order bno btree record 176 (324096 5) block 1/4
block (1,324096-324096) multiply claimed by bno space tree, state - 1
agf_freeblks 27730912, counted 27730884 in ag 1
agf_freeblks 28437926, counted 28437911 in ag 3
block (2,5220537-5220537) multiply claimed by cnt space tree, state - 2
agf_freeblks 26476336, counted 26476369 in ag 2
agi_freecount 51, counted 52 in ag 3
agi_freecount 64, counted 65 in ag 2
agi_freecount 139, counted 142 in ag 0
sb_ifree 368, counted 335
sb_fdblocks 106740156, counted 106773627
 - found root inode chunk
Phase 3 - for each AG...
 - scan and clear agi unlinked lists...
 - process known inodes and perform inode discovery...
 - agno = 0
data fork in ino 137948 claims free block 4822
data fork in ino 137948 claims free block 4823
correcting nblocks for inode 10686304, was 1 - counted 0
 - agno = 1
Metadata corruption detected at block 0xfa1bb10/0x2000
(...)
Metadata corruption detected at block 0xfa1bb10/0x2000
Metadata corruption detected at block 0xfa1bb10/0x2000
data fork in ino 536882165 claims free block 33555077
Metadata corruption detected at block 0xfa03108/0x1000
corrupt block 0 in directory inode 536896076
 will junk block
no . entry for directory 536896076
no .. entry for directory 536896076
problem with directory contents in inode 536896076
cleared inode 536896076
bad magic number 0x0 on inode 537097760
bad version number 0x0 on inode 537097760
(...)
Phase 4 - check for duplicate blocks...
 - setting up duplicate extent list...
 - check for inodes claiming duplicate blocks...
 - agno = 0
 - agno = 1
 - agno = 2
 - agno = 3
(...)
Phase 5 - rebuild AG headers and trees...
 - reset superblock...
Phase 6 - check inode connectivity...
 - resetting contents of realtime bitmap and summary inodes
 - traversing filesystem ...
(...)
Phase 7 - verify and correct link counts...
resetting inode 61515 nlinks from 20 to 19
resetting inode 512221 nlinks from 16 to 15
Metadata corruption detected at block 0x8058/0x1000
libxfs_writebufr: write verifer failed on bno 0x8058/0x1000
Metadata corruption detected at block 0x3fe90/0x1000
libxfs_writebufr: write verifer failed on bno 0x3fe90/0x1000
Metadata corruption detected at block 0x3fe90/0x1000
libxfs_writebufr: write verifer failed on bno 0x3fe90/0x1000
Metadata corruption detected at block 0x8058/0x1000
libxfs_writebufr: write verifer failed on bno 0x8058/0x1000
done
$ sudo mount -o loop /opt/back-vgroup-var_lv.img ./mnt
$

こちらがddrescueviewで表示させたもの。赤色が不良セクタ：

ddrescueviewの結果

不良セクタのサイズが少なかったことが不幸中の幸いだった。これらのセクタはMySQLのデータであったけどブログには影響が無くて安心した 0:)。

思えば、今夏の酷暑がHDDに与えていた影響は少なくない[a]加えて、筐体も普通のPCのタワー型だし。として、HDD間の配置を変更し、RootfsはSSDにして発熱を抑えることにした。そして、今さらながらHDDの寿命と故障率について身にしみたのでバックアップを励行することにした。

ということで、全復旧までお金と一週間ほどの時間を要したけど、素晴らしいツールと教訓を得ることができて良しとする。

この後は、自動バックアップシステムを構築し、S.M.A.R.Tで温度を監視しつつサーバを運用することにする。

参照

参照
↑a 加えて、筐体も普通のPCのタワー型だし。

Mikeforce server downed.

1件のフィードバック

この記事をアップできている現在は復旧済みで、ことの顛末は次のような次第：

先週は平成30（2018）年9月1日[a]週末の土曜日で仏滅だった。朝、歯医者に行くために少し早めに起きて天気予報を確認しようと Web を開いたら「インターネットに接続できません」なるメッセージが表示された。日頃、常時接続な環境なので、モデムかハブか何かが落ちたかと思って見てみたが特に問題はない。あれ!?っとPCを見てみるとケースにある青色の電源ランプが点いていなかった :|。う〜ｍ。
たしか昨晩寝る前、部屋の照明を消した時に扇風機の電源ランプ[b]これも青い色。暗い部屋では赤色と共に最も視認しやすく目につく色である。が消えていることを確認したが、同時にその背後にPCの電源ランプが見えていたのを記憶していたので、その時までは確かに動いていた。

で、ケースの電源ボタンを押してみたが全く動かない。何もしていないのに電源が落ち、さらに電源が入らないということで、まず最初に昨年春に取り替えた電源ユニットのCoolerMaster V650 Semi-Modular[c]昨年、突然 PC の電源モジュールからカラカラ音が鳴り出したので、調べたらファンの羽が折れ曲がっていた。最初は叩いたら収まっていたが、段々と音も大きくなってきたので電源ユニット本体を取り替えたと云う次第。を疑った。

ケースを開けて、歯医者に出かけるギリギリまで調べてみたが、ハードウェアが故障したような「臭い」は無く、特に電源ユニット回りに至っては焦げた跡など異常は見当たらず。加えて電源ユニットを ON するとマザーボードのP9X79上にあるStandby Power LEDが点灯するので電源ユニットからマザーボードへは通電しているっぽい。しかしケースの電源ボタンを押してもマザーボード上のChassis LEDやCPUファンは動かないし、何より電源ユニットが動いていない :$。

今まで見たことの無い症状。
その昔、Windows系OSが載ったPCが立ち上がらなかった時があったが、その時はCMOSの電池切れだったり、DIMMがキチンと差さっておらず少し浮いていたのが原因だった。一応、今回は起動中に落ちているぽいので関係は無いとは思うが、念の為、予備の電池のCR2032に交換したり、メモリを挿し直したが特に変化なし：

グラフィックスボードを外したところ

これにあまり時間を割いていられないし、外（インターネット）に気安く出られないのも不便[d]このサーバはWifiなどの自宅内ネットワークのGWでもある。だし、なにより電源ユニットが問題ということであれば5年保証を要求するところだけど、そこまで原因が確定できていない。メーカーとやりとりしていたら復旧が来週一杯までかかってしまいそう。なので、ここは翌日までに入手できそうな電源ユニットをスマフォから Amazon で注文。いろいろ迷ったが昨年購入したユニットの廉価版っぽいCoolerMaster MW Semi-Modular 650Wにした。値段は半額ほど。まぁ買い捨て覚悟。

そして翌朝の日曜日、ありがたいことに午前中の早い時間に受け取ることができたので、早速マザーボードと電源ユニットを接続してみたが、一回目はケースや CPU ファンが少しだけ動いたものの、結果は同じで電源は立ち上がらない :|。 う〜ｍ。いやはや困った。もしかしてマザーボードか!?なんて、思わず最悪な状況を想像してしまった :(。

ここでPCI Expressに装着していたグラフィックスボードの陰に隠れていたLEDを確認しようと、一旦取り外して電源を入れてみると、ピポッと音がなるやいなやCPUファンが回りだして、POSTまで動き出した :O。
なんと原因はグラフィックスボードだった：

これが問題の NVIDIA GeForce GTX 660Ti (2GB)

この二枚差しDuallボード、てっきりボード上部に付いていたPCI Expressコネクタに電源ケーブルを指していなければ電源は供給されないものと思っていたが、どうやら間違い。マザーボードからも電源は供給されているようだ（二枚差しだから）。以前はデスクトップとして使っていたPCを今はサーバとして使っている。なので2枚差しのグラフィックスパワーを使う機会は全く無い :D。

ということで、今の時間から Amazon を利用しても無駄なので、単にVGAとして利用できる安価なグラフィックスボードを電車に乗ってヨドバシで購入して挿してみたら、あっけなく起動した：

NVIDIA GEFORCE GT710 (2GB)

購入したのはNVIDIA GEFORCE GT710（5,510円/当時）。サーバならば、この程度で十分すぎるスペック。原則的にリモート操作で、どうせ起動時のログを確認する程度にしか使わないし。

ということで、あとでsyslogのログを確認してみたら、PCが落ちたのは9月1日 05:39:16だった。早朝のクロン・ルーチン中に落ちたっぽいがKernelログには異常は無いのでハードウェア故障だ。復旧までに24時間くらいかかってしまった。初動調査で電源が怪しいと見てしまったのが原因だけど、まさかグラフィックスボードが原因で起動しないなって。だって、なくても起動するし :/。

ということで不要な電源が一つできてしまった。欲しい方がいれば譲ります =)。

参照

参照
↑a 週末の土曜日で仏滅だった。
↑b これも青い色。暗い部屋では赤色と共に最も視認しやすく目につく色である。
↑c 昨年、突然 PC の電源モジュールからカラカラ音が鳴り出したので、調べたらファンの羽が折れ曲がっていた。最初は叩いたら収まっていたが、段々と音も大きくなってきたので電源ユニット本体を取り替えたと云う次第。
↑d このサーバはWifiなどの自宅内ネットワークのGWでもある。