Merge "Handle image cache hashing on shared storage."

3 files changed, 145 insertions, 85 deletions

diff --git a/nova/tests/test_imagecache.py b/nova/tests/test_imagecache.py
index 72c58104a..78b7248bc 100644
--- a/nova/tests/test_imagecache.py
+++ b/nova/tests/test_imagecache.py
@@ -19,6 +19,7 @@
 import contextlib
 import cStringIO
 import hashlib
+import json
 import logging
 import os
 import time
@@ -53,7 +54,7 @@ class ImageCacheManagerTestCase(test.TestCase):
 
     def test_read_stored_checksum_missing(self):
         self.stubs.Set(os.path, 'exists', lambda x: False)
-        csum = imagecache.read_stored_checksum('/tmp/foo')
+        csum = imagecache.read_stored_checksum('/tmp/foo', timestamped=False)
         self.assertEquals(csum, None)
 
     def test_read_stored_checksum(self):
@@ -69,7 +70,8 @@ class ImageCacheManagerTestCase(test.TestCase):
             f.write(csum_input)
             f.close()
 
-            csum_output = imagecache.read_stored_checksum(fname)
+            csum_output = imagecache.read_stored_checksum(fname,
+                                                          timestamped=False)
             self.assertEquals(csum_input.rstrip(),
                               '{"sha1": "%s"}' % csum_output)
 
@@ -85,7 +87,8 @@ class ImageCacheManagerTestCase(test.TestCase):
             f.write('fdghkfhkgjjksfdgjksjkghsdf')
             f.close()
 
-            csum_output = imagecache.read_stored_checksum(fname)
+            csum_output = imagecache.read_stored_checksum(fname,
+                                                          timestamped=False)
             self.assertEquals(csum_output, 'fdghkfhkgjjksfdgjksjkghsdf')
             self.assertFalse(os.path.exists(old_fname))
             self.assertTrue(os.path.exists(virtutils.get_info_filename(fname)))
@@ -351,9 +354,8 @@ class ImageCacheManagerTestCase(test.TestCase):
         fname = os.path.join(tmpdir, 'aaa')
         info_fname = virtutils.get_info_filename(fname)
 
-        f = open(fname, 'w')
-        f.write(testdata)
-        f.close()
+        with open(fname, 'w') as f:
+            f.write(testdata)
 
         return fname, info_fname, testdata
 
@@ -480,26 +482,23 @@ class ImageCacheManagerTestCase(test.TestCase):
                 self.assertNotEqual(log.find('image verification failed'), -1)
 
     def test_verify_checksum_file_missing(self):
-        img = {'container_format': 'ami', 'id': '42'}
-
         self.flags(checksum_base_images=True)
 
-        with self._intercept_log_messages() as stream:
-            with utils.tempdir() as tmpdir:
-                self.flags(instances_path=tmpdir)
-                self.flags(image_info_filename_pattern=('$instances_path/'
-                                                        '%(image)s.info'))
+        with utils.tempdir() as tmpdir:
+            self.flags(instances_path=tmpdir)
+            self.flags(image_info_filename_pattern=('$instances_path/'
+                                                    '%(image)s.info'))
 
-                fname, info_fname, testdata = self._make_checksum(tmpdir)
+            fname, info_fname, testdata = self._make_checksum(tmpdir)
 
-                # Checksum file missing
-                image_cache_manager = imagecache.ImageCacheManager()
-                res = image_cache_manager._verify_checksum(img, fname)
-                self.assertEquals(res, None)
+            # Checksum file missing
+            image_cache_manager = imagecache.ImageCacheManager()
+            res = image_cache_manager._verify_checksum('aaa', fname)
+            self.assertEquals(res, None)
 
-                # Checksum requests for a file with no checksum now have the
-                # side effect of creating the checksum
-                self.assertTrue(os.path.exists(info_fname))
+            # Checksum requests for a file with no checksum now have the
+            # side effect of creating the checksum
+            self.assertTrue(os.path.exists(info_fname))
 
     @contextlib.contextmanager
     def _make_base_file(self, checksum=True):
@@ -683,9 +682,12 @@ class ImageCacheManagerTestCase(test.TestCase):
         img = '123'
 
         with self._make_base_file() as fname:
-            f = open(fname, 'w')
-            f.write('banana')
-            f.close()
+            with open(fname, 'w') as f:
+                f.write('banana')
+
+            d = {'sha1': '21323454'}
+            with open('%s.info' % fname, 'w') as f:
+                f.write(json.dumps(d))
 
             image_cache_manager = imagecache.ImageCacheManager()
             image_cache_manager.unexplained_images = [fname]
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)