Merge "Improve message and logging for corrupt VHD footers"

1 files changed, 39 insertions, 15 deletions

diff --git a/plugins/xenserver/xenapi/etc/xapi.d/plugins/utils.py b/plugins/xenserver/xenapi/etc/xapi.d/plugins/utils.py
index 411d52a2f..95f01bba3 100644
--- a/plugins/xenserver/xenapi/etc/xapi.d/plugins/utils.py
+++ b/plugins/xenserver/xenapi/etc/xapi.d/plugins/utils.py
@@ -15,6 +15,7 @@
 """Various utilities used by XenServer plugins."""
 
 import cPickle as pickle
+import errno
 import logging
 import os
 import shlex
@@ -24,6 +25,7 @@ import tempfile
 
 import XenAPIPlugin
 
+LOG = logging.getLogger(__name__)
 CHUNK_SIZE = 8192
 
 
@@ -32,18 +34,18 @@ def delete_if_exists(path):
         os.unlink(path)
     except OSError, e:
         if e.errno == errno.ENOENT:
-            logging.warning("'%s' was already deleted, skipping delete" % path)
+            LOG.warning("'%s' was already deleted, skipping delete" % path)
         else:
             raise
 
 
 def _link(src, dst):
-    logging.info("Hard-linking file '%s' -> '%s'" % (src, dst))
+    LOG.info("Hard-linking file '%s' -> '%s'" % (src, dst))
     os.link(src, dst)
 
 
 def _rename(src, dst):
-    logging.info("Renaming file '%s' -> '%s'" % (src, dst))
+    LOG.info("Renaming file '%s' -> '%s'" % (src, dst))
     os.rename(src, dst)
 
 
@@ -54,14 +56,14 @@ def make_subprocess(cmdline, stdout=False, stderr=False, stdin=False,
     # NOTE(dprince): shlex python 2.4 doesn't like unicode so we
     # explicitly convert to ascii
     cmdline = cmdline.encode('ascii')
-    logging.info("Running cmd '%s'" % cmdline)
+    LOG.info("Running cmd '%s'" % cmdline)
     kwargs = {}
     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)
+    LOG.info("Running args '%s'" % args)
     proc = subprocess.Popen(args, **kwargs)
     return proc
 
@@ -162,7 +164,7 @@ def _assert_vhd_not_hidden(path):
     out, err = finish_subprocess(query_proc, query_cmd)
 
     for line in out.splitlines():
-        if line.startswith('hidden'):
+        if line.lower().startswith('hidden'):
             value = line.split(':')[1].strip()
             if value == "1":
                 raise Exception(
@@ -170,8 +172,13 @@ def _assert_vhd_not_hidden(path):
                     locals())
 
 
-def _validate_footer_timestamp(vdi_path):
+def _validate_vhd(vdi_path):
     """
+    This checks for several errors in the VHD structure.
+
+    Most notably, it checks that the timestamp in the footer is correct, but
+    may pick up other errors also.
+
     This check ensures that the timestamps listed in the VHD footer aren't in
     the future.  This can occur during a migration if the clocks on the the two
     Dom0's are out-of-sync. This would corrupt the SR if it were imported, so
@@ -183,13 +190,30 @@ def _validate_footer_timestamp(vdi_path):
             check_proc, check_cmd, ok_exit_codes=[0, 22])
     first_line = out.splitlines()[0].strip()
 
-    if 'primary footer invalid' in first_line:
-        raise Exception("VDI '%(vdi_path)s' has timestamp in the future,"
-                        " ensure source and destination host machines have"
-                        " time set correctly" % locals())
-    elif check_proc.returncode != 0:
-        raise Exception("Unexpected output '%(out)s' from vhd-util" %
-                        locals())
+    if 'invalid' in first_line:
+        if 'footer' in first_line:
+            part = 'footer'
+        elif 'header' in first_line:
+            part = 'header'
+        else:
+            part = 'setting'
+
+        details = first_line.split(':', 1)
+        if len(details) == 2:
+            details = details[1]
+        else:
+            details = first_line
+
+        extra = ''
+        if 'timestamp' in first_line:
+            extra = (" ensure source and destination host machines have "
+                     "time set correctly")
+
+        LOG.info("VDI Error details: %s" % out)
+
+        raise Exception(
+            "VDI '%(vdi_path)s' has an invalid %(part)s: '%(details)s'"
+            "%(extra)s" % locals())
 
 
 def _validate_vdi_chain(vdi_path):
@@ -219,7 +243,7 @@ def _validate_vdi_chain(vdi_path):
 
     cur_path = vdi_path
     while cur_path:
-        _validate_footer_timestamp(cur_path)
+        _validate_vhd(cur_path)
         cur_path = get_parent_path(cur_path)