sleep(0) 也能引发的性能问题?

2023-04-20 19:07:33 浏览数 (2)

概要

以前我只是知道系统调用开销大,耗时长,但是这个代价有多大一直没量化。前段时间处理一个问题让我对这个有了比较“理性”的认识,也就是说现在可以拿出相对量化的指标。


优化案例

业务背景太长了不方便说。不过单单从技术上来看,这个就比较简单;就是代码中出现了 sleep(0) 使得性能与预期不一致。

也就是说期望的代码是

代码语言:javascript复制
int benchmark(int i) 
{
    return i;
}

但是实际的代码是

代码语言:javascript复制
int benchmark(int i) 
{
    sleep(0);
    return i;
}

一开始看到 sleep(0) 的时候只是感觉奇怪;主要是看到睡眠的时间是 0 以为就没有影响,后面发现这里是一个大坑


比较 sleep(0) 带来的性能差异

我们比较了“有 sleep(0)” 与 “注释掉 sleep(0)”的耗时情况(我这里说的耗时是指的上文的 benchmark 函数,技术之外的事不方便多说)。

代码中有 sleep(0) 时 benchmark 函数耗时平均值是 253073(ns) ,当注释掉 sleep(0) 的时候平均耗时是3246(ns) 。画成图表的话会直观一些,我们可以看到它们两个的耗时比较大致上是这样的。

以下是 bpftrace 的代码(用来追踪函数的执行耗时)

代码语言:javascript复制
#!/usr/bin/env bpftrace 

/*
追踪 /data/repos/cpp-20/build/cpps 程序 的 benchmark 函数的执行耗时
作者: 蒋乐兴
时间: 2022-09
*/

BEGIN 
{
    printf("**** start trace cpps.benchmark function time cost ****n");
}

uprobe:/data/repos/cpp-20/build/cpps:benchmark 
{
    print("enter function benchmark .");
    @start[comm] = nsecs;
}

uretprobe:/data/repos/cpp-20/build/cpps:benchmark  / @start[comm] /
{
    print("exit  function benchmark .");
    printf("time-cost %d (ns) nn", (nsecs - @start[comm]));
    delete(@start[comm]);
}

END 
{
    printf("**** end trace cpps.benchmark function time cost   ****n");
    clear(@start);
}

执行追踪程序

代码语言:javascript复制
bpftrace benckmark-trace.bt
Attaching 4 probes...
**** start trace cpps.benchmark function time cost ****
## 以下是没有 sleep(0) 时的耗时
enter function benchmark .
exit  function benchmark .
time-cost 3106 (ns) 

enter function benchmark .
exit  function benchmark .
time-cost 3437 (ns) 

enter function benchmark .
exit  function benchmark .
time-cost 3196 (ns)

# 以下是 sleep(0) 时的耗时导致,可以看到这个涨上去了。
enter function benchmark .
exit  function benchmark .
time-cost 234281 (ns) 

enter function benchmark .
exit  function benchmark .
time-cost 366080 (ns) 

enter function benchmark .
exit  function benchmark .
time-cost 158860 (ns)

分析

前面我们通过控制变量的方法,确认了问题是由 sleep(0) 引起的。怀疑编译器没有把 sleep(0) 优化掉。

这样的话问题就简单了,我们只要确认在执行 sleep(0) 的时候有没有发生系统调用就行,这个也有现成的工具 strace 就是专门用来看这个的。

代码语言:javascript复制
strace build/cpps

execve("build/cpps", ["build/cpps"], 0x7ffe8f3797d0 /* 30 vars */) = 0
brk(NULL)                               = 0xb8d000
arch_prctl(0x3001 /* ARCH_??? */, 0x7fff526919c0) = -1 EINVAL (Invalid argument)
....

clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=0}, 0x7fff52691980) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=0}, 0x7fff52691980) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=0}, 0x7fff52691980) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=0}, 0x7fff52691980) = 0
clock_nanosleep(CLOCK_REALTIME, 0, {tv_sec=0, tv_nsec=0}, 0x7fff52691980) = 0
exit_group(0)

这下好了!sleep(0) 并没有被优化掉,它还是去调用了 clock_nanosleep 这个系统调用 。


福利

可以用以下命令确认一下你的服务器上是不是有这种 sleep 的进程存在;不要真的被这种 sleep(2) 改成 sleep(1) 的优化“技巧”给忽悠了。

代码语言:javascript复制
bpftrace -e 'tracepoint:syscalls:sys_enter_nanosleep{printf("%s is sleeping.n", comm);}'

Attaching 1 probe...
YDService is sleeping.
YDService is sleeping.
YDService is sleeping.
sh is sleeping.
... ... ...

0 人点赞