azurecloud: fix issues with instances not starting (#205)

The azurecloud platform did not always start instances
during collect runs.  This was a result of two issues. First
the image class _instance method did not invoke the start()
method which then allowed collect stage to attempt to run
scripts without an endpoint.  Second, azurecloud used the
image_id as both an instance handle (which is typically
vmName in azure api) as well as an image handle (for image
capture).  Resolve this by adding a .vm_name property to
the AzureCloudInstance and reference this property in
AzureCloudImage.

Also in this branch

- Fix error encoding user-data when value is None
- Add additional logging in AzureCloud platform
- Update logging format to print pathname,funcName and line number
  This greatly eases debugging.

LP: #1861921

1 files changed, 20 insertions, 12 deletions

diff --git a/tests/cloud_tests/platforms/azurecloud/image.py b/tests/cloud_tests/platforms/azurecloud/image.py
index 96a946f3..aad2bca1 100644
--- a/tests/cloud_tests/platforms/azurecloud/image.py
+++ b/tests/cloud_tests/platforms/azurecloud/image.py
@@ -21,26 +21,26 @@ class AzureCloudImage(Image):
         @param image_id: image id used to boot instance
         """
         super(AzureCloudImage, self).__init__(platform, config)
-        self.image_id = image_id
         self._img_instance = None
+        self.image_id = image_id
 
     @property
     def _instance(self):
         """Internal use only, returns a running instance"""
-        LOG.debug('creating instance')
         if not self._img_instance:
             self._img_instance = self.platform.create_instance(
                 self.properties, self.config, self.features,
                 self.image_id, user_data=None)
+            self._img_instance.start(wait=True, wait_for_cloud_init=True)
         return self._img_instance
 
     def destroy(self):
         """Delete the instance used to create a custom image."""
-        LOG.debug('deleting VM that was used to create image')
         if self._img_instance:
-            LOG.debug('Deleting instance %s', self._img_instance.name)
+            LOG.debug('Deleting backing instance %s',
+                      self._img_instance.vm_name)
             delete_vm = self.platform.compute_client.virtual_machines.delete(
-                self.platform.resource_group.name, self.image_id)
+                self.platform.resource_group.name, self._img_instance.vm_name)
             delete_vm.wait()
 
         super(AzureCloudImage, self).destroy()
@@ -48,7 +48,7 @@ class AzureCloudImage(Image):
     def _execute(self, *args, **kwargs):
         """Execute command in image, modifying image."""
         LOG.debug('executing commands on image')
-        self._instance.start()
+        self._instance.start(wait=True)
         return self._instance._execute(*args, **kwargs)
 
     def push_file(self, local_path, remote_path):
@@ -72,21 +72,26 @@ class AzureCloudImage(Image):
         Otherwise runs the clean script, deallocates, generalizes
         and creates custom image from instance.
         """
-        LOG.debug('creating image from VM')
+        LOG.debug('creating snapshot of image')
         if not self._img_instance:
+            LOG.debug('No existing image, snapshotting base image')
             return AzureCloudSnapshot(self.platform, self.properties,
                                       self.config, self.features,
-                                      self.image_id, delete_on_destroy=False)
+                                      self._instance.vm_name,
+                                      delete_on_destroy=False)
 
+        LOG.debug('creating snapshot from instance: %s', self._img_instance)
         if self.config.get('boot_clean_script'):
             self._img_instance.run_script(self.config.get('boot_clean_script'))
 
+        LOG.debug('deallocating instance %s', self._instance.vm_name)
         deallocate = self.platform.compute_client.virtual_machines.deallocate(
-            self.platform.resource_group.name, self.image_id)
+            self.platform.resource_group.name, self._instance.vm_name)
         deallocate.wait()
 
+        LOG.debug('generalizing instance %s', self._instance.vm_name)
         self.platform.compute_client.virtual_machines.generalize(
-            self.platform.resource_group.name, self.image_id)
+            self.platform.resource_group.name, self._instance.vm_name)
 
         image_params = {
             "location": self.platform.location,
@@ -96,13 +101,16 @@ class AzureCloudImage(Image):
                 }
             }
         }
+        LOG.debug('updating resource group image %s', self._instance.vm_name)
         self.platform.compute_client.images.create_or_update(
-            self.platform.resource_group.name, self.image_id,
+            self.platform.resource_group.name, self._instance.vm_name,
             image_params)
 
+        LOG.debug('destroying self')
         self.destroy()
 
+        LOG.debug('snapshot complete')
         return AzureCloudSnapshot(self.platform, self.properties, self.config,
-                                  self.features, self.image_id)
+                                  self.features, self._instance.vm_name)
 
 # vi: ts=4 expandtab