英文原文：A C++ Profiling Module for Multithreaded APIs

在之前一篇关于锁竞争的帖子中，我在一个多线程游戏引擎中为内存分配器提供了一些统计数据：从3个线程每秒发起15000次调用，占用差不多2%的CPU。为了收集这些数据，我写了一个小的分析模块，将在这分享给大家。

一个分析模块与常规分析工具，如xpref或VTune不同，它不需要借助第三方工具。你只需把这个模块放到任何C++应用程序里，然后这个进程就会自动收集并报告性能数据。

这个特定的分析模块是为了运行在应用程序中的一个或多个目标模块上。一个目标模块可以是任何公开了一个定义良好的API的程序，比如一个内存分配器。要让它工作，你必须为这个API公开的每个公共函数插入一个名为API_PROFILER的宏。下面我已经把它加到dlmalloc里--一个在Doug Lea Malloc中的函数。同样的宏还需加到realloc、dlfree和其他公共函数中。

DEFINE_API_PROFILER(dlmalloc); void* dlmalloc(size_t bytes)
{ API_PROFILER(dlmalloc); #if USE_LOCKS
    ensure_initialization(); #endif if (!PREACTION(gm))
    { void* mem;
        size_t nb; if (bytes <= MAX_SMALL_REQUEST)
        {
            ...

这个宏接受单个参数--一个为正被分析的目标模块设置的标识符。为了使它成为有效的标识符，如上所示，你必须严格地把宏DEFINE_API_PROFILER放在全局范围内。你也可以将DECLARE_API_PROFILER插入到全局范围的任何地方，或许在头文件中，并以同样的方式声明一个全局变量或函数。

当这个应用运行的时候，每个线程每秒自动记录性能统计结果一次，其中包括线程标识(TID),目标模块内所花费时间和调用次数。下面我们可以看到６个不同的线程的性能统计:

TID 0x13bc time spent in "dlmalloc": 7/1001 ms 0.7% 6481x
TID 0x1244 time spent in "dlmalloc": 6/1000 ms 0.6% 6166x
TID 0x198 time spent in "dlmalloc": 0/3072 ms 0.0% 2x
TID 0x11d0 time spent in "dlmalloc": 0/1113 ms 0.0% 6x
TID 0x12a4 time spent in "dlmalloc": 0/1000 ms 0.0% 20x
TID 0xc14 time spent in "dlmalloc": 4/1011 ms 0.4% 3243x

为了识别各个线程，只要在调试器内设置中断，然后在查看线程里查找线程标识(TID)即可。

大多数分析模块像下面这样是在单个头文件中实现的。为了简单起见，我只提供Windows版本，不过你可以很容易地移植这段代码到其他平台。

#define ENABLE_API_PROFILER 1     // Comment this line to disable the profiler

#if ENABLE_API_PROFILER

//------------------------------------------------------------------
// A class for local variables created on the stack by the API_PROFILER macro:
//------------------------------------------------------------------
class APIProfiler
{
public:
    //------------------------------------------------------------------
    // A structure for each thread to store information about an API:
    //------------------------------------------------------------------
    struct ThreadInfo
    {
        INT64 lastReportTime;
        INT64 accumulator;   // total time spent in target module since the last report
        INT64 hitCount;      // number of times the target module was called since last report
        const char *name;    // the name of the target module
    };

private:
    INT64 m_start;
    ThreadInfo *m_threadInfo;

    static float s_ooFrequency;      // 1.0 divided by QueryPerformanceFrequency()
    static INT64 s_reportInterval;   // length of time between reports
    void Flush(INT64 end);
    
public:
    __forceinline APIProfiler(ThreadInfo *threadInfo)
    {
        LARGE_INTEGER start;
        QueryPerformanceCounter(&start);
        m_start = start.QuadPart;
        m_threadInfo = threadInfo;
    }

    __forceinline ~APIProfiler()
    {
        LARGE_INTEGER end;
        QueryPerformanceCounter(&end);
        m_threadInfo->accumulator += (end.QuadPart - m_start);
        m_threadInfo->hitCount++;
        if (end.QuadPart - m_threadInfo->lastReportTime > s_reportInterval)
            Flush(end.QuadPart);
    }
};

//----------------------
// Profiler is enabled
//----------------------
#define DECLARE_API_PROFILER(name) 
    extern __declspec(thread) APIProfiler::ThreadInfo __APIProfiler_##name;

#define DEFINE_API_PROFILER(name) 
    __declspec(thread) APIProfiler::ThreadInfo __APIProfiler_##name = { 0, 0, 0, #name };

#define TOKENPASTE2(x, y) x ## y
#define TOKENPASTE(x, y) TOKENPASTE2(x, y)
#define API_PROFILER(name) 
    APIProfiler TOKENPASTE(__APIProfiler_##name, __LINE__)(&__APIProfiler_##name)

#else

//----------------------
// Profiler is disabled
//----------------------
#define DECLARE_API_PROFILER(name)
#define DEFINE_API_PROFILER(name)
#define API_PROFILER(name)

#endif

DEFINE_API_PROFILER宏定义了一个使用declspec(thread)修改器的线程局部变量。这使得每个线程都拥有独立于其他线程的、自己的私有数据，因此整个系统在很少的性能损失的情况下运行在多线程环境下。在GCC里，等同的存储类修改器是thread。这样的存储需要的资源是很低的，然而在Windows上，会捕捉到以下信息：你不能跨DLL使用它。

API_PROFILER宏在栈上创建了一个C++对象，这个对象的构造器指示统计测量开始，解构器指示统计测量结束。这个宏使用当前行号作为粘贴标记创建唯一的局部变量名。

不递归地调用这个宏是非常重要的。换句话说，在API_PROFILER标识符的范围内可调用统一标识符的任何地方不要插入另一个API_PROFILER。如果你这么做，那么 你最终将计算花费在目标模块内的时间两次！如果绝对必须这么做，那么你要在花费很少额外资源的情况下修改分析模块以绕过这个限制。

解构器有时候调用一个名字为Flush的函数。它是一个很耗资源的函数，因此我们在separate.cpp文件里定义了它，以确保每秒之调用它一次:

#if ENABLE_API_PROFILER

static const float APIProfiler_ReportIntervalSecs = 1.0f;

float APIProfiler::s_ooFrequency = 0;
INT64 APIProfiler::s_reportInterval = 0;

//------------------------------------------------------------------
// Flush is called at the rate determined by APIProfiler_ReportIntervalSecs
//------------------------------------------------------------------
void APIProfiler::Flush(INT64 end)
{
    // Auto-initialize globals based on timer frequency:
    if (s_reportInterval == 0)
    {
        LARGE_INTEGER freq;
        QueryPerformanceFrequency(&freq);
        s_ooFrequency = 1.0f / freq.QuadPart;
        MemoryBarrier();
        s_reportInterval = (INT64) (freq.QuadPart * APIProfiler_ReportIntervalSecs);
    }

    // Avoid garbage timing on first call by initializing a new interval:
    if (m_threadInfo->lastReportTime == 0)
    {
        m_threadInfo->lastReportTime = m_start;
        return;
    }

    // Enough time has elapsed. Print statistics to console:
    float interval = (end - m_threadInfo->lastReportTime) * s_ooFrequency;
    float measured = m_threadInfo->accumulator * s_ooFrequency;
    printf("TID 0x%x time spent in "%s": %.0f/%.0f ms %.1f%% %dx
",
        GetCurrentThreadId(),
        m_threadInfo->name,
        measured * 1000,
        interval * 1000,
        100.f * measured / interval,
        m_threadInfo->hitCount);

    // Reset statistics and begin next timing interval:
    m_threadInfo->lastReportTime = end;
    m_threadInfo->accumulator = 0;
    m_threadInfo->hitCount = 0;
}

#endif

在上面的代码里，记录日志的时候使用了printf，不过你可以很容易地用sprintf和OutputDebugString或者其他函数替代它。记录日志到控制台这样好的事情在即使没有图形显示的时候仍然可以工作，比如游戏装载期间，或者应用启动时刻。这些都是你分析特定API可能非常感兴趣的时刻。

这个分析模块的另一个便利之处是不需要显式地进行初始化。当第一次调用宏的时候，这个宏就会调用Flush。调用Flush的第一个线程将会看到s_reportInterval依然没有得到初始化，于是自己进行初始化。如果最终出现两个线程同时对全局变量初始化，这种情形无关紧要；因为它们写的是同一值。

我测到两种处理器上API_PROFILER宏所花费的时间：在1.86G赫兹的Core 2 Duo处理器上是 99纳秒，而在2.66G赫兹的至强处理器上是 30.8纳秒。这只比非常适宜于细粒度分析技术的 争用Windows临界区稍慢了一丁点。你可以通过调用 rdtsc而不是调用QueryPerformanceCounter来更进一步减少所花费的时间，不过得到的结果数值 在多核系统非常不可靠，因此我没有选择使用它。

内置分析模块也不是新事物-Jeff Everett在游戏编程Gems 2里说明了另一个内置在游戏中的分析器。我希望至少写出了我对这方面的一点思考。我也有兴趣听取你自己对它的思考。据我所知，没有任何第三方分析器能够像我在这儿所描述的分析器那样容易地且精确地对多线程API进行分析。无论是Valgrind、xperf、Vtune、Shark、PIX、Tuner、Visula Studio Profiler或者其他分析器。如果我是错的，请读者指出错误，我将改正。

另一方面，这样的分析器会向你展示了什么时候测量的模块将很耗资源-例如，模块内部函数运行接近程序计数取样分析的最高值。有时，随机突破可以提供类似的线索。这时，你将不得不使用像这儿所提到的内置分析模块进行更进一步的分析，并测量出后来更改的代码对性能的影响。

本文中的所有译文仅用于学习和交流目的，转载请务必注明文章译者、出处、和本文链接。 2KB翻译工作遵照 CC 协议，如果我们的工作有侵犯到您的权益，请及时联系我们。

2KB项目（www.2kb.com，源码交易平台）,提供担保交易、源码交易、虚拟商品、在家创业、在线创业、任务交易、网站设计、软件设计、网络兼职、站长交易、域名交易、链接买卖、网站交易、广告买卖、站长培训、建站美工等服务