pam: Fix races handling in VHS tests and fix bubbletea models implementations (#846)

See commits for details, but basically lots of cleanups to ensure that
the races are properly monitored and that the artifacts saved in CI,
then I decided to tackle the root cause of
charmbracelet/bubbletea#909 that was mostly
due to the fact that we were, in various cases, updating the models with
pointer receivers, instead of relying on the returned and modified
value.

Coming with various cleanups.

UDENG-6474

Author: 3v1n0

.github/workflows/qa.yaml

@@ -254,6 +254,7 @@ jobs:
         if: matrix.test == 'race'
         env:
           GO_TESTS_TIMEOUT: 35m
+          AUTHD_TESTS_SLEEP_MULTIPLIER: 3
         run: |
           go test -json -timeout ${GO_TESTS_TIMEOUT} -race ./... | \
             gotestfmt --logfile "${AUTHD_TEST_ARTIFACTS_PATH}/gotestfmt.race.log"
@@ -266,6 +267,7 @@ jobs:
           CGO_CFLAGS: "-O0 -g3 -fno-omit-frame-pointer"
           G_DEBUG: "fatal-criticals"
           GO_TESTS_TIMEOUT: 30m
+          AUTHD_TESTS_SLEEP_MULTIPLIER: 1.5
           # Use these flags to give ASAN a better time to unwind the stack trace
           GO_GC_FLAGS: -N -l
         run: |

examplebroker/broker.go

@@ -843,6 +843,9 @@ func (b *Broker) UserPreCheck(ctx context.Context, username string) (string, err
 		strings.Contains(username, fmt.Sprintf("-%s-", UserIntegrationPreCheckValue)) {
 		return userInfoFromName(username), nil
 	}
+
+	exampleUsersMu.Lock()
+	defer exampleUsersMu.Unlock()
 	if _, exists := exampleUsers[username]; !exists {
 		return "", fmt.Errorf("user %q does not exist", username)
 	}

internal/testutils/args.go

@@ -79,6 +79,7 @@ func SleepMultiplier() float64 {
 			if sleepMultiplier <= 0 {
 				panic("Negative or 0 sleep multiplier is not supported")
 			}
+			return
 		}
 
 		if IsAsan() {

internal/testutils/daemon.go

@@ -3,6 +3,7 @@ package testutils
 import (
 	"bytes"
 	"context"
+	"errors"
 	"fmt"
 	"os"
 	"os/exec"
@@ -24,6 +25,8 @@ type daemonOptions struct {
 	existentDB string
 	socketPath string
 	pidFile    string
+	outputFile string
+	shared     bool
 	env        []string
 }
 
@@ -66,6 +69,20 @@ func WithPidFile(pidFile string) DaemonOption {
 	}
 }
 
+// WithOutputFile sets the path where the process log will be saved.
+func WithOutputFile(outputFile string) DaemonOption {
+	return func(o *daemonOptions) {
+		o.outputFile = outputFile
+	}
+}
+
+// WithSharedDaemon sets whether the daemon is shared between tests.
+func WithSharedDaemon(shared bool) DaemonOption {
+	return func(o *daemonOptions) {
+		o.shared = shared
+	}
+}
+
 // RunDaemon runs the daemon in a separate process and returns the socket path and a channel that will be closed when
 // the daemon stops.
 func RunDaemon(ctx context.Context, t *testing.T, execPath string, args ...DaemonOption) (socketPath string, stopped chan struct{}) {
@@ -134,16 +151,42 @@ paths:
 		if opts.pidFile != "" {
 			processPid <- cmd.Process.Pid
 		}
+
+		// When using a shared daemon we should not use the test parameter from now on
+		// since the test is referring to may not be the one actually running.
+		t := t
+		logger := t.Logf
+		errorIs := func(err, target error, format string, args ...any) {
+			require.ErrorIs(t, err, target, fmt.Sprintf(format, args...))
+		}
+		if opts.shared {
+			// Unset the testing value, since it's wrong to use it from!
+			t = nil
+			logger = func(format string, args ...any) { fmt.Fprintf(os.Stderr, format+"\n", args...) }
+			errorIs = func(err, target error, format string, args ...any) {
+				if errors.Is(err, target) {
+					return
+				}
+				panic(fmt.Sprintf("Error %v is not matching %v: %s", err, target, fmt.Sprintf(format, args...)))
+			}
+		}
+
 		err = cmd.Wait()
 		out := b.Bytes()
-		require.ErrorIs(t, err, context.Canceled, "Setup: daemon stopped unexpectedly: %s", out)
+		if opts.outputFile != "" {
+			logger("writing authd log files to %v", opts.outputFile)
+			if err := os.WriteFile(opts.outputFile, out, 0600); err != nil {
+				logger("TearDown: failed to save output file %q: %v", opts.outputFile, err)
+			}
+		}
+		errorIs(err, context.Canceled, "Setup: daemon stopped unexpectedly: %s", out)
 		if opts.pidFile != "" {
 			defer cancel(nil)
 			if err := os.Remove(opts.pidFile); err != nil {
-				t.Logf("TearDown: failed to remove pid file %q: %v", opts.pidFile, err)
+				logger("TearDown: failed to remove pid file %q: %v", opts.pidFile, err)
 			}
 		}
-		t.Logf("Daemon stopped (%v)\n ##### Output #####\n %s \n ##### END #####", err, out)
+		logger("Daemon stopped (%v)\n ##### Output #####\n %s \n ##### END #####", err, out)
 	}()
 
 	conn, err := grpc.NewClient("unix://"+opts.socketPath, grpc.WithTransportCredentials(insecure.NewCredentials()), grpc.WithUnaryInterceptor(errmessages.FormatErrorMessage))

pam/integration-tests/helpers_test.go

@@ -52,12 +52,18 @@ func runAuthdForTesting(t *testing.T, gpasswdOutput, groupsFile string, currentU
 	t.Helper()
 
 	ctx, cancel := context.WithCancel(context.Background())
+
 	env := localgroupstestutils.AuthdIntegrationTestsEnvWithGpasswdMock(t, gpasswdOutput, groupsFile)
 	if currentUserAsRoot {
 		env = append(env, authdCurrentUserRootEnvVariableContent)
 	}
 	args = append(args, testutils.WithEnvironment(env...))
+
+	outputFile := filepath.Join(t.TempDir(), "authd.log")
+	args = append(args, testutils.WithOutputFile(outputFile))
+
 	socketPath, stopped := testutils.RunDaemon(ctx, t, daemonPath, args...)
+	saveArtifactsForDebugOnCleanup(t, []string{outputFile})
 	return socketPath, func() {
 		cancel()
 		<-stopped
@@ -121,7 +127,8 @@ func sharedAuthd(t *testing.T) (socketPath string, gpasswdFile string) {
 
 	sa.gPasswdOutputPath = filepath.Join(t.TempDir(), "gpasswd.output")
 	sa.groupsFile = filepath.Join(testutils.TestFamilyPath(t), "gpasswd.group")
-	sa.socketPath, sa.cleanup = runAuthdForTesting(t, sa.gPasswdOutputPath, sa.groupsFile, true)
+	sa.socketPath, sa.cleanup = runAuthdForTesting(t, sa.gPasswdOutputPath,
+		sa.groupsFile, true, testutils.WithSharedDaemon(true))
 	return sa.socketPath, sa.gPasswdOutputPath
 }
 

pam/integration-tests/vhs-helpers_test.go

@@ -1,7 +1,6 @@
 package main_test
 
 import (
-	"errors"
 	"fmt"
 	"maps"
 	"math"
@@ -260,14 +259,13 @@ func (td tapeData) RunVhs(t *testing.T, testType vhsTestType, outDir string, cli
 	var raceLog string
 	if testutils.IsRace() {
 		raceLog = filepath.Join(t.TempDir(), "gorace.log")
-		cmd.Env = append(cmd.Env, fmt.Sprintf("GORACE=log_path=%s", raceLog))
-		saveArtifactsForDebugOnCleanup(t, []string{raceLog})
+		cmd.Env = append(cmd.Env, fmt.Sprintf("GORACE=log_path=%s exitcode=0", raceLog))
 	}
 
 	cmd.Args = append(cmd.Args, td.PrepareTape(t, testType, outDir))
 	out, err := cmd.CombinedOutput()
-	if err != nil {
-		checkDataRace(t, raceLog)
+	if raceLog != "" {
+		checkDataRaces(t, raceLog)
 	}
 
 	isSSHError := func(processOut []byte) bool {
@@ -324,35 +322,45 @@ func (td tapeData) Output() string {
 	return txt
 }
 
-func checkDataRace(t *testing.T, raceLog string) {
+func checkDataRaces(t *testing.T, raceLog string) {
 	t.Helper()
 
-	if !testutils.IsRace() || raceLog == "" {
+	if !testutils.IsRace() {
 		return
 	}
 
-	content, err := os.ReadFile(raceLog)
-	if err == nil || errors.Is(err, os.ErrNotExist) {
-		return
+	var raceLogs []string
+	err := filepath.Walk(filepath.Dir(raceLog),
+		func(path string, info os.FileInfo, err error) error {
+			if err != nil {
+				return err
+			}
+			if !strings.HasPrefix(info.Name(), filepath.Base(raceLog)) {
+				return nil
+			}
+			t.Logf("Found data race %s", info.Name())
+			raceLogs = append(raceLogs, filepath.Join(filepath.Dir(raceLog), info.Name()))
+			return nil
+		})
+
+	require.NoError(t, err, "TearDown: Check for races")
+	saveArtifactsForDebugOnCleanup(t, raceLogs)
+	for _, raceLog := range raceLogs {
+		checkDataRace(t, raceLog)
 	}
+}
+
+func checkDataRace(t *testing.T, raceLog string) {
+	t.Helper()
+
+	content, err := os.ReadFile(raceLog)
 	require.NoError(t, err, "TearDown: Error reading race log %q", raceLog)
 
 	out := string(content)
 	if strings.TrimSpace(out) == "" {
 		return
 	}
 
-	if strings.Contains(out, "bubbles/cursor.(*Model).BlinkCmd.func1") {
-		// FIXME: This is a well known race of bubble tea:
-		// https://github.com/charmbracelet/bubbletea/issues/909
-		// We can't do much here, as the workaround will likely affect the
-		// GUI behavior, but we ignore this since it's definitely not our bug.
-
-		// TODO: In case other races are detected, we should still fail here.
-		t.Skipf("This is a very well known bubble tea bug (#909), ignoring it:\n%s", out)
-		return
-	}
-
 	t.Fatalf("Got a GO Race on vhs child:\n%s", out)
 }