all: fix data race in tests and [httpServer.ExecuteTail]

In the test for AwwanLocal, use buffer with lock, so each write and
read is safe.

In the httpServer, the test found data race during ExecuteTail when
accessing [ExecResponse.EndAt].
We fix it by locking the resource during call to end() and when
accessing the EndAt field.

5 files changed, 95 insertions, 43 deletions

diff --git a/Makefile b/Makefile
index 3e95bd5..c5f2a79 100644
--- a/Makefile
+++ b/Makefile
@@ -1,6 +1,8 @@
-## SPDX-FileCopyrightText: 2019 M. Shulhan <ms@kilabit.info>
 ## SPDX-License-Identifier: GPL-3.0-or-later
+## SPDX-FileCopyrightText: 2019 M. Shulhan <ms@kilabit.info>
 
+COVER_HTML=cover.html
+COVER_OUT=cover.txt
 LD_FLAGS=-s -w
 VERSION=$(shell git describe --long | sed 's/\([^-]*-g\)/r\1/;s/-/./g')
 
@@ -8,10 +10,10 @@ VERSION=$(shell git describe --long | sed 's/\([^-]*-g\)/r\1/;s/-/./g')
 all: test lint
 
 .PHONY: test
+test: CGO_ENABLED=1
 test:
-	go test -cover ./... -test.gocoverdir=_coverage
-	go tool covdata textfmt -i=_coverage -o cover.txt
-	go tool cover -html=cover.txt -o cover.html
+	go test -failfast -timeout=2m -race -coverprofile=$(COVER_OUT) ./...
+	go tool cover -html=$(COVER_OUT) -o $(COVER_HTML)
 
 .PHONY: lint
 lint:
@@ -74,15 +76,17 @@ test-integration:
 		/bin/sh -c "cd src; ./awwan.test"
 
 .PHONY: test-all
+test-all: CGO_ENABLED=1
 test-all:
 	rm -f _coverage/*
-	go test -cover ./... -test.gocoverdir=_coverage
+	go test -failfast -timeout=2m -race -coverprofile=$(COVER_OUT) ./...
 	machinectl shell awwan@awwan-test \
 		/bin/sh -c "cd src; \
-		go test -cover -tags=integration ./... -test.gocoverdir=_coverage"
-	go tool covdata textfmt -i=_coverage -o cover.txt
-	go tool cover -html=cover.txt -o cover.html
-	go tool covdata percent -i=_coverage
+		go test -failfast -timeout=2m -race \
+			-coverprofile=$(COVER_OUT) \
+			-tags=integration \
+			./...
+	go tool cover -html=$(COVER_OUT) -o $(COVER_HTML)
 
 #}}}
 #{{{ Tasks to test or deploy awwan.org website.
diff --git a/awwan_local_test.go b/awwan_local_test.go
index 2dd590a..f4b4113 100644
--- a/awwan_local_test.go
+++ b/awwan_local_test.go
@@ -11,13 +11,40 @@ import (
 	"io/fs"
 	"os"
 	"path/filepath"
+	"sync"
 	"testing"
 	"time"
 
+	"git.sr.ht/~shulhan/pakakeh.go/lib/mlog"
 	"git.sr.ht/~shulhan/pakakeh.go/lib/test"
 	"git.sr.ht/~shulhan/pakakeh.go/lib/test/mock"
 )
 
+type lockBuffer struct {
+	b bytes.Buffer
+	sync.Mutex
+}
+
+func (lb *lockBuffer) Reset() {
+	lb.Lock()
+	lb.b.Reset()
+	lb.Unlock()
+}
+
+func (lb *lockBuffer) String() (s string) {
+	lb.Lock()
+	s = lb.b.String()
+	lb.Unlock()
+	return s
+}
+
+func (lb *lockBuffer) Write(p []byte) (n int, err error) {
+	lb.Lock()
+	n, err = lb.b.Write(p)
+	lb.Unlock()
+	return n, err
+}
+
 func TestAwwanLocal(t *testing.T) {
 	type testCase struct {
 		scriptFile string
@@ -70,10 +97,10 @@ func TestAwwanLocal(t *testing.T) {
 	var (
 		ctx = context.Background()
 
-		req  *ExecRequest
-		logw bytes.Buffer
-		c    testCase
+		req *ExecRequest
+		c   testCase
 	)
+	var logw lockBuffer
 	for _, c = range cases {
 		req, err = NewExecRequest(CommandModeLocal, c.scriptFile, c.lineRange)
 		if err != nil {
@@ -126,16 +153,11 @@ func TestAwwanLocalCancel(t *testing.T) {
 		t.Fatal(err)
 	}
 
-	var logw bytes.Buffer
+	var logw lockBuffer
 
 	execReq.registerLogWriter(`output`, &logw)
 
-	var (
-		ctx         = context.Background()
-		ctxDoCancel context.CancelFunc
-	)
-
-	ctx, ctxDoCancel = context.WithCancel(ctx)
+	var ctx = context.Background()
 
 	go func() {
 		var err2 = aww.Local(ctx, execReq)
@@ -145,8 +167,6 @@ func TestAwwanLocalCancel(t *testing.T) {
 	// Wait for actual exec.CommandContext to run ...
 	time.Sleep(500 * time.Millisecond)
 
-	ctxDoCancel()
-
 	test.Assert(t, `stdout`, string(tdata.Output[`cancel`]), logw.String())
 }
 
@@ -392,7 +412,8 @@ func TestAwwanLocal_withEncryption(t *testing.T) {
 		lineRange string
 		pass      string
 		expError  string
-		expOutput string
+		expStderr string
+		expStdout string
 	}
 
 	var (
@@ -423,36 +444,42 @@ func TestAwwanLocal_withEncryption(t *testing.T) {
 		script:    filepath.Join(basedir, `local_encrypted.aww`),
 		lineRange: `3`,
 		pass:      "s3cret\r",
-		expOutput: string(tdata.Output[`echo_encrypted`]),
+		expStderr: string(tdata.Output[`echo_encrypted:stderr`]),
+		expStdout: string(tdata.Output[`echo_encrypted:stdout`]),
 	}, {
 		desc:      `With encrypted value, no passphrase`,
 		script:    filepath.Join(basedir, `local_encrypted.aww`),
 		lineRange: `3`,
-		expError:  string(tdata.Output[`echo_encrypted_no_pass`]),
-		expOutput: string(tdata.Output[`echo_encrypted_no_pass:output`]),
+		expError:  string(tdata.Output[`echo_encrypted_no_pass:error`]),
+		expStderr: string(tdata.Output[`echo_encrypted_no_pass:stderr`]),
+		expStdout: string(tdata.Output[`echo_encrypted_no_pass:stdout`]),
 	}, {
 		desc:      `With encrypted value, invalid passphrase`,
 		script:    filepath.Join(basedir, `local_encrypted.aww`),
 		lineRange: `3`,
 		pass:      "invalid\r",
-		expError:  string(tdata.Output[`echo_encrypted_invalid_pass`]),
-		expOutput: string(tdata.Output[`echo_encrypted_invalid_pass:output`]),
+		expError:  string(tdata.Output[`echo_encrypted_invalid_pass:error`]),
+		expStderr: string(tdata.Output[`echo_encrypted_invalid_pass:stderr`]),
+		expStdout: string(tdata.Output[`echo_encrypted_invalid_pass:stdout`]),
 	}, {
 		desc:      `With encrypted value in sub`,
 		script:    filepath.Join(basedir, `sub`, `local_encrypted.aww`),
 		lineRange: `1`,
 		pass:      "s3cret\r",
-		expOutput: string(tdata.Output[`sub_echo_encrypted`]),
+		expStderr: string(tdata.Output[`sub_echo_encrypted:stderr`]),
+		expStdout: string(tdata.Output[`sub_echo_encrypted:stdout`]),
 	}}
 
 	var (
 		ctx = context.Background()
 
-		c    testCase
-		logw bytes.Buffer
-		req  *ExecRequest
+		c   testCase
+		req *ExecRequest
 	)
-
+	var testerr bytes.Buffer
+	var namederr = mlog.NewNamedWriter(`testerr`, &testerr)
+	var testout bytes.Buffer
+	var namedout = mlog.NewNamedWriter(`testout`, &testout)
 	for _, c = range cases {
 		t.Log(c.desc)
 
@@ -461,8 +488,10 @@ func TestAwwanLocal_withEncryption(t *testing.T) {
 			t.Fatal(err)
 		}
 
-		logw.Reset()
-		req.registerLogWriter(`output`, &logw)
+		testerr.Reset()
+		testout.Reset()
+		req.mlog.RegisterErrorWriter(namederr)
+		req.mlog.RegisterOutputWriter(namedout)
 
 		// Mock terminal to read passphrase for private key.
 		mockrw.BufRead.Reset()
@@ -474,6 +503,7 @@ func TestAwwanLocal_withEncryption(t *testing.T) {
 			test.Assert(t, `Local error`, c.expError, err.Error())
 		}
 
-		test.Assert(t, `output`, c.expOutput, logw.String())
+		test.Assert(t, c.desc+`: stderr`, c.expStderr, testerr.String())
+		test.Assert(t, c.desc+`: stdout`, c.expStdout, testout.String())
 	}
 }
diff --git a/exec_response.go b/exec_response.go
index a5cb1ff..92774cf 100644
--- a/exec_response.go
+++ b/exec_response.go
@@ -89,6 +89,9 @@ func (execRes *ExecResponse) Write(out []byte) (n int, err error) {
 
 // end mark the execution completed, possibly with error.
 func (execRes *ExecResponse) end(execErr error) {
+	execRes.mtxOutput.Lock()
+	defer execRes.mtxOutput.Unlock()
+
 	var ev sseclient.Event
 
 	if execErr != nil {
diff --git a/http_server.go b/http_server.go
index 2a7f534..f2a35b4 100644
--- a/http_server.go
+++ b/http_server.go
@@ -853,11 +853,14 @@ func (httpd *httpServer) ExecuteTail(sseconn *libhttp.SSEConn) {
 		evid int64
 	)
 
+	execRes.mtxOutput.Lock()
 	if len(execRes.EndAt) != 0 {
 		// The execution has been completed.
 		_ = sseconn.WriteEvent(`end`, execRes.EndAt, nil)
+		execRes.mtxOutput.Unlock()
 		goto out
 	}
+	execRes.mtxOutput.Unlock()
 
 	// And wait for the rest...
 
diff --git a/testdata/local/local_encrypted.data b/testdata/local/local_encrypted.data
index 3d523a0..045e884 100644
--- a/testdata/local/local_encrypted.data
+++ b/testdata/local/local_encrypted.data
@@ -1,23 +1,35 @@
-<<< echo_encrypted
+<<< echo_encrypted:stdout
 ----/--/-- --:--:-- === BEGIN: local testdata/local/local_encrypted.aww 3
 ----/--/-- --:--:-- -->   3: echo this_is_a_secret
-this_is_a_secret
 ----/--/-- --:--:-- === END: local testdata/local/local_encrypted.aww 3
 
-<<< echo_encrypted_no_pass
+<<< echo_encrypted:stderr
+this_is_a_secret
+
+
+<<< echo_encrypted_no_pass:error
 Local: NewScript: ParseScript: template: local_encrypted.aww:3:7: executing "local_encrypted.aww" at <.Val>: error calling Val: "secret::pass" is empty
 
-<<< echo_encrypted_no_pass:output
+<<< echo_encrypted_no_pass:stderr
 ----/--/-- --:--:-- !!! NewScript: ParseScript: template: local_encrypted.aww:3:7: executing "local_encrypted.aww" at <.Val>: error calling Val: "secret::pass" is empty
 
-<<< echo_encrypted_invalid_pass
+<<< echo_encrypted_no_pass:stdout
+
+<<< echo_encrypted_invalid_pass:error
 Local: NewSession: .awwan.env.vault: LoadPrivateKeyInteractive: x509: decryption password incorrect
 
-<<< echo_encrypted_invalid_pass:output
+<<< echo_encrypted_invalid_pass:stderr
 ----/--/-- --:--:-- !!! NewSession: .awwan.env.vault: LoadPrivateKeyInteractive: x509: decryption password incorrect
 
-<<< sub_echo_encrypted
+<<< echo_encrypted_invalid_pass:stdout
+
+<<< sub_echo_encrypted:error
+
+<<< sub_echo_encrypted:stderr
+this_is_a_secret_in_sub
+
+
+<<< sub_echo_encrypted:stdout
 ----/--/-- --:--:-- === BEGIN: local testdata/local/sub/local_encrypted.aww 1
 ----/--/-- --:--:-- -->   1: echo this_is_a_secret_in_sub
-this_is_a_secret_in_sub
 ----/--/-- --:--:-- === END: local testdata/local/sub/local_encrypted.aww 1