Skip to content

Commit

Permalink
feat: allow custom labels with standard library logging (#264)
Browse files Browse the repository at this point in the history
  • Loading branch information
daniel-sanche committed Apr 22, 2021
1 parent 6b10b74 commit fe4de39
Show file tree
Hide file tree
Showing 6 changed files with 71 additions and 38 deletions.
4 changes: 2 additions & 2 deletions google/cloud/logging_v2/client.py
Expand Up @@ -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(
Expand Down
31 changes: 16 additions & 15 deletions google/cloud/logging_v2/handlers/handlers.py
Expand Up @@ -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
Expand All @@ -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 {}
Expand Down Expand Up @@ -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)
Expand All @@ -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.
Expand All @@ -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,
)


Expand Down
20 changes: 14 additions & 6 deletions google/cloud/logging_v2/handlers/structured_log.py
Expand Up @@ -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)
Expand Down
26 changes: 18 additions & 8 deletions tests/unit/handlers/test_handlers.py
Expand Up @@ -268,22 +268,27 @@ def test_emit(self):
)
logname = "loggername"
message = "hello world"
labels = {"test-key": "test-value"}
record = logging.LogRecord(logname, logging, None, None, message, None, None)
record.labels = labels
handler.emit(record)
handler.handle(record)
self.assertEqual(
handler.transport.send_called_with,
(record, message, _GLOBAL_RESOURCE, labels, None, None, None, None),
(record, message, _GLOBAL_RESOURCE, None, None, None, None, None),
)

def test_emit_manual_field_override(self):
from google.cloud.logging_v2.logger import _GLOBAL_RESOURCE
from google.cloud.logging_v2.resource import Resource

client = _Client(self.PROJECT)
default_labels = {
"default_key": "default-value",
"overwritten_key": "bad_value",
}
handler = self._make_one(
client, transport=_Transport, resource=_GLOBAL_RESOURCE
client,
transport=_Transport,
resource=_GLOBAL_RESOURCE,
labels=default_labels,
)
logname = "loggername"
message = "hello world"
Expand All @@ -299,9 +304,14 @@ def test_emit_manual_field_override(self):
setattr(record, "source_location", expected_source)
expected_resource = Resource(type="test", labels={})
setattr(record, "resource", expected_resource)
expected_labels = {"test-label": "manual"}
setattr(record, "labels", expected_labels)
handler.emit(record)
added_labels = {"added_key": "added_value", "overwritten_key": "new_value"}
expected_labels = {
"default_key": "default-value",
"overwritten_key": "new_value",
"added_key": "added_value",
}
setattr(record, "labels", added_labels)
handler.handle(record)

self.assertEqual(
handler.transport.send_called_with,
Expand Down
26 changes: 20 additions & 6 deletions tests/unit/handlers/test_structured_log.py
Expand Up @@ -40,17 +40,18 @@ def index():

def test_ctor_defaults(self):
handler = self._make_one()
self.assertIsNone(handler.name)
self.assertIsNone(handler.project_id)

def test_ctor_w_name(self):
handler = self._make_one(name="foo")
self.assertEqual(handler.name, "foo")
def test_ctor_w_project(self):
handler = self._make_one(project_id="foo")
self.assertEqual(handler.project_id, "foo")

def test_format(self):
import logging
import json

handler = self._make_one()
labels = {"default_key": "default-value"}
handler = self._make_one(labels=labels)
logname = "loggername"
message = "hello world,嗨 世界"
pathname = "testpath"
Expand All @@ -74,6 +75,7 @@ def test_format(self):
"userAgent": "",
"protocol": "",
},
"logging.googleapis.com/labels": labels,
}
handler.filter(record)
result = json.loads(handler.format(record))
Expand Down Expand Up @@ -106,6 +108,7 @@ def test_format_minimal(self):
"userAgent": "",
"protocol": "",
},
"logging.googleapis.com/labels": {},
}
handler.filter(record)
result = json.loads(handler.format(record))
Expand Down Expand Up @@ -160,7 +163,11 @@ def test_format_overrides(self):
import logging
import json

handler = self._make_one()
default_labels = {
"default_key": "default-value",
"overwritten_key": "bad_value",
}
handler = self._make_one(labels=default_labels)
logname = "loggername"
message = "hello world,嗨 世界"
record = logging.LogRecord(logname, logging.INFO, "", 0, message, None, None)
Expand All @@ -172,6 +179,8 @@ def test_format_overrides(self):
record.http_request = {"requestUrl": overwrite_path}
record.source_location = {"file": overwrite_file}
record.trace = overwrite_trace
added_labels = {"added_key": "added_value", "overwritten_key": "new_value"}
record.labels = added_labels
expected_payload = {
"logging.googleapis.com/trace": overwrite_trace,
"logging.googleapis.com/sourceLocation": {
Expand All @@ -185,6 +194,11 @@ def test_format_overrides(self):
"userAgent": "",
"protocol": "",
},
"logging.googleapis.com/labels": {
"default_key": "default-value",
"overwritten_key": "new_value",
"added_key": "added_value",
},
}

app = self.create_app()
Expand Down

0 comments on commit fe4de39

Please sign in to comment.