perf scripts python: Add new compaction-times script
authorTony Jones <tonyj@suse.com>
Mon, 17 Aug 2015 19:48:52 +0000 (12:48 -0700)
committerArnaldo Carvalho de Melo <acme@redhat.com>
Fri, 28 Aug 2015 17:53:40 +0000 (14:53 -0300)
commit84e5d89a777cca26cc513264752b439874702dd6
tree4ac2209d0622579f405925b20d2a38dc79b6dc6d
parent1d945012d1381f0232ea2d66e32b06182eedb476
perf scripts python: Add new compaction-times script

This patch creates a new script (compaction-times) to report time
spent in mm compaction. It is possible to report times in nanoseconds
(default) or microseconds (-u).

The option -p will break down results by process id, -pv will further
decompose by each compaction entry/exit.

For each compaction entry/exit what is reported is controlled by the
options:

  -t   report only timing
  -m   report migration stats
  -ms  report migration scanner stats
  -fs  report free scanner stats

The default is to report all.

Entries may be further filtered by pid, pid-range or comm (regex).

The script is useful when analysing workloads that compact memory. The
most common example will be THP allocations on systems with a lot of
uptime that has fragmented memory.

This is an example of using the script to analyse a thpscale from
mmtests which deliberately fragments memory and allocates THP in 4
separate threads

  # Recording step, one of the following;
  $ perf record -e 'compaction:mm_compaction_*' ./workload
  # or:
  $ perf script record compaction-times

  # Reporting: basic
  total: 2444505743ns migration: moved=357738 failed=39275
  free_scanner: scanned=2705578 isolated=387875
  migration_scanner: scanned=414426 isolated=397013

  # Reporting: Per task stall times
  $ perf script report compaction-times -- -t -p
  total: 2444505743ns
  6384[thpscale]: 740800017ns
  6385[thpscale]: 274119512ns
  6386[thpscale]: 832961337ns
  6383[thpscale]: 596624877ns

  # Reporting: Per-compaction attempts for task 6385
  $ perf script report compaction-times -- -m -pv 6385
  total: 274119512ns migration: moved=14893 failed=24285
  6385[thpscale]: 274119512ns migration: moved=14893 failed=24285
  6385[thpscale].1: 3033277ns migration: moved=511 failed=1
  6385[thpscale].2: 9592094ns migration: moved=1524 failed=12
  6385[thpscale].3: 2495587ns migration: moved=512 failed=0
  6385[thpscale].4: 2561766ns migration: moved=512 failed=0
  6385[thpscale].5: 2523521ns migration: moved=512 failed=0
  ..... output continues ...

Changes since v1:
- report stats for isolate_migratepages and isolate_freepages
  (Vlastimil Babka)
- refactor code to achieve above
- add help text
- output to stdout/stderr explicitly

Signed-off-by: Tony Jones <tonyj@suse.com>
Cc: Mel Gorman <mgorman@suse.com>
Cc: Vlastimil Babka <vbabka@suse.cz>
Link: http://lkml.kernel.org/r/1439840932-8933-1-git-send-email-tonyj@suse.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
tools/perf/scripts/python/bin/compaction-times-record [new file with mode: 0644]
tools/perf/scripts/python/bin/compaction-times-report [new file with mode: 0644]
tools/perf/scripts/python/compaction-times.py [new file with mode: 0644]