Some refactoring wrt logging and debugging

- clangd launcher has been moved into main module, removing an unneded
indirection.
- streams management functions now resides in their own module.
- file logging has been downgraded from an object to a function

Author: cmaglie

Diff for: handler/handler.go

@@ -6,7 +6,6 @@ import (
 	"encoding/json"
 	"fmt"
 	"io"
-	"io/ioutil"
 	"log"
 	"os"
 	"regexp"
@@ -33,19 +32,19 @@ func Setup(cliPath string, _enableLogging bool, _asyncProcessing bool) {
 type CLangdStarter func() (stdin io.WriteCloser, stdout io.ReadCloser, stderr io.ReadCloser)
 
 // NewInoHandler creates and configures an InoHandler.
-func NewInoHandler(stdin io.ReadCloser, stdout io.WriteCloser, logStreams *StreamLogger, startClangd CLangdStarter, board Board) *InoHandler {
+func NewInoHandler(stdio io.ReadWriteCloser, clangdStdio io.ReadWriteCloser, board Board) *InoHandler {
 	handler := &InoHandler{
-		clangdProc: ClangdProc{
-			Start: startClangd,
-			Logs:  logStreams,
-		},
 		data: make(map[lsp.DocumentURI]*FileData),
 		config: BoardConfig{
 			SelectedBoard: board,
 		},
 	}
-	handler.startClangd()
-	stdStream := jsonrpc2.NewBufferedStream(logStreams.AttachStdInOut(stdin, stdout), jsonrpc2.VSCodeObjectCodec{})
+
+	clangdStream := jsonrpc2.NewBufferedStream(clangdStdio, jsonrpc2.VSCodeObjectCodec{})
+	clangdHandler := jsonrpc2.AsyncHandler(jsonrpc2.HandlerWithError(handler.FromClangd))
+	handler.ClangdConn = jsonrpc2.NewConn(context.Background(), clangdStream, clangdHandler)
+
+	stdStream := jsonrpc2.NewBufferedStream(stdio, jsonrpc2.VSCodeObjectCodec{})
 	var stdHandler jsonrpc2.Handler = jsonrpc2.HandlerWithError(handler.FromStdio)
 	if asyncProcessing {
 		stdHandler = AsyncHandler{
@@ -64,18 +63,11 @@ func NewInoHandler(stdin io.ReadCloser, stdout io.WriteCloser, logStreams *Strea
 type InoHandler struct {
 	StdioConn    *jsonrpc2.Conn
 	ClangdConn   *jsonrpc2.Conn
-	clangdProc   ClangdProc
 	data         map[lsp.DocumentURI]*FileData
 	config       BoardConfig
 	synchronizer Synchronizer
 }
 
-// ClangdProc contains the process input / output streams for clangd.
-type ClangdProc struct {
-	Start func() (io.WriteCloser, io.ReadCloser, io.ReadCloser)
-	Logs  *StreamLogger
-}
-
 // FileData gathers information on a .ino source file.
 type FileData struct {
 	sourceText    string
@@ -86,20 +78,6 @@ type FileData struct {
 	version       int
 }
 
-// StartClangd starts the clangd process and connects its input / output streams.
-func (handler *InoHandler) startClangd() {
-	clangdWrite, clangdRead, clangdErr := handler.clangdProc.Start()
-	if enableLogging {
-		go io.Copy(handler.clangdProc.Logs.ClangdErr, clangdErr)
-	} else {
-		go io.Copy(ioutil.Discard, clangdErr)
-	}
-	srw := handler.clangdProc.Logs.AttachClangdInOut(clangdRead, clangdWrite)
-	clangdStream := jsonrpc2.NewBufferedStream(srw, jsonrpc2.VSCodeObjectCodec{})
-	clangdHandler := jsonrpc2.AsyncHandler(jsonrpc2.HandlerWithError(handler.FromClangd))
-	handler.ClangdConn = jsonrpc2.NewConn(context.Background(), clangdStream, clangdHandler)
-}
-
 // StopClangd closes the connection to the clangd process.
 func (handler *InoHandler) StopClangd() {
 	handler.ClangdConn.Close()

Diff for: handler/streamlog.go

@@ -7,8 +7,10 @@ import (
 	"log"
 	"os"
 	"os/exec"
+	"path/filepath"
 
 	"github.com/bcmi-labs/arduino-language-server/handler"
+	"github.com/bcmi-labs/arduino-language-server/streams"
 )
 
 var clangdPath string
@@ -29,29 +31,53 @@ func main() {
 	flag.StringVar(&loggingBasePath, "logpath", ".", "Location where to write logging files to when logging is enabled")
 	flag.Parse()
 
-	// var stdinLog, stdoutLog, clangdinLog, clangdoutLog, clangderrLog io.Writer
-	var logStreams *handler.StreamLogger
 	if enableLogging {
-		var err error
-		logStreams, err = handler.NewStreamLogger(loggingBasePath)
-		if err != nil {
-			log.Fatal(err)
-		}
-		defer logStreams.Close()
-
-		log.SetOutput(logStreams.Default)
+		logfile := openLogFile("inols-err.log")
+		defer logfile.Close()
+		log.SetOutput(logfile)
 	} else {
-		logStreams = handler.NewNoopLogger()
 		log.SetOutput(os.Stderr)
 	}
 
 	handler.Setup(cliPath, enableLogging, true)
 	initialBoard := handler.Board{Fqbn: initialFqbn, Name: initialBoardName}
-	inoHandler := handler.NewInoHandler(os.Stdin, os.Stdout, logStreams, startClangd, initialBoard)
+
+	clangdStdout, clangdStdin, clangdStderr := startClangd()
+	clangdStdio := streams.NewReadWriteCloser(clangdStdin, clangdStdout)
+	if enableLogging {
+		logfile := openLogFile("inols-clangd.log")
+		defer logfile.Close()
+		clangdStdio = streams.LogReadWriteCloserToFile(clangdStdio, logfile)
+
+		errLogfile := openLogFile("inols-clangd-err.log")
+		defer errLogfile.Close()
+		go io.Copy(errLogfile, clangdStderr)
+	}
+
+	stdio := streams.NewReadWriteCloser(os.Stdin, os.Stdout)
+	if enableLogging {
+		logfile := openLogFile("inols.log")
+		defer logfile.Close()
+		stdio = streams.LogReadWriteCloserToFile(stdio, logfile)
+	}
+
+	inoHandler := handler.NewInoHandler(stdio, clangdStdio, initialBoard)
 	defer inoHandler.StopClangd()
 	<-inoHandler.StdioConn.DisconnectNotify()
 }
 
+func openLogFile(name string) *os.File {
+	path := filepath.Join(loggingBasePath, name)
+	logfile, err := os.Create(path)
+	if err != nil {
+		log.Fatalf("Error opening log file: %s", err)
+	} else {
+		abs, _ := filepath.Abs(path)
+		log.Println("logging to " + abs)
+	}
+	return logfile
+}
+
 func startClangd() (clangdIn io.WriteCloser, clangdOut io.ReadCloser, clangdErr io.ReadCloser) {
 	if enableLogging {
 		log.Println("Starting clangd process:", clangdPath)

Diff for: main.go

@@ -0,0 +1,45 @@
+package streams
+
+import (
+	"fmt"
+	"io"
+	"os"
+)
+
+// LogReadWriteCloserToFile return a proxy for the given upstream io.ReadWriteCloser
+// that forward and logs all read/write/close operations on the given file.
+func LogReadWriteCloserToFile(upstream io.ReadWriteCloser, file *os.File) io.ReadWriteCloser {
+	return &dumper{upstream, file}
+}
+
+type dumper struct {
+	upstream io.ReadWriteCloser
+	logfile  *os.File
+}
+
+func (d *dumper) Read(buff []byte) (int, error) {
+	n, err := d.upstream.Read(buff)
+	if err != nil {
+		d.logfile.Write([]byte(fmt.Sprintf("<<< Read Error: %s\n", err)))
+	} else {
+		d.logfile.Write([]byte(fmt.Sprintf("<<< Read %d bytes:\n%s\n", n, buff[:n])))
+	}
+	return n, err
+}
+
+func (d *dumper) Write(buff []byte) (int, error) {
+	n, err := d.upstream.Write(buff)
+	if err != nil {
+		_, _ = d.logfile.Write([]byte(fmt.Sprintf(">>> Write Error: %s\n", err)))
+	} else {
+		_, _ = d.logfile.Write([]byte(fmt.Sprintf(">>> Wrote %d bytes:\n%s\n", n, buff[:n])))
+	}
+	return n, err
+}
+
+func (d *dumper) Close() error {
+	err := d.upstream.Close()
+	_, _ = d.logfile.Write([]byte(fmt.Sprintf("--- Stream closed, err=%s\n", err)))
+	_ = d.logfile.Close()
+	return err
+}

Diff for: streams/dumper.go

@@ -0,0 +1,33 @@
+package streams
+
+import "io"
+
+// NewReadWriteCloser create an io.ReadWriteCloser from given io.ReadCloser and io.WriteCloser.
+func NewReadWriteCloser(in io.ReadCloser, out io.WriteCloser) io.ReadWriteCloser {
+	return &combinedReadWriteCloser{in, out}
+}
+
+type combinedReadWriteCloser struct {
+	reader io.ReadCloser
+	writer io.WriteCloser
+}
+
+func (sd *combinedReadWriteCloser) Read(p []byte) (int, error) {
+	return sd.reader.Read(p)
+}
+
+func (sd *combinedReadWriteCloser) Write(p []byte) (int, error) {
+	return sd.writer.Write(p)
+}
+
+func (sd *combinedReadWriteCloser) Close() error {
+	ierr := sd.reader.Close()
+	oerr := sd.writer.Close()
+	if ierr != nil {
+		return ierr
+	}
+	if oerr != nil {
+		return oerr
+	}
+	return nil
+}