ゲームラグ白書 › L11 ディスク
同期ログ書き込み Synchronous logging
原因ID dk-sync-log · 主担当 ゲーム開発チーム・サーバー開発 · 副担当 インフラチーム・サーバーインフラ
図と実験のあるメインページでこのカードを開く →
ゲームスレッドがログを1行書くたびにディスクへの書き込み完了を待っていると、ディスクが忙しいときにゲームの進行も一緒に止まります。
なぜ 戦闘・取引ログをゲームスレッドから直接ファイルに書く → すると 確実な書き込み（fsync）を要求したり、OSの書き込みバッファ（ページキャッシュ）が上限に達したりすると、ディスクが忙しいときに1回の書き込みが数十ms → 画面では ログの多い戦闘で一瞬止まる
- 症状
- カクつき, フリーズ
- 要因
- ストール
- 誰に起きるか
- 特定の場所・チャンネル, サーバー全体
- いつ
- 人が集中したとき
- 担当
- 主担当 ゲーム開発チーム・サーバー開発 · 副担当 インフラチーム・サーバーインフラ
- ゲーム開発チームの対応
- 非同期ロギング（メモリバッファ + 別スレッド）、ログ量の削減、ゲームスレッドではfsyncしない。
- インフラチームの対応
- ログのローテーション・圧縮はI/O優先度を下げて実行、ログはデータとは別のディスクに、ディスク書き込み遅延の監視。
- グラフでは
- 不定期なスパイク · サーバーのティック時間、ディスク書き込み遅延
- 確認箇所
- iostat -x 1のw_await・aqu-szをティック時間と重ねて確認し、perf trace -p PID --duration 10でゲームサーバー内の10msを超えたwrite・fsync呼び出しとそのスレッドを探す
- 該当する場合
- ティックが跳ねた時刻に、ゲームスレッドのwrite・fsync呼び出しが数十msかかり、その瞬間ディスク書き込み遅延も跳ね上がる。ログのローテーション・圧縮の時刻と重なることが多い
- 該当しない場合
- ゲームスレッドに時間のかかったシステムコールがないのにティックが跳ねるなら、GC・ロック・ティックバジェット超過など別の原因。ログ専用スレッドだけが長くかかっているなら、ゲームの進行には影響しない
- 確認手段
- インフラのツールで確認（ゲームコード不要）
- もっと詳しく
- 通常、OSは書き込みをまずメモリ（ページキャッシュ）で受け取り、あとからディスクに書き出すので、ログ1行の書き込みはたいていすぐに終わります。止まるのは、fsyncで確実な書き込みを要求したとき、たまった書き込みが上限を超えてOSが書き込みの呼び出しをブロックしたとき、ログファイルをローテーションしたり圧縮したりするときです。そのため、普段は問題ないのに、ディスクが忙しい瞬間にだけ跳ねます。
出典
- fsync(2) — Linux manual page Linux man-pages
fsyncは変更されたデータをディスク（ディスクキャッシュを含む）まで書き出し、デバイスが完了を通知するまでブロック - Documentation for /proc/sys/vm/ Linux kernel
たまった書き込み（dirty）がdirty_ratioに達すると、書き込みをしているプロセス自身がディスクへの書き出しを肩代わりする - ionice(1) — Linux manual page util-linux
idleのI/O優先度で動かした処理は、他のプログラムがディスクを使っていないときだけディスク時間を得る - iostat(1) — Linux manual page sysstat
-x：w_await（書き込み要求がキューで待った時間を含む平均処理時間）、aqu-sz（平均キュー長、旧名avgqu-sz） - perf-trace(1) — Linux manual page perf
-pで実行中のプロセスのシステムコールをトレース、--durationで指定したmsより長くかかった呼び出しだけを表示
あわせて読みたい原因
同じ層：L11 ディスク
同じ症状（カクつき）を起こすほかの層の原因
図と実験のあるメインページでこのカードを見る