More structured `lsp.log`

Language Server Protocol (LSP)
1

Hi there

I’ve been having some difficulty extracting useful information from the contents of /home/$USER/.local/state/nvim/lsp.log. The log consists of entries of the form:

[DEBUG][2023-04-23 21:49:10] .../vim/lsp/rpc.lua:388	"rpc.receive" {  jsonrpc = "2.0",  method = "$/progress",  params = { ... } }

Where the ellipsized bit is what appears to be a serialization of a deeply nested lua record.

Since these presumably arise from just marshalling the underlying JSON-RPC messages, would it make sense to just have a more structured “JSON-centric” view of the log instead?

In other words, instead of a stream of semi-structured log-entries in an ad-hoc format like [$SEVERITY][$TIMESTAMP] $LOCATION $EVENT_NAME $LUA_RECORD, we just use a stream of single-line JSON records containing both the metadata and (if applicable) JSON-RPC payload.

This is a format that goes by many names (ndjson, jsonl, etc.) but the important thing is that it’s easy to parse (even when streaming), and consequently there’s a wide variety of tooling that will help a plugin author or someone debugging an issue extract useful information from the stream.

I have no strong opinions on what specific structured log technology is used (e.g. i’ll use protobuf instead of jsonl if i have to), or what the precise log message schema should be (e.g. maybe):

{ "event_id": "rpc.receive", "data": { "meta": { ... severity, timestamp, location etc... } }, "payload": { ... json-rpc payload... } }

But I think regardless of how these details shake out it would be an improvement over the status quo.

Does this make sense?

Thanks,
Asad

1 Like
2

Hi,

:+1: for having more structured logs in the format of ndjson

in the meantime you can use lnav with following custom formatter:

{
  "nvim_lsp": {
    "title": "Nvim Lsp Log Format",
    "description": "Log format used by nvim lsp client",
    "regex": {
      "basic": {
        "pattern": "^\\[(?<level>\\w+)\\]\\[(?<timestamp>\\d{4}-\\d{2}-\\d{2} \\d{2}:\\d{2}:\\d{2})\\]\\s(?<source>.+?:\\d+)(?:\\s+.+?)?(?:\\s+.+?)?\\s+(?<body>.+)$"
      }
    },
    "level": {
      "error": "ERROR",
      "warning": "WARN",
      "info": "START"
    },
    "value": {
      "source": {
        "kind": "string",
        "identifier": true
      }
    },
    "sample": [
      {
        "line": "[ERROR][2023-11-06 17:35:57] .../vim/lsp/rpc.lua:734    \"rpc\"   \"/nix/store/m496nzhqma57j1968fbn4hm6g8q9kzga-smithy_ls-0.0.28/bin/smithy_ls\"    \"stderr\"        \"Nov 06, 2023 5:35:57 PM org.eclipse.lsp4j.jsonrpc.services.GenericEndpoint notify\nWARNING: Unsupported notification method: metals/didFocusTextDocument\n\""
      }
    ]
  }
}