[PATCH 0/5] trace: inroduce qmp: trace namespace

[PATCH 0/5] trace: inroduce qmp: trace namespace

[Vladimir Sementsov-Ogievskiy]

Hi all!

We have handle_qmp_command and qmp_command_repond trace points to trace
qmp commands. They are very useful to debug problems involving
management tools like libvirt.

But tracing all qmp commands is too much.

Here I suggest a kind of tracing namespace. Formally this series adds a
trace points called qmp:<some-command> for every command, which may be
enabled in separate like

  --trace qmp:drive-backup

or by pattern like

  --trace qmp:block-job-*

or similarly with help of qmp command trace-event-set-state.

This also allows to enable tracing of some qmp commands permanently
 (by downstream patch or in libvirt xml). For example, I'm going to
enable tracing of block job comamnds and blockdev-* commands in
Virtuozzo. Qemu logs are often too empty (for example, in comparison
with Libvirt), logging block jobs is not too much but will be very
helpful.

Vladimir Sementsov-Ogievskiy (5):
  trace/control: introduce trace_opt_parse_opts()
  qapi/qmp: QmpCommand: add .tracing field and API
  monitor: add qmp tracing API for qmp_commands
  util/qemu-option: make qemu_opt_del_all() function public
  trace: add qmp trace event namespace

 include/monitor/monitor.h   |  3 +++
 include/qapi/qmp/dispatch.h | 14 ++++++++++++++
 include/qemu/option.h       |  1 +
 trace/control.h             |  7 +++++++
 monitor/qmp.c               | 10 ++++++++++
 qapi/qmp-dispatch.c         | 20 ++++++++++++++++++++
 qapi/qmp-registry.c         | 27 +++++++++++++++++++++++++++
 softmmu/vl.c                | 21 ++++++++++++++++++++-
 trace/control.c             | 18 ++++++++++++------
 trace/qmp.c                 | 20 ++++++++++++++++++++
 util/qemu-option.c          |  2 +-
 qapi/trace-events           |  2 ++
 12 files changed, 137 insertions(+), 8 deletions(-)

-- 
2.29.2

[PATCH 1/5] trace/control: introduce trace_opt_parse_opts()

[Vladimir Sementsov-Ogievskiy]

Add a function same as trace_opt_parse, but parameter is QemuOpts.

Signed-off-by: Vladimir Sementsov-Ogievskiy <vsementsov@virtuozzo.com>
---
 trace/control.h |  7 +++++++
 trace/control.c | 18 ++++++++++++------
 2 files changed, 19 insertions(+), 6 deletions(-)

diff --git a/trace/control.h b/trace/control.h
index 23b8393b29..fb898e2c4a 100644
--- a/trace/control.h
+++ b/trace/control.h
@@ -251,6 +251,13 @@ extern QemuOptsList qemu_trace_opts;
  */
 void trace_opt_parse(const char *optarg);
 
+/**
+ * Same as trace_opt_parse, but accept QemuOpts instead of options string.
+ *
+ * Releases @opts at the end.
+ */
+void trace_opt_parse_opts(QemuOpts *opts);
+
 /**
  * trace_get_vcpu_event_count:
  *
diff --git a/trace/control.c b/trace/control.c
index d5b68e846e..4bcbd96511 100644
--- a/trace/control.c
+++ b/trace/control.c
@@ -313,13 +313,8 @@ bool trace_init_backends(void)
     return true;
 }
 
-void trace_opt_parse(const char *optarg)
+void trace_opt_parse_opts(QemuOpts *opts)
 {
-    QemuOpts *opts = qemu_opts_parse_noisily(qemu_find_opts("trace"),
-                                             optarg, true);
-    if (!opts) {
-        exit(1);
-    }
     if (qemu_opt_get(opts, "enable")) {
         trace_enable_events(qemu_opt_get(opts, "enable"));
     }
@@ -330,6 +325,17 @@ void trace_opt_parse(const char *optarg)
     qemu_opts_del(opts);
 }
 
+void trace_opt_parse(const char *optarg)
+{
+    QemuOpts *opts = qemu_opts_parse_noisily(qemu_find_opts("trace"),
+                                             optarg, true);
+    if (!opts) {
+        exit(1);
+    }
+
+    trace_opt_parse_opts(opts);
+}
+
 uint32_t trace_get_vcpu_event_count(void)
 {
     return next_vcpu_id;
-- 
2.29.2

[PATCH 2/5] qapi/qmp: QmpCommand: add .tracing field and API

[Vladimir Sementsov-Ogievskiy]

We are going to add a possibility to trace some qmp commands by user
selection. For now add a new field to QmpCommand structure and two
functions to manipulate with it.

Signed-off-by: Vladimir Sementsov-Ogievskiy <vsementsov@virtuozzo.com>
---
 include/qapi/qmp/dispatch.h | 14 ++++++++++++++
 qapi/qmp-registry.c         | 27 +++++++++++++++++++++++++++
 2 files changed, 41 insertions(+)

diff --git a/include/qapi/qmp/dispatch.h b/include/qapi/qmp/dispatch.h
index 075203dc67..5d0df2f984 100644
--- a/include/qapi/qmp/dispatch.h
+++ b/include/qapi/qmp/dispatch.h
@@ -38,6 +38,7 @@ typedef struct QmpCommand
     QTAILQ_ENTRY(QmpCommand) node;
     bool enabled;
     const char *disable_reason;
+    bool tracing;
 } QmpCommand;
 
 typedef QTAILQ_HEAD(QmpCommandList, QmpCommand) QmpCommandList;
@@ -64,4 +65,17 @@ typedef void (*qmp_cmd_callback_fn)(const QmpCommand *cmd, void *opaque);
 void qmp_for_each_command(const QmpCommandList *cmds, qmp_cmd_callback_fn fn,
                           void *opaque);
 
+/*
+ * Enable or disable tracing for commands matching the pattern.
+ * Pattern matching is handled by g_pattern_match_simple().
+ */
+void qmp_commands_set_tracing(QmpCommandList *cmds, const char *pattern,
+                              bool enable);
+
+/*
+ * Return true if tracing is enabled for any command matching the pattern.
+ * If pattern is NULL, return true if tracing is enabled for any command.
+ */
+bool qmp_commands_is_tracing_enabled(QmpCommandList *cmds, const char *pattern);
+
 #endif
diff --git a/qapi/qmp-registry.c b/qapi/qmp-registry.c
index f78c064aae..56e761857b 100644
--- a/qapi/qmp-registry.c
+++ b/qapi/qmp-registry.c
@@ -67,6 +67,33 @@ void qmp_enable_command(QmpCommandList *cmds, const char *name)
     qmp_toggle_command(cmds, name, true, NULL);
 }
 
+void qmp_commands_set_tracing(QmpCommandList *cmds, const char *pattern,
+                              bool enable)
+{
+    QmpCommand *cmd;
+
+    QTAILQ_FOREACH(cmd, cmds, node) {
+        if (g_pattern_match_simple(pattern, cmd->name)) {
+            cmd->tracing = true;
+        }
+    }
+}
+
+bool qmp_commands_is_tracing_enabled(QmpCommandList *cmds, const char *pattern)
+{
+    QmpCommand *cmd;
+
+    QTAILQ_FOREACH(cmd, cmds, node) {
+        if (cmd->tracing &&
+            (!pattern || g_pattern_match_simple(pattern, cmd->name)))
+        {
+            return true;
+        }
+    }
+
+    return false;
+}
+
 bool qmp_command_is_enabled(const QmpCommand *cmd)
 {
     return cmd->enabled;
-- 
2.29.2

[PATCH 3/5] monitor: add qmp tracing API for qmp_commands

[Vladimir Sementsov-Ogievskiy]

Add wrappers to manipulate with .tracing in qmp_commands list.

Signed-off-by: Vladimir Sementsov-Ogievskiy <vsementsov@virtuozzo.com>
---
 include/monitor/monitor.h |  3 +++
 monitor/qmp.c             | 10 ++++++++++
 2 files changed, 13 insertions(+)

diff --git a/include/monitor/monitor.h b/include/monitor/monitor.h
index 1a8a369b50..9587998217 100644
--- a/include/monitor/monitor.h
+++ b/include/monitor/monitor.h
@@ -54,4 +54,7 @@ int64_t monitor_fdset_dup_fd_find(int dup_fd);
 void monitor_register_hmp(const char *name, bool info,
                           void (*cmd)(Monitor *mon, const QDict *qdict));
 
+bool monitor_qmp_is_tracing_enabled(const char *pattern);
+void monitor_qmp_set_tracing(const char *pattern, bool enable);
+
 #endif /* MONITOR_H */
diff --git a/monitor/qmp.c b/monitor/qmp.c
index 092c527b6f..def2c7d1da 100644
--- a/monitor/qmp.c
+++ b/monitor/qmp.c
@@ -536,3 +536,13 @@ void monitor_init_qmp(Chardev *chr, bool pretty, Error **errp)
         monitor_list_append(&mon->common);
     }
 }
+
+void monitor_qmp_set_tracing(const char *pattern, bool enable)
+{
+    qmp_commands_set_tracing(&qmp_commands, pattern, enable);
+}
+
+bool monitor_qmp_is_tracing_enabled(const char *pattern)
+{
+    return qmp_commands_is_tracing_enabled(&qmp_commands, pattern);
+}
-- 
2.29.2

[PATCH 4/5] util/qemu-option: make qemu_opt_del_all() function public

[Vladimir Sementsov-Ogievskiy]

To be used in the following commit.

Signed-off-by: Vladimir Sementsov-Ogievskiy <vsementsov@virtuozzo.com>
---
 include/qemu/option.h | 1 +
 util/qemu-option.c    | 2 +-
 2 files changed, 2 insertions(+), 1 deletion(-)

diff --git a/include/qemu/option.h b/include/qemu/option.h
index 306bf07575..4ba88f2632 100644
--- a/include/qemu/option.h
+++ b/include/qemu/option.h
@@ -71,6 +71,7 @@ struct QemuOptsList {
 
 const char *qemu_opt_get(QemuOpts *opts, const char *name);
 char *qemu_opt_get_del(QemuOpts *opts, const char *name);
+void qemu_opt_del_all(QemuOpts *opts, const char *name);
 /**
  * qemu_opt_has_help_opt:
  * @opts: options to search for a help request
diff --git a/util/qemu-option.c b/util/qemu-option.c
index 61cb4a97bd..2c75cc2e46 100644
--- a/util/qemu-option.c
+++ b/util/qemu-option.c
@@ -244,7 +244,7 @@ static void qemu_opt_del(QemuOpt *opt)
 /* qemu_opt_set allows many settings for the same option.
  * This function deletes all settings for an option.
  */
-static void qemu_opt_del_all(QemuOpts *opts, const char *name)
+void qemu_opt_del_all(QemuOpts *opts, const char *name)
 {
     QemuOpt *opt, *next_opt;
 
-- 
2.29.2

[PATCH 5/5] trace: add qmp trace event namespace

[Vladimir Sementsov-Ogievskiy]

Add a possibility to trace some qmp commands by user selection.

User API is simple: it looks like after this patch we have trace-points
for all qmp commands, in format "qmp:<qmp-command>". So user may do

  --trace qmp:drive-backup

or run qmp command trace-event-set-state with arguments

  name="qmp:drive-backup", enable=true

Patterns are supported in the same way as for general trace events, for
example:

  --trace "qmp:query-*"

to cover query-block, query-block-jobs, and a lot of other query-
commands

or

  --trace "qmp:job-*" --trace "qmp:block-job-*"

to cover job manipulation commands.

Trace event qmp covers both qmp command call and its respond.

Implementation details:

In qmp_dispatch() we add two trace points, similar to
trace_handle_qmp_command. We also check for cmd->tracking field being
set, and for handle-qmp-command/monitor-qmp-respond trace points being
disabled, to not print same information twice.

For qmp trace-event-{get,set}-state and for command line
parse additionally new "qmp:" namespace

Signed-off-by: Vladimir Sementsov-Ogievskiy <vsementsov@virtuozzo.com>
---
 qapi/qmp-dispatch.c | 20 ++++++++++++++++++++
 softmmu/vl.c        | 21 ++++++++++++++++++++-
 trace/qmp.c         | 20 ++++++++++++++++++++
 qapi/trace-events   |  2 ++
 4 files changed, 62 insertions(+), 1 deletion(-)

diff --git a/qapi/qmp-dispatch.c b/qapi/qmp-dispatch.c
index 59600210ce..40fd008fa8 100644
--- a/qapi/qmp-dispatch.c
+++ b/qapi/qmp-dispatch.c
@@ -26,6 +26,9 @@
 #include "qemu/coroutine.h"
 #include "qemu/main-loop.h"
 
+#include "trace.h"
+#include "trace/trace-monitor.h"
+
 CompatPolicy compat_policy;
 
 Visitor *qobject_input_visitor_new_qmp(QObject *obj)
@@ -133,6 +136,12 @@ static void do_qmp_dispatch_bh(void *opaque)
     aio_co_wake(data->co);
 }
 
+static void do_trace_qmp(const char *what, QObject *obj)
+{
+    g_autoptr(GString) req_json = qobject_to_json(obj);
+    trace_qmp(what, req_json->str);
+}
+
 /*
  * Runs outside of coroutine context for OOB commands, but in coroutine
  * context for everything else.
@@ -176,6 +185,11 @@ QDict *qmp_dispatch(const QmpCommandList *cmds, QObject *request,
                   "The command %s has not been found", command);
         goto out;
     }
+    if (!trace_event_get_state_backends(TRACE_HANDLE_QMP_COMMAND) &&
+        trace_event_get_state_backends(TRACE_QMP) && cmd->tracing)
+    {
+        do_trace_qmp(">>", request);
+    }
     if (cmd->options & QCO_DEPRECATED) {
         switch (compat_policy.deprecated_input) {
         case COMPAT_POLICY_INPUT_ACCEPT:
@@ -282,5 +296,11 @@ out:
         qdict_put_obj(rsp, "id", qobject_ref(id));
     }
 
+    if (!trace_event_get_state_backends(TRACE_MONITOR_QMP_RESPOND) &&
+        trace_event_get_state_backends(TRACE_QMP) && cmd->tracing)
+    {
+        do_trace_qmp("<<", QOBJECT(rsp));
+    }
+
     return rsp;
 }
diff --git a/softmmu/vl.c b/softmmu/vl.c
index 55ab70eb97..fd452b7013 100644
--- a/softmmu/vl.c
+++ b/softmmu/vl.c
@@ -2722,6 +2722,25 @@ void qmp_x_exit_preconfig(Error **errp)
     }
 }
 
+static void trace_opt_parse_with_qmp(const char *optarg)
+{
+    const char *pattern;
+    QemuOpts *opts = qemu_opts_parse_noisily(qemu_find_opts("trace"),
+                                             optarg, true);
+    if (!opts) {
+        exit(1);
+    }
+
+    pattern = qemu_opt_get(opts, "enable");
+    if (pattern && !strncmp(pattern, "qmp:", 4)) {
+        monitor_qmp_set_tracing(pattern + 4, true);
+        qemu_opt_del_all(opts, "enable");
+        qemu_opt_set(opts, "enable", "qmp", &error_abort);
+    }
+
+    trace_opt_parse_opts(opts);
+}
+
 void qemu_init(int argc, char **argv, char **envp)
 {
     QemuOpts *opts;
@@ -3480,7 +3499,7 @@ void qemu_init(int argc, char **argv, char **envp)
                 xen_domid_restrict = true;
                 break;
             case QEMU_OPTION_trace:
-                trace_opt_parse(optarg);
+                trace_opt_parse_with_qmp(optarg);
                 break;
             case QEMU_OPTION_plugin:
                 qemu_plugin_opt_parse(optarg, &plugin_list);
diff --git a/trace/qmp.c b/trace/qmp.c
index 3b4f4702b4..87766422d9 100644
--- a/trace/qmp.c
+++ b/trace/qmp.c
@@ -11,6 +11,7 @@
 #include "qapi/error.h"
 #include "qapi/qapi-commands-trace.h"
 #include "control-vcpu.h"
+#include "monitor/monitor.h"
 
 
 static CPUState *get_cpu(bool has_vcpu, int vcpu, Error **errp)
@@ -77,6 +78,14 @@ TraceEventInfoList *qmp_trace_event_get_state(const char *name,
     bool is_pattern = trace_event_is_pattern(name);
     CPUState *cpu;
 
+    if (!strncmp(name, "qmp:", 4)) {
+        if (!monitor_qmp_is_tracing_enabled(name + 4)) {
+            return NULL;
+        }
+
+        return qmp_trace_event_get_state("qmp", has_vcpu, vcpu, errp);
+    }
+
     /* Check provided vcpu */
     cpu = get_cpu(has_vcpu, vcpu, &err);
     if (err) {
@@ -139,6 +148,17 @@ void qmp_trace_event_set_state(const char *name, bool enable,
     bool is_pattern = trace_event_is_pattern(name);
     CPUState *cpu;
 
+    if (!strncmp(name, "qmp:", 4)) {
+        monitor_qmp_set_tracing(name + 4, enable);
+
+        if (enable || !monitor_qmp_is_tracing_enabled(NULL)) {
+            qmp_trace_event_set_state("qmp", enable, has_ignore_unavailable,
+                                      ignore_unavailable, has_vcpu, vcpu, errp);
+        }
+
+        return;
+    }
+
     /* Check provided vcpu */
     cpu = get_cpu(has_vcpu, vcpu, &err);
     if (err) {
diff --git a/qapi/trace-events b/qapi/trace-events
index cccafc07e5..753433856c 100644
--- a/qapi/trace-events
+++ b/qapi/trace-events
@@ -36,3 +36,5 @@ visit_type_str(void *v, const char *name, char **obj) "v=%p name=%s obj=%p"
 visit_type_number(void *v, const char *name, void *obj) "v=%p name=%s obj=%p"
 visit_type_any(void *v, const char *name, void *obj) "v=%p name=%s obj=%p"
 visit_type_null(void *v, const char *name, void *obj) "v=%p name=%s obj=%p"
+
+qmp(const char *what, const char *json) "%s %s"
-- 
2.29.2

Re: [PATCH 0/5] trace: inroduce qmp: trace namespace

[Markus Armbruster]

Vladimir Sementsov-Ogievskiy <vsementsov@virtuozzo.com> writes:

> Hi all!
>
> We have handle_qmp_command and qmp_command_repond trace points to trace
> qmp commands. They are very useful to debug problems involving
> management tools like libvirt.
>
> But tracing all qmp commands is too much.
>
> Here I suggest a kind of tracing namespace. Formally this series adds a
> trace points called qmp:<some-command> for every command, which may be
> enabled in separate like
>
>   --trace qmp:drive-backup
>
> or by pattern like
>
>   --trace qmp:block-job-*
>
> or similarly with help of qmp command trace-event-set-state.
>
> This also allows to enable tracing of some qmp commands permanently
>  (by downstream patch or in libvirt xml). For example, I'm going to
> enable tracing of block job comamnds and blockdev-* commands in
> Virtuozzo. Qemu logs are often too empty (for example, in comparison
> with Libvirt), logging block jobs is not too much but will be very
> helpful.

What exactly is traced?  Peeking at PATCH 5... looks like it's input
that makes it to qmp_dispatch() and command responses, but not events.

Fine print on "input that makes it to qmp_dispatch()":

* You trace right before we execute the command, not when we receive,
  parse and enqueue input.

* Corollary: input with certain errors is not traced.

* You don't trace the input text, you trace the unparsed parse tree.

All fine, I presume.

Existing tracepoints in monitor/qmp.c, and what information they send
(inessential bits omitted for clarity):

* handle_qmp_command

  Handling a QMP command: unparsed parse tree

  Fine print, safe to ignore:

  - Out-of-band commands will be executed right away, in-band commands
    will be queued.  Tracepoints monitor_qmp_in_band_enqueue and
    monitor_qmp_in_band_dequeue provide insight into that.

  - This also receives and queues parse errors, without tracing them.
    Tracepoint monitor_qmp_err_in_band traces them as they are dequeued.

* monitor_qmp_cmd_in_band

  About to execute in-band command: command ID, if any

* monitor_qmp_cmd_out_of_band

  About to execute out-of-band command: command ID, if any

* monitor_qmp_respond

  About to send command response or event: QObject

For input, --trace qmp:* is like --trace handle_qmp_command, except it
traces late rather than early.

For output, --trace qmp:* is like --trace monitor_qmp_respond less
events.

The main improvement over existing tracepoints seems to be the ability
to filter on command names.

To get that, you overload the @name argument of QMP command
trace-event-set-state.  In addition to the documented meaning "Event
name pattern", it also has an alternate, undocumented meaning "QMP
command name pattern".  The "undocumented" part is easy enough to fix.
However, QMP heavily frowns on argument values that need to be parsed.
But before we discuss this in depth, we should decide whether we want
the filtering feature.

Management applications can enable and disable tracing as needed, but
doing it all in QEMU might be more convenient or robust.

Libvirt logs all QMP traffic.  I doubt it'll make use of your filtering
feature.  Cc'ing libvir-list just in case.

Another way to log all traffic is to route it through socat -x or
similar.

Opinions?

Re: [PATCH 0/5] trace: inroduce qmp: trace namespace

[Vladimir Sementsov-Ogievskiy]

12.10.2021 14:49, Markus Armbruster wrote:
> Vladimir Sementsov-Ogievskiy <vsementsov@virtuozzo.com> writes:
> 
>> Hi all!
>>
>> We have handle_qmp_command and qmp_command_repond trace points to trace
>> qmp commands. They are very useful to debug problems involving
>> management tools like libvirt.
>>
>> But tracing all qmp commands is too much.
>>
>> Here I suggest a kind of tracing namespace. Formally this series adds a
>> trace points called qmp:<some-command> for every command, which may be
>> enabled in separate like
>>
>>    --trace qmp:drive-backup
>>
>> or by pattern like
>>
>>    --trace qmp:block-job-*
>>
>> or similarly with help of qmp command trace-event-set-state.
>>
>> This also allows to enable tracing of some qmp commands permanently
>>   (by downstream patch or in libvirt xml). For example, I'm going to
>> enable tracing of block job comamnds and blockdev-* commands in
>> Virtuozzo. Qemu logs are often too empty (for example, in comparison
>> with Libvirt), logging block jobs is not too much but will be very
>> helpful.
> 
> What exactly is traced?  Peeking at PATCH 5... looks like it's input
> that makes it to qmp_dispatch() and command responses, but not events.
> 
> Fine print on "input that makes it to qmp_dispatch()":
> 
> * You trace right before we execute the command, not when we receive,
>    parse and enqueue input.
> 
> * Corollary: input with certain errors is not traced.
> 
> * You don't trace the input text, you trace the unparsed parse tree.
> 
> All fine, I presume.
> 
> Existing tracepoints in monitor/qmp.c, and what information they send
> (inessential bits omitted for clarity):
> 
> * handle_qmp_command
> 
>    Handling a QMP command: unparsed parse tree
> 
>    Fine print, safe to ignore:
> 
>    - Out-of-band commands will be executed right away, in-band commands
>      will be queued.  Tracepoints monitor_qmp_in_band_enqueue and
>      monitor_qmp_in_band_dequeue provide insight into that.
> 
>    - This also receives and queues parse errors, without tracing them.
>      Tracepoint monitor_qmp_err_in_band traces them as they are dequeued.
> 
> * monitor_qmp_cmd_in_band
> 
>    About to execute in-band command: command ID, if any
> 
> * monitor_qmp_cmd_out_of_band
> 
>    About to execute out-of-band command: command ID, if any
> 
> * monitor_qmp_respond
> 
>    About to send command response or event: QObject
> 
> For input, --trace qmp:* is like --trace handle_qmp_command, except it
> traces late rather than early.
> 
> For output, --trace qmp:* is like --trace monitor_qmp_respond less
> events.
> 
> The main improvement over existing tracepoints seems to be the ability
> to filter on command names.
> 
> To get that, you overload the @name argument of QMP command
> trace-event-set-state.  In addition to the documented meaning "Event
> name pattern", it also has an alternate, undocumented meaning "QMP
> command name pattern".  The "undocumented" part is easy enough to fix.
> However, QMP heavily frowns on argument values that need to be parsed.

Still, pattern is parsed anyway, as pattern. But yes, this patch adds
rather specific and tricky logic, which a lot more than just a pattern
to search through the list.

Another possible way is to update QAPI code generator to insert a personal
trace point for each qmp command.. That seems more complicated to implement,
but I can try.

> But before we discuss this in depth, we should decide whether we want
> the filtering feature.
> 
> Management applications can enable and disable tracing as needed, but
> doing it all in QEMU might be more convenient or robust.
> 
> Libvirt logs all QMP traffic.

I am not sure.. At lest in Vz7 (based on RH7) it doesn't.. Is something changed in new versions?

For example, I run a migration by virsh. In libvirtd.log I see migration events, but don't see the "migrate" command itself, neither migrate-set-parameters / migrate-set-capabilities..

So, I never could rely on libvirt logs in this area, and we usually use Qemu tracing to debug QMP traffic.

Also, Libvirt is not the only source of QMP traffic.. In Vz7 backup is done separately. I do backup of VM. In vm log I see drive-backup trace point. In Libvirt I see only "new connection, client: /usr/libexec/vz_backup_client <cmdline follows>"..

>  I doubt it'll make use of your filtering
> feature.  Cc'ing libvir-list just in case.
> 
> Another way to log all traffic is to route it through socat -x or
> similar.
> 
> Opinions?
> 

The benefit of Qemu tracepoints, is that you can enable them independently of any environment/management tool.

-- 
Best regards,
Vladimir

Re: [PATCH 0/5] trace: inroduce qmp: trace namespace

[Stefan Hajnoczi]

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

On Thu, Oct 14, 2021 at 06:22:32PM +0300, Vladimir Sementsov-Ogievskiy wrote:
> 12.10.2021 14:49, Markus Armbruster wrote:
> > Vladimir Sementsov-Ogievskiy <vsementsov@virtuozzo.com> writes:
> > 
> > > Hi all!
> > > 
> > > We have handle_qmp_command and qmp_command_repond trace points to trace
> > > qmp commands. They are very useful to debug problems involving
> > > management tools like libvirt.
> > > 
> > > But tracing all qmp commands is too much.
> > > 
> > > Here I suggest a kind of tracing namespace. Formally this series adds a
> > > trace points called qmp:<some-command> for every command, which may be
> > > enabled in separate like
> > > 
> > >    --trace qmp:drive-backup
> > > 
> > > or by pattern like
> > > 
> > >    --trace qmp:block-job-*
> > > 
> > > or similarly with help of qmp command trace-event-set-state.
> > > 
> > > This also allows to enable tracing of some qmp commands permanently
> > >   (by downstream patch or in libvirt xml). For example, I'm going to
> > > enable tracing of block job comamnds and blockdev-* commands in
> > > Virtuozzo. Qemu logs are often too empty (for example, in comparison
> > > with Libvirt), logging block jobs is not too much but will be very
> > > helpful.
> > 
> > What exactly is traced?  Peeking at PATCH 5... looks like it's input
> > that makes it to qmp_dispatch() and command responses, but not events.
> > 
> > Fine print on "input that makes it to qmp_dispatch()":
> > 
> > * You trace right before we execute the command, not when we receive,
> >    parse and enqueue input.
> > 
> > * Corollary: input with certain errors is not traced.
> > 
> > * You don't trace the input text, you trace the unparsed parse tree.
> > 
> > All fine, I presume.
> > 
> > Existing tracepoints in monitor/qmp.c, and what information they send
> > (inessential bits omitted for clarity):
> > 
> > * handle_qmp_command
> > 
> >    Handling a QMP command: unparsed parse tree
> > 
> >    Fine print, safe to ignore:
> > 
> >    - Out-of-band commands will be executed right away, in-band commands
> >      will be queued.  Tracepoints monitor_qmp_in_band_enqueue and
> >      monitor_qmp_in_band_dequeue provide insight into that.
> > 
> >    - This also receives and queues parse errors, without tracing them.
> >      Tracepoint monitor_qmp_err_in_band traces them as they are dequeued.
> > 
> > * monitor_qmp_cmd_in_band
> > 
> >    About to execute in-band command: command ID, if any
> > 
> > * monitor_qmp_cmd_out_of_band
> > 
> >    About to execute out-of-band command: command ID, if any
> > 
> > * monitor_qmp_respond
> > 
> >    About to send command response or event: QObject
> > 
> > For input, --trace qmp:* is like --trace handle_qmp_command, except it
> > traces late rather than early.
> > 
> > For output, --trace qmp:* is like --trace monitor_qmp_respond less
> > events.
> > 
> > The main improvement over existing tracepoints seems to be the ability
> > to filter on command names.
> > 
> > To get that, you overload the @name argument of QMP command
> > trace-event-set-state.  In addition to the documented meaning "Event
> > name pattern", it also has an alternate, undocumented meaning "QMP
> > command name pattern".  The "undocumented" part is easy enough to fix.
> > However, QMP heavily frowns on argument values that need to be parsed.
> 
> Still, pattern is parsed anyway, as pattern. But yes, this patch adds
> rather specific and tricky logic, which a lot more than just a pattern
> to search through the list.
> 
> Another possible way is to update QAPI code generator to insert a personal
> trace point for each qmp command.. That seems more complicated to implement,
> but I can try.

That's what came to mind when I saw this series too. The QAPI generator
can create a trace event for each QMP command. That way each command has
a dedicated trace event that can be enabled/disabled in the usual way
(e.g. built-in "trace" monitor command, SystemTap scripts, etc) without
introducing special syntax.

Stefan

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

Re: [PATCH 0/5] trace: inroduce qmp: trace namespace

[Markus Armbruster]

Stefan Hajnoczi <stefanha@redhat.com> writes:

> On Thu, Oct 14, 2021 at 06:22:32PM +0300, Vladimir Sementsov-Ogievskiy wrote:
>> 12.10.2021 14:49, Markus Armbruster wrote:
>> > Vladimir Sementsov-Ogievskiy <vsementsov@virtuozzo.com> writes:

[...]

>> Another possible way is to update QAPI code generator to insert a personal
>> trace point for each qmp command.. That seems more complicated to implement,
>> but I can try.
>
> That's what came to mind when I saw this series too. The QAPI generator
> can create a trace event for each QMP command. That way each command has
> a dedicated trace event that can be enabled/disabled in the usual way
> (e.g. built-in "trace" monitor command, SystemTap scripts, etc) without
> introducing special syntax.

I like how this way stays entirely within the existing interface.  I
couldn't tell you how to implement it, though :)