From 728ed46ae025e62457a6a626418c79bc3da4c8a1 Mon Sep 17 00:00:00 2001
From: pjw <pjw@google.com>
Date: Sat, 15 Dec 2018 07:35:11 -0500
Subject: [PATCH] cmd/golsp: make each log message result from a single call to
 fmt.Fprintf

If several RPCs finish together the existing code may mix the log
messages, making reading them difficult.

Change-Id: I1de15373f739c97ccfaf210511b5f5443f7ef036
Reviewed-on: https://go-review.googlesource.com/c/154346
Reviewed-by: Rebecca Stambler <rstambler@golang.org>
---
 cmd/golsp/main.go | 31 ++++++++++++++++++-------------
 1 file changed, 18 insertions(+), 13 deletions(-)

diff --git a/cmd/golsp/main.go b/cmd/golsp/main.go
index 25e6726e..b129b6a8 100644
--- a/cmd/golsp/main.go
+++ b/cmd/golsp/main.go
@@ -20,6 +20,7 @@ import (
 	"runtime"
 	"runtime/pprof"
 	"runtime/trace"
+	"strings"
 	"time"
 
 	"golang.org/x/tools/internal/jsonrpc2"
@@ -108,43 +109,47 @@ func main() {
 		jsonrpc2.NewHeaderStream(os.Stdin, os.Stdout),
 		func(direction jsonrpc2.Direction, id *jsonrpc2.ID, elapsed time.Duration, method string, payload *json.RawMessage, err *jsonrpc2.Error) {
 
+			const eol = "\r\n\r\n\r\n"
 			if err != nil {
-				fmt.Fprintf(out, "[Error - %v] %s %s%s %v", time.Now().Format("3:04:05 PM"), direction, method, id, err)
+				fmt.Fprintf(out, "[Error - %v] %s %s%s %v%s", time.Now().Format("3:04:05 PM"),
+					direction, method, id, err, eol)
 				return
 			}
-			fmt.Fprintf(out, "[Trace - %v] ", time.Now().Format("3:04:05 PM"))
+			outx := new(strings.Builder)
+			fmt.Fprintf(outx, "[Trace - %v] ", time.Now().Format("3:04:05 PM"))
 			switch direction {
 			case jsonrpc2.Send:
-				fmt.Fprint(out, "Received ")
+				fmt.Fprint(outx, "Received ")
 			case jsonrpc2.Receive:
-				fmt.Fprint(out, "Sending ")
+				fmt.Fprint(outx, "Sending ")
 			}
 			switch {
 			case id == nil:
-				fmt.Fprint(out, "notification ")
+				fmt.Fprint(outx, "notification ")
 			case elapsed >= 0:
-				fmt.Fprint(out, "response ")
+				fmt.Fprint(outx, "response ")
 			default:
-				fmt.Fprint(out, "request ")
+				fmt.Fprint(outx, "request ")
 			}
-			fmt.Fprintf(out, "'%s", method)
+			fmt.Fprintf(outx, "'%s", method)
 			switch {
 			case id == nil:
 				// do nothing
 			case id.Name != "":
-				fmt.Fprintf(out, " - (%s)", id.Name)
+				fmt.Fprintf(outx, " - (%s)", id.Name)
 			default:
-				fmt.Fprintf(out, " - (%d)", id.Number)
+				fmt.Fprintf(outx, " - (%d)", id.Number)
 			}
-			fmt.Fprint(out, "'")
+			fmt.Fprint(outx, "'")
 			if elapsed >= 0 {
-				fmt.Fprintf(out, " in %vms", elapsed.Nanoseconds()/1000)
+				fmt.Fprintf(outx, " in %vms", elapsed.Nanoseconds()/1000)
 			}
 			params := string(*payload)
 			if params == "null" {
 				params = "{}"
 			}
-			fmt.Fprintf(out, ".\r\nParams: %s\r\n\r\n\r\n", params)
+			fmt.Fprintf(outx, ".\r\nParams: %s%s", params, eol)
+			fmt.Fprintf(out, "%s", outx.String())
 		},
 	); err != nil {
 		log.Fatal(err)