diff --git a/changelog.d/8916.misc b/changelog.d/8916.misc
new file mode 100644
index 0000000000..c71ef480e6
--- /dev/null
+++ b/changelog.d/8916.misc
@@ -0,0 +1 @@
+Improve structured logging tests.
diff --git a/tests/logging/test_terse_json.py b/tests/logging/test_terse_json.py
index 73f469b802..f6e7e5fdaa 100644
--- a/tests/logging/test_terse_json.py
+++ b/tests/logging/test_terse_json.py
@@ -18,30 +18,35 @@ import logging
from io import StringIO
from synapse.logging._terse_json import JsonFormatter, TerseJsonFormatter
+from synapse.logging.context import LoggingContext, LoggingContextFilter
from tests.logging import LoggerCleanupMixin
from tests.unittest import TestCase
class TerseJsonTestCase(LoggerCleanupMixin, TestCase):
+ def setUp(self):
+ self.output = StringIO()
+
+ def get_log_line(self):
+ # One log message, with a single trailing newline.
+ data = self.output.getvalue()
+ logs = data.splitlines()
+ self.assertEqual(len(logs), 1)
+ self.assertEqual(data.count("\n"), 1)
+ return json.loads(logs[0])
+
def test_terse_json_output(self):
"""
The Terse JSON formatter converts log messages to JSON.
"""
- output = StringIO()
-
- handler = logging.StreamHandler(output)
+ handler = logging.StreamHandler(self.output)
handler.setFormatter(TerseJsonFormatter())
logger = self.get_logger(handler)
logger.info("Hello there, %s!", "wally")
- # One log message, with a single trailing newline.
- data = output.getvalue()
- logs = data.splitlines()
- self.assertEqual(len(logs), 1)
- self.assertEqual(data.count("\n"), 1)
- log = json.loads(logs[0])
+ log = self.get_log_line()
# The terse logger should give us these keys.
expected_log_keys = [
@@ -57,9 +62,7 @@ class TerseJsonTestCase(LoggerCleanupMixin, TestCase):
"""
Additional information can be included in the structured logging.
"""
- output = StringIO()
-
- handler = logging.StreamHandler(output)
+ handler = logging.StreamHandler(self.output)
handler.setFormatter(TerseJsonFormatter())
logger = self.get_logger(handler)
@@ -67,12 +70,7 @@ class TerseJsonTestCase(LoggerCleanupMixin, TestCase):
"Hello there, %s!", "wally", extra={"foo": "bar", "int": 3, "bool": True}
)
- # One log message, with a single trailing newline.
- data = output.getvalue()
- logs = data.splitlines()
- self.assertEqual(len(logs), 1)
- self.assertEqual(data.count("\n"), 1)
- log = json.loads(logs[0])
+ log = self.get_log_line()
# The terse logger should give us these keys.
expected_log_keys = [
@@ -96,26 +94,47 @@ class TerseJsonTestCase(LoggerCleanupMixin, TestCase):
"""
The Terse JSON formatter converts log messages to JSON.
"""
- output = StringIO()
-
- handler = logging.StreamHandler(output)
+ handler = logging.StreamHandler(self.output)
handler.setFormatter(JsonFormatter())
logger = self.get_logger(handler)
logger.info("Hello there, %s!", "wally")
- # One log message, with a single trailing newline.
- data = output.getvalue()
- logs = data.splitlines()
- self.assertEqual(len(logs), 1)
- self.assertEqual(data.count("\n"), 1)
- log = json.loads(logs[0])
+ log = self.get_log_line()
+
+ # The terse logger should give us these keys.
+ expected_log_keys = [
+ "log",
+ "level",
+ "namespace",
+ ]
+ self.assertCountEqual(log.keys(), expected_log_keys)
+ self.assertEqual(log["log"], "Hello there, wally!")
+
+ def test_with_context(self):
+ """
+ The logging context should be added to the JSON response.
+ """
+ handler = logging.StreamHandler(self.output)
+ handler.setFormatter(JsonFormatter())
+ handler.addFilter(LoggingContextFilter(request=""))
+ logger = self.get_logger(handler)
+
+ with LoggingContext() as context_one:
+ context_one.request = "test"
+ logger.info("Hello there, %s!", "wally")
+
+ log = self.get_log_line()
# The terse logger should give us these keys.
expected_log_keys = [
"log",
"level",
"namespace",
+ "request",
+ "scope",
]
self.assertCountEqual(log.keys(), expected_log_keys)
self.assertEqual(log["log"], "Hello there, wally!")
+ self.assertEqual(log["request"], "test")
+ self.assertIsNone(log["scope"])
|