日々の破片

_ Rails 5.2.0から5.2.1で何か重要な修正が入ったようだが調べなかった(多分わかった)

サーバーサイドでPDFを作るために、ネストしたRailsの呼出しを作った。

最初にクライアントからリクエストを得る。（Action Aが動く）

コントローラの中でリクエストの正当性を検証した後に、サーバーサイドで動作しているヘッドレスChromeをDevToolsで操作してリクエストを要求させる。

ヘッドレスChromeは別のアクションを呼び出す。（Action Bが動く）呼出しに答えてレスポンスを返す。

Action Aで動いていたDevToolsクライアントがNavigateの完了を得て、さらにいろいろ動いたあと、DevToolsでPDF出力を要求し、結果のBase64（PDFそのもの）を得る。

Base64をデコードして（つまりapplication/pdfを得て）Action Aのクライアントに応答を返す。

これを2つのドメインで動かしているのだが、開発用のドメインでは2回に1回はタイムアウトすることに気付いた（発生タイミングはランダム）。ログを見ると、Action Bが動くかどうかのぎりぎりのところでハングし（ActionControllerに制御が与えられたかどうか微妙なところだ）、Action Aに対してnginxのタイマアウト検出によってAction Bの残りが動作して解消している。

少なくともpumaの中では止まっていないので、次にactionpackの中を順番に見ていくのだがなかなか止まっている箇所にたどりつけない。

同じDBのロウに対する読み込み（Action Aの検証でfindをかけている）だから一瞬行ロックか？ と思ったが、明示していない以上、それはあり得ない（というか、そんな理由なら100発100中のはずだが、半分は成功する）。

聞き込みをしてみると、ステージング用ドメインでは一切そういう問題は発生していないらしい（リクエスト数ははるかにステージング用のほうが多いので発生していたらもっと早く気づく）。

これも理解できないので、何が違うか調べたら、ステージング環境へのデプロイでBundleを動かすところで特にバージョン制限していなかったから、開発環境はRails 5.2.0、ステージングは5.2.1で、そこが違った。

なんだ、リリースノートを見ればわかるな、と思ったらわからん。

GVLが原因のデッドロックだというのはほぼ間違いないのだが（他に理由があり得ない。とはいえ、Action AはヘッドレスChromeに対するDevTools呼出しのWebsocketの待ち状態でしか無いはずで、ここには問題はない）、調査打ち切り。

#追記：https://github.com/puma/puma/pull/1563 このissueの修正版のpumaがRails 5.2.1には含まれているからではないか？

# 2018/10/11 多分、理由がわかった。バージョンは関係なくて、開発環境だと修正->試す->ロックされて死ぬ→試す→修正->試す->ロックされて死ぬ→試すというサイクルを取ることが問題だったのだ。つまり、修正->試す->ロックされて死ぬ→試す→試す（以降OK）。developmentなので（またそれを期待している）クラスの再読み込みが走る、それが原因でほぼ間違いない。再読み込み中に別スレッドでさらに再読み込みが走るのでデッドロックするのだろう。