サービスのパフォーマンステストがうまくいかないときに確認すべきポイント - Cybozu Inside Out

この記事は、CYBOZU SUMMER BLOG FES '24 (クラウド基盤 Stage) DAY 14 の記事です。

クラウド基盤本部 Cloud Platform 部の新井です。 Cloud Platform 部では現在、現行クラウド基盤上で動作している製品を、Kubernetes ベースの新基盤に移行させるための様々なサービスを開発・運用しています。その中には、特にパフォーマンスが心配なサービスがあったので、パフォーマンステストを行ってボトルネックを分析し、最終的にスループットを10倍向上させました。

めでたしめでたし 🎉

と言いたいところなんですが、この結果を得るまでに複数のハマりどころがあり、想定よりも長い時間がかかってしまいました。そこで本記事では、私たちがどのようにサーバのパフォーマンステストを実施して、どんな落とし穴にハマってきたのかをご紹介します。

このプロジェクトで採用したツール

パフォーマンステストを行えるツールは数多く存在しますが、このプロジェクトでは k6 を採用しました。 k6 を採用した理由は、社内で利用実績があったことと、チームでよく使っている Go で書かれていたからです。

grafana.com

そして、パフォーマンステストの対象のサービスも Go で書かれています。そのため、これ以降で書くことは k6 や Go 特有のものもありますが、それ以外のツール・言語を使う場合でも適用できることもあるので、参考になれば幸いです。

k6 の基本的な使い方

以下では k6 の用語も出てくるので、簡単に k6 の使い方について説明します。今回利用した k6 のバージョンは、k6 v0.49.0 (commit/b5328aa782, go1.21.6, linux/amd64) です。まずは、Get started > Running k6 に書かれているように、以下のようなコマンドを実行します。

$ k6 new            # パフォーマンステストの設定ファイルが script.js という名前で作成されます。
$ k6 run script.js  # script.js の設定内容でパフォーマンステストを実行します。

k6 new で生成される設定ファイルは、コメント行を除くと以下のようになっています。

import http from 'k6/http';
import { sleep } from 'k6';

export const options = {
  vus: 10,          // 同時にリクエストする仮想ユーザの数
  duration: '30s',  // テスト時間
};

export default function() {
  http.get('https://test.k6.io');
  sleep(1);
}

この設定では、https://test.k6.io に GET リクエストを送信してレスポンスを受け取った後、1秒間スリープするという手続きを、10個のグリーンスレッドで並行実行します。 30秒経過後、パフォーマンステストは終了し、結果のサマリ（リクエスト・レスポンスサイズ、レイテンシなど）が標準出力に出ます。

指定した秒間リクエスト数で負荷をかける方法

上の方法では、指定した数のユーザが指定した間隔でリクエストを送ってくるというシナリオは表現できるのですが、パフォーマンステストでは、ある秒間リクエスト数で負荷がかかっている時のパフォーマンスを測定したいということがよくあります。そのような場合、以下のように script.js を変更します。

import { check } from 'k6';
import http from 'k6/http';

export const options = {
  scenarios: {
    contacts: {
      executor: 'constant-arrival-rate',
      duration: '30s',
      rate: 100,  // timeUnit 内に下の関数を実行する回数
      timeUnit: '1s',
      preAllocatedVUs: 200,  // あらかじめ立ち上げておくグリーンスレッドの数
    },
  },
};

export default function () {
  http.get('https://test.k6.io');
}

このようにして、秒間 100 リクエストの負荷をかけられます。詳細は Open and closed models をご確認ください。

パフォーマンステストの実施

次に、パフォーマンステストを行った際にハマったことと、それをどのように解決したかを紹介します。

負荷をかける側のリソース不足

経緯

パフォーマンステストを実施する環境を整えて、負荷の設定を行い、実際にサーバに負荷をかけてついにレイテンシを測定できました。そこで、徐々に負荷を高めてレイテンシを測定する作業を繰り返していると、ある秒間リクエストを境にレイテンシが大きく増加したので、ここが捌ける負荷の限界だとわかり、ボトルネックの分析に取り掛かりました。

しかし、アプリケーションサーバ・DB サーバの CPU・メモリ使用量はそれなりに高いもののまだ余裕がありました。処理の中で CPU の待ちが発生しているのか、それとも全く考えていなかったところで遅くなっているのか、と考えましたが、原因は別のところにありました。

原因と解決

原因は負荷をかける側（クライアント）のリソース不足でした。これが厄介なのは、問題に気づきにくいことです。例えばメモリ不足になると Out Of Memory で気付けることもありますが、CPU の場合はリクエストを送ってからレスポンスを受け取るまでの時間が伸びるだけなので、パフォーマンステストの結果だけを見ているとサーバ側の性能劣化にしか見えません。

負荷試験を行う際は、サーバだけでなくクライアントのリソース監視が必要です。簡単な方法としては、パフォーマンステストと同時に htop を起動して、CPU やメモリ消費量を確認するという方法があります。どちらも使用率が 80% を超えるとリソース不足の疑いが強まるので、超えた場合はリソース増強やノード分散を検討する必要があります。

また、CPU やメモリ以外にも、ネットワークリソース、ファイルディスクリプタ、エフェメラルポートなどのリソースも枯渇しがちです。

この辺りに関しては k6 のドキュメントの Testing guides > Running large tests によくまとまっているので、パフォーマンステストに取り掛かる前にご一読をおすすめします。

さらに言えば、大量のユーザがリクエストするというシナリオでパフォーマンステストを実施する場合、一台のノードだけを使って負荷をかけることは難しいため、早々にノード分散を検討することになると思います。お手元に自由に使える Kubernetes クラスタをお持ちの方は k6-operator を利用されるのがよいと思いますが、単により強い負荷をかけたいだけであれば、複数マシンに k6 をインストールして同時に実行するという手もあります。

このプロジェクトでは、自由に使える Kubernetes クラスタはあったもののオペレータを導入するほどではなかったので、Kubernetes の Job リソースを使うことで、複数の Pod で k6 を動かして大量のリクエストを送っていました。

ネットワーク経路上のボトルネック

経緯

マシンのリソース問題を解消し、より高い負荷をかけられるはずでした。ところが、あるときからクライアント側のログに dial: i/o timeout が記録されるようになりました。これもサーバのレイテンシが増加したことによってタイムアウトしたのかなと思いましたが、サーバ側のアクセスログにはそれほど遅いリクエストが記録されていません。そこで、ネットワーク経路のどこかでパケットがドロップして、クライアントのリクエストがサーバに届いていないのではないかと考えました。

原因と解決

負荷試験を行なった環境の簡略化した構成は以下のようになっていました。

ここで、Deployment と書いたのがテスト対象のサーバを動作させている Kubernetes の Deployment リソースで、Service によって公開されています。 Job は k6 を動かしている Job リソースを示していて、Egress NAT と書いた NAT プロキシを介してインターネット経由でテスト対象サーバにリクエストを送ります。一度インターネットに出ている理由は、本番環境における通信のフローを模倣し、ネットワーク経路も含めたパフォーマンスを測定するためです。

さて、この中で怪しいのは Egress NAT なので、そのリソースを増やしたりしてみたのですが改善せず、他に原因も見つかりませんでした。そこで、通信経路を含めたパフォーマンステストの実施を諦め、テスト対象サーバのパフォーマンスに絞ることにしました。具体的には、通信のフローを変え、Job が Egress NAT を経由せず、Service 経由で Deployment に接続するようにしました。

ただし、テスト対象サーバは接続先ホスト名をチェックしているので、 test.k6.io のようなホスト名で接続する必要がありました。直接 Service の IP アドレスにリクエストを送ると、ホスト名がその IP アドレスになってしまうので、k6 の設定ファイルを書き換えて、名前解決を乗っ取ることにしました。

import { check } from 'k6';
import http from 'k6/http';

export const options = {
  scenarios: {
    contacts: {
      executor: 'constant-arrival-rate',
      duration: '30s',
      rate: 100,
      timeUnit: '1s',
      preAllocatedVUs: 200,
    },
  },
  hosts: {
    "test.k6.io": "xx.xx.xx.xx",  // test.k6.io が指定した IP アドレスに解決される
  },
};

export default function () {
  http.get('https://test.k6.io');
}

リクエストの経路変更により、大量のリクエストを送ってもタイムアウトは起きなくなりました。

今回は問題になったのがプロキシでしたが、その他にも、ファイアウォールや DDoS プロテクション、回線の帯域制限など、ネットワークの問題でパフォーマンテストが実施できないことがあるので、パフォーマンステストを行う際にはネットワークとその周辺のコンポーネントについて理解を深める必要があります。

ボトルネック分析

経緯

ようやく分散パフォーマンステストができるようになり、さらに大きい秒間リクエスト数でサーバに負荷をかけてレイテンシを測定していました。そして、ついにレイテンシが大きく増加する秒間リクエスト数がわかったので、サーバのリソース増強や、DB からデータを取得する処理にキャッシュ機構の導入を検討し始めました。

実際のボトルネックがどこだったのか

チームメンバからのアドバイスで、パフォーマンス改善に着手する前に、実際にどこで時間がかかっているのか計測するため、net/http/pprof を利用することにしました。このパッケージを使って以下のようにコードを追加すると、CPU プロファイルを取得するパスが作られます。

package main

import (
    "net/http"
    "net/http/pprof"
)

func main() {
  http.HandleFunc("/debug/pprof/profile", pprof.Profile)
  http.ListenAndServe(":8080", nil)
}

そして、負荷をかけている間に以下のコマンドを実行することにより、プロファイルをダウンロードしつつ、どの処理のどれだけ時間がかかっているかを可視化できます。

go tool pprof -http :6060 <テスト対象サーバのアドレス>:8080/debug/pprof/profile

その結果、ボトルネックは当初想定していた DB への問い合わせ処理ではなく、DB への接続処理でした。原因を調査すると、DB のコネクションプールの設定が不適切で、コネクションが正しく使い回されず頻繁に接続が行われていたことでパフォーマンスが低下していました。

コネクションプールのパラメータチューニング

このサーバでは database/sql パッケージを使っていたのですが、SetMaxOpenConns などのメソッドが呼ばれていませんでした。これらのメソッドがメソッドが呼ばれていない時、コネクションプールの設定は以下のようになります。

オープンできるコネクション数は無制限
プールに保持されるアイドル中のコネクションは2つまで
コネクションを使い回せる期間は無制限

この設定における問題点は以下の記事が詳しいですが、簡単に書くと次の点が挙げられます。

プールされているアイドル中のコネクションが2つと少ないため、複数のリクエストが来たときにすぐに使い果たされてしまう。
プールされているコネクションがすでに使われている場合は新しいコネクションをオープンするが、無制限にオープンされうるためデータベース側のリソースが枯渇したり、データベース側のコネクション数制限に引っかかる。
一般にデータベースとの接続を長時間使い回すのは危険である。

参考にした記事： please-sleep.cou929.nu dsas.blog.klab.org

そこで、これらの値を変えながらパフォーマンステストを実施し、以下のように設定を変更しました。

オープンできるコネクション数、およびプールに保持されるアイドル中のコネクションは 1,000 まで
コネクションを使い回せる期間は5分

これにより、テスト対象サーバとデータベースの負荷が軽減され、スループットが大幅に向上しました。

今回はチームメンバからの助言で事前に pprof を教えてもらっていたのでスムーズにボトルネック分析ができましたが、もし闇雲にキャッシュを入れたりしていたら、想定よりもパフォーマンスが改善されずに悩んでいた可能性があります。

Go 以外の言語でもこのようなプロファイラツールは提供されているので、これからをパフォーマンステストを始めるぞという方は、テストツールとセットでプロファイラツールを選定されるのが良いと思います。

その後も、パフォーマンステストとボトルネック分析、そしてパフォーマンス改善を繰り返し実施しました。

例えば、テスト対象サーバが行なっているサービスディスカバリや DNS の問い合わせに時間がかかっていることがわかったので、問い合わせ結果をキャッシュするようにしました。また、キャッシュが切れた時などに問い合わせが集中しないように singleflight の導入を行いました。

pkg.go.dev

そのような改善の結果、テスト対象サーバのスループットは最初のバージョンと比較して10倍向上しました。

最後に

本プロジェクトでは、製品の Neco 移行に必要なサーバのパフォーマンステストを行い、いくつかの落とし穴にハマりながらも、最終的にはサーバのパフォーマンス計測・向上という目的を達成できました。負荷の増大に起因した性能劣化は、あるとき突然大規模かつ長期にわたる障害を引き起こすことがあります。Cloud Platform チームでは引き続き、製品の Neco 移行と安定運用のための取り組みを継続していきます。

Cloud Platform 部では一緒に働いてくれる方を募集中です。以下の募集要項を見て興味を持った方はぜひご応募ください。

cybozu.co.jp