Repository: dwavesystems/dwave-cloud-client
Pull request #625 (2024-06-11 20:17:56)

Test logging configurations
Here we update our logging config helper and test some interesting/useful configurations. 


Patch:
diff --git a/dwave/cloud/__init__.py b/dwave/cloud/__init__.py
index 77ec720..b2bc8ef 100644
--- a/dwave/cloud/__init__.py
+++ b/dwave/cloud/__init__.py
@@ -95,22 +95,31 @@ def configure_logging(logger: typing.Optional[logging.Logger] = None,
                       *,
                       level: int = logging.WARNING,
                       filter_secrets: bool = True,
-                      output_stream: io.IOBase = sys.stderr,
+                      output_stream: typing.Optional[io.IOBase] = None,
                       in_utc: bool = False,
                       structured_output: bool = False,
+                      handler_level: typing.Optional[int] = None,
+                      additive: bool = False,
                       ) -> logging.Logger:
     """Configure cloud-client's `dwave.cloud` base logger.
 
     Logging output from the cloud-client is suppressed by default. This utility
-    function can be used from user's (app) code to quickly setup basic logging
-    from the library.
+    function can be used to quickly setup basic logging from the library.
+
+    .. note::
+       This function is currently intended for internal/private use only.
 
     .. versionadded:: 0.12.0
        Explicit optional logging configuration. Previously, logger was minimally
        configured by default.
     """
+
     if logger is None:
         logger = logging.getLogger(__name__)
+    if output_stream is None:
+        output_stream = sys.stderr
+    if handler_level is None:
+        handler_level = level
 
     format = dict(
         fmt='%(asctime)s %(name)s %(levelname)s %(threadName)s [%(funcName)s] %(message)s',
@@ -128,12 +137,18 @@ def configure_logging(logger: typing.Optional[logging.Logger] = None,
     else:
         Formatter = formatter_base
 
+    if not additive:
+        # make sure handlers are not accumulated
+        while len(logger.handlers):
+            logger.removeHandler(logger.handlers[-1])
+
     formatter = Formatter(**format)
     handler = logging.StreamHandler(stream=output_stream)
     handler.setFormatter(formatter)
+    handler.setLevel(handler_level)
 
-    logger.setLevel(level)
     logger.addHandler(handler)
+    logger.setLevel(level)
 
     return logger
 


Test patch:
diff --git a/tests/test_utils.py b/tests/test_utils.py
index 911bb08..f96014d 100644
--- a/tests/test_utils.py
+++ b/tests/test_utils.py
@@ -12,6 +12,7 @@
 # See the License for the specific language governing permissions and
 # limitations under the License.
 
+import io
 import copy
 import json
 import uuid
@@ -24,13 +25,13 @@ from unittest import mock
 from collections import OrderedDict
 from itertools import count
 from datetime import datetime
-from functools import partial
+from functools import partial, wraps
 from typing import Tuple, Union
 
 import numpy
 from parameterized import parameterized
 
-from dwave.cloud import FilteredSecretsFormatter
+from dwave.cloud import FilteredSecretsFormatter, configure_logging
 from dwave.cloud.utils import (
     uniform_iterator, uniform_get, strip_head, strip_tail,
     active_qubits, generate_random_ising_problem,
@@ -39,6 +40,8 @@ from dwave.cloud.utils import (
     parse_loglevel, user_agent, default_user_agent, hasinstance, exception_chain,
     is_caused_by, get_distribution, PackageNotFoundError, VersionNotFoundError)
 
+logger = logging.getLogger(__name__)
+
 
 class TestSimpleUtils(unittest.TestCase):
 
@@ -983,5 +986,65 @@ class TestDistUtils(unittest.TestCase):
             get_distribution("package-that-is-not-installed")
 
 
+def capture_stderr(fn):
+    """Decorator that captures stderr and provides access via `output` argument."""
+    @wraps(fn)
+    def wrapper(*args, **kwargs):
+        with contextlib.redirect_stderr(io.StringIO()) as output:
+            return fn(*args, output=output, **kwargs)
+    return wrapper
+
+
+class TestLogging(unittest.TestCase):
+
+    @capture_stderr
+    def test_default_configure(self, output):
+        configure_logging(logger)
+
+        logger.info('test')
+        logger.warning('secret: beefcafe-aaaa-bbbb-cccc-0123456789ab')
+
+        # level is warning+, and secrets are filtered
+        lines = output.getvalue().splitlines()
+        self.assertEqual(len(lines), 1)
+        self.assertIn('bee...9ab', lines[0])
+
+    @capture_stderr
+    def test_structured_logging(self, output):
+        configure_logging(logger, level=logging.INFO, structured_output=True)
+
+        logger.info('test', extra=dict(key='value'))
+
+        # level is info+, json output contains the extra dict
+        lines = output.getvalue().splitlines()
+        self.assertEqual(len(lines), 1)
+        record = json.loads(lines[0])
+        self.assertEqual(record.get('message'), 'test')
+        self.assertEqual(record.get('key'), 'value')
+
+    @capture_stderr
+    def test_multiple_handlers(self, output):
+        structured_stream = io.StringIO()
+
+        configure_logging(
+            logger, handler_level=logging.ERROR)
+        configure_logging(
+            logger, level=logging.DEBUG, additive=True,
+            output_stream=structured_stream, structured_output=True)
+
+        logger.debug('debug')
+        logger.error('error')
+
+        # structured_stream has all as json, stderr only errors in text
+        error = output.getvalue().splitlines()
+        self.assertEqual(len(error), 1)
+        self.assertIn('error', error[0])
+
+        debug = list(map(json.loads, structured_stream.getvalue().splitlines()))
+        self.assertEqual(len(debug), 2)
+        self.assertEqual(debug[0].get('message'), 'debug')
+        self.assertEqual(debug[1].get('message'), 'error')
+
+
 if __name__ == '__main__':
     unittest.main()