Skip to content
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
41 changes: 41 additions & 0 deletions docs/structured_logging.md
Original file line number Diff line number Diff line change
Expand Up @@ -78,3 +78,44 @@ loggers:
The above logging config will set Synapse as 'INFO' logging level by default,
with the SQL layer at 'WARNING', and will log JSON formatted messages to a
remote endpoint at 10.1.2.3:9999.

## Google Cloud Logging (GKE)

When running Synapse on GKE, use `synapse.logging.GcpJsonFormatter`. It outputs
JSON to stdout with a `severity` field that Google Cloud Logging maps to the
correct per-entry severity. Without this, GKE assigns `ERROR` to everything
written to stderr regardless of the actual Python log level.

Example output:

```json
{"severity":"INFO","message":"Processed request: 3.481sec 200 GET /sync","logger":"synapse.access.http.8008","time":"2026-05-12T13:40:37.829Z"}
```

Configuration:

```yaml
version: 1
disable_existing_loggers: false

formatters:
gcp_json:
class: synapse.logging.GcpJsonFormatter

handlers:
console:
class: logging.StreamHandler
formatter: gcp_json
stream: ext://sys.stdout

loggers:
synapse.storage.SQL:
level: WARNING
twisted:
handlers: [console]
propagate: false

root:
level: INFO
handlers: [console]
```
4 changes: 2 additions & 2 deletions synapse/logging/__init__.py
Original file line number Diff line number Diff line change
Expand Up @@ -22,10 +22,10 @@
import logging

from synapse.logging._remote import RemoteHandler
from synapse.logging._terse_json import JsonFormatter, TerseJsonFormatter
from synapse.logging._terse_json import GcpJsonFormatter, JsonFormatter, TerseJsonFormatter

# These are imported to allow for nicer logging configuration files.
__all__ = ["RemoteHandler", "JsonFormatter", "TerseJsonFormatter"]
__all__ = ["RemoteHandler", "JsonFormatter", "TerseJsonFormatter", "GcpJsonFormatter"]

# Debug logger for https://github.com/matrix-org/synapse/issues/9533 etc
issue9533_logger = logging.getLogger("synapse.9533_debug")
29 changes: 29 additions & 0 deletions synapse/logging/_terse_json.py
Original file line number Diff line number Diff line change
Expand Up @@ -25,6 +25,7 @@

import json
import logging
from datetime import datetime, timezone

_encoder = json.JSONEncoder(ensure_ascii=False, separators=(",", ":"))

Expand Down Expand Up @@ -93,3 +94,31 @@ def format(self, record: logging.LogRecord) -> str:
}

return self._format(record, event)


class GcpJsonFormatter(logging.Formatter):
"""JSON formatter compatible with Google Cloud Logging structured logging.

Outputs `severity` (not `level`) so GCL correctly maps each log record to
the right severity instead of inheriting ERROR from stderr.
"""

def format(self, record: logging.LogRecord) -> str:
msg = record.getMessage()
if record.exc_info:
if not record.exc_text:
record.exc_text = self.formatException(record.exc_info)
if record.exc_text:
msg = f"{msg}\n{record.exc_text}"

event = {
"severity": record.levelname,
"message": msg,
"logger": record.name,
"time": datetime.fromtimestamp(record.created, tz=timezone.utc).strftime(
"%Y-%m-%dT%H:%M:%S.%f"
)[:-3]
+ "Z",
}

return _encoder.encode(event)
76 changes: 75 additions & 1 deletion tests/logging/test_terse_json.py
Original file line number Diff line number Diff line change
Expand Up @@ -28,7 +28,7 @@
from twisted.web.server import Request

from synapse.http.site import SynapseRequest
from synapse.logging._terse_json import JsonFormatter, TerseJsonFormatter
from synapse.logging._terse_json import GcpJsonFormatter, JsonFormatter, TerseJsonFormatter
from synapse.logging.context import LoggingContext, LoggingContextFilter
from synapse.types import JsonDict

Expand Down Expand Up @@ -251,3 +251,77 @@ def test_with_exception(self) -> None:
self.assertEqual(log["log"], "Hello there, wally!")
self.assertEqual(log["exc_type"], "ValueError")
self.assertEqual(log["exc_value"], "That's wrong, you wally!")


class GcpJsonFormatterTestCase(LoggerCleanupMixin, TestCase):
def setUp(self) -> None:
self.output = StringIO()

def get_log_line(self) -> JsonDict:
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_gcp_json_output(self) -> None:
"""
GcpJsonFormatter produces exactly the four fields GCL expects.
"""
handler = logging.StreamHandler(self.output)
handler.setFormatter(GcpJsonFormatter())
logger = self.get_logger(handler)

logger.info("Hello there, %s!", "wally")

log = self.get_log_line()

self.assertIncludes(
log.keys(), {"severity", "message", "logger", "time"}, exact=True
)
self.assertEqual(log["message"], "Hello there, wally!")
self.assertEqual(log["severity"], "INFO")
self.assertTrue(log["time"].endswith("Z"))

def test_severity_levels(self) -> None:
"""
Python log levels are mapped to their GCL severity equivalents.
"""
cases = [
(logging.DEBUG, "DEBUG"),
(logging.INFO, "INFO"),
(logging.WARNING, "WARNING"),
(logging.ERROR, "ERROR"),
(logging.CRITICAL, "CRITICAL"),
]
for level, expected_severity in cases:
self.output = StringIO()
handler = logging.StreamHandler(self.output)
handler.setFormatter(GcpJsonFormatter())
logger = self.get_logger(handler)
logger.setLevel(level)
logger.log(level, "test")
log = self.get_log_line()
self.assertEqual(log["severity"], expected_severity, f"level={level}")

def test_gcp_json_with_exception(self) -> None:
"""
Exception info is appended to the message field, not separate keys.
"""
handler = logging.StreamHandler(self.output)
handler.setFormatter(GcpJsonFormatter())
logger = self.get_logger(handler)

try:
raise ValueError("That's wrong, you wally!")
except ValueError:
logger.exception("Hello there, %s!", "wally")

log = self.get_log_line()

self.assertIncludes(
log.keys(), {"severity", "message", "logger", "time"}, exact=True
)
self.assertIn("Hello there, wally!", log["message"])
self.assertIn("ValueError", log["message"])
self.assertIn("That's wrong, you wally!", log["message"])