昨天接到一个活，让我把项目中各个过程消耗的时间写到日志里。这个问题不困难，但是很麻烦。第一需要对项目的整个流程大致了解才行；第二需要修改的地方太多，需要在每个过程的开头开始计时，最后在结束后停止计时。经过一番修改，最终找到了一个还算不错的解决办法，且听我细细道来。
1 C++计时方法
说到计时，无非就是在开始的时候获取一个时间点，结束后获取一个时间点，然后将二者相减。
#include <time.h>
int main(){
// 获取开始时间
clock_t before = clock(); // clock() 可以获取程序开始执行到现在经历的时间，单位为毫秒，clock_t就是long
// 过程代码
// ...
// 获取结束时间
clock_t after = clock();
// 计算经历时间
clock_t during = after - before;
// 将经历时间转为字符串
during %= (1000 * 3600);
int m = during / 1000 / 60;
during %= (1000 * 60);
int s = during / 1000;
during %= 1000;
int ms = during;
std::stringstream stm;
stm << std::setfill('0');
stm << h << "H ";
stm << m << "M ";
stm << s << "S ";
stm << ms << "MS";
cout << stm.str();
}
计时的原理一定是这样，但是在实际运用的过程中则非常的不方便。
- 如果一个计时过程有大量的代码，需要人工找到过程的起始点和终止点。
- 一个项目中需要计时的过程非常多。
- 每开始一个计时就需要定义一个计时变量，尤其是在一大段计时中又需要分几个小段的情况下，命名非常困难且容易冲突。
- 主业务代码中添加了很多计时用的代码，使代码变得混乱，主业务逻辑不清晰。
总之缺陷很多。
2 对每个函数进行计时
如果换一种思路，对每个函数进行计时，那么就不需要去区分哪些代码属于一个过程，并且一个函数只需要计时一次，也不会出现命名的困难。当然，如果代码的架构很好的话，本来就将各个过程都封装成了函数，这两个问题就成了一个问题。但是，对函数计时也存在一定的困难，请看下面的情况：
void function() {
if (condition1)
{
// ...
if (condition1)
{
// ...
if (condition1)
{
// ...
return;
}
else
{
return;
}
}
else
{
return;
}
}
else
{
return;
}
}
也就是一个函数有很多地方有 return，那么如果我们就需要在每一个 return 前面加上结束计时的代码。这同样很麻烦，没有任何一个程序员喜欢把代码复制了到处粘贴的。
3 利用 try…catch…finally 语句对函数进行计时？
在遇到上面的问题后，我的第一反应就是可以以用 try…catch…finally 语句对函数进行计时，因为 finally 块中包含的语句即使函数返回了也会执行，只要在 finally 块中结束计时不久可以了吗？抱歉：
1 IntelliSense: 未定义标识符 “finally” …….
标准 C++ 不支持 finally，WTF？
4 使用析构函数来实现
既然 C++ 不支持 finally ，那就想另想办法吧。我们的主要目的是：在函数退出时获取时间并打印计时。那么还有什么是在函数退出时发生的呢？(o゜▽゜)o☆[BINGO!]，局部变量的析构发生在退出局部作用域时，简单地说，就是：
- 写一个类，在构造函数中获取开始时间。
- 在析构函数中获取结束时间，并计算经历时间，完成写日志工作。
- 在需要计时的函数开头声明一个此类的局部变量。
实现：
class CLogTime
{
private:
long long startPoint;
std::string statement;
public:
CLogTime(CString file, int line, CString function); // 三个参数分表表示调用此函数处的文件名、行数、调用此函数的函数名。
~CLogTime();
};
CLogTime::CLogTime(CString file, int line, CString function)
{
CString timeFunctionStr;
timeFunctionStr.Format(_T("FILE: %s, LINE: %d, FUNCTION: %s"), file, line, function);
USES_CONVERSION;
statement = std::string(T2A(timeFunctionStr.GetBuffer()));
startPoint = clock(); // 获得开始时间
}
CLogTime::~CLogTime()
{
// 获得析构时间
long long endPoint = clock();
// 获得经历时间
long during = endPoint - startPoint;
int h = during / 1000 / 3600;
during %= (1000 * 3600);
int m = during / 1000 / 60;
during %= (1000 * 60);
int s = during / 1000;
during %= 1000;
int ms = during;
std::stringstream stm;
stm << std::setfill('0');
stm << h << "H ";
stm << m << "M ";
stm << s << "S ";
stm << ms << "MS";
// 写入日志
CLogManager::writeLog(statement.append(" cost time: ").append(stm.str()));
}
5 改进
虽然已经实现功能了，但是还需要改进一下：
- 把被计时的函数的函数名写入日志。
- 让调用形式更统一，更方便。
定义宏：
// 记录时间的宏，在函数的开头使用此宏，会将函数运行的时间写入日志
#define _TIME_THIS_FUNCTION_ \
CLogTime logFunctionTime(__FILEW__, __LINE__, __FUNCTIONW__);
这样在每个需要计时的函数开始加上
_TIME_THIS_FUNCTION_
就可以输出哪个文件，哪一行，哪个函数消耗了多少时间，效果如下。
2019-11-19 11:41:11 FILE: ReadBaseLineIDXtoBuildModel.cpp, LINE: 252, FUNCTION: ReadBaseLineIDX cost time: 0H 0M 0S 257MS