address PR feedback

Author: ohmayr

google/api_core/client_logging.py

@@ -7,7 +7,7 @@
 _LOGGING_INITIALIZED = False
 _BASE_LOGGER_NAME = "google"
 
-# TODO(https://github.com/googleapis/python-api-core/issues/761): Update this list to support additional logging fields
+# TODO(https://github.com/googleapis/python-api-core/issues/761): Update this list to support additional logging fields.
 _recognized_logging_fields = [
     "httpRequest",
     "rpcName",
@@ -50,7 +50,7 @@ def configure_defaults(logger):
         logger.addHandler(console_handler)
 
 
-def setup_logging(scopes=[]):
+def setup_logging(scopes=""):
 
     # only returns valid logger scopes (namespaces)
     # this list has at most one element.
@@ -70,6 +70,8 @@ def setup_logging(scopes=[]):
 
 
 class StructuredLogFormatter(logging.Formatter):
+    # TODO(https://github.com/googleapis/python-api-core/issues/761): ensure that additional fields such as
+    # function name, file name, and line no. appear in a log output.
     def format(self, record):
         log_obj = {
             "timestamp": self.formatTime(record),

tests/unit/test_client_logging.py

@@ -1,9 +1,11 @@
+import json
 import logging
 from unittest import mock
 
 from google.api_core.client_logging import (
     setup_logging,
     initialize_logging,
+    StructuredLogFormatter,
 )
 
 
@@ -28,10 +30,10 @@ def test_setup_logging_w_no_scopes():
 def test_setup_logging_w_base_scope():
     with mock.patch("google.api_core.client_logging._BASE_LOGGER_NAME", "foo"):
         setup_logging("foo")
-    base_logger = logging.getLogger("foo")
-    assert isinstance(base_logger.handlers[0], logging.StreamHandler)
-    assert not base_logger.propagate
-    assert base_logger.level == logging.DEBUG
+        base_logger = logging.getLogger("foo")
+        assert isinstance(base_logger.handlers[0], logging.StreamHandler)
+        assert not base_logger.propagate
+        assert base_logger.level == logging.DEBUG
 
     reset_logger("foo")
 
@@ -40,15 +42,15 @@ def test_setup_logging_w_module_scope():
     with mock.patch("google.api_core.client_logging._BASE_LOGGER_NAME", "foo"):
         setup_logging("foo.bar")
 
-    base_logger = logging.getLogger("foo")
-    assert base_logger.handlers == []
-    assert not base_logger.propagate
-    assert base_logger.level == logging.NOTSET
+        base_logger = logging.getLogger("foo")
+        assert base_logger.handlers == []
+        assert not base_logger.propagate
+        assert base_logger.level == logging.NOTSET
 
-    module_logger = logging.getLogger("foo.bar")
-    assert isinstance(module_logger.handlers[0], logging.StreamHandler)
-    assert not module_logger.propagate
-    assert module_logger.level == logging.DEBUG
+        module_logger = logging.getLogger("foo.bar")
+        assert isinstance(module_logger.handlers[0], logging.StreamHandler)
+        assert not module_logger.propagate
+        assert module_logger.level == logging.DEBUG
 
     reset_logger("foo")
     reset_logger("foo.bar")
@@ -58,16 +60,16 @@ def test_setup_logging_w_incorrect_scope():
     with mock.patch("google.api_core.client_logging._BASE_LOGGER_NAME", "foo"):
         setup_logging("abc")
 
-    base_logger = logging.getLogger("foo")
-    assert base_logger.handlers == []
-    assert not base_logger.propagate
-    assert base_logger.level == logging.NOTSET
+        base_logger = logging.getLogger("foo")
+        assert base_logger.handlers == []
+        assert not base_logger.propagate
+        assert base_logger.level == logging.NOTSET
 
-    # TODO(https://github.com/googleapis/python-api-core/issues/759): update test once we add logic to ignore an incorrect scope.
-    logger = logging.getLogger("abc")
-    assert isinstance(logger.handlers[0], logging.StreamHandler)
-    assert not logger.propagate
-    assert logger.level == logging.DEBUG
+        # TODO(https://github.com/googleapis/python-api-core/issues/759): update test once we add logic to ignore an incorrect scope.
+        logger = logging.getLogger("abc")
+        assert isinstance(logger.handlers[0], logging.StreamHandler)
+        assert not logger.propagate
+        assert logger.level == logging.DEBUG
 
     reset_logger("foo")
     reset_logger("abc")
@@ -79,25 +81,48 @@ def test_initialize_logging():
         with mock.patch("google.api_core.client_logging._BASE_LOGGER_NAME", "foo"):
             initialize_logging()
 
-    base_logger = logging.getLogger("foo")
-    assert base_logger.handlers == []
-    assert not base_logger.propagate
-    assert base_logger.level == logging.NOTSET
+            base_logger = logging.getLogger("foo")
+            assert base_logger.handlers == []
+            assert not base_logger.propagate
+            assert base_logger.level == logging.NOTSET
 
-    module_logger = logging.getLogger("foo.bar")
-    assert isinstance(module_logger.handlers[0], logging.StreamHandler)
-    assert not module_logger.propagate
-    assert module_logger.level == logging.DEBUG
+            module_logger = logging.getLogger("foo.bar")
+            assert isinstance(module_logger.handlers[0], logging.StreamHandler)
+            assert not module_logger.propagate
+            assert module_logger.level == logging.DEBUG
 
-    base_logger.propagate = True
-    module_logger.propagate = True
+            # Check that `initialize_logging()` is a no-op after the first time by verifying that user-set configs are not modified:
+            base_logger.propagate = True
+            module_logger.propagate = True
 
-    with mock.patch("os.getenv", return_value="foo.bar"):
-        with mock.patch("google.api_core.client_logging._BASE_LOGGER_NAME", "foo"):
             initialize_logging()
 
-    assert base_logger.propagate
-    assert module_logger.propagate
+            assert base_logger.propagate
+            assert module_logger.propagate
 
     reset_logger("foo")
     reset_logger("foo.bar")
+
+
+def test_structured_log_formatter():
+    # TODO(https://github.com/googleapis/python-api-core/issues/761): Test additional fields when implemented.
+    record = logging.LogRecord(
+        name="foo",
+        level=logging.DEBUG,
+        msg="This is a test message.",
+        pathname="foo/bar",
+        lineno=25,
+        args=None,
+        exc_info=None,
+    )
+
+    # Extra fields:
+    record.rpcName = "bar"
+
+    formatted_msg = StructuredLogFormatter().format(record)
+    parsed_msg = json.loads(formatted_msg)
+
+    assert parsed_msg["name"] == "foo"
+    assert parsed_msg["severity"] == "DEBUG"
+    assert parsed_msg["message"] == "This is a test message."
+    assert parsed_msg["rpcName"] == "bar"