Merge "Add fixture to limit unit test log output"

This commit is contained in:
Zuul 2018-04-18 12:08:04 +00:00 committed by Gerrit Code Review
commit c6376ea0b3
2 changed files with 99 additions and 0 deletions

View File

@ -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."""

View File

@ -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)