[Qemu-devel] [PATCH for-2.5 0/2] trace: decrease overhead of simpletrace and stderr backends

[Qemu-devel] [PATCH for-2.5 0/2] trace: decrease overhead of simpletrace and stderr backends

[Paolo Bonzini]

This patch series makes it faster for simpletrace and stderr backends
to discard disabled events.  This is done in two ways: patch 1 makes
the common case of no enabled events faster; patch 2 makes the other
case less heavy on the data cache by packing the "tracepoint enabled"
flag and avoiding useless pointer chasing.

This should decrease the impact of changing the default tracing backend
to stderr aka log, which Peter suggested could be a problem.

Paolo

Paolo Bonzini (2):
  trace: count number of enabled events
  trace: track enabled events in a separate array

 scripts/tracetool/format/events_c.py |  2 +-
 trace/control-internal.h             | 15 ++++++++++++---
 trace/control.c                      |  3 +++
 trace/control.h                      |  2 +-
 trace/event-internal.h               |  2 --
 5 files changed, 17 insertions(+), 7 deletions(-)

-- 
2.5.0

[Qemu-devel] [PATCH 1/2] trace: count number of enabled events

[Paolo Bonzini]

This lets trace_event_get_state_dynamic quickly return false.  Right
now there is hardly any benefit because there are also many assertions
and indirections, but the next patch will streamline all of this.

Signed-off-by: Paolo Bonzini <pbonzini@redhat.com>
---
 trace/control-internal.h | 4 +++-
 trace/control.c          | 2 ++
 2 files changed, 5 insertions(+), 1 deletion(-)

diff --git a/trace/control-internal.h b/trace/control-internal.h
index 5a8df28..271bddb 100644
--- a/trace/control-internal.h
+++ b/trace/control-internal.h
@@ -14,6 +14,7 @@
 
 
 extern TraceEvent trace_events[];
+extern int trace_events_enabled_count;
 
 
 static inline TraceEventID trace_event_count(void)
@@ -54,13 +55,14 @@ static inline bool trace_event_get_state_static(TraceEvent *ev)
 static inline bool trace_event_get_state_dynamic(TraceEvent *ev)
 {
     assert(ev != NULL);
-    return ev->dstate;
+    return unlikely(trace_events_enabled_count) && ev->dstate;
 }
 
 static inline void trace_event_set_state_dynamic(TraceEvent *ev, bool state)
 {
     assert(ev != NULL);
     assert(trace_event_get_state_static(ev));
+    trace_events_enabled_count += state - ev->dstate;
     ev->dstate = state;
 }
 
diff --git a/trace/control.c b/trace/control.c
index 995beb3..95fbc07 100644
--- a/trace/control.c
+++ b/trace/control.c
@@ -16,6 +16,8 @@
 #endif
 #include "qemu/error-report.h"
 
+int trace_events_enabled_count;
+
 TraceEvent *trace_event_name(const char *name)
 {
     assert(name != NULL);
-- 
2.5.0

[Qemu-devel] [PATCH 2/2] trace: track enabled events in a separate array

[Paolo Bonzini]

This is more cache friendly on the fast path, where we already have
the event id available.

Signed-off-by: Paolo Bonzini <pbonzini@redhat.com>
---
 scripts/tracetool/format/events_c.py |  2 +-
 trace/control-internal.h             | 15 +++++++++++----
 trace/control.c                      |  1 +
 trace/control.h                      |  2 +-
 trace/event-internal.h               |  2 --
 5 files changed, 14 insertions(+), 8 deletions(-)

diff --git a/scripts/tracetool/format/events_c.py b/scripts/tracetool/format/events_c.py
index 2d97fa3..2717ea3 100644
--- a/scripts/tracetool/format/events_c.py
+++ b/scripts/tracetool/format/events_c.py
@@ -27,7 +27,7 @@ def generate(events, backend):
     out('TraceEvent trace_events[TRACE_EVENT_COUNT] = {')
 
     for e in events:
-        out('    { .id = %(id)s, .name = \"%(name)s\", .sstate = %(sstate)s, .dstate = 0 },',
+        out('    { .id = %(id)s, .name = \"%(name)s\", .sstate = %(sstate)s },',
             id = "TRACE_" + e.name.upper(),
             name = e.name,
             sstate = "TRACE_%s_ENABLED" % e.name.upper())
diff --git a/trace/control-internal.h b/trace/control-internal.h
index 271bddb..07cb1c1 100644
--- a/trace/control-internal.h
+++ b/trace/control-internal.h
@@ -14,6 +14,7 @@
 
 
 extern TraceEvent trace_events[];
+extern bool trace_events_dstate[];
 extern int trace_events_enabled_count;
 
 
@@ -52,18 +53,24 @@ static inline bool trace_event_get_state_static(TraceEvent *ev)
     return ev->sstate;
 }
 
+static inline bool trace_event_get_state_dynamic_by_id(int id)
+{
+    return unlikely(trace_events_enabled_count) && trace_events_dstate[id];
+}
+
 static inline bool trace_event_get_state_dynamic(TraceEvent *ev)
 {
-    assert(ev != NULL);
-    return unlikely(trace_events_enabled_count) && ev->dstate;
+    int id = trace_event_get_id(ev);
+    return trace_event_get_state_dynamic_by_id(id);
 }
 
 static inline void trace_event_set_state_dynamic(TraceEvent *ev, bool state)
 {
+    int id = trace_event_get_id(ev);
     assert(ev != NULL);
     assert(trace_event_get_state_static(ev));
-    trace_events_enabled_count += state - ev->dstate;
-    ev->dstate = state;
+    trace_events_enabled_count += state - trace_events_dstate[id];
+    trace_events_dstate[id] = state;
 }
 
 #endif  /* TRACE__CONTROL_INTERNAL_H */
diff --git a/trace/control.c b/trace/control.c
index 95fbc07..700440c 100644
--- a/trace/control.c
+++ b/trace/control.c
@@ -17,6 +17,7 @@
 #include "qemu/error-report.h"
 
 int trace_events_enabled_count;
+bool trace_events_dstate[TRACE_EVENT_COUNT];
 
 TraceEvent *trace_event_name(const char *name)
 {
diff --git a/trace/control.h b/trace/control.h
index da9bb6b..6af7ddc 100644
--- a/trace/control.h
+++ b/trace/control.h
@@ -104,7 +104,7 @@ static const char * trace_event_get_name(TraceEvent *ev);
  * As a down side, you must always use an immediate #TraceEventID value.
  */
 #define trace_event_get_state(id)                       \
-    ((id ##_ENABLED) && trace_event_get_state_dynamic(trace_event_id(id)))
+    ((id ##_ENABLED) && trace_event_get_state_dynamic_by_id(id))
 
 /**
  * trace_event_get_state_static:
diff --git a/trace/event-internal.h b/trace/event-internal.h
index b2310d9..86f6a51 100644
--- a/trace/event-internal.h
+++ b/trace/event-internal.h
@@ -18,7 +18,6 @@
  * @id: Unique event identifier.
  * @name: Event name.
  * @sstate: Static tracing state.
- * @dstate: Dynamic tracing state.
  *
  * Opaque generic description of a tracing event.
  */
@@ -26,7 +25,6 @@ typedef struct TraceEvent {
     TraceEventID id;
     const char * name;
     const bool sstate;
-    bool dstate;
 } TraceEvent;
 
 
-- 
2.5.0

Re: [Qemu-devel] [PATCH for-2.5 0/2] trace: decrease overhead of simpletrace and stderr backends

[Stefan Hajnoczi]

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

On Wed, Oct 28, 2015 at 07:06:25AM +0100, Paolo Bonzini wrote:
> This patch series makes it faster for simpletrace and stderr backends
> to discard disabled events.  This is done in two ways: patch 1 makes
> the common case of no enabled events faster; patch 2 makes the other
> case less heavy on the data cache by packing the "tracepoint enabled"
> flag and avoiding useless pointer chasing.
> 
> This should decrease the impact of changing the default tracing backend
> to stderr aka log, which Peter suggested could be a problem.
> 
> Paolo
> 
> Paolo Bonzini (2):
>   trace: count number of enabled events
>   trace: track enabled events in a separate array
> 
>  scripts/tracetool/format/events_c.py |  2 +-
>  trace/control-internal.h             | 15 ++++++++++++---
>  trace/control.c                      |  3 +++
>  trace/control.h                      |  2 +-
>  trace/event-internal.h               |  2 --
>  5 files changed, 17 insertions(+), 7 deletions(-)

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

Stefan

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