Logging audit for trove/guestagent module
Adjust logging to conform to logging standards. Found and fixed a pattern of not logging exception information. Cleaned up some messages that were unclear. Also addressed a pattern of having exception's using LOG.error to log the exception (rather than using LOG.exception). Change-Id: Idab510051321f4f9ed096c9972322530028ad2e6 Partial-Bug: #1324206
This commit is contained in:
parent
5f98abb9df
commit
b668e85cb6
@ -27,6 +27,7 @@ from trove.openstack.common import rpc
|
||||
from trove.openstack.common import log as logging
|
||||
from trove.openstack.common.rpc import proxy
|
||||
from trove.openstack.common.rpc import common
|
||||
from trove.openstack.common.gettextutils import _
|
||||
|
||||
CONF = cfg.CONF
|
||||
LOG = logging.getLogger(__name__)
|
||||
@ -45,34 +46,34 @@ class API(proxy.RpcProxy):
|
||||
RPC_API_VERSION)
|
||||
|
||||
def _call(self, method_name, timeout_sec, **kwargs):
|
||||
LOG.debug("Calling %s with timeout %s" % (method_name, timeout_sec))
|
||||
LOG.debug("Calling %s with timeout %s." % (method_name, timeout_sec))
|
||||
try:
|
||||
result = self.call(self.context,
|
||||
self.make_msg(method_name, **kwargs),
|
||||
timeout=timeout_sec)
|
||||
|
||||
LOG.debug("Result is %s" % result)
|
||||
LOG.debug("Result is %s." % result)
|
||||
return result
|
||||
except common.RemoteError as r:
|
||||
LOG.error(r)
|
||||
LOG.exception(_("Error calling %s") % method_name)
|
||||
raise exception.GuestError(original_message=r.value)
|
||||
except Exception as e:
|
||||
LOG.error(e)
|
||||
LOG.exception(_("Error calling %s") % method_name)
|
||||
raise exception.GuestError(original_message=str(e))
|
||||
except Timeout:
|
||||
raise exception.GuestTimeout()
|
||||
|
||||
def _cast(self, method_name, **kwargs):
|
||||
LOG.debug("Casting %s" % method_name)
|
||||
LOG.debug("Casting %s." % method_name)
|
||||
try:
|
||||
self.cast(self.context, self.make_msg(method_name, **kwargs),
|
||||
topic=kwargs.get('topic'),
|
||||
version=kwargs.get('version'))
|
||||
except common.RemoteError as r:
|
||||
LOG.error(r)
|
||||
LOG.exception(_("Error calling %s") % method_name)
|
||||
raise exception.GuestError(original_message=r.value)
|
||||
except Exception as e:
|
||||
LOG.error(e)
|
||||
LOG.exception(_("Error calling %s") % method_name)
|
||||
raise exception.GuestError(original_message=str(e))
|
||||
|
||||
def _cast_with_consumer(self, method_name, **kwargs):
|
||||
@ -81,10 +82,10 @@ class API(proxy.RpcProxy):
|
||||
conn = rpc.create_connection(new=True)
|
||||
conn.create_consumer(self._get_routing_key(), None, fanout=False)
|
||||
except common.RemoteError as r:
|
||||
LOG.error(r)
|
||||
LOG.exception(_("Error calling %s") % method_name)
|
||||
raise exception.GuestError(original_message=r.value)
|
||||
except Exception as e:
|
||||
LOG.error(e)
|
||||
LOG.exception(_("Error calling %s") % method_name)
|
||||
raise exception.GuestError(original_message=str(e))
|
||||
finally:
|
||||
if conn:
|
||||
@ -117,31 +118,31 @@ class API(proxy.RpcProxy):
|
||||
"""Make an asynchronous call to change the passwords of one or more
|
||||
users.
|
||||
"""
|
||||
LOG.debug("Changing passwords for users on Instance %s", self.id)
|
||||
LOG.debug("Changing passwords for users on Instance %s.", self.id)
|
||||
self._cast("change_passwords", users=users)
|
||||
|
||||
def update_attributes(self, username, hostname, user_attrs):
|
||||
"""Update user attributes."""
|
||||
LOG.debug("Changing user attributes on Instance %s", self.id)
|
||||
LOG.debug("Changing user attributes on Instance %s.", self.id)
|
||||
self._cast("update_attributes", username=username, hostname=hostname,
|
||||
user_attrs=user_attrs)
|
||||
|
||||
def create_user(self, users):
|
||||
"""Make an asynchronous call to create a new database user"""
|
||||
LOG.debug("Creating Users for Instance %s", self.id)
|
||||
LOG.debug("Creating Users for Instance %s.", self.id)
|
||||
self._cast("create_user", users=users)
|
||||
|
||||
def get_user(self, username, hostname):
|
||||
"""Make an asynchronous call to get a single database user."""
|
||||
LOG.debug("Getting a user on Instance %s", self.id)
|
||||
LOG.debug("User name is %s" % username)
|
||||
LOG.debug("Getting a user on Instance %s.", self.id)
|
||||
LOG.debug("User name is %s." % username)
|
||||
return self._call("get_user", AGENT_LOW_TIMEOUT,
|
||||
username=username, hostname=hostname)
|
||||
|
||||
def list_access(self, username, hostname):
|
||||
"""Show all the databases to which a user has more than USAGE."""
|
||||
LOG.debug("Showing user grants on Instance %s", self.id)
|
||||
LOG.debug("User name is %s" % username)
|
||||
LOG.debug("Showing user grants on Instance %s.", self.id)
|
||||
LOG.debug("User name is %s." % username)
|
||||
return self._call("list_access", AGENT_LOW_TIMEOUT,
|
||||
username=username, hostname=hostname)
|
||||
|
||||
@ -159,13 +160,13 @@ class API(proxy.RpcProxy):
|
||||
|
||||
def list_users(self, limit=None, marker=None, include_marker=False):
|
||||
"""Make an asynchronous call to list database users."""
|
||||
LOG.debug("Listing Users for Instance %s", self.id)
|
||||
LOG.debug("Listing Users for Instance %s.", self.id)
|
||||
return self._call("list_users", AGENT_LOW_TIMEOUT, limit=limit,
|
||||
marker=marker, include_marker=include_marker)
|
||||
|
||||
def delete_user(self, user):
|
||||
"""Make an asynchronous call to delete an existing database user."""
|
||||
LOG.debug("Deleting user %(user)s for Instance %(instance_id)s" %
|
||||
LOG.debug("Deleting user %(user)s for Instance %(instance_id)s." %
|
||||
{'user': user, 'instance_id': self.id})
|
||||
self._cast("delete_user", user=user)
|
||||
|
||||
@ -173,12 +174,12 @@ class API(proxy.RpcProxy):
|
||||
"""Make an asynchronous call to create a new database
|
||||
within the specified container
|
||||
"""
|
||||
LOG.debug("Creating databases for Instance %s", self.id)
|
||||
LOG.debug("Creating databases for Instance %s.", self.id)
|
||||
self._cast("create_database", databases=databases)
|
||||
|
||||
def list_databases(self, limit=None, marker=None, include_marker=False):
|
||||
"""Make an asynchronous call to list databases."""
|
||||
LOG.debug("Listing databases for Instance %s", self.id)
|
||||
LOG.debug("Listing databases for Instance %s.", self.id)
|
||||
return self._call("list_databases", AGENT_LOW_TIMEOUT, limit=limit,
|
||||
marker=marker, include_marker=include_marker)
|
||||
|
||||
@ -187,39 +188,39 @@ class API(proxy.RpcProxy):
|
||||
within the specified container
|
||||
"""
|
||||
LOG.debug("Deleting database %(database)s for "
|
||||
"Instance %(instance_id)s" % {'database': database,
|
||||
'instance_id': self.id})
|
||||
"Instance %(instance_id)s." % {'database': database,
|
||||
'instance_id': self.id})
|
||||
self._cast("delete_database", database=database)
|
||||
|
||||
def enable_root(self):
|
||||
"""Make a synchronous call to enable the root user for
|
||||
access from anywhere
|
||||
"""
|
||||
LOG.debug("Enable root user for Instance %s", self.id)
|
||||
LOG.debug("Enable root user for Instance %s.", self.id)
|
||||
return self._call("enable_root", AGENT_HIGH_TIMEOUT)
|
||||
|
||||
def disable_root(self):
|
||||
"""Make a synchronous call to disable the root user for
|
||||
access from anywhere
|
||||
"""
|
||||
LOG.debug("Disable root user for Instance %s", self.id)
|
||||
LOG.debug("Disable root user for Instance %s.", self.id)
|
||||
return self._call("disable_root", AGENT_LOW_TIMEOUT)
|
||||
|
||||
def is_root_enabled(self):
|
||||
"""Make a synchronous call to check if root access is
|
||||
available for the container
|
||||
"""
|
||||
LOG.debug("Check root access for Instance %s", self.id)
|
||||
LOG.debug("Check root access for Instance %s.", self.id)
|
||||
return self._call("is_root_enabled", AGENT_LOW_TIMEOUT)
|
||||
|
||||
def get_hwinfo(self):
|
||||
"""Make a synchronous call to get hardware info for the container"""
|
||||
LOG.debug("Check hwinfo on Instance %s", self.id)
|
||||
LOG.debug("Check hwinfo on Instance %s.", self.id)
|
||||
return self._call("get_hwinfo", AGENT_LOW_TIMEOUT)
|
||||
|
||||
def get_diagnostics(self):
|
||||
"""Make a synchronous call to get diagnostics for the container"""
|
||||
LOG.debug("Check diagnostics on Instance %s", self.id)
|
||||
LOG.debug("Check diagnostics on Instance %s.", self.id)
|
||||
return self._call("get_diagnostics", AGENT_LOW_TIMEOUT)
|
||||
|
||||
def prepare(self, memory_mb, packages, databases, users,
|
||||
@ -229,7 +230,7 @@ class API(proxy.RpcProxy):
|
||||
"""Make an asynchronous call to prepare the guest
|
||||
as a database container optionally includes a backup id for restores
|
||||
"""
|
||||
LOG.debug("Sending the call to prepare the Guest")
|
||||
LOG.debug("Sending the call to prepare the Guest.")
|
||||
packages = packages.split()
|
||||
self._cast_with_consumer(
|
||||
"prepare", packages=packages, databases=databases,
|
||||
@ -267,7 +268,7 @@ class API(proxy.RpcProxy):
|
||||
|
||||
def upgrade(self, instance_version, location, metadata=None):
|
||||
"""Make an asynchronous call to self upgrade the guest agent."""
|
||||
LOG.debug("Sending an upgrade call to nova-guest")
|
||||
LOG.debug("Sending an upgrade call to nova-guest.")
|
||||
self._cast("upgrade",
|
||||
instance_version=instance_version,
|
||||
location=location,
|
||||
@ -275,7 +276,7 @@ class API(proxy.RpcProxy):
|
||||
|
||||
def get_volume_info(self):
|
||||
"""Make a synchronous call to get volume info for the container."""
|
||||
LOG.debug("Check Volume Info on Instance %s", self.id)
|
||||
LOG.debug("Check Volume Info on Instance %s.", self.id)
|
||||
# self._check_for_hearbeat()
|
||||
return self._call("get_filesystem_stats", AGENT_LOW_TIMEOUT,
|
||||
fs_path=None)
|
||||
@ -287,57 +288,57 @@ class API(proxy.RpcProxy):
|
||||
def create_backup(self, backup_info):
|
||||
"""Make async call to create a full backup of this instance."""
|
||||
LOG.debug("Create Backup %(backup_id)s "
|
||||
"for Instance %(instance_id)s" %
|
||||
"for Instance %(instance_id)s." %
|
||||
{'backup_id': backup_info['id'], 'instance_id': self.id})
|
||||
self._cast("create_backup", backup_info=backup_info)
|
||||
|
||||
def mount_volume(self, device_path=None, mount_point=None):
|
||||
"""Mount the volume."""
|
||||
LOG.debug("Mount volume %(mount)s on instance %(id)s" % {
|
||||
LOG.debug("Mount volume %(mount)s on instance %(id)s." % {
|
||||
'mount': mount_point, 'id': self.id})
|
||||
self._call("mount_volume", AGENT_LOW_TIMEOUT,
|
||||
device_path=device_path, mount_point=mount_point)
|
||||
|
||||
def unmount_volume(self, device_path=None, mount_point=None):
|
||||
"""Unmount the volume."""
|
||||
LOG.debug("Unmount volume %(device)s on instance %(id)s" % {
|
||||
LOG.debug("Unmount volume %(device)s on instance %(id)s." % {
|
||||
'device': device_path, 'id': self.id})
|
||||
self._call("unmount_volume", AGENT_LOW_TIMEOUT,
|
||||
device_path=device_path, mount_point=mount_point)
|
||||
|
||||
def resize_fs(self, device_path=None, mount_point=None):
|
||||
"""Resize the filesystem."""
|
||||
LOG.debug("Resize device %(device)s on instance %(id)s" % {
|
||||
LOG.debug("Resize device %(device)s on instance %(id)s." % {
|
||||
'device': device_path, 'id': self.id})
|
||||
self._call("resize_fs", AGENT_HIGH_TIMEOUT, device_path=device_path,
|
||||
mount_point=mount_point)
|
||||
|
||||
def update_overrides(self, overrides, remove=False):
|
||||
"""Update the overrides."""
|
||||
LOG.debug("Updating overrides on Instance %s", self.id)
|
||||
LOG.debug("Updating overrides values %s" % overrides)
|
||||
LOG.debug("Updating overrides on Instance %s.", self.id)
|
||||
LOG.debug("Updating overrides values %s." % overrides)
|
||||
self._cast("update_overrides", overrides=overrides, remove=remove)
|
||||
|
||||
def apply_overrides(self, overrides):
|
||||
LOG.debug("Applying overrides on Instance %s", self.id)
|
||||
LOG.debug("Applying overrides values %s" % overrides)
|
||||
LOG.debug("Applying overrides on Instance %s.", self.id)
|
||||
LOG.debug("Applying overrides values %s." % overrides)
|
||||
self._cast("apply_overrides", overrides=overrides)
|
||||
|
||||
def get_replication_snapshot(self, master_config=None):
|
||||
LOG.debug("Retrieving replication snapshot from instance %s", self.id)
|
||||
LOG.debug("Retrieving replication snapshot from instance %s.", self.id)
|
||||
self._call("get_replication_snapshot", AGENT_HIGH_TIMEOUT,
|
||||
master_config=master_config)
|
||||
|
||||
def attach_replication_slave(self, snapshot, slave_config=None):
|
||||
LOG.debug("Configuring instance %s to replicate from %s",
|
||||
LOG.debug("Configuring instance %s to replicate from %s.",
|
||||
self.id, snapshot.get('master').get('id'))
|
||||
self._cast("attach_replication_slave", snapshot=snapshot,
|
||||
slave_config=slave_config)
|
||||
|
||||
def detach_replication_slave(self):
|
||||
LOG.debug("Detaching slave %s from its master", self.id)
|
||||
LOG.debug("Detaching slave %s from its master.", self.id)
|
||||
self._call("detach_replication_slave", AGENT_LOW_TIMEOUT)
|
||||
|
||||
def demote_replication_master(self):
|
||||
LOG.debug("Demoting instance %s to non-master", self.id)
|
||||
LOG.debug("Demoting instance %s to non-master.", self.id)
|
||||
self._call("demote_replication_master", AGENT_LOW_TIMEOUT)
|
||||
|
@ -28,6 +28,7 @@ import os
|
||||
from trove.openstack.common import log
|
||||
from itertools import chain
|
||||
from trove.common import cfg
|
||||
from trove.openstack.common.gettextutils import _
|
||||
|
||||
|
||||
LOG = log.getLogger(__name__)
|
||||
@ -69,7 +70,7 @@ def get_filesystem_volume_stats(fs_path):
|
||||
try:
|
||||
stats = os.statvfs(fs_path)
|
||||
except OSError:
|
||||
LOG.exception("Error getting volume stats.")
|
||||
LOG.exception(_("Error getting volume stats."))
|
||||
raise RuntimeError("Filesystem not found (%s)" % fs_path)
|
||||
|
||||
total = stats.f_blocks * stats.f_bsize
|
||||
|
@ -21,6 +21,7 @@ from trove.common import utils
|
||||
from trove.db import get_db_api
|
||||
from trove.db import models as dbmodels
|
||||
from trove.openstack.common import log as logging
|
||||
from trove.openstack.common.gettextutils import _
|
||||
|
||||
LOG = logging.getLogger(__name__)
|
||||
|
||||
@ -81,8 +82,8 @@ class AgentHeartBeat(dbmodels.DatabaseModelBase):
|
||||
try:
|
||||
return cls.find_by(instance_id=instance_id)
|
||||
|
||||
except exception.NotFound as e:
|
||||
LOG.error(e.message)
|
||||
except exception.NotFound:
|
||||
LOG.exception(_("Error finding instance %s") % instance_id)
|
||||
raise exception.ModelNotFoundError(instance_id=instance_id)
|
||||
|
||||
@staticmethod
|
||||
|
@ -114,7 +114,8 @@ class RedhatPackagerMixin(BasePackagerMixin):
|
||||
utils.execute("rpm", "-e", "--nodeps", package_name,
|
||||
run_as_root=True, root_helper="sudo")
|
||||
except ProcessExecutionError:
|
||||
LOG.error(_("Error removing conflict %s") % package_name)
|
||||
LOG.exception(_("Error removing conflict %(package)s") %
|
||||
package_name)
|
||||
|
||||
def _install(self, packages, time_out):
|
||||
"""Attempts to install packages.
|
||||
@ -164,6 +165,7 @@ class RedhatPackagerMixin(BasePackagerMixin):
|
||||
|
||||
"""
|
||||
cmd = "sudo yum --color=never -y remove %s" % package_name
|
||||
LOG.debug("Running package remove command: %s" % cmd)
|
||||
output_expects = ['\[sudo\] password for .*:',
|
||||
'No Packages marked for removal',
|
||||
'Removed:']
|
||||
@ -210,8 +212,9 @@ class RedhatPackagerMixin(BasePackagerMixin):
|
||||
if matches:
|
||||
line = matches.group()
|
||||
return line
|
||||
msg = _("version() saw unexpected output from rpm!")
|
||||
LOG.error(msg)
|
||||
|
||||
LOG.error(_("Unexpected output from rpm command. (%(output)s)") %
|
||||
{'output': std_out})
|
||||
|
||||
def pkg_remove(self, package_name, time_out):
|
||||
"""Removes a package."""
|
||||
@ -233,7 +236,7 @@ class DebianPackagerMixin(BasePackagerMixin):
|
||||
utils.execute("dpkg", "--configure", "-a", run_as_root=True,
|
||||
root_helper="sudo")
|
||||
except ProcessExecutionError:
|
||||
LOG.error(_("Error fixing dpkg"))
|
||||
LOG.exception(_("Error fixing dpkg"))
|
||||
|
||||
def _fix_package_selections(self, packages, config_opts):
|
||||
"""
|
||||
@ -320,6 +323,7 @@ class DebianPackagerMixin(BasePackagerMixin):
|
||||
"'sudo dpkg --configure -a'"),
|
||||
"Unable to lock the administration directory",
|
||||
"Removing %s*" % package_name]
|
||||
LOG.debug("Running remove package command %s" % cmd)
|
||||
i, match = self.pexpect_run(cmd, output_expects, time_out)
|
||||
if i == 0:
|
||||
raise PkgPermissionError("Invalid permissions.")
|
||||
@ -339,7 +343,7 @@ class DebianPackagerMixin(BasePackagerMixin):
|
||||
utils.execute("apt-get", "update", run_as_root=True,
|
||||
root_helper="sudo")
|
||||
except ProcessExecutionError:
|
||||
LOG.error(_("Error updating the apt sources"))
|
||||
LOG.exception(_("Error updating the apt sources"))
|
||||
|
||||
result = self._install(packages, time_out)
|
||||
if result != OK:
|
||||
|
@ -13,13 +13,10 @@
|
||||
# License for the specific language governing permissions and limitations
|
||||
# under the License.
|
||||
|
||||
from trove.openstack.common import log as logging
|
||||
import routes
|
||||
|
||||
from trove.common import wsgi
|
||||
|
||||
LOG = logging.getLogger(__name__)
|
||||
|
||||
|
||||
class Controller(wsgi.Controller):
|
||||
"""Base controller class."""
|
||||
|
@ -54,15 +54,22 @@ class VolumeDevice(object):
|
||||
"""
|
||||
try:
|
||||
num_tries = CONF.num_tries
|
||||
LOG.debug("Checking if %s exists." % self.device_path)
|
||||
|
||||
utils.execute('sudo', 'blockdev', '--getsize64', self.device_path,
|
||||
attempts=num_tries)
|
||||
except ProcessExecutionError:
|
||||
LOG.exception(_("Error getting device status"))
|
||||
raise GuestError(_("InvalidDevicePath(path=%s)") %
|
||||
self.device_path)
|
||||
|
||||
def _check_format(self):
|
||||
"""Checks that an unmounted volume is formatted."""
|
||||
child = pexpect.spawn("sudo dumpe2fs %s" % self.device_path)
|
||||
cmd = "sudo dumpe2fs %s" % self.device_path
|
||||
LOG.debug("Checking whether %s is formated: %s." %
|
||||
(self.device_path, cmd))
|
||||
|
||||
child = pexpect.spawn(cmd)
|
||||
try:
|
||||
i = child.expect(['has_journal', 'Wrong magic number'])
|
||||
if i == 0:
|
||||
@ -83,6 +90,8 @@ class VolumeDevice(object):
|
||||
cmd = "sudo mkfs -t %s %s %s" % (volume_fstype,
|
||||
format_options, self.device_path)
|
||||
volume_format_timeout = CONF.volume_format_timeout
|
||||
LOG.debug("Formatting %s. Executing: %s.",
|
||||
(self.device_path, cmd))
|
||||
child = pexpect.spawn(cmd, timeout=volume_format_timeout)
|
||||
# child.expect("(y,n)")
|
||||
# child.sendline('y')
|
||||
@ -96,6 +105,8 @@ class VolumeDevice(object):
|
||||
|
||||
def mount(self, mount_point, write_to_fstab=True):
|
||||
"""Mounts, and writes to fstab."""
|
||||
LOG.debug("Will mount %s at %s." % (self.device_path, mount_point))
|
||||
|
||||
mount_point = VolumeMountPoint(self.device_path, mount_point)
|
||||
mount_point.mount()
|
||||
if write_to_fstab:
|
||||
@ -111,8 +122,8 @@ class VolumeDevice(object):
|
||||
run_as_root=True, root_helper="sudo")
|
||||
utils.execute("resize2fs", self.device_path,
|
||||
run_as_root=True, root_helper="sudo")
|
||||
except ProcessExecutionError as err:
|
||||
LOG.error(err)
|
||||
except ProcessExecutionError:
|
||||
LOG.exception(_("Error resizing file system."))
|
||||
raise GuestError(_("Error resizing the filesystem: %s") %
|
||||
self.device_path)
|
||||
|
||||
@ -127,9 +138,8 @@ class VolumeDevice(object):
|
||||
mount_points = self.mount_points(device_path)
|
||||
for mnt in mount_points:
|
||||
LOG.info(_("Device %(device)s is already mounted in "
|
||||
"%(mount_point)s") %
|
||||
"%(mount_point)s. Unmounting now.") %
|
||||
{'device': device_path, 'mount_point': mnt})
|
||||
LOG.info(_("Unmounting %s") % mnt)
|
||||
self.unmount(mnt)
|
||||
|
||||
def mount_points(self, device_path):
|
||||
@ -139,8 +149,8 @@ class VolumeDevice(object):
|
||||
stdout, stderr = utils.execute(cmd, shell=True)
|
||||
return stdout.strip().split('\n')
|
||||
|
||||
except ProcessExecutionError as err:
|
||||
LOG.error(err)
|
||||
except ProcessExecutionError:
|
||||
LOG.exception(_("Error retrieving mount points"))
|
||||
raise GuestError(_("Could not obtain a list of mount points for "
|
||||
"device: %s") % device_path)
|
||||
|
||||
|
Loading…
Reference in New Issue
Block a user