nmi 内核调用紧密循环答案

【问题标题】：nmi kernel calls in a tight loopnmi 内核调用紧密循环
【发布时间】：2019-06-13 10:20:27
【问题描述】：

我有一个测试程序

void task()
{
   long sum=0;
   while(true) {
      for(int i=0; i<100000;++i)
         for(int j=0; j < 10000; ++j)
            sum += j
   }
}
int main()
{
   boost::thread t(task);
   t.join();
   return true;
}

我使用 perf record -t -e intel_pt// 来分析线程。我看到很多对 nmi 的调用，例如每隔几毫秒调用 2(?) 次。有没有办法摆脱这种类型的中断？ Centos 7，内核 3.10.0，kernel.watchdog = 0。

根据@Zulan 的评论进行编辑：gcc 版本：4.8.5。编译行：g++ -I//include/ -L//lib -lboost_system -lboost_thread test.cpp 处理器 Intel Platinum 8xxx/Gold 6xxx 系列。
perf 脚本输出片段：

       a.out 25192 [009]  3976.829805:          1     branches:  ffffffff816ac7f5 nmi ([kernel.kallsyms]) => ffffffff816ad500 do_nmi ([kernel.kallsyms])
       a.out 25192 [009]  3976.829805:          1     branches:  ffffffff816ad54f do_nmi ([kernel.kallsyms]) => ffffffff816ad5f3 do_nmi ([kernel.kallsyms])
       a.out 25192 [009]  3976.829805:          1     branches:  ffffffff816ad5fa do_nmi ([kernel.kallsyms]) => ffffffff8103dc10 is_debug_stack ([kernel.kallsyms])
       a.out 25192 [009]  3976.829805:          1     branches:  ffffffff8103dc62 is_debug_stack ([kernel.kallsyms]) => ffffffff816ad5ff do_nmi ([kernel.kallsyms])
       a.out 25192 [009]  3976.829805:          1     branches:  ffffffff816ad60e do_nmi ([kernel.kallsyms]) => ffffffff816ad558 do_nmi ([kernel.kallsyms])
       a.out 25192 [009]  3976.829805:          1     branches:  ffffffff816ad573 do_nmi ([kernel.kallsyms]) => ffffffff8113a3f0 rcu_nmi_enter ([kernel.kallsyms])
       a.out 25192 [009]  3976.829805:          1     branches:  ffffffff8113a41e rcu_nmi_enter ([kernel.kallsyms]) => ffffffff810ba170 __smp_mb__before_atomic ([kernel.kallsyms])
       a.out 25192 [009]  3976.829805:          1     branches:  ffffffff810ba17a __smp_mb__before_atomic ([kernel.kallsyms]) => ffffffff8113a423 rcu_nmi_enter ([kernel.kallsyms])
       a.out 25192 [009]  3976.829805:          1     branches:  ffffffff8113a427 rcu_nmi_enter ([kernel.kallsyms]) => ffffffff810ba180 __smp_mb__after_atomic ([kernel.kallsyms])
       ...
       a.out 25192 [009]  3976.829807:          1     branches:  ffffffff8113a4aa rcu_nmi_exit ([kernel.kallsyms]) => ffffffff8113a48a rcu_nmi_exit ([kernel.kallsyms])
       a.out 25192 [009]  3976.829807:          1     branches:  ffffffff8113a48c rcu_nmi_exit ([kernel.kallsyms]) => ffffffff816ad592 do_nmi ([kernel.kallsyms])
       a.out 25192 [009]  3976.829807:          1     branches:  ffffffff816ad5ed do_nmi ([kernel.kallsyms]) => ffffffff816ad760 do_nmi ([kernel.kallsyms])
       a.out 25192 [009]  3976.829807:          1     branches:  ffffffff816ad76e do_nmi ([kernel.kallsyms]) => ffffffff816ac7fa nmi ([kernel.kallsyms])
       a.out 25192 [009]  3976.829807:          1     branches:  ffffffff816ac804 nmi ([kernel.kallsyms]) => ffffffff816ac23c restore_args ([kernel.kallsyms])
       a.out 25192 [009]  3976.829808:          1     branches:  ffffffff816ac26c irq_return ([kernel.kallsyms]) =>           40576f task (a.out)

另一个：

       a.out 25192 [009]  3976.829808:          1     branches:  ffffffff816b6718 irq_work_interrupt ([kernel.kallsyms]) => ffffffff8102f620 smp_irq_work_interrupt ([kernel.kallsyms])
       a.out 25192 [009]  3976.829808:          1     branches:  ffffffff8102f629 smp_irq_work_interrupt ([kernel.kallsyms]) => ffffffff81090d20 irq_enter ([kernel.kallsyms])
       a.out 25192 [009]  3976.829808:          1     branches:  ffffffff81090d29 irq_enter ([kernel.kallsyms]) => ffffffff8113a360 rcu_irq_enter ([kernel.kallsyms])
       a.out 25192 [009]  3976.829808:          1     branches:  ffffffff8113a3a0 rcu_irq_enter ([kernel.kallsyms]) => ffffffff8113a3b8 rcu_irq_enter ([kernel.kallsyms])
       a.out 25192 [009]  3976.829808:          1     branches:  ffffffff8113a3c0 rcu_irq_enter ([kernel.kallsyms]) => ffffffff81137e10 rcu_eqs_exit_common.isra.31 ([kernel.kallsyms])
       ...
       a.out 25192 [009]  3976.829809:          1     branches:  ffffffff8113a27d rcu_irq_exit ([kernel.kallsyms]) => ffffffff8113a260 rcu_irq_exit ([kernel.kallsyms])
       a.out 25192 [009]  3976.829809:          1     branches:  ffffffff8113a26e rcu_irq_exit ([kernel.kallsyms]) => ffffffff81090e4e irq_exit ([kernel.kallsyms])
       a.out 25192 [009]  3976.829809:          1     branches:  ffffffff81090e50 irq_exit ([kernel.kallsyms]) => ffffffff8102f653 smp_irq_work_interrupt ([kernel.kallsyms])
       a.out 25192 [009]  3976.829809:          1     branches:  ffffffff8102f654 smp_irq_work_interrupt ([kernel.kallsyms]) => ffffffff816b671d irq_work_interrupt ([kernel.kallsyms])
       a.out 25192 [009]  3976.829809:          1     branches:  ffffffff816b671d irq_work_interrupt ([kernel.kallsyms]) => ffffffff816ac1ed ret_from_intr ([kernel.kallsyms])
       a.out 25192 [009]  3976.829809:          1     branches:  ffffffff816ac234 retint_swapgs ([kernel.kallsyms]) => ffffffff816ac23c restore_args ([kernel.kallsyms])
       a.out 25192 [009]  3976.829809:          1     branches:  ffffffff816ac26c irq_return ([kernel.kallsyms]) =>           40576f task (a.out)

perf 脚本输出中 irq_return() 的 grep'g 显示每 20 毫秒 3 个 irq。

           a.out 25192 [009]  3976.809174:          1     branches:  ffffffff816ac26c irq_return ([kernel.kallsyms]) =>           405764 task (a.out)
       a.out 25192 [009]  3976.809178:          1     branches:  ffffffff816ac26c irq_return ([kernel.kallsyms]) =>           405764 task (a.out)
       a.out 25192 [009]  3976.829808:          1     branches:  ffffffff816ac26c irq_return ([kernel.kallsyms]) =>           40576f task (a.out)
       a.out 25192 [009]  3976.829809:          1     branches:  ffffffff816ac26c irq_return ([kernel.kallsyms]) =>           40576f task (a.out)
       a.out 25192 [009]  3976.850317:          1     branches:  ffffffff816ac26c irq_return ([kernel.kallsyms]) =>           405764 task (a.out)
       a.out 25192 [009]  3976.850393:          1     branches:  ffffffff816ac26c irq_return ([kernel.kallsyms]) =>           405764 task (a.out)
       a.out 25192 [009]  3976.850395:          1     branches:  ffffffff816ac26c irq_return ([kernel.kallsyms]) =>           405764 task (a.out)
       a.out 25192 [009]  3976.870945:          1     branches:  ffffffff816ac26c irq_return ([kernel.kallsyms]) =>           405764 task (a.out)
       a.out 25192 [009]  3976.870984:          1     branches:  ffffffff816ac26c irq_return ([kernel.kallsyms]) =>           40576f task (a.out)
       a.out 25192 [009]  3976.870985:          1     branches:  ffffffff816ac26c irq_return ([kernel.kallsyms]) =>           40576f task (a.out)
       a.out 25192 [009]  3976.891571:          1     branches:  ffffffff816ac26c irq_return ([kernel.kallsyms]) =>           40576f task (a.out)
       a.out 25192 [009]  3976.891609:          1     branches:  ffffffff816ac26c irq_return ([kernel.kallsyms]) =>           40576f task (a.out)
       a.out 25192 [009]  3976.891611:          1     branches:  ffffffff816ac26c irq_return ([kernel.kallsyms]) =>           40576f task (a.out)

在 grub 中，isolcpus、nohz_full、rcu_nocbs 设置在特定的 cpus 上，并且 nmi_watchdog=0。使用 taskset -c a.out 运行的测试程序。

【问题讨论】：

请提供 1) 编译器版本 2) 编译命令 3) 来自实际perf script 输出的 sn-p 4) 处理器规格 4) 与此代码的非线程版本的比较。
什么硬件/主板？您在运行类似软件的不同硬件上是否得到相同的结果（如果您有其他机器运行如此旧的内核）？
NMI 是perf使用的机制。不要使用perf 将是一个解决方案。
如何在 AWS 上使用 intel_pt 和访问 grub？
@BeeOnRope: see here

标签： linux-kernel redhat perf nmi

【解决方案1】：

首先，如果你想跟踪内核，你会在跟踪中得到很多内核函数调用，包括但不限于与NMI相关的调用。

如果您想像上面发布的那样跟踪您的用户空间程序，请使用

perf record -t -e intel_pt//u ...

最好参考文档https://elixir.bootlin.com/linux/latest/source/tools/perf/Documentation/intel-pt.txt

【讨论】：

不过，据报道，这些调用发生在 CPU 9 上，与我的程序相同的 cpu 并且一次占用几微秒。这不意味着时间花在了我的自旋循环之外的内核 NMI 调用上吗？如果是这样，如何摆脱 nmi 中断——我的目标是尽可能多地从自旋循环中消除中断。我尝试的第一件事是将 nohz_full 放在启动命令中。
@surfcode：你可以通过not在perf record下运行你的程序来摆脱它们。它们是内核如何收集 PMU 数据的一部分。即它们是使用intel_pt 所固有的测量开销的一部分。可能有一些选项可以使用更大的缓冲区，以减少它们发生的频率或其他......
好的——让我看看我是否理解正确。这些中断来自perf 记录。因此，如果我不在perf 记录 下运行程序，它们通常不存在。听起来如果我想在系统调整后检查时序/硬件/时钟/等中断，我最好使用 perf stat 或其他一些工具。对吗？