openstack
/
trove
Code Issues Proposed changes

Adjusted audit logging for trove.instance module 

The trove.instance module is logging some verbose debug data at the
info level, and some info messages at the debug level. Some log
entries are also lacking context because of missing identifiers such
as InstanceID and TenantID.

Changed logging level of various messages to conform to standard,
added references to various ID's as needed.

Change-Id: I3bb569529befa2b2497d2d5a094e3306e569422c
Partial-Bug: #1324206
This commit is contained in:
Simon Chang 2014-07-07 18:37:57 -04:00
parent accce2ced3
commit a99b787cc2
2 changed files with 78 additions and 61 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

88
trove/instance/models.py
View File

@ -72,7 +72,7 @@ def load_server(context, instance_id, server_id):
try:
server = client.servers.get(server_id)
except nova_exceptions.NotFound:
LOG.debug("Could not find nova server_id(%s)" % server_id)
LOG.error(_("Could not find nova server_id(%s).") % server_id)
raise exception.ComputeInstanceNotFound(instance_id=instance_id,
server_id=server_id)
except nova_exceptions.ClientException as e:
@ -411,7 +411,7 @@ def load_any_instance(context, id):
try:
return load_instance(BuiltInstance, context, id, needs_server=True)
except exception.UnprocessableEntity:
LOG.warn("Could not load instance %s." % id)
LOG.warn(_("Could not load instance %s.") % id)
return load_instance(FreshInstance, context, id, needs_server=False)
@ -431,21 +431,24 @@ def load_instance(cls, context, id, needs_server=False):
db_info.server_status = server.status
db_info.addresses = server.addresses
except exception.ComputeInstanceNotFound:
LOG.error("COMPUTE ID = %s" % db_info.compute_instance_id)
LOG.error(_("Could not load compute instance %s.") %
db_info.compute_instance_id)
raise exception.UnprocessableEntity("Instance %s is not ready." %
id)
service_status = InstanceServiceStatus.find_by(instance_id=id)
LOG.info("service status=%s" % service_status.status)
LOG.debug("Instance %(instance_id)s service status is %(service_status)s."
% {'instance_id': id, 'service_status': service_status.status})
return cls(context, db_info, server, service_status)
def load_instance_with_guest(cls, context, id):
db_info = get_db_info(context, id)
load_simple_instance_server_status(context, db_info)
datastore_status = InstanceServiceStatus.find_by(instance_id=id)
LOG.info("datastore status=%s" % datastore_status.status)
instance = cls(context, db_info, datastore_status)
service_status = InstanceServiceStatus.find_by(instance_id=id)
LOG.debug("Instance %(instance_id)s service status is %(service_status)s."
% {'instance_id': id, 'service_status': service_status.status})
instance = cls(context, db_info, service_status)
load_guest_info(instance, context, id)
return instance
@ -510,9 +513,8 @@ class BaseInstance(SimpleInstance):
if self.is_building:
raise exception.UnprocessableEntity("Instance %s is not ready."
% self.id)
LOG.debug(" ... deleting compute id = %s" %
LOG.debug("Deleting instance with compute id = %s." %
self.db_info.compute_instance_id)
LOG.debug(" ... setting status to DELETING.")
self.update_db(task_status=InstanceTasks.DELETING,
configuration_id=None)
task_api.API(self.context).delete_instance(self.id)
@ -531,7 +533,7 @@ class BaseInstance(SimpleInstance):
def delete_async(self):
deleted_at = datetime.utcnow()
self._delete_resources(deleted_at)
LOG.debug("Setting instance %s to be deleted..." % self.id)
LOG.debug("Setting instance %s to be deleted." % self.id)
# Delete guest queue.
try:
guest = self.get_guest()
@ -576,7 +578,7 @@ class BaseInstance(SimpleInstance):
return self._volume_client
def reset_task_status(self):
LOG.info(_("Setting task status to NONE on instance %s...") % self.id)
LOG.info(_("Resetting task status to NONE on instance %s.") % self.id)
self.update_db(task_status=InstanceTasks.NONE)
@ -607,7 +609,7 @@ class Instance(BuiltInstance):
return root_on_create
except NoSuchOptError:
LOG.debug("root_on_create not configured for %s,"
" hence defaulting the value to False"
" hence defaulting the value to False."
% datastore_manager)
return False
@ -669,9 +671,8 @@ class Instance(BuiltInstance):
task_status=InstanceTasks.BUILDING,
configuration_id=configuration_id,
slave_of_id=slave_of_id)
LOG.debug("Tenant %(tenant)s created new "
"Trove instance %(db)s..." %
{'tenant': context.tenant, 'db': db_info.id})
LOG.debug("Tenant %(tenant)s created new Trove instance %(db)s."
% {'tenant': context.tenant, 'db': db_info.id})
# if a configuration group is associated with an instance,
# generate an overrides dict to pass into the instance creation
@ -717,15 +718,18 @@ class Instance(BuiltInstance):
def get_default_configuration_template(self):
flavor = self.get_flavor()
LOG.debug("flavor: %s" % flavor)
LOG.debug("Getting default config template for datastore version "
"%(ds_version)s and flavor %(flavor)s." %
{'ds_version': self.ds_version, 'flavor': flavor})
config = template.SingleInstanceConfigTemplate(
self.ds_version, flavor, id)
return config.render_dict()
def resize_flavor(self, new_flavor_id):
self.validate_can_perform_action()
LOG.debug("resizing instance %s flavor to %s"
% (self.id, new_flavor_id))
LOG.info(_("Resizing instance %(instance_id)s flavor to "
"%(flavor_id)s.")
% {'instance_id': self.id, 'flavor_id': new_flavor_id})
# Validate that the flavor can be found and that it isn't the same size
# as the current one.
client = create_nova_client(self.context)
@ -761,12 +765,12 @@ class Instance(BuiltInstance):
def resize_volume(self, new_size):
def _resize_resources():
self.validate_can_perform_action()
LOG.info("Resizing volume of instance %s..." % self.id)
LOG.info(_("Resizing volume of instance %s.") % self.id)
old_size = self.volume_size
if int(new_size) <= old_size:
raise exception.BadRequest(_("The new volume 'size' must be "
"larger than the current volume "
"size of '%s'") % old_size)
"size of '%s'.") % old_size)
# Set the task to Resizing before sending off to the taskmanager
self.update_db(task_status=InstanceTasks.RESIZING)
task_api.API(self.context).resize_volume(new_size, self.id)
@ -782,13 +786,13 @@ class Instance(BuiltInstance):
def reboot(self):
self.validate_can_perform_action()
LOG.info("Rebooting instance %s..." % self.id)
LOG.info(_("Rebooting instance %s.") % self.id)
self.update_db(task_status=InstanceTasks.REBOOTING)
task_api.API(self.context).reboot(self.id)
def restart(self):
self.validate_can_perform_action()
LOG.info("Restarting MySQL on instance %s..." % self.id)
LOG.info(_("Restarting datastore on instance %s.") % self.id)
# Set our local status since Nova might not change it quick enough.
#TODO(tim.simpson): Possible bad stuff can happen if this service
# shuts down before it can set status to NONE.
@ -800,7 +804,9 @@ class Instance(BuiltInstance):
def migrate(self, host=None):
self.validate_can_perform_action()
LOG.info("Migrating instance id = %s, to host = %s" % (self.id, host))
LOG.info(_("Migrating instance id = %(instance_id)s "
"to host = %(host)s.")
% {'instance_id': self.id, 'host': host})
self.update_db(task_status=InstanceTasks.MIGRATING)
task_api.API(self.context).migrate(self.id, host)
@ -822,8 +828,9 @@ class Instance(BuiltInstance):
# action can be performed
return
msg = ("Instance is not currently available for an action to be "
"performed (status was %s)." % status)
msg = (_("Instance %(instance_id)s is not currently available for an "
"action to be performed (status was %(action_status)s).") %
{'instance_id': self.id, 'action_status': status})
LOG.error(msg)
raise exception.UnprocessableEntity(msg)
@ -850,15 +857,15 @@ class Instance(BuiltInstance):
status=status)
def unassign_configuration(self):
LOG.debug("Unassigning the configuration from the instance %s"
LOG.debug("Unassigning the configuration from the instance %s."
% self.id)
if self.configuration and self.configuration.id:
LOG.debug("Unassigning the configuration id %s"
LOG.debug("Unassigning the configuration id %s."
% self.configuration.id)
flavor = self.get_flavor()
config_id = self.configuration.id
LOG.debug("Configuration being unassigned; "
"marking restart required")
"Marking restart required.")
self.update_db(task_status=InstanceTasks.RESTART_REQUIRED)
task_api.API(self.context).unassign_configuration(self.id,
flavor,
@ -873,7 +880,7 @@ class Instance(BuiltInstance):
configuration = Configuration.load(self.context, configuration_id)
except exception.ModelNotFoundError:
raise exception.NotFound(
message='Configuration group id: %s could not be found'
message='Configuration group id: %s could not be found.'
% configuration_id)
config_ds_v = configuration.datastore_version_id
@ -886,18 +893,18 @@ class Instance(BuiltInstance):
overrides = Configuration.get_configuration_overrides(
self.context, configuration.id)
LOG.info(overrides)
LOG.debug("Config overrides is %s." % overrides)
self.update_overrides(overrides)
self.update_db(configuration_id=configuration.id)
def update_overrides(self, overrides):
LOG.debug("Updating or removing overrides for instance %s"
LOG.debug("Updating or removing overrides for instance %s."
% self.id)
need_restart = do_configs_require_restart(
overrides, datastore_manager=self.ds_version.manager)
LOG.debug("config overrides has non-dynamic settings, "
"requires a restart: %s" % need_restart)
LOG.debug("Config overrides has non-dynamic settings, "
"requires a restart: %s." % need_restart)
if need_restart:
self.update_db(task_status=InstanceTasks.RESTART_REQUIRED)
task_api.API(self.context).update_overrides(self.id, overrides)
@ -917,7 +924,7 @@ def create_server_list_matcher(server_list):
instance_id=instance_id, server_id=server_id)
else:
# Should never happen, but never say never.
LOG.error(_("Server %(server)s for instance %(instance)s was"
LOG.error(_("Server %(server)s for instance %(instance)s was "
"found twice!") % {'server': server_id,
'instance': instance_id})
raise exception.TroveError(uuid=instance_id)
@ -950,8 +957,9 @@ class Instances(object):
find_server = create_server_list_matcher(servers)
for db in db_infos:
LOG.debug("Checking for db [id=%s, compute_instance_id=%s]" %
(db.id, db.compute_instance_id))
LOG.debug("Checking for db [id=%(db_id)s, "
"compute_instance_id=%(instance_id)s]." %
{'db_id': db.id, 'instance_id': db.compute_instance_id})
ret = Instances._load_servers_status(load_simple_instance, context,
data_view.collection,
find_server)
@ -982,13 +990,13 @@ class Instances(object):
instance_id=db.id)
if not datastore_status.status: # This should never happen.
LOG.error(_("Server status could not be read for "
"instance id(%s)") % db.id)
"instance id(%s).") % db.id)
continue
LOG.info(_("Server api_status(%s)") %
datastore_status.status.api_status)
LOG.debug("Server api_status(%s)." %
datastore_status.status.api_status)
except exception.ModelNotFoundError:
LOG.error(_("Server status could not be read for "
"instance id(%s)") % db.id)
"instance id(%s).") % db.id)
continue
ret.append(load_instance(context, db, datastore_status,
server=server))

51
trove/instance/service.py
View File

@ -67,9 +67,7 @@ class InstanceController(wsgi.Controller):
:param tenant_id: the tenant id for whom owns the instance
:param id: ???
"""
LOG.info("req : '%s'\n\n" % req)
LOG.info("Comitting an ACTION again instance %s for tenant '%s'"
% (id, tenant_id))
LOG.debug("instance action req : '%s'\n\n" % req)
if not body:
raise exception.BadRequest(_("Invalid request body."))
context = req.environ[wsgi.CONTEXT_KEY]
@ -80,9 +78,15 @@ class InstanceController(wsgi.Controller):
'reset_password': self._action_reset_password
}
selected_action = None
action_name = None
for key in body:
if key in _actions:
selected_action = _actions[key]
action_name = key
LOG.info(_("Performing %(action_name)s action against "
"instance %(instance_id)s for tenant '%(tenant_id)s'")
% {'action_name': action_name, 'instance_id': id,
'tenant_id': tenant_id})
return selected_action(instance, body)
def _action_restart(self, instance, body):
@ -126,8 +130,8 @@ class InstanceController(wsgi.Controller):
def index(self, req, tenant_id):
"""Return all instances."""
LOG.info(_("req : '%s'\n\n") % req)
LOG.info(_("Indexing a database instance for tenant '%s'") % tenant_id)
LOG.info(_("Listing database instances for tenant '%s'") % tenant_id)
LOG.debug("req : '%s'\n\n" % req)
context = req.environ[wsgi.CONTEXT_KEY]
servers, marker = models.Instances.load(context)
view = views.InstancesView(servers, req=req)
@ -137,9 +141,9 @@ class InstanceController(wsgi.Controller):
def backups(self, req, tenant_id, id):
"""Return all backups for the specified instance."""
LOG.info(_("req : '%s'\n\n") % req)
LOG.info(_("Indexing backups for instance '%s'") %
LOG.info(_("Listing backups for instance '%s'") %
id)
LOG.debug("req : '%s'\n\n" % req)
context = req.environ[wsgi.CONTEXT_KEY]
backups, marker = backup_model.list_for_instance(context, id)
view = backup_views.BackupViews(backups)
@ -149,9 +153,10 @@ class InstanceController(wsgi.Controller):
def show(self, req, tenant_id, id):
"""Return a single instance."""
LOG.info(_("req : '%s'\n\n") % req)
LOG.info(_("Showing a database instance for tenant '%s'") % tenant_id)
LOG.info(_("id : '%s'\n\n") % id)
LOG.info(_("Showing database instance '%(instance_id)s' for tenant "
"'%(tenant_id)s'") %
{'instance_id': id, 'tenant_id': tenant_id})
LOG.debug("req : '%s'\n\n" % req)
context = req.environ[wsgi.CONTEXT_KEY]
server = models.load_instance_with_guest(models.DetailInstance,
@ -161,9 +166,10 @@ class InstanceController(wsgi.Controller):
def delete(self, req, tenant_id, id):
"""Delete a single instance."""
LOG.info(_("req : '%s'\n\n") % req)
LOG.info(_("Deleting a database instance for tenant '%s'") % tenant_id)
LOG.info(_("id : '%s'\n\n") % id)
LOG.info(_("Deleting database instance '%(instance_id)s' for tenant "
"'%(tenant_id)s'") %
{'instance_id': id, 'tenant_id': tenant_id})
LOG.debug("req : '%s'\n\n" % req)
# TODO(hub-cap): turn this into middleware
context = req.environ[wsgi.CONTEXT_KEY]
instance = models.load_any_instance(context, id)
@ -174,8 +180,8 @@ class InstanceController(wsgi.Controller):
def create(self, req, body, tenant_id):
# TODO(hub-cap): turn this into middleware
LOG.info(_("Creating a database instance for tenant '%s'") % tenant_id)
LOG.info(logging.mask_password(_("req : '%s'\n\n") % req))
LOG.info(logging.mask_password(_("body : '%s'\n\n") % body))
LOG.debug(logging.mask_password("req : '%s'\n\n" % req))
LOG.debug(logging.mask_password("body : '%s'\n\n" % body))
context = req.environ[wsgi.CONTEXT_KEY]
datastore_args = body['instance'].get('datastore', {})
datastore, datastore_version = (
@ -241,9 +247,11 @@ class InstanceController(wsgi.Controller):
def update(self, req, id, body, tenant_id):
"""Updates the instance to attach/detach configuration."""
LOG.info(_("Updating instance for tenant id %s") % tenant_id)
LOG.info(_("req: %s") % req)
LOG.info(_("body: %s") % body)
LOG.info(_("Updating database instance '%(instance_id)s' for tenant "
"'%(tenant_id)s'") %
{'instance_id': id, 'tenant_id': tenant_id})
LOG.debug("req: %s" % req)
LOG.debug("body: %s" % body)
context = req.environ[wsgi.CONTEXT_KEY]
instance = models.Instance.load(context, id)
@ -265,11 +273,12 @@ class InstanceController(wsgi.Controller):
"""
Returns the default configuration template applied to the instance.
"""
LOG.debug("getting default configuration for the instance(%s)" % id)
LOG.info(_("Getting default configuration for instance %s") % id)
context = req.environ[wsgi.CONTEXT_KEY]
instance = models.Instance.load(context, id)
LOG.debug("server: %s" % instance)
LOG.debug("Server: %s" % instance)
config = instance.get_default_configuration_template()
LOG.debug("default config for instance is: %s" % config)
LOG.debug("Default config for instance %(instance_id)s is %(config)s" %
{'instance_id': id, 'config': config})
return wsgi.Result(views.DefaultConfigurationView(
config).data(), 200)