feat: allow custom labels with standard library logging (#264)

Author: daniel-sanche

packages/google-cloud-logging/google/cloud/logging_v2/client.py

@@ -362,9 +362,9 @@ def get_default_handler(self, **kw):
             ):
                 # Cloud Functions with runtimes > 3.8 supports structured logs on standard out
                 # 3.7 should use the standard CloudLoggingHandler, which sends logs over the network.
-                return StructuredLogHandler(**kw, project=self.project)
+                return StructuredLogHandler(**kw, project_id=self.project)
             elif monitored_resource.type == _RUN_RESOURCE_TYPE:
-                return StructuredLogHandler(**kw, project=self.project)
+                return StructuredLogHandler(**kw, project_id=self.project)
         return CloudLoggingHandler(self, resource=monitored_resource, **kw)
 
     def setup_logging(

packages/google-cloud-logging/google/cloud/logging_v2/handlers/handlers.py

@@ -37,8 +37,9 @@ class CloudLoggingFilter(logging.Filter):
     the `extras` argument when writing logs.
     """
 
-    def __init__(self, project=None):
+    def __init__(self, project=None, default_labels=None):
         self.project = project
+        self.default_labels = default_labels if default_labels else {}
 
     def filter(self, record):
         # ensure record has all required fields set
@@ -61,6 +62,12 @@ def filter(self, record):
         inferred_http, inferred_trace = get_request_data()
         if inferred_trace is not None and self.project is not None:
             inferred_trace = f"projects/{self.project}/traces/{inferred_trace}"
+        # set labels
+        user_labels = getattr(record, "labels", {})
+        record.total_labels = {**self.default_labels, **user_labels}
+        record.total_labels_str = ", ".join(
+            [f'"{k}": "{v}"' for k, v in record.total_labels.items()]
+        )
 
         record.trace = getattr(record, "trace", inferred_trace) or ""
         record.http_request = getattr(record, "http_request", inferred_http) or {}
@@ -126,8 +133,7 @@ def __init__(
                 option is :class:`.SyncTransport`.
             resource (~logging_v2.resource.Resource):
                 Resource for this Handler. Defaults to ``global``.
-            labels (Optional[dict]): Monitored resource of the entry, defaults
-                to the global resource type.
+            labels (Optional[dict]): Additional labels to attach to logs.
             stream (Optional[IO]): Stream to be used by the handler.
         """
         super(CloudLoggingHandler, self).__init__(stream)
@@ -138,7 +144,8 @@ def __init__(
         self.resource = resource
         self.labels = labels
         # add extra keys to log record
-        self.addFilter(CloudLoggingFilter(self.project_id))
+        log_filter = CloudLoggingFilter(project=self.project_id, default_labels=labels)
+        self.addFilter(log_filter)
 
     def emit(self, record):
         """Actually log the specified logging record.
@@ -151,22 +158,16 @@ def emit(self, record):
             record (logging.LogRecord): The record to be logged.
         """
         message = super(CloudLoggingHandler, self).format(record)
-        user_labels = getattr(record, "labels", {})
-        # merge labels
-        total_labels = self.labels if self.labels is not None else {}
-        total_labels.update(user_labels)
-        if len(total_labels) == 0:
-            total_labels = None
         # send off request
         self.transport.send(
             record,
             message,
             resource=getattr(record, "resource", self.resource),
-            labels=total_labels,
-            trace=getattr(record, "trace", None),
-            span_id=getattr(record, "span_id", None),
-            http_request=getattr(record, "http_request", None),
-            source_location=getattr(record, "source_location", None),
+            labels=getattr(record, "total_labels", None) or None,
+            trace=getattr(record, "trace", None) or None,
+            span_id=getattr(record, "span_id", None) or None,
+            http_request=getattr(record, "http_request", None) or None,
+            source_location=getattr(record, "source_location", None) or None,
         )
 
 

packages/google-cloud-logging/google/cloud/logging_v2/handlers/structured_log.py

@@ -19,26 +19,34 @@
 
 from google.cloud.logging_v2.handlers.handlers import CloudLoggingFilter
 
-GCP_FORMAT = '{"message": "%(message)s", "severity": "%(levelname)s", "logging.googleapis.com/trace": "%(trace)s", "logging.googleapis.com/sourceLocation": { "file": "%(file)s", "line": "%(line)d", "function": "%(function)s"}, "httpRequest": {"requestMethod": "%(request_method)s", "requestUrl": "%(request_url)s", "userAgent": "%(user_agent)s", "protocol": "%(protocol)s"} }'
+GCP_FORMAT = (
+    '{"message": "%(message)s", '
+    '"severity": "%(levelname)s", '
+    '"logging.googleapis.com/labels": { %(total_labels_str)s }, '
+    '"logging.googleapis.com/trace": "%(trace)s", '
+    '"logging.googleapis.com/sourceLocation": { "file": "%(file)s", "line": "%(line)d", "function": "%(function)s"}, '
+    '"httpRequest": {"requestMethod": "%(request_method)s", "requestUrl": "%(request_url)s", "userAgent": "%(user_agent)s", "protocol": "%(protocol)s"} }'
+)
 
 
 class StructuredLogHandler(logging.StreamHandler):
     """Handler to format logs into the Cloud Logging structured log format,
     and write them to standard output
     """
 
-    def __init__(self, *, name=None, stream=None, project=None):
+    def __init__(self, *, labels=None, stream=None, project_id=None):
         """
         Args:
-            name (Optional[str]): The name of the custom log in Cloud Logging.
+            labels (Optional[dict]): Additional labels to attach to logs.
             stream (Optional[IO]): Stream to be used by the handler.
+            project (Optional[str]): Project Id associated with the logs.
         """
         super(StructuredLogHandler, self).__init__(stream=stream)
-        self.name = name
-        self.project_id = project
+        self.project_id = project_id
 
         # add extra keys to log record
-        self.addFilter(CloudLoggingFilter(project))
+        log_filter = CloudLoggingFilter(project=project_id, default_labels=labels)
+        self.addFilter(log_filter)
 
         # make logs appear in GCP structured logging format
         self.formatter = logging.Formatter(GCP_FORMAT)

packages/google-cloud-logging/tests/environment/deployable/python/snippets.py

@@ -43,21 +43,30 @@ def pylogging(log_text="pylogging", severity="WARNING", **kwargs):
     # allowed severity: debug, info, warning, error, critical
 
     # build http request if fields given as argument
-    http_keys =  ["protocol", "requestUrl", "userAgent", "requestMethod"]
+    http_keys = ["protocol", "requestUrl", "userAgent", "requestMethod"]
     if any([k in kwargs for k in http_keys]):
         http_request = {}
         for key in http_keys:
             if key in kwargs:
                 http_request[key] = kwargs[key]
-        kwargs['http_request'] = http_request
+        kwargs["http_request"] = http_request
     # build source location if given as argument
-    source_keys =  ["line", "file", "function"]
+    source_keys = ["line", "file", "function"]
     if any([k in kwargs for k in http_keys]):
         source_location = {}
         for key in source_keys:
             if key in kwargs:
                 source_location[key] = kwargs[key]
-        kwargs['source_location'] = source_location
+        kwargs["source_location"] = source_location
+    # build custom labels
+    label_prefix = "label_"
+    label_keys = [k for k in kwargs.keys() if k.startswith(label_prefix)]
+    if label_keys:
+        labels = {}
+        for k in label_keys:
+            adjusted_key = k[len(label_prefix) :]
+            labels[adjusted_key] = kwargs[k]
+        kwargs["labels"] = labels
 
     severity = severity.upper()
     if severity == "DEBUG":
@@ -71,13 +80,24 @@ def pylogging(log_text="pylogging", severity="WARNING", **kwargs):
     else:
         logging.critical(log_text, extra=kwargs)
 
-def pylogging_flask(log_text="pylogging_flask", path="/", base_url="http://google", agent="Chrome", trace="123", **kwargs):
+
+def pylogging_flask(
+    log_text="pylogging_flask",
+    path="/",
+    base_url="http://google",
+    agent="Chrome",
+    trace="123",
+    **kwargs,
+):
     import flask
+
     app = flask.Flask(__name__)
     with app.test_request_context(
-            path, base_url, headers={'User-Agent': agent, "X_CLOUD_TRACE_CONTEXT": trace}):
+        path, base_url, headers={"User-Agent": agent, "X_CLOUD_TRACE_CONTEXT": trace}
+    ):
         logging.info(log_text)
 
+
 def print_handlers(**kwargs):
     root_logger = logging.getLogger()
     handlers_str = ", ".join([type(h).__name__ for h in root_logger.handlers])

packages/google-cloud-logging/tests/environment/tests/common/common.py

@@ -170,7 +170,9 @@ def test_severity(self):
             "DEBUG",
         ]
         for severity in severities:
-            log_list = self.trigger_and_retrieve(log_text, "simplelog", severity=severity)
+            log_list = self.trigger_and_retrieve(
+                log_text, "simplelog", severity=severity
+            )
             found_severity = log_list[-1].severity
             self.assertEqual(found_severity.lower(), severity.lower())
         # DEFAULT severity should result in empty field

packages/google-cloud-logging/tests/environment/tests/common/python.py

@@ -72,12 +72,12 @@ def test_source_location_pylogging(self):
         found_source = log_list[-1].source_location
 
         self.assertIsNotNone(found_source)
-        self.assertIsNotNone(found_source['file'])
-        self.assertIsNotNone(found_source['function'])
-        self.assertIsNotNone(found_source['line'])
-        self.assertIn("snippets.py", found_source['file'])
-        self.assertEqual(found_source['function'], "pylogging")
-        self.assertTrue(int(found_source['line']) > 0)
+        self.assertIsNotNone(found_source["file"])
+        self.assertIsNotNone(found_source["function"])
+        self.assertIsNotNone(found_source["line"])
+        self.assertIn("snippets.py", found_source["file"])
+        self.assertEqual(found_source["function"], "pylogging")
+        self.assertTrue(int(found_source["line"]) > 0)
 
     def test_flask_http_request_pylogging(self):
         if self.environment == "kubernetes" or "appengine" in self.environment:
@@ -91,19 +91,25 @@ def test_flask_http_request_pylogging(self):
         expected_path = "/pylogging"
         expected_trace = "123"
 
-        log_list = self.trigger_and_retrieve(log_text, "pylogging_flask",
-                path=expected_path, trace=expected_trace, base_url=expected_base_url, agent=expected_agent)
+        log_list = self.trigger_and_retrieve(
+            log_text,
+            "pylogging_flask",
+            path=expected_path,
+            trace=expected_trace,
+            base_url=expected_base_url,
+            agent=expected_agent,
+        )
         found_request = log_list[-1].http_request
 
         self.assertIsNotNone(found_request)
-        self.assertIsNotNone(found_request['requestMethod'])
-        self.assertIsNotNone(found_request['requestUrl'])
-        self.assertIsNotNone(found_request['userAgent'])
-        self.assertIsNotNone(found_request['protocol'])
-        self.assertEqual(found_request['requestMethod'], 'GET')
-        self.assertEqual(found_request['requestUrl'], expected_base_url + expected_path)
-        self.assertEqual(found_request['userAgent'], expected_agent)
-        self.assertEqual(found_request['protocol'], 'HTTP/1.1')
+        self.assertIsNotNone(found_request["requestMethod"])
+        self.assertIsNotNone(found_request["requestUrl"])
+        self.assertIsNotNone(found_request["userAgent"])
+        self.assertIsNotNone(found_request["protocol"])
+        self.assertEqual(found_request["requestMethod"], "GET")
+        self.assertEqual(found_request["requestUrl"], expected_base_url + expected_path)
+        self.assertEqual(found_request["userAgent"], expected_agent)
+        self.assertEqual(found_request["protocol"], "HTTP/1.1")
 
         found_trace = log_list[-1].trace
         self.assertIsNotNone(found_trace)
@@ -116,36 +122,50 @@ def test_pylogging_extras(self):
             return
         log_text = f"{inspect.currentframe().f_code.co_name}"
         kwargs = {
-            'trace': '123',
-            'requestMethod': 'POST',
-            'requestUrl': 'http://test',
-            'userAgent': 'agent',
-            'protocol': 'test',
-            'line': 25,
-            'file': 'test-file',
-            'function': 'test-function'
+            "trace": "123",
+            "requestMethod": "POST",
+            "requestUrl": "http://test",
+            "userAgent": "agent",
+            "protocol": "test",
+            "line": 25,
+            "file": "test-file",
+            "function": "test-function",
+            "label_custom": "test-label",
         }
         log_list = self.trigger_and_retrieve(log_text, "pylogging", **kwargs)
         found_log = log_list[-1]
 
         if self.environment != "functions":
             # functions seems to override the user's trace value
-            self.assertEqual(found_log.trace, kwargs['trace'])
+            self.assertEqual(found_log.trace, kwargs["trace"])
 
         # check that custom http request fields were set
         self.assertIsNotNone(found_log.http_request)
-        for field in ['requestMethod', 'requestUrl', 'userAgent', 'protocol']:
-            self.assertIsNotNone(found_log.http_request[field],
-                    'http_request[{field}] is unexpectedly None')
-            self.assertEqual(found_log.http_request[field], kwargs[field],
-                    f'http_request[{field}] != {kwargs[field]}')
+        for field in ["requestMethod", "requestUrl", "userAgent", "protocol"]:
+            self.assertIsNotNone(
+                found_log.http_request[field],
+                "http_request[{field}] is unexpectedly None",
+            )
+            self.assertEqual(
+                found_log.http_request[field],
+                kwargs[field],
+                f"http_request[{field}] != {kwargs[field]}",
+            )
         # check that custom source location fields were set
         self.assertIsNotNone(found_log.source_location)
-        for field in ['line', 'file', 'function']:
-            self.assertIsNotNone(found_log.source_location[field],
-                    f'source_location[{field}] is unexpectedly None')
-            self.assertEqual(found_log.source_location[field], kwargs[field],
-                    f'source_location[{field}] != {kwargs[field]}')
+        for field in ["line", "file", "function"]:
+            self.assertIsNotNone(
+                found_log.source_location[field],
+                f"source_location[{field}] is unexpectedly None",
+            )
+            self.assertEqual(
+                found_log.source_location[field],
+                kwargs[field],
+                f"source_location[{field}] != {kwargs[field]}",
+            )
+        # check that custom label is set
+        self.assertIsNotNone(found_log.labels)
+        self.assertEqual(found_log.labels["custom"], kwargs["label_custom"])
 
     def test_pylogging_extras_sparse(self):
         if self.environment == "kubernetes" or "appengine" in self.environment:
@@ -154,21 +174,27 @@ def test_pylogging_extras_sparse(self):
             return
         log_text = f"{inspect.currentframe().f_code.co_name}"
         kwargs = {
-            'requestMethod': 'POST',
-            'file': 'test-file',
+            "requestMethod": "POST",
+            "file": "test-file",
         }
         log_list = self.trigger_and_retrieve(log_text, "pylogging", **kwargs)
         found_log = log_list[-1]
 
         # check that custom http request fields were set
         self.assertIsNotNone(found_log.http_request)
-        self.assertEqual(found_log.http_request["requestMethod"], kwargs["requestMethod"])
-        for field in ['requestUrl', 'userAgent', 'protocol']:
-            self.assertIsNone(found_log.http_request.get(field, None),
-                    f'http_request[{field}] is unexpectedly not None')
+        self.assertEqual(
+            found_log.http_request["requestMethod"], kwargs["requestMethod"]
+        )
+        for field in ["requestUrl", "userAgent", "protocol"]:
+            self.assertIsNone(
+                found_log.http_request.get(field, None),
+                f"http_request[{field}] is unexpectedly not None",
+            )
         # check that custom source location fields were set
         self.assertIsNotNone(found_log.source_location)
-        self.assertEqual(found_log.source_location['file'], kwargs['file'])
-        for field in ['line', 'function']:
-            self.assertIsNone(found_log.source_location.get(field, None),
-                    f'source_location[{field}] is unexpectedly not None')
+        self.assertEqual(found_log.source_location["file"], kwargs["file"])
+        for field in ["line", "function"]:
+            self.assertIsNone(
+                found_log.source_location.get(field, None),
+                f"source_location[{field}] is unexpectedly not None",
+            )

packages/google-cloud-logging/tests/environment/tests/nodejs/test_cloudrun.py

@@ -22,17 +22,18 @@
 
 from ..common.common import Common
 
+
 class TestCloudRun(Common, unittest.TestCase):
 
-  environment = "cloudrun"
-  language = "nodejs"
+    environment = "cloudrun"
+    language = "nodejs"
 
-  # What it should be
-  monitored_resource_name = "cloud_run_revision"
-  monitored_resource_labels = [
-      "project_id",
-      "service_name",
-      "revision_name",
-      "location",
-      "configuration_name",
-  ]
+    # What it should be
+    monitored_resource_name = "cloud_run_revision"
+    monitored_resource_labels = [
+        "project_id",
+        "service_name",
+        "revision_name",
+        "location",
+        "configuration_name",
+    ]