Blend day's Note

思い立ったことをメモする

FreeNAS に １週間溶かした話

技術 ハードウェア

kayo-tozaki.hatenablog.com

↑前回のエントリーから早１週間。とある事案で１週間ぐらい溶かしてしまいました。

その抗いの過程的何かをまとめてメモしておこうかと。

ことのはじまり

FreeNASを構築して、組み立てから予め予定していた設計通りにZFSを構築・設定をして、予めとっておいたバックアップデータをリストアしていったのですが、

リストアを始めてから2日目、データをコピーし始めたら…

「あれ？CIFSが落ちるぞ〜？？Ping通るけどWebUIが読み込まないぞ〜〜〜？？」

この時、まさか１週間溶かす事になるとは、知る由もなかった。

起こった現象

1) ZFS(raidz1-0) を組んだ ボリューム に CIFS を利用してWindowsからアクセスする

2) CIFS 経由で3GB以上のデータを移す

3) CIFS で接続しているドライブからの応答がなくなる。（転送中のプログレスバーが緑から赤になって、最終的には切断のポップアップが）

f:id:kayo_tozaki:20160313123946j:plain

↓

f:id:kayo_tozaki:20160313124832j:plain

4) FreeNASのWebUIにアクセス出来なくなる

5) 最悪の場合、HDDが１台抜けるというアラートが鳴り響く（メール）

という一連の流れ。

または

  1. ブートする
  2. HDDが抜けてる
  3. ZFSが崩壊しているというアラートが鳴り響く

ということが起こっていました。 前者はやるたびに必ず。後者は前者のインシデント発生後に起こることが多かったことです。

この現象を赤バー現象と名付けます。以下頻出するのでご了承を

構成

物理構成

前回ブログに記述したとおりですがもう一度

  • CPU : AMD A6-7400K
  • MEM : 16 GB (8GB * 2) + 4GB ( 2GB * 2 ) / あまりもの
  • Mother : A88XM-E45 V2
  • POW : KRPW-L5 400W/80+
  • CASE : Fractal Design node 804
  • Storage : HDD 2TB * 4 + 0.5TB * 3 / かき集めたもの

ソフトウェア構成

こちらは初出

OS

FreeNAS-9.3-STABLE-201602031011

USBメモリにOSをインストールして使用

ボリューム構成

  • 2.0TB * 4 : zraid1-0 / 6TB
  • 0.5TB * 3 : zraid1-0 / 1TB

それぞれに、以下の設定を付与

  • 圧縮レベル : lz4 (継承)
  • ZFS 重複排除 : ON (継承)

設定した共有

  • CIFS
  • NFS (未検証)
  • S.M.A.R.T
  • SSH

設定変更した内容がどこだかわからないぐらいにいじったので、設定箇所は省略。

考えられる原因とその調査結果

一週間も頭を抱えて色々と原因を考えていました。ずっとぐるぐるしてたので他にも原因が上げられそうな感じがしますが、解決したので打ち切りしました…疲れたのです…

ハード面

HDD の故障

→ HDDに書き込みできないってことは…と思い一番最初に思いつきました

今回障害を起こしたディスクはSamsungのHD500HI（偶然にも3台とも同じ型番) です。

HDDといえば、S.M.A.R.TチェックとメーカのHDD検査ツールで生死確認をするのが基本だと思うので、今回もそうしました。

結果的には、SMARTもHDD検査ツール*1も問題なく通過しました。安堵感と残念感が同時に味わえました。

電源の容量不足

→ HDD７台ってことは電源が…と思い立った次第

実際に、CPUのTDPとHDDに書かれている電圧・電流標記と400W電源のスペックをにらめっこした結果...

f:id:kayo_tozaki:20160313100146p:plain

参考までに、玄人志向の製品詳細ページにあった表↓

f:id:kayo_tozaki:20160313100214p:plain

見た感じ、すごく余裕そう*2

NIC が本領発揮してない？

→ 今回のマザーボードは所謂 蟹（realtek) NICなので、INTELとは違って本領が発揮できて無いのでは無いかと思って…

Pingは通るけど、ブラウザは見れない。SSHのコネクションもロストする（ロストしなくても、入力が受け付けられない）ので、もしかしたら...

検査は、秘儀 iftopとか使いたかったのですが、なんせベースOSが FreeBSD なので、普段のLinuxとは全然違くて...

結局検査できなかったので、こちらは不明です。転送中にどう見ても理論値超え*3だろって数値出たのでもういいです。

メモリーの故障

→ 20GBあるうち、OS側は16GBぐらいしか使ってなさそうなので、もしかしたらメモリーも壊れてるかも…？

この考えが出てきたのは、最終日付近で、そろそろ諦めムードが漂ってきはじめ、疲れがピークに...という時なので半分やけくそです。

検査は、memtest86+ をUSBブートで動かしました。Passは１回ぽっきりです。一周するのに３時間弱かかったので。

結果は問題なく通過です。問題なんか何もないよ～♪*4

ソフト側

CIFS の 調整ミス

→ デフォルトから変更しているかもしれないのでもしかしたら…

CIFS(Samba)を使う時だけめでたく落ちるので、疑い始めました。 このように断定するのは、CIFSを使った時に落ちるファイル（3GB）をiSCSIでマウントしたドライブに転送しても落ちなかった。というのが理由です。

この時に色々とパラメーターを弄ったのです。

読込が遅い

よくわからなくなってきたので、思ったことは片っ端から治すことに。

解決方法は、smb4.confに store dos attributes = no とするだけ。
確かに読込は早くなったが、転送時の赤バーは未だに治らず

認証周りが怪しい

ログが大量に上がってました

[2016/03/12 17:15:06.704243,  1] ../source3/smbd/files.c:218(file_init_global)
  file_init_global: Information only: requested 440381 open files, 59392 are available.
[2016/03/12 17:15:07.014400,  0] ../lib/util/become_daemon.c:136(daemon_ready)
  STATUS=daemon 'smbd' finished starting up and ready to serve connectionsFailed to fetch record!
[2016/03/12 17:17:00.836324,  1] ../source3/smbd/server_reload.c:69(delete_and_reload_printers)
  pcap cache not loaded
  STATUS=daemon 'smbd' finished starting up and ready to serve connectionscreate_connection_session_info failed: NT_STATUS_ACCESS_DENIED
  STATUS=daemon 'smbd' finished starting up and ready to serve connectionscreate_connection_session_info failed: NT_STATUS_ACCESS_DENIED
  STATUS=daemon 'smbd' finished starting up and ready to serve connectionscreate_connection_session_info failed: NT_STATUS_ACCESS_DENIED
  STATUS=daemon 'smbd' finished starting up and ready to serve connectionscreate_connection_session_info failed: NT_STATUS_ACCESS_DENIED
  STATUS=daemon 'smbd' finished starting up and ready to serve connectionsFailed to fetch record!
[2016/03/12 17:18:07.716346,  1] ../source3/smbd/server_reload.c:69(delete_and_reload_printers)
  pcap cache not loaded
  STATUS=daemon 'smbd' finished starting up and ready to serve connectionsScheduled cleanup of brl and lock database after unclean shutdown
[2016/03/12 17:22:34.384464,  1] ../source3/smbd/service.c:1130(close_cnum)
  natsudama-pc (ipv4:192.168.1.17:6853) closed connection to service samba-nas
[2016/03/12 17:22:53.987127,  1] ../source3/smbd/server.c:391(cleanup_timeout_fn)
  Cleaning up brl and lock database after unclean shutdown
[2016/03/12 17:27:04.885292,  1] ../source3/printing/printer_list.c:226(printer_list_get_last_refresh)
  Failed to fetch record!
[2016/03/12 17:27:05.585167,  1] ../source3/smbd/server_reload.c:69(delete_and_reload_printers)
  pcap cache not loaded
[2016/03/12 17:27:06.584579,  1] ../source3/smbd/service.c:550(make_connection_snum)
  create_connection_session_info failed: NT_STATUS_ACCESS_DENIED
[2016/03/12 17:27:07.555948,  1] ../source3/smbd/service.c:550(make_connection_snum)
  create_connection_session_info failed: NT_STATUS_ACCESS_DENIED
[2016/03/12 17:27:08.283670,  1] ../source3/smbd/service.c:550(make_connection_snum)
  create_connection_session_info failed: NT_STATUS_ACCESS_DENIED
[2016/03/12 17:27:09.153937,  1] ../source3/smbd/service.c:550(make_connection_snum)
  create_connection_session_info failed: NT_STATUS_ACCESS_DENIED
[2016/03/12 17:27:11.585229,  1] ../source3/printing/printer_list.c:226(printer_list_get_last_refresh)
  Failed to fetch record!
[2016/03/12 17:27:12.186169,  1] ../source3/smbd/server_reload.c:69(delete_and_reload_printers)
  pcap cache not loaded
[2016/03/12 17:27:13.284007,  1] ../source3/smbd/service.c:550(make_connection_snum)
  create_connection_session_info failed: NT_STATUS_ACCESS_DENIED
[2016/03/12 17:27:14.254715,  1] ../source3/smbd/service.c:550(make_connection_snum)
  create_connection_session_info failed: NT_STATUS_ACCESS_DENIED
[2016/03/12 17:27:14.882766,  1] ../source3/smbd/service.c:550(make_connection_snum)
  create_connection_session_info failed: NT_STATUS_ACCESS_DENIED
[2016/03/12 17:27:15.755886,  1] ../source3/smbd/service.c:550(make_connection_snum)
  create_connection_session_info failed: NT_STATUS_ACCESS_DENIED
[2016/03/12 17:28:26.745392,  1] ../source3/smbd/server.c:438(remove_child_pid)
  Scheduled cleanup of brl and lock database after unclean shutdown
[2016/03/12 17:28:46.746095,  1] ../source3/smbd/server.c:391(cleanup_timeout_fn)
  Cleaning up brl and lock database after unclean shutdown
[2016/03/12 17:29:19.164145,  1] ../source3/printing/printer_list.c:226(printer_list_get_last_refresh)
  Failed to fetch record!
[2016/03/12 17:29:19.164218,  1] ../source3/smbd/server_reload.c:69(delete_and_reload_printers)
  pcap cache not loaded

調べてみると、先ほど同様、 smb4.conf に client ntlmv2 auth = no を設定するとログはでなくなった気がしました。
が、これも関係ないです。お先真っ暗☆

USBへの書き込み速度

→ デフォルトではUSBにSyslogが書き込まれていませんが、設定を変えてログなどはUSBに書き込むようにセットしたのですが、それが原因かも…？

と、思ったのですが、関係ないみたいで。

設定を元に戻した（system data の保存先をHDD側(デフォルト）にする）上で、再度実験するも、赤バー現象は解消されず...

FreeNASのバージョン

→ 絶賛開発中っぽいので、バージョンがあれかもしれない…

なんでもかんでも疑心暗鬼に疑います。最新版に上げても症状変わらず。

ZFSのメモリーバカ食い…？

ameblo.jp

この辺りが怪しいかも…？とか。もうこの頃になると何が怪しんだかわからなくて迷走してました。

とりあえず、上記サイト様を参考に設定すると、ちょっとだけ改善された気が*5したので、もしかしたら...という気がしてきました。

ZFS の調整ミス

→ CIFS同様。もしかしたら...

と、言う訳で、色々とパラメーターを見ていると...

f:id:kayo_tozaki:20160313102318j:plain

"ZFS 重複排除"...

闇雲に一つづつONとOFFをやってみると...

赤バー現象が解消した!!

今まで、１００発１００中で止まっていたファイルが、綺麗に転送できました。

更なる調査のため、他のサイズのデカいファイル*6を転送すると...

完全解消！

別の仮想環境で同じような環境（FreeNAS9.3.1,HDD３台raidz）を構築して、ZFS重複排除をOn,CIFSも有効化した上で、検証した結果、

同様の赤バー現象が起こることを確認しました。

というわけで、原因は、 ZFS 重複排除でした。

まとめ

赤バー現象は、ZFS 重複排除 機能によるものでした

ZFSの便利機能で、良かれと思ってOnにしていたものが、まさかの部分で引っかかり、正直驚いています。

なぜ引っかかったのかは不明ですが、おそらく、１ファイルが大きすぎて、重複確認とコピーしてきたものとでディスクIOが詰まったのでは無いかと勝手に思っています。

色々と学べた

今回の騒動で学べたことを箇条書きで上げてみると...

  • FreeNASはインストールは楽。
  • ZFSは奥が深い
  • 新しい機能を良かれと思って付け過ぎると、のちのち困る
  • 頭の回転をもっと早くしなければならない
  • FreeBSDはLinuxとは違う
  • logはしっかり読もう
  • 注意書きはしっかり読もう

Enabling dedup may have drastic performance implications, as well as impact your ability to access your data. Consider using compression instead.

「dedup(重複排除)を有効化することは、根本的なシステムに包括されることになり、
あなたのデータにアクセスすることにとても強いインパクトを与えることになります。
熟考した上で、圧縮の代わりにお使いください」
（筆者訳：間違えている可能性あり / ZFS 重複排除 の注意書き）

おまけ

今回の騒動中のBGMはこちら↓です。

www.amazon.co.jp

恋愛マニュアルとエーリアンガールフレンドが好きです。ぜひぜひ。

*1:Samsungのツールではなく、Seagateのツールを使用しました。買収されていたのを知りませんでした...

*2:実は、検証中はWの値をAと見間違えて全然足りねぇ...とか思ってたり思ってなかったり...

*3:175MB/sという表示が一瞬だけ。んなわけあるか→100MB/s → 10MB/s → 赤バー →▂▅▇█▓▒(’ω’)▒▓█▇▅▂ っていう流れが何度もありました

*4:http://www.kasi-time.com/item-67754.html

*5:プラシーボ効果？

*6:小さいものは赤バー現象が起こっていないので