知人NASのCIFS共有が調子良くない問題の調査中、smbdがアホほどメモリ確保する現象に見舞われた。1プロセスあたりギガ単位で消費し、最終的に16GBの物理メモリとスワップ64GBを食いつぶし、強制的に電源落とすしかなくなるなんて、どう考えても異常だ。smbdがメモリをバカ食いするせいでARCにメモリが割り当てられず、ストレージの実効性能が上がらないのもCIFSが遅い問題の遠因になってると思われる。
Sambaのオプションをあれこれイジった所、シャドウコピーを有効にするとダメっぽい。下図がシャドウコピーオプション有無でのtopを比較したものだ。
もうね、笑っちゃうくらい一目瞭然。メモリ消費量が文字通り桁違いである。シャドーコピー有効の方は、1日足らずでメモリ枯渇しかけてるのに対し、無効の方は4日程度経過のロードアベレージが13行くほどの負荷が掛かってるのに余裕のよっちゃんイカ。（ちなみにこの状態でもつつがなくファイル共有が行われている。）
Sambaでシャドーコピーってことは、vfs_shadow_copy2モジュールあたりがバグってんのかしらね？NAS4Free 9か10の頃は、シャドーコピー有効でもこんなこと起こらなかった記憶があるんだけど…。（超おぼろげなので保証はできない。）
この記事には技術的裏付けがない、個人の感想、雑感、推測がふんだんに含まれています。ご利用の際は用法・用量を守り正しくお使いください。
知人のNAS4Freeなファイルサーバが重い問題、Sambaが原因で一件落着かと思いきや解決してなかった。（こっちはこっちで別の問題が発生してたりするので別途書く予定。）
知人とやり取りしつつCPU, ネットワーク, ディスクI/O, その他諸々を継続的にモニタリングしてみると、どーにもディスクアクセスがボトルネックになっている事があるようで…。ファイルサーバのターミナルで直接cpしても、全然速度が上がらないのだ。対象のファイルは、50～200kBの数十万個のPNGを含む膨大なファイル群で、ファイルシステム的に結構厳しい条件ではあるものの、ストレージは仮にもHDD 2ペア×3セットからなるRAID10である。十数MB/sは出るだろうと思ってたが、実際には1MB/s以下になることさえある。
いくらなんでもオカシイだろうとzpool iostatしてみた結果がこちら。
capacity operations bandwidth
pool alloc free read write read write
---------- ----- ----- ----- ----- ----- -----
zdata 4.56T 6.31T 5.65K 435 25.5M 4.94M
zdata 4.56T 6.31T 7.43K 0 32.7M 0
zdata 4.56T 6.31T 5.44K 0 24.1M 0
zdata 4.56T 6.31T 6.20K 0 27.3M 0
zdata 4.56T 6.31T 6.44K 0 28.4M 0
zdata 4.56T 6.31T 5.81K 398 26.6M 3.89M
zdata 4.56T 6.31T 4.36K 215 34.8M 10.8M
zdata 4.56T 6.31T 2.76K 391 12.5M 3.47M
zdata 4.56T 6.31T 3.58K 0 19.7M 0
zdata 4.56T 6.31T 3.65K 0 20.1M 0
zdata 4.56T 6.31T 3.15K 0 17.7M 0
zdata 4.56T 6.31T 4.05K 0 19.0M 0
zdata 4.56T 6.31T 2.59K 343 14.6M 3.15M
zdata 4.56T 6.31T 3.66K 0 19.6M 0
zdata 4.56T 6.31T 4.99K 0 32.5M 0
zdata 4.56T 6.31T 2.93K 0 19.1M 0
zdata 4.56T 6.31T 6.38K 0 28.4M 0
zdata 4.56T 6.31T 3K 344 13.6M 2.99M
zdata 4.56T 6.31T 3.86K 0 17.9M 0
zdata 4.56T 6.31T 3.77K 0 16.9M 0
zdata 4.56T 6.31T 3.72K 0 16.8M 0
zdata 4.56T 6.31T 2.91K 226 13.3M 2.39M
読み込み操作数（operations）と読み込み量（bandwidth）の割に、書き込み量が著しく少ない。コピーと並行してSambaへ断続的なアクセスがあるってことを差し引いても全然スループットが出てない。つーか、書き込み量とネットワークに出ていく量を合わせても全然読み込み量に足らん罠。
大量の読み込みoperationsが走ってても、いい感じに処理できてる時は↓こんな感じで順当にbandwidthが上がる。CIFSによるリクエスト分がそのまま処理されてネットワークに流れていっている。
capacity operations bandwidth
pool alloc free read write read write
---------- ----- ----- ----- ----- ----- -----
zdata 4.70T 6.17T 15.3K 638 64.8M 7.06M
zdata 4.70T 6.17T 23.8K 0 101M 0
zdata 4.70T 6.17T 20.4K 0 85.9M 0
zdata 4.70T 6.17T 23.6K 0 98.7M 0
zdata 4.70T 6.17T 18.4K 0 76.5M 0
zdata 4.70T 6.17T 7.06K 720 30.1M 8.41M
zdata 4.70T 6.17T 16.6K 0 70.0M 0
zdata 4.70T 6.17T 13.7K 0 57.7M 0
zdata 4.70T 6.17T 18.1K 0 77.3M 0
zdata 4.70T 6.17T 16.7K 536 72.3M 6.52M
zdata 4.70T 6.17T 7.63K 80 32.5M 376K
zdata 4.70T 6.17T 12.3K 0 52.7M 0
zdata 4.70T 6.17T 9.78K 0 42.4M 0
zdata 4.70T 6.17T 11.8K 0 51.0M 0
zdata 4.70T 6.17T 9.32K 586 40.4M 6.41M
zdata 4.70T 6.17T 9.47K 0 40.6M 0
zdata 4.70T 6.17T 11.6K 0 49.2M 0
zdata 4.70T 6.17T 12.1K 0 51.8M 0
zdata 4.70T 6.17T 5.05K 0 22.2M 0
zdata 4.70T 6.17T 4.88K 579 22.1M 6.61M
rsyncでディスク内コピーを行うと更に悲惨で、びっくりするほど速度が出ない。ネットワーク（1000BASE-T）越しの別マシンにzfs sendし、そいつとrsyncで同期した方が早いっていうね…。すわ、断片化か！？と思ったけど、プールは半分以上空いてるしちょっと考えにくい。
あれこれ考えてるうちに、ZFSはキャッシュのヒット率が重要って事を思い出した。1フォルダに大量の細かなファイルがあるって事は、その分メタデータ処理が重いと考えられる。とすれば、メタデータを使いまくってそうなrsyncで速度が出ないってのも説明が付く………気がしなくもない。
zfs-statsを入れてキャッシュのヒット率を見てみたら、なんと2割を切ってるじゃないの。キャッシュに乗り切らなかったメタデータに毎度アクセスしに行くために、read operationsの割にbandwidthが上がらなかったのかしら…？
とりあえずarc関連のカーネル変数を調整したところ、いい感じでキャッシュヒットするようになった。問題のプール内のディレクトリ間でrsyncした時の結果が↓これ。
キャッシュヒット率が90%ほどに改善し、書き込みも12MB/s程出ている（zdata iostatは1秒毎、vfs.zfs.txg.timeout=5である）。
購入時期は忘れたが、その昔、中古で買ったSSDSC2BB240G4が発掘されたのでベンチをうｐ。家鯖で、VM置き場/ZIL/L2ARCとして使っていたブツ。
-----------------------------------------------------------------------
CrystalDiskMark 6.0.0 x64 (C) 2007-2017 hiyohiyo
Crystal Dew World : https://crystalmark.info/
-----------------------------------------------------------------------
* MB/s = 1,000,000 bytes/s [SATA/600 = 600,000,000 bytes/s]
* KB = 1000 bytes, KiB = 1024 bytes
Sequential Read (Q= 32,T= 1) : 509.971 MB/s
Sequential Write (Q= 32,T= 1) : 285.330 MB/s
Random Read 4KiB (Q= 8,T= 8) : 312.081 MB/s [ 76191.7 IOPS]
Random Write 4KiB (Q= 8,T= 8) : 271.718 MB/s [ 66337.4 IOPS]
Random Read 4KiB (Q= 32,T= 1) : 271.167 MB/s [ 66202.9 IOPS]
Random Write 4KiB (Q= 32,T= 1) : 252.995 MB/s [ 61766.4 IOPS]
Random Read 4KiB (Q= 1,T= 1) : 33.345 MB/s [ 8140.9 IOPS]
Random Write 4KiB (Q= 1,T= 1) : 94.851 MB/s [ 23157.0 IOPS]
Test : 4096 MiB [D: 0.1% (0.1/223.4 GiB)] (x3) [Interval=5 sec]
Date : 2018/03/01 1:41:52
OS : Windows 10 Professional [10.0 Build 16299] (x64)
Intel SSDSC2BB240G4
PS4 Proに挿してたST2000LX001が壊れた件！Seagate絶許！！でカッとなってPS4用のSSDとしてIntel DC S3500の800GBを買ったった。SSDSC2BB800G4のDELL向けOEM品で、いつものごとく中古。からのいつものごとくベンチ。今回はいつもと違ってSATA接続だぬ。
-----------------------------------------------------------------------
CrystalDiskMark 6.0.0 x64 (C) 2007-2017 hiyohiyo
Crystal Dew World : https://crystalmark.info/
-----------------------------------------------------------------------
* MB/s = 1,000,000 bytes/s [SATA/600 = 600,000,000 bytes/s]
* KB = 1000 bytes, KiB = 1024 bytes
Sequential Read (Q= 32,T= 1) : 509.671 MB/s
Sequential Write (Q= 32,T= 1) : 493.405 MB/s
Random Read 4KiB (Q= 8,T= 8) : 311.824 MB/s [ 76128.9 IOPS]
Random Write 4KiB (Q= 8,T= 8) : 274.177 MB/s [ 66937.7 IOPS]
Random Read 4KiB (Q= 32,T= 1) : 271.002 MB/s [ 66162.6 IOPS]
Random Write 4KiB (Q= 32,T= 1) : 261.758 MB/s [ 63905.8 IOPS]
Random Read 4KiB (Q= 1,T= 1) : 33.284 MB/s [ 8126.0 IOPS]
Random Write 4KiB (Q= 1,T= 1) : 95.878 MB/s [ 23407.7 IOPS]
Test : 4096 MiB [D: 0.0% (0.2/745.1 GiB)] (x3) [Interval=5 sec]
Date : 2018/02/28 22:58:44
OS : Windows 10 Professional [10.0 Build 16299] (x64)
Intel SSDSC2BB800G4R
ベンチ結果はいつも通りというか何というか。
S.M.A.R.T.から総読み書き量は取れないけど、稼働時間からしたら然程使われてないものかなと。
着々とIntel DCシリーズが増えていってる・・・！
ZFSプールが手狭になったため、HDDを順繰り大容量のものにzpool replaceしてた。
$ zpool status zdata
pool: zdata
state: ONLINE
status: One or more devices has experienced an error resulting in data
corruption. Applications may be affected.
action: Restore the file in question if possible. Otherwise restore the
entire pool from backup.
see: http://illumos.org/msg/ZFS-8000-8A
scan: resilvered 8.82T in 25h57m with 2 errors on Tue Jan 23 22:47:38 2018
config:
NAME STATE READ WRITE CKSUM
zdata ONLINE 0 0 2
raidz1-0 ONLINE 0 0 4
ada3p1 ONLINE 0 0 0
ada2p1 ONLINE 0 0 0
replacing-2 ONLINE 0 0 0
ada1p1 ONLINE 0 0 0
da0p1 ONLINE 0 0 0
ada5p1 ONLINE 0 0 0
logs
mirror-1 ONLINE 0 0 0
ada6p5 ONLINE 0 0 0
ada7p5 ONLINE 0 0 0
errors: 2 data errors, use '-v' for a list
replace-2でada1p1をda0p1にreplaceしてた感じ。置き換え中のデバイスには(resilvering)表記が付くのだが、ご覧の通り上記のda0p1には付いてない。てなもんで、処理が終わったと判断し、ada1p1を切り離そうとしたら…
# zpool detach zdata ada1p1
cannot detach ada1p1: no valid replicas
と、言われてしまった所で日記タイトルなのである。
「有効なレプリカがない」とな…。ZFS暦7年目にして初めて目にするエラーでござる。errors: 2 data errors, use '-v' for a listで報告された壊れているファイルを消してもダメぽ。それどころか、、、
# zpool status -v zdata
pool: zdata
state: ONLINE
status: One or more devices has experienced an error resulting in data
corruption. Applications may be affected.
action: Restore the file in question if possible. Otherwise restore the
entire pool from backup.
see: http://illumos.org/msg/ZFS-8000-8A
scan: resilvered 8.82T in 25h57m with 2 errors on Tue Jan 23 22:47:38 2018
config:
NAME STATE READ WRITE CKSUM
zdata ONLINE 0 0 0
raidz1-0 ONLINE 0 0 0
ada3p1 ONLINE 0 0 0
ada2p1 ONLINE 0 0 0
replacing-2 ONLINE 0 0 0
ada1p1 ONLINE 0 0 0
da0p1 ONLINE 0 0 0
ada5p1 ONLINE 0 0 0
logs
mirror-1 ONLINE 0 0 0
ada6p5 ONLINE 0 0 0
ada7p5 ONLINE 0 0 0
errors: Permanent errors have been detected in the following files:
zdata/NFC/data/Decomo:<0x196090>
なんやねん、zdata/NFC/data/Decomo:<0x196090>って。こうなったら神頼みのzpool scrubするしかない。
# zpool scrub zdata
$ zpool status zdata
pool: zdata
state: ONLINE
status: One or more devices has experienced an error resulting in data
corruption. Applications may be affected.
action: Restore the file in question if possible. Otherwise restore the
entire pool from backup.
see: http://illumos.org/msg/ZFS-8000-8A
scan: scrub in progress since Tue Jan 23 23:39:17 2018
100G scanned out of 18.1T at 427M/s, 12h15m to go
25.0G repaired, 0.54% done
config:
NAME STATE READ WRITE CKSUM
zdata ONLINE 0 0 0
raidz1-0 ONLINE 0 0 0
ada3p1 ONLINE 0 0 0
ada2p1 ONLINE 0 0 0
replacing-2 ONLINE 0 0 0
ada1p1 ONLINE 0 0 0
da0p1 ONLINE 0 0 0 (repairing)
ada5p1 ONLINE 0 0 0
logs
mirror-1 ONLINE 0 0 0
ada6p5 ONLINE 0 0 0
ada7p5 ONLINE 0 0 0
修復が始まった。replaceでのresilveringは一体なんだったのか…。しばらく放置してからプールの状態を見てみると、、、
$ zpool status zdata
pool: zdata
state: ONLINE
status: Some supported features are not enabled on the pool. The pool can
still be used, but some features are unavailable.
action: Enable all features using 'zpool upgrade'. Once this is done,
the pool may no longer be accessible by software that does not support
the features. See zpool-features(7) for details.
scan: scrub repaired 4.51T in 15h42m with 0 errors on Wed Jan 24 15:21:24 2018
config:
NAME STATE READ WRITE CKSUM
zdata ONLINE 0 0 0
raidz1-0 ONLINE 0 0 0
ada3p1 ONLINE 0 0 0
ada2p1 ONLINE 0 0 0
da0p1 ONLINE 0 0 0
ada5p1 ONLINE 0 0 0
logs
mirror-1 ONLINE 0 0 0
ada6p5 ONLINE 0 0 0
ada7p5 ONLINE 0 0 0
errors: No known data errors
修復が終わりデバイスの置き換えまで行われてる！
今回得た知見：
