测量linux内核中函数的执行时间

Posted 2023-02-23

【中文标题】测量linux内核中函数的执行时间

【英文标题】：Measuring execution time of a function inside linux kernel

【发布时间】：2011-01-11 08:45:08

【问题描述】：

我正在使用 Linux 安全模块挂钩向 recv() 系统调用添加一些自定义功能。与原始的 recv() 相比，我想测量此功能的开销。我编写了一个简单的 tcp 服务器，可以在有和没有模块的情况下运行。此 tcp 服务器调用 recv() 函数“N”次。它测量每个 recv 所花费的时间，例如：

clock_gettime(before);
recv()
clock_gettime(after);
global_time += after - before.

最后，我用“global_time/N”打印单个recv() 的平均时间。让我们将此时间称为“user_space_avg_recv”时间。

在我的模块中，我想放置时间测量函数来计算我的钩子的确切执行时间。我尝试了 3 种方法。

我使用 jiffies 如下：

sj = jiffies;
my_hook();
ej = jiffies;
current->total_oh = ej - sj;

但我发现 sj 和 ej 值之间没有区别。因此 total_oh 没有改变。

我使用 current_kernel_time() 因为我认为它以纳秒为单位返回时间。但是，再一次，前后时间没有区别。

我使用了 get_cycles。我打印进程退出时的总周期。但是，当我将总周期值转换为毫秒时，它会远大于 “user_space_avg_recv”值。这没有意义，因为内核内部的测量值总是小于从用户空间测量的时间值。这可能意味着我要么没有使用正确的 API 进行测量，要么在将值从周期转换为毫秒时出错。

我基本上使用以下公式将周期转换为毫秒：

avg overhead of my hook in milliseconds = 
             (((cycles / 2.99) / 10^6) / N)

2.99 因为我的时钟频率是 2.99Ghz

几点：

我的用户空间程序使用 set affinity 绑定到单个内核。

我使用的是内核 2.6.22.14

为了阻止内核在我的钩子中切换上下文，我使用了 preempt_disable() 和 preempt_enable()。因此它不会计算其他内核线程的执行时间。即使这样，由于我的钩子使用了一些 I/O，我的线程可能会自愿释放控制，或者可能会发生一些中断，这可能会增加总周期数。

问题： 如何在内核中准确测量函数执行时间？

【问题讨论】：

尝试在 Bios 中禁用频率更改并按周期重新测量

你试过ktime_get吗？

【参考方案1】：

您可以使用function tracer API 来跟踪所有函数调用和返回，并带有高精度时间戳。这包括中断事件和上下文切换。然后，您可以分析用户空间中生成的跟踪，以准确了解您的函数需要多长时间运行。

如果您不能使用函数跟踪器 API，您可以调用 do_gettimeofday() 来获取微秒分辨率的时间戳，或调用 getnstimeofday() 来获取纳秒分辨率。这些与用户空间 gettimeofday() 调用在内部使用的功能相同。当然，对于非常快速的函数，这可能不够准确；任何比这更快的精度，您可能需要深入研究计时器代码以查看它如何实现周期转换。另请注意，仅仅因为它们具有高分辨率并不意味着它们具有那么高的准确性 - 但它们应该对基准测试有用。

请注意，任何形式的跟踪都会导致额外的延迟 - do_gettimeofday() 需要许多原子比较和交换操作，并且 ftrace 将日志代码放在每个单个函数的前置和后置码时间>。在解释结果时应考虑到这一点。

【讨论】：

那不是为 2.6.28 以后写的吗？我正在使用 2.6.22.14。

@Methos：用另一种方法更新。

@bdonlan，感谢您的更新。但是，do_gettimeofday() 在内部从“xtime”读取值。我在数字 2 中提到的 current_kernel_time() 函数也有同样的作用（它在同一个文件 kernel/time.c 中）。正如我在第 2 点中所说，我没有看到在我的钩子之前和之后返回的值之间有任何时间差。

实际上，它们是不同的——xtime 会定期更新，因此精度有限。 do_gettimeofday 根据 CPU 周期计数应用偏移量，以获得更高的结果精度。比较我链接到的do_gettimeofday() 的代码和current_kernel_time 的代码（lxr.linux.no/linux+v2.6.22.14/kernel/time.c#L219）

我想你说的是从 do_gettimeofday() 中的 time_interpolator_get_offset() 获得的偏移量。我不知道这是否确实计算了 CPU 周期（但我会相信你的话）。在任何情况下，do_gettimeofday() 在“struct timeval”中返回值，其精度为秒和微秒。我需要 struct timespec，它的精度为 sec 和 nanosec。我想我必须添加我自己的 my_gettimeofday()，它基本上不会将 nsec 转换为 microsec。我将对内核进行更改，编译并测试您的理论。再次感谢。

【参考方案2】：

我不确定你会得到你想要的结果，但我们使用以下代码来获得微秒。

double Microsecs()

   static struct timeval _t;  
   static struct timezone tz;  
   gettimeofday(&_t, &tz);  
   return   (double)_t.tv_sec + (double)_t.tv_usec/(1000*1000);

比你在你想要的调用之前和之后调用它，看看它有多少次。 我们一直在使用这种方法来评估 IO 时间监控读/写/寻道操作，以优化性能，并且取得了不错的效果。

HTH。

【讨论】：

为什么是“静态结构”而不是普通结构？对我来说，这似乎是一种竞争条件......

你可能是对的。在单线程代码中减少了堆栈上的活动量，特别是当您在测试中调用它超过 10^6 次并执行非常多的非常小的时间片总和时。但是，无论如何，你可能是对的。我 9 年前做过，我实际上不记得是否检查过性能差异。

【参考方案3】：

您尝试过使用 OProfile 吗？

【讨论】：

我想过。但是我想分别分析每个进程的钩子。我不知道如何使用 Oprofile 来做到这一点，我认为这种方法会更容易。关于如何使用 Oprofile 执行此操作的任何指示？

@Dan：这不是答案。您可以通过发表评论来澄清这些事情。