diff --git a/.gitignore b/.gitignore index ba7b78cf..b4243ced 100644 --- a/.gitignore +++ b/.gitignore @@ -61,6 +61,3 @@ system_tests/local_test_setup # Make sure a generated file isn't accidentally committed. pylintrc pylintrc.test - -# ignore owlbot -owl-bot-staging diff --git a/google/cloud/logging_v2/handlers/_helpers.py b/google/cloud/logging_v2/handlers/_helpers.py index 6d9debfe..931b7a2f 100644 --- a/google/cloud/logging_v2/handlers/_helpers.py +++ b/google/cloud/logging_v2/handlers/_helpers.py @@ -68,7 +68,10 @@ def get_request_data_from_flask(): http_request = { "requestMethod": flask.request.method, "requestUrl": flask.request.url, + "requestSize": flask.request.content_length, "userAgent": flask.request.user_agent.string, + "remoteIp": flask.request.remote_addr, + "referer": flask.request.referrer, "protocol": flask.request.environ.get(_PROTOCOL_HEADER), } @@ -93,11 +96,21 @@ def get_request_data_from_django(): if request is None: return None, None, None + # convert content_length to int if it exists + content_length = None + try: + content_length = int(request.META.get(_DJANGO_CONTENT_LENGTH)) + except (ValueError, TypeError): + content_length = None + # build http_request http_request = { "requestMethod": request.method, "requestUrl": request.build_absolute_uri(), + "requestSize": content_length, "userAgent": request.META.get(_DJANGO_USERAGENT_HEADER), + "remoteIp": request.META.get(_DJANGO_REMOTE_ADDR_HEADER), + "referer": request.META.get(_DJANGO_REFERER_HEADER), "protocol": request.META.get(_PROTOCOL_HEADER), } diff --git a/google/cloud/logging_v2/handlers/handlers.py b/google/cloud/logging_v2/handlers/handlers.py index 3580a4e9..b3b787fe 100644 --- a/google/cloud/logging_v2/handlers/handlers.py +++ b/google/cloud/logging_v2/handlers/handlers.py @@ -45,6 +45,10 @@ class CloudLoggingFilter(logging.Filter): overwritten using the `extras` argument when writing logs. """ + # The subset of http_request fields have been tested to work consistently across GCP environments + # https://cloud.google.com/logging/docs/reference/v2/rest/v2/LogEntry#httprequest + _supported_http_fields = ("requestMethod", "requestUrl", "userAgent", "protocol") + def __init__(self, project=None, default_labels=None): self.project = project self.default_labels = default_labels if default_labels else {} @@ -74,8 +78,17 @@ def filter(self, record): Add new Cloud Logging data to each LogRecord as it comes in """ user_labels = getattr(record, "labels", {}) + # infer request data from the environment inferred_http, inferred_trace, inferred_span = get_request_data() + if inferred_http is not None: + # filter inferred_http to include only well-supported fields + inferred_http = { + k: v + for (k, v) in inferred_http.items() + if k in self._supported_http_fields and v is not None + } if inferred_trace is not None and self.project is not None: + # add full path for detected trace inferred_trace = f"projects/{self.project}/traces/{inferred_trace}" # set new record values record._resource = getattr(record, "resource", None) @@ -84,13 +97,14 @@ def filter(self, record): record._http_request = getattr(record, "http_request", inferred_http) record._source_location = CloudLoggingFilter._infer_source_location(record) record._labels = {**self.default_labels, **user_labels} or None - # create guaranteed string representations for structured logging - record._msg_str = record.msg or "" + # create string representations for structured logging record._trace_str = record._trace or "" record._span_id_str = record._span_id or "" record._http_request_str = json.dumps(record._http_request or {}) record._source_location_str = json.dumps(record._source_location or {}) record._labels_str = json.dumps(record._labels or {}) + # break quotes for parsing through structured logging + record._msg_str = str(record.msg).replace('"', '\\"') if record.msg else "" return True diff --git a/tests/environment b/tests/environment index f1937814..912d193c 160000 --- a/tests/environment +++ b/tests/environment @@ -1 +1 @@ -Subproject commit f1937814bf78953a160fa33600f6af8cfdb82527 +Subproject commit 912d193cfb90b741fee035dff29fa0d5959a5186 diff --git a/tests/unit/handlers/test__helpers.py b/tests/unit/handlers/test__helpers.py index e1230991..d26e700e 100644 --- a/tests/unit/handlers/test__helpers.py +++ b/tests/unit/handlers/test__helpers.py @@ -75,23 +75,18 @@ def test_http_request_populated(self): expected_agent = "Mozilla/5.0" expected_referrer = "self" expected_ip = "10.1.2.3" - body_content = "test" headers = { "User-Agent": expected_agent, "Referer": expected_referrer, } app = self.create_app() - with app.test_client() as c: - c.put( - path=expected_path, - data=body_content, - environ_base={"REMOTE_ADDR": expected_ip}, - headers=headers, - ) + with app.test_request_context( + expected_path, headers=headers, environ_base={"REMOTE_ADDR": expected_ip} + ): http_request, *_ = self._call_fut() - self.assertEqual(http_request["requestMethod"], "PUT") + self.assertEqual(http_request["requestMethod"], "GET") self.assertEqual(http_request["requestUrl"], expected_path) self.assertEqual(http_request["userAgent"], expected_agent) self.assertEqual(http_request["protocol"], "HTTP/1.1") @@ -99,10 +94,9 @@ def test_http_request_populated(self): def test_http_request_sparse(self): expected_path = "http://testserver/123" app = self.create_app() - with app.test_client() as c: - c.put(path=expected_path) + with app.test_request_context(expected_path): http_request, *_ = self._call_fut() - self.assertEqual(http_request["requestMethod"], "PUT") + self.assertEqual(http_request["requestMethod"], "GET") self.assertEqual(http_request["requestUrl"], expected_path) self.assertEqual(http_request["protocol"], "HTTP/1.1") diff --git a/tests/unit/handlers/test_handlers.py b/tests/unit/handlers/test_handlers.py index f0a1f81d..4ba05212 100644 --- a/tests/unit/handlers/test_handlers.py +++ b/tests/unit/handlers/test_handlers.py @@ -134,22 +134,20 @@ def test_record_with_request(self): expected_span = "456" combined_trace = f"{expected_trace}/{expected_span}" expected_request = { - "requestMethod": "PUT", + "requestMethod": "GET", "requestUrl": expected_path, "userAgent": expected_agent, "protocol": "HTTP/1.1", } app = self.create_app() - with app.test_client() as c: - c.put( - path=expected_path, - data="body", - headers={ - "User-Agent": expected_agent, - "X_CLOUD_TRACE_CONTEXT": combined_trace, - }, - ) + with app.test_request_context( + expected_path, + headers={ + "User-Agent": expected_agent, + "X_CLOUD_TRACE_CONTEXT": combined_trace, + }, + ): success = filter_obj.filter(record) self.assertTrue(success) diff --git a/tests/unit/handlers/test_structured_log.py b/tests/unit/handlers/test_structured_log.py index 4b83a4c2..0536583a 100644 --- a/tests/unit/handlers/test_structured_log.py +++ b/tests/unit/handlers/test_structured_log.py @@ -104,6 +104,23 @@ def test_format_minimal(self): value, result[key], f"expected_payload[{key}] != result[{key}]" ) + def test_format_with_quotes(self): + """ + When logging a message containing quotes, escape chars should be added + """ + import logging + import json + + handler = self._make_one() + message = '"test"' + expected_result = '\\"test\\"' + record = logging.LogRecord(None, logging.INFO, None, None, message, None, None,) + record.created = None + handler.filter(record) + result = json.loads(handler.format(record)) + result["message"] = expected_result + self.assertEqual(result["message"], expected_result) + def test_format_with_request(self): import logging import json @@ -121,7 +138,7 @@ def test_format_with_request(self): "logging.googleapis.com/trace": expected_trace, "logging.googleapis.com/spanId": expected_span, "httpRequest": { - "requestMethod": "PUT", + "requestMethod": "GET", "requestUrl": expected_path, "userAgent": expected_agent, "protocol": "HTTP/1.1", @@ -129,15 +146,13 @@ def test_format_with_request(self): } app = self.create_app() - with app.test_client() as c: - c.put( - path=expected_path, - data="body", - headers={ - "User-Agent": expected_agent, - "X_CLOUD_TRACE_CONTEXT": trace_header, - }, - ) + with app.test_request_context( + expected_path, + headers={ + "User-Agent": expected_agent, + "X_CLOUD_TRACE_CONTEXT": trace_header, + }, + ): handler.filter(record) result = json.loads(handler.format(record)) for (key, value) in expected_payload.items():