このエントリーをはてなブックマークに追加

 

手を動かしてさくさく理解する
C言語/C++ 処理時間計測 入門
Copyright (C) 2014 by Nobuhide Tsuda

 

※ イラスト提供:かわいいフリー素材集「いらすとや」様

概要

プログラム開発当初から過度のパフォーマンス最適化を行うのは良くないと言われている。 プログラムソースの柔軟性が失われる可能性があるし、必要無いかもしれない最適化に時間を費やすのは開発工数管理的に好ましくないからだ。

プログラムがある程度動作するようになり、パフォーマンスが悪い(実行速度が遅すぎる)場合は、 処理時間計測を行い処理時間を要している箇所を探しだし、アルゴリズムやデータ構造の変更などのパフォーマンス・チューニングを行う必要がある。
予備調査として、色々なアルゴリズム・データ構造を採用した場合の処理時間計測を行い、 どれが最適か、どのような性質があるかを知ることも重要である。

本稿では、上記のような目的のためにプログラムの処理時間を計測する方法について説明する。

場合によっては、ストップウォッチを片手にプログラムを実行し、処理時間を計測することもあるかもしれないが、 精度が1秒程度なので、場合によっては不適切である。
処理時間計測関数を使えば、ミリ秒の精度で計測することが出来るぞ。

処理時間計測関数

Windows 環境では、プログラムの処理時間を計測するための関数として、以下の様なものがある。

clock()

clock() は、C 言語から用意されている関数で、プログラム実行開始からの経過時間を返す。 単位は通常ミリ秒である。精度は処理系に依存する。Windows では10ミリ秒程度のようだ。

clock() を使うには「<time.h>」をインクルードする必要がある。

clock() は clock_t 型(windows では32ビット整数)を返すので、「clock_t start = clock();」で、処理の開始時間を記録し、
処理時間計測を行いたい処理を行った後、「clock_t end = clock();」で処理の終了時間を記録する。 「end - start」で処理時間の数値を得ることが出来る。

秒に変換したい場合は、「CLOCKS_PER_SEC」で割る。

#include <iostream>
#include <vector>
#include <windows.h>
#include <time.h>     // for clock()
int main()
{
    std::cout << "clock():\n";
    for (int i = 0; i < 10; ++i) {
        std::vector<int> v;         // int 型動的配列
        clock_t start = clock();    // スタート時間
        const int N = 1000*100;    //  10万回
        for (int i = 0; i < N; ++i) {
            v.push_back(i);              // 末尾に i を追加
        }
        clock_t end = clock();     // 終了時間
        std::cout << "duration = " << (double)(end - start) / CLOCKS_PER_SEC << "sec.\n";
    }
    getchar();
    return 0;
}

演習問題

  1. 上記ソースをビルド・実行(デバッグモード、リリースモード両方)してみなさい。
  2. 上記ソースを、動的配列(vector)の先頭に i を挿入するよう修正し、ビルド・実行してみなさい。
  3. 上記ソースを deque の先頭に i を挿入するよう修正し、ビルド・実行してみなさい。
  4. for文の部分を、処理時間を計測してみたい何かに変更し、ビルド・実行してみなさい。

GetTickCount()

GetTickCount() は、Win32 API で用意されている関数で、システム起動開始からの経過時間を返す。 単位はミリ秒である。精度は環境に依存するが、10ミリ秒程度のようだ。
※ GetSystemTimeAdjustment() を使うと、実際の精度をナノ秒単位で取得できる。 本稿では説明しないので、興味がある人は自分で調べてね。

GetTickCount() を使うには「<windows.h>」をインクルードする必要がある。

GetTickCount() は DWORD 型(32ビット整数)を返すので、「DWORD start = GetTickCount();」で、処理の開始時間を記録し、
処理時間計測を行いたい処理を行った後、「DWORD end = GetTickCount();」で処理の終了時間を記録する。 「end - start」で処理時間の数値(単位はミリ秒)を得ることが出来る。

秒に変換したい場合は、「1000」で割る。

#include <iostream>
#include <vector>
#include <windows.h>
int main()
{
    std::cout << "GetTickCount():\n";
    for (int i = 0; i < 10; ++i) {
        std::vector<int> v;         // int 型動的配列
        DWORD start = GetTickCount();       // スタート時間
        const int N = 1000*100;    //  10万回
        for (int i = 0; i < N; ++i) {
            v.push_back(i);              // 末尾に i を追加
        }
        DWORD end = GetTickCount();    // 終了時間
        std::cout << "duration = " << (double)(end - start) / 1000 << "sec.\n";
    }
    getchar();
    return 0;
}

演習問題

  1. 上記ソースをビルド・実行してみなさい。

timeGetTime()

timeGetTime() というくどい名前の関数は、システム起動開始からの経過時間を返す。 単位はミリ秒で、精度は1ミリ秒程度である。

timeGetTime() を使うには「<windows.h>」をインクルードする必要がある。 さらに、「winmm.lib」をリンクする必要がある。ライブラリリンクをソースコードで指定するには、
「#pragma comment(lib, "winmm.lib")」と記述するとよい。

timeGetTime() は DWORD 型(32ビット整数)を返すので、「DWORD start = timeGetTime();」で、処理の開始時間を記録し、
処理時間計測を行いたい処理を行った後、「DWORD end = timeGetTime();」で処理の終了時間を記録する。 「end - start」で処理時間の数値(単位はミリ秒)を得ることが出来る。

秒に変換したい場合は、「1000」で割る。

#include <iostream>
#include <vector>
#include <windows.h>
#pragma comment(lib, "winmm.lib")
int main()
{
    std::cout << "timeGetTime():\n";
    for (int i = 0; i < 10; ++i) {
        std::vector<int> v;         // int 型動的配列
        DWORD start = timeGetTime();       // スタート時間
        const int N = 1000*1000;    //  100万回
        for (int i = 0; i < N; ++i) {
            v.push_back(i);              // 末尾に i を追加
        }
        DWORD end = timeGetTime();    // 終了時間
        std::cout << "duration = " << (double)(end - start) / 1000 << "sec.\n";
    }
    getchar();
    return 0;
}

演習問題

  1. 上記ソースをビルド・実行して、精度が1ミリ秒程度であることを確認しなさい。
  2. rand() と std::mt19937 と std::random_device の速度比較を行いなさい。
    ※ std::mt19937、std::random_device を知らない人は ここ を参照
  3. Sleep(1); を実行すると、実際にはどの程度時間が経過するかを計測してみなさい。
    ※ Sleep を知らない人は ここ を参照
  4. std::vector<int>::push_back() と std::deque<int>::push_back() の速度比較を行いなさい。
    ※ vector を知らない人は ここ を参照
  5. 処理速度計測を行い、vector<int>::push_back(d) が O(1) であることを確認しなさい。
  6. 処理速度計測を行い、vector<int>::insert(先頭, d) が O(N) であることを確認しなさい。
  7. 処理速度計測を行い、deque<int>::push_front(d) が O(1) であることを確認しなさい。
  8. 処理速度計測を行い、std::sort(v.begin(), v.end()) が O(N*logN) であることを確認しなさい。
  9. strlen(char *) の処理速度を計測し、文字列の長さが増えると、strlen() の処理時間がどう変化するかを調べなさい。
  10. strstr(char *, char *) の処理速度を計測し、被検索文字列・検索文字列の長さが増えると、strstr() の処理時間がどう変化するかを調べなさい。

※ ちなみに一般的論としては、トータル処理時間として許されるのは O(N * LogN) までである。
O(N^2) ではデータ数が多く(数万件以上)なると処理時間が膨大になり、実用に耐えないことがある。

QueryPerformanceCounter()

QueryPerformanceCounter(LARGE_INTEGER *) は、Win32 API で用意されている関数で、 高分解能パフォーマンスカウンタが存在する場合、そのカウンタの現在の値を取得する。 精度は環境に依存するが、1ミリ秒よりもかなり小さく、これまで説明した関数よりかなり精度が高い。

カウンタの値は引数のポインタが指す場所に格納され、カウンタを取得できた場合は TRUE を返す。

QueryPerformanceCounter(LARGE_INTEGER *) を使うには「<windows.h>」をインクルードする必要がある。

「LARGE_INTEGER start, end;」を予め定義しておき、「QueryPerformanceCounter(&start);」で、処理の開始時間を記録し、
処理時間計測を行いたい処理を行った後、「QueryPerformanceCounter(&end);」で処理の終了時間を記録する。
カウンタの数値を参照したい場合は「start.QuadPart」のように参照する。 「end.QuadPart - start.QuadPart」で処理時間の数値を得ることが出来る。

このようにして取得した数値の単位は「QueryPerformanceFrequency(LARGE_INTEGER *)」で取得する。 秒に変換したい場合は、「LARGE_INTEGER freq; QueryPerformanceFrequency(&freq);」で予め、単位を習得しておき、 結果を freq.QuadPart で割る。

#include <iostream>
#include <vector>
#include <windows.h>
int main()
{
    std::cout << "QueryPerformanceCounter():\n";
    LARGE_INTEGER freq;
    if( !QueryPerformanceFrequency(&freq) )      // 単位習得
        return 0;
    LARGE_INTEGER start, end;
    for (int i = 0; i < 10; ++i) {
        std::vector<int> v;         // int 型動的配列
        if( !QueryPerformanceCounter(&start) )
            break;       // 取得失敗
        const int N = 1000*100;    //  10万回
        for (int i = 0; i < N; ++i) {
            v.push_back(i);              // 末尾に i を追加
        }
        if( !QueryPerformanceCounter(&end) )
            break;    // 取得失敗
        std::cout << "duration = " << (double)(end.QuadPart - start.QuadPart) / freq.QuadPart << "sec.\n";
    }
    getchar();
    return 0;
}

※ この関数の測定精度は1ミリ秒よりかなり細かいが、実際の処理時間は同時に動作している他のアプリや、OSの状態に依存する。 なので、過度に高い精度で計測しても、その処理そのものの処理時間を計測しているわけではないことに留意して欲しい。

演習問題

  1. 上記ソースをビルド・実行してみなさい。
  2. Sleep(1); を実行すると、実際にはどの程度時間が経過するかを計測してみなさい。
  3. QueryPerformanceCounter() を使って、なにかの処理時間を計測してみなさい。

std::chrono

std::chrono は C++11 で追加された時間計測の枠組みだ。いくつかのクラスから構成される。 高機能で、そこそこ使いやすく、プラットフォームには依存しないので、覚えておいて損はないと思う。

まずは、具体的な使い方から見てみよう。

#include <iostream>
#include <vector>
#include <chrono>

int main()
{
    const int N = 1000*1000;
    std::vector<int> v;
    auto start = std::chrono::system_clock::now();      // 計測スタート時刻を保存
    for (int i = 0; i < N; ++i) {
        v.push_back(i);
    }
    auto end = std::chrono::system_clock::now();       // 計測終了時刻を保存
    auto dur = end - start;        // 要した時間を計算
    auto msec = std::chrono::duration_cast<std::chrono::milliseconds>(dur).count();
    // 要した時間をミリ秒(1/1000秒)に変換して表示
    std::cout << msec << " milli sec \n";
    getchar();
    return 0;
}

上記は std::vector の末尾に要素を百万回追加するのに要する時間を計測するコードだ。

計測方法は、これまでに出てきた関数たちとそう変わらない。

最初に std::chrono::system_clock::now() をコールして、現在時刻を保存する。ちょっと長ったらしいがしょうがない。
長いのは嫌だという人は「using namespace std::chrono;」と書いておくといいかもしれない。

.....
using namespace std::chrono;
int main() {
    ....
    auto start = system_clock::now();      // 計測スタート時刻を保存
    ....
}

実は system_clock::now() は std::chrono::system_clock::time_point というクラスのオブジェクトを返す。 これもそのまま記述するのは長ったらしく、めんどうで、タイプミスの元なので auto を使うのが普通だ。

スタート時刻を保存したら、計測したい処理を書く。そして system_clock::now() を呼んで、計測終了時刻を保存する。
次に、終了時刻から開始時刻を引き、要した時間を計算する。
この型は std::chrono::duration というクラスなのだが、これも長ったらしいので賢く auto を使用しよう。

最後に duration_cast<変換型>(duration) を用いて、ミリ秒などに変換し、count() で整数値に変換して表示する。
変換は、ナノ秒(nanoseconds)、マイクロ秒(microseconds)、ミリ秒(microseconds)、秒(seconds) を指定できる。 少々長ったらしいと思う人は、using namespace std::chrono; を使うといいだろう。

using namespace std::chrono;
    .....
    std::cout << duration_cast<milliseconds>(dur).count() << " milli sec \n";
    .....

ソース的には、ナノ秒単位の計測も可能だが、Windows 7 VS2013 環境で試してみたところ、精度は1ミリ秒程度のようであった。

演習問題

  1. いろいろな処理時間を chrono を使って計測してみなさい。

処理時間計測クラス

これまで説明したコードでも処理時間計測には充分なのだが、処理時間計測のためのクラス Timer を定義し、 もっと簡単に処理時間計測出来るようにしてみる。

下記が、Timer クラスの実装だ。

// timeGetTime() を使った時間計測タイマー クラス
#pragma comment(lib, "winmm.lib")
class Timer
{
public:
    Timer() { restart(); }
public:
    void  restart()
    {
        m_start = timeGetTime();        // 計測開始時間を保存
    }
    double  elapsed()    // リスタートからの秒数を返す
    {
        DWORD end = timeGetTime();
        return (double)(end - m_start) / 1000;
    }
private:
    DWORD    m_start;    //  計測開始時間
};

使い方は簡単で、「Timer tm;」などで、タイマーオブジェクトを生成すると、その時点から時間計測が開始され、 「tm.elapsed()」コールで、経過秒数を double 型で返す。
再度計測開始したい場合は「tm.restart()」をコールする。

以下に、具体的な使用例を示す。どのように時間を計測しているかがカプセル化され、使いやすくなっていることを理解・納得していただけただろうか。

#include <iostream>
#include <vector>
#include <windows.h>
int main()
{
    std::cout << "Timer:\n";
    for (int i = 0; i < 10; ++i) {
        std::vector<int> v;         // int 型動的配列
        Timer tm;
        for (int i = 0; i < 1000*100; ++i) { // 10万回ループ
            v.push_back(i);              // 末尾に i を追加
        }
        std::cout << "duration = " << tm.elapsed() << "\n";
    }
    getchar();
    return 0;
}

演習問題

  1. 上記ソースをビルド・実行してみなさい。
  2. Timer クラスを、timeGetTime() ではなく QueryPerformanceCounter() を使用するよう修正してみなさい。

まとめ

下記の5つの処理時間計測関数について簡単に説明した。

関数名精度環境
clock()10ミリ秒程度C言語/C++
GetTickCount()10ミリ秒程度Windows
timeGetTime()1ミリ秒程度Windows
QueryPerformanceCounter()1マイクロ秒程度Windows
chrono()1ミリ秒程度C++11

※ 精度は Windows 環境でのおおよその値

個人的には QueryPerformanceCounter() はややオーバスペック気味だと考える。
関数名はくどいが、扱いの簡単さと精度の点で timeGetTime() を使うか、 マルチプラットフォーム・普遍性を考えると chrono を使うのがよいのではないかと考える。


 

 

演習問題解答例