Trying to isolate a race condition in tests

.gitlab-ci.yml

@@ -10,7 +10,7 @@ test:
       - main
       - merge_requests
   script:
-    - go test ./...
+    - go test -race ./...
 
 push:
   stage: push

cmd/mothd/httpd_test.go

@@ -4,10 +4,12 @@ import (
 	"bytes"
 	"encoding/json"
 	"fmt"
+	"io/ioutil"
+	"log"
 	"net/http/httptest"
 	"net/url"
+	"strings"
 	"testing"
-	"time"
 
 	"github.com/spf13/afero"
 )
@@ -33,7 +35,8 @@ func (hs *HTTPServer) TestRequest(path string, args map[string]string) *httptest
 }
 
 func TestHttpd(t *testing.T) {
-	hs := NewHTTPServer("/", NewTestServer())
+	server := NewTestServer()
+	hs := NewHTTPServer("/", server)
 
 	if r := hs.TestRequest("/", nil); r.Result().StatusCode != 200 {
 		t.Error(r.Result())
@@ -106,11 +109,26 @@ func TestHttpd(t *testing.T) {
 
 	if r := hs.TestRequest("/answer", map[string]string{"cat": "pategory", "points": "1", "answer": "answer123"}); r.Result().StatusCode != 200 {
 		t.Error(r.Result())
+	} else if strings.Contains(r.Body.String(), "incorrect answer") {
+		// Pernicious intermittent bug
+		t.Error("Incorrect answer that was actually correct")
+		for _, provider := range server.PuzzleProviders {
+			if mb, ok := provider.(*Mothballs); !ok {
+				t.Error("Provider is not a mothball")
+			} else {
+				cat, _ := mb.getCat("pategory")
+				f, _ := cat.Open("answers.txt")
+				defer f.Close()
+				answersBytes, _ := ioutil.ReadAll(f)
+				t.Errorf("Correct answers: %v", string(answersBytes))
+			}
+		}
+		t.Error("Wrong answer")
 	} else if r.Body.String() != `{"status":"success","data":{"short":"accepted","description":"1 points awarded in pategory"}}` {
 		t.Error("Unexpected body", r.Body.String())
 	}
 
-	time.Sleep(TestMaintenanceInterval)
+	server.State.refresh()
 
 	if r := hs.TestRequest("/content/pategory/2/puzzle.json", nil); r.Result().StatusCode != 200 {
 		t.Error(r.Result())
@@ -122,13 +140,37 @@ func TestHttpd(t *testing.T) {
 	} else if err := json.Unmarshal(r.Body.Bytes(), &state); err != nil {
 		t.Error(err)
 	} else if len(state.PointsLog) != 1 {
-		t.Error("Points log wrong length")
+		switch v := server.State.(type) {
+		case *State:
+			log.Print(v)
+		}
+
+		t.Errorf("Points log wrong length. Wanted 1, got %v", state.PointsLog)
 	} else if len(state.Puzzles["pategory"]) != 2 {
 		t.Error("Didn't unlock next puzzle")
 	}
 
 	if r := hs.TestRequest("/answer", map[string]string{"cat": "pategory", "points": "1", "answer": "answer123"}); r.Result().StatusCode != 200 {
 		t.Error(r.Result())
+	} else if strings.Contains(r.Body.String(), "incorrect answer") {
+		// Pernicious intermittent bug
+		t.Error("Incorrect answer that was actually correct")
+		for _, provider := range server.PuzzleProviders {
+			if mb, ok := provider.(*Mothballs); !ok {
+				t.Error("Provider is not a mothball")
+			} else {
+				if cat, ok := mb.getCat("pategory"); !ok {
+					t.Error("opening pategory failed")
+				} else if f, err := cat.Open("answers.txt"); err != nil {
+					t.Error("opening answers.txt", err)
+				} else {
+					defer f.Close()
+					answersBytes, _ := ioutil.ReadAll(f)
+					t.Errorf("Correct answers: %#v len %d", string(answersBytes), len(answersBytes))
+				}
+			}
+		}
+		t.Error("Wrong answer")
 	} else if r.Body.String() != `{"status":"fail","data":{"short":"not accepted","description":"error awarding points: points already awarded to this team in this category"}}` {
 		t.Error("Unexpected body", r.Body.String())
 	}

cmd/mothd/mothballs.go

@@ -92,23 +92,30 @@ func (m *Mothballs) Inventory() []Category {
 func (m *Mothballs) CheckAnswer(cat string, points int, answer string) (bool, error) {
 	zfs, ok := m.getCat(cat)
 	if !ok {
+		log.Println("There's no such category")
 		return false, fmt.Errorf("no such category: %s", cat)
 	}
 
+	log.Println("Opening answers.txt")
 	af, err := zfs.Open("answers.txt")
 	if err != nil {
+		log.Println("I did not find an answer")
 		return false, fmt.Errorf("no answers.txt file")
 	}
 	defer af.Close()
 
+	log.Println("I'm going to start looking for an answer")
 	needle := fmt.Sprintf("%d %s", points, answer)
 	scanner := bufio.NewScanner(af)
 	for scanner.Scan() {
+		log.Println("testing equality between", scanner.Text(), needle)
 		if scanner.Text() == needle {
 			return true, nil
 		}
 	}
 
+	log.Println("I did not find the answer", answer)
+
 	return false, nil
 }
 

cmd/mothd/server.go

@@ -68,6 +68,9 @@ type Maintainer interface {
 	// It will only be called once, when execution begins.
 	// It's okay to just exit if there's no maintenance to be done.
 	Maintain(updateInterval time.Duration)
+
+	// refresh is a shortcut used internally for testing
+	refresh()
 }
 
 // MothServer gathers together the providers that make up a MOTH server.

cmd/mothd/server_test.go

@@ -11,6 +11,9 @@ import (
 const TestMaintenanceInterval = time.Millisecond * 1
 const TestTeamID = "teamID"
 
+// NewTestServer creates a new MothServer with NewTestMothballs and some initial state.
+//
+// See function definition for details.
 func NewTestServer() *MothServer {
 	puzzles := NewTestMothballs()
 	go puzzles.Maintain(TestMaintenanceInterval)

cmd/mothd/theme.go

@@ -38,3 +38,7 @@ func (t *Theme) Open(name string) (ReadSeekCloser, time.Time, error) {
 func (t *Theme) Maintain(i time.Duration) {
 	// No periodic tasks for a theme
 }
+
+func (t *Theme) refresh() {
+	// Nothing to do for a theme
+}

cmd/mothd/transpiler.go

@@ -79,3 +79,7 @@ func (p TranspilerProvider) Mothball(cat string, w io.Writer) error {
 func (p TranspilerProvider) Maintain(updateInterval time.Duration) {
 	// Nothing to do here.
 }
+
+func (p TranspilerProvider) refresh() {
+	// Nothing to do for a theme
+}