Merge "Handle image cache hashing on shared storage."

2 files changed, 119 insertions, 61 deletions

diff --git a/nova/virt/libvirt/imagecache.py b/nova/virt/libvirt/imagecache.py
index 865135340..634210a26 100644
--- a/nova/virt/libvirt/imagecache.py
+++ b/nova/virt/libvirt/imagecache.py
@@ -30,6 +30,7 @@ import time
 from nova.compute import task_states
 from nova.compute import vm_states
 from nova.openstack.common import cfg
+from nova.openstack.common import lockutils
 from nova.openstack.common import log as logging
 from nova import utils
 from nova.virt.libvirt import utils as virtutils
@@ -52,6 +53,9 @@ imagecache_opts = [
     cfg.BoolOpt('checksum_base_images',
                 default=False,
                 help='Write a checksum for files in _base to disk'),
+    cfg.IntOpt('checksum_interval_seconds',
+               default=3600,
+               help='How frequently to checksum base images'),
     ]
 
 CONF = cfg.CONF
@@ -61,27 +65,26 @@ CONF.import_opt('instances_path', 'nova.compute.manager')
 CONF.import_opt('base_dir_name', 'nova.compute.manager')
 
 
-def read_stored_checksum(target):
+def read_stored_checksum(target, timestamped=True):
     """Read the checksum.
 
     Returns the checksum (as hex) or None.
     """
-    return virtutils.read_stored_info(target, field='sha1')
+    return virtutils.read_stored_info(target, field='sha1',
+                                      timestamped=timestamped)
 
 
 def write_stored_checksum(target):
     """Write a checksum to disk for a file in _base."""
 
-    if not read_stored_checksum(target):
-        img_file = open(target, 'r')
+    with open(target, 'r') as img_file:
         checksum = utils.hash_file(img_file)
-        img_file.close()
-
-        virtutils.write_stored_info(target, field='sha1', value=checksum)
+    virtutils.write_stored_info(target, field='sha1', value=checksum)
 
 
 class ImageCacheManager(object):
     def __init__(self):
+        self.lock_path = os.path.join(CONF.instances_path, 'locks')
         self._reset_state()
 
     def _reset_state(self):
@@ -227,35 +230,61 @@ class ImageCacheManager(object):
         if not CONF.checksum_base_images:
             return None
 
-        stored_checksum = read_stored_checksum(base_file)
-        if stored_checksum:
-            f = open(base_file, 'r')
-            current_checksum = utils.hash_file(f)
-            f.close()
-
-            if current_checksum != stored_checksum:
-                LOG.error(_('%(id)s (%(base_file)s): image verification '
-                            'failed'),
-                          {'id': img_id,
-                           'base_file': base_file})
-                return False
+        lock_name = 'hash-%s' % os.path.split(base_file)[-1]
+
+        # Protect against other nova-computes performing checksums at the same
+        # time if we are using shared storage
+        @lockutils.synchronized(lock_name, 'nova-', external=True,
+                                lock_path=self.lock_path)
+        def inner_verify_checksum():
+            (stored_checksum, stored_timestamp) = read_stored_checksum(
+                base_file, timestamped=True)
+            if stored_checksum:
+                # NOTE(mikal): Checksums are timestamped. If we have recently
+                # checksummed (possibly on another compute node if we are using
+                # shared storage), then we don't need to checksum again.
+                if (stored_timestamp and
+                    time.time() - stored_timestamp <
+                    CONF.checksum_interval_seconds):
+                    return True
+
+                # NOTE(mikal): If there is no timestamp, then the checksum was
+                # performed by a previous version of the code.
+                if not stored_timestamp:
+                    virtutils.write_stored_info(base_file, field='sha1',
+                                                value=stored_checksum)
+
+                with open(base_file, 'r') as f:
+                    current_checksum = utils.hash_file(f)
+
+                if current_checksum != stored_checksum:
+                    LOG.error(_('%(id)s (%(base_file)s): image verification '
+                                'failed'),
+                              {'id': img_id,
+                               'base_file': base_file})
+                    return False
+
+                else:
+                    return True
 
             else:
-                return True
-
-        else:
-            LOG.info(_('%(id)s (%(base_file)s): image verification skipped, '
-                       'no hash stored'),
-                     {'id': img_id,
-                      'base_file': base_file})
-
-            # NOTE(mikal): If the checksum file is missing, then we should
-            # create one. We don't create checksums when we download images
-            # from glance because that would delay VM startup.
-            if create_if_missing:
-                write_stored_checksum(base_file)
-
-            return None
+                LOG.info(_('%(id)s (%(base_file)s): image verification '
+                           'skipped, no hash stored'),
+                         {'id': img_id,
+                          'base_file': base_file})
+
+                # NOTE(mikal): If the checksum file is missing, then we should
+                # create one. We don't create checksums when we download images
+                # from glance because that would delay VM startup.
+                if CONF.checksum_base_images and create_if_missing:
+                    LOG.info(_('%(id)s (%(base_file)s): generating checksum'),
+                             {'id': img_id,
+                              'base_file': base_file})
+                    write_stored_checksum(base_file)
+
+                return None
+
+        return inner_verify_checksum()
 
     def _remove_base_file(self, base_file):
         """Remove a single base file if it is old enough.
diff --git a/nova/virt/libvirt/utils.py b/nova/virt/libvirt/utils.py
index d1a2ecd6b..292fe571e 100644
--- a/nova/virt/libvirt/utils.py
+++ b/nova/virt/libvirt/utils.py
@@ -21,8 +21,10 @@
 
 import errno
 import hashlib
+import json
 import os
 import re
+import time
 
 from lxml import etree
 
@@ -30,6 +32,7 @@ from nova import exception
 from nova.openstack.common import cfg
 from nova.openstack.common import fileutils
 from nova.openstack.common import jsonutils
+from nova.openstack.common import lockutils
 from nova.openstack.common import log as logging
 from nova import utils
 from nova.virt import images
@@ -468,23 +471,38 @@ def is_valid_info_file(path):
     return False
 
 
-def read_stored_info(base_path, field=None):
+def _read_possible_json(serialized, info_file):
+    try:
+        d = jsonutils.loads(serialized)
+
+    except ValueError, e:
+        LOG.error(_('Error reading image info file %(filename)s: '
+                    '%(error)s'),
+                  {'filename': info_file,
+                   'error': e})
+        d = {}
+
+    return d
+
+
+def read_stored_info(target, field=None, timestamped=False):
     """Read information about an image.
 
     Returns an empty dictionary if there is no info, just the field value if
     a field is requested, or the entire dictionary otherwise.
     """
 
-    info_file = get_info_filename(base_path)
+    info_file = get_info_filename(target)
     if not os.path.exists(info_file):
-        # Special case to handle essex checksums being converted
-        old_filename = base_path + '.sha1'
+        # NOTE(mikal): Special case to handle essex checksums being converted.
+        # There is an assumption here that target is a base image filename.
+        old_filename = target + '.sha1'
         if field == 'sha1' and os.path.exists(old_filename):
             hash_file = open(old_filename)
             hash_value = hash_file.read()
             hash_file.close()
 
-            write_stored_info(base_path, field=field, value=hash_value)
+            write_stored_info(target, field=field, value=hash_value)
             os.remove(old_filename)
             d = {field: hash_value}
 
@@ -492,24 +510,24 @@ def read_stored_info(base_path, field=None):
             d = {}
 
     else:
-        LOG.info(_('Reading image info file: %s'), info_file)
-        f = open(info_file, 'r')
-        serialized = f.read().rstrip()
-        f.close()
-        LOG.info(_('Read: %s'), serialized)
+        lock_name = 'info-%s' % os.path.split(target)[-1]
+        lock_path = os.path.join(CONF.instances_path, 'locks')
 
-        try:
-            d = jsonutils.loads(serialized)
+        @lockutils.synchronized(lock_name, 'nova-', external=True,
+                                lock_path=lock_path)
+        def read_file(info_file):
+            LOG.debug(_('Reading image info file: %s'), info_file)
+            with open(info_file, 'r') as f:
+                return f.read().rstrip()
 
-        except ValueError, e:
-            LOG.error(_('Error reading image info file %(filename)s: '
-                        '%(error)s'),
-                      {'filename': info_file,
-                       'error': e})
-            d = {}
+        serialized = read_file(info_file)
+        d = _read_possible_json(serialized, info_file)
 
     if field:
-        return d.get(field, None)
+        if timestamped:
+            return (d.get(field, None), d.get('%s-timestamp' % field, None))
+        else:
+            return d.get(field, None)
     return d
 
 
@@ -520,14 +538,25 @@ def write_stored_info(target, field=None, value=None):
         return
 
     info_file = get_info_filename(target)
+    LOG.info(_('Writing stored info to %s'), info_file)
     fileutils.ensure_tree(os.path.dirname(info_file))
 
-    d = read_stored_info(info_file)
-    d[field] = value
-    serialized = jsonutils.dumps(d)
+    lock_name = 'info-%s' % os.path.split(target)[-1]
+    lock_path = os.path.join(CONF.instances_path, 'locks')
+
+    @lockutils.synchronized(lock_name, 'nova-', external=True,
+                            lock_path=lock_path)
+    def write_file(info_file, field, value):
+        d = {}
+
+        if os.path.exists(info_file):
+            with open(info_file, 'r') as f:
+                d = _read_possible_json(f.read(), info_file)
+
+        d[field] = value
+        d['%s-timestamp' % field] = time.time()
+
+        with open(info_file, 'w') as f:
+            f.write(json.dumps(d))
 
-    LOG.info(_('Writing image info file: %s'), info_file)
-    LOG.info(_('Wrote: %s'), serialized)
-    f = open(info_file, 'w')
-    f.write(serialized)
-    f.close()
+    write_file(info_file, field, value)