This is a hacky patch for comment but I've included the diagnostic
hacks to the migration test as well as my workaround to get itworking.

This test was failing on my KVM system. On investigation I found the
nVME activity meant the migration never completed. I ended up
inserting some sleeps into the workload script until I was able to
get it to run.

*NOTE*: obviously this can't be merged as is but I think we could
certainly do with more tracking in the test to see when things aren't
working with possibly the sleep as another patch.

Signed-off-by: Alex Bennée <alex.bennee@linaro.org>
---
 tests/functional/migration.py                 | 37 +++++++++++++++----
 .../functional/x86_64/test_nvme_migration.py  |  1 +
 2 files changed, 31 insertions(+), 7 deletions(-)

diff --git a/tests/functional/migration.py b/tests/functional/migration.py
index 8d2428efc24..e51a82c22f4 100644
--- a/tests/functional/migration.py
+++ b/tests/functional/migration.py
@@ -22,18 +22,41 @@ class MigrationTest(QemuSystemTest):
     timeout = 10
 
     @staticmethod
-    def migration_finished(vm):
-        return vm.cmd('query-migrate')['status'] in ('completed', 'failed')
+    def migration_finished(query):
+        return query['status'] in ('completed', 'failed')
 
-    def assert_migration(self, src_vm, dst_vm):
+    def wait_for_vm(self, src_or_dst, vm):
+        "Track the state of one VM in the migration"
+        current_state = last_state = vm.cmd('query-migrate')
 
-        end = time.monotonic() + self.timeout
-        while time.monotonic() < end and not self.migration_finished(src_vm):
-            time.sleep(0.1)
+        self.log.info(f"waiting for {src_or_dst} to complete")
 
         end = time.monotonic() + self.timeout
-        while time.monotonic() < end and not self.migration_finished(dst_vm):
+        while time.monotonic() < end:
+            if self.migration_finished(current_state):
+                break
+            else:
+                last_remain = last_state['remaining']
+                current_remain = current_state['remaining']
+
+                if current_remain > last_remain:
+                    self.log.warning(f"slow migration {current_remain} > {last_remain}")
+
             time.sleep(0.1)
+            last_state = current_state
+            current_state = vm.cmd('query-migrate')
+
+
+    def assert_migration(self, src_vm, dst_vm):
+
+        self.wait_for_vm("src", src_vm)
+
+        # if we hit this we never completed...
+        self.assertEqual(src_vm.cmd('query-migrate')['status'], 'completed')
+
+        self.wait_for_vm("dst", dst_vm)
+
+        self.log.info("checking everything is OK")
 
         self.assertEqual(src_vm.cmd('query-migrate')['status'], 'completed')
         self.assertEqual(dst_vm.cmd('query-migrate')['status'], 'completed')
diff --git a/tests/functional/x86_64/test_nvme_migration.py b/tests/functional/x86_64/test_nvme_migration.py
index 890f0aab6d6..58596f63cd3 100755
--- a/tests/functional/x86_64/test_nvme_migration.py
+++ b/tests/functional/x86_64/test_nvme_migration.py
@@ -109,6 +109,7 @@ def launch_source_vm(self, vm):
                 rm -f /tmp/test_nvme_mig_workload.iter_finished; \
                 echo 3 > /proc/sys/vm/drop_caches; \
                 find /usr/bin -type f -exec cksum {} \\;; \
+                sleep 0.3; \
                 touch /tmp/test_nvme_mig_workload.iter_finished; \
             done) > /dev/null 2> /tmp/test_nvme_mig_workload.errors &",
             prompt, vm=vm)
-- 
2.47.3