为什么cmp指令花费太多时间?

问题描述

我正在尝试使用libunwind(使用linux perf)进行概要分析,并使用perf top监视目标进程,得到以下组装时间成本屏幕:

trace_lookup source code

  0.19 │       mov    %rcx,0x18(%rsp)                                                                                                                                    ▒
       │     trace_lookup():                                                                                                                                             ▒
  1.54 │       mov    0x8(%r9),%rcx                                                                                                                                      ▒
       │     _ULx86_64_tdep_trace():                                                                                                                                     ▒
  0.52 │       and    $0x1,%edx                                                                                                                                          ◆
  0.57 │       mov    %r14d,0xc(%rsp)                                                                                                                                    ▒
  0.40 │       mov    0x78(%rsp),%r10                                                                                                                                    ▒
  1.24 │       sub    %rdx,%r15                                                                                                                                          ▒
       │     trace_lookup():                                                                                                                                             ▒
  0.35 │       shl    %cl,%r12d                                                                                                                                          ▒
       │     _ULx86_64_tdep_trace():                                                                                                                                     ▒
  2.18 │       mov    0x90(%rsp),%r8                                                                                                                                     ▒
       │     trace_lookup():                                                                                                                                             ▒
  0.46 │       imul   %r15,%r13                                                                                                                                          ▒
       │     _ULx86_64_tdep_trace():                                                                                                                                     ▒
  0.59 │       mov    %r15,0x88(%rsp)                                                                                                                                    ▒
       │     trace_lookup():                                                                                                                                             ▒
  0.50 │       lea    -0x1(%r12),%rdx                                                                                                                                    ▒
  1.22 │       shr    $0x2b,%r13                                                                                                                                         ▒
  0.37 │       and    %r13,%rdx                                                                                                                                          ▒
  0.57 │177:   mov    %rdx,%rbp                                                                                                                                          ▒
  0.43 │       shl    $0x4,%rbp                                                                                                                                          ▒
  1.33 │       add    %rdi,%rbp                                                                                                                                          ▒
  0.49 │       mov    0x0(%rbp),%rsi                                                                                                                                     ▒
 24.40 │       cmp    %rsi,%r15                                                                                                                                          ▒
       │     ↓ jne    420                                                                                                                                                ▒
       │     _ULx86_64_tdep_trace():                                                                                                                                     ▒
  2.10 │18e:   movzbl 0x8(%rbp),%edx                                                                                                                                     ▒
  3.68 │       test   $0x8,%dl                                                                                                                                           ▒
       │     ↓ jne    370                                                                                                                                                ▒
  1.27 │       mov    %edx,%eax                                                                                                                                          ▒
  0.06 │       shl    $0x5,%eax                                                                                                                                          ▒
  0.73 │       sar    $0x5,%al                                                                                                                                           ▒
  1.70 │       cmp    $0xfe,%al                                                                                                                                          ▒
       │     ↓ je     380                                                                                                                                                ▒
  0.01 │     ↓ jle    2f0                                                                                                                                                ▒
  0.01 │       cmp    $0xff,%al                                                                                                                                          ▒
       │     ↓ je     3a0                                                                                                                                                ▒
  0.02 │       cmp    $0x1,%al                                                                                                                                           ▒
       │     ↓ jne    298                                                                                                                                                ▒
  0.01 │       and    $0x10,%edx                                                                                                                                         ▒
       │       movl   $0x1,0x10(%rsp)                                                                                                                                    ▒
       │       movl   $0x1,0x1c8(%rbx)                                                                                                                                   ▒
  0.00 │     ↓ je     393                             

对应的源代码在这里trace_lookup source code,如果我没看错,与该热路径cmp指令对应的代码行数是296行,但是我不知道为什么这行这么慢,大部分时间都花钱吗?

解决方法

命令cmp %rsi,%r15被标记为具有巨大开销,因为它等待mov 0x0(%rbp),%rsi命令从缓存或内存中加载数据。该命令可能存在L1甚至L2高速缓存未命中。

对于代码片段

       │     trace_lookup():
  0.50 │       lea    -0x1(%r12),%rdx
  1.22 │       shr    $0x2b,%r13     
  0.37 │       and    %r13,%rdx      
  0.57 │177:   mov    %rdx,%rbp      
  0.43 │       shl    $0x4,%rbp      
  1.33 │       add    %rdi,%rbp      
  0.49 │       mov    0x0(%rbp),%rsi 
 24.40 │       cmp    %rsi,%r15      
       │     ↓ jne    420    

您将当前函数的24%的分析事件记录到cmp指令中。采样分析的默认事件为“周期”(CPU时钟周期的硬件事件)或“ cpu-clock”(线性时间的软件事件)。因此,据报告此cmp命令的指令地址中有大约24%的采样中断确实中断了此功能。概要分析和现代乱序CPU可能会出现系统性偏差,因为报告的成本不是针对运行缓慢的命令,而是针对未快速完成执行(退出)的命令。如果%rsi寄存器值不等于%r15寄存器值,则此cmp + jne命令对(融合的uop)将更改程序的指令流。在远古时代,这种命令应该只读取两个寄存器并比较它们的值,这是快速的,并且不应占用函数执行时间的1/4。但是,随着现代CPU寄存器不仅存储值的32位或64位,它们还具有一些在乱序引擎中使用的隐藏标志(或重命名技术)。在您的示例中,有mov 0x0(%rbp),%rsi确实更改了%rsi寄存器。该命令是通过地址*%rbp从内存中加载的。 CPU确实已开始将此加载加载到高速缓存/内存子系统,并将%rsi寄存器标记为“正在从内存加载加载”,继续执行指令。很有可能,下一条指令不需要该负载的结果(这会花费一些时间,例如Haswell:L1命中4个cpu周期,L2命中12个cpu,L3命中36-66,另外50个-100 ns用于高速缓存未命中和RAM读取)。但是,在您的情况下,下一条指令是从%rsi读取的cmp + jne,并且该指令只有在将内存中的数据写入%rsi时才能完成(CPU可能在cmp + jne执行过程中阻塞,或者需要重新启动许多指令)该命令)。因此,cmp的开销为24%,因为mov确实错过了最近的缓存。使用更高级的计数器,您可以估计它错过了哪个缓存,以及哪个缓存/内存层最常为请求提供服务。

这里对应的源代码是trace_lookup源代码,如果我没看错,与该热路径cmp指令对应的代码行数是296行,但是我不知道为什么这行如此慢并且花费最多的时间?

由于asm片段很短,因此很难在trace_lookup的源代码中找到相应的代码行,并且很难找到L1 / L2缓存中的值和原因。您应该尝试编写简短的可复制示例。

相关问答

错误1:Request method ‘DELETE‘ not supported 错误还原:...
错误1:启动docker镜像时报错:Error response from daemon:...
错误1:private field ‘xxx‘ is never assigned 按Alt...
报错如下,通过源不能下载,最后警告pip需升级版本 Requirem...