Re: [PATCH] [PATCH] kvm: powerpc: add exit timing statistics

[Christian Ehrhardt <ehrhardt@linux.vnet.ibm.com>]

This patch reports the square sum in addition to the classic sum/count 
(+min/max) to allow more details statistical post processing.
That way you can process average, % of whole duration and using the 
square sum also the standard deviation.

A simple way to get these numbers with awk is:

#!/bin/bash
echo "processing file ${1}"
sumsum=`awk 'BEGIN { csum=0; sumsum=0; count=0}{ csum=csum+$3; count++; 
sumsum = sumsum+$9;}END { printf("%s\n", sumsum)}' $1`
echo "sum of time ${sumsum}"
awk '!/count          0/ { printf("%s",$0); printf(" avg %16.4lf stddev 
%12.3lf %% %5.2f\n",$9/$3, sqrt($11/$3-(($9/$3)*($9/$3))), 
($9/('$sumsum'/100))); }' $1

This runs awk twice, because for % of overall time you need the sum the 
durations and I personally don't like all those "rewind hacks" for awk.

Ehrhardt Christian wrote:
> From: Christian Ehrhardt <ehrhardt@linux.vnet.ibm.com>
>
> Other existing kvm stats are either just counters (kvm_stat) reported for kvm
> generally or trace based aproaches like kvm_trace.
> For kvm on powerpc we had the need to track the timings of the different exit
> types. While this could be achieved parsing data created with a kvm_trace
> extension this adds too muhc overhead (at least on embedded powerpc) slowing
> down the workloads we wanted to measure.
>
> Therefore this patch adds a in kernel exit timing statistic to the powerpc kvm
> code. These statistic is available per vm&vcpu under the kvm debugfs directory.
> As this statistic is low, but still some overhead it can be enabled via a
> .config entry and should be off by default.
>
> Since this patch touched all powerpc kvm_stat code anyway this code is now
> merged and simpliefied together with the exit timing statistic code (still
> working with exit timing disabled in .config).
>
> Here is a sample output (after postprocessing with the awk script I'll post in reply to this patch) how the results look like.
> sum of time 27504898
>         MMIO: count        824 min         51 max        555 sum                75825 sum_quad              9232871 avg          92.0206 stddev       52.318 %  0.28
>          DCR: count        140 min         44 max         92 sum                 6746 sum_quad               327658 avg          48.1857 stddev        4.307 %  0.02
>       SIGNAL: count          2 min        309 max        993 sum                 1302 sum_quad              1081530 avg         651.0000 stddev      342.000 %  0.00
>     ITLBREAL: count        293 min         11 max         14 sum                 3515 sum_quad                42175 avg          11.9966 stddev        0.155 %  0.01
>     ITLBVIRT: count     113822 min         20 max        338 sum              2595412 sum_quad             60256824 avg          22.8024 stddev        3.074 %  9.44
>     DTLBREAL: count        242 min         11 max         14 sum                 2908 sum_quad                34974 avg          12.0165 stddev        0.352 %  0.01
>     DTLBVIRT: count      66687 min         21 max        329 sum              1530048 sum_quad             35434926 avg          22.9437 stddev        2.224 %  5.56
>      SYSCALL: count         72 min          9 max         10 sum                  649 sum_quad                 5851 avg           9.0139 stddev        0.117 %  0.00
>          ISI: count         56 min          9 max         10 sum                  506 sum_quad                 4574 avg           9.0357 stddev        0.186 %  0.00
>          DSI: count         49 min          9 max         10 sum                  448 sum_quad                 4102 avg           9.1429 stddev        0.350 %  0.00
>     EMULINST: count     211220 min          7 max       7700 sum              3292984 sum_quad           5797023806 avg          15.5903 stddev      164.931 % 11.97
>          DEC: count       6582 min         49 max        322 sum               367567 sum_quad             22996737 avg          55.8443 stddev       19.373 %  1.34
>       EXTINT: count          4 min         79 max        513 sum                  797 sum_quad               290423 avg         199.2500 stddev      181.398 %  0.00
>  TIMEINGUEST: count     399993 min          0 max       3952 sum             19626191 sum_quad          61148587807 avg          49.0663 stddev      387.900 % 71.36
>
> Signed-off-by: Christian Ehrhardt <ehrhardt@linux.vnet.ibm.com>
> ---
>
> [diffstat]
>  arch/powerpc/include/asm/kvm_host.h         |   49 ++++++++
>  arch/powerpc/include/asm/kvm_timing_stats.h |  142 ++++++++++++++++++++++++
>  arch/powerpc/include/asm/mmu-44x.h          |    1
>  arch/powerpc/kernel/asm-offsets.c           |   11 +
>  arch/powerpc/kvm/Kconfig                    |    9 +
>  arch/powerpc/kvm/booke.c                    |   35 +++---
>  arch/powerpc/kvm/booke.h                    |    7 +
>  arch/powerpc/kvm/booke_interrupts.S         |   24 ++++
>  arch/powerpc/kvm/powerpc.c                  |  163 +++++++++++++++++++++++++++-
>  9 files changed, 425 insertions(+), 16 deletions(-)
>
> [diff]
>   
[...]

-- 

Grüsse / regards, 
Christian Ehrhardt
IBM Linux Technology Center, Open Virtualization