Improved logging of jsonrpc requests

Author: cmaglie

go.mod

@@ -5,6 +5,7 @@ go 1.12
 require (
 	github.com/arduino/arduino-cli v0.0.0-20201215104024-6a177ebf56f2
 	github.com/arduino/go-paths-helper v1.5.0
+	github.com/fatih/color v1.7.0
 	github.com/pkg/errors v0.9.1
 	github.com/sourcegraph/jsonrpc2 v0.0.0-20200429184054-15c2290dcb37
 	github.com/stretchr/testify v1.6.1

handler/handler.go

@@ -83,7 +83,10 @@ func NewInoHandler(stdio io.ReadWriteCloser, board lsp.Board) *InoHandler {
 	handler.clangdStarted = sync.NewCond(&handler.dataMux)
 	stdStream := jsonrpc2.NewBufferedStream(stdio, jsonrpc2.VSCodeObjectCodec{})
 	var stdHandler jsonrpc2.Handler = jsonrpc2.HandlerWithError(handler.HandleMessageFromIDE)
-	handler.StdioConn = jsonrpc2.NewConn(context.Background(), stdStream, stdHandler)
+	handler.StdioConn = jsonrpc2.NewConn(context.Background(), stdStream, stdHandler,
+		jsonrpc2.OnRecv(streams.JSONRPCConnLogOnRecv("IDE --> LS     CL:")),
+		jsonrpc2.OnSend(streams.JSONRPCConnLogOnSend("IDE <-- LS     CL:")),
+	)
 
 	handler.progressHandler = NewProgressProxy(handler.StdioConn)
 
@@ -514,7 +517,9 @@ func (handler *InoHandler) initializeWorkbench(ctx context.Context, params *lsp.
 
 		clangdStream := jsonrpc2.NewBufferedStream(clangdStdio, jsonrpc2.VSCodeObjectCodec{})
 		clangdHandler := AsyncHandler{jsonrpc2.HandlerWithError(handler.FromClangd)}
-		handler.ClangdConn = jsonrpc2.NewConn(context.Background(), clangdStream, clangdHandler)
+		handler.ClangdConn = jsonrpc2.NewConn(context.Background(), clangdStream, clangdHandler,
+			jsonrpc2.OnRecv(streams.JSONRPCConnLogOnRecv("IDE     LS <-- CL:")),
+			jsonrpc2.OnSend(streams.JSONRPCConnLogOnSend("IDE     LS --> CL:")))
 
 		// Send initialization command to clangd
 		ctx, cancel := context.WithTimeout(context.Background(), time.Second)

streams/jsonrpc2.go

@@ -0,0 +1,52 @@
+package streams
+
+import (
+	"log"
+	"runtime/debug"
+
+	"github.com/fatih/color"
+	"github.com/sourcegraph/jsonrpc2"
+)
+
+var green = color.New(color.FgHiGreen)
+var red = color.New(color.FgHiRed)
+
+// JSONRPCConnLogOnRecv perform logging of the given req and resp
+func JSONRPCConnLogOnRecv(prefix string) func(req *jsonrpc2.Request, resp *jsonrpc2.Response) {
+	return func(req *jsonrpc2.Request, resp *jsonrpc2.Response) {
+		jsonrpcLog(prefix, req, resp, false)
+	}
+}
+
+// JSONRPCConnLogOnSend perform logging of the given req and resp
+func JSONRPCConnLogOnSend(prefix string) func(req *jsonrpc2.Request, resp *jsonrpc2.Response) {
+	return func(req *jsonrpc2.Request, resp *jsonrpc2.Response) {
+		jsonrpcLog(prefix, req, resp, true)
+	}
+}
+
+func jsonrpcLog(prefix string, req *jsonrpc2.Request, resp *jsonrpc2.Response, sending bool) {
+	color.NoColor = false
+	var c *color.Color
+	if sending {
+		c = red
+	} else {
+		c = green
+	}
+	if resp != nil {
+		if req != nil {
+			log.Print(c.Sprintf(prefix+" ANSWER %s %v (%v)", req.Method, req.ID, resp.ID))
+		} else {
+			log.Print(c.Sprintf(prefix+" ANSWER UNBOUND (%v)", resp.ID))
+		}
+	} else if req != nil {
+		if !req.Notif {
+			log.Print(c.Sprintf(prefix+" REQUEST %s %v", req.Method, req.ID))
+		} else {
+			log.Print(c.Sprintf(prefix+" NOTIFICATION %s", req.Method))
+		}
+	} else {
+		log.Print(green.Sprintf(prefix + " NULL MESSAGE"))
+		log.Print(string(debug.Stack()))
+	}
+}