gprof显示一个简单的信号处理程序占用大量CPU

debugcn 发表于 Dev

达斯汀

我使用gprof来分析在Linux上运行的程序，该程序使用25毫秒间隔的计时器（由timer_create（）创建）来更新全局变量。信号处理程序类似于update_every_25ms（），它调用profile_dummy（）来增加一个怪异的变量：

static void update_every_25ms(int sig_nr) { profile_dummy(); }
void profile_dummy(void) { global_var++; }

计时器是通过以下方式创建的：

timer_t timer;
struct itimerspec itimer;
timer_create(CLOCK_MONOTONIC, NULL, &timer)
itimer.it_interval.tv_sec = 0;
itimer.it_interval.tv_nsec = 25 * 1000 * 1000;
timer_settime(timer, 0, &itimer, NULL);

我的程序做了很多繁重的工作，但是gprof显示，当CPU使用率为100％时，update_every_25ms（）函数会花费大部分时间，并且此函数本身每次调用大约需要1.53ms！

以下是间隔为25ms时的几组gprof输出：

%time  cumulative  self     calls  self    total    name
       seconds     seconds         ms/call ms/call
3.72   116.26      7.76     22963  0.34    0.34     profile_dummy

在这里，CPU使用率为60％。为什么profile_dummy（）每次通话需要0.34毫秒？

%time  cumulative  self     calls  self    total    name
       seconds     seconds         ms/call ms/call
9.38   38.87       38.87    25349  0.00    0.00     profile_dummy

在这里，CPU使用率为100％。38.87s / 25349 = 1.53ms但gprof输出0.00，发生了什么？

%time  cumulative  self     calls  self    total    name
       seconds     seconds         ms/call ms/call
6.21   270.58      57.72 59105     0.00    0.00     profile_dummy

在这里，CPU使用率为90％。并且57.72s / 59105 = 0.98ms，但gprof也输出0.00。

这是我将计时器间隔更改为25s时的gprof输出：

%time  cumulative  self     calls  self    total    name
       seconds     seconds         ms/call ms/call
0.01   287.52      0.03  23        1.30    1.30     profile_dummy

该函数只是增加一个全局变量，为什么需要1.30ms？

感谢您的答复。

迈克·邓拉维

我只是在猜测一个危险。

gprof每10毫秒有一个信号中断，这时它将对程序计数器（PC）进行采样。例程的总自身时间是该例程中降落的样本数。由于它也计入对例程的调用，因此可以获得每次调用的平均自身时间。

通常，当您的程序被阻塞时，例如I / O，睡眠或多任务挂起，PC没有意义，因此中断被挂起。这就是为什么gprof根本看不到I / O的原因。

但是，如果您有自己的计时器中断，则可能仅掩盖探查器中断，而不会暂停该中断，导致在取消您的计时器中断后对其进行应答，这可能会使PC优先进入中断处理程序。

但这只是一个猜测。

除非这纯粹是一个学术问题，否则没有比更好的分析器gprof。

本文收集自互联网，转载请注明来源。

如有侵权，请联系[email protected] 删除。