崇山 發表於 2025-6-23 10:17:00

DotTrace系列：3. 时间度量之墙钟时间和线程时间

<h2 id="一背景">一：背景</h2>
<h3 id="1-讲故事">1. 讲故事</h3>
<p>在用 dotTrace 对程序进行性能评测的时候，有一个非常重要的概念需要使用者明白，那就是 <code>时间度量 (Time measurement)</code>，主要分为两种。</p>
<ul>
<li>墙钟时间</li>
<li>线程时间</li>
</ul>
<p>在 dotTrace 中有四种测量维度，其中 <code>Real time</code> 对应着 墙钟时间，截图如下：</p>
<p><img src="https://img2024.cnblogs.com/blog/214741/202506/214741-20250623101655979-1292301723.png" alt="" loading="lazy"></p>
<h2 id="二时间度量分析">二：时间度量分析</h2>
<h3 id="1-墙钟时间">1. 墙钟时间</h3>
<p><code>墙钟时间</code> 顾名思义就是墙上的时钟，只要给它上电它就能跑，无视这人世间发生的任何变化，屹立千年而不倒。</p>
<p>用程序的话术就是它可以追踪到线程的 <code>上班时间</code> 和 <code>下班时间</code>，在 dottrace 中用 <code>performance counter</code> 和 <code>cpu instruction</code> 两种方式，本质上来说前者是后者的包装。</p>
<p>如果有朋友比较懵的话，可以用 C 调一下对应的 Win32 api 就明白了，参考代码如下：</p>
<pre><code class="language-C#">
#include &lt;windows.h&gt;
#include &lt;stdio.h&gt;
#include &lt;intrin.h&gt;

// 1. Real Time (Performance Counter)
void measure_real_time_perf_counter() {

        LARGE_INTEGER freq, start, end;
        QueryPerformanceFrequency(&amp;freq);
        QueryPerformanceCounter(&amp;start);
        // 模拟工作负载（Sleep 不占用 CPU 时间）
        Sleep(100);
        QueryPerformanceCounter(&amp;end);
        double elapsed = (double)(end.QuadPart - start.QuadPart) / freq.QuadPart;
        printf("RealTime (Performance Counter): %.2f ms\n", elapsed * 1000);
}

// 2. Real Time (CPU TSC)
void measure_cpu_tsc() {
        unsigned __int64 start = __rdtsc();
        // 模拟工作负载（注意：Sleep 不会增加 TSC）
        Sleep(100);// 此处仅为演示，实际应用应使用 CPU 密集型操作
        unsigned __int64 end = __rdtsc();
        printf("RealTime (CPU TSC): %llu cycles\n", end - start);
}

int main() {
        printf("----- Measuring Time with Win32 APIs -----\n");
        measure_real_time_perf_counter();
        measure_cpu_tsc();
        return 0;
}

</code></pre>
<p><img src="https://img2024.cnblogs.com/blog/214741/202506/214741-20250623101655984-486444822.png" alt="" loading="lazy"></p>
<p>从卦中可以看到这两种模式都可以追踪到线程的 <code>下班时间</code>，接下来稍微解释下。</p>
<ol>
<li>QueryPerformanceCounter，QueryPerformanceFrequency</li>
</ol>
<p>上面的 QueryPerformanceCounter 是Windows硬件定时器的计数，而 QueryPerformanceFrequency 是这个定时器的时钟频率 （速度），所以时间值可以用小学的公式 <strong>T= S/V</strong> 算出来。</p>
<ol start="2">
<li>__rdtsc</li>
</ol>
<p>tsc 是cpucore中的一个硬件寄存器，这个寄存器记录了cpu上电之后的时钟周期数，要想算出时间需要知道cpu的时钟频率，截图如下：</p>
<p><img src="https://img2024.cnblogs.com/blog/214741/202506/214741-20250623101655991-546901438.png" alt="" loading="lazy"></p>
<p>有些朋友就说了，你拿 <code>差值/2.2GHZ</code> 不就是时间吗？这么算的话其实不准的，因为 <code>2.2GHZ</code> 是基准频率，CPU在工作时会有上下浮动，比如写到这里的时候，当前的CPU的频率是<code>4.93Ghz</code>，这个就差的有点大了，截图如下：</p>
<p><img src="https://img2024.cnblogs.com/blog/214741/202506/214741-20250623101656012-1928487171.png" alt="" loading="lazy"></p>
<p>所以比较合理的做法需要校准下 <code>时钟频率</code>，我觉得 dottrace 内部应该是这么做的，毕竟这东西是闭源的，为了最简化，这里就用一个硬编码，参考如下：</p>
<pre><code class="language-C#">
// 2. Real Time (CPU TSC)
void measure_cpu_tsc() {

        double CPU_FREQUENCY_GHZ = 2.2;// 例如 2.2 GHz

        unsigned __int64 start = __rdtsc();

        Sleep(100);// 实际应用应替换为 CPU 密集型操作
        unsigned __int64 end = __rdtsc();

        // 计算时间（毫秒）：
        // 1. 计算时钟周期差值
        unsigned __int64 cycles = end - start;
        // 2. 转换为秒：cycles / (frequency in Hz)
        double seconds = (double)cycles / (CPU_FREQUENCY_GHZ * 1e9);
        // 3. 转换为毫秒
        double milliseconds = seconds * 1000.0;

        printf("RealTime (CPU TSC): %.2f ms\n", milliseconds);
}

</code></pre>
<p><img src="https://img2024.cnblogs.com/blog/214741/202506/214741-20250623101655991-1561985033.png" alt="" loading="lazy"></p>
<h3 id="2-线程时间">2. 线程时间</h3>
<p><code>线程时间</code> 它追踪的是 <code>线程活动的时间</code>，即线程的上班时间，同样 dottrace 也支持两种，分别为 <code>Thread cycle time</code> 和 <code>Thread time</code> ，本质上来说也是直接调用 Win32 Api 算出来的，参考代码如下：</p>
<pre><code class="language-C#">

#include &lt;windows.h&gt;
#include &lt;stdio.h&gt;
#include &lt;intrin.h&gt;


// 1. Thread Time (User + Kernel Mode CPU Time)
void measure_thread_time() {
        FILETIME creation, exit, kernel_start, user_start, kernel_end, user_end;
        HANDLE thread = GetCurrentThread();
        GetThreadTimes(thread, &amp;creation, &amp;exit, &amp;kernel_start, &amp;user_start);
        // 模拟 CPU 密集型工作
        volatile int sum = 0;
        for (int i = 0; i &lt; 500000000; i++) sum += i;
        GetThreadTimes(thread, &amp;creation, &amp;exit, &amp;kernel_end, &amp;user_end);

        // 将 FILETIME（100ns 单位）转换为微秒
        ULARGE_INTEGER kernel_time, user_time;
        kernel_time.LowPart = kernel_end.dwLowDateTime - kernel_start.dwLowDateTime;
        kernel_time.HighPart = kernel_end.dwHighDateTime - kernel_start.dwHighDateTime;
        user_time.LowPart = user_end.dwLowDateTime - user_start.dwLowDateTime;
        user_time.HighPart = user_end.dwHighDateTime - user_start.dwHighDateTime;

        printf("Thread Time: Kernel=%.2f ms, User=%.2f ms\n",
                kernel_time.QuadPart / 10000.0,
                user_time.QuadPart / 10000.0);
}

// 2. Thread Cycle Time
void measure_thread_cycle_time() {
        ULONG64 start, end;
        HANDLE thread = GetCurrentThread();
        QueryThreadCycleTime(thread, &amp;start);
        // 模拟 CPU 密集型工作
        volatile int sum = 0;
        for (int i = 0; i &lt; 500000000; i++) sum += i;
        QueryThreadCycleTime(thread, &amp;end);
        printf("Thread Cycle Time: %llu cycles\n", end - start);
}

int main() {
        printf("----- Measuring Time with Win32 APIs -----\n");
        measure_thread_time();
        measure_thread_cycle_time();
        return 0;
}

</code></pre>
<p><img src="https://img2024.cnblogs.com/blog/214741/202506/214741-20250623101655975-1231869318.png" alt="" loading="lazy"></p>
<p>同样的也来稍微解读下。</p>
<ol>
<li>GetThreadTimes</li>
</ol>
<p>这个方法是直接获取线程内核数据结构 <code>KThread</code> 里的 KernelTime 和 UserTime 字段，我可以用 windbg 给大家演示下。</p>
<pre><code class="language-C#">
lkd&gt; !process 0 2 notepad.exe
PROCESS ffffb98d5cc1a080
    SessionId: noneCid: 6af4    Peb: ed94d6c000ParentCid: 22a0
    DirBase: 3f045a000ObjectTable: ffffe1039bf39040HandleCount: 848.
    Image: Notepad.exe

      THREAD ffffb98d5f0a3080Cid 6af4.60ccTeb: 000000ed94d6d000 Win32Thread: ffffb98d69a53e20 WAIT: (WrUserRequest) UserMode Non-Alertable
            ffffb98d6d64a9c0QueueObject

      THREAD ffffb98d8766c080Cid 6af4.3894Teb: 000000ed94d6f000 Win32Thread: 0000000000000000 WAIT: (Unknown) UserMode Alertable
            ffffb98d78286140QueueObject
    ...

lkd&gt; dt nt!_KTHREAD ffffb98d5f0a3080 -y KernelTime UserTime
   +0x28c KernelTime : 4
   +0x2dc UserTime   : 2

</code></pre>
<p>要注意的是上面的字段是 <code>100纳秒</code> 为单位的，即 <code>100纳秒=0.1ms</code>，所以上面分别为 <code>0.4ms</code> 和 <code>0.2ms</code>。</p>
<ol start="2">
<li>QueryThreadCycleTime</li>
</ol>
<p>在 _KTHREAD 中有一个字段 <code>CycleTime</code>，当<code>线程上班</code>和<code>线程下班</code>时都要打卡到 <code>CycleTime</code> 字段里，同样也可以用windbg 验证。</p>
<pre><code class="language-C#">
lkd&gt; dt nt!_KTHREAD ffffb98d5f0a3080 -y CycleTime
   +0x048 CycleTime : 0x6db6621

lkd&gt; ? 0x6db6621
Evaluate expression: 115041825 = 00000000`06db6621

</code></pre>
<p>接下来就是如何将时钟周期差值转为 ms 呢？这需要知道CPU当时的时钟频率，同样我也简化一下，参考代码如下：</p>
<pre><code class="language-C#">
// 2. Thread Cycle Time
void measure_thread_cycle_time() {
        ULONG64 start, end;
        HANDLE thread = GetCurrentThread();
        QueryThreadCycleTime(thread, &amp;start);

        volatile int sum = 0;
        for (int i = 0; i &lt; 500000000; i++) sum += i;

        QueryThreadCycleTime(thread, &amp;end);

        const double CPU_FREQUENCY_GHZ = 2.2;// 假设 CPU 主频 2.2 GHz
        double milliseconds = (double)(end - start) / (CPU_FREQUENCY_GHZ * 1e6);// 直接计算毫秒

        printf("Thread Cycle Time: %.2f ms\n", milliseconds);
}

</code></pre>
<p><img src="https://img2024.cnblogs.com/blog/214741/202506/214741-20250623101655981-950363533.png" alt="" loading="lazy"></p>
<p>哈哈，这两个值偏差还是有点大哈。</p>
<h2 id="三总结">三：总结</h2>
<p>理解墙钟时间和线程时间的底层原理，对我们后续的场景分析特别有用，比如前者适合分析为什么程序卡死？后者适合分析是哪些线程吃了那么多的CPU？</p>
<blockquote>
<p>作为JetBrains社区内容合作者，如有购买jetbrains的产品，可以用我的折扣码 HUANGXINCHENG，有25%的内部优惠哦。</p>
</blockquote>
<img src="https://images.cnblogs.com/cnblogs_com/huangxincheng/345039/o_210929020104最新消息优惠促销公众号关注二维码.jpg" width="700" height="300" alt="图片名称" align="center"><br><br>
来源：https://www.cnblogs.com/huangxincheng/p/18943834
頁: [1]
查看完整版本: DotTrace系列：3. 时间度量之墙钟时间和线程时间