From: Olaf Hering Date: Thu, 4 Feb 2021 20:33:53 +0100 Subject: libxc sr track migration time Track live migration state unconditionally in logfiles to see how long a domU was suspended. Signed-off-by: Olaf Hering --- tools/include/xentoollog.h | 1 + tools/libs/ctrl/xc_domain.c | 12 +++++-- tools/libs/ctrl/xc_private.h | 9 +++++ tools/libs/guest/xg_resume.c | 5 ++- tools/libs/guest/xg_sr_common.c | 59 ++++++++++++++++++++++++++++++++ tools/libs/guest/xg_sr_common.h | 3 ++ tools/libs/guest/xg_sr_restore.c | 3 ++ tools/libs/guest/xg_sr_save.c | 6 +++- tools/xl/xl.c | 2 ++ 9 files changed, 96 insertions(+), 4 deletions(-) --- a/tools/include/xentoollog.h +++ b/tools/include/xentoollog.h @@ -133,6 +133,7 @@ const char *xtl_level_to_string(xentooll }); +#define XL_NO_SUSEINFO "XL_NO_SUSEINFO" #endif /* XENTOOLLOG_H */ /* --- a/tools/libs/ctrl/xc_domain.c +++ b/tools/libs/ctrl/xc_domain.c @@ -66,20 +66,28 @@ int xc_domain_cacheflush(xc_interface *x int xc_domain_pause(xc_interface *xch, uint32_t domid) { + int ret; struct xen_domctl domctl = {}; domctl.cmd = XEN_DOMCTL_pausedomain; domctl.domain = domid; - return do_domctl(xch, &domctl); + ret = do_domctl(xch, &domctl); + if (getenv(XL_NO_SUSEINFO) == NULL) + SUSEINFO("domid %u: %s returned %d", domid, __func__, ret); + return ret; } int xc_domain_unpause(xc_interface *xch, uint32_t domid) { + int ret; struct xen_domctl domctl = {}; domctl.cmd = XEN_DOMCTL_unpausedomain; domctl.domain = domid; - return do_domctl(xch, &domctl); + ret = do_domctl(xch, &domctl); + if (getenv(XL_NO_SUSEINFO) == NULL) + SUSEINFO("domid %u: %s returned %d", domid, __func__, ret); + return ret; } --- a/tools/libs/ctrl/xc_private.h +++ b/tools/libs/ctrl/xc_private.h @@ -42,6 +42,15 @@ #include +/* + * Using loglevel ERROR to make sure the intended informational messages appear + * in libvirts libxl-driver.log + */ +#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 --- a/tools/libs/guest/xg_resume.c +++ b/tools/libs/guest/xg_resume.c @@ -259,7 +259,10 @@ 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)); + if (getenv(XL_NO_SUSEINFO) == NULL) + SUSEINFO("domid %u: %s%s returned %d", domid, __func__, fast ? " fast" : "", ret); + return ret; } --- a/tools/libs/guest/xg_sr_common.c +++ b/tools/libs/guest/xg_sr_common.c @@ -163,6 +163,65 @@ static void __attribute__((unused)) buil BUILD_BUG_ON(sizeof(struct xc_sr_rec_hvm_params) != 8); } +/* 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'; +} + /* * Expand the tracking structures as needed. * To avoid realloc()ing too excessively, the size increased to the nearest --- a/tools/libs/guest/xg_sr_common.h +++ b/tools/libs/guest/xg_sr_common.h @@ -294,6 +294,7 @@ struct xc_sr_context xc_stream_type_t stream_type; xc_domaininfo_t dominfo; + char uuid[16*2+4+1]; union /* Common save or restore data. */ { @@ -505,6 +506,8 @@ extern struct xc_sr_save_ops save_ops_x8 extern struct xc_sr_restore_ops restore_ops_x86_pv; extern struct xc_sr_restore_ops restore_ops_x86_hvm; +extern void sr_uuid_to_string(char *dest, const uint8_t *uuid); + struct xc_sr_record { uint32_t type; --- a/tools/libs/guest/xg_sr_restore.c +++ b/tools/libs/guest/xg_sr_restore.c @@ -871,6 +871,8 @@ static int restore(struct xc_sr_context struct xc_sr_rhdr rhdr; int rc, saved_rc = 0, saved_errno = 0; + SUSEINFO("domid %u: %s %s start", ctx->domid, ctx->uuid, __func__); + DPRINTF("domid %u: max_pages %lx tot_pages %lx p2m_size %lx", ctx->domid, ctx->restore.max_pages, ctx->restore.tot_pages, ctx->restore.p2m_size); IPRINTF("Restoring domain"); rc = setup(ctx); @@ -946,6 +948,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 ) @@ -1011,6 +1014,7 @@ int xc_domain_restore(xc_interface *xch, io_fd, dom, hvm, stream_type); ctx.domid = dom; + sr_uuid_to_string(ctx.uuid, ctx.dominfo.handle); if ( read_headers(&ctx) ) return -1; --- a/tools/libs/guest/xg_sr_save.c +++ b/tools/libs/guest/xg_sr_save.c @@ -353,7 +353,7 @@ static void show_transfer_rate(struct xc MiB_sec = (ctx->save.pages_sent * PAGE_SIZE * 1000U) / ms / (1024U*1024U); errno = 0; - IPRINTF("%s: %zu bytes + %zu pages in %ld.%09ld sec, %zu MiB/sec", __func__, + SUSEINFO("domid %u: %zu bytes + %zu pages in %ld.%09ld sec, %zu MiB/sec", ctx->domid, ctx->save.overhead_sent, ctx->save.pages_sent, diff.tv_sec, diff.tv_nsec, MiB_sec); } @@ -875,13 +875,16 @@ static int save(struct xc_sr_context *ct { xc_interface *xch = ctx->xch; int rc, saved_rc = 0, saved_errno = 0; + unsigned long tot_pages = ctx->dominfo.tot_pages; + SUSEINFO("domid %u: %s %s start, %lu pages allocated", ctx->domid, ctx->uuid, __func__, tot_pages); IPRINTF("Saving domain %d, type %s", ctx->domid, dhdr_type_to_str(guest_type)); rc = setup(ctx); if ( rc ) goto err; + SUSEINFO("domid %u: p2m_size %lx", ctx->domid, ctx->save.p2m_size); xc_report_progress_single(xch, "Start of stream"); @@ -995,6 +998,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 ) @@ -1054,6 +1058,7 @@ int xc_domain_save(xc_interface *xch, in io_fd, dom, flags, hvm); ctx.domid = dom; + sr_uuid_to_string(ctx.uuid, ctx.dominfo.handle); if ( hvm ) { --- a/tools/xl/xl.c +++ b/tools/xl/xl.c @@ -424,6 +424,8 @@ int main(int argc, char **argv) logger = xtl_createlogger_stdiostream(stderr, minmsglevel, xtl_flags); if (!logger) exit(EXIT_FAILURE); + /* Provide context to libxl and libxc: no SUSEINFO() from xl */ + setenv(XL_NO_SUSEINFO, "1", 0); xl_ctx_alloc(); atexit(xl_ctx_free);