LSP Logging #1321
LSP Logging #1321
Conversation
This uses the LSP window/logMessage notification to send terraform-ls logs to the client instead of to stderr. This has the benefit of not using stderr for clients that report that as errors as well as shipping logs for TCP connections. How these logs are displayed varies by editor, with VS Code, SublimeText and neovim appearing to handle these fine.
Signed-off-by: hashicorp-copywrite[bot] <110428419+hashicorp-copywrite[bot]@users.noreply.github.com>
There was a problem hiding this comment.
First of all thank you for looking into this!
Have you considered the concerns mentioned in #1271 ?
Aside from in-line comments I'd be specifically still concerned about this
how do we debug/log the LSP traffic itself without doubling the number of requests, i.e. without logging every e.g.
textDocument/completionviawindow/logMessage?
If I'm not mistaken, at this current stage of the draft, the server would continue logging every LSP request, maybe even notifications? Aside from doubling the number of requests it would also turn into an endless loop of window/logMessage logging window/logMessage, would it not?
| // TODO: Not sure about removing this here. We can't use window/LogMessage yet | ||
| // because we haven't started | ||
| // If we leave this here, some stuff still goes to stderr | ||
| // srv.SetLogger(logger) |
There was a problem hiding this comment.
Yes, this is one of the concerns I mentioned in #1271
IMHO I think we'll just need to review what those log messages are, maybe remove any non-critical ones and continue sending the rest to STDERR as there just isn't any better location.
| @@ -105,6 +106,10 @@ func (ls *langServer) StartAndWait(reader io.Reader, writer io.WriteCloser) erro | |||
| cancelFunc() | |||
| }() | |||
|
|
|||
| ls.SetLogger(logging.NewLspLogger(&logging.LspLogger{ | |||
| Context: ctx, | |||
There was a problem hiding this comment.
In general storing context is considered anti-pattern in Go. We could pass the server instance here instead of the context. It would also make the contract much clearer, where the LspLogger depends on "LSP server" rather than arbitrary context which may or may not contain the instance of the server.
| @@ -85,7 +86,7 @@ func (ls *langServer) startServer(reader io.Reader, writer io.WriteCloser) (*sin | |||
| return nil, err | |||
| } | |||
| srv.Start(channel.LSP(reader, writer)) | |||
|
|
|||
| @@ -39,6 +40,9 @@ func (svc *service) Initialize(ctx context.Context, params lsp.InitializeParams) | |||
| expClientCaps := lsp.ExperimentalClientCapabilities(clientCaps.Experimental) | |||
|
|
|||
| svc.server = jrpc2.ServerFromContext(ctx) | |||
| svc.logger = logging.NewLspLogger(&logging.LspLogger{ | |||
| Context: ctx, | |||
There was a problem hiding this comment.
| Context: ctx, | |
| Server: svc.server, |
As per other comment this would make for a cleaner contract.
| // there appears to be an extra newline that's helpful for stderr | ||
| // but not for outputchannel | ||
| logMessage = strings.TrimSuffix(logMessage, "\n") |
There was a problem hiding this comment.
I wonder if this just originates from our use of some Printlns in various places? 🤔
I'd be slightly worried about the performance impact here in such a critical path but maybe it's negligible.
|
FWIW there is a structured logging package coming up in Go 1.21 (planned for August '23), currently available via https://pkg.go.dev/golang.org/x/exp/slog which could help answer one of the concerns regarding the log levels (warn, info, debug etc.) and maybe better align the logging with LSP's logging, which has multiple levels too. I'd be open to finishing this but we should find some answers to the mentioned concerns. Even if the solution isn't ideal we should agree on a solution. We should also ensure we're not boxing ourselves into a corner when it comes to structured logging which we should IMHO adopt eventually. It's not super clear in the spec but I am guessing that LSP expects "human-readable" log messages inside the On a related note I was hoping this would present an opportunity to extract/collect some metrics more easily, where we could essentially just send some specific log messages somewhere where we aggregate the structured data inside each such log message. The LSP spec suggests that won't work though, or at least isn't meant to work that way. |
|
I'm going to lock this pull request because it has been closed for 30 days ⏳. This helps our maintainers find and focus on the active issues. |
This uses the LSP window/logMessage notification to send terraform-ls logs to the client instead of to stderr. This has the benefit of not using stderr for clients that report that as errors as well as shipping logs for TCP connections.
How these logs are displayed varies by editor, with VS Code, SublimeText and neovim appearing to handle these fine.
This is currently a hackweek project that needs some work to get into a state that can be shipped