Merge pull request #434 from openstack-charmers/lourot/bug/1877076

Add some tenacity around cinder backup creation

zaza/openstack/charm_tests/cinder_backup/tests.py

@@ -63,7 +63,7 @@ class CinderBackupTest(test_utils.OpenStackBaseTest):
             self.cinder_client.volumes,
             vol_new.id,
             expected_status="available",
-            msg="Volume status wait")
+            msg="Extended volume")
 
     def test_410_cinder_vol_create_backup_delete_restore_pool_inspect(self):
         """Create, backup, delete, restore a ceph-backed cinder volume.
@@ -89,29 +89,44 @@ class CinderBackupTest(test_utils.OpenStackBaseTest):
 
         self.assertEqual(pool_name, expected_pool)
 
-        # Create ceph-backed cinder volume
-        cinder_vol = self.cinder_client.volumes.create(
-            name='{}-410-vol'.format(self.RESOURCE_PREFIX),
-            size=1)
-        openstack_utils.resource_reaches_status(
-            self.cinder_client.volumes,
-            cinder_vol.id,
-            wait_iteration_max_time=180,
-            stop_after_attempt=30,
-            expected_status='available',
-            msg='Volume status wait')
+        for attempt in tenacity.Retrying(
+                stop=tenacity.stop_after_attempt(3)):
+            with attempt:
+                # Create ceph-backed cinder volume
+                cinder_vol_name = '{}-410-{}-vol'.format(
+                    self.RESOURCE_PREFIX, attempt.retry_state.attempt_number)
+                cinder_vol = self.cinder_client.volumes.create(
+                    name=cinder_vol_name, size=1)
+                openstack_utils.resource_reaches_status(
+                    self.cinder_client.volumes,
+                    cinder_vol.id,
+                    wait_iteration_max_time=180,
+                    stop_after_attempt=15,
+                    expected_status='available',
+                    msg='ceph-backed cinder volume')
+
+                # Back up the volume
+                # NOTE(lourot): sometimes, especially on Mitaka, the backup
+                # remains stuck forever in 'creating' state and the volume in
+                # 'backing-up' state. See lp:1877076
+                # Attempting to create another volume and another backup
+                # usually then succeeds. Release notes and bug trackers show
+                # that many things have been fixed and are still left to be
+                # fixed in this area.
+                # When the backup creation succeeds, it usually does within
+                # 12 minutes.
+                vol_backup_name = '{}-410-{}-backup-vol'.format(
+                    self.RESOURCE_PREFIX, attempt.retry_state.attempt_number)
+                vol_backup = self.cinder_client.backups.create(
+                    cinder_vol.id, name=vol_backup_name)
+                openstack_utils.resource_reaches_status(
+                    self.cinder_client.backups,
+                    vol_backup.id,
+                    wait_iteration_max_time=180,
+                    stop_after_attempt=15,
+                    expected_status='available',
+                    msg='Backup volume')
 
-        # Backup the volume
-        vol_backup = self.cinder_client.backups.create(
-            cinder_vol.id,
-            name='{}-410-backup-vol'.format(self.RESOURCE_PREFIX))
-        openstack_utils.resource_reaches_status(
-            self.cinder_client.backups,
-            vol_backup.id,
-            wait_iteration_max_time=180,
-            stop_after_attempt=30,
-            expected_status='available',
-            msg='Volume status wait')
         # Delete the volume
         openstack_utils.delete_volume(self.cinder_client, cinder_vol.id)
         # Restore the volume
@@ -122,7 +137,7 @@ class CinderBackupTest(test_utils.OpenStackBaseTest):
             wait_iteration_max_time=180,
             stop_after_attempt=15,
             expected_status='available',
-            msg='Backup status wait')
+            msg='Restored backup volume')
         # Delete the backup
         openstack_utils.delete_volume_backup(
             self.cinder_client,
@@ -143,12 +158,12 @@ class CinderBackupTest(test_utils.OpenStackBaseTest):
         obj_count_samples.append(obj_count)
         pool_size_samples.append(kb_used)
 
-        name = '{}-410-vol'.format(self.RESOURCE_PREFIX)
         vols = self.cinder_client.volumes.list()
         try:
-            cinder_vols = [v for v in vols if v.name == name]
+            cinder_vols = [v for v in vols if v.name == cinder_vol_name]
         except AttributeError:
-            cinder_vols = [v for v in vols if v.display_name == name]
+            cinder_vols = [v for v in vols if
+                           v.display_name == cinder_vol_name]
         if not cinder_vols:
             # NOTE(hopem): it appears that at some point cinder-backup stopped
             # restoring volume metadata properly so revert to default name if

zaza/openstack/utilities/openstack.py

@@ -1901,14 +1901,13 @@ def _resource_reaches_status(resource, resource_id,
     :param expected_status: status to expect resource to reach
     :type expected_status: str
     :param msg: text to identify purpose in logging
-    :type msy: str
+    :type msg: str
     :raises: AssertionError
     """
     resource_status = resource.get(resource_id).status
-    logging.info(resource_status)
-    assert resource_status == expected_status, (
-        "Resource in {} state, waiting for {}" .format(resource_status,
-                                                       expected_status,))
+    logging.info("{}: resource {} in {} state, waiting for {}".format(
+        msg, resource_id, resource_status, expected_status))
+    assert resource_status == expected_status
 
 
 def resource_reaches_status(resource,
@@ -1970,8 +1969,8 @@ def _resource_removed(resource, resource_id, msg="resource"):
     :raises: AssertionError
     """
     matching = [r for r in resource.list() if r.id == resource_id]
-    logging.debug("Resource {} still present".format(resource_id))
-    assert len(matching) == 0, "Resource {} still present".format(resource_id)
+    logging.debug("{}: resource {} still present".format(msg, resource_id))
+    assert len(matching) == 0
 
 
 def resource_removed(resource,