関数の時間計測

C++のthreadライブラリを使っている。いかんせん並列化の経験が少ないのでちゃんとthreadが立ち上がっているのかとか、並列に処理されているのかとかがよくわからないし、ツールもよく知らない。VTuneのことは知っているが個人で持っているようなものでもない。なので、最も愚直な方法、単に時間を計測して出力して調べることにした。

しかし、出力するといっても、文字列の出力はatomicではない。しかし、関数内でmutexをlockしたりする場合、そのmutexのスコープはどうなるのか。グローバルか? だとすればあまり嬉しいことにはならない。実際には最終的に出力するべき内容が全て出力できればいいのだから、関数から時刻も一緒に返して受け取ってから単一のスレッドで出力を行えばよいことになる。というわけで以下のようなコードを書いた。

ちなみに、std::chrono::system_clock::now()はスレッドセーフであると信じている。裏は取っていない。

auto fut = std::async(std::launch::async, [](){
        const auto start = std::chrono::system_clock::now();
        const auto retval = do_async_work();
        const auto end = std::chrono::system_clock::now();
        return std::make_tuple(retval, start, end);
    });

auto result = fut.get();
std::cerr << "thread starts at : "
          << std::chrono::duration_cast<std::chrono::microseconds>(
                 std::get<1>(result).time_since_epoch()).count()
          << std::endl;
std::cerr << "thread ends at   : "
          << std::chrono::duration_cast<std::chrono::microseconds>(
                 std::get<2>(result).time_since_epoch()).count()
          << std::endl;
std::cerr << "elapsed time     : "
          << std::chrono::duration_cast<std::chrono::microseconds>(
                 std::get<2>(result) - std::get<1>(result)).count()
          << std::endl;

volatileとかをつけた方がよかったかもしれない。だがそれ以前に、このコードを書くのは本当にダルい。いったい何回std::chrono::を書けばいいのか。もちろんusing std::chronoをするという手はあるが、できるだけこれはしたくない。なので、以下のようなクラスを作った。

template<typename T>
class timestamp
{
  public:
    typedef T value_type;
    typedef std::chrono::system_clock::time_point time_point_type;

  public:
    timestamp() = default;
    ~timestamp() = default;

    void start(){this->start_ = std::chrono::system_clock::now();}
    void stop() {this->stop_  = std::chrono::system_clock::now();}

    value_type const& value() const {return value_;}
    value_type &      value()       {return value_;}

    template<typename durationT>
    durationT elapsed() const 
    {
        return std::chrono::duration_cast<durationT>(stop_ - start_);
    }

    template<typename durationT>
    durationT start_at() const
    {
        return std::chrono::duration_cast<durationT>(start_.time_since_epoch());
    }

    template<typename durationT>
    durationT stop_at() const 
    {
        return std::chrono::duration_cast<durationT>(stop_.time_since_epoch());
    }

  private:
    value_type value_;
    time_point_type start_;
    time_point_type stop_;
};

要するに先のlambdaで返しているtupleをラップしたような代物だ。これによって、上のコードは

int do_async_work();

int main()
{
    auto fut = std::async(std::launch::async, [](){
            timestamp<int> ts;
            ts.start();
            ts.value() = do_async_work();
            ts.stop();
            return ts;
        });

    auto result = fut.get();
    std::cerr << "thread starts at : "
              << result.start_at<std::chrono::microseconds>().count()
              << std::endl;
    std::cerr << "thread ends at   : "
              << result.stop_at<std::chrono::microseconds>().count()
              << std::endl;
    std::cerr << "elapsed time     : "
              << result.elapsed<std::chrono::microseconds>().count()
              << std::endl;
}

のようにシンプルになる。コンストラクト時に.start()を呼んでおくかどうかは一瞬考えたが、いろいろあって明示的に指示することにした。

ちなみに、上のコードだとTにvoidを渡すとvoid&とかが返ってアレということがあり、その特殊化はちゃんと追加してやる必要がある。まあコピペしてvalue_type関連の部分を消し去るだけでよいので書くほどのことはない。

ところで、書きつつ調べていたのだが、 valgrind/callgrind には --separate-threads=yes なるオプションが存在し、各threadごとのコールグラフを取ってくれる。便利だ。