先日、アプリケーション全体で最も遅く、リグレッション（リリース後、パフォーマンスが低下）している関数を表示する機能を開始しました。
今回、新しいタイプのパフォーマンス・イシューで、関数レベルのリグレッションをデバッグできるようになりました。関数のリグレッション問題は、アプリケーションの関数がリグレッションしたときに通知されますが、単にリグレッションを検出するだけではありません。
関数リグレッションの問題は、Sentry Profilingをサポートしているプラットフォームであれば検出することができます。以下では、Pythonプロジェクトのバックエンドを例に説明していきます。
上のスクリーンショットは、Sentryのライブランニングサーバーコードのスローダウンを特定した、実際のFunction Regression Issueです。Redisに保存された顧客のレート制限をチェックする関数の持続時間が50%近くも後退したために発生しました。
上のグラフは関数の持続時間の経時変化を示し、下のグラフは呼び出し回数（スループット）を示しています。スループットもスローダウン期間中に増加していることがわかります。これは、負荷の増加がこの回帰の原因の1つである可能性を示唆しています。
上のスクリーンショットでは、同じ問題によって、どのAPIエンドポイントがリグレッションの影響を受け、どれだけパフォーマンスが後退したかといった他の重要な情報を見ることができます。このデータから、レート制限関数が多くのエンドポイントで広く使用され、呼び出された結果、バックエンド全体のパフォーマンスが大幅に低下したことがわかります。
回帰問題からプロファイルを確認して根本原因を見つける
リグレッションした関数の問題では、リグレッションの前後にキャプチャされたプロファイルを簡単に確認できます。これらのプロファイルを比較することで、リグレッションの原因となった実行時の動作の変化を（コードレベルで）明らかにし、最も重要なコンテキストを提供します。
ここで実際に、リグレッションが発生する前にキャプチャされたプロファイル・イベントの例を見てみましょう。リグレッションが発生した関数は、サードパーティのredisモジュール内の2つの関数を呼び出していることに気づきました。 ConnectionPool.get_connectionとConnectionPool.releaseです。
これをリグレッション後に収集したプロファイルと比較したところ、これら2つの関数のうちの1つであるConnectionPool.get_connectionに以前よりも大幅に時間がかかっていることがわかります。
プロファイルの各関数フレームは、関数が定義された場所と実行された行番号のソース・コンテキストを提供します。この場合、redisモジュールでこのソースの場所を開くと、次の行（以下の画像参照）であることがわかりました。
この行はロックの取得を試みており、この行を実行したときの壁時間の大幅な増加は、複数のプロセスまたはスレッドが同時にロックを取得しようとしていることを示唆しています。このロックの競合がコード・レベルでのリグレッションの原因であることがわかります。
このロック競合の問題は、先にスループット・グラフで見たこと、つまりスループットが増加すると競合が起こりやすくなることとも一致しています。追加の調査を通じて、この関数のスループットの増加は、リグレッションの頃に始まったRedis接続数の増加に対応していることがわかりました。
今回の例を通じて、リグレッションした関数の問題が、プロファイリングデータを使ってリグレッションを引き起こしているコードに直接リンクするのに役立つことを説明しました。
今回の例はバックエンドのユースケースに焦点を当てていますが、この機能はSentry Profilingをサポートするどのプラットフォームでも機能します。
ファンクション・リグレッションの問題は、アーリー・アダプターの皆様には本日よりご利用いただけます。
結論
人々が使いたいと思うような差別化された製品を構築するためには、高性能なバーが不可欠です。ウェブ・バイタルとファンクション・レグレッション・イシューにより、すべての開発者がコードに接続することでパフォーマンスの問題を解決できる方法を提供していきます。
IchizokuはSentryと提携し、日本でSentry製品の導入支援、テクニカルサポート、ベストプラクティスの共有を行なっています。Ichizokuが提供するSentryの日本語サイトについてはこちらをご覧ください。またご導入についての相談はこちらのフォームからお気軽にお問い合わせください。
