2014. 10.27.
石立 喬

Visual Studio Express 2013 の新しい使い方(5)

――― コンソールアプリケーションで、Stopwatchとchronoを使って、実行時間を測定する ―――

  ISO C++11の新規格には、右辺値参照など、不必要なコピーを省略して実行効率を高める目的のものがある。今回、それらを確認しようと、実行時間の測定を試みた。ここでは、.まずNET FrameworkのStopwatchクラスを試し、C++11のchronoライブラリと比較した。結論として、マイクロ秒オーダーの実行時間の測定にはStopwatchが適し、chronoは、数百ミリ秒以上の十分長い時間でないと有意な結果が得られない。
 実行時間の測定では、コンパイルの方法や、マルチコアCPUの仕組みが影響してか、予想とは異なる結果が得られ、右辺値参照の優位性は確認できなかった。

.NET FrameworkのStopwatchクラスの使い方
 Stopwatchクラスは、名前空間System.Diagnosticsにある。
1)計測を開始するには、
 Stopwatch::StartNew()で、StopwatchクラスのオブジェクトstopWatchの生成と同時に時間を初期化して時間計測を開始するか、既存のオブジェクトに対して、stopWatch->Restart()を用いる。これは、Reset()→Start()と同じである
2)計測を終了するには、  stopWatch->Stop()で、計測を停止させる。
3)経過時間は、
 stopWatch->ElapsedTicksで求める。Ticksの周期は、stopWatchatch->Frequencyで得られるので、Tics / Frequencyで、経過時間を求める。
 stopWatch->Elapsedでは、00:00:00.0121151のような形式の、時・分・秒で得られるので、一般には、処理が必要になる。ミリ秒単位で経過時間を求める stopWatch->ElapsedMilliseconds もあるが、ミリ秒単位の整数でしか結果が得られず、精密な測定はできない。

Stopwatchを使ったプログラムと得られた結果
 Visual Studioで、「C++」→「CLR」→「コンソールアプリケーション」と選択して、コンソールアプリケーションで.NET Frameworkを使えるようにする。図1は、Stopwatchを用いて、あまり意味のない計算Math::Sin(1)*Math::Cos(1)の実行回数と、それに要した測定結果を表示するプログラムである。
 Stopwatchクラスを用いるので、名前空間System::Diagnosticsを宣言してある。
 参考のために、周波数frequency、すなわち1秒間のTicks数を確認して表示し、その逆数を取って、Ticsの周期も表示してある。この周期以下の時間間隔は、測定することができない。
 測定開始は、stopWatchをStartNew()で初期化することにより行い、stopWatch->Stop()でストップさせてから、経過時間(Ticks数)を、stopWatch->ElapsedTicksで求める。実際の時間は、これをfrequencyで割って求める。


図1 Stopwatchで実行時間を測定するプログラム


 図2は、得られた結果である。Ticksは、約2.4MHzで発生し、その周期(解像度)は約0.4μsecであった。1000回演算を行うと、約200μsecかかり、Math::Sin(1)*Math::Cos(1)を1回演算する所要時間は、0.2μsecであることが分かる。
 回数が少ない100回では、精度が悪くなっている。、


図2 得られた結果


C++11のchronoクラスの使い方
 chronoライブラリは、ヘッダ<chrono>をインクルードし、名前空間std::chronoを宣言して使用する。
1)現在の時刻を取得するには、
  time_point<system_clock>でt1やt2を宣言しておき、
  t1=system_clock::now();
で取得する。system_clockの代わりにhigh_resolution_clockも使用できるが、WindowsとVisual Studioの環境では、変わりがなかった。
 宣言と同時に時刻を取得する場合には、
  auto t1=system_clock::now();
で、簡単化できる。
2)時間差を求めるには、
  long long tdを宣言しておき、
  td=duration_cast<milliseconds>(t2-t1);
などで求まる。millisecondsをmicrosecondsなどに細かく設定することもできるが、Windows環境では、最小分解能(granurarity)が15.625ms(64Hzに相当)なので、あまり意味がない。
 この値を出力するには、
  td.count();を用いる。

chronoを使ったプログラムと得られた結果
  Visual Studioで、左欄で「C++」、右欄でWin32「コンソールアプリケーション」と選択して、コンソールアプリケーションのスケルトンを得る。図3は、C++11のchronoクラスを用いて、.NET Frameworkの場合と同様に、sin(1)*cos(1)の実行回数と、それに要した時間を表示するプログラムである。
 system_clockを用い、時間をmicrosecondsで表示させている。約15.625msecの倍数でしか時間が計測できないことが分かったので、実行回数を200000回にまで増やして測定した。


図3 chronoで時間間隔を測定するプログラム


 図4はプログラムの実行結果で、「差」が不連続で観測されることが分かる。つまり、最小分解能15.625ms(64Hzに相当)の倍数に近い値でしか、時間間隔が得られない。これはシステムクロックに原因があることが分かる。「実行回数」が、0と10000の場合、システムクロックは変化していない。しかし、10000回の実行終了後、20000回の開始までに、15618μsecの待ち時間がある。このようなことは、実際にはあり得ない。
 したがって、実際に使用するには、15.625msecに比べて、十分長い時間しか測定できない。実行回数と時間差から、一回当たりの所要時間を計算すると、最短で約0.2μsecなっており、Stopwatchを使用した場合と一致している。


図4 得られた結果


 結論として、chronoをWondowsアプリケーションで使用する場合、解像度は約16msecなので、それよりも十分長い期間の測定でないと、誤差が大きくなる。

いろいろなループの実行時間の測定
 より高い精度が得られるStopwatchクラスを用いて、forループ(i++でインクリメントする場合と、++iの場合と)、whileループ、do〜whileループの時間を調べた。これらのループは、繰り返す処理を空にして測定した。 図5、6、7はプログラムで、従来、StopwatchのスタートをStopwatch::StartNew()としていた代わりに、stopWatch->Restart()を用いた。これはそれまで実行していた時間の計測を停止し、経過時間をゼロにリセットして、計測を始める。この方が、何回も長時間にわたってStopwatchを繰り返し使い続けるには良いような気がした。
 各ループの繰り返し回数は100000にし、経過時間測定を10000回繰り返してその平均を取った。


図5 stopWatchをインスタンス化しておく



図6 各ループごとに100000回繰り返して、合計する



図7 100000回の平均をとり経過時間を求めて表示する


 図8は得られた結果で、forループが早く、後置インクリメントと前置インクリメントの違いについては、差は認められず(プログラム実行の場合により逆転することもあり、誤差の範囲と思われる)、whileループは一番遅く、do〜whileが少し早いと言う結果になった。
 forループで、++iの方が原理的に早い、との解説がなされている(イテレータのインクリメントは、前置が原則)が、通常の変数では、優劣がなさそうである。これらの結果には、Visual C++や、CLR(Common Langage Runtime)、CPUアーキテクチャが影響している可能性もある。


図8 いろいろなループ(空)を100000回まわしたときの所要時間


メソッド使用と右辺値参照の時間測定結果
 C++11で導入された右辺値参照は、実行時間の短縮に役立つといわれているので、それを試してみたが、ここでの実験に関する限り、その効果は感じられなかった。
 図9は、実験に使用したメソッドで、下が右辺値参照を使用したものである。


図9 実験に使用した通常のメソッドと右辺値参照メソッド


 実験には、図10に示すプログラム(forループのみは省略)を10000回実行し、その平均を取った。右辺値参照メソッドに対しては、リテラル(数値を直接表す文字)の場合と、左辺値を右辺値に変換するmoveを使用したものとを比較した。move()を使用するために、
  using namespace std;
  #include <algorithm>
を、最初に記述しておく。


図10 比較に使用したプログラム


 図11は得られた結果で、
 1)forループのみより、ループ内で何らかの処理(簡単なもの)をした方が早いのは、コンパイラでの最適化が行われているためか、CPUで並列演算が行われているためか、一見奇妙であるが、何回繰り返しても同じ結果であった。
 2)メソッドを呼び出すよりは、メインプログラム本文中で実行するのが最も早い。
 3)リテラルを用いても、右辺値参照の方が少し遅い。この理由はわからない。
 4)std::move()を使って左辺値を右辺値に変換して右辺値参照を行うのは、とても時間がかかる。
ことが分かった。
 あらためて、処理の実行時間の計測が難しいことを実感した。コンパイラやCPUに依存するので、単純な理論だけでは、片づけられないのかも知れない。


図11 意外な結果が得られた