Re: [PATCH 3/3] trace: trace hypercalls inside a multicall

[George Dunlap <george.dunlap@eu.citrix.com>]

On 31/05/12 12:06, David Vrabel wrote:
> From: David Vrabel<david.vrabel@citrix.com>
>
> Add a trace record for every hypercall inside a multicall.  These use
> a new event ID (with a different sub-class ) so they may be filtered
> out if only the calls into hypervisor are of interest.
>
> Signed-off-by: David Vrabel<david.vrabel@citrix.com>
[post 4.2]
Acked-by: George Dunlap <george.dunlap@eu.citrix.com>
> ---
>   tools/xentrace/formats         |    1 +
>   tools/xentrace/xentrace_format |    3 ++-
>   xen/arch/x86/trace.c           |    2 +-
>   xen/common/compat/multicall.c  |   12 ++++++++++++
>   xen/common/multicall.c         |   16 ++++++++++++++++
>   xen/common/trace.c             |    6 +++---
>   xen/include/public/trace.h     |    4 +++-
>   xen/include/xen/trace.h        |    3 ++-
>   8 files changed, 40 insertions(+), 7 deletions(-)
>
> diff --git a/tools/xentrace/formats b/tools/xentrace/formats
> index fa935c8..928e1d7 100644
> --- a/tools/xentrace/formats
> +++ b/tools/xentrace/formats
> @@ -105,6 +105,7 @@
>   0x0020100c  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  ptwr_emulation_pae  [ addr = 0x%(3)08x, eip = 0x%(4)08x, npte = 0x%(2)08x%(1)08x ]
>   0x0020110c  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  ptwr_emulation_pae  [ addr = 0x%(4)08x%(3)08x, rip = 0x%(6)08x%(5)08x, npte = 0x%(2)08x%(1)08x ]
>   0x0020100d  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  hypercall  [ op = 0x%(1)08x ]
> +0x0020200e  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)    hypercall  [ op = 0x%(1)08x ]
>
>   0x0040f001  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  shadow_not_shadow                 [ gl1e = 0x%(2)08x%(1)08x, va = 0x%(3)08x, flags = 0x%(4)08x ]
>   0x0040f101  CPU%(cpu)d  %(tsc)d (+%(reltsc)8d)  shadow_not_shadow                 [ gl1e = 0x%(2)08x%(1)08x, va = 0x%(4)08x%(3)08x, flags = 0x%(5)08x ]
> diff --git a/tools/xentrace/xentrace_format b/tools/xentrace/xentrace_format
> index 6dab034..554d4de 100644
> --- a/tools/xentrace/xentrace_format
> +++ b/tools/xentrace/xentrace_format
> @@ -112,6 +112,7 @@ last_tsc = [0]
>
>   TRC_TRACE_IRQ = 0x1f004
>   TRC_PV_HYPERCALL_V2 = 0x20100d
> +TRC_PV_HYPERCALL_SUBCALL = 0x20100e
>
>   NR_VECTORS = 256
>   irq_measure = [{'count':0, 'tot_cycles':0, 'max_cycles':0}] * NR_VECTORS
> @@ -199,7 +200,7 @@ while not interrupted:
>               d3 = irq_measure[d1]['tot_cycles']
>               d4 = irq_measure[d1]['max_cycles']
>
> -        if event == TRC_PV_HYPERCALL_V2:
> +        if event == TRC_PV_HYPERCALL_V2 or event == TRC_PV_HYPERCALL_SUBCALL:
>               # Mask off the argument present bits.
>               args[1]&= 0x000fffff
>
> diff --git a/xen/arch/x86/trace.c b/xen/arch/x86/trace.c
> index 30269e9..9cb39bc 100644
> --- a/xen/arch/x86/trace.c
> +++ b/xen/arch/x86/trace.c
> @@ -37,7 +37,7 @@ void trace_hypercall(void)
>           args[5] = regs->r9;
>       }
>
> -    __trace_hypercall(regs->eax, args);
> +    __trace_hypercall(TRC_PV_HYPERCALL_V2, regs->eax, args);
>   }
>
>   void __trace_pv_trap(int trapnr, unsigned long eip,
> diff --git a/xen/common/compat/multicall.c b/xen/common/compat/multicall.c
> index 0eb1212..e7e2a40 100644
> --- a/xen/common/compat/multicall.c
> +++ b/xen/common/compat/multicall.c
> @@ -5,6 +5,7 @@
>   #include<xen/config.h>
>   #include<xen/types.h>
>   #include<xen/multicall.h>
> +#include<xen/trace.h>
>
>   #define COMPAT
>   typedef int ret_t;
> @@ -25,6 +26,17 @@ DEFINE_XEN_GUEST_HANDLE(multicall_entry_compat_t);
>   #define do_multicall(l, n)   compat_multicall(_##l, n)
>   #define _XEN_GUEST_HANDLE(t) XEN_GUEST_HANDLE(t)
>
> +static void __trace_multicall_call(multicall_entry_t *call)
> +{
> +    unsigned long args[6];
> +    int i;
> +
> +    for ( i = 0; i<  ARRAY_SIZE(args); i++ )
> +        args[i] = call->args[i];
> +
> +    __trace_hypercall(TRC_PV_HYPERCALL_SUBCALL, call->op, args);
> +}
> +
>   #include "../multicall.c"
>
>   /*
> diff --git a/xen/common/multicall.c b/xen/common/multicall.c
> index 6c1a9d7..ca1839d 100644
> --- a/xen/common/multicall.c
> +++ b/xen/common/multicall.c
> @@ -11,14 +11,28 @@
>   #include<xen/multicall.h>
>   #include<xen/guest_access.h>
>   #include<xen/perfc.h>
> +#include<xen/trace.h>
>   #include<asm/current.h>
>   #include<asm/hardirq.h>
>
>   #ifndef COMPAT
>   typedef long ret_t;
>   #define xlat_multicall_entry(mcs)
> +
> +static void __trace_multicall_call(multicall_entry_t *call)
> +{
> +    __trace_hypercall(TRC_PV_HYPERCALL_SUBCALL, call->op, call->args);
> +}
>   #endif
>
> +static void trace_multicall_call(multicall_entry_t *call)
> +{
> +    if ( !tb_init_done )
> +        return;
> +
> +    __trace_multicall_call(call);
> +}
> +
>   ret_t
>   do_multicall(
>       XEN_GUEST_HANDLE(multicall_entry_t) call_list, unsigned int nr_calls)
> @@ -47,6 +61,8 @@ do_multicall(
>               break;
>           }
>
> +        trace_multicall_call(&mcs->call);
> +
>           do_multicall_call(&mcs->call);
>
>   #ifndef NDEBUG
> diff --git a/xen/common/trace.c b/xen/common/trace.c
> index 833f6b9..70054d3 100644
> --- a/xen/common/trace.c
> +++ b/xen/common/trace.c
> @@ -816,7 +816,8 @@ unlock:
>           tasklet_schedule(&trace_notify_dom0_tasklet);
>   }
>
> -void __trace_hypercall(unsigned long op, const unsigned long *args)
> +void __trace_hypercall(uint32_t event, unsigned long op,
> +                       const unsigned long *args)
>   {
>       struct {
>           uint32_t op;
> @@ -857,8 +858,7 @@ void __trace_hypercall(unsigned long op, const unsigned long *args)
>           break;
>       }
>
> -    __trace_var(TRC_PV_HYPERCALL_V2, 1,
> -                sizeof(uint32_t) * (1 + (a - d.args)),&d);
> +    __trace_var(event, 1, sizeof(uint32_t) * (1 + (a - d.args)),&d);
>   }
>
>   /*
> diff --git a/xen/include/public/trace.h b/xen/include/public/trace.h
> index ef43b23..3c93805 100644
> --- a/xen/include/public/trace.h
> +++ b/xen/include/public/trace.h
> @@ -94,7 +94,8 @@
>   #define TRC_MEM_POD_ZERO_RECLAIM    (TRC_MEM + 17)
>   #define TRC_MEM_POD_SUPERPAGE_SPLINTER (TRC_MEM + 18)
>
> -#define TRC_PV_ENTRY 0x00201000 /* Hypervisor entry points for PV guests. */
> +#define TRC_PV_ENTRY   0x00201000 /* Hypervisor entry points for PV guests. */
> +#define TRC_PV_SUBCALL 0x00202000 /* Sub-call in a multicall hypercall */
>
>   #define TRC_PV_HYPERCALL             (TRC_PV_ENTRY +  1)
>   #define TRC_PV_TRAP                  (TRC_PV_ENTRY +  3)
> @@ -108,6 +109,7 @@
>   #define TRC_PV_PTWR_EMULATION        (TRC_PV_ENTRY + 11)
>   #define TRC_PV_PTWR_EMULATION_PAE    (TRC_PV_ENTRY + 12)
>   #define TRC_PV_HYPERCALL_V2          (TRC_PV_ENTRY + 13)
> +#define TRC_PV_HYPERCALL_SUBCALL     (TRC_PV_SUBCALL + 14)
>
>   /*
>    * TRC_PV_HYPERCALL_V2 format
> diff --git a/xen/include/xen/trace.h b/xen/include/xen/trace.h
> index f601aeb..3b8a7b3 100644
> --- a/xen/include/xen/trace.h
> +++ b/xen/include/xen/trace.h
> @@ -44,7 +44,8 @@ static inline void trace_var(u32 event, int cycles, int extra,
>           __trace_var(event, cycles, extra, extra_data);
>   }
>
> -void __trace_hypercall(unsigned long call, const unsigned long *args);
> +void __trace_hypercall(uint32_t event, unsigned long op,
> +                       const unsigned long *args);
>
>   /* Convenience macros for calling the trace function. */
>   #define TRACE_0D(_e)                            \