xentrace fixes for xen-unstable

PATCH New Olaf Hering 5 participants 19 messages Jul 15, 2011 – Jul 18, 2011

lore

Share & tools

lore

Olaf Hering

author

2011-07-15 15:38 UTC #0 lore raw

PATCH 1/1 xentrace fixes for xen-unstable

A few small changes and a new trace hypercall.

The hypercall patch is here for review, I'm open to suggestions for better naming for example.

I'm leaving the existing HVMOP_xentrace in place to not break the API, even if there are no users in the tree.

Olaf

 tools/libxc/xc_tbuf.c       |   46 ++++++++++++++++++++++++++++++++++++++++++++
 tools/libxc/xenctrl.h       |    2 +
 xen/arch/x86/hvm/hvm.c      |    3 --
 xen/arch/x86/irq.c          |   12 +++++++----
 xen/arch/x86/trace.c        |    3 ++
 xen/arch/x86/x86_32/entry.S |    2 +
 xen/arch/x86/x86_64/entry.S |    2 +
 xen/common/trace.c          |   21 +++++++++++++++++++-
 xen/include/public/trace.h  |   10 +++++++++
 xen/include/public/xen.h    |    1 
 xen/include/xen/hypercall.h |    5 ++++
 11 files changed, 100 insertions(+), 7 deletions(-)

Olaf Hering

author

2011-07-15 15:38 UTC #1 lore raw

PATCH 1/1 hvm: remove cast from trace_var call for HVMOP_xentrace

# HG changeset patch
# User Olaf Hering <[email protected]>
# Date 1310741122 -7200
# Node ID d0dcdddf5285eba0605a95dfda79b794803fa733 # Parent fbb448cf5cba5f441ad94f7783a0a1394fd638f9
hvm: remove cast from trace_var call for HVMOP_xentrace

trace_var() takes a void pointer, casting is not needed.

Signed-off-by Olaf Hering <[email protected]>

xen/arch/x86/hvm/hvm.c +1 -2

diff -r fbb448cf5cba -r d0dcdddf5285 xen/arch/x86/hvm/hvm.c
@@ -3926,8 +3926,7 @@ long do_hvm_op(unsigned long op, XEN_GUE
 
         /* Cycles will be taken at the vmexit and vmenter */
         trace_var(tr.event | TRC_GUEST, 0 /*!cycles*/,
-                  tr.extra_bytes,
-                  (unsigned char *)tr.extra);
+                  tr.extra_bytes, tr.extra);
         break;
     }

Olaf Hering

author

2011-07-15 15:38 UTC #3 lore raw

PATCH 1/1 xentrace: replace ASSERT with printk in __trace_var

In reply to Olaf Hering

# HG changeset patch
# User Olaf Hering <[email protected]>
# Date 1310741871 -7200
# Node ID e0ff4eea0432e0af3210e090a47414a0126e9904 # Parent d0dcdddf5285eba0605a95dfda79b794803fa733
xentrace: replace ASSERT with printk in __trace_var

If trace_var gets called with large extra_data, do not crash the hypervisor. Instead print a warning and truncate the buffer.

Signed-off-by Olaf Hering <[email protected]>

xen/common/trace.c +4 -1

diff -r d0dcdddf5285 -r e0ff4eea0432 xen/common/trace.c
@@ -683,7 +683,10 @@ void __trace_var(u32 event, bool_t cycle
     if ( (extra % sizeof(u32)) != 0 )
         extra_word++;
     
-    ASSERT(extra_word <= TRACE_EXTRA_MAX);
+    if ( unlikely(extra_word > TRACE_EXTRA_MAX) )
+        printk(XENLOG_WARNING "xentrace: event %x extra_data %u too large.\n",
+                event, extra);
+
     extra_word = min_t(int, extra_word, TRACE_EXTRA_MAX);
 
     /* Round size up to nearest word */

Olaf Hering

author

2011-07-15 15:38 UTC #10 lore raw

PATCH 1/1 xentrace: reduce size of extradata in trace_irq_mask()

In reply to Olaf Hering

# HG changeset patch
# User Olaf Hering <[email protected]>
# Date 1310743144 -7200
# Node ID 6e4aef7b5051e18f19f2367a4439bba8f495335c # Parent e0ff4eea0432e0af3210e090a47414a0126e9904
xentrace: reduce size of extradata in trace_irq_mask()

Reduce size of extra_data in to avoid possible crash in trace_var.

(XEN) Assertion 'extra_word <= TRACE_EXTRA_MAX' failed at trace.c:687 (XEN) Xen call trace:

(XEN)    [<ffff82c480128783>] __trace_var+0x4d/0x3b8
(XEN)    [<ffff82c480162172>] trace_irq_mask+0x49/0x4b
(XEN)    [<ffff82c4801631ae>] __assign_irq_vector+0x241/0x374
(XEN)    [<ffff82c48015d813>] set_desc_affinity+0x5d/0xd4
(XEN)    [<ffff82c480160708>] set_msi_affinity+0x44/0x1c1
(XEN)    [<ffff82c480162938>] move_masked_irq+0x9c/0xcd
(XEN)    [<ffff82c4801629a7>] move_native_irq+0x3e/0x53
(XEN)    [<ffff82c48015d969>] ack_msi_irq+0x2c/0x6e
(XEN)    [<ffff82c4801622e3>] do_IRQ+0x16f/0x66d

Signed-off-by Olaf Hering <[email protected]>

xen/arch/x86/irq.c +8 -4

diff -r e0ff4eea0432 -r 6e4aef7b5051 xen/arch/x86/irq.c
@@ -77,10 +77,14 @@ void unlock_vector_lock(void)
 static void trace_irq_mask(u32 event, int irq, int vector, cpumask_t *mask)
 {
     struct {
-        int irq, vec;
-        cpumask_t mask;
-    } d = { irq, vector, *mask };
-    trace_var(event, 1, sizeof(d), (unsigned char *)&d);
+        unsigned int irq:16, vec:16;
+        unsigned int mask[6];
+    } d;
+    d.irq = irq;
+    d.vec = vector;
+    memset(d.mask, 0, sizeof(d.mask));
+    memcpy(d.mask, mask, min(sizeof(d.mask), sizeof(cpumask_t)));
+    trace_var(event, 1, sizeof(d), &d);
 }
 
 static int __init __bind_irq_vector(int irq, int vector, cpumask_t cpu_mask)

Olaf Hering

author

2011-07-15 15:38 UTC #13 lore raw

PATCH 1/1 Add a trace hypercall to allow tracing from dom0 or domU

In reply to Olaf Hering

# HG changeset patch
# User Olaf Hering <[email protected]>
# Date 1310744207 -7200
# Node ID f72dcd1b8bbdc7487d58702058983a5aa812a74e # Parent 6e4aef7b5051e18f19f2367a4439bba8f495335c Add a trace hypercall to allow tracing from dom0 or domU.

Mixing tracedata from Xen and dom0/domU events will help with debugging some issues. Either the chain of events is nice to know, or there is no console output available.

Signed-off-by Olaf Hering <[email protected]>

tools/libxc/xc_tbuf.c +46 -0

diff -r 6e4aef7b5051 -r f72dcd1b8bbd tools/libxc/xc_tbuf.c
@@ -156,3 +156,49 @@ int xc_tbuf_set_evt_mask(xc_interface *x
     return do_sysctl(xch, &sysctl);
 }
 
+static void do_tbuf_trace(xc_interface *xch, xen_guest_xentrace_t *t_guest)
+{
+    DECLARE_HYPERCALL;
+    DECLARE_HYPERCALL_BOUNCE(t_guest, sizeof(*t_guest), XC_HYPERCALL_BUFFER_BOUNCE_IN);
+
+    if ( xc_hypercall_bounce_pre(xch, t_guest) )
+    {
+        PERROR("Could not bounce buffer for xentrace hypercall");
+        return;
+    }
+
+    hypercall.op     = __HYPERVISOR_xentrace_op;
+    hypercall.arg[0] = HYPERCALL_BUFFER_AS_ARG(t_guest);
+    if ( do_xen_hypercall(xch, &hypercall) < 0 )
+    {
+        if ( errno == EACCES )
+            DPRINTF("sysctl operation failed -- need to"
+                    " rebuild the user-space tool set?\n");
+    }
+    xc_hypercall_bounce_post(xch, t_guest);
+}
+
+void xc_tbuf_trace(xc_interface *xch, uint16_t event, void *extra, size_t extra_bytes)
+{
+    DECLARE_HYPERCALL_BUFFER(xen_guest_xentrace_t, t_guest);
+
+    t_guest = xc_hypercall_buffer_alloc(xch, t_guest, sizeof(xen_guest_xentrace_t));
+    if ( !t_guest )
+    {
+        PERROR("Could not allocate memory for xentrace hypercall");
+        return ;
+    }
+
+    t_guest->event = event;
+    if ( extra_bytes )
+    {
+        if ( extra_bytes > sizeof(t_guest->extra) )
+            extra_bytes = sizeof(t_guest->extra);
+        memcpy(t_guest->extra, extra, extra_bytes);
+    }
+    t_guest->extra_bytes = extra_bytes;
+
+    do_tbuf_trace(xch, t_guest);
+
+    xc_hypercall_buffer_free(xch, t_guest);
+}

tools/libxc/xenctrl.h +2 -0

diff -r 6e4aef7b5051 -r f72dcd1b8bbd tools/libxc/xenctrl.h
@@ -1269,6 +1269,8 @@ int xc_tbuf_set_cpu_mask(xc_interface *x
 
 int xc_tbuf_set_evt_mask(xc_interface *xch, uint32_t mask);
 
+void xc_tbuf_trace(xc_interface *xch, uint16_t event, void *extra, size_t extra_bytes);
+
 int xc_domctl(xc_interface *xch, struct xen_domctl *domctl);
 int xc_sysctl(xc_interface *xch, struct xen_sysctl *sysctl);

xen/arch/x86/trace.c +3 -0

diff -r 6e4aef7b5051 -r f72dcd1b8bbd xen/arch/x86/trace.c
@@ -15,6 +15,9 @@ asmlinkage void trace_hypercall(void)
 {
     struct cpu_user_regs *regs = guest_cpu_user_regs();
 
+    if ( regs->eax == __HYPERVISOR_xentrace_op )
+        return;
+
 #ifdef __x86_64__
     if ( is_pv_32on64_vcpu(current) )
     {

xen/arch/x86/x86_32/entry.S +2 -0

diff -r 6e4aef7b5051 -r f72dcd1b8bbd xen/arch/x86/x86_32/entry.S
@@ -699,6 +699,7 @@ ENTRY(hypercall_table)
         .long do_domctl
         .long do_kexec_op
         .long do_tmem_op
+        .long do_xentrace_op
         .rept __HYPERVISOR_arch_0-((.-hypercall_table)/4)
         .long do_ni_hypercall
         .endr

@@ -747,6 +748,7 @@ ENTRY(hypercall_args_table)
         .byte 1 /* do_domctl            */
         .byte 2 /* do_kexec_op          */
         .byte 1 /* do_tmem_op           */
+        .byte 0 /* do_xentrace_op       */
         .rept __HYPERVISOR_arch_0-(.-hypercall_args_table)
         .byte 0 /* do_ni_hypercall      */
         .endr

xen/arch/x86/x86_64/entry.S +2 -0

diff -r 6e4aef7b5051 -r f72dcd1b8bbd xen/arch/x86/x86_64/entry.S
@@ -694,6 +694,7 @@ ENTRY(hypercall_table)
         .quad do_domctl
         .quad do_kexec_op
         .quad do_tmem_op
+        .quad do_xentrace_op
         .rept __HYPERVISOR_arch_0-((.-hypercall_table)/8)
         .quad do_ni_hypercall
         .endr

@@ -742,6 +743,7 @@ ENTRY(hypercall_args_table)
         .byte 1 /* do_domctl            */
         .byte 2 /* do_kexec             */
         .byte 1 /* do_tmem_op           */
+        .byte 0 /* do_xentrace_op       */
         .rept __HYPERVISOR_arch_0-(.-hypercall_args_table)
         .byte 0 /* do_ni_hypercall      */
         .endr

xen/common/trace.c +16 -0

diff -r 6e4aef7b5051 -r f72dcd1b8bbd xen/common/trace.c
@@ -31,6 +31,7 @@
 #include <xen/percpu.h>
 #include <xen/pfn.h>
 #include <xen/cpu.h>
+#include <xen/guest_access.h>
 #include <asm/atomic.h>
 #include <public/sysctl.h>

@@ -806,6 +807,21 @@ unlock:
         tasklet_schedule(&trace_notify_dom0_tasklet);
 }
 
+void do_xentrace_op(XEN_GUEST_HANDLE(xen_guest_xentrace_t) u_xentrace)
+{
+    xen_guest_xentrace_t tr;
+
+    if ( copy_from_guest(&tr, u_xentrace, 1 ) )
+        return;
+    if ( tr.event & ~((1u<<TRC_SUBCLS_SHIFT)-1) )
+        return;
+
+    if ( tr.extra_bytes > sizeof(tr.extra) )
+        tr.extra_bytes = sizeof(tr.extra);
+
+    __trace_var(tr.event | TRC_GUEST, 1, tr.extra_bytes, tr.extra);
+}
+
 /*
  * Local variables:
  * mode: C

xen/include/public/trace.h +10 -0

diff -r 6e4aef7b5051 -r f72dcd1b8bbd xen/include/public/trace.h
@@ -26,6 +26,8 @@
 #ifndef __XEN_PUBLIC_TRACE_H__
 #define __XEN_PUBLIC_TRACE_H__
 
+#include "xen.h"
+
 #define TRACE_EXTRA_MAX    7
 #define TRACE_EXTRA_SHIFT 28

@@ -65,6 +67,7 @@
 #define TRC_LOST_RECORDS        (TRC_GEN + 1)
 #define TRC_TRACE_WRAP_BUFFER  (TRC_GEN + 2)
 #define TRC_TRACE_CPU_CHANGE    (TRC_GEN + 3)
+#define TRC_TRACE_GUEST_HYPERCALL (TRC_GEN + 4)
 
 #define TRC_SCHED_RUNSTATE_CHANGE   (TRC_SCHED_MIN + 1)
 #define TRC_SCHED_CONTINUE_RUNNING  (TRC_SCHED_MIN + 2)

@@ -200,6 +203,13 @@ struct t_rec {
     } u;
 };
 
+struct xen_guest_xentrace {
+    uint16_t event, extra_bytes;
+    uint8_t extra[TRACE_EXTRA_MAX * sizeof(uint32_t)];
+};
+typedef struct xen_guest_xentrace xen_guest_xentrace_t;
+DEFINE_XEN_GUEST_HANDLE(xen_guest_xentrace_t);
+
 /*
  * This structure contains the metadata for a single trace buffer.  The head
  * field, indexes into an array of struct t_rec's.

xen/include/public/xen.h +1 -0

diff -r 6e4aef7b5051 -r f72dcd1b8bbd xen/include/public/xen.h
@@ -94,6 +94,7 @@ DEFINE_XEN_GUEST_HANDLE(xen_pfn_t);
 #define __HYPERVISOR_kexec_op             37
 #define __HYPERVISOR_tmem_op              38
 #define __HYPERVISOR_xc_reserved_op       39 /* reserved for XenClient */
+#define __HYPERVISOR_xentrace_op          40
 
 /* Architecture-specific hypercall definitions. */
 #define __HYPERVISOR_arch_0               48

xen/include/xen/hypercall.h +5 -0

diff -r 6e4aef7b5051 -r f72dcd1b8bbd xen/include/xen/hypercall.h
@@ -14,6 +14,7 @@
 #include <public/platform.h>
 #include <public/event_channel.h>
 #include <public/tmem.h>
+#include <public/trace.h>
 #include <asm/hypercall.h>
 #include <xsm/xsm.h>

@@ -43,6 +44,10 @@ extern long
 do_platform_op(
     XEN_GUEST_HANDLE(xen_platform_op_t) u_xenpf_op);
 
+extern void
+do_xentrace_op(
+    XEN_GUEST_HANDLE(xen_guest_xentrace_t) u_xentrace);
+
 /*
  * To allow safe resume of do_memory_op() after preemption, we need to know
  * at what point in the page list to resume. For this purpose I steal the

George Dunlap

Acked-by on v1 1/1

2011-07-15 15:48 UTC #2 lore raw

Re: [PATCH 1 of 4] hvm: remove cast from trace_var call for HVMOP_xentrace

In reply to Olaf Hering

Acked-by George Dunlap <[email protected]>

Quoted 24 lines · Olaf Hering

# HG changeset patch
# User Olaf Hering <[email protected]>
# Date 1310741122 -7200
# Node ID d0dcdddf5285eba0605a95dfda79b794803fa733 # Parent fbb448cf5cba5f441ad94f7783a0a1394fd638f9
hvm: remove cast from trace_var call for HVMOP_xentrace
trace_var() takes a void pointer, casting is not needed.
Signed-off-by Olaf Hering <[email protected]>
diff -r fbb448cf5cba -r d0dcdddf5285 xen/arch/x86/hvm/hvm.c
xen/arch/x86/hvm/hvm.c +1 -2
@@ -3926,8 +3926,7 @@ long do_hvm_op(unsigned long op, XEN_GUE
 
         /* Cycles will be taken at the vmexit and vmenter */
         trace_var(tr.event | TRC_GUEST, 0 /*!cycles*/,
-                  tr.extra_bytes,
-                  (unsigned char *)tr.extra);
+                  tr.extra_bytes, tr.extra);
         break;
     }
 

George Dunlap

Acked-by on v1 1/1

2011-07-15 16:28 UTC #11 lore raw

Re: [PATCH 3 of 4] xentrace: reduce size of extradata in trace_irq_mask()

In reply to Olaf Hering

Acked-by George Dunlap <[email protected]>

Quoted 45 lines · Olaf Hering

Reduce size of extra_data in to avoid possible crash in trace_var.

(XEN) Assertion 'extra_word <= TRACE_EXTRA_MAX' failed at trace.c:687 (XEN) Xen call trace:

(XEN)    [<ffff82c480128783>] __trace_var+0x4d/0x3b8
(XEN)    [<ffff82c480162172>] trace_irq_mask+0x49/0x4b
(XEN)    [<ffff82c4801631ae>] __assign_irq_vector+0x241/0x374
(XEN)    [<ffff82c48015d813>] set_desc_affinity+0x5d/0xd4
(XEN)    [<ffff82c480160708>] set_msi_affinity+0x44/0x1c1
(XEN)    [<ffff82c480162938>] move_masked_irq+0x9c/0xcd
(XEN)    [<ffff82c4801629a7>] move_native_irq+0x3e/0x53
(XEN)    [<ffff82c48015d969>] ack_msi_irq+0x2c/0x6e
(XEN)    [<ffff82c4801622e3>] do_IRQ+0x16f/0x66d

Signed-off-by Olaf Hering <[email protected]>

diff -r e0ff4eea0432 -r 6e4aef7b5051 xen/arch/x86/irq.c

xen/arch/x86/irq.c +8 -4

@@ -77,10 +77,14 @@ void unlock_vector_lock(void)
 static void trace_irq_mask(u32 event, int irq, int vector, cpumask_t *mask)
 {
     struct {
-        int irq, vec;
-        cpumask_t mask;
-    } d = { irq, vector, *mask };
-    trace_var(event, 1, sizeof(d), (unsigned char *)&d);
+        unsigned int irq:16, vec:16;
+        unsigned int mask[6];
+    } d;
+    d.irq = irq;
+    d.vec = vector;
+    memset(d.mask, 0, sizeof(d.mask));
+    memcpy(d.mask, mask, min(sizeof(d.mask), sizeof(cpumask_t)));
+    trace_var(event, 1, sizeof(d), &d);
 }
 
 static int __init __bind_irq_vector(int irq, int vector, cpumask_t cpu_mask)

George Dunlap

2011-07-15 16:31 UTC #4 lore raw

Re: [PATCH 2 of 4] xentrace: replace ASSERT with printk in __trace_var

In reply to Olaf Hering

This seems likely to spam the console if there is a trace which violates this; and this may happen in production environments if the loglevel is increased. I think putting in something to warn just once would be a better idea.

-George

Quoted 27 lines · Olaf Hering

# HG changeset patch
# User Olaf Hering <[email protected]>
# Date 1310741871 -7200
# Node ID e0ff4eea0432e0af3210e090a47414a0126e9904 # Parent d0dcdddf5285eba0605a95dfda79b794803fa733
xentrace: replace ASSERT with printk in __trace_var
If trace_var gets called with large extra_data, do not crash the hypervisor. Instead print a warning and truncate the buffer.
Signed-off-by Olaf Hering <[email protected]>
diff -r d0dcdddf5285 -r e0ff4eea0432 xen/common/trace.c
xen/common/trace.c +4 -1
@@ -683,7 +683,10 @@ void __trace_var(u32 event, bool_t cycle
     if ( (extra % sizeof(u32)) != 0 )
         extra_word++;
 
-    ASSERT(extra_word <= TRACE_EXTRA_MAX);
+    if ( unlikely(extra_word > TRACE_EXTRA_MAX) )
+        printk(XENLOG_WARNING "xentrace: event %x extra_data %u too large.\n",
+                event, extra);
+
     extra_word = min_t(int, extra_word, TRACE_EXTRA_MAX);
 
     /* Round size up to nearest word */

George Dunlap

2011-07-15 16:49 UTC #14 lore raw

Re: [PATCH 4 of 4] Add a trace hypercall to allow tracing from dom0 or domU

In reply to Olaf Hering

Quoted 13 lines · Olaf Hering

diff -r 6e4aef7b5051 -r f72dcd1b8bbd xen/include/public/trace.h

xen/include/public/trace.h +2 -0

@@ -26,6 +26,8 @@
 #ifndef __XEN_PUBLIC_TRACE_H__
 #define __XEN_PUBLIC_TRACE_H__
 
+#include "xen.h"
+
 #define TRACE_EXTRA_MAX    7
 #define TRACE_EXTRA_SHIFT 28

xen/include/public/trace.h line 70

Quoted 4 lines

xen/include/public/trace.h +1 -0

@@ -65,6 +67,7 @@
 #define TRC_LOST_RECORDS        (TRC_GEN + 1)
 #define TRC_TRACE_WRAP_BUFFER  (TRC_GEN + 2)
 #define TRC_TRACE_CPU_CHANGE    (TRC_GEN + 3)
+#define TRC_TRACE_GUEST_HYPERCALL (TRC_GEN + 4)

Looks like perhaps a leftover from an earlier patch? :-)

xen/include/public/xen.h DEFINE_XEN_GUEST_HANDLE(xen_pfn_t); · line 97

Quoted 8 lines

diff -r 6e4aef7b5051 -r f72dcd1b8bbd xen/include/public/xen.h

xen/include/public/xen.h +1 -0

@@ -94,6 +94,7 @@ DEFINE_XEN_GUEST_HANDLE(xen_pfn_t);
 #define __HYPERVISOR_kexec_op             37
 #define __HYPERVISOR_tmem_op              38
 #define __HYPERVISOR_xc_reserved_op       39 /* reserved for XenClient */
+#define __HYPERVISOR_xentrace_op          40

Seems unnecessary to make a whole hypercall just for this one thing, but I'll defer to Keir's judgement on that. At very least, it should accept an "op" command, of which "trace" is just one, so that it's expandable in the future without breaking backwards compatibility.

Other than that, looks good -- thanks for doing this.

-George

Olaf Hering

author

2011-07-15 20:45 UTC #15 lore raw

Re: [PATCH 4 of 4] Add a trace hypercall to allow tracing from dom0 or domU

Quoted 8 lines · George Dunlap

xen/include/public/trace.h line 70
Quoted 5 lines · Olaf Hering
xen/include/public/trace.h +1 -0
@@ -65,6 +67,7 @@
 #define TRC_LOST_RECORDS        (TRC_GEN + 1)
 #define TRC_TRACE_WRAP_BUFFER  (TRC_GEN + 2)
 #define TRC_TRACE_CPU_CHANGE    (TRC_GEN + 3)
+#define TRC_TRACE_GUEST_HYPERCALL (TRC_GEN + 4)
Looks like perhaps a leftover from an earlier patch? :-)

Yes, thats true. It was a domctrl a few weeks ago.

Quoted 5 lines

Quoted 5 lines
diff -r 6e4aef7b5051 -r f72dcd1b8bbd xen/include/public/xen.h
xen/include/public/xen.h +0 -0
@@ -94,6 +94,7 @@ DEFINE_XEN_GUEST_HANDLE(xen_pfn_t);
 #define __HYPERVISOR_kexec_op             37

Quoted 8 lines

xen/include/public/xen.h DEFINE_XEN_GUEST_HANDLE(xen_pfn_t); · line 97
Quoted 3 lines
xen/include/public/xen.h +1 -0
 #define __HYPERVISOR_tmem_op              38
 #define __HYPERVISOR_xc_reserved_op       39 /* reserved for XenClient */
+#define __HYPERVISOR_xentrace_op          40
Seems unnecessary to make a whole hypercall just for this one thing, but I'll defer to Keir's judgement on that. At very least, it should accept an "op" command, of which "trace" is just one, so that it's expandable in the future without breaking backwards compatibility.

One reason is that trace_hypercall() should not trace itself.

Olaf

Keir Fraser

2011-07-16 08:20 UTC #5 lore raw

Re: Re: [PATCH 2 of 4] xentrace: replace ASSERT with printk in __trace_var

In reply to George Dunlap

It's not like we have dodgy third-party drivers to worry about. Just fix the code -- *which is in the tree!* -- that is making the bad calls! It was correct to make this an assert/bug_on in the first place.

-- Keir

Quoted 43 lines · George Dunlap

This seems likely to spam the console if there is a trace which violates this; and this may happen in production environments if the loglevel is increased. I think putting in something to warn just once would be a better idea.
-George
Quoted 27 lines · Olaf Hering
# HG changeset patch
# User Olaf Hering <[email protected]>
# Date 1310741871 -7200
# Node ID e0ff4eea0432e0af3210e090a47414a0126e9904 # Parent d0dcdddf5285eba0605a95dfda79b794803fa733
xentrace: replace ASSERT with printk in __trace_var
If trace_var gets called with large extra_data, do not crash the hypervisor. Instead print a warning and truncate the buffer.
Signed-off-by Olaf Hering <[email protected]>
diff -r d0dcdddf5285 -r e0ff4eea0432 xen/common/trace.c
xen/common/trace.c +4 -1
@@ -683,7 +683,10 @@ void __trace_var(u32 event, bool_t cycle
     if ( (extra % sizeof(u32)) != 0 )
         extra_word++;
 
-    ASSERT(extra_word <= TRACE_EXTRA_MAX);
+    if ( unlikely(extra_word > TRACE_EXTRA_MAX) )
+        printk(XENLOG_WARNING "xentrace: event %x extra_data %u too
 large.\n",
+                event, extra);
+
     extra_word = min_t(int, extra_word, TRACE_EXTRA_MAX);
 
Quoted 1 line
     /* Round size up to nearest word */
_______________________________________________
Xen-devel mailing list
[email protected]
http://lists.xensource.com/xen-devel

Keir Fraser

2011-07-16 08:25 UTC #12 lore raw

Re: [PATCH 3 of 4] xentrace: reduce size of extradata in trace_irq_mask()

In reply to Olaf Hering

Quoted 8 lines · Olaf Hering

# HG changeset patch
# User Olaf Hering <[email protected]>
# Date 1310743144 -7200
# Node ID 6e4aef7b5051e18f19f2367a4439bba8f495335c # Parent e0ff4eea0432e0af3210e090a47414a0126e9904
xentrace: reduce size of extradata in trace_irq_mask()
Reduce size of extra_data in to avoid possible crash in trace_var.

Ah, so the assertion did its job. :-)

-- Keir

Quoted 41 lines

(XEN) Assertion 'extra_word <= TRACE_EXTRA_MAX' failed at trace.c:687 (XEN) Xen call trace:

(XEN)    [<ffff82c480128783>] __trace_var+0x4d/0x3b8
(XEN)    [<ffff82c480162172>] trace_irq_mask+0x49/0x4b
(XEN)    [<ffff82c4801631ae>] __assign_irq_vector+0x241/0x374
(XEN)    [<ffff82c48015d813>] set_desc_affinity+0x5d/0xd4
(XEN)    [<ffff82c480160708>] set_msi_affinity+0x44/0x1c1
(XEN)    [<ffff82c480162938>] move_masked_irq+0x9c/0xcd
(XEN)    [<ffff82c4801629a7>] move_native_irq+0x3e/0x53
(XEN)    [<ffff82c48015d969>] ack_msi_irq+0x2c/0x6e
(XEN)    [<ffff82c4801622e3>] do_IRQ+0x16f/0x66d

Signed-off-by Olaf Hering <[email protected]>

diff -r e0ff4eea0432 -r 6e4aef7b5051 xen/arch/x86/irq.c

xen/arch/x86/irq.c +8 -4

@@ -77,10 +77,14 @@ void unlock_vector_lock(void)
 static void trace_irq_mask(u32 event, int irq, int vector, cpumask_t *mask)
 {
     struct {
-        int irq, vec;
-        cpumask_t mask;
-    } d = { irq, vector, *mask };
-    trace_var(event, 1, sizeof(d), (unsigned char *)&d);
+        unsigned int irq:16, vec:16;
+        unsigned int mask[6];
+    } d;
+    d.irq = irq;
+    d.vec = vector;
+    memset(d.mask, 0, sizeof(d.mask));
+    memcpy(d.mask, mask, min(sizeof(d.mask), sizeof(cpumask_t)));
+    trace_var(event, 1, sizeof(d), &d);
 }
 
 static int __init __bind_irq_vector(int irq, int vector, cpumask_t cpu_mask)

_______________________________________________
Xen-devel mailing list
[email protected]
http://lists.xensource.com/xen-devel

Tim Deegan

2011-07-18 08:56 UTC #16 lore raw

Re: [PATCH 4 of 4] Add a trace hypercall to allow tracing from dom0 or domU

In reply to Olaf Hering

Hi,

Quoted 31 lines · Olaf Hering

diff -r 6e4aef7b5051 -r f72dcd1b8bbd xen/arch/x86/x86_32/entry.S

xen/arch/x86/x86_32/entry.S +2 -0

@@ -699,6 +699,7 @@ ENTRY(hypercall_table)
         .long do_domctl
         .long do_kexec_op
         .long do_tmem_op
+        .long do_xentrace_op
         .rept __HYPERVISOR_arch_0-((.-hypercall_table)/4)
         .long do_ni_hypercall
         .endr

@@ -747,6 +748,7 @@ ENTRY(hypercall_args_table)
         .byte 1 /* do_domctl            */
         .byte 2 /* do_kexec_op          */
         .byte 1 /* do_tmem_op           */
+        .byte 0 /* do_xentrace_op       */
         .rept __HYPERVISOR_arch_0-(.-hypercall_args_table)
         .byte 0 /* do_ni_hypercall      */
         .endr

diff -r 6e4aef7b5051 -r f72dcd1b8bbd xen/arch/x86/x86_64/entry.S

xen/arch/x86/x86_64/entry.S +1 -0

@@ -694,6 +694,7 @@ ENTRY(hypercall_table)
         .quad do_domctl
         .quad do_kexec_op
         .quad do_tmem_op
+        .quad do_xentrace_op
         .rept __HYPERVISOR_arch_0-((.-hypercall_table)/8)
         .quad do_ni_hypercall
         .endr

xen/arch/x86/x86_64/entry.S ENTRY(hypercall_args_table) · line 749

Quoted 7 lines

xen/arch/x86/x86_64/entry.S +1 -0

@@ -742,6 +743,7 @@ ENTRY(hypercall_args_table)
         .byte 1 /* do_domctl            */
         .byte 2 /* do_kexec             */
         .byte 1 /* do_tmem_op           */
+        .byte 0 /* do_xentrace_op       */
         .rept __HYPERVISOR_arch_0-(.-hypercall_args_table)
         .byte 0 /* do_ni_hypercall      */
         .endr

You need to do the same in x86/x86_64/compat/entry.S for 32-on-64 guests to be able to call it too.

Also, can you add some comments somewhere (say, public/trace.h) to say exactly what the new hypercall does and how to use it? A patch to docs/src/interface.tex would be great too, even if the rest of that doc is quite out of date.

George, is it worth trying to merge this into the existing HVMOP that does the same thing?

Cheers,

Tim.

Signature · 3 lines

Tim Deegan <[email protected]>
Principal Software Engineer, Xen Platform Team
Citrix Systems UK Ltd.  (Company #02937203, SL9 0BG)

Olaf Hering

author

2011-07-18 09:04 UTC #6 lore raw

Re: Re: [PATCH 2 of 4] xentrace: replace ASSERT with printk in __trace_var

In reply to Keir Fraser

Quoted 3 lines · Keir Fraser

It's not like we have dodgy third-party drivers to worry about. Just fix the code -- *which is in the tree!* -- that is making the bad calls! It was correct to make this an assert/bug_on in the first place.

trace_irq_mask() was the only function I found with a too large buffer.

Olaf

Keir Fraser

2011-07-18 09:37 UTC #7 lore raw

Re: Re: [PATCH 2 of 4] xentrace: replace ASSERT with printk in __trace_var

Quoted 7 lines · Olaf Hering

Quoted 3 lines · Keir Fraser
It's not like we have dodgy third-party drivers to worry about. Just fix the code -- *which is in the tree!* -- that is making the bad calls! It was correct to make this an assert/bug_on in the first place.
trace_irq_mask() was the only function I found with a too large buffer.

Yes, the fix was the very next email I looked at. I've applied it. Thanks!

-- Keir

Quoted 1 line

Olaf

George Dunlap

2011-07-18 10:41 UTC #8 lore raw

Re: Re: [PATCH 2 of 4] xentrace: replace ASSERT with printk in __trace_var

In reply to Keir Fraser

Quoted 3 lines · Keir Fraser

It's not like we have dodgy third-party drivers to worry about. Just fix the code -- *which is in the tree!* -- that is making the bad calls! It was correct to make this an assert/bug_on in the first place.

I think Olaf was objecting to a relatively minor fault like this causing a hypervisor crash (in debug builds only of course), and asked if it could be changed to a warning instead.

My personal preference would be to keep it an ASSERT, but I'm not really that fussed either way. The main thing is to make sure that only debug builds may have significant negative effects, and I think this patch doesn't satisfy that (as if you add loglvl=all on a production system, you may get stuck sending significant output to the console).

-George

Quoted 50 lines

-- Keir
Quoted 43 lines · George Dunlap
This seems likely to spam the console if there is a trace which violates this; and this may happen in production environments if the loglevel is increased. I think putting in something to warn just once would be a better idea.
-George
Quoted 27 lines · Olaf Hering
# HG changeset patch
# User Olaf Hering <[email protected]>
# Date 1310741871 -7200
# Node ID e0ff4eea0432e0af3210e090a47414a0126e9904 # Parent d0dcdddf5285eba0605a95dfda79b794803fa733
xentrace: replace ASSERT with printk in __trace_var
If trace_var gets called with large extra_data, do not crash the hypervisor. Instead print a warning and truncate the buffer.
Signed-off-by Olaf Hering <[email protected]>
diff -r d0dcdddf5285 -r e0ff4eea0432 xen/common/trace.c
xen/common/trace.c +4 -1
@@ -683,7 +683,10 @@ void __trace_var(u32 event, bool_t cycle
     if ( (extra % sizeof(u32)) != 0 )
         extra_word++;
 
-    ASSERT(extra_word <= TRACE_EXTRA_MAX);
+    if ( unlikely(extra_word > TRACE_EXTRA_MAX) )
+        printk(XENLOG_WARNING "xentrace: event %x extra_data %u too
 large.\n",
+                event, extra);
+
     extra_word = min_t(int, extra_word, TRACE_EXTRA_MAX);
 
Quoted 1 line
     /* Round size up to nearest word */
_______________________________________________
Xen-devel mailing list
[email protected]
http://lists.xensource.com/xen-devel

Keir Fraser

2011-07-18 11:12 UTC #9 lore raw

Re: Re: [PATCH 2 of 4] xentrace: replace ASSERT with printk in __trace_var

Quoted 9 lines · George Dunlap

Quoted 3 lines · Keir Fraser
It's not like we have dodgy third-party drivers to worry about. Just fix the code -- *which is in the tree!* -- that is making the bad calls! It was correct to make this an assert/bug_on in the first place.
I think Olaf was objecting to a relatively minor fault like this causing a hypervisor crash (in debug builds only of course), and asked if it could be changed to a warning instead.

Quoted 5 lines

My personal preference would be to keep it an ASSERT, but I'm not really that fussed either way. The main thing is to make sure that only debug builds may have significant negative effects, and I think this patch doesn't satisfy that (as if you add loglvl=all on a production system, you may get stuck sending significant output to the console).

It only has a negative effect if you have xentrace enabled. That's fine.

-- Keir

Quoted 55 lines

-George
Quoted 51 lines
-- Keir
Quoted 44 lines · George Dunlap
This seems likely to spam the console if there is a trace which violates this; and this may happen in production environments if the loglevel is increased. I think putting in something to warn just once would be a better idea.
-George
Quoted 28 lines · Olaf Hering
# HG changeset patch
# User Olaf Hering <[email protected]>
# Date 1310741871 -7200
# Node ID e0ff4eea0432e0af3210e090a47414a0126e9904 # Parent d0dcdddf5285eba0605a95dfda79b794803fa733
xentrace: replace ASSERT with printk in __trace_var
If trace_var gets called with large extra_data, do not crash the hypervisor.
Instead print a warning and truncate the buffer.
Signed-off-by Olaf Hering <[email protected]>
diff -r d0dcdddf5285 -r e0ff4eea0432 xen/common/trace.c
xen/common/trace.c +4 -1
@@ -683,7 +683,10 @@ void __trace_var(u32 event, bool_t cycle
     if ( (extra % sizeof(u32)) != 0 )
         extra_word++;
 
-    ASSERT(extra_word <= TRACE_EXTRA_MAX);
+    if ( unlikely(extra_word > TRACE_EXTRA_MAX) )
+        printk(XENLOG_WARNING "xentrace: event %x extra_data %u too
 large.\n",
+                event, extra);
+
     extra_word = min_t(int, extra_word, TRACE_EXTRA_MAX);
 
Quoted 1 line
     /* Round size up to nearest word */
_______________________________________________
Xen-devel mailing list
[email protected]
http://lists.xensource.com/xen-devel

George Dunlap

2011-07-18 11:17 UTC #17 lore raw

Re: [PATCH 4 of 4] Add a trace hypercall to allow tracing from dom0 or domU

In reply to Tim Deegan

Quoted 45 lines · Tim Deegan

Hi,

Quoted 31 lines · Olaf Hering

diff -r 6e4aef7b5051 -r f72dcd1b8bbd xen/arch/x86/x86_32/entry.S

xen/arch/x86/x86_32/entry.S +2 -0

@@ -699,6 +699,7 @@ ENTRY(hypercall_table)
         .long do_domctl
         .long do_kexec_op
         .long do_tmem_op
+        .long do_xentrace_op
         .rept __HYPERVISOR_arch_0-((.-hypercall_table)/4)
         .long do_ni_hypercall
         .endr

@@ -747,6 +748,7 @@ ENTRY(hypercall_args_table)
         .byte 1 /* do_domctl            */
         .byte 2 /* do_kexec_op          */
         .byte 1 /* do_tmem_op           */
+        .byte 0 /* do_xentrace_op       */
         .rept __HYPERVISOR_arch_0-(.-hypercall_args_table)
         .byte 0 /* do_ni_hypercall      */
         .endr

diff -r 6e4aef7b5051 -r f72dcd1b8bbd xen/arch/x86/x86_64/entry.S

xen/arch/x86/x86_64/entry.S +1 -0

@@ -694,6 +694,7 @@ ENTRY(hypercall_table)
         .quad do_domctl
         .quad do_kexec_op
         .quad do_tmem_op
+        .quad do_xentrace_op
         .rept __HYPERVISOR_arch_0-((.-hypercall_table)/8)
         .quad do_ni_hypercall
         .endr

xen/arch/x86/x86_64/entry.S ENTRY(hypercall_args_table) · line 749

Quoted 7 lines

xen/arch/x86/x86_64/entry.S +1 -0

@@ -742,6 +743,7 @@ ENTRY(hypercall_args_table)
         .byte 1 /* do_domctl            */
         .byte 2 /* do_kexec             */
         .byte 1 /* do_tmem_op           */
+        .byte 0 /* do_xentrace_op       */
         .rept __HYPERVISOR_arch_0-(.-hypercall_args_table)
         .byte 0 /* do_ni_hypercall      */
         .endr

You need to do the same in x86/x86_64/compat/entry.S for 32-on-64 guests to be able to call it too.

Quoted 7 lines

Also, can you add some comments somewhere (say, public/trace.h) to say exactly what the new hypercall does and how to use it? A patch to docs/src/interface.tex would be great too, even if the rest of that doc is quite out of date.
George, is it worth trying to merge this into the existing HVMOP that does the same thing?

I'm not sure what you mean by "merging this into the existing HVMOP". Do you mean just having dom0 (or whoever) call HVMOP_trace instead of making a separate hypercall?

-George

Tim Deegan

2011-07-18 12:22 UTC #18 lore raw

Re: [PATCH 4 of 4] Add a trace hypercall to allow tracing from dom0 or domU

Quoted 6 lines · George Dunlap

Quoted 2 lines
George, is it worth trying to merge this into the existing HVMOP that does the same thing?
I'm not sure what you mean by "merging this into the existing HVMOP". Do you mean just having dom0 (or whoever) call HVMOP_trace instead of making a separate hypercall?

No, I just meant sharing some code. The new hypercall adds struct xen_guest_xentrace, which is basically a dup of struct xen_hvm_xentrace, and do_xentrace_op() looks very like the code in do_hvm_op().

Tim.

Signature · 3 lines

Tim Deegan <[email protected]>
Principal Software Engineer, Xen Platform Team
Citrix Systems UK Ltd.  (Company #02937203, SL9 0BG)