diff --git a/.testr.conf b/.testr.conf index e8f41cd80f..7e8d028994 100644 --- a/.testr.conf +++ b/.testr.conf @@ -1,4 +1,4 @@ [DEFAULT] -test_command=OS_LOG_LEVEL=${OS_LOG_LEVEL:-INFO} OS_STDOUT_CAPTURE=${OS_STDOUT_CAPTURE:-1} OS_STDERR_CAPTURE=${OS_STDERR_CAPTURE:-1} OS_LOG_CAPTURE=${OS_LOG_CAPTURE:-1} OS_LOG_DEFAULTS=${OS_LOG_DEFAULTS:-""} ${PYTHON:-python} -m subunit.run discover -t ./ ${OS_TEST_PATH:-./tests/unit} $LISTOPT $IDOPTION +test_command=OS_STDOUT_CAPTURE=${OS_STDOUT_CAPTURE:-1} OS_STDERR_CAPTURE=${OS_STDERR_CAPTURE:-1} OS_LOG_CAPTURE=${OS_LOG_CAPTURE:-1} OS_LOG_DEFAULTS=${OS_LOG_DEFAULTS:-""} ${PYTHON:-python} -m subunit.run discover -t ./ ${OS_TEST_PATH:-./tests/unit} $LISTOPT $IDOPTION test_id_option=--load-list $IDFILE test_list_option=--list diff --git a/tests/base.py b/tests/base.py index 2d1dd7d50a..1c3a86f1b3 100755 --- a/tests/base.py +++ b/tests/base.py @@ -28,10 +28,12 @@ import re import select import shutil from six.moves import reload_module +from six import StringIO import socket import string import subprocess import swiftclient +import sys import tempfile import threading import time @@ -43,6 +45,8 @@ import kazoo.client import kazoo.exceptions import statsd import testtools +import testtools.content +import testtools.content_type from git.exc import NoSuchPathError import zuul.driver.gerrit.gerritsource as gerritsource @@ -64,10 +68,6 @@ FIXTURE_DIR = os.path.join(os.path.dirname(__file__), 'fixtures') USE_TEMPDIR = True -logging.basicConfig(level=logging.DEBUG, - format='%(asctime)s %(name)-32s ' - '%(levelname)-8s %(message)s') - def repack_repo(path): cmd = ['git', '--git-dir=%s/.git' % path, 'repack', '-afd'] @@ -1048,6 +1048,20 @@ class ChrootedKazooFixture(fixtures.Fixture): class BaseTestCase(testtools.TestCase): log = logging.getLogger("zuul.test") + def attachLogs(self, *args): + def reader(): + self._log_stream.seek(0) + while True: + x = self._log_stream.read(4096) + if not x: + break + yield x.encode('utf8') + content = testtools.content.content_from_reader( + reader, + testtools.content_type.UTF8_TEXT, + False) + self.addDetail('logging', content) + def setUp(self): super(BaseTestCase, self).setUp() test_timeout = os.environ.get('OS_TEST_TIMEOUT', 0) @@ -1069,40 +1083,37 @@ class BaseTestCase(testtools.TestCase): self.useFixture(fixtures.MonkeyPatch('sys.stderr', stderr)) if (os.environ.get('OS_LOG_CAPTURE') == 'True' or os.environ.get('OS_LOG_CAPTURE') == '1'): - log_level = logging.DEBUG - if os.environ.get('OS_LOG_LEVEL') == 'DEBUG': - log_level = logging.DEBUG - elif os.environ.get('OS_LOG_LEVEL') == 'INFO': - log_level = logging.INFO - elif os.environ.get('OS_LOG_LEVEL') == 'WARNING': - log_level = logging.WARNING - elif os.environ.get('OS_LOG_LEVEL') == 'ERROR': - log_level = logging.ERROR - elif os.environ.get('OS_LOG_LEVEL') == 'CRITICAL': - log_level = logging.CRITICAL - self.useFixture(fixtures.FakeLogger( - level=log_level, - format='%(asctime)s %(name)-32s ' - '%(levelname)-8s %(message)s')) + self._log_stream = StringIO() + self.addOnException(self.attachLogs) + else: + self._log_stream = sys.stdout - # NOTE(notmorgan): Extract logging overrides for specific libraries - # from the OS_LOG_DEFAULTS env and create FakeLogger fixtures for - # each. This is used to limit the output during test runs from - # libraries that zuul depends on such as gear. + handler = logging.StreamHandler(self._log_stream) + formatter = logging.Formatter('%(asctime)s %(name)-32s ' + '%(levelname)-8s %(message)s') + handler.setFormatter(formatter) + + logger = logging.getLogger() + logger.setLevel(logging.DEBUG) + logger.addHandler(handler) + + # NOTE(notmorgan): Extract logging overrides for specific + # libraries from the OS_LOG_DEFAULTS env and create loggers + # for each. This is used to limit the output during test runs + # from libraries that zuul depends on such as gear. log_defaults_from_env = os.environ.get( 'OS_LOG_DEFAULTS', - 'git.cmd=INFO,kazoo.client=INFO') + 'git.cmd=INFO,kazoo.client=WARNING,gear=INFO') if log_defaults_from_env: for default in log_defaults_from_env.split(','): try: name, level_str = default.split('=', 1) level = getattr(logging, level_str, logging.DEBUG) - self.useFixture(fixtures.FakeLogger( - name=name, - level=level, - format='%(asctime)s %(name)-32s ' - '%(levelname)-8s %(message)s')) + logger = logging.getLogger(name) + logger.setLevel(level) + logger.addHandler(handler) + logger.propagate = False except ValueError: # NOTE(notmorgan): Invalid format of the log default, # skip and don't try and apply a logger for the diff --git a/tests/unit/test_clonemapper.py b/tests/unit/test_clonemapper.py index b7814f82ef..bd8c8b0534 100644 --- a/tests/unit/test_clonemapper.py +++ b/tests/unit/test_clonemapper.py @@ -13,14 +13,9 @@ # License for the specific language governing permissions and limitations # under the License. -import logging import testtools from zuul.lib.clonemapper import CloneMapper -logging.basicConfig(level=logging.DEBUG, - format='%(asctime)s %(name)-17s ' - '%(levelname)-8s %(message)s') - class TestCloneMapper(testtools.TestCase): diff --git a/tests/unit/test_cloner.py b/tests/unit/test_cloner.py index 67b5303a38..2cdc8267ba 100644 --- a/tests/unit/test_cloner.py +++ b/tests/unit/test_cloner.py @@ -26,10 +26,6 @@ import zuul.lib.cloner from tests.base import ZuulTestCase -logging.basicConfig(level=logging.DEBUG, - format='%(asctime)s %(name)-32s ' - '%(levelname)-8s %(message)s') - class TestCloner(ZuulTestCase): diff --git a/tests/unit/test_cloner_cmd.py b/tests/unit/test_cloner_cmd.py index 9cbb5b83fd..2d8747f1d3 100644 --- a/tests/unit/test_cloner_cmd.py +++ b/tests/unit/test_cloner_cmd.py @@ -12,16 +12,11 @@ # License for the specific language governing permissions and limitations # under the License. -import logging import os import testtools import zuul.cmd.cloner -logging.basicConfig(level=logging.DEBUG, - format='%(asctime)s %(name)-32s ' - '%(levelname)-8s %(message)s') - class TestClonerCmdArguments(testtools.TestCase): diff --git a/tests/unit/test_merger_repo.py b/tests/unit/test_merger_repo.py index 5062c14405..f8153445df 100644 --- a/tests/unit/test_merger_repo.py +++ b/tests/unit/test_merger_repo.py @@ -23,10 +23,6 @@ import git from zuul.merger.merger import Repo from tests.base import ZuulTestCase -logging.basicConfig(level=logging.DEBUG, - format='%(asctime)s %(name)-32s ' - '%(levelname)-8s %(message)s') - class TestMergerRepo(ZuulTestCase): diff --git a/tests/unit/test_openstack.py b/tests/unit/test_openstack.py index 175b4bd323..d0c7ab2165 100644 --- a/tests/unit/test_openstack.py +++ b/tests/unit/test_openstack.py @@ -14,14 +14,8 @@ # License for the specific language governing permissions and limitations # under the License. -import logging - from tests.base import AnsibleZuulTestCase -logging.basicConfig(level=logging.DEBUG, - format='%(asctime)s %(name)-32s ' - '%(levelname)-8s %(message)s') - class TestOpenStack(AnsibleZuulTestCase): # A temporary class to experiment with how openstack can use diff --git a/tests/unit/test_requirements.py b/tests/unit/test_requirements.py index 1ea0b2eb38..7e578cf5d3 100644 --- a/tests/unit/test_requirements.py +++ b/tests/unit/test_requirements.py @@ -14,15 +14,10 @@ # License for the specific language governing permissions and limitations # under the License. -import logging import time from tests.base import ZuulTestCase -logging.basicConfig(level=logging.DEBUG, - format='%(asctime)s %(name)-32s ' - '%(levelname)-8s %(message)s') - class TestRequirementsApprovalNewerThan(ZuulTestCase): """Requirements with a newer-than comment requirement""" diff --git a/tests/unit/test_scheduler.py b/tests/unit/test_scheduler.py index 86c7c2df51..55c56d4388 100755 --- a/tests/unit/test_scheduler.py +++ b/tests/unit/test_scheduler.py @@ -15,7 +15,6 @@ # under the License. import json -import logging import os import re import shutil @@ -36,10 +35,6 @@ from tests.base import ( repack_repo, ) -logging.basicConfig(level=logging.DEBUG, - format='%(asctime)s %(name)-32s ' - '%(levelname)-8s %(message)s') - class TestScheduler(ZuulTestCase): tenant_config_file = 'config/single-tenant/main.yaml' diff --git a/tests/unit/test_v3.py b/tests/unit/test_v3.py index 9034bf7d59..31410fb9e3 100644 --- a/tests/unit/test_v3.py +++ b/tests/unit/test_v3.py @@ -14,16 +14,11 @@ # License for the specific language governing permissions and limitations # under the License. -import logging import os import textwrap from tests.base import AnsibleZuulTestCase -logging.basicConfig(level=logging.DEBUG, - format='%(asctime)s %(name)-32s ' - '%(levelname)-8s %(message)s') - class TestMultipleTenants(AnsibleZuulTestCase): # A temporary class to hold new tests while others are disabled diff --git a/tests/unit/test_zuultrigger.py b/tests/unit/test_zuultrigger.py index b36e5a4fe7..5d9c6e073b 100644 --- a/tests/unit/test_zuultrigger.py +++ b/tests/unit/test_zuultrigger.py @@ -14,14 +14,8 @@ # License for the specific language governing permissions and limitations # under the License. -import logging - from tests.base import ZuulTestCase -logging.basicConfig(level=logging.DEBUG, - format='%(asctime)s %(name)-32s ' - '%(levelname)-8s %(message)s') - class TestZuulTriggerParentChangeEnqueued(ZuulTestCase): tenant_config_file = 'config/zuultrigger/parent-change-enqueued/main.yaml' diff --git a/tox.ini b/tox.ini index 58acf09e55..b7d89d18f6 100644 --- a/tox.ini +++ b/tox.ini @@ -9,8 +9,7 @@ setenv = STATSD_HOST=127.0.0.1 STATSD_PORT=8125 VIRTUAL_ENV={envdir} OS_TEST_TIMEOUT=60 - OS_LOG_DEFAULTS={env:OS_LOG_DEFAULTS:gear=WARNING} -passenv = ZUUL_TEST_ROOT OS_STDOUT_CAPTURE OS_STDERR_CAPTURE OS_LOG_CAPTURE +passenv = ZUUL_TEST_ROOT OS_STDOUT_CAPTURE OS_STDERR_CAPTURE OS_LOG_CAPTURE OS_LOG_DEFAULTS usedevelop = True install_command = pip install {opts} {packages} deps = -r{toxinidir}/requirements.txt