最もシンプルなOpenCLによる演算の実行 - 実行時間

About

この項目では、項目「最もシンプルなOpenCLによる演算の実行」で行った、OpenCLによる演算の実行時間がどれ程のものか確認してみます。誤解を生まないために先に結果だけ述べておくと、用意したサンプルでは、ほとんどの人が実行時間は遅くなると思います。

実行時間の計測環境

この項目内で扱われる実行時間を計測した環境は次のようになっています。

基本のプログラムの実行時間

まずは OpenCL を利用しない場合の実行時間を計測します。厳密には色々手法がありますが、ここではシンプルに C#(.Net) に用意される Stopwatch クラスを利用して実行時間を計測します。また 1 回あたりの計測には 1 回の施行しかしません。※一般的には 1000 回実行した平均などとしますが。

基本のプログラムの場合には、次のように用意して見ました。変数の用意から始めて、計算の終了までのタイムを計ります。 実行結果ですが、実行時間は大体 10msec～12msec で収まりました。

            //★時間の計測を開始する
            Stopwatch stopWatch = new Stopwatch();
            stopWatch.Start();

            float[] xDataArray = new float[1920];
            float[] yDataArray = new float[1080];
            float[] rDataArray = new float[1920 * 1080];

            for (int i = 0; i < xDataArray.Length; i++)
                xDataArray[i] = 3.1415f;
            for (int i = 0; i < yDataArray.Length; i++)
                yDataArray[i] = 3.1415f;

            for (int y = 0; y < yDataArray.Length; y++)
                for (int x = 0; x < xDataArray.Length; x++)
                {
                    rDataArray[x + y * xDataArray.Length] = xDataArray[x] * yDataArray[y];
                }

            //★時間の計測を一時停止して出力する
            stopWatch.Stop();
            Console.WriteLine("Default calc time : " + stopWatch.Elapsed.TotalMilliseconds);

OpenCLプログラムの実行時間

OpenCLを利用したプログラムの実行時間の計測は、少々特殊な手順を取ることにしました。先の標準的なものと比べて計算実行までの手順が多いですから、何回かに分けて時間を計測してみます。区切りは次のようになっています。

1. データの用意からバッファの生成までの時間
2. 引数を設定して、コマンドを生成するまでの時間
3. OpenCLによる演算の実行から終了までの時間
4. 演算結果の取得までの時間

ここで先のサンプルは利用しなかった、clFinish 関数を利用しています。このメソッドは、OpenCL による演算が終了するまで、ホストプログラム(呼び出し元)に処理を返さないようにする関数です。これを利用して、確かに処理が終了するまでの時間を計測します。

      //★時間の計測を開始する
      double totalMsec = 0;
      Stopwatch stopWatch = new Stopwatch();
      stopWatch.Start();
…
      gcHandle = GCHandle.Alloc(rDataArray, GCHandleType.Pinned);
      IntPtr buffer_rData = clCreateBuffer
          (context, CL_MEM_WRITE_ONLY,
          (uint)(Marshal.SizeOf(rDataArray[0]) * rDataArray.Length),
          IntPtr.Zero, out errcode);
      //再度固定して利用するので、ここでは解放せずに固定したままにしておく。
      //gcHandle.Free();
      if (errcode != CL_SUCCESS)
          throw new Exception("Error at clCreateBuffer : " + errcode);

      //★時間の計測
      totalMsec += stopWatch.Elapsed.TotalMilliseconds;
      Console.WriteLine("OpenCL Setup Time - 1 : " + stopWatch.Elapsed.TotalMilliseconds);
      stopWatch.Restart();
…
      //コマンドの生成
      IntPtr commandQueue = clCreateCommandQueue
          (context, devices[0], 0, out errcode);
      if (errcode != CL_SUCCESS)
          throw new Exception("Error at clCreateCommandQueue : " + errcode);

      //★時間の計測
      totalMsec += stopWatch.Elapsed.TotalMilliseconds;
      Console.WriteLine("OpenCL Setup Time - 2 : " + stopWatch.Elapsed.TotalMilliseconds);
      stopWatch.Restart();

      //カーネルに実行するように指示をする
      errcode = clEnqueueTask(commandQueue, kernel, 0, null, IntPtr.Zero);
      if (errcode != CL_SUCCESS)
          throw new Exception("Error at clEnqueueTask : " + errcode);

      //★OpenCLの処理が終了するまでブロックする。
      clFinish(commandQueue);

      //★時間の計測
      totalMsec += stopWatch.Elapsed.TotalMilliseconds;
      Console.WriteLine("OpenCL Calc Time : " + stopWatch.Elapsed.TotalMilliseconds);
      stopWatch.Restart();

      //実行結果の取得
      errcode = clEnqueueReadBuffer
          (commandQueue, buffer_rData, CL_TRUE, 0,
          (uint)(Marshal.SizeOf(rDataArray[0]) * rDataArray.Length),
          gcHandle.AddrOfPinnedObject(), 0, null, IntPtr.Zero);
      gcHandle.Free();
      if (errcode != CL_SUCCESS)
          throw new Exception("Error at clEnqueueReadBuffer : " + errcode);

      //★時間の計測を終了して出力する
      stopWatch.Stop();
      totalMsec += stopWatch.Elapsed.TotalMilliseconds;
      Console.WriteLine("OpenCL End Time : " + stopWatch.Elapsed.TotalMilliseconds);
      Console.WriteLine("OpenCL Total Time : " + totalMsec);

実行結果は次のようになりました。何度か実行すると計測時間はわずかに前後しますが、あまり大きくは前後しません。このことから、今回のようなサンプルであつかった、何も考えない極めてシンプルな演算では、OpenCL(GPU) を利用するとかえって遅くなる、ということが分かります。OpenCL はその機能を有効に活用する方法をきちんと押さえておく必要があります。OpenCL は、とりあえず使えば速くなる、といった魔法のツールではないわけです。

OpenCL Setup Time - 1 : 279.0702
OpenCL Setup Time - 2 : 8.7545
OpenCL Calc Time : 341.7137
OpenCL End Time : 9.1246
OpenCL Total Time : 638.6596

考察

結局のところ、今回は並列化などを意識せずに、単純にタスクを、対象のデバイスに渡した形になります。特に GPU を対象に実行しているときには、GPU に処理を移譲しただけでそれ以上のことは何もしていません。

"Setup Time - 1" は、バッファオブジェクトを用意するところまでの時間です。今回用意した一般的な手法と比較して準備が多いため、時間がかかるのは当然のことです。しかしながら現実的に、ここまでの処理は実行前にあらかじめ用意しておくことができます。

"Setup Time - 2" は、主にカーネルに引数を設定する処理を対象としていますが、ここではあまり時間がかからないようです。とはいえ、今回用意した一般的な手法とほぼ同じような時間をここでとってしまっています。このことから、少なくともカーネルに引数を設定する時間よりは時間のかかる処理を、OpenCL による処理の対象としたほうが良さそうです。

"Calk Time" は、カーネルに命令を出し、指定したデバイスが処理を行って、ホストプログラムへコントロールが返るまでの時間です。びっくりするくらい時間がかかっています。前準備の時間がかかってしまうのは仕方ないとして、実際に処理するときに時間がかかっては仕方ありません。ここで掲載する時間は筆者の環境下で GPU ベースで処理を行ったものです。したがって考えられるのは転送のオーバーヘッドです。CPU->GPU へデータを転送し、さらにホストプログラムからそれを読み込むための準備を整えるまでの時間がかかっているものと思われます。この問題は簡単には解決できないでしょう。

"End Time" は、ホストプログラムにコントロールが返った後、実行結果を読み取るまでの時間です。やはり読み取るまでの時間で、今回用意した一般的な手法と同じくらいの時間を要しています。なお、clFinish を実行せずに、clEnqueueReadBuffer を実行すると、"Calk Time" と "End Time" がほぼ逆転したような結果となります。これは clEnqueueReadBuffer が、演算結果が読み取り可能な状態になるまで処理を待機しているためと思われます。定かではありません。

最終的にかかった時間は、およそ 640msec、用意した一般的な手法が 10msec とすると、実行時間は 64 倍の違いです。ビックリするほど無意味な OpenCL(GPU) の使い方をしていることが分かります。