0

I'm completely confused about the output of perf top

I'm running a C program called sac2, which burns an entire CPU. Specifically it iterates through a 100 billion byte array adding all the bytes as 8 bit ints.

It doesn't do anything interesting from a functional point of view, but enables me to collect and compare various hardware counters when I run it with different strides.

If I run top, it tells me that I'm using 100% of a CPU as in the following.

top - 00:27:48 up 8 days, 10:10,  4 users,  load average: 0.67, 0.49, 0.58
Tasks: 1881 total,   3 running, 1878 sleeping,   0 stopped,   0 zombie
%Cpu(s):  0.4 us,  0.4 sy,  0.0 ni, 99.2 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem : 15828906+total, 79267468+free, 51445376 used, 73877056+buff/cache
KiB Swap:  4194300 total,   207800 free,  3986500 used. 97584883+avail Mem

   PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
197713 root      20   0   93.2g  20.9g    508 R 100.0  1.4   0:25.91 sac2  
 61859 root      20   0 3875820 748664 102052 S   3.3  0.0  10:40.92 perf
258330 root      20   0  103340   9024   1524 S   2.2  0.0  80:17.05 pmdalinux
194985 root      20   0  163968   4204   1608 R   2.0  0.0   0:10.48 top
  7099 root      20   0   28504   4800    400 S   1.9  0.0 224:19.92 irqbalance
192315 pcp       20   0  125020  35180   2524 S   1.0  0.0   0:06.15 pmlogger
 71102 root      20   0  150408   6092   1584 S   0.7  0.0  25:47.99 dstat

However perf top tells me the overhead, which I assume is the CPU utilization, is only around 40%. If so, it should be 100% as well..

Samples: 68M of event 'cycles:ppp', 4000 Hz, Event count (approx.): 85009918166 lost: 0/0 drop: 0/0
Overhead  Shared Object                 Symbol
  39.63%  sac2                          [.] main
   9.18%  [kernel]                      [k] mem_cgroup_charge_common
   5.10%  [kernel]                      [k] clear_page_c_e
   3.43%  [kernel]                      [k] retint_userspace_restore_args
   3.00%  [kernel]                      [k] sysret_check

Furthermore, when sac2 finishes, perf top continues to show sac2 active for another 25 seconds, with the overhead decreasing steadily.

An additional problem is that almost all of the options described in the man page for perf-top are ignored.

For full disclosure, the system has 96 skylake cores with 192 threads and 1.5 TB of memory. I'm the only one on the machine when I ran the test. I'm running as root and the system is running Centos7, with a 3.10 Linux kernel.

One possibility is that perf top is very buggy on the 3.10 kernel. Another possibility is that I don't understand what overhead is, but even so the fact that most of the options don't work is very suspicious. Can anyone help?

5
  • can you add the precises perf top… command line you've run? Also, 100 billion bytes array implies you either have 100 GB of RAM, or your system is swapping memory to and from disk all the time (or sac2 does something you're not telling us!). May 29, 2022 at 12:31
  • 1
    @marcus I have 1.5 TB of RAM. There is no paging or swapping going on during my measurements. The program has 2 parts. The 1st part mallocs, and then populates the memory. The 2nd part, which is what I'm reporting on iteraterates through the array. The same behavior occurs if I use a much smaller array. There are no major page faults during either part -- only minor ones. My real concern is not with this program, but to learn how how to interpret perf top output when I run it on a real program whose performance I want to optimize. As for the command line I ran, it was just "perf top".
    – rkg1
    May 29, 2022 at 16:34
  • woah! That's what the + in KiB Mem : 15828906+total means. top, that's a very very bad method of truncating a number. May 29, 2022 at 16:53
  • could you tell me which version of top this is (top -h)? I'd like to file a bug report on this May 29, 2022 at 17:00
  • @marcus. "top -h" shows procps-ng version 3.3.10
    – rkg1
    May 29, 2022 at 18:12

1 Answer 1

0

Furthermore, when sac2 finishes, perf top continues to show sac2 active for another 25 seconds, with the overhead decreasing steadily.

That's a time average; "percentage of samples observed" of course changes with the amount of samples observed. So, this is fully expected!

Specifically it iterates through a 100 billion byte array adding all the bytes as 8 bit ints.

So, you got 100 GB of RAM? Otherwise, some of that RAM will have to be paged out. Your top output tells us you got more like 16 GB! Your top is misleading and you have 1.5 TB of RAM, so this fits well!

perf top can also count the times a page had to be fetched (i.e., was a cache miss), something that I guess happens a lot in your situation. Chances are this is not counted in that CPU timer!

Also note that perf top without -a will attach to a single CPU core, not sample all of them. Unless you pinned the sac2 process to the same core you're observing, it might be running elsewhere!

You must log in to answer this question.

Not the answer you're looking for? Browse other questions tagged .