From de59b02a388a96e06afcbc64c38650414bbed595 Mon Sep 17 00:00:00 2001 From: Sean McGinnis Date: Mon, 5 Feb 2018 16:54:36 -0600 Subject: [PATCH] Make CinderException format errors fatal for tests This patch borrows very heavily from Nova change I680fd46d029ff58bd3b72ef7c7903c2271b26549. We have a config option to treat exception message formatting errors as fatal, but it turned out our overriding of that config option was not actually working. Since this is really something only useful for testing, and we pretty much always want errors like that caught in testing, this deprecates the option and changes the code to always enforce raising errors during unit testing when there are problems formatting any exception messages. The previous config option is pretty much useless now, but this way we are following the deprecation policy and we can remove it right away in Rocky. Closes-Bug: #1728984 Change-Id: Iaeb2657a6622cede32c5a59327393ca20758f3c3 --- cinder/exception.py | 29 ++++++++++--------- cinder/test.py | 23 ++++++++++++++- cinder/tests/unit/test_exception.py | 5 +++- .../drivers/ibm/test_ibm_flashsystem.py | 10 ++++--- .../volume/drivers/ibm/test_storwize_svc.py | 9 +++--- .../drivers/inspur/instorage/test_common.py | 8 ++--- 6 files changed, 57 insertions(+), 27 deletions(-) diff --git a/cinder/exception.py b/cinder/exception.py index 8f1fb872a53..fd5aba1823b 100644 --- a/cinder/exception.py +++ b/cinder/exception.py @@ -22,8 +22,6 @@ SHOULD include dedicated exception logging. """ -import sys - from oslo_config import cfg from oslo_log import log as logging from oslo_versionedobjects import exception as obj_exc @@ -37,10 +35,14 @@ from cinder.i18n import _ LOG = logging.getLogger(__name__) +# TODO(smcginnis) Remove in Rocky exc_log_opts = [ cfg.BoolOpt('fatal_exception_format_errors', default=False, - help='Make exception message format errors fatal.'), + help='Make exception message format errors fatal.', + deprecated_for_removal=True, + deprecated_since='12.0.0', + deprecated_reason='This is only used for internal testing.'), ] CONF = cfg.CONF @@ -108,16 +110,9 @@ class CinderException(Exception): message = self.message % kwargs except Exception: - exc_info = sys.exc_info() - # kwargs doesn't match a variable in the message - # log the issue and the kwargs - LOG.exception('Exception in string format operation') - for name, value in kwargs.items(): - LOG.error("%(name)s: %(value)s", - {'name': name, 'value': value}) - if CONF.fatal_exception_format_errors: - six.reraise(*exc_info) - # at least get the core message out if something happened + # NOTE(melwitt): This is done in a separate method so it can be + # monkey-patched during testing to make it a hard failure. + self._log_exception() message = self.message elif isinstance(message, Exception): # NOTE(tommylikehu): If this is a cinder exception it will @@ -131,6 +126,14 @@ class CinderException(Exception): self.msg = message super(CinderException, self).__init__(message) + def _log_exception(self): + # kwargs doesn't match a variable in the message + # log the issue and the kwargs + LOG.exception('Exception in string format operation:') + for name, value in self.kwargs.items(): + LOG.error("%(name)s: %(value)s", + {'name': name, 'value': value}) + def _should_format(self): return self.kwargs['message'] is None or '%(message)' in self.message diff --git a/cinder/test.py b/cinder/test.py index 80505ed34fa..18f82ef7c0a 100644 --- a/cinder/test.py +++ b/cinder/test.py @@ -23,6 +23,7 @@ inline callbacks. import copy import logging import os +import sys import uuid import fixtures @@ -43,6 +44,7 @@ from cinder import context from cinder import coordination from cinder.db import migration from cinder.db.sqlalchemy import api as sqla_api +from cinder import exception from cinder import i18n from cinder.objects import base as objects_base from cinder import rpc @@ -63,6 +65,26 @@ class TestingException(Exception): pass +class CinderExceptionReraiseFormatError(object): + real_log_exception = exception.CinderException._log_exception + + @classmethod + def patch(cls): + exception.CinderException._log_exception = cls._wrap_log_exception + + @staticmethod + def _wrap_log_exception(self): + exc_info = sys.exc_info() + CinderExceptionReraiseFormatError.real_log_exception(self) + six.reraise(*exc_info) + + +# NOTE(melwitt) This needs to be done at import time in order to also catch +# CinderException format errors that are in mock decorators. In these cases, +# the errors will be raised during test listing, before tests actually run. +CinderExceptionReraiseFormatError.patch() + + class Database(fixtures.Fixture): def __init__(self, db_api, db_migrate, sql_connection): @@ -228,7 +250,6 @@ class TestCase(testtools.TestCase): fake_notifier.mock_notifier(self) - self.override_config('fatal_exception_format_errors', True) # This will be cleaned up by the NestedTempfile fixture lock_path = self.useFixture(fixtures.TempDir()).path self.fixture = self.useFixture( diff --git a/cinder/tests/unit/test_exception.py b/cinder/tests/unit/test_exception.py index c30e341b32f..f1b080e37d5 100644 --- a/cinder/tests/unit/test_exception.py +++ b/cinder/tests/unit/test_exception.py @@ -15,6 +15,7 @@ # License for the specific language governing permissions and limitations # under the License. +import fixtures import mock import six from six.moves import http_client @@ -45,7 +46,9 @@ class CinderExceptionTestCase(test.TestCase): def test_error_msg_exception_with_kwargs(self): # NOTE(dprince): disable format errors for this test - self.flags(fatal_exception_format_errors=False) + self.useFixture(fixtures.MonkeyPatch( + 'cinder.exception.CinderException._log_exception', + test.CinderExceptionReraiseFormatError.real_log_exception)) class FakeCinderException(exception.CinderException): message = "default message: %(misspelled_code)s" diff --git a/cinder/tests/unit/volume/drivers/ibm/test_ibm_flashsystem.py b/cinder/tests/unit/volume/drivers/ibm/test_ibm_flashsystem.py index a9eccc0ab9c..db6c13c493b 100644 --- a/cinder/tests/unit/volume/drivers/ibm/test_ibm_flashsystem.py +++ b/cinder/tests/unit/volume/drivers/ibm/test_ibm_flashsystem.py @@ -934,7 +934,8 @@ class FlashSystemDriverTestCase(test.TestCase): # case 3: _get_vdisk_map_properties raises exception with mock.patch.object(flashsystem_fc.FlashSystemFCDriver, '_get_vdisk_map_properties') as get_properties: - get_properties.side_effect = exception.VolumeBackendAPIException + get_properties.side_effect = ( + exception.VolumeBackendAPIException(data='')) self.assertRaises(exception.VolumeBackendAPIException, self.driver.initialize_connection, vol1, self.connector) @@ -1091,7 +1092,8 @@ class FlashSystemDriverTestCase(test.TestCase): # case 3: _copy_vdisk_data raises exception self.driver.create_volume(vol1) - _copy_vdisk_data.side_effect = exception.VolumeBackendAPIException + _copy_vdisk_data.side_effect = ( + exception.VolumeBackendAPIException(data='')) self.assertRaises( exception.VolumeBackendAPIException, self.driver._create_and_copy_vdisk_data, @@ -1139,7 +1141,7 @@ class FlashSystemDriverTestCase(test.TestCase): self.driver.terminate_connection(vol2, connector) # case 3: no mapped before copy, raise exception when scan - _scan_device.side_effect = exception.VolumeBackendAPIException + _scan_device.side_effect = exception.VolumeBackendAPIException(data='') self.assertRaises( exception.VolumeBackendAPIException, self.driver._copy_vdisk_data, @@ -1150,7 +1152,7 @@ class FlashSystemDriverTestCase(test.TestCase): self.assertFalse(v2_mapped) # case 4: no mapped before copy, raise exception when copy - copy_volume.side_effect = exception.VolumeBackendAPIException + copy_volume.side_effect = exception.VolumeBackendAPIException(data='') self.assertRaises( exception.VolumeBackendAPIException, self.driver._copy_vdisk_data, diff --git a/cinder/tests/unit/volume/drivers/ibm/test_storwize_svc.py b/cinder/tests/unit/volume/drivers/ibm/test_storwize_svc.py index 57b09458e61..65c049915d4 100644 --- a/cinder/tests/unit/volume/drivers/ibm/test_storwize_svc.py +++ b/cinder/tests/unit/volume/drivers/ibm/test_storwize_svc.py @@ -4974,7 +4974,7 @@ class StorwizeSVCCommonDriverTestCase(test.TestCase): # Test prestartfcmap failing with mock.patch.object( storwize_svc_common.StorwizeSSH, 'prestartfcmap') as prestart: - prestart.side_effect = exception.VolumeBackendAPIException + prestart.side_effect = exception.VolumeBackendAPIException(data='') self.assertRaises(exception.VolumeBackendAPIException, self.driver.create_snapshot, snap1) @@ -5060,7 +5060,8 @@ class StorwizeSVCCommonDriverTestCase(test.TestCase): # Fail the snapshot with mock.patch.object( storwize_svc_common.StorwizeSSH, 'prestartfcmap') as prestart: - prestart.side_effect = exception.VolumeBackendAPIException + prestart.side_effect = exception.VolumeBackendAPIException( + data='') self.assertRaises(exception.VolumeBackendAPIException, self.driver.create_volume_from_snapshot, vol2, snap1) @@ -5922,14 +5923,14 @@ class StorwizeSVCCommonDriverTestCase(test.TestCase): self.assertEqual({'_name_id': None}, model_update) rename_vdisk.reset_mock() - rename_vdisk.side_effect = exception.VolumeBackendAPIException + rename_vdisk.side_effect = exception.VolumeBackendAPIException(data='') model_update = self.driver.update_migrated_volume(ctxt, volume, backend_volume, 'available') self.assertEqual({'_name_id': backend_volume.id}, model_update) rename_vdisk.reset_mock() - rename_vdisk.side_effect = exception.VolumeBackendAPIException + rename_vdisk.side_effect = exception.VolumeBackendAPIException(data='') model_update = self.driver.update_migrated_volume(ctxt, volume, backend_volume, 'attached') diff --git a/cinder/tests/unit/volume/drivers/inspur/instorage/test_common.py b/cinder/tests/unit/volume/drivers/inspur/instorage/test_common.py index 9e98351eff9..28a81c4a1a9 100644 --- a/cinder/tests/unit/volume/drivers/inspur/instorage/test_common.py +++ b/cinder/tests/unit/volume/drivers/inspur/instorage/test_common.py @@ -438,7 +438,7 @@ class InStorageMCSCommonDriverTestCase(test.TestCase): # Test prestartlcmap failing with mock.patch.object( instorage_common.InStorageSSH, 'prestartlcmap') as prestart: - prestart.side_effect = exception.VolumeBackendAPIException + prestart.side_effect = exception.VolumeBackendAPIException(data='') self.assertRaises(exception.VolumeBackendAPIException, self.driver.create_snapshot, snap1) @@ -527,7 +527,7 @@ class InStorageMCSCommonDriverTestCase(test.TestCase): # Fail the snapshot with mock.patch.object( instorage_common.InStorageSSH, 'prestartlcmap') as prestart: - prestart.side_effect = exception.VolumeBackendAPIException + prestart.side_effect = exception.VolumeBackendAPIException(data='') self.assertRaises(exception.VolumeBackendAPIException, self.driver.create_volume_from_snapshot, vol2, snap1) @@ -1361,14 +1361,14 @@ class InStorageMCSCommonDriverTestCase(test.TestCase): self.assertEqual({'_name_id': None}, model_update) rename_vdisk.reset_mock() - rename_vdisk.side_effect = exception.VolumeBackendAPIException + rename_vdisk.side_effect = exception.VolumeBackendAPIException(data='') model_update = self.driver.update_migrated_volume(ctxt, volume, backend_volume, 'available') self.assertEqual({'_name_id': backend_volume.id}, model_update) rename_vdisk.reset_mock() - rename_vdisk.side_effect = exception.VolumeBackendAPIException + rename_vdisk.side_effect = exception.VolumeBackendAPIException(data='') model_update = self.driver.update_migrated_volume(ctxt, volume, backend_volume, 'attached')