Delay failure from pre-processing hooks

If something fails in the 'before_processing' hook, the only feedback
a user will receive is timeout. Actually, in many cases we're able
to find a node in cache and update it's state with reasonable error.

This patch collects exceptions from the pre-processing hooks and
raises them all after node is found in cache. If node is not found,
we assume that it might be due to hook failures.

Change-Id: I8f320504818b002981757dbc9bb1cf98b9829683
Closes-Bug: #1436276
This commit is contained in:
Dmitry Tantsur 2015-04-09 15:29:36 +02:00
parent 6eec990919
commit 958dc0a10b
2 changed files with 82 additions and 21 deletions

View File

@ -18,7 +18,7 @@ import logging
import eventlet
from ironicclient import exceptions
from ironic_discoverd.common.i18n import _, _LI, _LW
from ironic_discoverd.common.i18n import _, _LE, _LI, _LW
from ironic_discoverd import firewall
from ironic_discoverd import node_cache
from ironic_discoverd.plugins import base as plugins_base
@ -37,12 +37,50 @@ def process(node_info):
This function heavily relies on the hooks to do the actual data processing.
"""
hooks = plugins_base.processing_hooks_manager()
failures = []
for hook_ext in hooks:
hook_ext.obj.before_processing(node_info)
# NOTE(dtantsur): catch exceptions, so that we have changes to update
# node introspection status after look up
try:
hook_ext.obj.before_processing(node_info)
except utils.Error as exc:
LOG.error(_LE('Hook %(hook)s failed, delaying error report '
'until node look up: %(error)s'),
{'hook': hook_ext.name, 'error': exc})
failures.append('Preprocessing hook %(hook)s: %(error)s' %
{'hook': hook_ext.name, 'error': exc})
except Exception as exc:
LOG.exception(_LE('Hook %(hook)s failed, delaying error report '
'until node look up: %(error)s'),
{'hook': hook_ext.name, 'error': exc})
failures.append(_('Unexpected exception during preprocessing '
'in hook %s') % hook_ext.name)
cached_node = node_cache.find_node(
bmc_address=node_info.get('ipmi_address'),
mac=node_info.get('macs'))
try:
cached_node = node_cache.find_node(
bmc_address=node_info.get('ipmi_address'),
mac=node_info.get('macs'))
except utils.Error as exc:
if failures:
failures.append(_('Look up error: %s') % exc)
cached_node = None
else:
raise
if failures and cached_node:
msg = _('The following failures happened during running '
'pre-processing hooks for node %(uuid)s:\n%(failures)s') % {
'uuid': cached_node.uuid,
'failures': '\n'.join(failures)
}
cached_node.finished(error=_('Data pre-processing failed'))
raise utils.Error(msg)
elif failures:
msg = _('The following failures happened during running '
'pre-processing hooks for unknown node:\n%(failures)s') % {
'failures': '\n'.join(failures)
}
raise utils.Error(msg)
ironic = utils.get_client()
try:

View File

@ -21,6 +21,7 @@ from oslo_config import cfg
from ironic_discoverd import firewall
from ironic_discoverd import node_cache
from ironic_discoverd.plugins import base as plugins_base
from ironic_discoverd.plugins import example as example_plugin
from ironic_discoverd.plugins import standard as std_plugins
from ironic_discoverd import process
@ -71,7 +72,7 @@ class TestProcess(BaseTest):
pop_mock.return_value = node_cache.NodeInfo(
uuid=self.node.uuid,
started_at=self.started_at)
cli.port.create.side_effect = self.ports
pop_mock.return_value.finished = mock.Mock()
cli.node.get.return_value = self.node
process_mock.return_value = self.fake_result_json
@ -269,35 +270,57 @@ class TestProcess(BaseTest):
process.process, self.data)
cli.node.get.assert_called_once_with(self.uuid)
self.assertFalse(process_mock.called)
pop_mock.return_value.finished.assert_called_once_with(error=mock.ANY)
@mock.patch.object(node_cache.NodeInfo, 'finished', autospec=True)
def test_expected_exception(self, finished_mock, client_mock, pop_mock,
process_mock):
pop_mock.return_value = node_cache.NodeInfo(
uuid=self.node.uuid,
started_at=self.started_at)
@prepare_mocks
def test_expected_exception(self, cli, pop_mock, process_mock):
process_mock.side_effect = utils.Error('boom')
self.assertRaisesRegexp(utils.Error, 'boom',
process.process, self.data)
finished_mock.assert_called_once_with(mock.ANY, error='boom')
pop_mock.return_value.finished.assert_called_once_with(error='boom')
@mock.patch.object(node_cache.NodeInfo, 'finished', autospec=True)
def test_unexpected_exception(self, finished_mock, client_mock, pop_mock,
process_mock):
pop_mock.return_value = node_cache.NodeInfo(
uuid=self.node.uuid,
started_at=self.started_at)
@prepare_mocks
def test_unexpected_exception(self, cli, pop_mock, process_mock):
process_mock.side_effect = RuntimeError('boom')
self.assertRaisesRegexp(utils.Error, 'Unexpected exception',
process.process, self.data)
finished_mock.assert_called_once_with(
mock.ANY,
pop_mock.return_value.finished.assert_called_once_with(
error='Unexpected exception during processing')
@prepare_mocks
def test_hook_unexpected_exceptions(self, cli, pop_mock, process_mock):
for ext in plugins_base.processing_hooks_manager():
patcher = mock.patch.object(ext.obj, 'before_processing',
side_effect=RuntimeError('boom'))
patcher.start()
self.addCleanup(lambda p=patcher: p.stop())
self.assertRaisesRegexp(utils.Error, 'Unexpected exception',
process.process, self.data)
pop_mock.return_value.finished.assert_called_once_with(
error='Data pre-processing failed')
@prepare_mocks
def test_hook_unexpected_exceptions_no_node(self, cli, pop_mock,
process_mock):
# Check that error from hooks is raised, not "not found"
pop_mock.side_effect = utils.Error('not found')
for ext in plugins_base.processing_hooks_manager():
patcher = mock.patch.object(ext.obj, 'before_processing',
side_effect=RuntimeError('boom'))
patcher.start()
self.addCleanup(lambda p=patcher: p.stop())
self.assertRaisesRegexp(utils.Error, 'Unexpected exception',
process.process, self.data)
self.assertFalse(pop_mock.return_value.finished.called)
@mock.patch.object(eventlet.greenthread, 'spawn_n',
lambda f, *a: f(*a) and None)