Introduce "info migrate-times" monitor command

This accidentally didn't go to the list although it's been sent there (using git send-email)...

Michal

-------- Original Message --------
Subject: [PATCH] Introduce "info migrate-times" monitor command
Date: Tue, 12 Jul 2011 15:28:27 +0200
From: Michal Novotny <[email protected]>
To: [email protected]
CC: Michal Novotny <[email protected]>, Michal Novotny
<[email protected]>

From: Michal Novotny <[email protected]>

Hi,
this is the implementation of the "info migrate-times" command I did to get the times for the migration to get times for each migration stage. Based on the fact migration itself is just the vmsave on the source host and vmload on destination host this function can be also useful to get the save times however it's main purpose is measuring the migration times therefore it's called "info migrate-times". The total memory transferred during the last migration is being tracked there as well as total migration time, time of waiting for input data, times for various migration stages for total value, disk (if applicable) and ram memory transfer. There's also the time difference which is the inaccuracy value which is caused by block device flushing and also the qemu_get_clock_ns() is being used in there and subsequent calls of this function may result into minor inaccuracies (in the matter smaller than of milliseconds).

I also did the testing with various migration speed settings (using the set_migrate_speed monitor command) for 7 GiB RHEL-6 i386 guest running bonnie++ test for 14 GiB (2x RAM) and the results were as follows:

Max.speed | Memory transferred | Time (s)
--------------+-----------------------------+----------------

     32m      |       12 925 676 bytes      |      199 s
     64m      |        7 745 224 bytes      |       26 s
    128m      |        7 674 188 bytes      |       16 s
    256m      |        7 628 988 bytes      |       16 s
    512m      |        7 599 837 bytes      |       15 s
  1024m (1g)  |        7 592 934 bytes      |       14 s
     10g      |        7 583 824 bytes      |       13 s

This has been tested on the 1 GiB network using the remote migration.

The output of the command for last iteration (shown as an example was):

(qemu) info migrate-times
Total transferred memory: 7583824 kbytes
Total migration time: 13.552894 s
Waiting for input data: 6.942414 s
Time difference (inaccuracy): 0.018257 s
Times for total stage 1: 0.020247 s
Times for total stage 2: 6.355092 s
Times for total stage 3: 0.253398 s
Times for total total: 6.628737 s
Times for ram stage 1: 0.020238 s
Times for ram stage 2: 6.353832 s
Times for ram stage 3: 0.228953 s
Times for ram total: 6.603023 s
(qemu)

So please review. This patch could be useful for getting the migration stage times.

Thanks,
Michal

---
 arch_init.c       |   12 +++++-
 block-migration.c |    5 ++
 migration.c       |  105 +++++++++++++++++++++++++++++++++++++++++++++
 migration.h       |    4 ++
 monitor.c         |    8 +++
 savevm.c          |   50 ++++++++++++++++++---
 sysemu.h          |    6 +++
 vl.c              |  123 +++++++++++++++++++++++++++++++++++++++++++++++++++++
 8 files changed, 305 insertions(+), 8 deletions(-)

index 484b39d..684ae3c 100644
@@ -252,8 +252,12 @@ int ram_save_live(Monitor *mon, QEMUFile *f, int stage, void *opaque)
 {
     ram_addr_t addr;
     uint64_t bytes_transferred_last;
+    uint64_t t_start;
     double bwidth = 0;
     uint64_t expected_time = 0;
+    int retval = 0;
+
+    t_start = qemu_get_clock_ns(host_clock);
 
     if (stage < 0) {
         cpu_physical_memory_set_dirty_tracking(0);

@@ -272,6 +276,10 @@ int ram_save_live(Monitor *mon, QEMUFile *f, int stage, void *opaque)
         last_offset = 0;
         sort_ram_list();
 
+        time_set("ram", 1, 0);
+        time_set("ram", 2, 0);
+        time_set("ram", 3, 0);
+
         /* Make sure all dirty bits are set */
         QLIST_FOREACH(block, &ram_list.blocks, next) {
             for (addr = block->offset; addr < block->offset + block->length;

@@ -331,8 +339,10 @@ int ram_save_live(Monitor *mon, QEMUFile *f, int stage, void *opaque)
     qemu_put_be64(f, RAM_SAVE_FLAG_EOS);
 
     expected_time = ram_save_remaining() * TARGET_PAGE_SIZE / bwidth;
+    retval = (stage == 2) && (expected_time <= migrate_max_downtime());
 
-    return (stage == 2) && (expected_time <= migrate_max_downtime());
+    time_add2("ram", stage, qemu_get_clock_ns(host_clock), t_start);
+    return retval;
 }
 
 static inline void *host_from_stream_offset(QEMUFile *f,

index 0936c7d..b53a1f4 100644
@@ -17,6 +17,8 @@
 #include "qemu-queue.h"
 #include "qemu-timer.h"
 #include "monitor.h"
+#include "qemu-timer.h"
+#include "sysemu.h"
 #include "block-migration.h"
 #include "migration.h"
 #include "blockdev.h"

@@ -556,6 +558,7 @@ static void blk_mig_cleanup(Monitor *mon)
 
 static int block_save_live(Monitor *mon, QEMUFile *f, int stage, void *opaque)
 {
+    uint64_t t_start = qemu_get_clock_ns(host_clock);
     DPRINTF("Enter save live stage %d submitted %d transferred %d\n",
             stage, block_mig_state.submitted, block_mig_state.transferred);
 

@@ -633,6 +636,8 @@ static int block_save_live(Monitor *mon, QEMUFile *f, int stage, void *opaque)
 
     qemu_put_be64(f, BLK_MIG_FLAG_EOS);
 
+    time_add2("disk", stage, qemu_get_clock_ns(host_clock), t_start);
+
     return ((stage == 2) && is_stage2_completed());
 }
 

index 050c56c..ef61f3f 100644
@@ -70,6 +70,10 @@ void do_info_migrate_print(Monitor *mon, const QObject *data);
 
 void do_info_migrate(Monitor *mon, QObject **ret_data);
 
+void do_info_migrate_times_print(Monitor *mon, const QObject *data);
+
+void do_info_migrate_times(Monitor *mon, QObject **ret_data);
+
 int exec_start_incoming_migration(const char *host_port);
 
 MigrationState *exec_start_outgoing_migration(Monitor *mon,

index 67ceb46..ac555f3 100644
@@ -3060,6 +3060,14 @@ static const mon_cmd_t info_cmds[] = {
         .mhandler.info_new = do_info_migrate,
     },
     {
+        .name       = "migrate-times",
+        .args_type  = "",
+        .params     = "",
+        .help       = "show migration times",
+        .user_print = do_info_migrate_times_print,
+        .mhandler.info_new = do_info_migrate_times,
+    },
+    {
         .name       = "balloon",
         .args_type  = "",
         .params     = "",

index d3013f5..c533706 100644
@@ -77,6 +77,12 @@ int qemu_savevm_state_complete(Monitor *mon, QEMUFile *f);
 void qemu_savevm_state_cancel(Monitor *mon, QEMUFile *f);
 int qemu_loadvm_state(QEMUFile *f);
 
+uint64_t time_get(const char *name, int stage);
+void time_set(const char *name, int stage, uint64_t tv);
+void time_add(const char *name, int stage, uint64_t tv);
+void time_add2(const char *name, int stage, uint64_t time1, uint64_t time2);
+uint64_t save_total_time(void);
+
 /* SLIRP */
 void do_info_slirp(Monitor *mon);
 

1.7.3.2

Please resend cleanly, so that git-am commits with a reasonable commit message, not some crap like this:

commit 1f5de40943d4ce9c18d7f9d8b0070a755d7babb5

Author: Michal Novotny <[email protected]>
Date:   Tue Jul 12 16:17:59 2011 +0200

Fwd: [PATCH] Introduce "info migrate-times" monitor command

This accidentally didn't go to the list although it's been sent there (using git send-email)...

Michal

-------- Original Message --------
Subject: [PATCH] Introduce "info migrate-times" monitor command
Date: Tue, 12 Jul 2011 15:28:27 +0200
From: Michal Novotny <[email protected]>
To: [email protected]
CC: Michal Novotny <[email protected]>, Michal Novotny
<[email protected]>

From: Michal Novotny <[email protected]>

Hi,
this is the implementation of the "info migrate-times" command
[...]

Hi Markus,
I'd like to but when I tried to send it to the [email protected] using git send-email just a copy was going to my mailbox but nothing was going to the qemu-devel list. Any idea what may be wrong and how to fix it?

Thanks,
Michal

Michal Novotny <[email protected]>, RHCE, Red Hat
Virtualization | libvirt-php bindings | php-virt-control.org