External processes output is printed on stdout/stderr in a synchronized way.

Thus we are sure that those outputs do not interfere with our own output,
otherwise leading to wrongly formatted log messages. Fixes arduino#17

Signed-off-by: Federico Fissore <f.fissore@arduino.cc>

Author: Federico Fissore

src/arduino.cc/builder/builder_utils/utils.go

@@ -33,9 +33,9 @@ import (
 	"arduino.cc/builder/constants"
 	"arduino.cc/builder/i18n"
 	"arduino.cc/builder/props"
+	"arduino.cc/builder/types"
 	"arduino.cc/builder/utils"
 	"bytes"
-	"fmt"
 	"os"
 	"os/exec"
 	"path/filepath"
@@ -319,10 +319,18 @@ func ExecRecipe(properties map[string]string, recipe string, removeUnsetProperti
 	}
 
 	if echoOutput {
-		command.Stdout = os.Stdout
+		printToStdOut := func(s string) {
+			logger.UnformattedFprintln(os.Stdout, s)
+		}
+		stdout := &types.BufferedUntilNewLineWriter{PrintFunc: printToStdOut, Buffer: bytes.Buffer{}}
+		command.Stdout = stdout
 	}
 
-	command.Stderr = os.Stderr
+	printToStdErr := func(s string) {
+		logger.UnformattedFprintln(os.Stderr, s)
+	}
+	stderr := &types.BufferedUntilNewLineWriter{PrintFunc: printToStdErr, Buffer: bytes.Buffer{}}
+	command.Stderr = stderr
 
 	if echoOutput {
 		err := command.Run()
@@ -354,7 +362,7 @@ func PrepareCommandForRecipe(properties map[string]string, recipe string, remove
 	}
 
 	if echoCommandLine {
-		fmt.Println(commandLine)
+		logger.UnformattedFprintln(os.Stdout, commandLine)
 	}
 
 	return command, nil

src/arduino.cc/builder/coan_runner.go

@@ -34,7 +34,7 @@ import (
 	"arduino.cc/builder/i18n"
 	"arduino.cc/builder/props"
 	"arduino.cc/builder/utils"
-	"fmt"
+	"os"
 	"path/filepath"
 	"regexp"
 )
@@ -74,7 +74,7 @@ func (s *CoanRunner) Run(context map[string]interface{}) error {
 	command, err := utils.PrepareCommandFilteredArgs(commandLine, filterAllowedArg, logger)
 
 	if verbose {
-		fmt.Println(commandLine)
+		logger.UnformattedFprintln(os.Stdout, commandLine)
 	}
 
 	sourceBytes, _ := command.Output()

src/arduino.cc/builder/ctags_runner.go

@@ -34,7 +34,7 @@ import (
 	"arduino.cc/builder/i18n"
 	"arduino.cc/builder/props"
 	"arduino.cc/builder/utils"
-	"fmt"
+	"os"
 )
 
 type CTagsRunner struct{}
@@ -60,7 +60,7 @@ func (s *CTagsRunner) Run(context map[string]interface{}) error {
 
 	verbose := context[constants.CTX_VERBOSE].(bool)
 	if verbose {
-		fmt.Println(commandLine)
+		logger.UnformattedFprintln(os.Stdout, commandLine)
 	}
 
 	sourceBytes, err := command.Output()

src/arduino.cc/builder/i18n/i18n.go

@@ -38,12 +38,14 @@ import (
 	"regexp"
 	"strconv"
 	"strings"
+	"sync"
 )
 
 var PLACEHOLDER = regexp.MustCompile("{(\\d)}")
 
 type Logger interface {
 	Fprintln(w io.Writer, level string, format string, a ...interface{})
+	UnformattedFprintln(w io.Writer, s string)
 	Println(level string, format string, a ...interface{})
 	Name() string
 }
@@ -52,6 +54,8 @@ type NoopLogger struct{}
 
 func (s NoopLogger) Fprintln(w io.Writer, level string, format string, a ...interface{}) {}
 
+func (s NoopLogger) UnformattedFprintln(w io.Writer, str string) {}
+
 func (s NoopLogger) Println(level string, format string, a ...interface{}) {}
 
 func (s NoopLogger) Name() string {
@@ -61,10 +65,14 @@ func (s NoopLogger) Name() string {
 type HumanLogger struct{}
 
 func (s HumanLogger) Fprintln(w io.Writer, level string, format string, a ...interface{}) {
-	fmt.Fprintln(w, Format(format, a...))
+	fprintln(w, Format(format, a...))
+}
+
+func (s HumanLogger) UnformattedFprintln(w io.Writer, str string) {
+	fprintln(w, str)
 }
 
-func (s HumanLogger) Println(level string, format string, a ...interface{}) {
+func (s HumanLogger) Println(format string, level string, a ...interface{}) {
 	s.Fprintln(os.Stdout, level, Format(format, a...))
 }
 
@@ -74,28 +82,45 @@ func (s HumanLogger) Name() string {
 
 type MachineLogger struct{}
 
-func (s MachineLogger) printWithoutFormatting(w io.Writer, level string, format string, a []interface{}) {
+func (s MachineLogger) Fprintln(w io.Writer, level string, format string, a ...interface{}) {
+	printMachineFormattedLogLine(w, level, format, a)
+}
+
+func (s MachineLogger) Println(level string, format string, a ...interface{}) {
+	printMachineFormattedLogLine(os.Stdout, level, format, a)
+}
+
+func (s MachineLogger) UnformattedFprintln(w io.Writer, str string) {
+	fprintln(w, str)
+}
+
+func (s MachineLogger) Name() string {
+	return "machine"
+}
+
+func printMachineFormattedLogLine(w io.Writer, level string, format string, a []interface{}) {
 	a = append([]interface{}(nil), a...)
 	for idx, value := range a {
 		typeof := reflect.Indirect(reflect.ValueOf(value)).Kind()
 		if typeof == reflect.String {
 			a[idx] = url.QueryEscape(value.(string))
 		}
 	}
-	fmt.Fprintf(w, "===%s ||| %s ||| %s", level, format, a)
-	fmt.Fprintln(w)
+	fprintf(w, "===%s ||| %s ||| %s\n", level, format, a)
 }
 
-func (s MachineLogger) Fprintln(w io.Writer, level string, format string, a ...interface{}) {
-	s.printWithoutFormatting(w, level, format, a)
-}
+var lock sync.Mutex
 
-func (s MachineLogger) Println(level string, format string, a ...interface{}) {
-	s.printWithoutFormatting(os.Stdout, level, format, a)
+func fprintln(w io.Writer, s string) {
+	lock.Lock()
+	defer lock.Unlock()
+	fmt.Fprintln(w, s)
 }
 
-func (s MachineLogger) Name() string {
-	return "machine"
+func fprintf(w io.Writer, format string, a ...interface{}) {
+	lock.Lock()
+	defer lock.Unlock()
+	fmt.Fprintf(w, format, a...)
 }
 
 func FromJavaToGoSyntax(s string) string {

src/arduino.cc/builder/types/accessories.go

@@ -29,6 +29,11 @@
 
 package types
 
+import (
+	"bytes"
+	"sync"
+)
+
 type UniqueStringQueue []string
 
 func (queue UniqueStringQueue) Len() int           { return len(queue) }
@@ -74,3 +79,29 @@ func (queue *UniqueSourceFolderQueue) Pop() interface{} {
 func (queue *UniqueSourceFolderQueue) Empty() bool {
 	return queue.Len() == 0
 }
+
+type BufferedUntilNewLineWriter struct {
+	PrintFunc PrintFunc
+	Buffer    bytes.Buffer
+	lock      sync.Mutex
+}
+
+type PrintFunc func(string)
+
+func (w *BufferedUntilNewLineWriter) Write(p []byte) (n int, err error) {
+	w.lock.Lock()
+	defer w.lock.Unlock()
+
+	writtenToBuffer, err := w.Buffer.Write(p)
+	if err != nil {
+		return writtenToBuffer, err
+	}
+
+	bytesUntilNewLine, err := w.Buffer.ReadBytes('\n')
+	if err != nil && len(bytesUntilNewLine) > 0 {
+		bytesUntilNewLine = bytesUntilNewLine[:len(bytesUntilNewLine)-1]
+		w.PrintFunc(string(bytesUntilNewLine))
+	}
+
+	return writtenToBuffer, err
+}