• I
    perf report: Add per system call overhead histogram · 3dfabc74
    Ingo Molnar 提交于
    Take advantage of call-graph percounter sampling/recording to
    display a non-trivial histogram: the true, collapsed/summarized
    cost measurement, on a per system call total overhead basis:
    
     aldebaran:~/linux/linux/tools/perf> ./perf record -g -a -f ~/hackbench 10
     aldebaran:~/linux/linux/tools/perf> ./perf report -s symbol --syscalls | head -10
     #
     # (3536 samples)
     #
     # Overhead  Symbol
     # ........  ......
     #
         40.75%  [k] sys_write
         40.21%  [k] sys_read
          4.44%  [k] do_nmi
     ...
    
    This is done by accounting each (reliable) call-chain that chains back
    to a given system call to that system call function.
    
    [ So in the above example we can see that hackbench spends about 40% of
      its total time somewhere in sys_write() and 40% somewhere in
      sys_read(), the rest of the time is spent in user-space. The time
      is not spent in sys_write() _itself_ but in one of its many child
      functions. ]
    
    Or, a recording of a (source files are already in the page-cache) kernel build:
    
     $ perf record -g -m 512 -f -- make -j32 kernel
     $ perf report -s s --syscalls | grep '\[k\]' | grep -v nmi
    
         4.14%  [k] do_page_fault
         1.20%  [k] sys_write
         1.10%  [k] sys_open
         0.63%  [k] sys_exit_group
         0.48%  [k] smp_apic_timer_interrupt
         0.37%  [k] sys_read
         0.37%  [k] sys_execve
         0.20%  [k] sys_mmap
         0.18%  [k] sys_close
         0.14%  [k] sys_munmap
         0.13%  [k] sys_poll
         0.09%  [k] sys_newstat
         0.07%  [k] sys_clone
         0.06%  [k] sys_newfstat
         0.05%  [k] sys_access
         0.05%  [k] schedule
    
    Shows the true total cost of each syscall variant that gets used
    during a kernel build. This profile reveals it that pagefaults are
    the costliest, followed by read()/write().
    
    An interesting detail: timer interrupts cost 0.5% - or 0.5 seconds
    per 100 seconds of kernel build-time. (this was done with HZ=1000)
    
    The summary is done in 'perf report', i.e. in the post-processing
    stage - so once we have a good call-graph recording, this type of
    non-trivial high-level analysis becomes possible.
    
    Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
    Cc: Mike Galbraith <efault@gmx.de>
    Cc: Paul Mackerras <paulus@samba.org>
    Cc: Arnaldo Carvalho de Melo <acme@redhat.com>
    Cc: Linus Torvalds <torvalds@linux-foundation.org>
    Cc: Frederic Weisbecker <fweisbec@gmail.com>
    Cc: Pekka Enberg <penberg@cs.helsinki.fi>
    LKML-Reference: <new-submission>
    Signed-off-by: NIngo Molnar <mingo@elte.hu>
    3dfabc74
builtin-report.c 27.0 KB