Skip to content
This repository has been archived by the owner on Apr 26, 2024. It is now read-only.

Improve structured logging #8683

Open
clokep opened this issue Oct 29, 2020 · 1 comment
Open

Improve structured logging #8683

clokep opened this issue Oct 29, 2020 · 1 comment
Labels
A-Logging Synapse's logs (structured or otherwise). Not metrics. T-Enhancement New features, changes in functionality, improvements in performance, or user-facing enhancements.

Comments

@clokep
Copy link
Member

clokep commented Oct 29, 2020

Building on #8588 there's a desire to improve the output of Synapse structured logging.

Currently a "standard" log line would be turned into JSON (this was a curl to /_matrix/client/r0/login to get the login flows, but other logs look similar):

2020-10-29 07:36:00,762 - synapse.access.http.8080 - 315 - INFO - GET-0 - - - 8080 - {None} Processed request: 0.000sec/-0.000sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 285B 200 "GET /_matrix/client/r0/login HTTP/1.1" "curl/7.64.1" [0 dbevts]

This would transform to (note that whitespace was added for visibility, normally this would be a single line with no whitespaec between JSON separators):

{
    "log": "- - 8080 - {None} Processed request: 0.000sec/-0.000sec (0.000sec, 0.000sec) (0.000sec/0.000sec/0) 285B 200 \"GET /_matrix/client/r0/login HTTP/1.1\" \"curl/7.64.1\" [0 dbevts]",
    "namespace": "synapse.access.http.8080",
    "level": "INFO",
    "time": 1603971360.76,
    "request": "GET-0",
    "scope": null,
    "server_name": "localhost:8480"
}

A few improvements we'll want to make:

  • The log line includes a formatted message, which makes it difficult to search in a structured way.
  • Currently logging a message with additional fields requires including the fields twice (using the standard logging flow and the extra keyword to the logger).
@clokep
Copy link
Member Author

clokep commented Apr 20, 2021

To update this a bit:

  • The code to create the structured logs has been cleaned up quite a bit so I think this issue is now in a spot to include additional info on a per-log line basis.
  • We now include additional fields in the structed logs due to Record more information into structured logs #9654, which should make them more usable.

So the description here is still pretty valid (including the formatted log lines is not ideal), but much of the logging context is now included.

I'm no longer actively working on this so unassigning.

@clokep clokep removed their assignment Apr 20, 2021
@clokep clokep added T-Enhancement New features, changes in functionality, improvements in performance, or user-facing enhancements. and removed z-enhancement labels Apr 20, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
A-Logging Synapse's logs (structured or otherwise). Not metrics. T-Enhancement New features, changes in functionality, improvements in performance, or user-facing enhancements.
Projects
None yet
Development

No branches or pull requests

2 participants