task 785 Improve logging for vCeneter exceptions

package/cloudshell/cp/vcenter/commands/connect_orchestrator.py

@@ -226,7 +226,7 @@ def _set_vlan(self, action_mappings, si, vm_uuid, logger):
             results += self._get_set_vlan_result_suc(act_by_mode_by_vlan_by_nic, connection_res_map)
 
         except Exception as e:
-            self.logger.error('Exception raised while connecting vm({0}) with exception: {1}'.format(vm_uuid, e))
+            self.logger.exception('Exception raised while connecting vm({})'.format(vm_uuid))
             for mode, actions in set_vlan_actions.items():
                 for action in actions:
                     error_result = self._create_error_action_res(action, e)
@@ -347,7 +347,7 @@ def _remove_vlan(self, action_mappings, si, vm_uuid, logger):
                 results.append(action_result)
             final_res = self._consolidate_duplicate_results(results)
         except Exception as e:
-            self.logger.error('Exception raised while disconnecting vm({0}) with exception: {1}'.format(vm_uuid, e))
+            self.logger.exception('Exception raised while disconnecting vm({})'.format(vm_uuid))
             for mode, actions in mode_to_actions.items():
                 for action in actions:
                     error_result = self._create_error_action_res(action, e)

package/cloudshell/cp/vcenter/commands/destroy_vm.py

@@ -89,5 +89,5 @@ def _disconnect_all_my_connectors(session, resource_name, reservation_id, logger
         try:
             session.DisconnectRoutesInReservation(reservation_id, endpoints)
         except Exception as exc:
-            logger.error("Error disconnecting routes for resource {0} in reservation {1}. Error: {2}"
-                         .format(resource_name, reservation_id, get_error_message_from_exception(exc)))
+            logger.exception("Error disconnecting routes for resource {0} in reservation {1}. Error: {2}"
+                             .format(resource_name, reservation_id, get_error_message_from_exception(exc)))

package/cloudshell/cp/vcenter/common/vcenter/model_auto_discovery.py

@@ -37,14 +37,19 @@ def __init__(self):
         self.cs_helper = CloudshellDriverHelper()
         self.context_based_logger_factory = ContextBasedLoggerFactory()
 
-    def validate_and_discover(self, context):
-        """
-        :type context: models.QualiDriverModels.AutoLoadCommandContext
+    def _get_logger(self, context):
+        """Get Quali logger from the given context
+        :param context: models.QualiDriverModels.AutoLoadCommandContext
         """
-        logger = self.context_based_logger_factory.create_logger_for_context(
+        return self.context_based_logger_factory.create_logger_for_context(
             logger_name='vCenterShell',
             context=context)
 
+    def validate_and_discover(self, context):
+        """
+        :type context: models.QualiDriverModels.AutoLoadCommandContext
+        """
+        logger = self._get_logger(context)
         logger.info('Autodiscovery started')
 
         session = self.cs_helper.get_session(context.connectivity.server_address,
@@ -143,6 +148,9 @@ def _check_if_vcenter_user_pass_valid(self, context, session, attributes):
                                          connection_details.password,
                                          connection_details.port)
         except Exception:
+            logger = self._get_logger(context)
+            logger.exception("Could not connect to the vcenter")
+
             raise ValueError('could not connect to the vcenter: {0}, with the given credentials ({1})'.format(
                 connection_details.host,
                 connection_details.username))

package/cloudshell/cp/vcenter/common/vcenter/ovf_service.py

@@ -30,9 +30,9 @@ def deploy_image(self, vcenter_data_model, image_params, logger):
         """
         ovf_tool_exe_path = vcenter_data_model.ovf_tool_path
 
-        self._validate_url_exists(ovf_tool_exe_path, 'OVF Tool')
+        self._validate_url_exists(ovf_tool_exe_path, 'OVF Tool', logger)
 
-        args = self._get_args(ovf_tool_exe_path, image_params)
+        args = self._get_args(ovf_tool_exe_path, image_params, logger)
         logger.debug('opening ovf tool process with the params: {0}'.format(','.join(args)))
         process = subprocess.Popen(args, shell=True, stdin=subprocess.PIPE, stdout=subprocess.PIPE,
                                    stderr=subprocess.PIPE)
@@ -53,11 +53,11 @@ def deploy_image(self, vcenter_data_model, image_params, logger):
             return True
 
         image_params.connectivity.password = '******'
-        args_for_error = ' '.join(self._get_args(ovf_tool_exe_path, image_params))
+        args_for_error = ' '.join(self._get_args(ovf_tool_exe_path, image_params, logger))
         logger.error('error deploying image with the args: {0}, error: {1}'.format(args_for_error, res))
         raise Exception('error deploying image with the args: {0}, error: {1}'.format(args_for_error, res))
 
-    def _get_args(self, ovf_tool_exe_path, image_params):
+    def _get_args(self, ovf_tool_exe_path, image_params, logger):
         """
         :type image_params: vCenterShell.vm.ovf_image_params.OvfImageParams
         """
@@ -95,7 +95,7 @@ def _get_args(self, ovf_tool_exe_path, image_params):
         ovf_destination = self._get_ovf_destenation(image_params)
 
         image_url = image_params.image_url
-        self._validate_image_exists(image_url)
+        self._validate_image_exists(image_url, logger)
 
         # set location and destination
         args += [image_url,
@@ -124,16 +124,17 @@ def fix_param(param):
             return '\"{0}\"'.format(param)
         return param
 
-    def _validate_image_exists(self, image_url):
-        self._validate_url_exists(image_url, 'Image')
+    def _validate_image_exists(self, image_url, logger):
+        self._validate_url_exists(image_url, 'Image', logger)
 
     @staticmethod
-    def _validate_url_exists(image_url, type_name):
+    def _validate_url_exists(image_url, type_name, logger):
         try:
             f = urlopen(image_url)
             if f:
                 return True
         except Exception:  # invalid URL
+            logger.debug("Invalid URL", exc_info=True)
             exists = os.path.exists(image_url) and os.path.isfile(image_url)
             if exists:
                 return True

package/cloudshell/cp/vcenter/common/wrappers/command_wrapper.py

@@ -105,9 +105,8 @@ def execute_command_with_connection(self, context, command, *args):
             logger.debug(DEBUG_COMMAND_RESULT.format(str(results)))
 
             return results
-        except Exception as e:
-            logger.error(COMMAND_ERROR.format(command_name))
-            logger.exception(e)
+        except Exception:
+            logger.exception(COMMAND_ERROR.format(command_name))
             raise
         finally:
             if si:

package/cloudshell/cp/vcenter/network/dvswitch/creator.py

@@ -41,6 +41,7 @@ def get_or_create_network(self,
                                                                   '{0}/{1}'.format(dv_switch_path, dv_switch_name),
                                                                   dv_port_name)
                 except KeyError:
+                    logger.debug("Failed to find port group for {}".format(dv_port_name), exc_info=True)
                     network = None
 
             # if we still couldn't get the network ---> create it(can't find it, play god!)
@@ -58,6 +59,7 @@ def get_or_create_network(self,
             if not network:
                 raise ValueError('Could not get or create vlan named: {0}'.format(dv_port_name))
         except ValueError as e:
+            logger.debug("Failed to find network", exc_info=True)
             error = e
         finally:
             self._lock.release()

package/cloudshell/cp/vcenter/vm/portgroup_configurer.py

@@ -55,6 +55,7 @@ def connect_vnic_to_networks(self, vm, mapping, default_network, reserved_networ
             self.update_vnic_by_mapping(vm, update_mapping, logger)
             return update_mapping
         except Exception as e:
+            logger.exception("Failed to connect VM: {}".format(vm.name))
             raise ValueError('VM: {0} failed with: "{1}"'.format(vm.name, e.message))
 
     def erase_network_by_mapping(self, networks, reserved_networks, logger):
@@ -75,6 +76,7 @@ def erase_network_by_mapping(self, networks, reserved_networks, logger):
                                                                                logger=logger,
                                                                                action_name='Erase dv Port Group')
                 except Exception as e:
+                    logger.debug("Failed to erase network", exc_info=True)
                     a = e.msg
                     continue
         finally:

static_vm_package/VCenterAutoloadStaticVMDriver/app_discovery/vm_autoload_driver.py

@@ -46,7 +46,6 @@ def get_inventory(self, context):
 
         si = None
 
-
         try:
             self.logger.info('connecting to vcenter ({0})'.format(vcenter_api_res.Address))
             si = self._get_connection_to_vcenter(self.pv_service, session, vcenter_resource, vcenter_api_res.Address)
@@ -60,8 +59,8 @@ def get_inventory(self, context):
             if ip:
                 session.UpdateResourceAddress(context.resource.name, ip)
 
-        except Exception as e:
-            self.logger.error(e)
+        except Exception:
+            self.logger.exception("Get inventory command failed")
             raise
         finally:
             if si:
@@ -87,8 +86,8 @@ def _try_get_ip(self, pv_service, si, uuid, vcenter_resource):
                                             logger=self.logger)
             if ip_res.ip_address:
                 ip = ip_res.ip_address
-        except Exception as e:
-            self.logger.debug('Error while trying to load VM({0}) IP'.format(uuid))
+        except Exception:
+            self.logger.debug('Error while trying to load VM({0}) IP'.format(uuid), exc_info=True)
         return ip
 
     @staticmethod