]> review.fuel-infra Code Review - openstack-build/cinder-build.git/commitdiff
Copy StandardLogging fixture from Nova
authorMatt Riedemann <mriedem@us.ibm.com>
Mon, 29 Feb 2016 17:31:22 +0000 (12:31 -0500)
committerMatt Riedemann <mriedem@us.ibm.com>
Mon, 29 Feb 2016 22:46:31 +0000 (17:46 -0500)
This code was originally written for Nova by Joe Gordon
<joe.gordon0@gmail.com> and Sean Dague <sean@dague.net>.

This enables debug logging that is exercised by unit test
runs to be handled and detect formatting errors. The debug
logging does not actually go to the console unless the
OS_DEBUG environment variable is set.

As a result, a few formatting errors are detected and
cleaned up with this change.

This also fixes a problem where debug logging from stevedore
is dumped to the console every time an extension is loaded,
which in a gate-cinder-python27 job is 65K+ times.

Change-Id: I989f9d591d1483a56a1bab3c20de583e85997562
Closes-Bug: #1551325

cinder/backup/chunkeddriver.py
cinder/test.py
cinder/tests/fixtures.py [new file with mode: 0644]
cinder/tests/unit/test_vmware_vmdk.py
cinder/volume/drivers/hpe/hpe_lefthand_iscsi.py

index c77536109f253b288bce296b0e895d1a6cb4ae8e..065e61cb5d10ce267279155546cde198dfea83cb 100644 (file)
@@ -352,7 +352,7 @@ class ChunkedBackupDriver(driver.BackupDriver):
                       'compressed length: %(compressed_size_bytes)d. '
                       'Using original data for this chunk.',
                       {'data_size_bytes': data_size_bytes,
-                       'comp_size_bytes': comp_size_bytes,
+                       'compressed_size_bytes': comp_size_bytes,
                        })
             return 'none', data
         LOG.debug('Compressed %(data_size_bytes)d bytes of data '
index b068f237d03e45ed9669e3b4346aef3261b9a647..1d2d01c35abf51fe20a76b9f15c663de63be476f 100644 (file)
@@ -32,6 +32,7 @@ import mock
 from oslo_concurrency import lockutils
 from oslo_config import cfg
 from oslo_config import fixture as config_fixture
+from oslo_log.fixture import logging_error as log_fixture
 from oslo_log import log
 from oslo_messaging import conffixture as messaging_conffixture
 from oslo_utils import strutils
@@ -46,6 +47,7 @@ from cinder import i18n
 from cinder.objects import base as objects_base
 from cinder import rpc
 from cinder import service
+from cinder.tests import fixtures as cinder_fixtures
 from cinder.tests.unit import conf_fixture
 from cinder.tests.unit import fake_notifier
 
@@ -172,15 +174,9 @@ class TestCase(testtools.TestCase):
         if environ_enabled('OS_STDERR_CAPTURE'):
             stderr = self.useFixture(fixtures.StringStream('stderr')).stream
             self.useFixture(fixtures.MonkeyPatch('sys.stderr', stderr))
-        if environ_enabled('OS_LOG_CAPTURE'):
-            log_format = '%(levelname)s [%(name)s] %(message)s'
-            if environ_enabled('OS_DEBUG'):
-                level = logging.DEBUG
-            else:
-                level = logging.INFO
-            self.useFixture(fixtures.LoggerFixture(nuke_handlers=False,
-                                                   format=log_format,
-                                                   level=level))
+
+        self.useFixture(log_fixture.get_logging_handle_error_fixture())
+        self.useFixture(cinder_fixtures.StandardLogging())
 
         rpc.add_extra_exmods("cinder.tests.unit")
         self.addCleanup(rpc.clear_extra_exmods)
@@ -307,11 +303,6 @@ class TestCase(testtools.TestCase):
         for k, v in kw.items():
             self.override_config(k, v)
 
-    def log_level(self, level):
-        """Set logging level to the specified value."""
-        log_root = logging.getLogger(None).logger
-        log_root.setLevel(level)
-
     def start_service(self, name, host=None, **kwargs):
         host = host and host or uuid.uuid4().hex
         kwargs.setdefault('host', host)
diff --git a/cinder/tests/fixtures.py b/cinder/tests/fixtures.py
new file mode 100644 (file)
index 0000000..f858578
--- /dev/null
@@ -0,0 +1,101 @@
+# Copyright 2016 IBM Corp.
+#
+#    Licensed under the Apache License, Version 2.0 (the "License"); you may
+#    not use this file except in compliance with the License. You may obtain
+#    a copy of the License at
+#
+#         http://www.apache.org/licenses/LICENSE-2.0
+#
+#    Unless required by applicable law or agreed to in writing, software
+#    distributed under the License is distributed on an "AS IS" BASIS, WITHOUT
+#    WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. See the
+#    License for the specific language governing permissions and limitations
+#    under the License.
+
+"""Fixtures for Cinder tests."""
+# NOTE(mriedem): This is needed for importing from fixtures.
+from __future__ import absolute_import
+
+import logging as std_logging
+import os
+
+import fixtures
+
+_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(fixtures.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(
+            fixtures.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(fixtures.LogHandler(handler, nuke_handlers=False))
+            handler.setLevel(std_logging.DEBUG)
+
+            # Don't log every single DB migration step
+            std_logging.getLogger(
+                'migrate.versioning.api').setLevel(std_logging.WARNING)
index 2e514bbdc19a1c7d798d749e0e75773d7bc75b8d..f1870a3f5e966e9c06d6e667d71892306fa2bc2a 100644 (file)
@@ -733,7 +733,8 @@ class VMwareVcVmdkDriverTestCase(test.TestCase):
         host = mock.sentinel.host
         rp = mock.sentinel.rp
         folder = mock.sentinel.folder
-        summary = mock.Mock(name=mock.sentinel.ds_name)
+        # NOTE(mriedem): The summary.name gets logged so it has to be a string
+        summary = mock.Mock(name=six.text_type(mock.sentinel.ds_name))
         select_ds_for_volume.return_value = (host, rp, folder, summary)
 
         profile_id = mock.sentinel.profile_id
index ac5f9a9b18c9172d9ec6289bb1baffa94e1b6c61..0c5411d044c441fd6af38e665efc76e156d49689 100644 (file)
@@ -462,7 +462,7 @@ class HPELeftHandISCSIDriver(driver.ISCSIDriver):
                 volume_update['status'] = 'deleted'
             except Exception as ex:
                 LOG.error(_LE("There was an error deleting volume %(id)s: "
-                              "%(error)."),
+                              "%(error)s."),
                           {'id': volume.id,
                            'error': six.text_type(ex)})
                 volume_update['status'] = 'error'