RAII妙用之计算函数耗时

前面讲解了什么是RAII以及应用RAII的小技巧ScopeExit，这次我们使用RAII方式来更方便的打印函数耗时。

我们平时编程过程中不可避免的需要考虑性能，性能里最主要的最常见的应该就是函数耗时了吧，基本上每个开发者都有打印某个函数耗时的需求，你平时打印函数时间是否使用的是如下方式：

void Func() {
    ...
}

int CalTime() {
    int begin = GetCurrentTime(); // 伪代码
    Func();
    int end = GetCurrentTime();
    cout << "func time is " << end - begin << " s" << endl;
}

想计算某个函数的耗时就在函数前后获取时间之后再算差值，丑，麻烦。

这里可以利用RAII方式，把函数的生命周期和一个对象绑定，对象创建时候执行函数，对象生命周期结束析构时候函数执行完毕，这样对象存活的时间就是函数的耗时，见代码：

#pragma once

#include <sys/time.h>

#include <chrono>
#include <ctime>
#include <fstream>
#include <iostream>
#include <string>

using llong = long long;
using namespace std::chrono;
using std::cout;
using std::endl;

namespace wzq {
namespace timer {
class TimerLog {
   public:
    TimerLog(const std::string tag) { // 对象构造时候保存开始时间
        m_begin_ = high_resolution_clock::now();
        m_tag_ = tag;
    }

    void Reset() { m_begin_ = high_resolution_clock::now(); }

    llong Elapsed() {
        return static_cast<llong>(
            duration_cast<std::chrono::milliseconds>(high_resolution_clock::now() - m_begin_).count());
    }

    ~TimerLog() { // 对象析构时候计算当前时间与对象构造时候的时间差就是对象存活的时间
        auto time =
            duration_cast<std::chrono::milliseconds>(std::chrono::high_resolution_clock::now() - m_begin_).count();
        std::cout << "time { " << m_tag_ << " } " << static_cast<double>(time) << " ms" << std::endl;
    }


   private:
    std::chrono::time_point<std::chrono::high_resolution_clock> m_begin_;
    std::string m_tag_;
};

}  // namespace timer
}  // namespace wzq

使用方式：

void TestTimerLog() {
    auto func = [](){
        for (int i = 0; i < 5; ++i) {
            cout << "i " << i << endl;
            std::this_thread::sleep_for(std::chrono::milliseconds(1));
        }
    };
    {
        wzq::timer::TimerLog t("func");
        func();
    }
}

程序输出：

i 0
i 1
i 2
i 3
i 4
time { func } 5 ms

这样就可以很方便的打印函数时间，但是这里每次都需要定义一个对象，貌似也不太方便，可以考虑加个宏，如下：

#define CAL_SCOPE_TIME(x) wzq::timer::TimerLog t(x)

在如下使用：

void TestTimerLog() {
    auto func = [](){
        for (int i = 0; i < 5; ++i) {
            cout << "i " << i << endl;
            std::this_thread::sleep_for(std::chrono::milliseconds(1));
        }
    };
    {
        CAL_SCOPE_TIME("func time");
        func();
    }
}

是不是更方便啦，当然也有可能要计算多个交叉函数的耗时.

void TestTime() {
    func1();
    func2();
    func3();
    func4();
}

这里如果想计算func1()+func2()+func3()耗时，也想计算func2()+func3()+func4()耗时，使用上述RAII貌似就不太方便了，这里可以再写两个宏.

#define CAL_TIME_BEGIN(x) auto begin_##x = wzq::timer::TimerLog::Now();

#define CAL_TIME_END(x) \
    cout << "time { " << #x << " } " << wzq::timer::TimerLog::DiffMs(begin_##x, wzq::timer::TimerLog::Now()) << "ms" << endl;

就可以如下使用，尽管不是特别方便，但是也比最开始介绍的方便一些。

void TestTime() {
    CAL_TIME_BEGIN(func123)
    func1();
    CAL_TIME_BEGIN(func234)
    func2();
    func3();
    CAL_TIME_END(func123)
    func4();
    CAL_TIME_END(func234)
}

这样就会输出我们想要的耗时结果。

完整代码

#pragma once

#include <sys/time.h>

#include <chrono>
#include <ctime>
#include <fstream>
#include <iostream>
#include <string>

using llong = long long;
using namespace std::chrono;
using std::cout;
using std::endl;

#define CAL_SCOPE_TIME(x) wzq::timer::TimerLog t(x)

#define CAL_TIME_BEGIN(x) auto begin_##x = wzq::timer::TimerLog::Now();

#define CAL_TIME_END(x) \
    cout << "time { " << #x << " } " << wzq::timer::TimerLog::DiffMs(begin_##x, wzq::timer::TimerLog::Now()) << "ms" << endl;

namespace wzq {
namespace timer {
class TimerLog {
   public:
    TimerLog(const std::string tag) {
        m_begin_ = high_resolution_clock::now();
        m_tag_ = tag;
    }

    void Reset() { m_begin_ = high_resolution_clock::now(); }

    llong Elapsed() {
        return static_cast<llong>(
            duration_cast<std::chrono::milliseconds>(high_resolution_clock::now() - m_begin_).count());
    }

    static std::chrono::time_point<std::chrono::high_resolution_clock> Now() { return high_resolution_clock::now(); }

    static llong DiffUs(std::chrono::time_point<std::chrono::high_resolution_clock> before,
                        std::chrono::time_point<std::chrono::high_resolution_clock> after) {
        return static_cast<llong>(duration_cast<std::chrono::microseconds>(after - before).count());
    }

    static llong DiffMs(std::chrono::time_point<std::chrono::high_resolution_clock> before,
                        std::chrono::time_point<std::chrono::high_resolution_clock> after) {
        return static_cast<llong>(duration_cast<std::chrono::milliseconds>(after - before).count());
    }

    ~TimerLog() {
        auto time =
            duration_cast<std::chrono::milliseconds>(std::chrono::high_resolution_clock::now() - m_begin_).count();
        std::cout << "time { " << m_tag_ << " } " << static_cast<double>(time) << " ms" << std::endl;
    }

    static llong GetCurrentMs() {
        struct timeval time;
        gettimeofday(&time, NULL);
        return static_cast<llong>(time.tv_sec * 1000) + static_cast<llong>(time.tv_usec / 1000);
    }

    static void ShowCurTime() {
        time_t now = time(0);
        char* dt = ctime(&now);
        cout << "cur time is " << dt << endl;
        cout << "cur ms is " << GetCurrentMs() << endl;
    }

    static struct timeval GetCurrentTimeofDay() {
        struct timeval time;
        gettimeofday(&time, NULL);
        return time;
    }

   private:
    std::chrono::time_point<std::chrono::high_resolution_clock> m_begin_;
    std::string m_tag_;
};

}  // namespace timer
}  // namespace wzq

更多文章请关注