けんちゃんくんさんの乱とはなんだったのか

by pyamain mrubyon 投稿日:

mod_mruby ngx_mruby Advent Calendar 2017の記事を書きます。内容は僕が１２月の初旬に格闘していたくんさんレンタルについてです。

なお、無事、収束しているので変ではなく乱として扱います。変と乱の違いは下記を参照ください。

nginxのtracとしてはこのあたりが近いと思います。

乱の詳細

ペパボのEC事業部のケンちゃんくんさんがロリポップマネージドクラウド上でサービスを開始したくんさんレンタルのサイト描画が正常に行われない場合があるというのが初期症状でした。

ブラウザのデバッガーを利用するとこのように、jsや画像資産が正常にダウンロード出来ていないことが確認できました。

jsや画像系で起きていたのでHTTP/2のサーバプッシュを疑ったのですが、特にそういった設定は入っていなかったため、次に、ストリームの不具合を疑い、nginxのhttp2_max_concurrent_streamsに1を設定してみました。

すると問題なく表示がされたので、被疑がHTTP/2に移ります。この段階でHTTP/2を利用しなければ問題ないことは確定ではあったので、本番サーバでは一時的にHTTP/2を無効にしました。

次に状況を再現し、デバッグするためにdocker-composeを利用して、諸々の環境を準備し、手元で実行したところ全く症状が起きないことがわかりました。

本番環境と手元の環境の差異を考えてみると、クライアントとサーバのNW距離と、それに比例するNWレイテンシが考えられます。

その仮説に基づき、下記のパラメーターのチューニングを行いました。(一部)

  • net.ipv4.tcp_tw_reuse
  • net.ipv4.tcp_rmem
  • net.ipv4.tcp_wmem
  • net.core.rmem_max
  • net.core.wmem_max

しかし、スループットに多少の変化はあったものの、不安定な状況は改善しませんでした。次に被疑に考えたのはngx_mrubyのフックポイントです。この症状が起きる前にmruby_output_header_filterを利用して、レスポンスの直前にある処理を行うというフックを追加していました。このフックを利用することでレスポンスの処理がブロックされることになるので、そこが一つ何か問題を起こしているのではないかと考えました。

そこで試しに、フックポイントをmruby_output_header_filterからmruby_output_body_filterへ変更したところ、問題なくコンテンツが表示されるようになったため、この時点でmruby_output_header_filterが原因だとこの時点で断定しました。

後に、問題はこれだけでは解決せず、最終的にはmruby_log_handlerのフックを利用することになりました。

これらのことからHTTP/2とngx_mrubyを利用した場合に、output_filterで何か問題がありそうだと思って、先程まで環境を粛々と作っておったのですが、手元の環境では再現すらせず、完全に詰んでいました・・・

おそらく、HTTP/2 + ngx_mruby + NWレイテンシなのかなぁ・・・とぼやっとは思っているものの、今日中に環境作るのがあれだったのでひとまず記事を書いてみました。今日はいよいよクリスマス・イブですね！明日はペパボのアドカレの担当なので皆様また明日お会いしましょう？