diff --git a/ironic/drivers/modules/agent_base_vendor.py b/ironic/drivers/modules/agent_base_vendor.py index f09228afa5..788c2bde31 100644 --- a/ironic/drivers/modules/agent_base_vendor.py +++ b/ironic/drivers/modules/agent_base_vendor.py @@ -20,6 +20,7 @@ import ast import collections import time +from ironic_lib import metrics_utils from oslo_log import log from oslo_utils import excutils from oslo_utils import strutils @@ -47,6 +48,8 @@ from ironic import objects LOG = log.getLogger(__name__) +METRICS = metrics_utils.get_metrics_logger(__name__) + # This contains a nested dictionary containing the post clean step # hooks registered for each clean step of every interface. # Every key of POST_CLEAN_STEP_HOOKS is an interface and its value @@ -81,6 +84,7 @@ def _get_client(): return client +@METRICS.timer('post_clean_step_hook') def post_clean_step_hook(interface, step): """Decorator method for adding a post clean step hook. @@ -205,6 +209,7 @@ def _get_completed_cleaning_command(task, commands): return last_command +@METRICS.timer('log_and_raise_deployment_error') def log_and_raise_deployment_error(task, msg): """Helper method to log the error and raise exception.""" LOG.error(msg) @@ -246,6 +251,7 @@ class AgentDeployMixin(object): """ + @METRICS.timer('AgentDeployMixin._refresh_clean_steps') def _refresh_clean_steps(self, task): """Refresh the node's cached clean steps from the booted agent. @@ -302,6 +308,7 @@ class AgentDeployMixin(object): LOG.debug('Refreshed agent clean step cache for node %(node)s: ' '%(steps)s', {'node': node.uuid, 'steps': steps}) + @METRICS.timer('AgentDeployMixin.continue_cleaning') def continue_cleaning(self, task, **kwargs): """Start the next cleaning step if the previous one is complete. @@ -435,6 +442,7 @@ class AgentDeployMixin(object): LOG.error(msg) return manager_utils.cleaning_error_handler(task, msg) + @METRICS.timer('AgentDeployMixin.heartbeat') def heartbeat(self, task, callback_url): """Process a heartbeat. @@ -513,6 +521,7 @@ class AgentDeployMixin(object): elif node.provision_state in (states.DEPLOYING, states.DEPLOYWAIT): deploy_utils.set_failed_state(task, last_error) + @METRICS.timer('AgentDeployMixin.reboot_and_finish_deploy') def reboot_and_finish_deploy(self, task): """Helper method to trigger reboot on the node and finish deploy. @@ -587,6 +596,7 @@ class AgentDeployMixin(object): task.process_event('done') LOG.info(_LI('Deployment to node %s done'), task.node.uuid) + @METRICS.timer('AgentDeployMixin.prepare_instance_to_boot') def prepare_instance_to_boot(self, task, root_uuid, efi_sys_uuid): """Prepares instance to boot. @@ -611,6 +621,7 @@ class AgentDeployMixin(object): msg = _('Failed to continue agent deployment.') log_and_raise_deployment_error(task, msg) + @METRICS.timer('AgentDeployMixin.configure_local_boot') def configure_local_boot(self, task, root_uuid=None, efi_system_part_uuid=None): """Helper method to configure local boot on the node. @@ -698,6 +709,7 @@ class BaseAgentVendor(AgentDeployMixin, base.VendorInterface): 'payload version: %s') % version) + @METRICS.timer('BaseAgentVendor.heartbeat') @base.passthru(['POST']) @task_manager.require_exclusive_lock def heartbeat(self, task, **kwargs): @@ -721,6 +733,7 @@ class BaseAgentVendor(AgentDeployMixin, base.VendorInterface): super(BaseAgentVendor, self).heartbeat(task, callback_url) + @METRICS.timer('BaseAgentVendor.lookup') @base.driver_passthru(['POST'], async=False) def lookup(self, context, **kwargs): """Find a matching node for the agent. diff --git a/ironic/drivers/modules/iscsi_deploy.py b/ironic/drivers/modules/iscsi_deploy.py index e43afad816..e4e69d7688 100644 --- a/ironic/drivers/modules/iscsi_deploy.py +++ b/ironic/drivers/modules/iscsi_deploy.py @@ -16,6 +16,7 @@ import os from ironic_lib import disk_utils +from ironic_lib import metrics_utils from ironic_lib import utils as ironic_utils from oslo_config import cfg from oslo_log import log as logging @@ -36,6 +37,8 @@ from ironic.drivers.modules import image_cache LOG = logging.getLogger(__name__) +METRICS = metrics_utils.get_metrics_logger(__name__) + # NOTE(rameshg87): This file now registers some of opts in pxe group. # This is acceptable for now as a future refactoring into # separate boot and deploy interfaces is planned, and moving config @@ -128,6 +131,7 @@ def _save_disk_layout(node, i_info): node.save() +@METRICS.timer('check_image_size') def check_image_size(task): """Check if the requested image is larger than the root partition size. @@ -146,6 +150,7 @@ def check_image_size(task): raise exception.InstanceDeployFailure(msg) +@METRICS.timer('cache_instance_image') def cache_instance_image(ctx, node): """Fetch the instance's image from Glance @@ -171,6 +176,7 @@ def cache_instance_image(ctx, node): return (uuid, image_path) +@METRICS.timer('destroy_images') def destroy_images(node_uuid): """Delete instance's image file. @@ -181,6 +187,7 @@ def destroy_images(node_uuid): InstanceImageCache().clean_up() +@METRICS.timer('get_deploy_info') def get_deploy_info(node, address, iqn, port=None, lun='1'): """Returns the information required for doing iSCSI deploy in a dictionary. @@ -234,6 +241,7 @@ def get_deploy_info(node, address, iqn, port=None, lun='1'): return params +@METRICS.timer('continue_deploy') def continue_deploy(task, **kwargs): """Resume a deployment upon getting POST data from deploy ramdisk. @@ -305,6 +313,7 @@ def continue_deploy(task, **kwargs): return uuid_dict_returned +@METRICS.timer('do_agent_iscsi_deploy') def do_agent_iscsi_deploy(task, agent_client): """Method invoked when deployed with the agent ramdisk. @@ -374,6 +383,7 @@ def _get_boot_mode(node): return "bios" +@METRICS.timer('validate') def validate(task): """Validates the pre-requisites for iSCSI deploy. @@ -396,6 +406,7 @@ def validate(task): class AgentDeployMixin(agent_base_vendor.AgentDeployMixin): + @METRICS.timer('AgentDeployMixin.continue_deploy') @task_manager.require_exclusive_lock def continue_deploy(self, task): """Method invoked when deployed using iSCSI. @@ -427,6 +438,7 @@ class ISCSIDeploy(AgentDeployMixin, base.DeployInterface): def get_properties(self): return {} + @METRICS.timer('ISCSIDeploy.validate') def validate(self, task): """Validate the deployment information for the task's node. @@ -445,6 +457,7 @@ class ISCSIDeploy(AgentDeployMixin, base.DeployInterface): # broken down into separate boot and deploy implementations. validate(task) + @METRICS.timer('ISCSIDeploy.deploy') @task_manager.require_exclusive_lock def deploy(self, task): """Start deployment of the task's node. @@ -465,6 +478,7 @@ class ISCSIDeploy(AgentDeployMixin, base.DeployInterface): return states.DEPLOYWAIT + @METRICS.timer('ISCSIDeploy.tear_down') @task_manager.require_exclusive_lock def tear_down(self, task): """Tear down a previous deployment on the task's node. @@ -484,6 +498,7 @@ class ISCSIDeploy(AgentDeployMixin, base.DeployInterface): task.driver.network.unconfigure_tenant_networks(task) return states.DELETED + @METRICS.timer('ISCSIDeploy.prepare') @task_manager.require_exclusive_lock def prepare(self, task): """Prepare the deployment environment for this task's node. @@ -514,6 +529,7 @@ class ISCSIDeploy(AgentDeployMixin, base.DeployInterface): deploy_opts = deploy_utils.build_agent_options(node) task.driver.boot.prepare_ramdisk(task, deploy_opts) + @METRICS.timer('ISCSIDeploy.clean_up') def clean_up(self, task): """Clean up the deployment environment for the task's node. @@ -531,6 +547,7 @@ class ISCSIDeploy(AgentDeployMixin, base.DeployInterface): def take_over(self, task): pass + @METRICS.timer('ISCSIDeploy.get_clean_steps') def get_clean_steps(self, task): """Get the list of clean steps from the agent. @@ -546,6 +563,7 @@ class ISCSIDeploy(AgentDeployMixin, base.DeployInterface): 'erase_devices': CONF.deploy.erase_devices_priority}) return steps + @METRICS.timer('ISCSIDeploy.execute_clean_step') def execute_clean_step(self, task, step): """Execute a clean step asynchronously on the agent. @@ -558,6 +576,7 @@ class ISCSIDeploy(AgentDeployMixin, base.DeployInterface): """ return deploy_utils.agent_execute_clean_step(task, step) + @METRICS.timer('ISCSIDeploy.prepare_cleaning') def prepare_cleaning(self, task): """Boot into the agent to prepare for cleaning. @@ -569,6 +588,7 @@ class ISCSIDeploy(AgentDeployMixin, base.DeployInterface): return deploy_utils.prepare_inband_cleaning( task, manage_boot=True) + @METRICS.timer('ISCSIDeploy.tear_down_cleaning') def tear_down_cleaning(self, task): """Clean up the PXE and DHCP files after cleaning. diff --git a/ironic/drivers/modules/pxe.py b/ironic/drivers/modules/pxe.py index e31db8c1cd..45634a9f6a 100644 --- a/ironic/drivers/modules/pxe.py +++ b/ironic/drivers/modules/pxe.py @@ -18,6 +18,7 @@ PXE Boot Interface import os import shutil +from ironic_lib import metrics_utils from ironic_lib import utils as ironic_utils from oslo_config import cfg from oslo_log import log as logging @@ -93,6 +94,8 @@ pxe_opts = [ LOG = logging.getLogger(__name__) +METRICS = metrics_utils.get_metrics_logger(__name__) + CONF = cfg.CONF CONF.register_opts(pxe_opts, group='pxe') CONF.import_opt('deploy_callback_timeout', 'ironic.conductor.manager', @@ -240,6 +243,7 @@ def _build_pxe_config_options(task, pxe_info): return pxe_options +@METRICS.timer('validate_boot_option_for_uefi') def validate_boot_option_for_uefi(node): """In uefi boot mode, validate if the boot option is compatible. @@ -263,6 +267,7 @@ def validate_boot_option_for_uefi(node): {'node_uuid': node.uuid}) +@METRICS.timer('validate_boot_option_for_trusted_boot') def validate_boot_parameters_for_trusted_boot(node): """Check if boot parameters are valid for trusted boot.""" boot_mode = deploy_utils.get_boot_mode_for_deploy(node) @@ -335,6 +340,7 @@ class PXEBoot(base.BootInterface): """ return COMMON_PROPERTIES + @METRICS.timer('PXEBoot.validate') def validate(self, task): """Validate the PXE-specific info for booting deploy/instance images. @@ -385,6 +391,7 @@ class PXEBoot(base.BootInterface): props = ['kernel', 'ramdisk'] deploy_utils.validate_image_properties(task.context, d_info, props) + @METRICS.timer('PXEBoot.prepare_ramdisk') def prepare_ramdisk(self, task, ramdisk_params): """Prepares the boot of Ironic ramdisk using PXE. @@ -441,6 +448,7 @@ class PXEBoot(base.BootInterface): # the image kernel and ramdisk (Or even require it). _cache_ramdisk_kernel(task.context, node, pxe_info) + @METRICS.timer('PXEBoot.clean_up_ramdisk') def clean_up_ramdisk(self, task): """Cleans up the boot of ironic ramdisk. @@ -461,6 +469,7 @@ class PXEBoot(base.BootInterface): else: _clean_up_pxe_env(task, images_info) + @METRICS.timer('PXEBoot.prepare_instance') def prepare_instance(self, task): """Prepares the boot of instance. @@ -525,6 +534,7 @@ class PXEBoot(base.BootInterface): pxe_utils.clean_up_pxe_config(task) deploy_utils.try_set_boot_device(task, boot_devices.DISK) + @METRICS.timer('PXEBoot.clean_up_instance') def clean_up_instance(self, task): """Cleans up the boot of instance. diff --git a/ironic/tests/unit/drivers/modules/test_agent_base_vendor.py b/ironic/tests/unit/drivers/modules/test_agent_base_vendor.py index 2bb5efc3b0..c0042a7090 100644 --- a/ironic/tests/unit/drivers/modules/test_agent_base_vendor.py +++ b/ironic/tests/unit/drivers/modules/test_agent_base_vendor.py @@ -957,9 +957,10 @@ class TestHeartbeat(AgentDeployMixinBaseTest): shared=False) as task: self.deploy.prepare_instance_to_boot(task, root_uuid, efi_system_part_uuid) - configure_mock.assert_called_once_with(self.deploy, task, - root_uuid, - efi_system_part_uuid) + configure_mock.assert_called_once_with( + self.deploy, task, + root_uuid=root_uuid, + efi_system_part_uuid=efi_system_part_uuid) boot_option_mock.assert_called_once_with(task.node) prepare_instance_mock.assert_called_once_with(task.driver.boot, task) @@ -991,9 +992,10 @@ class TestHeartbeat(AgentDeployMixinBaseTest): self.assertRaises(exception.InstanceDeployFailure, self.deploy.prepare_instance_to_boot, task, root_uuid, efi_system_part_uuid) - configure_mock.assert_called_once_with(self.deploy, task, - root_uuid, - efi_system_part_uuid) + configure_mock.assert_called_once_with( + self.deploy, task, + root_uuid=root_uuid, + efi_system_part_uuid=efi_system_part_uuid) boot_option_mock.assert_called_once_with(task.node) self.assertFalse(prepare_mock.called) self.assertFalse(failed_state_mock.called)