Add more log messages to azure driver

Also add a note to the docs about possibly needing to register the
compute resource.

Also log the nodepool launcher version on startup.

Change-Id: I93df0f02a28d51ef924f6071054cea998e2ecc3a

doc/source/azure.rst

@@ -14,6 +14,9 @@ the instructions at `Azure CLI`_ and use the ``--sdk-auth`` flag::
 You must also have created a network for Nodepool to use.  Be sure to
 enable IPv6 on the network if you plan to use it.
 
+You may also need to register the `Microsoft.Compute` resource
+provider with your subscription.
+
 Selecting the azure driver adds the following options to the :attr:`providers`
 section of the configuration.
 

nodepool/driver/azure/adapter.py

@@ -366,6 +366,7 @@ class AzureAdapter(statemachine.Adapter):
 
     def uploadImage(self, image_name, filename, image_format,
                     metadata, md5, sha256):
+        self.log.debug(f"Uploading image {image_name}")
         file_sz = os.path.getsize(filename)
         disk_info = {
             "location": self.provider.location,
@@ -449,13 +450,16 @@ class AzureAdapter(statemachine.Adapter):
         if r['status'] != 'Succeeded':
             raise Exception("Unable to delete disk for image upload")
 
+        self.log.info(f"Uploaded image {image_name}")
         return image_name
 
     def deleteImage(self, external_id):
+        self.log.debug(f"Deleting image {external_id}")
         with self.rate_limiter:
             r = self.azul.images.delete(self.resource_group, external_id)
         r = self.azul.wait_for_async_operation(r)
 
+        self.log.info(f"Deleted image {external_id}")
         if r['status'] != 'Succeeded':
             raise Exception("Unable to delete image")
 
@@ -542,10 +546,12 @@ class AzureAdapter(statemachine.Adapter):
                 'publicIpAllocationMethod': allocation_method,
             },
         }
+        name = "%s-pip-%s" % (hostname, version)
         with self.rate_limiter:
+            self.log.debug(f"Creating external IP address {name}")
             return self.azul.public_ip_addresses.create(
                 self.resource_group,
-                "%s-pip-%s" % (hostname, version),
+                name,
                 v4_params_create,
             )
 
@@ -556,6 +562,7 @@ class AzureAdapter(statemachine.Adapter):
         else:
             return None
         with self.rate_limiter:
+            self.log.debug(f"Deleting external IP address {name}")
             self.azul.public_ip_addresses.delete(self.resource_group, name)
         return pip
 
@@ -601,10 +608,12 @@ class AzureAdapter(statemachine.Adapter):
                 'ipConfigurations': ip_configs
             }
         }
+        name = "%s-nic" % hostname
         with self.rate_limiter:
+            self.log.debug(f"Creating NIC {name}")
             return self.azul.network_interfaces.create(
                 self.resource_group,
-                "%s-nic" % hostname,
+                name,
                 nic_data
             )
 
@@ -615,6 +624,7 @@ class AzureAdapter(statemachine.Adapter):
         else:
             return None
         with self.rate_limiter:
+            self.log.debug(f"Deleting NIC {name}")
             self.azul.network_interfaces.delete(self.resource_group, name)
         return nic
 
@@ -673,6 +683,7 @@ class AzureAdapter(statemachine.Adapter):
         if label.user_data:
             spec['properties']['userData'] = label.user_data
         with self.rate_limiter:
+            self.log.debug(f"Creating VM {hostname}")
             return self.azul.virtual_machines.create(
                 self.resource_group, hostname, spec)
 
@@ -681,8 +692,10 @@ class AzureAdapter(statemachine.Adapter):
             if vm['name'] == name:
                 break
         else:
+            self.log.warning(f"VM not found when deleting {name}")
             return None
         with self.rate_limiter:
+            self.log.debug(f"Deleting VM {name}")
             self.azul.virtual_machines.delete(self.resource_group, name)
         return vm
 

nodepool/launcher.py

@@ -33,6 +33,7 @@ from nodepool import config as nodepool_config
 from nodepool import zk
 from nodepool.driver.utils import QuotaInformation
 from nodepool.logconfig import get_annotated_logger
+from nodepool.version import version_info as npd_version_info
 
 
 MINS = 60
@@ -1090,6 +1091,8 @@ class NodePool(threading.Thread):
         '''
         Start point for the NodePool thread.
         '''
+        self.log.info("Nodepool launcher %s starting",
+                      npd_version_info.release_string())
         while not self._stopped:
             try:
                 self.updateConfig()