作者 | 陈振宇

问题描述

某个应用使用信号量做线程通信与同步，设了1毫秒的超时时间，但程序实际等了8毫秒才超时返回。

程序样例代码如下

auto tStart = std::chrono::high_resolution_clock::now();
Wait(1);
auto tEnd = std::chrono::high_resolution_clock::now();
        
auto nDurationMs = std::chrono::duration_cast<std::chrono::milliseconds>(tEnd - tStart).count();
td::cout << "等待耗时: " << nDurationMs << "ms" << std::endl;

其中Wait的实现如下：

int Wait(int nTimeOutMs = -1) {
    sembuf op;
    op.sem_num = 0;
    op.sem_flg = SEM_UNDO;
    op.sem_op = -1;

    if (nTimeOutMs < 0) {
        return (semop(g_nSem, &op, 1) == -1) ? -1 : 0;
    } else {
        timespec end;
        end.tv_sec = nTimeOutMs / 1000;
        end.tv_nsec = (nTimeOutMs % 1000) * 1000000L;
        return (semtimedop(g_nSem, &op, 1, &end) == -1) ? -1 : 0;
    }
}

经多次测试发现，该程序在不同OS上表现也不一样，有的环境里，程序精确地等待1毫秒就超时返回了。这里将待定位的环境和正常环境表述为A和B。

问题分析

走读测试用例代码，观察到Wait函数使用了系统调用semtimedop，这个系统调用是在指定时间内对信号量进行操作，若无法在超时时间内进行操作，则超时返回。本测试用例设置超时时间为1ms，并且不操作信号量以触发超时。

单次测试超时返回耗时可能会有数据的浮动，修改测试用例，超时时间设置1ms，循环100次，也观察到了固定的差距。

semtimedop系统调用涉及进程调度的问题，分析是否在调度过程中出现了额外的资源开销。

使用strace查看系统调用的时间：

环境A

环境B

观察到环境A等待了约8ms才返回，环境B 约2ms就返回了。说明问题是在系统调用或更下层。

使用perf sched 查看进程间调度时间：

环境A

环境B

发现程序在调用semtimedop后到swapper执行调度唤醒程序的耗时与两个环境超时返回的耗时差距相近，程序在环境A等待了8ms才被调度唤醒。

为了验证这种调度时延差异是不是普遍存在，使用sleep代替semtimedop，观察调度的情况：

环境A

环境B

两个环境在执行usleep(1000)进行的调度时间接近，都在1ms左右。通过走读内核源码和查阅资料发现，usleep使用的是hrtimer高精度计时器，semtimedop依赖的是jiffies时钟滴答。两个环境的差异可能是jiffies的差异，jiffies的精度由CONFIG_HZ决定。

CONFIG_HZ 是内核中的一个配置选项，它定义了系统时钟中断的频率，即每秒产生的时钟中断次数。例如，若 CONFIG_HZ 设置为 1000，那么系统每秒会产生 1000 次时钟中断。它决定了系统定时器的粒度，对系统的时间管理、任务调度等方面都有重要影响。更高的 CONFIG_HZ 值意味着更精细的时间管理和更频繁的调度机会，但也会带来更多的时钟中断开销。

查看两个环境配置的HZ参数

cat /boot/config-`uname -r` | grep CONFIG_HZ=

环境A

环境B

发现两个环境的HZ设定值不一样。B环境是A环境的4倍，与之前测试的系统调用等待时间差距一致。

方案验证

修改环境A的内核配置，将CONFIG_HZ设为1000，并重编内核。使用新内核验证，观察到等待耗时缩短到1ms。