[Qemu-devel] [PATCH v2 0/3] Migration tracing and errors

[Qemu-devel] [PATCH v2 0/3] Migration tracing and errors

[Dr. David Alan Gilbert (git)]

From: "Dr. David Alan Gilbert" <dgilbert@redhat.com>

Tidy up some old printfs
Add some more error_reports that previously just failed with invalid.
Add lots and lots of tracing.

Dr. David Alan Gilbert (3):
  savevm: Convert fprintf to error_report
  Migration: Add lots of trace events
  Print errors in some of the early migration failure cases.

 migration/vmstate.c | 31 ++++++++++++++++++++++++-------
 savevm.c            | 38 ++++++++++++++++++++++++--------------
 trace-events        | 11 ++++++++++-
 3 files changed, 58 insertions(+), 22 deletions(-)

-- 

v2
   Fix missing ret initialisation
2.1.0

[Qemu-devel] [PATCH v2 1/3] savevm: Convert fprintf to error_report

[Dr. David Alan Gilbert (git)]

From: "Dr. David Alan Gilbert" <dgilbert@redhat.com>

Convert a bunch of fprintfs to error_reports

Signed-off-by: Dr. David Alan Gilbert <dgilbert@redhat.com>
---
 migration/vmstate.c |  7 ++++---
 savevm.c            | 21 +++++++++++----------
 2 files changed, 15 insertions(+), 13 deletions(-)

diff --git a/migration/vmstate.c b/migration/vmstate.c
index 3dde574..2c0b135 100644
--- a/migration/vmstate.c
+++ b/migration/vmstate.c
@@ -3,6 +3,7 @@
 #include "migration/qemu-file.h"
 #include "migration/vmstate.h"
 #include "qemu/bitops.h"
+#include "qemu/error-report.h"
 #include "trace.h"
 
 static void vmstate_subsection_save(QEMUFile *f, const VMStateDescription *vmsd,
@@ -122,8 +123,8 @@ int vmstate_load_state(QEMUFile *f, const VMStateDescription *vmsd,
                 }
             }
         } else if (field->flags & VMS_MUST_EXIST) {
-            fprintf(stderr, "Input validation failed: %s/%s\n",
-                    vmsd->name, field->name);
+            error_report("Input validation failed: %s/%s",
+                         vmsd->name, field->name);
             return -1;
         }
         field++;
@@ -167,7 +168,7 @@ void vmstate_save_state(QEMUFile *f, const VMStateDescription *vmsd,
             }
         } else {
             if (field->flags & VMS_MUST_EXIST) {
-                fprintf(stderr, "Output state validation failed: %s/%s\n",
+                error_report("Output state validation failed: %s/%s",
                         vmsd->name, field->name);
                 assert(!(field->flags & VMS_MUST_EXIST));
             }
diff --git a/savevm.c b/savevm.c
index 08ec678..48c2396 100644
--- a/savevm.c
+++ b/savevm.c
@@ -898,7 +898,7 @@ int qemu_loadvm_state(QEMUFile *f)
 
     v = qemu_get_be32(f);
     if (v == QEMU_VM_FILE_VERSION_COMPAT) {
-        fprintf(stderr, "SaveVM v2 format is obsolete and don't work anymore\n");
+        error_report("SaveVM v2 format is obsolete and don't work anymore");
         return -ENOTSUP;
     }
     if (v != QEMU_VM_FILE_VERSION) {
@@ -925,15 +925,16 @@ int qemu_loadvm_state(QEMUFile *f)
             /* Find savevm section */
             se = find_se(idstr, instance_id);
             if (se == NULL) {
-                fprintf(stderr, "Unknown savevm section or instance '%s' %d\n", idstr, instance_id);
+                error_report("Unknown savevm section or instance '%s' %d",
+                             idstr, instance_id);
                 ret = -EINVAL;
                 goto out;
             }
 
             /* Validate version */
             if (version_id > se->version_id) {
-                fprintf(stderr, "savevm: unsupported version %d for '%s' v%d\n",
-                        version_id, idstr, se->version_id);
+                error_report("savevm: unsupported version %d for '%s' v%d",
+                             version_id, idstr, se->version_id);
                 ret = -EINVAL;
                 goto out;
             }
@@ -948,8 +949,8 @@ int qemu_loadvm_state(QEMUFile *f)
 
             ret = vmstate_load(f, le->se, le->version_id);
             if (ret < 0) {
-                fprintf(stderr, "qemu: warning: error while loading state for instance 0x%x of device '%s'\n",
-                        instance_id, idstr);
+                error_report("error while loading state for instance 0x%x of"
+                             " device '%s'", instance_id, idstr);
                 goto out;
             }
             break;
@@ -963,20 +964,20 @@ int qemu_loadvm_state(QEMUFile *f)
                 }
             }
             if (le == NULL) {
-                fprintf(stderr, "Unknown savevm section %d\n", section_id);
+                error_report("Unknown savevm section %d", section_id);
                 ret = -EINVAL;
                 goto out;
             }
 
             ret = vmstate_load(f, le->se, le->version_id);
             if (ret < 0) {
-                fprintf(stderr, "qemu: warning: error while loading state section id %d\n",
-                        section_id);
+                error_report("error while loading state section id %d(%s)",
+                             section_id, le->se->idstr);
                 goto out;
             }
             break;
         default:
-            fprintf(stderr, "Unknown savevm section type %d\n", section_type);
+            error_report("Unknown savevm section type %d", section_type);
             ret = -EINVAL;
             goto out;
         }
-- 
2.1.0

[Qemu-devel] [PATCH v2 2/3] Migration: Add lots of trace events

[Dr. David Alan Gilbert (git)]

From: "Dr. David Alan Gilbert" <dgilbert@redhat.com>

Mostly on the load side, so that when we get a complaint about
a migration failure we can figure out what it didn't like.

Signed-off-by: Dr. David Alan Gilbert <dgilbert@redhat.com>
---
 migration/vmstate.c | 24 ++++++++++++++++++++----
 savevm.c            | 10 +++++++---
 trace-events        | 11 ++++++++++-
 3 files changed, 37 insertions(+), 8 deletions(-)

diff --git a/migration/vmstate.c b/migration/vmstate.c
index 2c0b135..dae5dd6 100644
--- a/migration/vmstate.c
+++ b/migration/vmstate.c
@@ -73,16 +73,21 @@ int vmstate_load_state(QEMUFile *f, const VMStateDescription *vmsd,
                        void *opaque, int version_id)
 {
     VMStateField *field = vmsd->fields;
-    int ret;
+    int ret = 0;
 
+    trace_vmstate_load_state(vmsd->name, version_id);
     if (version_id > vmsd->version_id) {
+        trace_vmstate_load_state_end(vmsd->name, "too new", -EINVAL);
         return -EINVAL;
     }
     if  (version_id < vmsd->minimum_version_id) {
         if (vmsd->load_state_old &&
             version_id >= vmsd->minimum_version_id_old) {
-            return vmsd->load_state_old(f, opaque, version_id);
+            ret = vmsd->load_state_old(f, opaque, version_id);
+            trace_vmstate_load_state_end(vmsd->name, "old path", ret);
+            return ret;
         }
+        trace_vmstate_load_state_end(vmsd->name, "too old", -EINVAL);
         return -EINVAL;
     }
     if (vmsd->pre_load) {
@@ -92,6 +97,7 @@ int vmstate_load_state(QEMUFile *f, const VMStateDescription *vmsd,
         }
     }
     while (field->name) {
+        trace_vmstate_load_state_field(vmsd->name, field->name);
         if ((field->field_exists &&
              field->field_exists(opaque, version_id)) ||
             (!field->field_exists &&
@@ -134,9 +140,10 @@ int vmstate_load_state(QEMUFile *f, const VMStateDescription *vmsd,
         return ret;
     }
     if (vmsd->post_load) {
-        return vmsd->post_load(opaque, version_id);
+        ret = vmsd->post_load(opaque, version_id);
     }
-    return 0;
+    trace_vmstate_load_state_end(vmsd->name, "end", ret);
+    return ret;
 }
 
 void vmstate_save_state(QEMUFile *f, const VMStateDescription *vmsd,
@@ -193,6 +200,8 @@ static const VMStateDescription *
 static int vmstate_subsection_load(QEMUFile *f, const VMStateDescription *vmsd,
                                    void *opaque)
 {
+    trace_vmstate_subsection_load(vmsd->name);
+
     while (qemu_peek_byte(f, 0) == QEMU_VM_SUBSECTION) {
         char idstr[256];
         int ret;
@@ -202,20 +211,24 @@ static int vmstate_subsection_load(QEMUFile *f, const VMStateDescription *vmsd,
         len = qemu_peek_byte(f, 1);
         if (len < strlen(vmsd->name) + 1) {
             /* subsection name has be be "section_name/a" */
+            trace_vmstate_subsection_load_bad(vmsd->name, "(short)");
             return 0;
         }
         size = qemu_peek_buffer(f, (uint8_t *)idstr, len, 2);
         if (size != len) {
+            trace_vmstate_subsection_load_bad(vmsd->name, "(peek fail)");
             return 0;
         }
         idstr[size] = 0;
 
         if (strncmp(vmsd->name, idstr, strlen(vmsd->name)) != 0) {
+            trace_vmstate_subsection_load_bad(vmsd->name, idstr);
             /* it don't have a valid subsection name */
             return 0;
         }
         sub_vmsd = vmstate_get_subsection(vmsd->subsections, idstr);
         if (sub_vmsd == NULL) {
+            trace_vmstate_subsection_load_bad(vmsd->name, "(lookup)");
             return -ENOENT;
         }
         qemu_file_skip(f, 1); /* subsection */
@@ -225,9 +238,12 @@ static int vmstate_subsection_load(QEMUFile *f, const VMStateDescription *vmsd,
 
         ret = vmstate_load_state(f, sub_vmsd, opaque, version_id);
         if (ret) {
+            trace_vmstate_subsection_load_bad(vmsd->name, "(child)");
             return ret;
         }
     }
+
+    trace_vmstate_subsection_load_good(vmsd->name);
     return 0;
 }
 
diff --git a/savevm.c b/savevm.c
index 48c2396..1cc0f02 100644
--- a/savevm.c
+++ b/savevm.c
@@ -674,7 +674,7 @@ int qemu_savevm_state_iterate(QEMUFile *f)
         qemu_put_be32(f, se->section_id);
 
         ret = se->ops->save_live_iterate(f, se->opaque);
-        trace_savevm_section_end(se->idstr, se->section_id);
+        trace_savevm_section_end(se->idstr, se->section_id, ret);
 
         if (ret < 0) {
             qemu_file_set_error(f, ret);
@@ -714,7 +714,7 @@ void qemu_savevm_state_complete(QEMUFile *f)
         qemu_put_be32(f, se->section_id);
 
         ret = se->ops->save_live_complete(f, se->opaque);
-        trace_savevm_section_end(se->idstr, se->section_id);
+        trace_savevm_section_end(se->idstr, se->section_id, ret);
         if (ret < 0) {
             qemu_file_set_error(f, ret);
             return;
@@ -741,7 +741,7 @@ void qemu_savevm_state_complete(QEMUFile *f)
         qemu_put_be32(f, se->version_id);
 
         vmstate_save(f, se);
-        trace_savevm_section_end(se->idstr, se->section_id);
+        trace_savevm_section_end(se->idstr, se->section_id, 0);
     }
 
     qemu_put_byte(f, QEMU_VM_EOF);
@@ -911,6 +911,7 @@ int qemu_loadvm_state(QEMUFile *f)
         char idstr[257];
         int len;
 
+        trace_qemu_loadvm_state_section(section_type);
         switch (section_type) {
         case QEMU_VM_SECTION_START:
         case QEMU_VM_SECTION_FULL:
@@ -922,6 +923,8 @@ int qemu_loadvm_state(QEMUFile *f)
             instance_id = qemu_get_be32(f);
             version_id = qemu_get_be32(f);
 
+            trace_qemu_loadvm_state_section_startfull(section_id, idstr,
+                                                      instance_id, version_id);
             /* Find savevm section */
             se = find_se(idstr, instance_id);
             if (se == NULL) {
@@ -958,6 +961,7 @@ int qemu_loadvm_state(QEMUFile *f)
         case QEMU_VM_SECTION_END:
             section_id = qemu_get_be32(f);
 
+            trace_qemu_loadvm_state_section_partend(section_id);
             QLIST_FOREACH(le, &loadvm_handlers, entry) {
                 if (le->section_id == section_id) {
                     break;
diff --git a/trace-events b/trace-events
index 8acbcce..1bf57b3 100644
--- a/trace-events
+++ b/trace-events
@@ -1133,8 +1133,11 @@ vmware_scratch_write(uint32_t index, uint32_t value) "index %d, value 0x%x"
 vmware_setmode(uint32_t w, uint32_t h, uint32_t bpp) "%dx%d @ %d bpp"
 
 # savevm.c
+qemu_loadvm_state_section(unsigned int section_type) "%d"
+qemu_loadvm_state_section_partend(uint32_t section_id) "%u"
+qemu_loadvm_state_section_startfull(uint32_t section_id, const char *idstr, uint32_t instance_id, uint32_t version_id) "%u(%s) %u %u"
 savevm_section_start(const char *id, unsigned int section_id) "%s, section_id %u"
-savevm_section_end(const char *id, unsigned int section_id) "%s, section_id %u"
+savevm_section_end(const char *id, unsigned int section_id, int ret) "%s, section_id %u -> %d"
 savevm_state_begin(void) ""
 savevm_state_iterate(void) ""
 savevm_state_complete(void) ""
@@ -1145,6 +1148,12 @@ qemu_announce_self_iter(const char *mac) "%s"
 
 # vmstate.c
 vmstate_load_field_error(const char *field, int ret) "field \"%s\" load failed, ret = %d"
+vmstate_load_state(const char *name, int version_id) "%s v%d"
+vmstate_load_state_end(const char *name, const char *reason, int val) "%s %s/%d"
+vmstate_load_state_field(const char *name, const char *field) "%s:%s"
+vmstate_subsection_load(const char *parent) "%s"
+vmstate_subsection_load_bad(const char *parent,  const char *sub) "%s: %s"
+vmstate_subsection_load_good(const char *parent) "%s"
 
 # qemu-file.c
 qemu_file_fclose(void) ""
-- 
2.1.0

[Qemu-devel] [PATCH v2 3/3] Print errors in some of the early migration failure cases.

[Dr. David Alan Gilbert (git)]

From: "Dr. David Alan Gilbert" <dgilbert@redhat.com>

Signed-off-by: Dr. David Alan Gilbert <dgilbert@redhat.com>
---
 savevm.c | 7 ++++++-
 1 file changed, 6 insertions(+), 1 deletion(-)

diff --git a/savevm.c b/savevm.c
index 1cc0f02..98895fe 100644
--- a/savevm.c
+++ b/savevm.c
@@ -883,16 +883,20 @@ int qemu_loadvm_state(QEMUFile *f)
     QLIST_HEAD(, LoadStateEntry) loadvm_handlers =
         QLIST_HEAD_INITIALIZER(loadvm_handlers);
     LoadStateEntry *le, *new_le;
+    Error *local_err = NULL;
     uint8_t section_type;
     unsigned int v;
     int ret;
 
-    if (qemu_savevm_state_blocked(NULL)) {
+    if (qemu_savevm_state_blocked(&local_err)) {
+        error_report("%s", error_get_pretty(local_err));
+        error_free(local_err);
         return -EINVAL;
     }
 
     v = qemu_get_be32(f);
     if (v != QEMU_VM_FILE_MAGIC) {
+        error_report("Not a migration stream");
         return -EINVAL;
     }
 
@@ -902,6 +906,7 @@ int qemu_loadvm_state(QEMUFile *f)
         return -ENOTSUP;
     }
     if (v != QEMU_VM_FILE_VERSION) {
+        error_report("Unsupported migration stream version");
         return -ENOTSUP;
     }
 
-- 
2.1.0