linux/tools
Namhyung Kim bdd75729e5 perf sched timehist: Fix invalid period calculation
When --time option is given with a value outside recorded time, the last
sample time (tprev) was set to that value and run time calculation might
be incorrect.  This is a problem of the first samples for each cpus
since it would skip the runtime update when tprev is 0.  But with --time
option it had non-zero (which is invalid) value so the calculation is
also incorrect.

For example, let's see the followging:

  $ perf sched timehist
             time    cpu  task name                       wait time  sch delay   run time
                          [tid/pid]                          (msec)     (msec)     (msec)
  --------------- ------  ------------------------------  ---------  ---------  ---------
      3195.968367 [0003]  <idle>                              0.000      0.000      0.000
      3195.968386 [0002]  Timer[4306/4277]                    0.000      0.000      0.018
      3195.968397 [0002]  Web Content[4277]                   0.000      0.000      0.000
      3195.968595 [0001]  JS Helper[4302/4277]                0.000      0.000      0.000
      3195.969217 [0000]  <idle>                              0.000      0.000      0.621
      3195.969251 [0001]  kworker/1:1H[291]                   0.000      0.000      0.033

The sample starts at 3195.968367 but when I gave a time interval from
3194 to 3196 (in sec) it will calculate the whole 2 second as runtime.
In below, 2 cpus accounted it as runtime, other 2 cpus accounted it as
idle time.

Before:

  $ perf sched timehist --time 3194,3196 -s | tail
  Idle stats:
      CPU  0 idle for   1995.991  msec
      CPU  1 idle for     20.793  msec
      CPU  2 idle for     30.191  msec
      CPU  3 idle for   1999.852  msec

      Total number of unique tasks: 23
  Total number of context switches: 128
             Total run time (msec): 3724.940

After:

  $ perf sched timehist --time 3194,3196 -s | tail
  Idle stats:
      CPU  0 idle for     10.811  msec
      CPU  1 idle for     20.793  msec
      CPU  2 idle for     30.191  msec
      CPU  3 idle for     18.337  msec

      Total number of unique tasks: 23
  Total number of context switches: 128
             Total run time (msec): 18.139

Committer notes:

Further testing:

Before:

  Idle stats:
      CPU  0 idle for    229.785  msec
      CPU  1 idle for    937.944  msec
      CPU  2 idle for    188.931  msec
      CPU  3 idle for    986.185  msec

  After:

  # perf sched timehist --time 40602,40603 -s | tail

  Idle stats:
      CPU  0 idle for    229.785  msec
      CPU  1 idle for    175.407  msec
      CPU  2 idle for    188.931  msec
      CPU  3 idle for    223.657  msec

      Total number of unique tasks: 68
  Total number of context switches: 814
             Total run time (msec): 97.688

  # for cpu in `seq 0 3` ; do echo -n "CPU $cpu idle for " ; perf sched timehist --time 40602,40603 | grep "\[000${cpu}\].*\<idle\>" | tr -s ' ' | cut -d' ' -f7 | awk '{entries++ ; s+=$1} END {print s " msec (entries: " entries ")"}' ; done
  CPU 0 idle for 229.721 msec (entries: 123)
  CPU 1 idle for 175.381 msec (entries: 65)
  CPU 2 idle for 188.903 msec (entries: 56)
  CPU 3 idle for 223.61 msec (entries: 102)

Difference due to the idle stats being accounted at nanoseconds precision while
the <idle> entries in 'perf sched timehist' are trucated at msec.usec.

Signed-off-by: Namhyung Kim <namhyung@kernel.org>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Fixes: 853b740711 ("perf sched timehist: Add option to specify time window of interest")
Link: http://lkml.kernel.org/r/20161222060350.17655-2-namhyung@kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-12-22 16:35:46 -03:00
..
accounting tools: move accounting tool from Documentation 2016-09-23 13:07:15 -06:00
arch Merge branch 'core/urgent' into x86/fpu, to merge fixes 2016-11-01 07:47:40 +01:00
build perf build: Check LLVM version in feature check 2016-12-06 13:21:55 -03:00
cgroup
firewire
gpio tools/gpio: fix gpio-event-mon header comment 2016-08-08 09:50:22 +02:00
hv tools: hv: Enable network manager for bonding scripts on RHEL 2016-12-06 10:13:55 -05:00
iio Second set of iio new device support, features and cleanups for the 4.9 cycle. 2016-09-14 20:42:03 +02:00
include tools lib bpf: Sync {tools,}/include/uapi/linux/bpf.h 2016-12-15 16:25:46 -03:00
kvm/kvm_stat tools: kvm_stat: Add comments 2016-05-25 16:12:06 +02:00
laptop tools: move laptops dslm tool from Documentation 2016-09-23 13:07:21 -06:00
lguest tools/lguest: Don't bork the terminal in case of wrong args 2016-09-08 08:05:24 +02:00
lib tools lib bpf: Add bpf_prog_{attach,detach} 2016-12-20 12:00:39 -03:00
net tools: bpf_jit_disasm: check for klogctl failure 2016-05-08 23:32:59 -04:00
nfsd
objtool objtool: Fix bytes check of lea's rex_prefix 2016-12-06 09:20:59 +01:00
pcmcia tools: move pcmcia crc32hash tool from Documentation 2016-09-23 13:07:27 -06:00
perf perf sched timehist: Fix invalid period calculation 2016-12-22 16:35:46 -03:00
power tools/power/acpi: Remove direct kernel source include reference 2016-11-16 22:31:26 +01:00
scripts tools build: Fix objtool build with ARCH=x86_64 2016-07-22 16:37:44 -03:00
spi Merge remote-tracking branches 'spi/topic/ti-qspi', 'spi/topic/tools', 'spi/topic/txx9' and 'spi/topic/xlp' into spi-next 2016-09-30 09:14:22 -07:00
testing These are the documentation changes for 4.10. 2016-12-12 21:58:13 -08:00
thermal/tmon
time
usb usbip: adding names db to port operation 2016-05-03 14:32:07 -07:00
virtio ringtest: poll for new buffers once before updating event index 2016-10-31 00:21:43 +02:00
vm tools/vm/page_owner: increase temporary buffer size 2016-07-26 16:19:19 -07:00
Makefile tools/gpio: add install section 2016-06-23 11:07:13 +02:00