From 0a852417564bc59441dc09509beacf7b49bc1e57 Mon Sep 17 00:00:00 2001 From: Paul Durrant Date: Thu, 4 Aug 2016 14:44:14 +0100 Subject: [PATCH 1/3] trace: add syslog tracing backend This patch adds a tracing backend which sends output using syslog(). The syslog backend is limited to POSIX compliant systems. openlog() is called with facility set to LOG_DAEMON, with the LOG_PID option. Trace events are logged at level LOG_INFO. Signed-off-by: Paul Durrant Message-id: 1470318254-29989-1-git-send-email-paul.durrant@citrix.com Cc: Stefan Hajnoczi Signed-off-by: Stefan Hajnoczi --- configure | 19 ++++++++++++ docs/tracing.txt | 12 ++++++++ scripts/tracetool/backend/syslog.py | 45 +++++++++++++++++++++++++++++ trace/control.c | 7 +++++ 4 files changed, 83 insertions(+) create mode 100644 scripts/tracetool/backend/syslog.py diff --git a/configure b/configure index 4b808f9d17..5a9bda18b5 100755 --- a/configure +++ b/configure @@ -4191,6 +4191,18 @@ if compile_prog "" "" ; then posix_madvise=yes fi +########################################## +# check if we have posix_syslog + +posix_syslog=no +cat > $TMPC << EOF +#include +int main(void) { openlog("qemu", LOG_PID, LOG_DAEMON); syslog(LOG_INFO, "configure"); return 0; } +EOF +if compile_prog "" "" ; then + posix_syslog=yes +fi + ########################################## # check if trace backend exists @@ -5468,6 +5480,13 @@ if have_backend "ftrace"; then feature_not_found "ftrace(trace backend)" "ftrace requires Linux" fi fi +if have_backend "syslog"; then + if test "$posix_syslog" = "yes" ; then + echo "CONFIG_TRACE_SYSLOG=y" >> $config_host_mak + else + feature_not_found "syslog(trace backend)" "syslog not available" + fi +fi echo "CONFIG_TRACE_FILE=$trace_file" >> $config_host_mak if test "$rdma" = "yes" ; then diff --git a/docs/tracing.txt b/docs/tracing.txt index 29f2f9a24d..e62444ca68 100644 --- a/docs/tracing.txt +++ b/docs/tracing.txt @@ -192,6 +192,18 @@ After running qemu by root user, you can get the trace: Restriction: "ftrace" backend is restricted to Linux only. +=== Syslog === + +The "syslog" backend sends trace events using the POSIX syslog API. The log +is opened specifying the LOG_DAEMON facility and LOG_PID option (so events +are tagged with the pid of the particular QEMU process that generated +them). All events are logged at LOG_INFO level. + +NOTE: syslog may squash duplicate consecutive trace events and apply rate + limiting. + +Restriction: "syslog" backend is restricted to POSIX compliant OS. + ==== Monitor commands ==== * trace-file on|off|flush|set diff --git a/scripts/tracetool/backend/syslog.py b/scripts/tracetool/backend/syslog.py new file mode 100644 index 0000000000..89019bc759 --- /dev/null +++ b/scripts/tracetool/backend/syslog.py @@ -0,0 +1,45 @@ +#!/usr/bin/env python +# -*- coding: utf-8 -*- + +""" +Syslog built-in backend. +""" + +__author__ = "Paul Durrant " +__copyright__ = "Copyright 2016, Citrix Systems Inc." +__license__ = "GPL version 2 or (at your option) any later version" + +__maintainer__ = "Stefan Hajnoczi" +__email__ = "stefanha@redhat.com" + + +from tracetool import out + + +PUBLIC = True + + +def generate_h_begin(events): + out('#include ', + '#include "trace/control.h"', + '') + + +def generate_h(event): + argnames = ", ".join(event.args.names()) + if len(event.args) > 0: + argnames = ", " + argnames + + if "vcpu" in event.properties: + # already checked on the generic format code + cond = "true" + else: + cond = "trace_event_get_state(%s)" % ("TRACE_" + event.name.upper()) + + out(' if (%(cond)s) {', + ' syslog(LOG_INFO, "%(name)s " %(fmt)s %(argnames)s);', + ' }', + cond=cond, + name=event.name, + fmt=event.fmt.rstrip("\n"), + argnames=argnames) diff --git a/trace/control.c b/trace/control.c index d173c09f44..b179cde9df 100644 --- a/trace/control.c +++ b/trace/control.c @@ -19,6 +19,9 @@ #ifdef CONFIG_TRACE_LOG #include "qemu/log.h" #endif +#ifdef CONFIG_TRACE_SYSLOG +#include +#endif #include "qapi/error.h" #include "qemu/error-report.h" #include "qemu/config-file.h" @@ -250,6 +253,10 @@ bool trace_init_backends(void) } #endif +#ifdef CONFIG_TRACE_SYSLOG + openlog(NULL, LOG_PID, LOG_DAEMON); +#endif + return true; } From a4d50b1d2a6c07a13fb8401a0c3b471f25b44b2a Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Llu=C3=ADs=20Vilanova?= Date: Tue, 23 Aug 2016 10:58:52 +0200 Subject: [PATCH 2/3] trace: Remove 'trace_events_dstate_init' MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Removes the event state array used for early initialization. Since only events with the "vcpu" property need a late initialization fixup, threats their initialization specially. Assumes that the user won't touch the state of "vcpu" events between early and late initialization (e.g., through QMP). Signed-off-by: Lluís Vilanova Message-id: 147194273191.26836.14423079546263831356.stgit@fimbulvetr.bsc.es Signed-off-by: Stefan Hajnoczi --- stubs/trace-control.c | 5 +++++ trace/control-target.c | 9 +++++++++ trace/control.c | 21 ++++++++++----------- trace/control.h | 3 +++ trace/event-internal.h | 1 + 5 files changed, 28 insertions(+), 11 deletions(-) diff --git a/stubs/trace-control.c b/stubs/trace-control.c index fe59836fce..3740c38589 100644 --- a/stubs/trace-control.c +++ b/stubs/trace-control.c @@ -11,6 +11,11 @@ #include "trace/control.h" +void trace_event_set_state_dynamic_init(TraceEvent *ev, bool state) +{ + trace_event_set_state_dynamic(ev, state); +} + void trace_event_set_state_dynamic(TraceEvent *ev, bool state) { TraceEventID id; diff --git a/trace/control-target.c b/trace/control-target.c index 74c029accc..4ee3733662 100644 --- a/trace/control-target.c +++ b/trace/control-target.c @@ -13,6 +13,15 @@ #include "translate-all.h" +void trace_event_set_state_dynamic_init(TraceEvent *ev, bool state) +{ + TraceEventID id = trace_event_get_id(ev); + assert(trace_event_get_state_static(ev)); + /* Ignore "vcpu" property, since no vCPUs have been created yet */ + trace_events_enabled_count += state - trace_events_dstate[id]; + trace_events_dstate[id] = state; +} + void trace_event_set_state_dynamic(TraceEvent *ev, bool state) { CPUState *vcpu; diff --git a/trace/control.c b/trace/control.c index b179cde9df..05d85accbd 100644 --- a/trace/control.c +++ b/trace/control.c @@ -34,8 +34,6 @@ int trace_events_enabled_count; * - true : Integral counting the number of vCPUs that have this event enabled. */ uint16_t trace_events_dstate[TRACE_EVENT_COUNT]; -/* Marks events for late vCPU state init */ -static bool trace_events_dstate_init[TRACE_EVENT_COUNT]; QemuOptsList qemu_trace_opts = { .name = "trace", @@ -145,10 +143,7 @@ static void do_trace_enable_events(const char *line_buf) TraceEvent *ev = NULL; while ((ev = trace_event_pattern(line_ptr, ev)) != NULL) { if (trace_event_get_state_static(ev)) { - /* start tracing */ - trace_event_set_state_dynamic(ev, enable); - /* mark for late vCPU init */ - trace_events_dstate_init[ev->id] = true; + trace_event_set_state_dynamic_init(ev, enable); } } } else { @@ -160,10 +155,7 @@ static void do_trace_enable_events(const char *line_buf) error_report("WARNING: trace event '%s' is not traceable", line_ptr); } else { - /* start tracing */ - trace_event_set_state_dynamic(ev, enable); - /* mark for late vCPU init */ - trace_events_dstate_init[ev->id] = true; + trace_event_set_state_dynamic_init(ev, enable); } } } @@ -284,7 +276,14 @@ void trace_init_vcpu_events(void) while ((ev = trace_event_pattern("*", ev)) != NULL) { if (trace_event_is_vcpu(ev) && trace_event_get_state_static(ev) && - trace_events_dstate_init[ev->id]) { + trace_event_get_state_dynamic(ev)) { + TraceEventID id = trace_event_get_id(ev); + /* check preconditions */ + assert(trace_events_dstate[id] == 1); + /* disable early-init state ... */ + trace_events_dstate[id] = 0; + trace_events_enabled_count--; + /* ... and properly re-enable */ trace_event_set_state_dynamic(ev, true); } } diff --git a/trace/control.h b/trace/control.h index 0413b28769..27a16fc955 100644 --- a/trace/control.h +++ b/trace/control.h @@ -274,6 +274,9 @@ char *trace_opt_parse(const char *optarg); * * Re-synchronize initial event state with vCPUs (which can be created after * trace_init_events()). + * + * Precondition: event states won't be changed between trace_enable_events() and + * trace_init_vcpu_events() (e.g., through QMP). */ void trace_init_vcpu_events(void); diff --git a/trace/event-internal.h b/trace/event-internal.h index 5d8fa97ca5..074faf6862 100644 --- a/trace/event-internal.h +++ b/trace/event-internal.h @@ -29,5 +29,6 @@ typedef struct TraceEvent { const bool sstate; } TraceEvent; +void trace_event_set_state_dynamic_init(TraceEvent *ev, bool state); #endif /* TRACE__EVENT_INTERNAL_H */ From 8eb1b9db559e243043aaeac3a0aa97e1f4a403c4 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Llu=C3=ADs=20Vilanova?= Date: Tue, 23 Aug 2016 10:58:58 +0200 Subject: [PATCH 3/3] trace: Avoid implicit bool->integer conversions MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit An explicit if/else is clearer than arithmetic assuming #true is 1, while the compiler should be able to generate just as optimal code. Signed-off-by: Lluís Vilanova Message-id: 147194273830.26836.5875729707953474838.stgit@fimbulvetr.bsc.es Signed-off-by: Stefan Hajnoczi --- stubs/trace-control.c | 17 +++++++++++++++-- trace/control-target.c | 31 ++++++++++++++++++++++++++----- 2 files changed, 41 insertions(+), 7 deletions(-) diff --git a/stubs/trace-control.c b/stubs/trace-control.c index 3740c38589..2dfcd9fb2b 100644 --- a/stubs/trace-control.c +++ b/stubs/trace-control.c @@ -19,10 +19,23 @@ void trace_event_set_state_dynamic_init(TraceEvent *ev, bool state) void trace_event_set_state_dynamic(TraceEvent *ev, bool state) { TraceEventID id; + bool state_pre; assert(trace_event_get_state_static(ev)); id = trace_event_get_id(ev); - trace_events_enabled_count += state - trace_events_dstate[id]; - trace_events_dstate[id] = state; + /* + * We ignore the "vcpu" property here, since there's no target code. Then + * dstate can only be 1 or 0. + */ + state_pre = trace_events_dstate[id]; + if (state_pre != state) { + if (state) { + trace_events_enabled_count++; + trace_events_dstate[id] = 1; + } else { + trace_events_enabled_count--; + trace_events_dstate[id] = 0; + } + } } void trace_event_set_vcpu_state_dynamic(CPUState *vcpu, diff --git a/trace/control-target.c b/trace/control-target.c index 4ee3733662..72081e2a34 100644 --- a/trace/control-target.c +++ b/trace/control-target.c @@ -16,10 +16,22 @@ void trace_event_set_state_dynamic_init(TraceEvent *ev, bool state) { TraceEventID id = trace_event_get_id(ev); + bool state_pre; assert(trace_event_get_state_static(ev)); - /* Ignore "vcpu" property, since no vCPUs have been created yet */ - trace_events_enabled_count += state - trace_events_dstate[id]; - trace_events_dstate[id] = state; + /* + * We ignore the "vcpu" property here, since no vCPUs have been created + * yet. Then dstate can only be 1 or 0. + */ + state_pre = trace_events_dstate[id]; + if (state_pre != state) { + if (state) { + trace_events_enabled_count++; + trace_events_dstate[id] = 1; + } else { + trace_events_enabled_count--; + trace_events_dstate[id] = 0; + } + } } void trace_event_set_state_dynamic(TraceEvent *ev, bool state) @@ -31,9 +43,18 @@ void trace_event_set_state_dynamic(TraceEvent *ev, bool state) trace_event_set_vcpu_state_dynamic(vcpu, ev, state); } } else { + /* Without the "vcpu" property, dstate can only be 1 or 0 */ TraceEventID id = trace_event_get_id(ev); - trace_events_enabled_count += state - trace_events_dstate[id]; - trace_events_dstate[id] = state; + bool state_pre = trace_events_dstate[id]; + if (state_pre != state) { + if (state) { + trace_events_enabled_count++; + trace_events_dstate[id] = 1; + } else { + trace_events_enabled_count--; + trace_events_dstate[id] = 0; + } + } } }