diff --git a/trove/taskmanager/api.py b/trove/taskmanager/api.py index 4edf772fd3..bd35df6885 100644 --- a/trove/taskmanager/api.py +++ b/trove/taskmanager/api.py @@ -134,7 +134,7 @@ class API(proxy.RpcProxy): overrides=overrides)) def update_overrides(self, instance_id, overrides=None): - LOG.debug("Making async call to update configuration overrides for " + LOG.debug("Making async call to update datastore configurations for " "instance %s" % instance_id) self.cast(self.context, @@ -143,7 +143,7 @@ class API(proxy.RpcProxy): overrides=overrides)) def unassign_configuration(self, instance_id, flavor, configuration_id): - LOG.debug("Making async call to unassign configuration for " + LOG.debug("Making async call to remove datastore configurations for " "instance %s" % instance_id) self.cast(self.context, diff --git a/trove/taskmanager/models.py b/trove/taskmanager/models.py old mode 100644 new mode 100755 index 055c891907..4c36336007 --- a/trove/taskmanager/models.py +++ b/trove/taskmanager/models.py @@ -167,7 +167,7 @@ class FreshInstanceTasks(FreshInstance, NotifyMixin, ConfigurationMixin): backup_id, availability_zone, root_password, nics, overrides): - LOG.debug("begin create_instance for id: %s" % self.id) + LOG.info(_("Creating instance %s.") % self.id) security_groups = None # If security group support is enabled and heat based instance @@ -259,16 +259,17 @@ class FreshInstanceTasks(FreshInstance, NotifyMixin, ConfigurationMixin): utils.poll_until(self._service_is_active, sleep_time=USAGE_SLEEP_TIME, time_out=usage_timeout) + LOG.info(_("Created instance %s successfully.") % self.id) self.send_usage_event('create', instance_size=flavor['ram']) except PollTimeOut: - LOG.error(_("Timeout for service changing to active. " - "No usage create-event sent.")) + LOG.error(_("Failed to create instance %s. " + "Timeout waiting for instance to become active. " + "No usage create-event was sent.") % self.id) self.update_statuses_on_time_out() except Exception: - LOG.exception(_("Error during create-event call.")) - - LOG.debug("end create_instance for id: %s" % self.id) + LOG.exception(_("Failed to send usage create-event for " + "instance %s.") % self.id) def report_root_enabled(self): mysql_models.RootHistory.create(self.context, self.id, 'root') @@ -328,7 +329,7 @@ class FreshInstanceTasks(FreshInstance, NotifyMixin, ConfigurationMixin): def _create_server_volume(self, flavor_id, image_id, security_groups, datastore_manager, volume_size, availability_zone, nics): - LOG.debug("begin _create_server_volume for id: %s" % self.id) + LOG.debug("Begin _create_server_volume for id: %s" % self.id) try: files = {"/etc/guest_info": ("[DEFAULT]\n--guest_id=" "%s\n--datastore_manager=%s\n" @@ -361,14 +362,14 @@ class FreshInstanceTasks(FreshInstance, NotifyMixin, ConfigurationMixin): except Exception as e: msg = _("Error creating server and volume for " "instance %s") % self.id - LOG.debug("end _create_server_volume for id: %s" % self.id) + LOG.debug("End _create_server_volume for id: %s" % self.id) err = inst_models.InstanceTasks.BUILDING_ERROR_SERVER self._log_and_raise(e, msg, err) device_path = self.device_path mount_point = CONF.get(datastore_manager).mount_point volume_info = {'device_path': device_path, 'mount_point': mount_point} - LOG.debug("end _create_server_volume for id: %s" % self.id) + LOG.debug("End _create_server_volume for id: %s" % self.id) return volume_info def _build_sg_rules_mapping(self, rule_ports): @@ -384,7 +385,7 @@ class FreshInstanceTasks(FreshInstance, NotifyMixin, ConfigurationMixin): def _create_server_volume_heat(self, flavor, image_id, datastore_manager, volume_size, availability_zone, nics): - LOG.debug("begin _create_server_volume_heat for id: %s" % self.id) + LOG.debug("Begin _create_server_volume_heat for id: %s" % self.id) try: client = create_heat_client(self.context) tcp_rules_mapping_list = self._build_sg_rules_mapping(CONF.get( @@ -403,8 +404,7 @@ class FreshInstanceTasks(FreshInstance, NotifyMixin, ConfigurationMixin): try: heat_template = heat_template_unicode.encode('utf-8') except UnicodeEncodeError: - LOG.error(_("heat template ascii encode issue")) - raise TroveError("heat template ascii encode issue") + raise TroveError("Failed to utf-8 encode Heat template.") parameters = {"Flavor": flavor["name"], "VolumeSize": volume_size, @@ -425,23 +425,23 @@ class FreshInstanceTasks(FreshInstance, NotifyMixin, ConfigurationMixin): sleep_time=USAGE_SLEEP_TIME, time_out=HEAT_TIME_OUT) except PollTimeOut: - LOG.error(_("Timeout during stack status tracing")) - raise TroveError("Timeout occurred in tracking stack status") + raise TroveError("Failed to obtain Heat stack status. " + "Timeout occurred.") stack = client.stacks.get(stack_name) if ((stack.action, stack.stack_status) not in HEAT_STACK_SUCCESSFUL_STATUSES): - raise TroveError("Heat Stack Create Failed.") + raise TroveError("Failed to create Heat stack.") resource = client.resources.get(stack.id, 'BaseInstance') if resource.resource_status != HEAT_RESOURCE_SUCCESSFUL_STATE: - raise TroveError("Heat Resource Provisioning Failed.") + raise TroveError("Failed to provision Heat base instance.") instance_id = resource.physical_resource_id if self.volume_support: resource = client.resources.get(stack.id, 'DataVolume') if resource.resource_status != HEAT_RESOURCE_SUCCESSFUL_STATE: - raise TroveError("Heat Resource Provisioning Failed.") + raise TroveError("Failed to provision Heat data volume.") volume_id = resource.physical_resource_id self.update_db(compute_instance_id=instance_id, volume_id=volume_id) @@ -464,8 +464,8 @@ class FreshInstanceTasks(FreshInstance, NotifyMixin, ConfigurationMixin): except (TroveError, heat_exceptions.HTTPNotFound, heat_exceptions.HTTPException) as e: - msg = "Error during creating stack for instance %s" % self.id - LOG.debug(msg) + msg = _("Error occurred during Heat stack creation for " + "instance %s.") % self.id err = inst_models.InstanceTasks.BUILDING_ERROR_SERVER self._log_and_raise(e, msg, err) @@ -473,14 +473,14 @@ class FreshInstanceTasks(FreshInstance, NotifyMixin, ConfigurationMixin): mount_point = CONF.get(datastore_manager).mount_point volume_info = {'device_path': device_path, 'mount_point': mount_point} - LOG.debug("end _create_server_volume_heat for id: %s" % self.id) + LOG.debug("End _create_server_volume_heat for id: %s" % self.id) return volume_info def _create_server_volume_individually(self, flavor_id, image_id, security_groups, datastore_manager, volume_size, availability_zone, nics): - LOG.debug("begin _create_server_volume_individually for id: %s" % + LOG.debug("Begin _create_server_volume_individually for id: %s" % self.id) server = None volume_info = self._build_volume_info(datastore_manager, @@ -495,10 +495,10 @@ class FreshInstanceTasks(FreshInstance, NotifyMixin, ConfigurationMixin): # Save server ID. self.update_db(compute_instance_id=server_id) except Exception as e: - msg = _("Error creating server for instance %s") % self.id + msg = _("Failed to create server for instance %s") % self.id err = inst_models.InstanceTasks.BUILDING_ERROR_SERVER self._log_and_raise(e, msg, err) - LOG.debug("end _create_server_volume_individually for id: %s" % + LOG.debug("End _create_server_volume_individually for id: %s" % self.id) return volume_info @@ -513,7 +513,7 @@ class FreshInstanceTasks(FreshInstance, NotifyMixin, ConfigurationMixin): volume_info = self._create_volume( volume_size, datastore_manager) except Exception as e: - msg = _("Error provisioning volume for instance: %s") % self.id + msg = _("Failed to create volume for instance %s") % self.id err = inst_models.InstanceTasks.BUILDING_ERROR_VOLUME self._log_and_raise(e, msg, err) else: @@ -535,8 +535,7 @@ class FreshInstanceTasks(FreshInstance, NotifyMixin, ConfigurationMixin): raise TroveError(message=message) def _create_volume(self, volume_size, datastore_manager): - LOG.info("Entering create_volume") - LOG.debug("begin _create_volume for id: %s" % self.id) + LOG.debug("Begin _create_volume for id: %s" % self.id) volume_client = create_cinder_client(self.context) volume_desc = ("datastore volume for %s" % self.id) volume_ref = volume_client.volumes.create( @@ -555,7 +554,7 @@ class FreshInstanceTasks(FreshInstance, NotifyMixin, ConfigurationMixin): v_ref = volume_client.volumes.get(volume_ref.id) if v_ref.status in ['error']: raise VolumeCreationFailure() - LOG.debug("end _create_volume for id: %s" % self.id) + LOG.debug("End _create_volume for id: %s" % self.id) return self._build_volume(v_ref, datastore_manager) def _build_volume(self, v_ref, datastore_manager): @@ -609,7 +608,7 @@ class FreshInstanceTasks(FreshInstance, NotifyMixin, ConfigurationMixin): availability_zone=availability_zone, nics=nics, config_drive=config_drive) LOG.debug("Created new compute instance %(server_id)s " - "for id: %(id)s" % + "for instance %(id)s" % {'server_id': server.id, 'id': self.id}) return server @@ -617,7 +616,6 @@ class FreshInstanceTasks(FreshInstance, NotifyMixin, ConfigurationMixin): packages, databases, users, backup_info=None, config_contents=None, root_password=None, overrides=None): - LOG.info(_("Entering guest_prepare")) # Now wait for the response from the create to do additional work self.guest.prepare(flavor_ram, packages, databases, users, device_path=volume_info['device_path'], @@ -641,8 +639,7 @@ class FreshInstanceTasks(FreshInstance, NotifyMixin, ConfigurationMixin): return self.nova_client.servers.get(c_id) def ip_is_available(server): - LOG.info(_("Polling for ip addresses: $%s ") % - server.addresses) + LOG.debug("Polling for ip addresses: $%s " % server.addresses) if server.addresses != {}: return True elif (server.addresses == {} and @@ -650,9 +647,9 @@ class FreshInstanceTasks(FreshInstance, NotifyMixin, ConfigurationMixin): return False elif (server.addresses == {} and server.status == InstanceStatus.ERROR): - LOG.error(_("Instance IP not available, " - "instance (%(instance)s): " - "server had status (%(status)s).") % + LOG.error(_("Failed to create DNS entry for instance " + "%(instance)s. Server status was " + "%(status)s).") % {'instance': self.id, 'status': server.status}) raise TroveError(status=server.status) @@ -661,10 +658,11 @@ class FreshInstanceTasks(FreshInstance, NotifyMixin, ConfigurationMixin): server = self.nova_client.servers.get( self.db_info.compute_instance_id) self.db_info.addresses = server.addresses - LOG.info(_("Creating dns entry...")) + LOG.debug(_("Creating dns entry...")) ip = self.dns_ip_address if not ip: - raise TroveError('Error creating DNS. No IP available.') + raise TroveError("Failed to create DNS entry for instance %s. " + "No IP available." % self.id) dns_client.create_instance_entry(self.id, ip) else: LOG.debug("%(gt)s: DNS not enabled for instance: %(id)s" % @@ -681,14 +679,15 @@ class FreshInstanceTasks(FreshInstance, NotifyMixin, ConfigurationMixin): def _create_rules(self, s_group, ports, protocol): err = inst_models.InstanceTasks.BUILDING_ERROR_SEC_GROUP - err_msg = _("Error creating security group rules." - " Invalid port format. " + err_msg = _("Failed to create security group rules for instance " + "%(instance_id)s: Invalid port format - " "FromPort = %(from)s, ToPort = %(to)s") def set_error_and_raise(port_or_range): from_port, to_port = port_or_range self.update_db(task_status=err) - msg = err_msg % {'from': from_port, 'to': to_port} + msg = err_msg % {'instance_id': self.id, 'from': from_port, + 'to': to_port} raise MalformedSecurityGroupRuleError(message=msg) for port_or_range in set(ports): @@ -730,7 +729,7 @@ class BuiltInstanceTasks(BuiltInstance, NotifyMixin, ConfigurationMixin): """ def _delete_resources(self, deleted_at): - LOG.debug("begin _delete_resources for id: %s" % self.id) + LOG.debug("Begin _delete_resources for instance %s" % self.id) server_id = self.db_info.compute_instance_id old_server = self.nova_client.servers.get(server_id) try: @@ -754,14 +753,14 @@ class BuiltInstanceTasks(BuiltInstance, NotifyMixin, ConfigurationMixin): LOG.exception(_("Error during dns entry of instance %(id)s: " "%(ex)s") % {'id': self.db_info.id, 'ex': ex}) - # Poll until the server is gone. + # Poll until the server is gone. def server_is_finished(): try: server = self.nova_client.servers.get(server_id) if not self.server_status_matches(['SHUTDOWN', 'ACTIVE'], server=server): - LOG.error(_("Server %(server_id)s got into ERROR status " - "during delete of instance %(instance_id)s!") % + LOG.error(_("Server %(server_id)s entered ERROR status " + "when deleting instance %(instance_id)s!") % {'server_id': server.id, 'instance_id': self.id}) return False except nova_exceptions.NotFound: @@ -771,12 +770,14 @@ class BuiltInstanceTasks(BuiltInstance, NotifyMixin, ConfigurationMixin): utils.poll_until(server_is_finished, sleep_time=2, time_out=CONF.server_delete_time_out) except PollTimeOut: - LOG.exception(_("Timout during nova server delete of server: %s") % - server_id) + LOG.exception(_("Failed to delete instance %(instance_id)s: " + "Timeout deleting compute server %(server_id)s") % + {'instance_id': self.id, 'server_id': server_id}) + self.send_usage_event('delete', deleted_at=timeutils.isotime(deleted_at), server=old_server) - LOG.debug("end _delete_resources for id: %s" % self.id) + LOG.debug("End _delete_resources for instance %s" % self.id) def server_status_matches(self, expected_status, server=None): if not server: @@ -785,29 +786,37 @@ class BuiltInstanceTasks(BuiltInstance, NotifyMixin, ConfigurationMixin): status.upper() for status in expected_status) def resize_volume(self, new_size): - LOG.debug("begin resize_volume for instance: %s" % self.id) + LOG.info(_("Resizing volume for instance %(instance_id)s from " + "%(old_size)s GB to %(new_size)s GB.") % + {'instance_id': self.id, 'old_size': self.volume_size, + 'new_size': new_size}) action = ResizeVolumeAction(self, self.volume_size, new_size) action.execute() - LOG.debug("end resize_volume for instance: %s" % self.id) + LOG.info(_("Resized volume for instance %s successfully.") % self.id) def resize_flavor(self, old_flavor, new_flavor): + LOG.info(_("Resizing instance %(instance_id)s from flavor " + "%(old_flavor)s to %(new_flavor)s.") % + {'instance_id': self.id, 'old_flavor': old_flavor['id'], + 'new_flavor': new_flavor['id']}) action = ResizeAction(self, old_flavor, new_flavor) action.execute() + LOG.info(_("Resized instance %s successfully.") % self.id) def migrate(self, host): - LOG.debug("Calling migrate with host(%s)..." % host) + LOG.info(_("Initiating migration to host %s.") % host) action = MigrateAction(self, host) action.execute() def create_backup(self, backup_info): - LOG.debug("Calling create_backup %s " % self.id) + LOG.info(_("Initiating backup for instance %s.") % self.id) self.guest.create_backup(backup_info) def reboot(self): try: - LOG.debug("Instance %s calling stop_db..." % self.id) + LOG.debug("Stopping datastore on instance %s." % self.id) self.guest.stop_db() - LOG.debug("Rebooting instance %s" % self.id) + LOG.info(_("Rebooting instance %s.") % self.id) self.server.reboot() # Poll nova until instance is active @@ -825,29 +834,27 @@ class BuiltInstanceTasks(BuiltInstance, NotifyMixin, ConfigurationMixin): # Set the status to PAUSED. The guest agent will reset the status # when the reboot completes and MySQL is running. self.set_datastore_status_to_paused() - LOG.debug("Successfully rebooted instance %s" % self.id) + LOG.info(_("Rebooted instance %s successfully.") % self.id) except Exception as e: LOG.error(_("Failed to reboot instance %(id)s: %(e)s") % {'id': self.id, 'e': str(e)}) finally: - LOG.debug("Rebooting FINALLY %s" % self.id) + LOG.debug("Rebooting FINALLY %s" % self.id) self.reset_task_status() def restart(self): - LOG.debug("Restarting datastore on instance %s " % self.id) + LOG.info(_("Initiating datastore restart on instance %s.") % self.id) try: self.guest.restart() - LOG.debug("Restarting datastore successful %s " % self.id) except GuestError: - LOG.error(_("Failure to restart datastore for instance %s.") % - self.id) + LOG.error(_("Failed to initiate datastore restart on instance " + "%s.") % self.id) finally: - LOG.debug("Restarting complete on instance %s " % self.id) self.reset_task_status() def update_overrides(self, overrides, remove=False): - LOG.debug("Updating configuration overrides on instance %s" - % self.id) + LOG.info(_("Initiating datastore configurations update on instance " + "%s.") % self.id) LOG.debug("overrides: %s" % overrides) LOG.debug("self.ds_version: %s" % self.ds_version.__dict__) # todo(cp16net) How do we know what datastore type we have? @@ -867,19 +874,19 @@ class BuiltInstanceTasks(BuiltInstance, NotifyMixin, ConfigurationMixin): self.guest.update_overrides(config_overrides.config_contents, remove=remove) self.guest.apply_overrides(overrides) - LOG.debug("Configuration overrides update successful.") except GuestError: - LOG.error(_("Failed to update configuration overrides.")) + LOG.error(_("Failed to initiate datastore configurations update " + "on instance %s.") % self.id) def unassign_configuration(self, flavor, configuration_id): - LOG.debug("Unassigning the configuration from the instance %s" - % self.id) - LOG.debug("Unassigning the configuration id %s" - % self.configuration.id) + LOG.info(_("Initiating configuration group %(config_id)s removal from " + "instance %(instance_id)s.") + % {'config_id': configuration_id, + 'instance_id': self.id}) def _find_item(items, item_name): - LOG.debug("items: %s" % items) - LOG.debug("item_name: %s" % item_name) + LOG.debug("Searching for %(item_name)s in %(items)s" % + {'item_name': item_name, 'items': items}) # find the item in the list for i in items: if i[0] == item_name: @@ -969,25 +976,26 @@ class BackupTasks(object): cont, prefix = cls._parse_manifest(manifest) if all([cont, prefix]): # This is a manifest file, first delete all segments. - LOG.info(_("Deleting files with prefix: %(cont)s/%(prefix)s") % - {'cont': cont, 'prefix': prefix}) + LOG.debug("Deleting files with prefix: %(cont)s/%(prefix)s" % + {'cont': cont, 'prefix': prefix}) # list files from container/prefix specified by manifest headers, segments = client.get_container(cont, prefix=prefix) LOG.debug(headers) for segment in segments: name = segment.get('name') if name: - LOG.info(_("Deleting file: %(cont)s/%(name)s") % - {'cont': cont, 'name': name}) + LOG.debug("Deleting file: %(cont)s/%(name)s" % + {'cont': cont, 'name': name}) client.delete_object(cont, name) # Delete the manifest file - LOG.info(_("Deleting file: %(cont)s/%(filename)s") % - {'cont': cont, 'filename': filename}) + LOG.debug("Deleting file: %(cont)s/%(filename)s" % + {'cont': cont, 'filename': filename}) client.delete_object(container, filename) @classmethod def delete_backup(cls, context, backup_id): #delete backup from swift + LOG.info(_("Deleting backup %s.") % backup_id) backup = bkup_models.Backup.get_by_id(context, backup_id) try: filename = backup.filename @@ -1000,13 +1008,15 @@ class BackupTasks(object): # Backup already deleted in swift backup.delete() else: - LOG.exception(_("Exception deleting from swift. " + LOG.exception(_("Error occurred when deleting from swift. " "Details: %s") % e) backup.state = bkup_models.BackupState.DELETE_FAILED backup.save() - raise TroveError("Failed to delete swift objects") + raise TroveError("Failed to delete swift object for backup %s." + % backup_id) else: backup.delete() + LOG.info(_("Deleted backup %s successfully.") % backup_id) class ResizeVolumeAction(object): @@ -1193,7 +1203,7 @@ class ResizeVolumeAction(object): raise def _resize_active_volume(self): - LOG.debug("begin _resize_active_volume for id: %(id)s" % { + LOG.debug("Begin _resize_active_volume for id: %(id)s" % { 'id': self.instance.id}) self._stop_db() self._unmount_volume(recover_func=self._recover_restart) @@ -1205,7 +1215,7 @@ class ResizeVolumeAction(object): self._resize_fs(recover_func=self._fail) self._mount_volume(recover_func=self._fail) self.instance.restart() - LOG.debug("end _resize_active_volume for id: %(id)s" % { + LOG.debug("End _resize_active_volume for id: %(id)s" % { 'id': self.instance.id}) def execute(self): @@ -1232,9 +1242,11 @@ class ResizeVolumeAction(object): volume_size=volume.size) else: self.instance.reset_task_status() - msg = _("Volume resize failed for instance %(id)s. The instance " - "must be in state %(state)s not %(inst_state)s.") % { + msg = _("Failed to resize instance %(id)s volume for server " + "%(server_id)s. The instance must be in state %(state)s " + "not %(inst_state)s.") % { 'id': self.instance.id, + 'server_id': self.instance.server.id, 'state': InstanceStatus.ACTIVE, 'inst_state': self.instance.server.status} raise TroveError(msg) @@ -1334,7 +1346,7 @@ class ResizeActionBase(object): def _perform_nova_action(self): """Calls Nova to resize or migrate an instance, and confirms.""" - LOG.debug("begin resize method _perform_nova_action instance: %s" % + LOG.debug("Begin resize method _perform_nova_action instance: %s" % self.instance.id) need_to_revert = False try: @@ -1372,7 +1384,7 @@ class ResizeActionBase(object): LOG.debug("Recording success") self._record_action_success() - LOG.debug("end resize method _perform_nova_action instance: %s" % + LOG.debug("End resize method _perform_nova_action instance: %s" % self.instance.id) def _wait_for_nova_action(self):