From f1dec5c2e2972cf571af9845b201bbb22bbc8cea Mon Sep 17 00:00:00 2001 From: Kyle Stevenson Date: Tue, 27 Jan 2015 13:56:05 -0800 Subject: [PATCH] Add additional logging and return results for IPA extensions Some of the extensions in IPA currently do not return any values from their respective command methods. This results in a lack of a paper trail of the command_result value to the point where it is not possible to know more information than a boolean result of if a command succeeded or failed. This change adds more logging to the extensions and provides return values which are used in the command_result property on (Async|Sync)CommandResult instances to provide useful debug info. While creating this patch several unit tests for *CommandResult objects were found to be using invalid data that would not pass validation if returned in API results. Those have been corrected in this patch. Change-Id: I23bae25a83881e7013c93d73f858c622ea941253 Closes-Bug: 1408080 --- ironic_python_agent/extensions/base.py | 11 ++++++ ironic_python_agent/extensions/decom.py | 2 ++ ironic_python_agent/extensions/standby.py | 8 +++++ ironic_python_agent/tests/agent.py | 3 +- ironic_python_agent/tests/extensions/base.py | 10 +++--- ironic_python_agent/tests/extensions/decom.py | 3 ++ .../tests/extensions/standby.py | 35 ++++++++++++++----- 7 files changed, 59 insertions(+), 13 deletions(-) diff --git a/ironic_python_agent/extensions/base.py b/ironic_python_agent/extensions/base.py index 8454cd768..03b839450 100644 --- a/ironic_python_agent/extensions/base.py +++ b/ironic_python_agent/extensions/base.py @@ -78,6 +78,11 @@ class SyncCommandResult(BaseCommandResult): super(SyncCommandResult, self).__init__(command_name, command_params) + + if type(result_or_error) in (str, unicode): + result_key = 'result' if success else 'error' + result_or_error = {result_key: result_or_error} + if success: self.command_status = AgentCommandStatus.SUCCEEDED self.command_result = result_or_error @@ -141,6 +146,10 @@ class AsyncCommandResult(BaseCommandResult): """Run a command.""" try: result = self.execute_method(**self.command_params) + + if type(result) in (str, unicode): + result = {'result': '{}: {}'.format(self.command_name, result)} + with self.command_state_lock: self.command_result = result self.command_status = AgentCommandStatus.SUCCEEDED @@ -239,6 +248,8 @@ def async_command(command_name, validator=None): """Will run the command in an AsyncCommandResult in its own thread. command_name is set based on the func name and command_params will be whatever args/kwargs you pass into the decorated command. + Return values of type `str` or `unicode` are prefixed with the + `command_name` parameter when returned for consistency. """ def async_decorator(func): func.command_name = command_name diff --git a/ironic_python_agent/extensions/decom.py b/ironic_python_agent/extensions/decom.py index cc73387da..2596bffc4 100644 --- a/ironic_python_agent/extensions/decom.py +++ b/ironic_python_agent/extensions/decom.py @@ -20,3 +20,5 @@ class DecomExtension(base.BaseAgentExtension): @base.async_command('erase_hardware') def erase_hardware(self): hardware.dispatch_to_managers('erase_devices') + + return 'finished' diff --git a/ironic_python_agent/extensions/standby.py b/ironic_python_agent/extensions/standby.py index b792d177b..862635d2b 100644 --- a/ironic_python_agent/extensions/standby.py +++ b/ironic_python_agent/extensions/standby.py @@ -210,10 +210,15 @@ class StandbyExtension(base.BaseAgentExtension): def cache_image(self, image_info=None, force=False): device = hardware.dispatch_to_managers('get_os_install_device') + result_msg = 'image ({0}) already present on device {1}' + if self.cached_image_id != image_info['id'] or force: _download_image(image_info) _write_image(image_info, device) self.cached_image_id = image_info['id'] + result_msg = 'image ({0}) cached to device {1}' + + return result_msg.format(image_info['id'], device) @base.async_command('prepare_image', _validate_image_info) def prepare_image(self, @@ -230,6 +235,9 @@ class StandbyExtension(base.BaseAgentExtension): if configdrive is not None: _write_configdrive_to_partition(configdrive, device) + return 'image ({0}) written to device {1}'.format(image_info['id'], + device) + @base.async_command('run_image') def run_image(self): script = _path_to_script('shell/reboot.sh') diff --git a/ironic_python_agent/tests/agent.py b/ironic_python_agent/tests/agent.py index f11473e4b..63ef31b9c 100644 --- a/ironic_python_agent/tests/agent.py +++ b/ironic_python_agent/tests/agent.py @@ -267,7 +267,8 @@ class TestBaseAgent(test_base.BaseTestCase): result.join() expected_result['command_status'] = 'SUCCEEDED' - expected_result['command_result'] = 'command execution succeeded' + expected_result['command_result'] = {'result': ('foo_command: command ' + 'execution succeeded')} self.assertEqualEncoded(result, expected_result) diff --git a/ironic_python_agent/tests/extensions/base.py b/ironic_python_agent/tests/extensions/base.py index 30ce34a07..b033314cb 100644 --- a/ironic_python_agent/tests/extensions/base.py +++ b/ironic_python_agent/tests/extensions/base.py @@ -114,7 +114,7 @@ class TestExecuteCommandMixin(test_base.BaseTestCase): ) self.assertEqual(result.command_status, base.AgentCommandStatus.FAILED) - self.assertEqual(result.command_error, msg) + self.assertEqual(result.command_error, {'error': msg}) class TestExtensionDecorators(test_base.BaseTestCase): @@ -133,7 +133,8 @@ class TestExtensionDecorators(test_base.BaseTestCase): self.assertEqual(base.AgentCommandStatus.SUCCEEDED, result.command_status) self.assertEqual(None, result.command_error) - self.assertEqual('v1', result.command_result) + self.assertEqual({'result': 'fake_async_command: v1'}, + result.command_result) self.agent.force_heartbeat.assert_called_once_with() def test_async_command_success_without_agent(self): @@ -146,7 +147,8 @@ class TestExtensionDecorators(test_base.BaseTestCase): self.assertEqual(base.AgentCommandStatus.SUCCEEDED, result.command_status) self.assertEqual(None, result.command_error) - self.assertEqual('v1', result.command_result) + self.assertEqual({'result': 'fake_async_command: v1'}, + result.command_result) def test_async_command_validation_failure(self): self.assertRaises(errors.InvalidCommandParamsError, @@ -181,7 +183,7 @@ class TestExtensionDecorators(test_base.BaseTestCase): self.assertEqual(base.AgentCommandStatus.SUCCEEDED, result.command_status) self.assertEqual(None, result.command_error) - self.assertEqual('v1', result.command_result) + self.assertEqual({'result': 'v1'}, result.command_result) # no need to force heartbeat on a sync command self.assertEqual(0, self.agent.force_heartbeat.call_count) diff --git a/ironic_python_agent/tests/extensions/decom.py b/ironic_python_agent/tests/extensions/decom.py index cfa01dd4c..751c58044 100644 --- a/ironic_python_agent/tests/extensions/decom.py +++ b/ironic_python_agent/tests/extensions/decom.py @@ -29,3 +29,6 @@ class TestDecomExtension(test_base.BaseTestCase): result = self.agent_extension.erase_hardware() result.join() mocked_dispatch.assert_called_once_with('erase_devices') + self.assertTrue('result' in result.command_result.keys()) + cmd_result_text = 'erase_hardware: finished' + self.assertEqual(cmd_result_text, result.command_result['result']) diff --git a/ironic_python_agent/tests/extensions/standby.py b/ironic_python_agent/tests/extensions/standby.py index 2e1079eb1..73d63aad8 100644 --- a/ironic_python_agent/tests/extensions/standby.py +++ b/ironic_python_agent/tests/extensions/standby.py @@ -276,7 +276,8 @@ class TestStandbyExtension(test_base.BaseTestCase): autospec=True) @mock.patch('ironic_python_agent.extensions.standby._download_image', autospec=True) - def test_cache_image(self, download_mock, write_mock, dispatch_mock): + def test_cache_image(self, download_mock, write_mock, + dispatch_mock): image_info = self._build_fake_image_info() download_mock.return_value = None write_mock.return_value = None @@ -289,7 +290,10 @@ class TestStandbyExtension(test_base.BaseTestCase): self.assertEqual(self.agent_extension.cached_image_id, image_info['id']) self.assertEqual('SUCCEEDED', async_result.command_status) - self.assertEqual(None, async_result.command_result) + self.assertTrue('result' in async_result.command_result.keys()) + cmd_result = ('cache_image: image ({0}) cached to device {1}' + ).format(image_info['id'], 'manager') + self.assertEqual(cmd_result, async_result.command_result['result']) @mock.patch('ironic_python_agent.hardware.dispatch_to_managers', autospec=True) @@ -298,7 +302,7 @@ class TestStandbyExtension(test_base.BaseTestCase): @mock.patch('ironic_python_agent.extensions.standby._download_image', autospec=True) def test_cache_image_force(self, download_mock, write_mock, - dispatch_mock): + dispatch_mock): image_info = self._build_fake_image_info() self.agent_extension.cached_image_id = image_info['id'] download_mock.return_value = None @@ -314,7 +318,10 @@ class TestStandbyExtension(test_base.BaseTestCase): self.assertEqual(self.agent_extension.cached_image_id, image_info['id']) self.assertEqual('SUCCEEDED', async_result.command_status) - self.assertEqual(None, async_result.command_result) + self.assertTrue('result' in async_result.command_result.keys()) + cmd_result = ('cache_image: image ({0}) cached to device {1}' + ).format(image_info['id'], 'manager') + self.assertEqual(cmd_result, async_result.command_result['result']) @mock.patch('ironic_python_agent.hardware.dispatch_to_managers', autospec=True) @@ -337,7 +344,10 @@ class TestStandbyExtension(test_base.BaseTestCase): self.assertEqual(self.agent_extension.cached_image_id, image_info['id']) self.assertEqual('SUCCEEDED', async_result.command_status) - self.assertEqual(None, async_result.command_result) + self.assertTrue('result' in async_result.command_result.keys()) + cmd_result = ('cache_image: image ({0}) already present on device {1}' + ).format(image_info['id'], 'manager') + self.assertEqual(cmd_result, async_result.command_result['result']) @mock.patch(('ironic_python_agent.extensions.standby.' '_write_configdrive_to_partition'), @@ -376,7 +386,10 @@ class TestStandbyExtension(test_base.BaseTestCase): 'manager') self.assertEqual('SUCCEEDED', async_result.command_status) - self.assertEqual(None, async_result.command_result) + self.assertTrue('result' in async_result.command_result.keys()) + cmd_result = ('prepare_image: image ({0}) written to device {1}' + ).format(image_info['id'], 'manager') + self.assertEqual(cmd_result, async_result.command_result['result']) download_mock.reset_mock() write_mock.reset_mock() @@ -394,7 +407,10 @@ class TestStandbyExtension(test_base.BaseTestCase): 'manager') self.assertEqual('SUCCEEDED', async_result.command_status) - self.assertEqual(None, async_result.command_result) + self.assertTrue('result' in async_result.command_result.keys()) + cmd_result = ('prepare_image: image ({0}) written to device {1}' + ).format(image_info['id'], 'manager') + self.assertEqual(cmd_result, async_result.command_result['result']) @mock.patch(('ironic_python_agent.extensions.standby.' '_write_configdrive_to_partition'), @@ -428,7 +444,10 @@ class TestStandbyExtension(test_base.BaseTestCase): self.assertEqual(configdrive_copy_mock.call_count, 0) self.assertEqual('SUCCEEDED', async_result.command_status) - self.assertEqual(None, async_result.command_result) + self.assertTrue('result' in async_result.command_result.keys()) + cmd_result = ('prepare_image: image ({0}) written to device {1}' + ).format(image_info['id'], 'manager') + self.assertEqual(cmd_result, async_result.command_result['result']) @mock.patch('ironic_python_agent.utils.execute', autospec=True) def test_run_image(self, execute_mock):