diff --git a/glance/tests/unit/fixtures.py b/glance/tests/unit/fixtures.py index e082df386d..423e3ebbb9 100644 --- a/glance/tests/unit/fixtures.py +++ b/glance/tests/unit/fixtures.py @@ -14,11 +14,105 @@ # NOTE(mriedem): This is needed for importing from fixtures. from __future__ import absolute_import +import logging as std_logging +import os import warnings import fixtures as pyfixtures +_TRUE_VALUES = ('True', 'true', '1', 'yes') + + +class NullHandler(std_logging.Handler): + """custom default NullHandler to attempt to format the record. + + Used in conjunction with + log_fixture.get_logging_handle_error_fixture to detect formatting errors in + debug level logs without saving the logs. + """ + def handle(self, record): + self.format(record) + + def emit(self, record): + pass + + def createLock(self): + self.lock = None + + +class StandardLogging(pyfixtures.Fixture): + """Setup Logging redirection for tests. + + There are a number of things we want to handle with logging in tests: + + * Redirect the logging to somewhere that we can test or dump it later. + + * Ensure that as many DEBUG messages as possible are actually + executed, to ensure they are actually syntactically valid (they + often have not been). + + * Ensure that we create useful output for tests that doesn't + overwhelm the testing system (which means we can't capture the + 100 MB of debug logging on every run). + + To do this we create a logger fixture at the root level, which + defaults to INFO and create a Null Logger at DEBUG which lets + us execute log messages at DEBUG but not keep the output. + + To support local debugging OS_DEBUG=True can be set in the + environment, which will print out the full debug logging. + + There are also a set of overrides for particularly verbose + modules to be even less than INFO. + + """ + + def setUp(self): + super(StandardLogging, self).setUp() + + # set root logger to debug + root = std_logging.getLogger() + root.setLevel(std_logging.DEBUG) + + # supports collecting debug level for local runs + if os.environ.get('OS_DEBUG') in _TRUE_VALUES: + level = std_logging.DEBUG + else: + level = std_logging.INFO + + # Collect logs + fs = '%(asctime)s %(levelname)s [%(name)s] %(message)s' + self.logger = self.useFixture( + pyfixtures.FakeLogger(format=fs, level=None)) + # TODO(sdague): why can't we send level through the fake + # logger? Tests prove that it breaks, but it's worth getting + # to the bottom of. + root.handlers[0].setLevel(level) + + if level > std_logging.DEBUG: + # Just attempt to format debug level logs, but don't save them + handler = NullHandler() + self.useFixture( + pyfixtures.LogHandler(handler, nuke_handlers=False)) + handler.setLevel(std_logging.DEBUG) + + # Don't log every single DB migration step + std_logging.getLogger( + 'alembic.runtime.migration').setLevel(std_logging.WARNING) + + # At times we end up calling back into main() functions in + # testing. This has the possibility of calling logging.setup + # again, which completely unwinds the logging capture we've + # created here. Once we've setup the logging in the way we want, + # disable the ability for the test to change this. + def fake_logging_setup(*args): + pass + + self.useFixture( + pyfixtures.MonkeyPatch('oslo_log.log.setup', fake_logging_setup)) + + class WarningsFixture(pyfixtures.Fixture): """Filters out warnings during test runs.""" diff --git a/glance/tests/utils.py b/glance/tests/utils.py index 32d85c3a6c..056c449c98 100644 --- a/glance/tests/utils.py +++ b/glance/tests/utils.py @@ -27,6 +27,7 @@ from alembic import command as alembic_command import fixtures from oslo_config import cfg from oslo_config import fixture as cfg_fixture +from oslo_log.fixture import logging_error as log_fixture from oslo_log import log from oslo_serialization import jsonutils from oslotest import moxstubout @@ -87,6 +88,10 @@ class BaseTestCase(testtools.TestCase): # Limit the amount of DeprecationWarning messages in the unit test logs self.useFixture(glance_fixtures.WarningsFixture()) + # Make sure logging output is limited but still test debug formatting + self.useFixture(log_fixture.get_logging_handle_error_fixture()) + self.useFixture(glance_fixtures.StandardLogging()) + def set_policy(self): conf_file = "policy.json" self.policy_file = self._copy_data_file(conf_file, self.conf_dir)