diff --git a/ironic/common/exception.py b/ironic/common/exception.py index 4352ee8bc8..a983bfba1a 100644 --- a/ironic/common/exception.py +++ b/ironic/common/exception.py @@ -20,7 +20,10 @@ SHOULD include dedicated exception logging. """ +import collections + from oslo_log import log as logging +from oslo_serialization import jsonutils import six from six.moves import http_client @@ -30,6 +33,52 @@ from ironic.conf import CONF LOG = logging.getLogger(__name__) +def _ensure_exception_kwargs_serializable(exc_class_name, kwargs): + """Ensure that kwargs are serializable + + Ensure that all kwargs passed to exception constructor can be passed over + RPC, by trying to convert them to JSON, or, as a last resort, to string. + If it is not possible, unserializable kwargs will be removed, letting the + receiver to handle the exception string as it is configured to. + + :param exc_class_name: an IronicException class name. + :param kwargs: a dictionary of keyword arguments passed to the exception + constructor. + :returns: a dictionary of serializable keyword arguments. + """ + serializers = [(jsonutils.dumps, _('when converting to JSON')), + (six.text_type, _('when converting to string'))] + exceptions = collections.defaultdict(list) + serializable_kwargs = {} + for k, v in kwargs.items(): + for serializer, msg in serializers: + try: + serializable_kwargs[k] = serializer(v) + exceptions.pop(k, None) + break + except Exception as e: + exceptions[k].append( + '(%(serializer_type)s) %(e_type)s: %(e_contents)s' % + {'serializer_type': msg, 'e_contents': e, + 'e_type': e.__class__.__name__}) + if exceptions: + LOG.error( + _LE("One or more arguments passed to the %(exc_class)s " + "constructor as kwargs can not be serialized. The serialized " + "arguments: %(serialized)s. These unserialized kwargs were " + "dropped because of the exceptions encountered during their " + "serialization:\n%(errors)s"), + dict(errors=';\n'.join("%s: %s" % (k, '; '.join(v)) + for k, v in exceptions.items()), + exc_class=exc_class_name, serialized=serializable_kwargs) + ) + # We might be able to actually put the following keys' values into + # format string, but there is no guarantee, drop it just in case. + for k in exceptions: + del kwargs[k] + return serializable_kwargs + + class IronicException(Exception): """Base Ironic Exception @@ -47,7 +96,9 @@ class IronicException(Exception): safe = False def __init__(self, message=None, **kwargs): - self.kwargs = kwargs + + self.kwargs = _ensure_exception_kwargs_serializable( + self.__class__.__name__, kwargs) if 'code' not in self.kwargs: try: diff --git a/ironic/tests/unit/common/test_exception.py b/ironic/tests/unit/common/test_exception.py index 443b36ae36..17a80b9fed 100644 --- a/ironic/tests/unit/common/test_exception.py +++ b/ironic/tests/unit/common/test_exception.py @@ -12,17 +12,65 @@ # License for the specific language governing permissions and limitations # under the License. +import re + +import mock import six from ironic.common import exception from ironic.tests import base +class Unserializable(object): + + def __str__(self): + raise NotImplementedError('nostr') + + +class TestException(exception.IronicException): + _msg_fmt = 'Some exception: %(spam)s, %(ham)s' + + class TestIronicException(base.TestCase): - def test____init__(self): + def test___init__(self): expected = b'\xc3\xa9\xe0\xaf\xb2\xe0\xbe\x84' if six.PY3: expected = expected.decode('utf-8') message = six.unichr(233) + six.unichr(0x0bf2) + six.unichr(3972) exc = exception.IronicException(message) self.assertEqual(expected, exc.__str__()) + + @mock.patch.object(exception.LOG, 'error', autospec=True) + def test___init___invalid_kwarg(self, log_mock): + self.config(fatal_exception_format_errors=False) + e = TestException(spam=Unserializable(), ham='eggs') + message = log_mock.call_args[0][0] % log_mock.call_args[0][1] + self.assertIsNotNone( + re.search('spam: .*JSON.* ValueError: Circular reference detected;' + '.*string.* NotImplementedError: nostr', message) + ) + self.assertEqual({'ham': '"eggs"', 'code': 500}, e.kwargs) + + @mock.patch.object(exception.LOG, 'error', autospec=True) + def test___init___invalid_kwarg_reraise(self, log_mock): + self.config(fatal_exception_format_errors=True) + self.assertRaises(KeyError, TestException, spam=Unserializable(), + ham='eggs') + message = log_mock.call_args[0][0] % log_mock.call_args[0][1] + self.assertIsNotNone( + re.search('spam: .*JSON.* ValueError: Circular reference detected;' + '.*string.* NotImplementedError: nostr', message) + ) + + def test___init___json_serializable(self): + exc = TestException(spam=[1, 2, 3], ham='eggs') + self.assertIn('[1, 2, 3]', six.text_type(exc)) + self.assertEqual('[1, 2, 3]', exc.kwargs['spam']) + + def test___init___string_serializable(self): + exc = TestException( + spam=type('ni', (object,), dict(a=1, b=2))(), ham='eggs' + ) + check_str = 'ni object at' + self.assertIn(check_str, six.text_type(exc)) + self.assertIn(check_str, exc.kwargs['spam']) diff --git a/releasenotes/notes/fix-rpc-exceptions-12c70eb6ba177e39.yaml b/releasenotes/notes/fix-rpc-exceptions-12c70eb6ba177e39.yaml new file mode 100644 index 0000000000..73d147ae4d --- /dev/null +++ b/releasenotes/notes/fix-rpc-exceptions-12c70eb6ba177e39.yaml @@ -0,0 +1,9 @@ +--- +fixes: + - Ironic exceptions that contained arbitrary objects in kwargs and were sent + via RPC were causing oslo_messaging serializer to fail. This was leading + to 500 errors from ironic API, timing out waiting for response from the + conductor. Starting with this release, all non-serializable objects + contained in an exception's kwargs are dropped. If the error is going to + be returned by the service will depend on the configuration option + ``[DEFAULT]fatal_exception_format_errors``.