こんにちは。サーバーサイドエンジニアの三村です。
保険薬局と患者さまを繋ぐ「かかりつけ薬局」化支援アプリ kakariやその姉妹サービスである患者接点を資産化する診療予約システム かかりつけクリニック支援サービス kakari for Clinicの開発を担当しています。
目次
はじめに
kakariをRuby v3.1.0にアップグレードする作業をしていたところSegmentation faultに遭遇したので、bugs.ruby への報告や再現コード作成などの経緯をまとめました。
賢い方法では無い部分も多々ありますが、温かい目で見守ってください。
bugs.rubyのissueはこちらです。
※ Ruby本体の実装の話は出てきません。
現象
kakariでRuby v3.1にアップデートをしたら、CircleCIで実行しているRSpecでたまにSegmentation faultが発生するようになりました。
以下のような状態でした。
- ActiveDecoratorの内部処理で発生
- 複数回発生
- エラー箇所は1箇所ではない
- 再実行すると直る
bugs.rubyに報告
何はともあれ、Segmentation faultはRubyのバグなので報告します。 が、原因分からず再現コードも全然整理出来ていなかったので報告を躊躇いました。 そんなときに便利なruby-jp Slack
温かく受け入れてくれそうだったので、安心してissueを作成することが出来ました。https://bugs.ruby-lang.org/issues/18489
issue起票当時は再現コードを整理する余裕がなかったので少しでも情報量を多くしようと思い、遭遇したSegmentation faultのログを複数個添付しました。
原因究明までの道のり
環境依存の問題かどうかを切り分け
これまでCircleCIでのみ再現していたので別の環境でも発生するのかをまず切り分けました。
ローカル開発環境(Docker Desktop for Mac)で複数回RSpecを全件実行し、無事に?再現することが確認出来ました。
Docker Image( cimg/ruby:3.1.0-browsers を利用 )依存ならまだしもCircleCI環境依存だった場合は原因究明までの試行錯誤が恐ろしく大変だったので一安心。
エラー発生ファイルの特定
特定のrequest specで再現することがすぐに判明出来ました。 が、このrequest specを単体で何回も実行しても再現しないことからファイルの読み込み順依存の問題であることも同時に分かり悲しみ。（ファイルの読み込み順問題よくありますよね）
specの実行順をランダムから定義順に変更
specは config.order = :random が指定されランダム順に実行されるようになっていたので、これを defined に変更し読み込み順を定義順にしました。
この状態でも本問題が再現することが確認できたのはかなりラッキーでした。
「randomの場合でのみたまに遭遇」みたいな状態だったらseed固定などもう一工夫必要になり面倒で諦めていたかもしれません。
因果関係のあるテストを特定
ここからは地道な試行錯誤の繰り返しです。
以下のspec群から本問題に関係のあるものを特定していきます。
$ tree -L 1 spec/ spec/ ├── controllers ├── decorators ├── helpers ├── lib ├── mailers ├── models ├── push_notifiers ├── requests ├── serializers ├── system ├── uploaders ├── validators └── workers
まずは試行時間の短縮の為に重たいspecを除外を試みました。 特にテスト数の多いmodelsと一つ一つが重たいsystemsを除外しました。 幸いこれらを除外しても変わらずSegmentation faultは再現できたのもラッキー。
脱Docker Desktop for Mac
この後もひたすらspecを実行しまくることが想像できたので少しでもspec実行時間を短くするように先に工夫しました。
kakariではDocker Desktop for Macを利用してローカル開発環境を構築しています。 が、これは色々な要因で重いことが有名ですね（詳細は割愛）。
ということで、脱Docker Desktop for Macを試みました*1。 （恒例の）mysql2のbuildでエラーになるなどちょいハマりポイントはあったものの、すんなり対応出来ました。 真面目に計測したわけではないですが、1.5~2倍くらい早くなった気がします。（かなりうろ覚えなので気になる方はご自身でお確かめください。）
MySQL -> SQLiteに変更
次にMySQLからSQLiteに変更をしました。
本事象は十中八九データベースは無関係だろうと予想していました。
MySQLが重たいわけではないですがSQLiteにすることでインメモリーなデータベースを利用することができる ( database: ':memory:' こんなやつ ) のでspecの並列実行が容易になりました。
基本的にDBの差異はActiveRecordが吸収しているのでadapterを切り替えるだけで済みました。 一部、外部キー制約やindex周りの挙動の違いはあったものの取り上げるほどのものはありませんでした。 （というか本事象と無関係だろうと思い深く考えずコメントアウトしたりして対応していました。）
↓はイメージですが、こんな感じの頭の悪い方法でspecを並列実行することが出来ました。
再現コードの特定
上記の工夫のおかげもあり、因果関係のあるファイルを数個に特定することができたのでミニマムな再現コードの調査に切り替えました。 特に「request specでのみ再現」という状況が色々と面倒だったので何とかシンプルなRubyスクリプトコードを書けないかを模索。
数行のRubyスクリプトコードで再現したりしなかったりする状態までたどり着いたものの、再現有無の条件が全く分かりませんでした。
が、唐突に「GCか？」と思いついたため試しに GC.start を差し込んでみたところめでたく再現しました。
ここから先は簡単で、ActiveDecoratorを利用して書かれた再現コードをplainなRubyコードに変換するだけです。 ActiveDecoratorのコードは予め目を通していたお陰でここは数分で出来ました。
その結果出来た再現コードがこちらです。
M = Module.new Object.new.extend(M) GC.start M.include(Module.new)
二日くらい費やした結果、美しく短い再現コードを作れた時は若干の感動がありました。
再現コード報告
早速「再現コード作れたよ」と追加報告です。
「ActiveDecoratorでSegmentation fault発生」という状況から一気にシンプルな再現コードに飛躍してしまったので「ActiveDecoratorをこんな感じに使ったら再現するよ」というのを添えてコメントしたのは我ながら親切ポイントです。
そして、再現コードをコメントしてから僅か2時間足らずでn0kadaさんが修正PRを作成してくれました。（流石だ）
修正確認
その後、issue上で 「Does https://github.com/ruby/ruby/pull/5455 fix it?」と聞かれてしまったので確認するしかありません。
Rubyをcloneして自前でビルドするのは初めてだったので不安がありましたが、実際にはruby/rubyのREADME手順通りにコマンド打つだけで大きなハマりどころもなくすんなり出来ました。 強いて言えばopensslのパス設定が必要だったかな程度です。あまり覚えていないくらい些細な問題でした。
上記の「脱Docker Desktop for mac」をしておいたのも地味に良かったです。
ruby-jpで相談していたところ、 k0kubunさんのブログ を紹介してもらいとても参考になりました（ありがとうございます！！） ※ 特に「ビルドしたrubyをrbenvから使うには」の所は便利
というわけで、大した苦労もなく無事に修正確認できました。
work around
無事に修正PRもマージされたとは言え流石にheadなrubyコードを利用するわけにはいかないので別途回避する方法を模索します。
これに関しては再現コードの特定が既に出来ているため簡単な話で、以下のような（不適切な形で）ActiveDecoratorを利用している箇所の修正するだけで済みました。
let!(:user) do - build(:user).extend UserDecorator + ActiveDecorator::Decorator.instance.decorate(build(:user)) end
本事象が発生していたのはspecのみで、実際のプロダクトコードでは同様の事象はなさそうでした。
まとめ
- Rubyを触り始めて6年近く経ちますが、初めて Ruby本体 にまともな貢献が出来たかなと実感できとても良い経験でした。
- ruby-jp Slackで気軽に相談できたのがとても有り難かったです。感謝感謝です。
- 自分のコミットではないにしろ、ほぼ同等のものが「テストコード」としてRubyに入ったの嬉しい。
- 褒められたの嬉しい。
ruby-jp Slackで褒められた様子
おまけ
無事にkakariはRuby v3.1.0にアップグレードすることができました。 本件は色々とありましたが、それ以外に必要な対応は殆どなくRubyの後方互換性の高さに感謝です。
以上です。 もし「Segmentation faultに遭遇して困った」なんて時に本記事が参考になれば幸いです。
メドピアでは一緒に働く仲間を募集しています。 ご応募をお待ちしております！
■募集ポジションはこちら
https://medpeer.co.jp/recruit/entry/
■開発環境はこちら
https://medpeer.co.jp/recruit/workplace/development.html
*1:今回の調査中だけの話です
