xenapi: Adding logging for migration plugin

With this change administrators will be able to examine hypervisor
logs for real-time progress of rsync operations (resizes, migrates).

Change-Id: I463b574be1021e141fe2c8380b9c07f6cd860c78

2 files changed, 17 insertions, 4 deletions

diff --git a/plugins/xenserver/xenapi/etc/xapi.d/plugins/migration b/plugins/xenserver/xenapi/etc/xapi.d/plugins/migration
index 4b6bf8811..f98562126 100755
--- a/plugins/xenserver/xenapi/etc/xapi.d/plugins/migration
+++ b/plugins/xenserver/xenapi/etc/xapi.d/plugins/migration
@@ -40,9 +40,20 @@ def _rsync_vhds(instance_uuid, host, staging_path, user="root"):
 
     dest_path = '%s@%s:/images/instance%s/' % (user, host, instance_uuid)
 
-    rsync_cmd = "nohup /usr/bin/rsync -av -e %(ssh_cmd)s %(staging_path)s"\
-               " %(dest_path)s" % locals()
-    rsync_proc = utils.make_subprocess(rsync_cmd, stdout=True, stderr=True)
+    rsync_cmd = "/usr/bin/rsync -av --progress -e %(ssh_cmd)s "\
+        "%(staging_path)s %(dest_path)s" % locals()
+
+    # NOTE(hillad): rsync's progress is carriage returned, requiring
+    # universal_newlines for real-time output.
+
+    rsync_proc = utils.make_subprocess(rsync_cmd, stdout=True, stderr=True,
+                                       universal_newlines=True)
+    while True:
+        rsync_progress = rsync_proc.stdout.readline()
+        if not rsync_progress:
+            break
+        logging.debug(rsync_progress)
+
     utils.finish_subprocess(rsync_proc, rsync_cmd)
 
 
diff --git a/plugins/xenserver/xenapi/etc/xapi.d/plugins/utils.py b/plugins/xenserver/xenapi/etc/xapi.d/plugins/utils.py
index 510687d7b..c19b85c38 100644
--- a/plugins/xenserver/xenapi/etc/xapi.d/plugins/utils.py
+++ b/plugins/xenserver/xenapi/etc/xapi.d/plugins/utils.py
@@ -47,7 +47,8 @@ def _rename(src, dst):
     os.rename(src, dst)
 
 
-def make_subprocess(cmdline, stdout=False, stderr=False, stdin=False):
+def make_subprocess(cmdline, stdout=False, stderr=False, stdin=False,
+                    universal_newlines=False):
     """Make a subprocess according to the given command-line string
     """
     # NOTE(dprince): shlex python 2.4 doesn't like unicode so we
@@ -58,6 +59,7 @@ def make_subprocess(cmdline, stdout=False, stderr=False, stdin=False):
     kwargs['stdout'] = stdout and subprocess.PIPE or None
     kwargs['stderr'] = stderr and subprocess.PIPE or None
     kwargs['stdin'] = stdin and subprocess.PIPE or None
+    kwargs['universal_newlines'] = universal_newlines
     args = shlex.split(cmdline)
     logging.info("Running args '%s'" % args)
     proc = subprocess.Popen(args, **kwargs)