一种有趣的错误跟踪LOG

我正式用C++做产品开发到现在大约有7、8年，从学C++算起的话有10年，经验应该算是比较丰富的。但是我很少写C++方面的技术文章，C++诞生到现在二十几年，经典书籍、技术文章数不胜数，能写的好像都被人写完了，找点值得一些的东西实在不容易。
在前一家公司的时候，我负责做基础框架，用COM+实现业务逻辑层。COM+这种东西不像standalone的application，调试和错误定位都很麻烦，而且它导出的接口是由外部模块执行，很多错误只能在后期才能发现。因此通常的排除故障的做法是在觉得可能出错的地方多输出一些LOG，通过 LOG信息逐步定位问题－这有点儿像嵌入式系统的调试。在复杂的场合下，知道在什么地方出错可能还不够，还得知道它是怎么执行到这一步的，换句话说，还得记录代码执行的路径。但是从另一个方面来看，输出太多的信息不但会影响系统性能，而且无关的信息也会干扰故障的诊断。因此，显而易见的理想情况是，系统正常时LOG越少越好，在出错的时候应该输出尽可能多的信息。我当时就想用C++做这么一个东西，可惜不久以后我就离开了那家公司，搞起了嵌入式，只留下一个prototype。
如何才能做到仅在出错的时候输出错误信息？我的基本想法是，在那些比较重要的代码路径上记录一些信息，在函数退出的时候根据函数的返回值决定是否输出到 LOG文件，在出现异常的情况下，利用C++的栈对象会在异常展开时被析构这一事实，异常情况也能cover。看下面的例子：

bool bar()
一种有趣的错误跟踪LOG

}

APPLOG_FUNCTION_ENTRY2分别在栈上定义一个本地C++对象
，在函数foo()和bar()返回或者抛出异常时C++对象的析构函数会被调用，在析构函数里结合返回值和异常决定是否输出LOG。
在这里析构函数的实现是关键，它必须识别出正常路径的析构和异常展开的析构两种情况，这得用到一些汇编知识。正常路径下析构函数的调用汇编代码大致是这样：

call AutoScopeTrace::~AutoScopeTrace

这里的call在X86架构下是一个相对调用指令（0xE8)。异常展开路径下的析构函数的调用的汇编代码大致如下：

mov eax, AutoScopeTrace::~AutoScopeTrace
call eax

这个call是一个间接调用指令（0xD0）。这样根据call指令编码的不同，我们就可以区分正常路径析构和异常展开路径下的析构。然而又有一个问题，如何在析构函数里获取调用它的代码地址呢？这个可以根据析构函数的返回地址（在栈上）来得到。然而在打开优化编译选项的情况，返回地址在栈上的位置并不确定，如果析构函数可以带参数，我们可以用这种方法得到返回地址：

AutoScopeTrace::~AutoScopeTrace(int var)
{
DWORD retaddr = (reinterpret_cast<DWORD*>(&var))[-1];
}

然而地球人都知道析构函数不能带参数。在VC中，一种解决办法是利用优化开关强制给这个析构函数生成frame pointer（ebp），然后用frame pointer定位返回地址：

#pragma optimize( "g" , off )
#pragma optimize( "y" , on )
AutoScopeTrace::~AutoScopeTrace()
{
// the first two instructions in the function are:
// push ebp
// mov ebp,esp
}
#pragma optimize("", on)

这样[ebp+4]就是函数的返回地址，根据返回地址得到call指令编码，我们就能区分正常析构和异常析构。完整的析构函数的实现大致如下：

const BYTE INST_RELATIVE_CALL = 0xE8;
一种有趣的错误跟踪LOG

const BYTE INST_RELATIVE_CALL_LENGTH = 5;
一种有趣的错误跟踪LOG

inline static BOOL IsNormalCall(PBYTE callAddr, PBYTE entryAddr)
一种有趣的错误跟踪LOG

下面是前面的例子的LOG输出：

SCOPE TRACE started at Fri Jan 12 14:41:07 2007 in module: testscopetrace.exe(pid:2028, tid:3348)
testscopetrace.cpp(17): foo() Enter
testscopetrace.cpp(11): bar() Enter
testscopetrace.cpp(11): bar() Leave failed due to return value: bool=false
testscopetrace.cpp(17): foo() Leave failed due to exception

SCOPE TRACE stopped at Fri Jan 12 15:15:03 2007 in module: testscopetrace.exe(pid:2028, tid:3348)

如果bar()中retval为true，foo()中不抛出异常，LOG中不会记录信息。

这里可以下载一个比较完整的例子。

更新：
movieqiu网友回复说这个例子在VC6下编译通不过，这个我以前也发现了，但是没怎么管它。
支持VC6要解决两个问题。一是

#ifndef __FUNCTION__
#define __FUNCTION__ ""
#endif // __FUNCTION__