パフォーマンス計測をしよう

テックポエム

ソフトウェアを開発していると、動作を高速化したい場面によく当たります。 重いUIは使っていて不快になりますし、長時間かかる処理は少しでも早く終わらせたいものです。
ソフトウェア開発において動作を高速化するための定石は数多く知られています。 その中でもまず試してみる手法として以下のものがよく挙がります。
  • JavaScriptやPythonなどの遅い言語ではなく、JavaやC++などの速い言語で書き直す
  • ソースコードをビルドするときに最適化オプションをつける
  • とにかく並列化する
  • バブルソートからクイックソートに変えるなど、遅いアルゴリズムから速いアルゴリズムに変える
これらの手法はたしかに必要な工数のわりに効果が大きく、とりあえず試してみる価値は十分あると思います。 そして高速化について語る記事でも、多くの場合が高速化の手法について語っているように見えます。
しかし、これらの手法を使って動作を高速化する前に行う必要のある作業があります。 それは、どこがボトルネックになっているか、つまりどこが一番実行に時間がかかっているのか、を特定する作業です。 時間のかかる処理でも、その処理にかかわる部分全体がまんべんなく遅いということはほとんどなく、多くの場合どこか1箇所に遅い部分が集中していることが経験的に知られています。
しかし、ソフトウェアのソースコードをひと目見ただけでボトルネックがわかることはほとんどありません。 そのため、ソフトウェアの性能を詳しく分析するプロファイラーを使ってボトルネックを探すことになります。 また、ボトルネックの場所が判明したあと、そこがボトルネックになっている原因を探る作業にもプロファイラーを使います。
プロファイラーには多くの種類があります。 その中でもWindowsでVisual Studioを使ったソフトウェア開発で一番気軽に使えるのは、Visual Studioに付属しているプロファイラーではないでしょうか。 以下、簡単にVisual Studio付属のプロファイラーの使い方を説明します。 お使いのVisual Studioのバージョンやエディションによって機能や操作法、そもそも使えるかどうかが変わってくると思いますが、ここではVisual Studio 2017 Professionalを使って説明します。
説明には、行列積を計算する、下のC++のプログラムを使います。 ソースコードの詳細を読み解く必要はありませんが、mulmat関数が行列積を計算する本体です。 説明の都合上、よく見かける3重ループとは少し異なる実装をしています。 実際はこのほかにmulmat関数にわたす入力を生成したり計算時間を計測したりするコードやプログラム実行用のmain関数がありますが、特に重要ではないので省略します。
// サンプルコード(抜粋)

// (i, j)成分がdata[i*n+j]であるm×n行列
struct matrix_t
{
    int m;
    int n;
    double* data;
};

// m×n行列dataのデータ配置をrow-major orderからcolumn-major orderに入れ替えた配列を返す
double* transpose(const double* data, int m, int n)
{
    double* result = new double[n * m];
    for (int i = 0; i < n; ++i) {
        for (int j = 0; j < m; ++j) {
            result[i * m + j] = data[j * n + i];
        }
    }
    return result;
}

// line_aとline_bのそれぞれ先頭k要素の内積を計算する
double inner_product(const double* line_a, const double* line_b, int k)
{
    double result = 0;
    for (int i = 0; i < k; ++i) {
        result += line_a[i] * line_b[i];
    }
    return result;
}

// AとBの行列積を計算する
matrix_t mulmat(const matrix_t& A, const matrix_t& B)
{
    assert(A.n == B.m);
    matrix_t result;
    int m = result.m = A.m;
    int n = result.n = B.n;
    int k = A.n;
    result.data = new double[m * n];

    // ★1
    double* data_A = A.data;
    double* data_B = transpose(B.data, k, n);
    double* data_C = result.data;

    // ★2
    for (int j = 0; j < m; ++j) {
        for (int i = 0; i < n; ++i) {
            data_C[j * n + i] = inner_product(&data_A[j * k], &data_B[i * k], k);
        }
    }

    return result;
}
プロファイラーを使ってプログラムの各部分の所要時間を計測するには、プログラムを実際に走らせる必要があります。 そのため、Visual Studioでプロファイラーを使う準備として、まず計測対象のプログラムを実行するにあたってコマンド引数や作業ディレクトリを設定する必要がある場合は、プロジェクトの設定からあらかじめ編集しておいてください。 今回は、あらかじめランダムに生成した4096x4096のサイズの行列2つとその答えを読み込んでmulmat関数が実行されるように設定しました。
それでは実際にプログラムの性能を計測してみましょう。 まずプロジェクトを開いた状態でメニューの「分析」→「パフォーマンスプロファイラー」を選択します。
パフォーマンスプロファイラーの起動メニュー
すると、使用可能なツールを選ぶ画面が表示されます。 Visual Studioではいくつかのプロファイラーが使用できます。 そのうちよく使いそうで処理時間に特化したものだけを紹介すると、 まず「CPU使用率」では、アプリケーションのCPU使用率をリアルタイムで確認することができます。 次に「CPUサンプリング」では、CPU時間を多く消費した部分が行単位でわかります。 最後に「インストルメンテーション」では、処理時間を多く消費した部分が関数単位でわかります。 それぞれ特徴を表1にまとめたので参考にしてください。 なお、ビルドの設定をDebugビルドからReleaseビルドに変更して計測することをおすすめされていますが、Releaseビルドでは最適化で関数がインライン化される可能性があるため、ある関数の実行に長時間かかったと表示されていても実際にはその中で呼び出している関数の部分に時間を要している場合があることに注意してください。
Visual Studioで利用可能なプロファイラー。プロジェクトの設定によって変わります
Visual Studioで使用可能なプロファイラー(一部)の比較
ツールCPU使用率CPUサンプリングインストルメンテーション
計測内容 CPU時間 CPU時間 実時間
計測粒度 行ごと 行ごと 関数ごと
オーバーヘッド
リアルタイム計測 × ×
用途 起動から時間が経ってから実行される処理(UIイベント等) 検証用コードからすぐ実行できる、CPU主体の処理(ライブラリー内の関数等) 検証用コードからすぐ実行できる、ネットワークやファイルI/OなどCPU以外が主体の処理(ライブラリー内の関数等)
今回はmulmat関数という、CPUが主体の関数1つに絞って計測したいので、CPUサンプリングで計測します。 「パフォーマンスウィザード」を選択してパフォーマンスウィザードを起動し、「CPUサンプリング」を選択し、「次へ」を押して次の画面に移ります。 プロファイルするアプリケーションは「使用可能な1つ以上のプロジェクト」を選択して「次へ」を押します。 最後にプロファイル対象のアプリケーションとして、計測するプロジェクトを選択して「次へ」を押します。 「完了」をクリックすると、選択したアプリケーションが実行され、パフォーマンス計測が始まります。 管理者権限を要求された場合は承認してください。 プログラムの実行が終了するとプロファイラーも自動的に終了し、統計情報が表示されます。

パフォーマンスウィザード

パフォーマンスウィザード
パフォーマンスウィザード
プログラムのパフォーマンス解析結果
「最も頻繁に個別の作業を実行している関数」を見ると、mulmat関数が一番多く(99.98%)時間を消費していることがわかります。 多くの関数に細かく分けられているプログラムではどの関数で一番時間を消費しているのかわかるだけでも有益な情報です。 ところがこのプログラムもtranspose関数やinner_product関数に分けているにもかかわらず、最適化の過程でインライン化されてしまっているのか、どちらの関数も所要時間が表示されず、有益な情報が得られません。
そこで、同じビューでmulmat関数のところをクリックして、詳細情報を見ることにします。 この詳細情報では、関数の中でどれだけ時間を消費したか(正確には、サンプリングされたときに何回その行にいたか)を行ごとに確認することができます。 どうも、★2の部分は★1より7000倍程度時間を消費しているようです。 これでボトルネックが特定できました。

行ごとの実行頻度

mulmat関数のボトルネックが特定できたので、ボトルネックの部分に絞って、簡単な高速化をしてみます。 冒頭の「高速化するにあたってまず検討する事項」を検討してみると、まずこのプログラムはすでにC++で書いていますし、Releaseビルドで実験しているので最適化も効いています。 アルゴリズムを速いものに変えるのは難しそうなので、OpenMPを使って並列化することにします。 ★2の次の行にOpenMPのpragmaを追加して、次のようにしました。
    // ★2
#pragma omp parallel for
    for (int j = 0; j < m; ++j) {
        for (int i = 0; i < n; ++i) {
            data_C[j * n + i] = inner_product(&data_A[j * m], &data_B[i * n], k);
        }
    }
ではmulmat関数はどれほど速くなったでしょうか? オーバーヘッドを避けるため、プロファイラーを使わずに計測してみます。 OpenMPを使って並列化する前は、4096x4096の行列2つを掛けるのに手元のPCで83.4秒かかっていました。 ところが並列化後は26.7秒と、3.12倍速くなりました。 ボトルネックを特定して1行追加しただけにしてはかなり速くなったのではないでしょうか?
今回はたまたま簡単に高速化できましたが、より高度なチューニングが必要な場合は他の情報が取れるプロファイラーを使って最適化していくことになります。 そして、プロファイラーはあくまで実行したプログラムの性能に関する情報しか取れないため、具体的な最適化手法については結局専門知識が必要ですし、プログラムを大局的に見ないとうまくいかないこともあります。 例えば今回のプログラムは、★2にだけ注目して並列化するのに加えて、★1と★2の部分を次のような普通の3重ループ(+α)にするほうが、コンパイラによっては自動ベクトル化がうまく働いて、圧倒的に速くなります。
// より速い書き方

// ★1
double* data_A = A.data;
double* data_B = B.data;
double* data_C = result.data;

// ★2
for (int j = 0; j < m; ++j) {
    for (int l = 0; l < k; ++l) {
        for (int i = 0; i < n; ++i) {
            data_C[j * n + i] += data_A[j * k + l] * data_B[l * n + i];
        }
    }
}
とはいえ、「あまり性能が必要ないはずのGUIアプリケーションの動作が少し重くて困る」というような場合にはVisual Studioのプロファイラーは気軽に使えて大変有用です。 開発中のプログラムのレスポンス速度が気になったときは試してみてください。