Why does `native_write_msr` dominate my profiling result?

user_9565109 0
Viewed 404

I have a program that runs on a multi-thread framework with Linux kernel 4.18 and Intel CPU. I ran perf record -p pid -g -e cycles:u --call-graph lbr -F 99 -- sleep 20 to collect stack trace and generate flame graph.

enter image description here

My program was running under a low workload, so the time spent on futex_wait is expected. But the top of the stack is a kernel function native_write_msr. According to What does native_write_msr in kernel do? and https://elixir.bootlin.com/linux/v4.18/source/arch/x86/include/asm/msr.h#L103, this function is used for performance counters. I have disabled the tracepoint in native_write_msr.

And pidstat -p pid 1 told me that the system CPU usage is quite low.

05:44:34 PM   UID       PID    %usr %system  %guest    %CPU   CPU  Command
05:44:35 PM  1001     67441   60.00    4.00    0.00   64.00    11  my_profram
05:44:36 PM  1001     67441   58.00    7.00    0.00   65.00    11  my_profram
05:44:37 PM  1001     67441   61.00    3.00    0.00   64.00    11  my_profram

My questions are

  1. Why does native_write_msr appear so many times in the stack traces (as a result, it occupies a large space in the flame graph for about 80%). Is it a block operation, or it realeases the CPU when called?
  2. Why is the system CPU usage relatively low against the frame graph? According to the graph, 80% of the CPU time should belong to %system instead of %usr.

Any help is appreciated. If I miss any useful infomation, please comment.

Thank you very much!

perf x86 linux-kernel profiling
1 Answers

From the flamegraph, you could find that native_write_msr function is called by the function schedule. When a running process is removed from one core (because it's migrated to another core or stopped by the scheduler to run another process), the scheduler need to dump the process's perf data and clean its perf configurations, so we don't mess up perf data of different processes. The scheduler may need to write to msr in this step, thus calling native_write_msr. So native_write_msr are called for so many times because scheduling or core migrations happens too frequently.

user_106834960
Related