Track live migration state unconditionally in logfiles to see how long a domU was suspended.
Depends on libxc.sr.superpage.patch

--- a/tools/libxc/xc_domain.c
+++ b/tools/libxc/xc_domain.c
@@ -91,20 +91,26 @@ int xc_domain_cacheflush(xc_interface *x
 int xc_domain_pause(xc_interface *xch,
                     uint32_t domid)
 {
+    int ret;
     DECLARE_DOMCTL;
     domctl.cmd = XEN_DOMCTL_pausedomain;
     domctl.domain = (domid_t)domid;
-    return do_domctl(xch, &domctl);
+    ret = do_domctl(xch, &domctl);
+    SUSEINFO("domid %u: %s returned %d", domid, __func__, ret);
+    return ret;
 }
 
 
 int xc_domain_unpause(xc_interface *xch,
                       uint32_t domid)
 {
+    int ret;
     DECLARE_DOMCTL;
     domctl.cmd = XEN_DOMCTL_unpausedomain;
     domctl.domain = (domid_t)domid;
-    return do_domctl(xch, &domctl);
+    ret = do_domctl(xch, &domctl);
+    SUSEINFO("domid %u: %s returned %d", domid, __func__, ret);
+    return ret;
 }
 
 
--- a/tools/libxc/xc_private.h
+++ b/tools/libxc/xc_private.h
@@ -40,6 +40,11 @@
 
 #include <xen/sys/privcmd.h>
 
+#define SUSEINFO(_m, _a...)  do { int ERROR_errno = errno; \
+        xc_report(xch, xch->error_handler, XTL_ERROR, XC_ERROR_NONE, "SUSEINFO: " _m , ## _a ); \
+        errno = ERROR_errno; \
+        } while (0)
+
 #if defined(HAVE_VALGRIND_MEMCHECK_H) && !defined(NDEBUG) && !defined(__MINIOS__)
 /* Compile in Valgrind client requests? */
 #include <valgrind/memcheck.h>
--- a/tools/libxc/xc_resume.c
+++ b/tools/libxc/xc_resume.c
@@ -284,7 +284,9 @@ out:
  */
 int xc_domain_resume(xc_interface *xch, uint32_t domid, int fast)
 {
-    return (fast
+    int ret = (fast
             ? xc_domain_resume_cooperative(xch, domid)
             : xc_domain_resume_any(xch, domid));
+    SUSEINFO("domid %u: %s%s returned %d", domid, __func__, fast ? " fast" : "", ret);
+    return ret;
 }
--- a/tools/libxc/xc_sr_common.c
+++ b/tools/libxc/xc_sr_common.c
@@ -196,6 +196,65 @@ bool _xc_sr_bitmap_resize(struct xc_sr_b
     return true;
 }
 
+/* Write a two-character hex representation of 'byte' to digits[].
+   Pre-condition: sizeof(digits) >= 2 */
+static void byte_to_hex(char *digits, const uint8_t byte)
+{
+    uint8_t nybbel = byte >> 4;
+
+    if ( nybbel > 9 )
+        digits[0] = 'a' + nybbel-10;
+    else
+        digits[0] = '0' + nybbel;
+
+    nybbel = byte & 0x0f;
+    if ( nybbel > 9 )
+        digits[1] = 'a' + nybbel-10;
+    else
+        digits[1] = '0' + nybbel;
+}
+
+/* Convert an array of 16 unsigned bytes to a DCE/OSF formatted UUID
+   string.
+
+   Pre-condition: sizeof(dest) >= 37 */
+void sr_uuid_to_string(char *dest, const uint8_t *uuid)
+{
+    int i = 0;
+    char *p = dest;
+
+    for (; i < 4; i++ )
+    {
+        byte_to_hex(p, uuid[i]);
+        p += 2;
+    }
+    *p++ = '-';
+    for (; i < 6; i++ )
+    {
+        byte_to_hex(p, uuid[i]);
+        p += 2;
+    }
+    *p++ = '-';
+    for (; i < 8; i++ )
+    {
+        byte_to_hex(p, uuid[i]);
+        p += 2;
+    }
+    *p++ = '-';
+    for (; i < 10; i++ )
+    {
+        byte_to_hex(p, uuid[i]);
+        p += 2;
+    }
+    *p++ = '-';
+    for (; i < 16; i++ )
+    {
+        byte_to_hex(p, uuid[i]);
+        p += 2;
+    }
+    *p = '\0';
+}
+
 /*
  * Local variables:
  * mode: C
--- a/tools/libxc/xc_sr_common.h
+++ b/tools/libxc/xc_sr_common.h
@@ -195,6 +195,7 @@ struct xc_sr_context
     int fd;
 
     xc_dominfo_t dominfo;
+    char uuid[16*2+4+1];
 
     union /* Common save or restore data. */
     {
@@ -430,6 +431,8 @@ static inline int pfn_set_populated(stru
     return 0;
 }
 
+extern void sr_uuid_to_string(char *dest, const uint8_t *uuid);
+
 struct xc_sr_record
 {
     uint32_t type;
--- a/tools/libxc/xc_sr_restore.c
+++ b/tools/libxc/xc_sr_restore.c
@@ -608,6 +608,7 @@ static int restore(struct xc_sr_context
     struct xc_sr_record rec;
     int rc, saved_rc = 0, saved_errno = 0;
 
+    SUSEINFO("domid %u: %s %s start", ctx->domid, ctx->uuid, __func__);
     IPRINTF("Restoring domain");
 
     rc = setup(ctx);
@@ -684,6 +685,7 @@ static int restore(struct xc_sr_context
     PERROR("Restore failed");
 
  done:
+    SUSEINFO("domid %u: %s done", ctx->domid, __func__);
     cleanup(ctx);
 
     if ( saved_rc )
@@ -749,6 +751,7 @@ int xc_domain_restore(xc_interface *xch,
     }
 
     ctx.domid = dom;
+    sr_uuid_to_string(ctx.uuid, ctx.dominfo.handle);
 
     if ( read_headers(&ctx) )
         return -1;
--- a/tools/libxc/xc_sr_save.c
+++ b/tools/libxc/xc_sr_save.c
@@ -498,6 +498,8 @@ static int send_memory_live(struct xc_sr
             rc = -1;
             goto out;
         }
+        SUSEINFO("domid %u: dirty pages %u after iteration %u/%u",
+                ctx->domid, stats.dirty_count, x, ctx->save.max_iterations);
 
         if ( stats.dirty_count == 0 )
             break;
@@ -518,6 +520,10 @@ static int send_memory_live(struct xc_sr
                __func__,
                stats.dirty_count, ctx->save.dirty_threshold, x);
     }
+    else if (!rc) {
+        SUSEINFO("domid %u: suspending, remaining dirty pages %u prior final transit",
+                ctx->domid, stats.dirty_count);
+    }
 
  out:
     xc_set_progress_prefix(xch, NULL);
@@ -800,6 +806,7 @@ static int save(struct xc_sr_context *ct
     xc_interface *xch = ctx->xch;
     int rc, saved_rc = 0, saved_errno = 0;
 
+    SUSEINFO("domid %u: %s %s start, %lu pages allocated", ctx->domid, ctx->uuid, __func__, ctx->dominfo.nr_pages);
     IPRINTF("Saving domain %d, type %s",
             ctx->domid, dhdr_type_to_str(guest_type));
 
@@ -912,6 +919,7 @@ static int save(struct xc_sr_context *ct
     PERROR("Save failed");
 
  done:
+    SUSEINFO("domid %u: %s done", ctx->domid, __func__);
     cleanup(ctx);
 
     if ( saved_rc )
@@ -981,6 +989,7 @@ int xc_domain_save_suse(xc_interface *xc
     }
 
     ctx.domid = dom;
+    sr_uuid_to_string(ctx.uuid, ctx.dominfo.handle);
 
     if ( ctx.dominfo.hvm )
     {
