From 5d16bdd7b52e1f60221247e74fc795574a05424a Mon Sep 17 00:00:00 2001 From: Ian Cottrell Date: Fri, 29 Mar 2019 19:04:29 -0400 Subject: [PATCH] internal/lsp: add the ability to log back to the client Also use it for errors that were otherwise silently dropped This makes it much easier to debug problems. Also added command line control over whether the rpc trace messages are printed, which allows you to read the log, otherwise the file edit messages swamp the log. Change-Id: I7b70fd18034a87b2964e6d6d5f6f33dcaf7d8ea8 Reviewed-on: https://go-review.googlesource.com/c/tools/+/170178 Reviewed-by: Rebecca Stambler --- internal/lsp/cache/check.go | 11 +- internal/lsp/cache/view.go | 23 ++- internal/lsp/cmd/cmd.go | 23 ++- internal/lsp/cmd/definition.go | 8 +- internal/lsp/cmd/serve.go | 80 ++++++----- internal/lsp/lsp_test.go | 5 +- internal/lsp/protocol/client.go | 63 +++++--- internal/lsp/protocol/log.go | 32 +++++ internal/lsp/protocol/protocol.go | 35 ++--- internal/lsp/protocol/server.go | 223 +++++++++++++++++++---------- internal/lsp/server.go | 17 ++- internal/lsp/source/diagnostics.go | 6 +- internal/lsp/source/view.go | 2 + internal/lsp/xlog/xlog.go | 71 +++++++++ 14 files changed, 415 insertions(+), 184 deletions(-) create mode 100644 internal/lsp/protocol/log.go create mode 100644 internal/lsp/xlog/xlog.go diff --git a/internal/lsp/cache/check.go b/internal/lsp/cache/check.go index f49d8719..1fdbf4a0 100644 --- a/internal/lsp/cache/check.go +++ b/internal/lsp/cache/check.go @@ -8,7 +8,6 @@ import ( "go/scanner" "go/types" "io/ioutil" - "log" "os" "path/filepath" "strings" @@ -55,7 +54,7 @@ func (v *View) parse(ctx context.Context, f *File) ([]packages.Error, error) { return nil, err } // Add every file in this package to our cache. - v.cachePackage(pkg) + v.cachePackage(ctx, pkg) // If we still have not found the package for the file, something is wrong. if f.pkg == nil { @@ -64,22 +63,22 @@ func (v *View) parse(ctx context.Context, f *File) ([]packages.Error, error) { return nil, nil } -func (v *View) cachePackage(pkg *Package) { +func (v *View) cachePackage(ctx context.Context, pkg *Package) { for _, file := range pkg.GetSyntax() { // TODO: If a file is in multiple packages, which package do we store? if !file.Pos().IsValid() { - log.Printf("invalid position for file %v", file.Name) + v.Logger().Errorf(ctx, "invalid position for file %v", file.Name) continue } tok := v.Config.Fset.File(file.Pos()) if tok == nil { - log.Printf("no token.File for %v", file.Name) + v.Logger().Errorf(ctx, "no token.File for %v", file.Name) continue } fURI := span.FileURI(tok.Name()) f, err := v.getFile(fURI) if err != nil { - log.Printf("no file: %v", err) + v.Logger().Errorf(ctx, "no file: %v", err) continue } f.token = tok diff --git a/internal/lsp/cache/view.go b/internal/lsp/cache/view.go index fb5e5980..f37cba05 100644 --- a/internal/lsp/cache/view.go +++ b/internal/lsp/cache/view.go @@ -13,6 +13,7 @@ import ( "golang.org/x/tools/go/packages" "golang.org/x/tools/internal/lsp/source" + "golang.org/x/tools/internal/lsp/xlog" "golang.org/x/tools/internal/span" ) @@ -20,6 +21,10 @@ type View struct { // mu protects all mutable state of the view. mu sync.Mutex + // baseCtx is the context handed to NewView. This is the parent of all + // background contexts created for this view. + baseCtx context.Context + // backgroundCtx is the current context used by background tasks initiated // by the view. backgroundCtx context.Context @@ -28,6 +33,9 @@ type View struct { // should be stopped. cancel context.CancelFunc + // the logger to use to communicate back with the client + log xlog.Logger + // Name is the user visible name of this view. Name string @@ -80,11 +88,13 @@ type entry struct { ready chan struct{} // closed to broadcast ready condition } -func NewView(name string, folder span.URI, config *packages.Config) *View { - ctx, cancel := context.WithCancel(context.Background()) +func NewView(ctx context.Context, log xlog.Logger, name string, folder span.URI, config *packages.Config) *View { + backgroundCtx, cancel := context.WithCancel(ctx) v := &View{ - backgroundCtx: ctx, + baseCtx: ctx, + backgroundCtx: backgroundCtx, cancel: cancel, + log: log, Config: *config, Name: name, Folder: folder, @@ -116,11 +126,10 @@ func (v *View) FileSet() *token.FileSet { func (v *View) SetContent(ctx context.Context, uri span.URI, content []byte) error { v.mu.Lock() defer v.mu.Unlock() - // Cancel all still-running previous requests, since they would be // operating on stale data. v.cancel() - v.backgroundCtx, v.cancel = context.WithCancel(context.Background()) + v.backgroundCtx, v.cancel = context.WithCancel(v.baseCtx) v.contentChanges[uri] = func() { v.applyContentChange(uri, content) @@ -277,3 +286,7 @@ func (v *View) mapFile(uri span.URI, f *File) { v.filesByBase[f.basename] = append(v.filesByBase[f.basename], f) } } + +func (v *View) Logger() xlog.Logger { + return v.log +} diff --git a/internal/lsp/cmd/cmd.go b/internal/lsp/cmd/cmd.go index 6ac65cc8..7159dbb7 100644 --- a/internal/lsp/cmd/cmd.go +++ b/internal/lsp/cmd/cmd.go @@ -14,6 +14,7 @@ import ( "go/ast" "go/parser" "go/token" + "log" "net" "os" "strings" @@ -126,7 +127,7 @@ func (app *Application) connect(ctx context.Context, client protocol.Client) (pr cr, sw, _ := os.Pipe() sr, cw, _ := os.Pipe() var jc *jsonrpc2.Conn - jc, server = protocol.NewClient(jsonrpc2.NewHeaderStream(cr, cw), client) + jc, server, _ = protocol.NewClient(jsonrpc2.NewHeaderStream(cr, cw), client) go jc.Run(ctx) go lsp.NewServer(jsonrpc2.NewHeaderStream(sr, sw)).Run(ctx) default: @@ -136,7 +137,7 @@ func (app *Application) connect(ctx context.Context, client protocol.Client) (pr } stream := jsonrpc2.NewHeaderStream(conn, conn) var jc *jsonrpc2.Conn - jc, server = protocol.NewClient(stream, client) + jc, server, _ = protocol.NewClient(stream, client) if err != nil { return nil, err } @@ -162,8 +163,22 @@ func (c *baseClient) ShowMessage(ctx context.Context, p *protocol.ShowMessagePar func (c *baseClient) ShowMessageRequest(ctx context.Context, p *protocol.ShowMessageRequestParams) (*protocol.MessageActionItem, error) { return nil, nil } -func (c *baseClient) LogMessage(ctx context.Context, p *protocol.LogMessageParams) error { return nil } -func (c *baseClient) Telemetry(ctx context.Context, t interface{}) error { return nil } +func (c *baseClient) LogMessage(ctx context.Context, p *protocol.LogMessageParams) error { + switch p.Type { + case protocol.Error: + log.Print("Error:", p.Message) + case protocol.Warning: + log.Print("Warning:", p.Message) + case protocol.Info: + log.Print("Info:", p.Message) + case protocol.Log: + log.Print("Log:", p.Message) + default: + log.Print(p.Message) + } + return nil +} +func (c *baseClient) Telemetry(ctx context.Context, t interface{}) error { return nil } func (c *baseClient) RegisterCapability(ctx context.Context, p *protocol.RegistrationParams) error { return nil } diff --git a/internal/lsp/cmd/definition.go b/internal/lsp/cmd/definition.go index 89b8b481..e0f5f928 100644 --- a/internal/lsp/cmd/definition.go +++ b/internal/lsp/cmd/definition.go @@ -16,6 +16,7 @@ import ( guru "golang.org/x/tools/cmd/guru/serial" "golang.org/x/tools/internal/lsp/cache" "golang.org/x/tools/internal/lsp/source" + "golang.org/x/tools/internal/lsp/xlog" "golang.org/x/tools/internal/span" "golang.org/x/tools/internal/tool" ) @@ -30,9 +31,9 @@ type Definition struct { // help is still valid. // They refer to "Set" in "flag.FlagSet" from the DetailedHelp method below. const ( - exampleLine = 46 + exampleLine = 47 exampleColumn = 47 - exampleOffset = 1319 + exampleOffset = 1359 ) // definition implements the definition noun for the query command. @@ -61,7 +62,8 @@ func (d *definition) Run(ctx context.Context, args ...string) error { if len(args) != 1 { return tool.CommandLineErrorf("definition expects 1 argument") } - view := cache.NewView("definition_test", span.FileURI(d.query.app.Config.Dir), &d.query.app.Config) + log := xlog.New(xlog.StdSink{}) + view := cache.NewView(ctx, log, "definition_test", span.FileURI(d.query.app.Config.Dir), &d.query.app.Config) from := span.Parse(args[0]) f, err := view.GetFile(ctx, from.URI()) if err != nil { diff --git a/internal/lsp/cmd/serve.go b/internal/lsp/cmd/serve.go index afa333ac..2cc1de20 100644 --- a/internal/lsp/cmd/serve.go +++ b/internal/lsp/cmd/serve.go @@ -29,6 +29,7 @@ type Serve struct { Mode string `flag:"mode" help:"no effect"` Port int `flag:"port" help:"port on which to run gopls for debugging purposes"` Address string `flag:"listen" help:"address on which to listen for remote connections"` + Trace bool `flag:"rpc.trace" help:"Print the full rpc trace in lsp inspector format"` app *Application } @@ -71,7 +72,49 @@ func (s *Serve) Run(ctx context.Context, args ...string) error { if s.app.Remote != "" { return s.forward() } - logger := func(direction jsonrpc2.Direction, id *jsonrpc2.ID, elapsed time.Duration, method string, payload *json.RawMessage, err *jsonrpc2.Error) { + + // For debugging purposes only. + run := func(srv *lsp.Server) { + srv.Conn.Logger = logger(s.Trace, out) + go srv.Conn.Run(ctx) + } + if s.Address != "" { + return lsp.RunServerOnAddress(ctx, s.Address, run) + } + if s.Port != 0 { + return lsp.RunServerOnPort(ctx, s.Port, run) + } + stream := jsonrpc2.NewHeaderStream(os.Stdin, os.Stdout) + srv := lsp.NewServer(stream) + srv.Conn.Logger = logger(s.Trace, out) + return srv.Conn.Run(ctx) +} + +func (s *Serve) forward() error { + conn, err := net.Dial("tcp", s.app.Remote) + if err != nil { + return err + } + errc := make(chan error) + + go func(conn net.Conn) { + _, err := io.Copy(conn, os.Stdin) + errc <- err + }(conn) + + go func(conn net.Conn) { + _, err := io.Copy(os.Stdout, conn) + errc <- err + }(conn) + + return <-errc +} + +func logger(trace bool, out io.Writer) jsonrpc2.Logger { + return func(direction jsonrpc2.Direction, id *jsonrpc2.ID, elapsed time.Duration, method string, payload *json.RawMessage, err *jsonrpc2.Error) { + if !trace { + return + } const eol = "\r\n\r\n\r\n" if err != nil { fmt.Fprintf(out, "[Error - %v] %s %s%s %v%s", time.Now().Format("3:04:05 PM"), @@ -118,39 +161,4 @@ func (s *Serve) Run(ctx context.Context, args ...string) error { fmt.Fprintf(outx, ".\r\nParams: %s%s", params, eol) fmt.Fprintf(out, "%s", outx.String()) } - // For debugging purposes only. - run := func(srv *lsp.Server) { - srv.Conn.Logger = logger - go srv.Conn.Run(ctx) - } - if s.Address != "" { - return lsp.RunServerOnAddress(ctx, s.Address, run) - } - if s.Port != 0 { - return lsp.RunServerOnPort(ctx, s.Port, run) - } - stream := jsonrpc2.NewHeaderStream(os.Stdin, os.Stdout) - srv := lsp.NewServer(stream) - srv.Conn.Logger = logger - return srv.Conn.Run(ctx) -} - -func (s *Serve) forward() error { - conn, err := net.Dial("tcp", s.app.Remote) - if err != nil { - return err - } - errc := make(chan error) - - go func(conn net.Conn) { - _, err := io.Copy(conn, os.Stdin) - errc <- err - }(conn) - - go func(conn net.Conn) { - _, err := io.Copy(os.Stdout, conn) - errc <- err - }(conn) - - return <-errc } diff --git a/internal/lsp/lsp_test.go b/internal/lsp/lsp_test.go index 61884707..a21b86ca 100644 --- a/internal/lsp/lsp_test.go +++ b/internal/lsp/lsp_test.go @@ -22,6 +22,7 @@ import ( "golang.org/x/tools/internal/lsp/cache" "golang.org/x/tools/internal/lsp/protocol" "golang.org/x/tools/internal/lsp/source" + "golang.org/x/tools/internal/lsp/xlog" "golang.org/x/tools/internal/span" ) @@ -34,6 +35,7 @@ func TestLSP(t *testing.T) { } func testLSP(t *testing.T, exporter packagestest.Exporter) { + ctx := context.Background() const dir = "testdata" // We hardcode the expected number of test cases to ensure that all tests @@ -70,8 +72,9 @@ func testLSP(t *testing.T, exporter packagestest.Exporter) { return parser.ParseFile(fset, filename, src, parser.AllErrors|parser.ParseComments) } + log := xlog.New(xlog.StdSink{}) s := &Server{ - view: cache.NewView("lsp_test", span.FileURI(cfg.Dir), &cfg), + view: cache.NewView(ctx, log, "lsp_test", span.FileURI(cfg.Dir), &cfg), } // Do a first pass to collect special markers for completion. if err := exported.Expect(map[string]interface{}{ diff --git a/internal/lsp/protocol/client.go b/internal/lsp/protocol/client.go index d16eef2b..2962a777 100644 --- a/internal/lsp/protocol/client.go +++ b/internal/lsp/protocol/client.go @@ -9,6 +9,7 @@ import ( "encoding/json" "golang.org/x/tools/internal/jsonrpc2" + "golang.org/x/tools/internal/lsp/xlog" ) type Client interface { @@ -24,13 +25,13 @@ type Client interface { PublishDiagnostics(context.Context, *PublishDiagnosticsParams) error } -func clientHandler(client Client) jsonrpc2.Handler { +func clientHandler(log xlog.Logger, client Client) jsonrpc2.Handler { return func(ctx context.Context, conn *jsonrpc2.Conn, r *jsonrpc2.Request) { switch r.Method { case "$/cancelRequest": var params CancelParams if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } conn.Cancel(params.ID) @@ -38,51 +39,63 @@ func clientHandler(client Client) jsonrpc2.Handler { case "window/showMessage": var params ShowMessageParams if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } - unhandledError(client.ShowMessage(ctx, ¶ms)) + if err := client.ShowMessage(ctx, ¶ms); err != nil { + log.Errorf(ctx, "%v", err) + } case "window/showMessageRequest": var params ShowMessageRequestParams if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } resp, err := client.ShowMessageRequest(ctx, ¶ms) - unhandledError(conn.Reply(ctx, r, resp, err)) + if err := conn.Reply(ctx, r, resp, err); err != nil { + log.Errorf(ctx, "%v", err) + } case "window/logMessage": var params LogMessageParams if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } - unhandledError(client.LogMessage(ctx, ¶ms)) + if err := client.LogMessage(ctx, ¶ms); err != nil { + log.Errorf(ctx, "%v", err) + } case "telemetry/event": var params interface{} if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } - unhandledError(client.Telemetry(ctx, ¶ms)) + if err := client.Telemetry(ctx, ¶ms); err != nil { + log.Errorf(ctx, "%v", err) + } case "client/registerCapability": var params RegistrationParams if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } - unhandledError(client.RegisterCapability(ctx, ¶ms)) + if err := client.RegisterCapability(ctx, ¶ms); err != nil { + log.Errorf(ctx, "%v", err) + } case "client/unregisterCapability": var params UnregistrationParams if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } - unhandledError(client.UnregisterCapability(ctx, ¶ms)) + if err := client.UnregisterCapability(ctx, ¶ms); err != nil { + log.Errorf(ctx, "%v", err) + } case "workspace/workspaceFolders": if r.Params != nil { @@ -90,33 +103,41 @@ func clientHandler(client Client) jsonrpc2.Handler { return } resp, err := client.WorkspaceFolders(ctx) - unhandledError(conn.Reply(ctx, r, resp, err)) + if err := conn.Reply(ctx, r, resp, err); err != nil { + log.Errorf(ctx, "%v", err) + } case "workspace/configuration": var params ConfigurationParams if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } resp, err := client.Configuration(ctx, ¶ms) - unhandledError(conn.Reply(ctx, r, resp, err)) + if err := conn.Reply(ctx, r, resp, err); err != nil { + log.Errorf(ctx, "%v", err) + } case "workspace/applyEdit": var params ApplyWorkspaceEditParams if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } resp, err := client.ApplyEdit(ctx, ¶ms) - unhandledError(conn.Reply(ctx, r, resp, err)) + if err := conn.Reply(ctx, r, resp, err); err != nil { + log.Errorf(ctx, "%v", err) + } case "textDocument/publishDiagnostics": var params PublishDiagnosticsParams if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } - unhandledError(client.PublishDiagnostics(ctx, ¶ms)) + if err := client.PublishDiagnostics(ctx, ¶ms); err != nil { + log.Errorf(ctx, "%v", err) + } default: if r.IsNotify() { diff --git a/internal/lsp/protocol/log.go b/internal/lsp/protocol/log.go new file mode 100644 index 00000000..71725c93 --- /dev/null +++ b/internal/lsp/protocol/log.go @@ -0,0 +1,32 @@ +package protocol + +import ( + "context" + + "golang.org/x/tools/internal/lsp/xlog" +) + +// logSink implements xlog.Sink in terms of the LogMessage call to a client. +type logSink struct { + client Client +} + +// NewLogger returns an xlog.Sink that sends its messages using client.LogMessage. +// It maps Debug to the Log level, Info and Error to their matching levels, and +// does not support warnings. +func NewLogger(client Client) xlog.Sink { + return logSink{client: client} +} + +func (s logSink) Log(ctx context.Context, level xlog.Level, message string) { + typ := Log + switch level { + case xlog.ErrorLevel: + typ = Error + case xlog.InfoLevel: + typ = Info + case xlog.DebugLevel: + typ = Log + } + s.client.LogMessage(ctx, &LogMessageParams{Type: typ, Message: message}) +} diff --git a/internal/lsp/protocol/protocol.go b/internal/lsp/protocol/protocol.go index 123358d0..eebfb245 100644 --- a/internal/lsp/protocol/protocol.go +++ b/internal/lsp/protocol/protocol.go @@ -6,9 +6,9 @@ package protocol import ( "context" - "log" "golang.org/x/tools/internal/jsonrpc2" + "golang.org/x/tools/internal/lsp/xlog" ) const defaultMessageBufferSize = 20 @@ -17,41 +17,32 @@ func canceller(ctx context.Context, conn *jsonrpc2.Conn, req *jsonrpc2.Request) conn.Notify(context.Background(), "$/cancelRequest", &CancelParams{ID: *req.ID}) } -func NewClient(stream jsonrpc2.Stream, client Client) (*jsonrpc2.Conn, Server) { +func NewClient(stream jsonrpc2.Stream, client Client) (*jsonrpc2.Conn, Server, xlog.Logger) { + log := xlog.New(NewLogger(client)) conn := jsonrpc2.NewConn(stream) conn.Capacity = defaultMessageBufferSize conn.RejectIfOverloaded = true - conn.Handler = clientHandler(client) + conn.Handler = clientHandler(log, client) conn.Canceler = jsonrpc2.Canceler(canceller) - return conn, &serverDispatcher{Conn: conn} + return conn, &serverDispatcher{Conn: conn}, log } -func NewServer(stream jsonrpc2.Stream, server Server) (*jsonrpc2.Conn, Client) { +func NewServer(stream jsonrpc2.Stream, server Server) (*jsonrpc2.Conn, Client, xlog.Logger) { conn := jsonrpc2.NewConn(stream) + client := &clientDispatcher{Conn: conn} + log := xlog.New(NewLogger(client)) conn.Capacity = defaultMessageBufferSize conn.RejectIfOverloaded = true - conn.Handler = serverHandler(server) + conn.Handler = serverHandler(log, server) conn.Canceler = jsonrpc2.Canceler(canceller) - return conn, &clientDispatcher{Conn: conn} + return conn, client, log } -func sendParseError(ctx context.Context, conn *jsonrpc2.Conn, req *jsonrpc2.Request, err error) { +func sendParseError(ctx context.Context, log xlog.Logger, conn *jsonrpc2.Conn, req *jsonrpc2.Request, err error) { if _, ok := err.(*jsonrpc2.Error); !ok { err = jsonrpc2.NewErrorf(jsonrpc2.CodeParseError, "%v", err) } - unhandledError(conn.Reply(ctx, req, nil, err)) -} - -// unhandledError is used in places where an error may occur that cannot be handled. -// This occurs in things like rpc handlers that are a notify, where we cannot -// reply to the caller, or in a call when we are actually attempting to reply. -// In these cases, there is nothing we can do with the error except log it, so -// we do that in this function, and the presence of this function acts as a -// useful reminder of why we are effectively dropping the error and also a -// good place to hook in when debugging those kinds of errors. -func unhandledError(err error) { - if err == nil { - return + if err := conn.Reply(ctx, req, nil, err); err != nil { + log.Errorf(ctx, "%v", err) } - log.Printf("%v", err) } diff --git a/internal/lsp/protocol/server.go b/internal/lsp/protocol/server.go index 5e8e28d5..4cb8e48b 100644 --- a/internal/lsp/protocol/server.go +++ b/internal/lsp/protocol/server.go @@ -9,6 +9,7 @@ import ( "encoding/json" "golang.org/x/tools/internal/jsonrpc2" + "golang.org/x/tools/internal/lsp/xlog" ) type Server interface { @@ -51,44 +52,52 @@ type Server interface { FoldingRanges(context.Context, *FoldingRangeParams) ([]FoldingRange, error) } -func serverHandler(server Server) jsonrpc2.Handler { +func serverHandler(log xlog.Logger, server Server) jsonrpc2.Handler { return func(ctx context.Context, conn *jsonrpc2.Conn, r *jsonrpc2.Request) { switch r.Method { case "initialize": var params InitializeParams if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } resp, err := server.Initialize(ctx, ¶ms) - unhandledError(conn.Reply(ctx, r, resp, err)) + if err := conn.Reply(ctx, r, resp, err); err != nil { + log.Errorf(ctx, "%v", err) + } case "initialized": var params InitializedParams if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } - unhandledError(server.Initialized(ctx, ¶ms)) + if err := server.Initialized(ctx, ¶ms); err != nil { + log.Errorf(ctx, "%v", err) + } case "shutdown": if r.Params != nil { conn.Reply(ctx, r, nil, jsonrpc2.NewErrorf(jsonrpc2.CodeInvalidParams, "Expected no params")) return } - unhandledError(server.Shutdown(ctx)) + if err := server.Shutdown(ctx); err != nil { + log.Errorf(ctx, "%v", err) + } case "exit": if r.Params != nil { conn.Reply(ctx, r, nil, jsonrpc2.NewErrorf(jsonrpc2.CodeInvalidParams, "Expected no params")) return } - unhandledError(server.Exit(ctx)) + if err := server.Exit(ctx); err != nil { + log.Errorf(ctx, "%v", err) + } case "$/cancelRequest": var params CancelParams if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } conn.Cancel(params.ID) @@ -96,291 +105,357 @@ func serverHandler(server Server) jsonrpc2.Handler { case "workspace/didChangeWorkspaceFolders": var params DidChangeWorkspaceFoldersParams if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } - unhandledError(server.DidChangeWorkspaceFolders(ctx, ¶ms)) + if err := server.DidChangeWorkspaceFolders(ctx, ¶ms); err != nil { + log.Errorf(ctx, "%v", err) + } case "workspace/didChangeConfiguration": var params DidChangeConfigurationParams if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } - unhandledError(server.DidChangeConfiguration(ctx, ¶ms)) + if err := server.DidChangeConfiguration(ctx, ¶ms); err != nil { + log.Errorf(ctx, "%v", err) + } case "workspace/didChangeWatchedFiles": var params DidChangeWatchedFilesParams if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } - unhandledError(server.DidChangeWatchedFiles(ctx, ¶ms)) + if err := server.DidChangeWatchedFiles(ctx, ¶ms); err != nil { + log.Errorf(ctx, "%v", err) + } case "workspace/symbol": var params WorkspaceSymbolParams if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } resp, err := server.Symbols(ctx, ¶ms) - unhandledError(conn.Reply(ctx, r, resp, err)) + if err := conn.Reply(ctx, r, resp, err); err != nil { + log.Errorf(ctx, "%v", err) + } case "workspace/executeCommand": var params ExecuteCommandParams if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } resp, err := server.ExecuteCommand(ctx, ¶ms) - unhandledError(conn.Reply(ctx, r, resp, err)) + if err := conn.Reply(ctx, r, resp, err); err != nil { + log.Errorf(ctx, "%v", err) + } case "textDocument/didOpen": var params DidOpenTextDocumentParams if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } - unhandledError(server.DidOpen(ctx, ¶ms)) + if err := server.DidOpen(ctx, ¶ms); err != nil { + log.Errorf(ctx, "%v", err) + } case "textDocument/didChange": var params DidChangeTextDocumentParams if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } - unhandledError(server.DidChange(ctx, ¶ms)) + if err := server.DidChange(ctx, ¶ms); err != nil { + log.Errorf(ctx, "%v", err) + } case "textDocument/willSave": var params WillSaveTextDocumentParams if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } - unhandledError(server.WillSave(ctx, ¶ms)) + if err := server.WillSave(ctx, ¶ms); err != nil { + log.Errorf(ctx, "%v", err) + } case "textDocument/willSaveWaitUntil": var params WillSaveTextDocumentParams if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } resp, err := server.WillSaveWaitUntil(ctx, ¶ms) - unhandledError(conn.Reply(ctx, r, resp, err)) + if err := conn.Reply(ctx, r, resp, err); err != nil { + log.Errorf(ctx, "%v", err) + } case "textDocument/didSave": var params DidSaveTextDocumentParams if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } - unhandledError(server.DidSave(ctx, ¶ms)) + if err := server.DidSave(ctx, ¶ms); err != nil { + log.Errorf(ctx, "%v", err) + } case "textDocument/didClose": var params DidCloseTextDocumentParams if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } - unhandledError(server.DidClose(ctx, ¶ms)) + if err := server.DidClose(ctx, ¶ms); err != nil { + log.Errorf(ctx, "%v", err) + } case "textDocument/completion": var params CompletionParams if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } resp, err := server.Completion(ctx, ¶ms) - unhandledError(conn.Reply(ctx, r, resp, err)) + if err := conn.Reply(ctx, r, resp, err); err != nil { + log.Errorf(ctx, "%v", err) + } case "completionItem/resolve": var params CompletionItem if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } resp, err := server.CompletionResolve(ctx, ¶ms) - unhandledError(conn.Reply(ctx, r, resp, err)) + if err := conn.Reply(ctx, r, resp, err); err != nil { + log.Errorf(ctx, "%v", err) + } case "textDocument/hover": var params TextDocumentPositionParams if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } resp, err := server.Hover(ctx, ¶ms) - unhandledError(conn.Reply(ctx, r, resp, err)) + if err := conn.Reply(ctx, r, resp, err); err != nil { + log.Errorf(ctx, "%v", err) + } case "textDocument/signatureHelp": var params TextDocumentPositionParams if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } resp, err := server.SignatureHelp(ctx, ¶ms) - unhandledError(conn.Reply(ctx, r, resp, err)) + if err := conn.Reply(ctx, r, resp, err); err != nil { + log.Errorf(ctx, "%v", err) + } case "textDocument/definition": var params TextDocumentPositionParams if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } resp, err := server.Definition(ctx, ¶ms) - unhandledError(conn.Reply(ctx, r, resp, err)) + if err := conn.Reply(ctx, r, resp, err); err != nil { + log.Errorf(ctx, "%v", err) + } case "textDocument/typeDefinition": var params TextDocumentPositionParams if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } resp, err := server.TypeDefinition(ctx, ¶ms) - unhandledError(conn.Reply(ctx, r, resp, err)) + if err := conn.Reply(ctx, r, resp, err); err != nil { + log.Errorf(ctx, "%v", err) + } case "textDocument/implementation": var params TextDocumentPositionParams if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } resp, err := server.Implementation(ctx, ¶ms) - unhandledError(conn.Reply(ctx, r, resp, err)) + if err := conn.Reply(ctx, r, resp, err); err != nil { + log.Errorf(ctx, "%v", err) + } case "textDocument/references": var params ReferenceParams if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } resp, err := server.References(ctx, ¶ms) - unhandledError(conn.Reply(ctx, r, resp, err)) + if err := conn.Reply(ctx, r, resp, err); err != nil { + log.Errorf(ctx, "%v", err) + } case "textDocument/documentHighlight": var params TextDocumentPositionParams if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } resp, err := server.DocumentHighlight(ctx, ¶ms) - unhandledError(conn.Reply(ctx, r, resp, err)) + if err := conn.Reply(ctx, r, resp, err); err != nil { + log.Errorf(ctx, "%v", err) + } case "textDocument/documentSymbol": var params DocumentSymbolParams if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } resp, err := server.DocumentSymbol(ctx, ¶ms) - unhandledError(conn.Reply(ctx, r, resp, err)) + if err := conn.Reply(ctx, r, resp, err); err != nil { + log.Errorf(ctx, "%v", err) + } case "textDocument/codeAction": var params CodeActionParams if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } resp, err := server.CodeAction(ctx, ¶ms) - unhandledError(conn.Reply(ctx, r, resp, err)) + if err := conn.Reply(ctx, r, resp, err); err != nil { + log.Errorf(ctx, "%v", err) + } case "textDocument/codeLens": var params CodeLensParams if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } resp, err := server.CodeLens(ctx, ¶ms) - unhandledError(conn.Reply(ctx, r, resp, err)) + if err := conn.Reply(ctx, r, resp, err); err != nil { + log.Errorf(ctx, "%v", err) + } case "codeLens/resolve": var params CodeLens if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } resp, err := server.CodeLensResolve(ctx, ¶ms) - unhandledError(conn.Reply(ctx, r, resp, err)) + if err := conn.Reply(ctx, r, resp, err); err != nil { + log.Errorf(ctx, "%v", err) + } case "textDocument/documentLink": var params DocumentLinkParams if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } resp, err := server.DocumentLink(ctx, ¶ms) - unhandledError(conn.Reply(ctx, r, resp, err)) + if err := conn.Reply(ctx, r, resp, err); err != nil { + log.Errorf(ctx, "%v", err) + } case "documentLink/resolve": var params DocumentLink if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } resp, err := server.DocumentLinkResolve(ctx, ¶ms) - unhandledError(conn.Reply(ctx, r, resp, err)) + if err := conn.Reply(ctx, r, resp, err); err != nil { + log.Errorf(ctx, "%v", err) + } case "textDocument/documentColor": var params DocumentColorParams if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } resp, err := server.DocumentColor(ctx, ¶ms) - unhandledError(conn.Reply(ctx, r, resp, err)) + if err := conn.Reply(ctx, r, resp, err); err != nil { + log.Errorf(ctx, "%v", err) + } case "textDocument/colorPresentation": var params ColorPresentationParams if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } resp, err := server.ColorPresentation(ctx, ¶ms) - unhandledError(conn.Reply(ctx, r, resp, err)) + if err := conn.Reply(ctx, r, resp, err); err != nil { + log.Errorf(ctx, "%v", err) + } case "textDocument/formatting": var params DocumentFormattingParams if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } resp, err := server.Formatting(ctx, ¶ms) - unhandledError(conn.Reply(ctx, r, resp, err)) + if err := conn.Reply(ctx, r, resp, err); err != nil { + log.Errorf(ctx, "%v", err) + } case "textDocument/rangeFormatting": var params DocumentRangeFormattingParams if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } resp, err := server.RangeFormatting(ctx, ¶ms) - unhandledError(conn.Reply(ctx, r, resp, err)) + if err := conn.Reply(ctx, r, resp, err); err != nil { + log.Errorf(ctx, "%v", err) + } case "textDocument/onTypeFormatting": var params DocumentOnTypeFormattingParams if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } resp, err := server.OnTypeFormatting(ctx, ¶ms) - unhandledError(conn.Reply(ctx, r, resp, err)) + if err := conn.Reply(ctx, r, resp, err); err != nil { + log.Errorf(ctx, "%v", err) + } case "textDocument/rename": var params RenameParams if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } resp, err := server.Rename(ctx, ¶ms) - unhandledError(conn.Reply(ctx, r, resp, err)) + if err := conn.Reply(ctx, r, resp, err); err != nil { + log.Errorf(ctx, "%v", err) + } case "textDocument/foldingRange": var params FoldingRangeParams if err := json.Unmarshal(*r.Params, ¶ms); err != nil { - sendParseError(ctx, conn, r, err) + sendParseError(ctx, log, conn, r, err) return } resp, err := server.FoldingRanges(ctx, ¶ms) - unhandledError(conn.Reply(ctx, r, resp, err)) + if err := conn.Reply(ctx, r, resp, err); err != nil { + log.Errorf(ctx, "%v", err) + } default: if r.IsNotify() { conn.Reply(ctx, r, nil, jsonrpc2.NewErrorf(jsonrpc2.CodeMethodNotFound, "method %q not found", r.Method)) diff --git a/internal/lsp/server.go b/internal/lsp/server.go index 0ea00852..3a5ea3ea 100644 --- a/internal/lsp/server.go +++ b/internal/lsp/server.go @@ -22,6 +22,7 @@ import ( "golang.org/x/tools/internal/lsp/cache" "golang.org/x/tools/internal/lsp/protocol" "golang.org/x/tools/internal/lsp/source" + "golang.org/x/tools/internal/lsp/xlog" "golang.org/x/tools/internal/span" ) @@ -29,6 +30,7 @@ import ( func NewClientServer(client protocol.Client) *Server { return &Server{ client: client, + log: xlog.New(protocol.NewLogger(client)), } } @@ -36,7 +38,7 @@ func NewClientServer(client protocol.Client) *Server { // stream is closed. func NewServer(stream jsonrpc2.Stream) *Server { s := &Server{} - s.Conn, s.client = protocol.NewServer(stream, s) + s.Conn, s.client, s.log = protocol.NewServer(stream, s) return s } @@ -68,6 +70,7 @@ func RunServerOnAddress(ctx context.Context, addr string, h func(s *Server)) err type Server struct { Conn *jsonrpc2.Conn client protocol.Client + log xlog.Logger initializedMu sync.Mutex initialized bool // set once the server has received "initialize" request @@ -117,8 +120,11 @@ func (s *Server) Initialize(ctx context.Context, params *protocol.InitializePara // flag). Disabled for now to simplify debugging. s.textDocumentSyncKind = protocol.Full + //We need a "detached" context so it does not get timeout cancelled. + //TODO(iancottrell): Do we need to copy any values across? + viewContext := context.Background() //TODO:use workspace folders - s.view = cache.NewView(path.Base(string(rootURI)), rootURI, &packages.Config{ + s.view = cache.NewView(viewContext, s.log, path.Base(string(rootURI)), rootURI, &packages.Config{ Context: ctx, Dir: rootPath, Env: os.Environ(), @@ -566,13 +572,6 @@ func (s *Server) FoldingRanges(context.Context, *protocol.FoldingRangeParams) ([ return nil, notImplemented("FoldingRanges") } -func (s *Server) Error(err error) { - s.client.LogMessage(context.Background(), &protocol.LogMessageParams{ - Type: protocol.Error, - Message: fmt.Sprint(err), - }) -} - func (s *Server) processConfig(config interface{}) error { //TODO: we should probably store and process more of the config c, ok := config.(map[string]interface{}) diff --git a/internal/lsp/source/diagnostics.go b/internal/lsp/source/diagnostics.go index a20175f5..cee64135 100644 --- a/internal/lsp/source/diagnostics.go +++ b/internal/lsp/source/diagnostics.go @@ -8,7 +8,6 @@ import ( "bytes" "context" "fmt" - "log" "golang.org/x/tools/go/analysis" "golang.org/x/tools/go/analysis/passes/asmdecl" @@ -90,7 +89,8 @@ func Diagnostics(ctx context.Context, v View, uri span.URI) (map[span.URI][]Diag if diagFile, err := v.GetFile(ctx, spn.URI()); err == nil { tok := diagFile.GetToken(ctx) if tok == nil { - continue // ignore errors + v.Logger().Errorf(ctx, "Could not matching tokens for diagnostic: %v", diagFile.URI()) + continue } content := diagFile.GetContent(ctx) c := span.NewTokenConverter(diagFile.GetFileSet(ctx), tok) @@ -124,7 +124,7 @@ func Diagnostics(ctx context.Context, v View, uri span.URI) (map[span.URI][]Diag if err != nil { //TODO: we could not process the diag.Pos, and thus have no valid span //we don't have anywhere to put this error though - log.Print(err) + v.Logger().Errorf(ctx, "%v", err) } category := a.Name if diag.Category != "" { diff --git a/internal/lsp/source/view.go b/internal/lsp/source/view.go index 855fc2c0..2b7d2b18 100644 --- a/internal/lsp/source/view.go +++ b/internal/lsp/source/view.go @@ -12,6 +12,7 @@ import ( "golang.org/x/tools/go/analysis" "golang.org/x/tools/go/packages" + "golang.org/x/tools/internal/lsp/xlog" "golang.org/x/tools/internal/span" ) @@ -19,6 +20,7 @@ import ( // package. The view provides access to files and their contents, so the source // package does not directly access the file system. type View interface { + Logger() xlog.Logger GetFile(ctx context.Context, uri span.URI) (File, error) SetContent(ctx context.Context, uri span.URI, content []byte) error FileSet() *token.FileSet diff --git a/internal/lsp/xlog/xlog.go b/internal/lsp/xlog/xlog.go new file mode 100644 index 00000000..a8d5bdad --- /dev/null +++ b/internal/lsp/xlog/xlog.go @@ -0,0 +1,71 @@ +// Copyright 2018 The Go Authors. All rights reserved. +// Use of this source code is governed by a BSD-style +// license that can be found in the LICENSE file. + +package xlog + +import ( + "context" + "fmt" + "log" +) + +// Logger is a wrapper over a sink to provide a clean API over the core log +// function. +type Logger struct { + sink Sink +} + +// Level indicates the severity of the logging message. +type Level int + +const ( + ErrorLevel = Level(iota) + InfoLevel + DebugLevel +) + +// Sink is the interface to something that consumes logging messages. +// This can be implemented and then registered with a context to control the +// destination or formatting of logging. +type Sink interface { + Log(ctx context.Context, level Level, message string) +} + +// StdSink is a Sink that writes to the standard log package. +type StdSink struct{} + +// New returns a logger for the provided sink. +func New(sink Sink) Logger { + return Logger{sink: sink} +} + +// Errorf is intended for the logging of errors that we could not easily return +// to the client but that caused problems internally. +func (l Logger) Errorf(ctx context.Context, format string, args ...interface{}) { + l.sink.Log(ctx, ErrorLevel, fmt.Sprintf(format, args...)) +} + +// Infof is intended for logging of messages that may help the user understand +// the behavior or be useful in a bug report. +func (l Logger) Infof(ctx context.Context, format string, args ...interface{}) { + l.sink.Log(ctx, InfoLevel, fmt.Sprintf(format, args...)) +} + +// Debugf is intended to be used only while debugging. +func (l Logger) Debugf(ctx context.Context, format string, args ...interface{}) { + l.sink.Log(ctx, DebugLevel, fmt.Sprintf(format, args...)) +} + +// Log implements Sink for the StdSink. +// It writes the message using log.Print with a level based prefix. +func (StdSink) Log(ctx context.Context, level Level, message string) { + switch level { + case ErrorLevel: + log.Print("Error: ", message) + case InfoLevel: + log.Print("Info: ", message) + case DebugLevel: + log.Print("Debug: ", message) + } +}