[Qemu-devel] [PATCH v2 0/2] trace: fix trace_event_get_state() for SystemTap and LTTng UST

[Qemu-devel] [PATCH v2 0/2] trace: fix trace_event_get_state() for SystemTap and LTTng UST

[Stefan Hajnoczi]

v2:
 * Don't special-case QEMU dstate [Daniel Berrange]
 * Use _backends() postfix to clarify function purpose [Lluís]

Trace events that compute their arguments can affect performance.  The
following idom can be used to avoid computing arguments when the trace event is
disabled:

  if (trace_event_get_state(TRACE_MY_EVENT)) {
      char *str = g_strdup_printf("Expensive string ...", ...);
      trace_my_event(str);
      g_free(str);
  }

Unfortunately this breaks the trace event for SystemTap and LTTng UST since
those tracers manage their own enabled/disabled state.

These patches add per-backend dstate to trace_event_get_state() so that the
trace event fires as expected when enabled via SystemTap or LTTng UST.

Stefan Hajnoczi (2):
  trace: add TRACE_<event>_BACKEND_DSTATE()
  trace: add trace_event_get_state_backends()

 docs/devel/tracing.txt                |  2 +-
 trace/control.h                       | 18 +++++++++++++++++-
 hw/usb/hcd-ohci.c                     | 13 +++++--------
 net/colo-compare.c                    | 11 ++++++-----
 net/filter-rewriter.c                 |  4 ++--
 scripts/tracetool/__init__.py         |  1 +
 scripts/tracetool/backend/__init__.py |  3 +++
 scripts/tracetool/backend/dtrace.py   | 12 ++++++++++++
 scripts/tracetool/backend/ftrace.py   |  5 +++++
 scripts/tracetool/backend/log.py      |  5 +++++
 scripts/tracetool/backend/simple.py   |  5 +++++
 scripts/tracetool/backend/syslog.py   |  5 +++++
 scripts/tracetool/backend/ust.py      |  5 +++++
 scripts/tracetool/format/h.py         | 10 ++++++++++
 14 files changed, 82 insertions(+), 17 deletions(-)

-- 
2.13.3

[Qemu-devel] [PATCH v2 1/2] trace: add TRACE_<event>_BACKEND_DSTATE()

[Stefan Hajnoczi]

QEMU keeps track of trace event enabled/disabled state and provides
monitor commands to inspect and modify the "dstate".  SystemTap and
LTTng UST maintain independent enabled/disabled states for each trace
event, the other backends rely on QEMU dstate.

Introduce a new per-event macro that combines backend-specific dstate
like this:

  #define TRACE_MY_EVENT_BACKEND_DSTATE() ( \
      QEMU_MY_EVENT_ENABLED() || /* SystemTap */ \
      tracepoint_enabled(qemu, my_event) /* LTTng UST */ || \
      false)

This will be used to extend trace_event_get_state() in the next patch.

Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
---
v2:
 * Don't special-case QEMU dstate [Daniel Berrange]
---
 scripts/tracetool/__init__.py         |  1 +
 scripts/tracetool/backend/__init__.py |  3 +++
 scripts/tracetool/backend/dtrace.py   | 12 ++++++++++++
 scripts/tracetool/backend/ftrace.py   |  5 +++++
 scripts/tracetool/backend/log.py      |  5 +++++
 scripts/tracetool/backend/simple.py   |  5 +++++
 scripts/tracetool/backend/syslog.py   |  5 +++++
 scripts/tracetool/backend/ust.py      |  5 +++++
 scripts/tracetool/format/h.py         | 10 ++++++++++
 9 files changed, 51 insertions(+)

diff --git a/scripts/tracetool/__init__.py b/scripts/tracetool/__init__.py
index d4c204a472..0670ec17d5 100644
--- a/scripts/tracetool/__init__.py
+++ b/scripts/tracetool/__init__.py
@@ -271,6 +271,7 @@ class Event(object):
     QEMU_TRACE_NOCHECK       = "_nocheck__" + QEMU_TRACE
     QEMU_TRACE_TCG           = QEMU_TRACE + "_tcg"
     QEMU_DSTATE              = "_TRACE_%(NAME)s_DSTATE"
+    QEMU_BACKEND_DSTATE      = "TRACE_%(NAME)s_BACKEND_DSTATE"
     QEMU_EVENT               = "_TRACE_%(NAME)s_EVENT"
 
     def api(self, fmt=None):
diff --git a/scripts/tracetool/backend/__init__.py b/scripts/tracetool/backend/__init__.py
index f735a259c0..259c6a6531 100644
--- a/scripts/tracetool/backend/__init__.py
+++ b/scripts/tracetool/backend/__init__.py
@@ -119,5 +119,8 @@ class Wrapper:
     def generate(self, event, group):
         self._run_function("generate_%s", event, group)
 
+    def generate_backend_dstate(self, event, group):
+        self._run_function("generate_%s_backend_dstate", event, group)
+
     def generate_end(self, events, group):
         self._run_function("generate_%s_end", events, group)
diff --git a/scripts/tracetool/backend/dtrace.py b/scripts/tracetool/backend/dtrace.py
index c6812b70a2..17f902cc62 100644
--- a/scripts/tracetool/backend/dtrace.py
+++ b/scripts/tracetool/backend/dtrace.py
@@ -44,8 +44,20 @@ def generate_h_begin(events, group):
     out('#include "%s"' % header,
         '')
 
+    # SystemTap defines <provider>_<name>_ENABLED() but other DTrace
+    # implementations might not.
+    for e in events:
+        out('#ifndef QEMU_%(uppername)s_ENABLED',
+            '#define QEMU_%(uppername)s_ENABLED() false',
+            '#endif',
+            uppername=e.name.upper())
 
 def generate_h(event, group):
     out('    QEMU_%(uppername)s(%(argnames)s);',
         uppername=event.name.upper(),
         argnames=", ".join(event.args.names()))
+
+
+def generate_h_backend_dstate(event, group):
+    out('    QEMU_%(uppername)s_ENABLED() || \\',
+        uppername=event.name.upper())
diff --git a/scripts/tracetool/backend/ftrace.py b/scripts/tracetool/backend/ftrace.py
index dd0eda4441..92f71b28f9 100644
--- a/scripts/tracetool/backend/ftrace.py
+++ b/scripts/tracetool/backend/ftrace.py
@@ -45,3 +45,8 @@ def generate_h(event, group):
         event_id="TRACE_" + event.name.upper(),
         fmt=event.fmt.rstrip("\n"),
         argnames=argnames)
+
+
+def generate_h_backend_dstate(event, group):
+    out('    trace_event_get_state_dynamic_by_id(%(event_id)s) || \\',
+        event_id="TRACE_" + event.name.upper())
diff --git a/scripts/tracetool/backend/log.py b/scripts/tracetool/backend/log.py
index 54f0a69886..da86f6b882 100644
--- a/scripts/tracetool/backend/log.py
+++ b/scripts/tracetool/backend/log.py
@@ -48,3 +48,8 @@ def generate_h(event, group):
         name=event.name,
         fmt=event.fmt.rstrip("\n"),
         argnames=argnames)
+
+
+def generate_h_backend_dstate(event, group):
+    out('    trace_event_get_state_dynamic_by_id(%(event_id)s) || \\',
+        event_id="TRACE_" + event.name.upper())
diff --git a/scripts/tracetool/backend/simple.py b/scripts/tracetool/backend/simple.py
index f983670ee1..c2fd1c24c4 100644
--- a/scripts/tracetool/backend/simple.py
+++ b/scripts/tracetool/backend/simple.py
@@ -42,6 +42,11 @@ def generate_h(event, group):
         args=", ".join(event.args.names()))
 
 
+def generate_h_backend_dstate(event, group):
+    out('    trace_event_get_state_dynamic_by_id(%(event_id)s) || \\',
+        event_id="TRACE_" + event.name.upper())
+
+
 def generate_c_begin(events, group):
     out('#include "qemu/osdep.h"',
         '#include "trace/control.h"',
diff --git a/scripts/tracetool/backend/syslog.py b/scripts/tracetool/backend/syslog.py
index 1ce627f0fc..668fb73fee 100644
--- a/scripts/tracetool/backend/syslog.py
+++ b/scripts/tracetool/backend/syslog.py
@@ -42,3 +42,8 @@ def generate_h(event, group):
         name=event.name,
         fmt=event.fmt.rstrip("\n"),
         argnames=argnames)
+
+
+def generate_h_backend_dstate(event, group):
+    out('    trace_event_get_state_dynamic_by_id(%(event_id)s) || \\',
+        event_id="TRACE_" + event.name.upper())
diff --git a/scripts/tracetool/backend/ust.py b/scripts/tracetool/backend/ust.py
index 2adaf548d5..412592b8e0 100644
--- a/scripts/tracetool/backend/ust.py
+++ b/scripts/tracetool/backend/ust.py
@@ -38,3 +38,8 @@ def generate_h(event, group):
     out('    tracepoint(qemu, %(name)s%(tp_args)s);',
         name=event.name,
         tp_args=argnames)
+
+
+def generate_h_backend_dstate(event, group):
+    out('    tracepoint_enabled(qemu, %(name)s) || \\',
+        name=event.name)
diff --git a/scripts/tracetool/format/h.py b/scripts/tracetool/format/h.py
index aecf249d66..e06f0f27c5 100644
--- a/scripts/tracetool/format/h.py
+++ b/scripts/tracetool/format/h.py
@@ -49,6 +49,16 @@ def generate(events, backend, group):
     backend.generate_begin(events, group)
 
     for e in events:
+        # tracer-specific dstate
+        out('',
+            '#define %(api)s() ( \\',
+            api=e.api(e.QEMU_BACKEND_DSTATE))
+
+        if "disable" not in e.properties:
+            backend.generate_backend_dstate(e, group)
+
+        out('    false)')
+
         # tracer without checks
         out('',
             'static inline void %(api)s(%(args)s)',
-- 
2.13.3

Re: [Qemu-devel] [PATCH v2 1/2] trace: add TRACE_<event>_BACKEND_DSTATE()

[Daniel P. Berrange]

On Mon, Jul 31, 2017 at 03:07:17PM +0100, Stefan Hajnoczi wrote:
> QEMU keeps track of trace event enabled/disabled state and provides
> monitor commands to inspect and modify the "dstate".  SystemTap and
> LTTng UST maintain independent enabled/disabled states for each trace
> event, the other backends rely on QEMU dstate.
> 
> Introduce a new per-event macro that combines backend-specific dstate
> like this:
> 
>   #define TRACE_MY_EVENT_BACKEND_DSTATE() ( \
>       QEMU_MY_EVENT_ENABLED() || /* SystemTap */ \
>       tracepoint_enabled(qemu, my_event) /* LTTng UST */ || \
>       false)
> 
> This will be used to extend trace_event_get_state() in the next patch.
> 
> Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>


> diff --git a/scripts/tracetool/backend/dtrace.py b/scripts/tracetool/backend/dtrace.py
> index c6812b70a2..17f902cc62 100644
> --- a/scripts/tracetool/backend/dtrace.py
> +++ b/scripts/tracetool/backend/dtrace.py
> @@ -44,8 +44,20 @@ def generate_h_begin(events, group):
>      out('#include "%s"' % header,
>          '')
>  
> +    # SystemTap defines <provider>_<name>_ENABLED() but other DTrace
> +    # implementations might not.
> +    for e in events:
> +        out('#ifndef QEMU_%(uppername)s_ENABLED',
> +            '#define QEMU_%(uppername)s_ENABLED() false',
> +            '#endif',
> +            uppername=e.name.upper())


IIUC, this means that on other DTrace impls, any trace points guarded by
QEMU_*_ENABLED() will never run, even if DTrace probes are set. Having
some trace points silently never run makes it pretty useless IMHO.

IOW, you need the opposite, #define it to true. The probe will still
only be executed if DTrace has enabled it, but you'll have to take the
hit of evaluating the probe arguments regardless. Not as optimized
performance-wise, but functionally correct at least.

>  
>  def generate_h(event, group):
>      out('    QEMU_%(uppername)s(%(argnames)s);',
>          uppername=event.name.upper(),
>          argnames=", ".join(event.args.names()))
> +
> +
> +def generate_h_backend_dstate(event, group):
> +    out('    QEMU_%(uppername)s_ENABLED() || \\',
> +        uppername=event.name.upper())

Regards,
Daniel
-- 
|: https://berrange.com      -o-    https://www.flickr.com/photos/dberrange :|
|: https://libvirt.org         -o-            https://fstop138.berrange.com :|
|: https://entangle-photo.org    -o-    https://www.instagram.com/dberrange :|

Re: [Qemu-devel] [PATCH v2 1/2] trace: add TRACE_<event>_BACKEND_DSTATE()

[Stefan Hajnoczi]

[-- Attachment #1: Type: text/plain, Size: 1387 bytes --]

On Mon, Jul 31, 2017 at 04:16:39PM +0100, Daniel P. Berrange wrote:
> On Mon, Jul 31, 2017 at 03:07:17PM +0100, Stefan Hajnoczi wrote:
> > diff --git a/scripts/tracetool/backend/dtrace.py b/scripts/tracetool/backend/dtrace.py
> > index c6812b70a2..17f902cc62 100644
> > --- a/scripts/tracetool/backend/dtrace.py
> > +++ b/scripts/tracetool/backend/dtrace.py
> > @@ -44,8 +44,20 @@ def generate_h_begin(events, group):
> >      out('#include "%s"' % header,
> >          '')
> >  
> > +    # SystemTap defines <provider>_<name>_ENABLED() but other DTrace
> > +    # implementations might not.
> > +    for e in events:
> > +        out('#ifndef QEMU_%(uppername)s_ENABLED',
> > +            '#define QEMU_%(uppername)s_ENABLED() false',
> > +            '#endif',
> > +            uppername=e.name.upper())
> 
> 
> IIUC, this means that on other DTrace impls, any trace points guarded by
> QEMU_*_ENABLED() will never run, even if DTrace probes are set. Having
> some trace points silently never run makes it pretty useless IMHO.
> 
> IOW, you need the opposite, #define it to true. The probe will still
> only be executed if DTrace has enabled it, but you'll have to take the
> hit of evaluating the probe arguments regardless. Not as optimized
> performance-wise, but functionally correct at least.

Good point!  Thank you, will fix when merging.

Stefan

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 455 bytes --]

Re: [Qemu-devel] [PATCH v2 1/2] trace: add TRACE_<event>_BACKEND_DSTATE()

[Daniel P. Berrange]

On Mon, Jul 31, 2017 at 05:35:11PM +0100, Stefan Hajnoczi wrote:
> On Mon, Jul 31, 2017 at 04:16:39PM +0100, Daniel P. Berrange wrote:
> > On Mon, Jul 31, 2017 at 03:07:17PM +0100, Stefan Hajnoczi wrote:
> > > diff --git a/scripts/tracetool/backend/dtrace.py b/scripts/tracetool/backend/dtrace.py
> > > index c6812b70a2..17f902cc62 100644
> > > --- a/scripts/tracetool/backend/dtrace.py
> > > +++ b/scripts/tracetool/backend/dtrace.py
> > > @@ -44,8 +44,20 @@ def generate_h_begin(events, group):
> > >      out('#include "%s"' % header,
> > >          '')
> > >  
> > > +    # SystemTap defines <provider>_<name>_ENABLED() but other DTrace
> > > +    # implementations might not.
> > > +    for e in events:
> > > +        out('#ifndef QEMU_%(uppername)s_ENABLED',
> > > +            '#define QEMU_%(uppername)s_ENABLED() false',
> > > +            '#endif',
> > > +            uppername=e.name.upper())
> > 
> > 
> > IIUC, this means that on other DTrace impls, any trace points guarded by
> > QEMU_*_ENABLED() will never run, even if DTrace probes are set. Having
> > some trace points silently never run makes it pretty useless IMHO.
> > 
> > IOW, you need the opposite, #define it to true. The probe will still
> > only be executed if DTrace has enabled it, but you'll have to take the
> > hit of evaluating the probe arguments regardless. Not as optimized
> > performance-wise, but functionally correct at least.
> 
> Good point!  Thank you, will fix when merging.

Ok, You can add

Reviewed-by: Daniel P. Berrange <berrange@redhat.com>

if the change of false to true is made.

Regards,
Daniel
-- 
|: https://berrange.com      -o-    https://www.flickr.com/photos/dberrange :|
|: https://libvirt.org         -o-            https://fstop138.berrange.com :|
|: https://entangle-photo.org    -o-    https://www.instagram.com/dberrange :|

[Qemu-devel] [PATCH v2 2/2] trace: add trace_event_get_state_backends()

[Stefan Hajnoczi]

Code that checks dstate is unaware of SystemTap and LTTng UST dstate, so
the following trace event will not fire when solely enabled by SystemTap
or LTTng UST:

  if (trace_event_get_state(TRACE_MY_EVENT)) {
      str = g_strdup_printf("Expensive string to generate ...",
                            ...);
      trace_my_event(str);
      g_free(str);
  }

Add trace_event_get_state_backends() to fetch backend dstate.  Those
backends that use QEMU dstate fetch it as part of
generate_h_backend_dstate().

Update existing trace_event_get_state() callers to use
trace_event_get_state_backends() instead.

Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
---
v2:
 * Use _backends() postfix to clarify function purpose [Lluís]
---
 docs/devel/tracing.txt |  2 +-
 trace/control.h        | 18 +++++++++++++++++-
 hw/usb/hcd-ohci.c      | 13 +++++--------
 net/colo-compare.c     | 11 ++++++-----
 net/filter-rewriter.c  |  4 ++--
 5 files changed, 31 insertions(+), 17 deletions(-)

diff --git a/docs/devel/tracing.txt b/docs/devel/tracing.txt
index 5768a0b7a2..07abbb345c 100644
--- a/docs/devel/tracing.txt
+++ b/docs/devel/tracing.txt
@@ -353,7 +353,7 @@ guard such computations and avoid its compilation when the event is disabled:
     }
 
 You can check both if the event has been disabled and is dynamically enabled at
-the same time using the 'trace_event_get_state' routine (see header
+the same time using the 'trace_event_get_state_backends' routine (see header
 "trace/control.h" for more information).
 
 === "tcg" ===
diff --git a/trace/control.h b/trace/control.h
index b931824d60..1903e22975 100644
--- a/trace/control.h
+++ b/trace/control.h
@@ -96,7 +96,7 @@ static const char * trace_event_get_name(TraceEvent *ev);
  * trace_event_get_state:
  * @id: Event identifier name.
  *
- * Get the tracing state of an event (both static and dynamic).
+ * Get the tracing state of an event, both static and the QEMU dynamic state.
  *
  * If the event has the disabled property, the check will have no performance
  * impact.
@@ -105,6 +105,22 @@ static const char * trace_event_get_name(TraceEvent *ev);
     ((id ##_ENABLED) && trace_event_get_state_dynamic_by_id(id))
 
 /**
+ * trace_event_get_state_backends:
+ * @id: Event identifier name.
+ *
+ * Get the tracing state of an event, both static and dynamic state from all
+ * compiled-in backends.
+ *
+ * If the event has the disabled property, the check will have no performance
+ * impact.
+ *
+ * Returns: true if at least one backend has the event enabled and the event
+ * does not have the disabled property.
+ */
+#define trace_event_get_state_backends(id)              \
+    ((id ##_ENABLED) && id ##_BACKEND_DSTATE())
+
+/**
  * trace_event_get_vcpu_state:
  * @vcpu: Target vCPU.
  * @id: Event identifier name.
diff --git a/hw/usb/hcd-ohci.c b/hw/usb/hcd-ohci.c
index 3ada35e954..267982e160 100644
--- a/hw/usb/hcd-ohci.c
+++ b/hw/usb/hcd-ohci.c
@@ -936,16 +936,18 @@ static int ohci_service_iso_td(OHCIState *ohci, struct ohci_ed *ed,
     return 1;
 }
 
-#ifdef trace_event_get_state
 static void ohci_td_pkt(const char *msg, const uint8_t *buf, size_t len)
 {
-    bool print16 = !!trace_event_get_state(TRACE_USB_OHCI_TD_PKT_SHORT);
-    bool printall = !!trace_event_get_state(TRACE_USB_OHCI_TD_PKT_FULL);
+    bool print16;
+    bool printall;
     const int width = 16;
     int i;
     char tmp[3 * width + 1];
     char *p = tmp;
 
+    print16 = !!trace_event_get_state_backends(TRACE_USB_OHCI_TD_PKT_SHORT);
+    printall = !!trace_event_get_state_backends(TRACE_USB_OHCI_TD_PKT_FULL);
+
     if (!printall && !print16) {
         return;
     }
@@ -967,11 +969,6 @@ static void ohci_td_pkt(const char *msg, const uint8_t *buf, size_t len)
         p += sprintf(p, " %.2x", buf[i]);
     }
 }
-#else
-static void ohci_td_pkt(const char *msg, const uint8_t *buf, size_t len)
-{
-}
-#endif
 
 /* Service a transport descriptor.
    Returns nonzero to terminate processing of this endpoint.  */
diff --git a/net/colo-compare.c b/net/colo-compare.c
index ca67c68615..5fe8e3fad9 100644
--- a/net/colo-compare.c
+++ b/net/colo-compare.c
@@ -188,7 +188,7 @@ static int packet_enqueue(CompareState *s, int mode)
  */
 static int colo_packet_compare_common(Packet *ppkt, Packet *spkt, int offset)
 {
-    if (trace_event_get_state(TRACE_COLO_COMPARE_MISCOMPARE)) {
+    if (trace_event_get_state_backends(TRACE_COLO_COMPARE_MISCOMPARE)) {
         char pri_ip_src[20], pri_ip_dst[20], sec_ip_src[20], sec_ip_dst[20];
 
         strcpy(pri_ip_src, inet_ntoa(ppkt->ip->ip_src));
@@ -274,7 +274,8 @@ static int colo_packet_compare_tcp(Packet *spkt, Packet *ppkt)
         res = -1;
     }
 
-    if (res != 0 && trace_event_get_state(TRACE_COLO_COMPARE_MISCOMPARE)) {
+    if (res != 0 &&
+        trace_event_get_state_backends(TRACE_COLO_COMPARE_MISCOMPARE)) {
         char pri_ip_src[20], pri_ip_dst[20], sec_ip_src[20], sec_ip_dst[20];
 
         strcpy(pri_ip_src, inet_ntoa(ppkt->ip->ip_src));
@@ -334,7 +335,7 @@ static int colo_packet_compare_udp(Packet *spkt, Packet *ppkt)
     if (ret) {
         trace_colo_compare_udp_miscompare("primary pkt size", ppkt->size);
         trace_colo_compare_udp_miscompare("Secondary pkt size", spkt->size);
-        if (trace_event_get_state(TRACE_COLO_COMPARE_MISCOMPARE)) {
+        if (trace_event_get_state_backends(TRACE_COLO_COMPARE_MISCOMPARE)) {
             qemu_hexdump((char *)ppkt->data, stderr, "colo-compare pri pkt",
                          ppkt->size);
             qemu_hexdump((char *)spkt->data, stderr, "colo-compare sec pkt",
@@ -371,7 +372,7 @@ static int colo_packet_compare_icmp(Packet *spkt, Packet *ppkt)
                                            ppkt->size);
         trace_colo_compare_icmp_miscompare("Secondary pkt size",
                                            spkt->size);
-        if (trace_event_get_state(TRACE_COLO_COMPARE_MISCOMPARE)) {
+        if (trace_event_get_state_backends(TRACE_COLO_COMPARE_MISCOMPARE)) {
             qemu_hexdump((char *)ppkt->data, stderr, "colo-compare pri pkt",
                          ppkt->size);
             qemu_hexdump((char *)spkt->data, stderr, "colo-compare sec pkt",
@@ -390,7 +391,7 @@ static int colo_packet_compare_icmp(Packet *spkt, Packet *ppkt)
 static int colo_packet_compare_other(Packet *spkt, Packet *ppkt)
 {
     trace_colo_compare_main("compare other");
-    if (trace_event_get_state(TRACE_COLO_COMPARE_MISCOMPARE)) {
+    if (trace_event_get_state_backends(TRACE_COLO_COMPARE_MISCOMPARE)) {
         char pri_ip_src[20], pri_ip_dst[20], sec_ip_src[20], sec_ip_dst[20];
 
         strcpy(pri_ip_src, inet_ntoa(ppkt->ip->ip_src));
diff --git a/net/filter-rewriter.c b/net/filter-rewriter.c
index 55a6cf56fd..98120095de 100644
--- a/net/filter-rewriter.c
+++ b/net/filter-rewriter.c
@@ -69,7 +69,7 @@ static int handle_primary_tcp_pkt(NetFilterState *nf,
     struct tcphdr *tcp_pkt;
 
     tcp_pkt = (struct tcphdr *)pkt->transport_header;
-    if (trace_event_get_state(TRACE_COLO_FILTER_REWRITER_DEBUG)) {
+    if (trace_event_get_state_backends(TRACE_COLO_FILTER_REWRITER_DEBUG)) {
         trace_colo_filter_rewriter_pkt_info(__func__,
                     inet_ntoa(pkt->ip->ip_src), inet_ntoa(pkt->ip->ip_dst),
                     ntohl(tcp_pkt->th_seq), ntohl(tcp_pkt->th_ack),
@@ -115,7 +115,7 @@ static int handle_secondary_tcp_pkt(NetFilterState *nf,
 
     tcp_pkt = (struct tcphdr *)pkt->transport_header;
 
-    if (trace_event_get_state(TRACE_COLO_FILTER_REWRITER_DEBUG)) {
+    if (trace_event_get_state_backends(TRACE_COLO_FILTER_REWRITER_DEBUG)) {
         trace_colo_filter_rewriter_pkt_info(__func__,
                     inet_ntoa(pkt->ip->ip_src), inet_ntoa(pkt->ip->ip_dst),
                     ntohl(tcp_pkt->th_seq), ntohl(tcp_pkt->th_ack),
-- 
2.13.3

Re: [Qemu-devel] [PATCH v2 2/2] trace: add trace_event_get_state_backends()

[Lluís Vilanova]

Stefan Hajnoczi writes:

> Code that checks dstate is unaware of SystemTap and LTTng UST dstate, so
> the following trace event will not fire when solely enabled by SystemTap
> or LTTng UST:

>   if (trace_event_get_state(TRACE_MY_EVENT)) {
>       str = g_strdup_printf("Expensive string to generate ...",
>                             ...);
>       trace_my_event(str);
>       g_free(str);
>   }

I believe this should be trace_event_get_state_backends(). Same applies to the
cover letter.

Cheers,
  Lluis

> Add trace_event_get_state_backends() to fetch backend dstate.  Those
> backends that use QEMU dstate fetch it as part of
> generate_h_backend_dstate().

> Update existing trace_event_get_state() callers to use
> trace_event_get_state_backends() instead.

> Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
> ---
> v2:
>  * Use _backends() postfix to clarify function purpose [Lluís]
> ---
>  docs/devel/tracing.txt |  2 +-
>  trace/control.h        | 18 +++++++++++++++++-
>  hw/usb/hcd-ohci.c      | 13 +++++--------
>  net/colo-compare.c     | 11 ++++++-----
>  net/filter-rewriter.c  |  4 ++--
>  5 files changed, 31 insertions(+), 17 deletions(-)

> diff --git a/docs/devel/tracing.txt b/docs/devel/tracing.txt
> index 5768a0b7a2..07abbb345c 100644
> --- a/docs/devel/tracing.txt
> +++ b/docs/devel/tracing.txt
> @@ -353,7 +353,7 @@ guard such computations and avoid its compilation when the event is disabled:
>      }
 
>  You can check both if the event has been disabled and is dynamically enabled at
> -the same time using the 'trace_event_get_state' routine (see header
> +the same time using the 'trace_event_get_state_backends' routine (see header
>  "trace/control.h" for more information).
 
>  === "tcg" ===
> diff --git a/trace/control.h b/trace/control.h
> index b931824d60..1903e22975 100644
> --- a/trace/control.h
> +++ b/trace/control.h
> @@ -96,7 +96,7 @@ static const char * trace_event_get_name(TraceEvent *ev);
>   * trace_event_get_state:
>   * @id: Event identifier name.
>   *
> - * Get the tracing state of an event (both static and dynamic).
> + * Get the tracing state of an event, both static and the QEMU dynamic state.
>   *
>   * If the event has the disabled property, the check will have no performance
>   * impact.
> @@ -105,6 +105,22 @@ static const char * trace_event_get_name(TraceEvent *ev);
>      ((id ##_ENABLED) && trace_event_get_state_dynamic_by_id(id))
 
>  /**
> + * trace_event_get_state_backends:
> + * @id: Event identifier name.
> + *
> + * Get the tracing state of an event, both static and dynamic state from all
> + * compiled-in backends.
> + *
> + * If the event has the disabled property, the check will have no performance
> + * impact.
> + *
> + * Returns: true if at least one backend has the event enabled and the event
> + * does not have the disabled property.
> + */
> +#define trace_event_get_state_backends(id)              \
> +    ((id ##_ENABLED) && id ##_BACKEND_DSTATE())
> +
> +/**
>   * trace_event_get_vcpu_state:
>   * @vcpu: Target vCPU.
>   * @id: Event identifier name.
> diff --git a/hw/usb/hcd-ohci.c b/hw/usb/hcd-ohci.c
> index 3ada35e954..267982e160 100644
> --- a/hw/usb/hcd-ohci.c
> +++ b/hw/usb/hcd-ohci.c
> @@ -936,16 +936,18 @@ static int ohci_service_iso_td(OHCIState *ohci, struct ohci_ed *ed,
>      return 1;
>  }
 
> -#ifdef trace_event_get_state
>  static void ohci_td_pkt(const char *msg, const uint8_t *buf, size_t len)
>  {
> -    bool print16 = !!trace_event_get_state(TRACE_USB_OHCI_TD_PKT_SHORT);
> -    bool printall = !!trace_event_get_state(TRACE_USB_OHCI_TD_PKT_FULL);
> +    bool print16;
> +    bool printall;
>      const int width = 16;
>      int i;
>      char tmp[3 * width + 1];
>      char *p = tmp;
 
> +    print16 = !!trace_event_get_state_backends(TRACE_USB_OHCI_TD_PKT_SHORT);
> +    printall = !!trace_event_get_state_backends(TRACE_USB_OHCI_TD_PKT_FULL);
> +
>      if (!printall && !print16) {
>          return;
>      }
> @@ -967,11 +969,6 @@ static void ohci_td_pkt(const char *msg, const uint8_t *buf, size_t len)
>          p += sprintf(p, " %.2x", buf[i]);
>      }
>  }
> -#else
> -static void ohci_td_pkt(const char *msg, const uint8_t *buf, size_t len)
> -{
> -}
> -#endif
 
>  /* Service a transport descriptor.
>     Returns nonzero to terminate processing of this endpoint.  */
> diff --git a/net/colo-compare.c b/net/colo-compare.c
> index ca67c68615..5fe8e3fad9 100644
> --- a/net/colo-compare.c
> +++ b/net/colo-compare.c
> @@ -188,7 +188,7 @@ static int packet_enqueue(CompareState *s, int mode)
>   */
>  static int colo_packet_compare_common(Packet *ppkt, Packet *spkt, int offset)
>  {
> -    if (trace_event_get_state(TRACE_COLO_COMPARE_MISCOMPARE)) {
> +    if (trace_event_get_state_backends(TRACE_COLO_COMPARE_MISCOMPARE)) {
>          char pri_ip_src[20], pri_ip_dst[20], sec_ip_src[20], sec_ip_dst[20];
 
>          strcpy(pri_ip_src, inet_ntoa(ppkt->ip->ip_src));
> @@ -274,7 +274,8 @@ static int colo_packet_compare_tcp(Packet *spkt, Packet *ppkt)
>          res = -1;
>      }
 
> -    if (res != 0 && trace_event_get_state(TRACE_COLO_COMPARE_MISCOMPARE)) {
> +    if (res != 0 &&
> +        trace_event_get_state_backends(TRACE_COLO_COMPARE_MISCOMPARE)) {
>          char pri_ip_src[20], pri_ip_dst[20], sec_ip_src[20], sec_ip_dst[20];
 
>          strcpy(pri_ip_src, inet_ntoa(ppkt->ip->ip_src));
> @@ -334,7 +335,7 @@ static int colo_packet_compare_udp(Packet *spkt, Packet *ppkt)
>      if (ret) {
>          trace_colo_compare_udp_miscompare("primary pkt size", ppkt->size);
>          trace_colo_compare_udp_miscompare("Secondary pkt size", spkt->size);
> -        if (trace_event_get_state(TRACE_COLO_COMPARE_MISCOMPARE)) {
> +        if (trace_event_get_state_backends(TRACE_COLO_COMPARE_MISCOMPARE)) {
>              qemu_hexdump((char *)ppkt->data, stderr, "colo-compare pri pkt",
ppkt-> size);
>              qemu_hexdump((char *)spkt->data, stderr, "colo-compare sec pkt",
> @@ -371,7 +372,7 @@ static int colo_packet_compare_icmp(Packet *spkt, Packet *ppkt)
ppkt-> size);
>          trace_colo_compare_icmp_miscompare("Secondary pkt size",
spkt-> size);
> -        if (trace_event_get_state(TRACE_COLO_COMPARE_MISCOMPARE)) {
> +        if (trace_event_get_state_backends(TRACE_COLO_COMPARE_MISCOMPARE)) {
>              qemu_hexdump((char *)ppkt->data, stderr, "colo-compare pri pkt",
ppkt-> size);
>              qemu_hexdump((char *)spkt->data, stderr, "colo-compare sec pkt",
> @@ -390,7 +391,7 @@ static int colo_packet_compare_icmp(Packet *spkt, Packet *ppkt)
>  static int colo_packet_compare_other(Packet *spkt, Packet *ppkt)
>  {
>      trace_colo_compare_main("compare other");
> -    if (trace_event_get_state(TRACE_COLO_COMPARE_MISCOMPARE)) {
> +    if (trace_event_get_state_backends(TRACE_COLO_COMPARE_MISCOMPARE)) {
>          char pri_ip_src[20], pri_ip_dst[20], sec_ip_src[20], sec_ip_dst[20];
 
>          strcpy(pri_ip_src, inet_ntoa(ppkt->ip->ip_src));
> diff --git a/net/filter-rewriter.c b/net/filter-rewriter.c
> index 55a6cf56fd..98120095de 100644
> --- a/net/filter-rewriter.c
> +++ b/net/filter-rewriter.c
> @@ -69,7 +69,7 @@ static int handle_primary_tcp_pkt(NetFilterState *nf,
>      struct tcphdr *tcp_pkt;
 
>      tcp_pkt = (struct tcphdr *)pkt->transport_header;
> -    if (trace_event_get_state(TRACE_COLO_FILTER_REWRITER_DEBUG)) {
> +    if (trace_event_get_state_backends(TRACE_COLO_FILTER_REWRITER_DEBUG)) {
>          trace_colo_filter_rewriter_pkt_info(__func__,
>                      inet_ntoa(pkt->ip->ip_src), inet_ntoa(pkt->ip->ip_dst),
>                      ntohl(tcp_pkt->th_seq), ntohl(tcp_pkt->th_ack),
> @@ -115,7 +115,7 @@ static int handle_secondary_tcp_pkt(NetFilterState *nf,
 
>      tcp_pkt = (struct tcphdr *)pkt->transport_header;
 
> -    if (trace_event_get_state(TRACE_COLO_FILTER_REWRITER_DEBUG)) {
> +    if (trace_event_get_state_backends(TRACE_COLO_FILTER_REWRITER_DEBUG)) {
>          trace_colo_filter_rewriter_pkt_info(__func__,
>                      inet_ntoa(pkt->ip->ip_src), inet_ntoa(pkt->ip->ip_dst),
>                      ntohl(tcp_pkt->th_seq), ntohl(tcp_pkt->th_ack),
> -- 
> 2.13.3

Re: [Qemu-devel] [PATCH v2 2/2] trace: add trace_event_get_state_backends()

[Stefan Hajnoczi]

[-- Attachment #1: Type: text/plain, Size: 882 bytes --]

On Mon, Jul 31, 2017 at 06:09:56PM +0300, Lluís Vilanova wrote:
> Stefan Hajnoczi writes:
> 
> > Code that checks dstate is unaware of SystemTap and LTTng UST dstate, so
> > the following trace event will not fire when solely enabled by SystemTap
> > or LTTng UST:
> 
> >   if (trace_event_get_state(TRACE_MY_EVENT)) {
> >       str = g_strdup_printf("Expensive string to generate ...",
> >                             ...);
> >       trace_my_event(str);
> >       g_free(str);
> >   }
> 
> I believe this should be trace_event_get_state_backends(). Same applies to the
> cover letter.

This instance and the cover letter are both showing the pattern in
existing code.

The description "event will not fire" is correct with
trace_event_get_state().  If I change it to
trace_event_get_state_backends() then the description is no longer
correct :).

Stefan

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 455 bytes --]

Re: [Qemu-devel] [PATCH v2 2/2] trace: add trace_event_get_state_backends()

[Lluís Vilanova]

Stefan Hajnoczi writes:

> On Mon, Jul 31, 2017 at 06:09:56PM +0300, Lluís Vilanova wrote:
>> Stefan Hajnoczi writes:
>> 
>> > Code that checks dstate is unaware of SystemTap and LTTng UST dstate, so
>> > the following trace event will not fire when solely enabled by SystemTap
>> > or LTTng UST:
>> 
>> >   if (trace_event_get_state(TRACE_MY_EVENT)) {
>> >       str = g_strdup_printf("Expensive string to generate ...",
>> >                             ...);
>> >       trace_my_event(str);
>> >       g_free(str);
>> >   }
>> 
>> I believe this should be trace_event_get_state_backends(). Same applies to the
>> cover letter.

> This instance and the cover letter are both showing the pattern in
> existing code.

> The description "event will not fire" is correct with
> trace_event_get_state().  If I change it to
> trace_event_get_state_backends() then the description is no longer
> correct :).

Woops, I read this too quickly and assumed it was a usage example, sorry :)

Cheers,
  Lluis

Re: [Qemu-devel] [PATCH v2 2/2] trace: add trace_event_get_state_backends()

[Daniel P. Berrange]

On Mon, Jul 31, 2017 at 03:07:18PM +0100, Stefan Hajnoczi wrote:
> Code that checks dstate is unaware of SystemTap and LTTng UST dstate, so
> the following trace event will not fire when solely enabled by SystemTap
> or LTTng UST:
> 
>   if (trace_event_get_state(TRACE_MY_EVENT)) {
>       str = g_strdup_printf("Expensive string to generate ...",
>                             ...);
>       trace_my_event(str);
>       g_free(str);
>   }
> 
> Add trace_event_get_state_backends() to fetch backend dstate.  Those
> backends that use QEMU dstate fetch it as part of
> generate_h_backend_dstate().
> 
> Update existing trace_event_get_state() callers to use
> trace_event_get_state_backends() instead.
> 
> Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
> ---
> v2:
>  * Use _backends() postfix to clarify function purpose [Lluís]
> ---
>  docs/devel/tracing.txt |  2 +-
>  trace/control.h        | 18 +++++++++++++++++-
>  hw/usb/hcd-ohci.c      | 13 +++++--------
>  net/colo-compare.c     | 11 ++++++-----
>  net/filter-rewriter.c  |  4 ++--
>  5 files changed, 31 insertions(+), 17 deletions(-)

Reviewed-by: Daniel P. Berrange <berrange@redhat.com>


Regards,
Daniel
-- 
|: https://berrange.com      -o-    https://www.flickr.com/photos/dberrange :|
|: https://libvirt.org         -o-            https://fstop138.berrange.com :|
|: https://entangle-photo.org    -o-    https://www.instagram.com/dberrange :|

Re: [Qemu-devel] [PATCH v2 0/2] trace: fix trace_event_get_state() for SystemTap and LTTng UST

[Stefan Hajnoczi]

[-- Attachment #1: Type: text/plain, Size: 1929 bytes --]

On Mon, Jul 31, 2017 at 03:07:16PM +0100, Stefan Hajnoczi wrote:
> v2:
>  * Don't special-case QEMU dstate [Daniel Berrange]
>  * Use _backends() postfix to clarify function purpose [Lluís]
> 
> Trace events that compute their arguments can affect performance.  The
> following idom can be used to avoid computing arguments when the trace event is
> disabled:
> 
>   if (trace_event_get_state(TRACE_MY_EVENT)) {
>       char *str = g_strdup_printf("Expensive string ...", ...);
>       trace_my_event(str);
>       g_free(str);
>   }
> 
> Unfortunately this breaks the trace event for SystemTap and LTTng UST since
> those tracers manage their own enabled/disabled state.
> 
> These patches add per-backend dstate to trace_event_get_state() so that the
> trace event fires as expected when enabled via SystemTap or LTTng UST.
> 
> Stefan Hajnoczi (2):
>   trace: add TRACE_<event>_BACKEND_DSTATE()
>   trace: add trace_event_get_state_backends()
> 
>  docs/devel/tracing.txt                |  2 +-
>  trace/control.h                       | 18 +++++++++++++++++-
>  hw/usb/hcd-ohci.c                     | 13 +++++--------
>  net/colo-compare.c                    | 11 ++++++-----
>  net/filter-rewriter.c                 |  4 ++--
>  scripts/tracetool/__init__.py         |  1 +
>  scripts/tracetool/backend/__init__.py |  3 +++
>  scripts/tracetool/backend/dtrace.py   | 12 ++++++++++++
>  scripts/tracetool/backend/ftrace.py   |  5 +++++
>  scripts/tracetool/backend/log.py      |  5 +++++
>  scripts/tracetool/backend/simple.py   |  5 +++++
>  scripts/tracetool/backend/syslog.py   |  5 +++++
>  scripts/tracetool/backend/ust.py      |  5 +++++
>  scripts/tracetool/format/h.py         | 10 ++++++++++
>  14 files changed, 82 insertions(+), 17 deletions(-)
> 
> -- 
> 2.13.3
> 
> 

Thanks, applied to my tracing tree:
https://github.com/stefanha/qemu/commits/tracing

Stefan

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 455 bytes --]