大量データの JSON serialize 処理を高速化し、レスポンスが倍速になった話

こんにちは、freee会計でワークフロー機能の開発をしている @mitubaEX です。

先日 freee会計のパフォーマンスチューニングに取り組みました。本記事では、調査の流れ、改善の事例を紹介します。

問題発覚までの流れ

freee では自社の経理業務に freee会計を利用しており、その中でも経費精算の機能はほぼすべての従業員が利用しています。そのため日々多くのフィードバックをもらえます。そのフィードバックの1つで、「経費精算の一覧を開くのが遅い」という報告をもらいました。幸い表示件数を指定できるので調整すれば遅くはならないのですが、一覧性が下がってしまうため有用な解決策ではありません。

そこでワークフローを開発しているチームで、このパフォーマンスイシューの調査を始めました。

調査する

まず事前調査として Datadog*1 で一覧画面を表示するリクエストの処理を確認しました。

上図の赤枠で囲んだ部分は DB アクセスを伴う処理で、それ以外の空白の部分がアプリケーションの処理になります。この情報から、DB の処理は遅く無くアプリケーションの処理にネックがある状態だと推測を立てました。もう少し詳細に見ると DB アクセスが前半部分と後半部分にあることから、前半部分が一覧データの取得部分で後半部分が serialize 時の依存データの取得部分であると推測できました。この間には一覧画面に表示するデータの生成処理が存在しボトルネックになっていることが確認できたので、ここに着目し調査を進めました。

調査する際に行ったことは stackprof*2 、Datadog trace*3 によるボトルネックとなっている箇所の処理の把握です。

stackprof による調査では、一覧画面に表示するデータの生成処理を profiling するようにコードに変更を加え、検証環境にデプロイしました。その後データ量が多い事業所のデータを用いて該当箇所を動かして profile を出力しました。そうして取得された profile を Frame Graph で吐いたものを以下に示します。

この Frame Graph により、極端に遅い処理に当たりを付けることができます。

次にDatadog trace を該当箇所に仕込み、どれくらい時間がかかっているかも測定しました。すると全体の 92.1%を一覧画面に表示するデータの生成処理が占めていました。

さて、これで原因箇所の特定ができたので、上記の情報を参考に実際のコードを読み始めました。

どのような部分がボトルネックになっていたのか

結論から言うと、大量のデータを JSON に serialize する処理がボトルネックになっていました。freee 会計では脱Rails Way を進めており ActiveRecord を介さずにデータを serialize する設計に徐々に置き換わっています。この置き換え後の serialize 時のデータ取得方法が非効率だったのが原因でした。

実装の詳細について触れると、serialize するために必要なデータを取得する際、ネストした依存を取得するという処理があります。この情報を取得するためには一つずつ依存を掘る必要があり、依存を掘るためには一時オブジェクトを作り次の依存を取得する必要があります。この一時オブジェクトの量がデータ量に応じて増え、別の依存を一から取得する際に一時オブジェクトを何度も作り直してしまっていたことがパフォーマンスイシューになっていました。

これらの解決策として、依存の探索方法を効率化し作成される一時オブジェクトの数を削減しました。これにより今回のパフォーマンスイシューの改善を行うことができました。

また脱 Rails Way の話は mihyaeru の登壇資料に記載されているので、興味のある方は是非お読みください。

speakerdeck.com