安定稼働しないtuboneのサーバー周り。
どうも。可用性に自身ニキのAWS S3の障害が話題ですが、我が家でも障害。
我が家にある録画サーバーですが、かなり長い時間、障害でサービスが提供できない、という、AWSもびっくりな障害がありました。
Table of Contents
障害検知-ALM発生
ALM発生は25~26夜にかけて、0バイトファイルが作成されるというALMがZABBIXから上がりました。
仕組みは、録画サーバーの先にNFSで接続されているNASに0バイトファイルが一定時間以上作成されたままになると、
loggerコマンドでエラーログをはく、というcronで検知するものですが、そちらのALMが発生したのですね。
とりあえず、時間がなかったということと疲れていたということで録画サーバーの系切り替えを実施し、その場をしのぎました。(系切り替え自体はうまく行きました。リソースの兼ね合い上、バックアップ側での録画はワンセグ形式になるので画質は良くないです。)
さて、次の土日まで、どうにも直す気力がなくて、そのままにしておりました。(NAS側の障害の可能性を当初疑っていましたが、ファイルの作成自体は、問題なくできているので本格的に原因を調査する必要があり、稼働も気力も間に合いませんでした)
障害原因調査-復旧
さて、本格的に本問題を解決する日が来ました。
まずは再起動。
とりあえず録画サーバーのプロセス(サービス)を再起動しました。
録画サーバーでは2つのプロセスが動いています。
WEB-UIを提供するchinachu-wuiと
録画や録画予約処理をするchinachu-operator
それぞれ再起動しましたが事象は解決せず。
次にサーバー(録画サーバーはKVM上に立てられた仮想マシンです)の再起動。
とりあえずrebootコマンド。
解決せず。
次にNASの再起動
解決せず。 NASを再起動したので、NASを利用している別サーバーにも念のためログインして使えているか
確認。(ここが時間かかる。)
ならばハイパーバイザから仮想マシンの停止・起動だ。
解決せず。
ここで飯を食う。(のんきなものです)
物理デバイスと仮想マシンの相性の悪さ
飯を食い終わったとき、ふと気になったことが。
実はALMが発生した日、別の併発ALMが出ていました。
録画サーバーで録画したファイルはとても大きいので順次圧縮しています。
それは別ノード(余ったノートPC)で実行しているのですが、そちらが完全に
機能停止するALMが上がっていました。
原因は簡単で、勝手に親が部屋に入り電源周りをいじったか何かで電源が落ちたこと。
もしかして、チューナ周りもいじったのでは??
監視サーバー経由でハイパーバイザの仮想マシンマネージャーを確認し、USBのアタッチ状況を確認。
我が家の仮想基盤サーバーはKVM+QEMU+libvirtと仮想マシンマネージャーというオーソドックスな
Linuxの仮想基盤となっています。
仮想マシンの設定を見る限り、USBで確実にアタッチされているみたい。仮想基盤サーバー上の
USB監視も問題なし。
まさか。
実際に録画サーバーに入り、lsusb。
あ。
認識されていない。
原因判明。すぐさま、仮想マシンマネージャー経由でサーバーをシャットダウン。
設定を入れ直し再度起動。
録画できた。お疲れ様でした。
振り返り
KVMでの物理デバイスの管理はほぼほぼQEMUが行っている(という認識ですが間違っているかもしれません。たしかKVMのメインのお仕事はCPUリソースの払い出しだったと思います。)
のですが、そちらの方の設定はUSBリダイレクションではなく、ホストPCのUSBのパススルーで設定しております。
そちらで一時的にUSBが切り離された場合、仮想基盤側では再組み込みと再割り当てが行われますが、どうやら仮想マシンにまで再割り当てはされないもようです。
リソースの割り当ては起動前、という原則に則れば、当たり前なのですが…。
なので、一度切り離されたUSBは(一瞬でも)仮想マシンには戻らない、ということになります。なるほど。
実はこれだけ原因の切り分けに時間がかかっていましたが、灯台もと暗し。アプリログには以下の文面が。
5 Mar 02:04:02 - RECORD: 2017-03-05T02:00:00+0900 [TOKYO MX2] ヒーリン
グタイム&ヘッドラインニュース
5 Mar 02:04:02 - LOCK: PX-S1UD (n=0)
5 Mar 02:04:02 - SPAWN: recdvb --dev 0 --b25 --strip --sid 23610 20 - - (pid=147
6)
5 Mar 02:04:02 - WRITE: /home/tubone/chinachu/data/recording.json
5 Mar 02:04:02 - STREAM: /media/tv/[170305-0200][20]ヒーリングタイム&ヘッドライ
ンニュース.m2ts
5 Mar 02:04:02 - #recdvb: using device: /dev/dvb/adapter0 pid = 1476 cannot open frontend device
5 Mar 02:04:02 - UNLOCK: PX-S1UD (n=0)
そうです。frontend deviceがopenできないという。(Linux特有の表現ですが、デバイスファイルが開けない=使えないということです。)
ちなみに、正常時は
5 Mar 22:26:55 - STREAM: /media/tv/[170305-2227][20]にゃんこデイズ.m2ts
5 Mar 22:26:55 - #recdvb: using device: /dev/dvb/adapter0 using pid = 10294 device = /dev/dvb/adapter0/frontend0 Using DVB card "Siano M
obile Digital MDTV Receiver" tuning to 515143 kHz polling..
と、デバイスファイルが開ける。
こんな簡単なログを見落としてたのか。失格ですね。
対策
今後、このような障害を起こさないように以下の対策をします。
まず、lsusb監視を仮想サーバーそばにもつけるようにします。(今週中)
アプリログについて、監視文言にcannot open frontend deviceを加えます。
また、それ以外にも明示的にErrorと表記されないものについて見直しをし、
Zabbixに挙げられるようにします。(3月中)
さらに、監視サーバー上のVNCの解像度が低く、仮想マシンマネージャーの操作に難があり、
一部virshコマンド等でオペレーションをしておりました。画面解像度の見直しをします。(対策済み)
サービスを守る。という使命感が乏しかったので、今後はサーバー優先の生活をするように担当者(自分)に言い聞かせました。
以上。