Skip to content

Commit b840435

Browse files
daniel-sanchedaniel-sanche
authored
fix: nested json with structured log handler (#636)
1 parent 44deb1b commit b840435

File tree

7 files changed

+166
-6
lines changed

7 files changed

+166
-6
lines changed

‎google/cloud/logging_v2/handlers/structured_log.py‎

Lines changed: 6 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -96,8 +96,10 @@ def format(self, record):
9696
del message[key]
9797
# if input is a dictionary, encode it as a json string
9898
encoded_msg = json.dumps(message, ensure_ascii=False)
99-
# strip out open and close parentheses
100-
payload = encoded_msg.lstrip("{").rstrip("}") + ","
99+
# all json.dumps strings should start and end with parentheses
100+
# strip them out to embed these fields in the larger JSON payload
101+
if len(encoded_msg) > 2:
102+
payload = encoded_msg[1:-1] + ","
101103
elif message:
102104
# properly break any formatting in string to make it json safe
103105
encoded_message = json.dumps(message, ensure_ascii=False)
@@ -119,5 +121,5 @@ def emit(self, record):
119121

120122
def emit_instrumentation_info(self):
121123
google.cloud.logging_v2._instrumentation_emitted = True
122-
diagnostic_object = _create_diagnostic_entry().to_api_repr()
123-
logging.info(diagnostic_object)
124+
diagnostic_object = _create_diagnostic_entry()
125+
logging.info(diagnostic_object.payload)

‎tests/environment‎

‎tests/unit/handlers/test_handlers.py‎

Lines changed: 41 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -573,6 +573,47 @@ def test_emit_w_json_extras(self):
573573
),
574574
)
575575

576+
def test_format_with_nested_json(self):
577+
"""
578+
JSON can contain nested dictionaries of data
579+
"""
580+
from google.cloud.logging_v2.logger import _GLOBAL_RESOURCE
581+
import logging
582+
583+
client = _Client(self.PROJECT)
584+
handler = self._make_one(
585+
client,
586+
transport=_Transport,
587+
resource=_GLOBAL_RESOURCE,
588+
)
589+
json_fields = {"outer": {"inner": {"hello": "world"}}}
590+
record = logging.LogRecord(
591+
None,
592+
logging.INFO,
593+
None,
594+
None,
595+
None,
596+
None,
597+
None,
598+
)
599+
record.created = None
600+
setattr(record, "json_fields", json_fields)
601+
handler.handle(record)
602+
self.assertEqual(
603+
handler.transport.send_called_with,
604+
(
605+
record,
606+
json_fields,
607+
_GLOBAL_RESOURCE,
608+
None,
609+
None,
610+
None,
611+
False,
612+
None,
613+
None,
614+
),
615+
)
616+
576617
def test_emit_with_encoded_json(self):
577618
"""
578619
Handler should parse json encoded as a string

‎tests/unit/handlers/test_structured_log.py‎

Lines changed: 72 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -487,6 +487,30 @@ def test_format_with_json_fields(self):
487487
self.assertEqual(result["hello"], "world")
488488
self.assertEqual(result["number"], 12)
489489

490+
def test_format_with_nested_json(self):
491+
"""
492+
JSON can contain nested dictionaries of data
493+
"""
494+
import logging
495+
import json
496+
497+
handler = self._make_one()
498+
json_fields = {"outer": {"inner": {"hello": "world"}}}
499+
record = logging.LogRecord(
500+
None,
501+
logging.INFO,
502+
None,
503+
None,
504+
None,
505+
None,
506+
None,
507+
)
508+
record.created = None
509+
setattr(record, "json_fields", json_fields)
510+
handler.filter(record)
511+
result = json.loads(handler.format(record))
512+
self.assertEqual(result["outer"], json_fields["outer"])
513+
490514
def test_emits_instrumentation_info(self):
491515
import logging
492516
import mock
@@ -510,3 +534,51 @@ def side_effect():
510534

511535
# emit_instrumentation_info should be called once
512536
emit_info.assert_called_once()
537+
538+
def test_valid_instrumentation_info(self):
539+
import logging
540+
import mock
541+
import json
542+
543+
with mock.patch.object(logging, "info") as mock_log:
544+
handler = self._make_one()
545+
handler.emit_instrumentation_info()
546+
mock_log.assert_called_once()
547+
# ensure instrumentaiton payload is formatted as expected
548+
called_payload = mock_log.call_args.args[0]
549+
self.assertEqual(len(called_payload.keys()), 1)
550+
self.assertIn("logging.googleapis.com/diagnostic", called_payload.keys())
551+
inst_source_dict = called_payload["logging.googleapis.com/diagnostic"]
552+
self.assertEqual(len(inst_source_dict.keys()), 1)
553+
self.assertIn("instrumentation_source", inst_source_dict.keys())
554+
source_list = inst_source_dict["instrumentation_source"]
555+
self.assertEqual(
556+
len(source_list), 1, "expected single instrumentation source"
557+
)
558+
for source_dict in source_list:
559+
self.assertEqual(
560+
len(source_dict.keys()),
561+
2,
562+
f"expected two keys in payload: {source_dict.keys()}",
563+
)
564+
self.assertIn("name", source_dict.keys())
565+
self.assertIn("version", source_dict.keys())
566+
self.assertEqual(source_dict["name"], "python")
567+
# ensure it is parsed properly by handler
568+
record = logging.LogRecord(
569+
None,
570+
logging.INFO,
571+
None,
572+
None,
573+
called_payload,
574+
None,
575+
None,
576+
)
577+
record.created = None
578+
handler.filter(record)
579+
result = json.loads(handler.format(record))
580+
self.assertEqual(
581+
result["logging.googleapis.com/diagnostic"],
582+
inst_source_dict,
583+
"instrumentation payload not logged properly",
584+
)

‎tests/unit/handlers/transports/test_background_thread.py‎

Lines changed: 23 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -69,6 +69,29 @@ def test_send(self):
6969
resource=_GLOBAL_RESOURCE,
7070
)
7171

72+
def test_send_json(self):
73+
from google.cloud.logging_v2.logger import _GLOBAL_RESOURCE
74+
75+
client = _Client(self.PROJECT)
76+
name = "python_logger"
77+
78+
transport, _ = self._make_one(client, name)
79+
80+
python_logger_name = "mylogger"
81+
message = {"hello": {"world": "!"}}
82+
83+
record = logging.LogRecord(
84+
python_logger_name, logging.INFO, None, None, message, None, None
85+
)
86+
87+
transport.send(record, message, resource=_GLOBAL_RESOURCE)
88+
89+
transport.worker.enqueue.assert_called_once_with(
90+
record,
91+
message,
92+
resource=_GLOBAL_RESOURCE,
93+
)
94+
7295
def test_trace_send(self):
7396
from google.cloud.logging_v2.logger import _GLOBAL_RESOURCE
7497

‎tests/unit/handlers/transports/test_sync.py‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -70,7 +70,7 @@ def test_send_struct(self):
7070
client_name = "python"
7171
python_logger_name = "mylogger"
7272
transport = self._make_one(client, client_name)
73-
message = {"message": "hello world", "extra": "test"}
73+
message = {"message": "hello world", "extra": "test", "nested": {"one": 2}}
7474
record = logging.LogRecord(
7575
python_logger_name, logging.INFO, None, None, message, None, None
7676
)

‎tests/unit/test_logger.py‎

Lines changed: 22 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -304,6 +304,28 @@ def test_log_struct_defaults(self):
304304

305305
self.assertEqual(api._write_entries_called_with, (ENTRIES, None, None, None))
306306

307+
def test_log_nested_struct(self):
308+
from google.cloud.logging_v2.handlers._monitored_resources import (
309+
detect_resource,
310+
)
311+
312+
STRUCT = {"message": "MESSAGE", "weather": "cloudy", "nested": {"one": 2}}
313+
RESOURCE = detect_resource(self.PROJECT)._to_dict()
314+
ENTRIES = [
315+
{
316+
"logName": "projects/%s/logs/%s" % (self.PROJECT, self.LOGGER_NAME),
317+
"jsonPayload": STRUCT,
318+
"resource": RESOURCE,
319+
}
320+
]
321+
client = _Client(self.PROJECT)
322+
api = client.logging_api = _DummyLoggingAPI()
323+
logger = self._make_one(self.LOGGER_NAME, client=client)
324+
325+
logger.log(STRUCT)
326+
327+
self.assertEqual(api._write_entries_called_with, (ENTRIES, None, None, None))
328+
307329
def test_log_struct_w_default_labels(self):
308330
from google.cloud.logging_v2.handlers._monitored_resources import (
309331
detect_resource,

0 commit comments

Comments
 (0)