printf记录程序日志

通常我们需要在程序中输出部分日志信息，并把它记录到文件中。在这种情况下，使用printf可以为我们带了很大方便。因为printf却省情况下是向stdout即控制台屏幕输出信息，在GUI程序中，我们看不到printf的输出结果，但是我们可以将该输出重定向到指定的文件中。即使用freopen(“c:\\yourlog.log”,“a+”,stdout)或通过yourapp.exe >c:\yourlog.log完成输出重定向操作。

但是通常我们需要在记录日志的时候记录更多的信息，比如说运行时间等，所以我们不能使用一条简单的printf来完成该操作，另外，为防止日志信息以外丢失，我们最好是在每次printf后立即调用fflush。所以我们通常会使用下面的方法来完成日志记录操作：

void __cdecl log0 (const char*  _Format, ...)
{
    char buff[10240], tm[80];
    va_list vl;
    va_start (vl, _Format);

    _strtime (tm);
    vsnprintf (buff, 10240, _Format, vl);
    printf ("%s - %s", tm, buff);
    fflush(stdout);
    va_end (vl);
}

从该代码可以看出，我们必须事先定义好一个我们认为足够大的缓存已存储所有可能的数据，这就是使用该方法带来的inflexibility，究竟多大才算足够大啊？10240？102400？甚至1024000？恐怕你的栈也没这么大吧！即使你在堆中分配存储空间也一样！
接下来我就介绍一种不用预先分配缓存并且能够接受并输出任意长度的信息至日至文件中（当然，只要不超过你的系统允许的大小），试想，只要我们在log0中完成了我们想做的任何事（比如输出日志前缀信息等），并且如果能够将调用者传递给log0的参数“原封不动”的传递给printf的话，即将所有的可变参数按照printf所要求的格式传递给它，由它来完成剩下的操作。这是不是就克服了使用预先分配缓存的问题呢？没错，接下来所要解决的就是怎样将这些可变参数“传递”给printf。

由于在log0内部，我们不知道调用者究竟传递了多少个参数进来，所以我们不能按照通常所用的按照参数名的方式将参数传递给printf。但是，先别急，看看log0的函数声明，他是不是和printf的声明完全一致呢（事实上只要是log0中的参数和printf中的部分一致也可，如voidlog1(char* filename, int len, char* _Format, ...)也可。）？

也就是说拥有相同声明的函数，在被调用时，他们所拥有的参数栈（即StackFrame）的结构是一样的。所以，只要我们能够从一个函数A“突然”跳转到另外一个函数B中，那么B所拥有的参数栈和A将是同一份数据，即他们“共享”了同一份参数栈数据。需要注意的是，这里的跳转不能使用通常的函数掉用来实现，因为函数被调用时，编译器会在背后做很多事情，如给我们设置新的ESP指针等等，因此这样势必不能达到共享参数栈数据的目的。为了不让编译器在函数调用时在背后做任何事情，我们需要使用一个naked函数，在这样的函数中我们就可以自己利用栈资源，自己控制所有一切。有了这样的函数后，就可以很轻松，而且很高效的达到我们的目的了。

void  mkprefix ()
{   char buff[80];
    _strtime (buff);
    printf ("%s - ", buff);
}

__declspec (naked)
void  __cdecl
xprintf (const char*  _Format, ...)
{
    __asm
    {   call    dword ptr [mkprefix]

        pop     ebx/* 将函数返回地址保存到EBX中 */
        call    dword ptr [printf]
        sub     esp, 4   /* 1 */

       /* 调用fflush将数据立即保存到文件中*/
        call    dword ptr [__iob_func]
        add     eax, 0x20
        push    eax
        call    dword ptr [fflush]
        add     esp, 4 /* 2 */

        mov     dword ptr [esp], ebx/* 恢复函数返回地址 */
        ret
    }
}

代码中在1和2处分别对ESP减4后又加4，所以这两处的代码完全可以忽略，在这里加上是为了更好的理解函数调用的机制（即在函数调用后需要修正ESP，即所谓的Stackclean-up）。你可以将mkprefix 作的足够复杂已记录更多的信息，甚至我们可以通过log0将参数传递到mkprefix 中，向log1那样。不过这样处理起来就稍复杂点，为简单起见，就不再讲述这种方法了。

当然，这只是这种所谓的“栈共享”技术的一个应用而已了，掌握了这种技术后，我想你肯定会把它应用到其他更适合的地方。

其实，在VC8中，由于提供了可变参数的宏，所以我们可以通过下面一条简单的调用来完成日至记录操作，而且信息还比较完全：

#define TRACE(fmt, ...) printf ("%s (%s:%d) - "##fmt, mkprefix(), __FILE__, __LINE__, __VA_ARGS__)

TRACE ( "This is a debug information, a = %d, b = %s.", 234, "xxxxx");