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

森萌黠 · 2025-6-23 09:08:10

一：背景

1. 讲故事

在用 dotTrace 对程序进行性能评测的时候，有一个非常重要的概念需要使用者明白，那就是时间度量 (Time measurement)，主要分为两种。

墙钟时间
线程时间

在 dotTrace 中有四种测量维度，其中 Real time 对应着墙钟时间，截图如下：

二：时间度量分析

1. 墙钟时间

墙钟时间顾名思义就是墙上的时钟，只要给它上电它就能跑，无视这人世间发生的任何变化，屹立千年而不倒。
用程序的话术就是它可以追踪到线程的上班时间和下班时间，在 dottrace 中用 performance counter 和 cpu instruction 两种方式，本质上来说前者是后者的包装。
如果有朋友比较懵的话，可以用 C 调一下对应的 Win32 api 就明白了，参考代码如下：

#include <windows.h>
#include <stdio.h>
#include <intrin.h>
// 1. Real Time (Performance Counter)
void measure_real_time_perf_counter() {
LARGE_INTEGER freq, start, end;
QueryPerformanceFrequency(&freq);
QueryPerformanceCounter(&start);
// 模拟工作负载（Sleep 不占用 CPU 时间）
Sleep(100);
QueryPerformanceCounter(&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;
}

复制代码

从卦中可以看到这两种模式都可以追踪到线程的下班时间，接下来稍微解释下。

QueryPerformanceCounter，QueryPerformanceFrequency

上面的 QueryPerformanceCounter 是Windows硬件定时器的计数，而 QueryPerformanceFrequency 是这个定时器的时钟频率（速度），所以时间值可以用小学的公式 T= S/V 算出来。

__rdtsc

tsc 是cpucore中的一个硬件寄存器，这个寄存器记录了cpu上电之后的时钟周期数，要想算出时间需要知道cpu的时钟频率，截图如下：

有些朋友就说了，你拿差值/2.2GHZ 不就是时间吗？这么算的话其实不准的，因为 2.2GHZ 是基准频率，CPU在工作时会有上下浮动，比如写到这里的时候，当前的CPU的频率是4.93Ghz，这个就差的有点大了，截图如下：

所以比较合理的做法需要校准下时钟频率，我觉得 dottrace 内部应该是这么做的，毕竟这东西是闭源的，为了最简化，这里就用一个硬编码，参考如下：

// 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);
}

复制代码

2. 线程时间

线程时间它追踪的是线程活动的时间，即线程的上班时间，同样 dottrace 也支持两种，分别为 Thread cycle time 和 Thread time ，本质上来说也是直接调用 Win32 Api 算出来的，参考代码如下：

#include <windows.h>
#include <stdio.h>
#include <intrin.h>
// 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, &creation, &exit, &kernel_start, &user_start);
// 模拟 CPU 密集型工作
volatile int sum = 0;
for (int i = 0; i < 500000000; i++) sum += i;
GetThreadTimes(thread, &creation, &exit, &kernel_end, &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, &start);
// 模拟 CPU 密集型工作
volatile int sum = 0;
for (int i = 0; i < 500000000; i++) sum += i;
QueryThreadCycleTime(thread, &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;
}

复制代码

同样的也来稍微解读下。

GetThreadTimes

这个方法是直接获取线程内核数据结构 KThread 里的 KernelTime 和 UserTime 字段，我可以用 windbg 给大家演示下。

lkd> !process 0 2 notepad.exe
PROCESS ffffb98d5cc1a080
SessionId: none Cid: 6af4 Peb: ed94d6c000 ParentCid: 22a0
DirBase: 3f045a000 ObjectTable: ffffe1039bf39040 HandleCount: 848.
Image: Notepad.exe
THREAD ffffb98d5f0a3080 Cid 6af4.60cc Teb: 000000ed94d6d000 Win32Thread: ffffb98d69a53e20 WAIT: (WrUserRequest) UserMode Non-Alertable
ffffb98d6d64a9c0 QueueObject
THREAD ffffb98d8766c080 Cid 6af4.3894 Teb: 000000ed94d6f000 Win32Thread: 0000000000000000 WAIT: (Unknown) UserMode Alertable
ffffb98d78286140 QueueObject
...
lkd> dt nt!_KTHREAD ffffb98d5f0a3080 -y KernelTime UserTime
+0x28c KernelTime : 4
+0x2dc UserTime : 2

复制代码

要注意的是上面的字段是 100纳秒为单位的，即 100纳秒=0.1ms，所以上面分别为 0.4ms 和 0.2ms。

QueryThreadCycleTime

在 _KTHREAD 中有一个字段 CycleTime，当线程上班和线程下班时都要打卡到 CycleTime 字段里，同样也可以用windbg 验证。

lkd> dt nt!_KTHREAD ffffb98d5f0a3080 -y CycleTime
+0x048 CycleTime : 0x6db6621
lkd> ? 0x6db6621
Evaluate expression: 115041825 = 00000000`06db6621

复制代码

接下来就是如何将时钟周期差值转为 ms 呢？这需要知道CPU当时的时钟频率，同样我也简化一下，参考代码如下：

// 2. Thread Cycle Time
void measure_thread_cycle_time() {
ULONG64 start, end;
HANDLE thread = GetCurrentThread();
QueryThreadCycleTime(thread, &start);
volatile int sum = 0;
for (int i = 0; i < 500000000; i++) sum += i;
QueryThreadCycleTime(thread, &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);
}

复制代码

哈哈，这两个值偏差还是有点大哈。
三：总结

理解墙钟时间和线程时间的底层原理，对我们后续的场景分析特别有用，比如前者适合分析为什么程序卡死？后者适合分析是哪些线程吃了那么多的CPU？

作为JetBrains社区内容合作者，如有购买jetbrains的产品，可以用我的折扣码 HUANGXINCHENG，有25%的内部优惠哦。

来源：程序园用户自行投稿发布，如果侵权，请联系站长删除
免责声明：如果侵犯了您的权益，请联系站长，我们会及时删除侵权内容，谢谢合作！

账号		自动登录	找回密码
密码			立即注册

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

浏览过的版块

签约作者