diff --git a/test/preflight/apps_v2_integration_test.go b/test/preflight/apps_v2_integration_test.go index 1294bc6734..41883f7a01 100644 --- a/test/preflight/apps_v2_integration_test.go +++ b/test/preflight/apps_v2_integration_test.go @@ -444,12 +444,14 @@ func testDeployDetach(t *testing.T) { f := testlib.NewTestEnvFromEnv(t) appName := f.CreateRandomAppName() - f.Fly("launch --org %s --name %s --region %s --now --internal-port 80 --image nginx --auto-confirm", f.OrgSlug(), appName, f.PrimaryRegion()) + // With auto-stop on, the proxy stops these idle machines and deploy + // leaves them stopped, so they would never reach "started". + f.Fly("launch --org %s --name %s --region %s --now --internal-port 80 --image nginx --auto-confirm --auto-stop off", f.OrgSlug(), appName, f.PrimaryRegion()) ml := f.MachinesList(appName) require.GreaterOrEqual(f, len(ml), 1) m := ml[0] - f.Fly("machine wait %s --state started --wait-timeout 15s", m.ID) + f.Fly("machine wait %s --state started --wait-timeout 60s", m.ID) res := f.Fly("deploy --detach") require.NotContains(f, res.StdOutString(), "started") @@ -457,7 +459,7 @@ func testDeployDetach(t *testing.T) { ml = f.MachinesList(appName) require.GreaterOrEqual(f, len(ml), 1) m = ml[0] - f.Fly("machine wait %s --state started --wait-timeout 15s", m.ID) + f.Fly("machine wait %s --state started --wait-timeout 60s", m.ID) res = f.Fly("deploy") require.Contains(f, res.StdOutString(), "started") @@ -467,13 +469,15 @@ func testDeployDetachBatching(t *testing.T) { f := testlib.NewTestEnvFromEnv(t) appName := f.CreateRandomAppName() - f.Fly("launch --org %s --name %s --region %s --now --internal-port 80 --image nginx --auto-confirm", f.OrgSlug(), appName, f.PrimaryRegion()) + // With auto-stop on, the proxy stops these idle machines and deploy + // leaves them stopped, so they would never reach "started". + f.Fly("launch --org %s --name %s --region %s --now --internal-port 80 --image nginx --auto-confirm --auto-stop off", f.OrgSlug(), appName, f.PrimaryRegion()) f.Fly("scale count 6 --yes") ml := f.MachinesList(appName) require.GreaterOrEqual(f, len(ml), 1) m := ml[0] - f.Fly("machine wait %s --state started --wait-timeout 15s", m.ID) + f.Fly("machine wait %s --state started --wait-timeout 60s", m.ID) res := f.Fly("deploy --detach") require.NotContains(f, res.StdOutString(), "started", false) @@ -481,7 +485,7 @@ func testDeployDetachBatching(t *testing.T) { ml = f.MachinesList(appName) require.GreaterOrEqual(f, len(ml), 1) m = ml[0] - f.Fly("machine wait %s --state started --wait-timeout 15s", m.ID) + f.Fly("machine wait %s --state started --wait-timeout 60s", m.ID) res = f.Fly("deploy") require.Contains(f, res.StdOutString(), "started", false) diff --git a/test/preflight/fly_deploy_test.go b/test/preflight/fly_deploy_test.go index dda5219ac7..f2e8e99d92 100644 --- a/test/preflight/fly_deploy_test.go +++ b/test/preflight/fly_deploy_test.go @@ -400,7 +400,9 @@ func TestFlyDeploy_DeployMachinesCheck(t *testing.T) { useShortLivedDeployToken(t, f) deployRes := f.Fly("deploy --buildkit --remote-only") output := deployRes.StdOutString() - require.Contains(f, output, "Test Machine") + // The "Test Machine : " summary is skipped once the test + // machine has been destroyed, so check for the success line instead. + require.Regexp(f, `Test machine \S+ completed successfully`, output) } func TestFlyDeploy_NoServiceDeployMachinesCheck(t *testing.T) { @@ -420,7 +422,9 @@ func TestFlyDeploy_NoServiceDeployMachinesCheck(t *testing.T) { useShortLivedDeployToken(t, f) deployRes := f.Fly("deploy --buildkit --remote-only") output := deployRes.StdOutString() - require.Contains(f, output, "Test Machine") + // The "Test Machine : " summary is skipped once the test + // machine has been destroyed, so check for the success line instead. + require.Regexp(f, `Test machine \S+ completed successfully`, output) } // TODO: This test times out after ~15 minutes in CI (hangs at deploy command) diff --git a/test/preflight/fly_launch_test.go b/test/preflight/fly_launch_test.go index 27d3e6a662..eeb41fa09c 100644 --- a/test/preflight/fly_launch_test.go +++ b/test/preflight/fly_launch_test.go @@ -308,12 +308,19 @@ func TestFlyLaunchWithBuildSecrets(t *testing.T) { RUN --mount=type=secret,id=secret1 cat /run/secrets/secret1 > /tmp/secrets.txt `) - f.Fly("launch --org %s --name %s --region %s --internal-port 80 --ha=false --now --build-secret secret1=SECRET1 --remote-only", f.OrgSlug(), appName, f.PrimaryRegion()) + f.Fly("launch --org %s --name %s --region %s --internal-port 80 --ha=false --now --build-secret secret1=SECRET1 --remote-only --auto-stop off", f.OrgSlug(), appName, f.PrimaryRegion()) + // The machine may not accept SSH connections right after launch, so a + // failed or hung attempt must be retried rather than failing the test. require.EventuallyWithT(t, func(c *assert.CollectT) { - ssh := f.Fly("ssh console -C 'cat /tmp/secrets.txt'") - assert.Equal(c, "SECRET1", ssh.StdOut().String()) - }, 10*time.Second, 1*time.Second) + // The first attempt may need to start the agent and open a WireGuard + // tunnel, so give each attempt room for that. + ssh := f.FlyBestEffort(time.Minute, "ssh console -C 'cat /tmp/secrets.txt'") + if !assert.Equal(c, 0, ssh.ExitCode(), "ssh console failed: %s", ssh.StdErrString()) { + return + } + assert.Equal(c, "SECRET1", ssh.StdOutString()) + }, 3*time.Minute, 2*time.Second) } func TestFlyLaunchBasicNodeApp(t *testing.T) { diff --git a/test/preflight/fly_wireguard_test.go b/test/preflight/fly_wireguard_test.go index 1936cc250b..1731d0e3e4 100644 --- a/test/preflight/fly_wireguard_test.go +++ b/test/preflight/fly_wireguard_test.go @@ -50,11 +50,18 @@ CMD ["sleep", "infinity"] // The backend is eventually consistent. The peer may not be immediately visible. assert.EventuallyWithT(t, func(t *assert.CollectT) { - result := f.Fly("machine exec -a %s %s 'dig +short aaaa @fdaa::3 %s._peer.internal'", appName, machineID, peerName) + // A failed or hung exec must be retried rather than failing the test. + result := f.FlyBestEffort(30*time.Second, "machine exec -a %s %s 'dig +short aaaa @fdaa::3 %s._peer.internal'", appName, machineID, peerName) + if !assert.Equal(t, 0, result.ExitCode(), "machine exec failed: %s", result.StdErrString()) { + return + } assert.Contains(t, result.StdOutString(), "fdaa:") - result = f.Fly("machine exec -a %s %s 'dig +noall +answer txt @fdaa::3 _peer.internal'", appName, machineID) + result = f.FlyBestEffort(30*time.Second, "machine exec -a %s %s 'dig +noall +answer txt @fdaa::3 _peer.internal'", appName, machineID) + if !assert.Equal(t, 0, result.ExitCode(), "machine exec failed: %s", result.StdErrString()) { + return + } assert.Contains(t, cleanupDigOutput(result.StdOutString()), peerName) - }, 10*time.Second, time.Second) + }, 2*time.Minute, 2*time.Second) }) } diff --git a/test/preflight/testlib/result.go b/test/preflight/testlib/result.go index 64e5fbb445..d7303890f2 100644 --- a/test/preflight/testlib/result.go +++ b/test/preflight/testlib/result.go @@ -20,6 +20,7 @@ type FlyctlResult struct { testIoStreams *iostreams.IOStreams stdIn, stdOut, stdErr *bytes.Buffer exitCode int + timedOut bool } func (r *FlyctlResult) CmdString() string { @@ -30,6 +31,11 @@ func (r *FlyctlResult) ExitCode() int { return r.exitCode } +// TimedOut reports whether the command was killed for exceeding its deadline. +func (r *FlyctlResult) TimedOut() bool { + return r.timedOut +} + func (r *FlyctlResult) StdOut() *bytes.Buffer { return r.stdOut } diff --git a/test/preflight/testlib/test_env.go b/test/preflight/testlib/test_env.go index a06e863139..31d43832fb 100644 --- a/test/preflight/testlib/test_env.go +++ b/test/preflight/testlib/test_env.go @@ -10,6 +10,7 @@ import ( "os/exec" "path/filepath" "strings" + "sync" "testing" "time" @@ -30,10 +31,13 @@ type FlyctlTestEnv struct { primaryRegion string otherRegions []string env map[string]string - cmdHistory []*FlyctlResult - noHistoryOnFail bool - id string - VMSize string + // historyMu guards cmdHistory, which retry goroutines that outlive an + // EventuallyWithT call can still append to. + historyMu sync.Mutex + cmdHistory []*FlyctlResult + noHistoryOnFail bool + id string + VMSize string } // Preflight flyctl commands are not supposed to take more than five minutes. @@ -213,8 +217,22 @@ func (f *FlyctlTestEnv) FlyAllowExitFailure(flyctlCmd string, vals ...interface{ return f.FlyContextAndConfig(ctx, FlyCmdConfig{NoAssertSuccessfulExit: true}, flyctlCmd, vals...) } +// FlyBestEffort runs flyctl command with the given timeout and returns the result. +// It does not fail the test because of the command's outcome: a non-zero exit +// is reported by ExitCode, and a command that exceeds the timeout is killed and +// reported by TimedOut. This makes it safe for retry loops and cleanup. +func (f *FlyctlTestEnv) FlyBestEffort(timeout time.Duration, flyctlCmd string, vals ...interface{}) *FlyctlResult { + ctx, cancel := context.WithTimeout(context.Background(), timeout) + defer cancel() + + return f.FlyContextAndConfig(ctx, FlyCmdConfig{NoAssertSuccessfulExit: true, NoAssertDeadline: true}, flyctlCmd, vals...) +} + type FlyCmdConfig struct { NoAssertSuccessfulExit bool + // NoAssertDeadline reports a command that exceeds its context deadline + // through TimedOut instead of failing the test. + NoAssertDeadline bool } func (f *FlyctlTestEnv) FlyContextAndConfig(ctx context.Context, cfg FlyCmdConfig, flyctlCmd string, vals ...interface{}) *FlyctlResult { @@ -253,16 +271,24 @@ func (f *FlyctlTestEnv) FlyContextAndConfig(ctx context.Context, cfg FlyCmdConfi } err = cmd.Wait() if err != nil && ctx.Err() != nil { - f.Fatalf("command exceeded its deadline: %s [context error]: %v [stdout]: %s [stderr]: %s", res.cmdStr, ctx.Err(), res.stdOut.String(), res.stdErr.String()) - } - if err == nil { + if !cfg.NoAssertDeadline { + f.Fatalf("command exceeded its deadline: %s [context error]: %v [stdout]: %s [stderr]: %s", res.cmdStr, ctx.Err(), res.stdOut.String(), res.stdErr.String()) + } + // Record the timeout in stderr rather than logging it: this may run in a + // retry goroutine that outlives the test, where t.Logf panics. + fmt.Fprintf(res.stdErr, "\ncommand exceeded its deadline: %v", ctx.Err()) + res.exitCode = -1 + res.timedOut = true + } else if err == nil { res.exitCode = 0 } else if exitErr, ok := err.(*exec.ExitError); ok { res.exitCode = exitErr.ExitCode() } else { f.Fatalf("unexpected error waiting on command: %s [error]: %v", res.cmdStr, err) } + f.historyMu.Lock() f.cmdHistory = append(f.cmdHistory, res) + f.historyMu.Unlock() if !cfg.NoAssertSuccessfulExit { res.AssertSuccessfulExit() } @@ -282,7 +308,10 @@ func (f *FlyctlTestEnv) DebugPrintHistory() { if f.Failed() || f.noHistoryOnFail { return } - for i, r := range f.cmdHistory { + f.historyMu.Lock() + history := append([]*FlyctlResult(nil), f.cmdHistory...) + f.historyMu.Unlock() + for i, r := range history { fmt.Printf("%3d:\n", i+1) r.DebugPrintOutput() } @@ -321,7 +350,12 @@ func (f *FlyctlTestEnv) CreateRandomAppName() string { appName := randomName(f, prefix) f.Cleanup(func() { - f.FlyAllowExitFailure("apps destroy --yes %s", appName) + // A slow destroy shouldn't fail a test that already passed, or hold up + // the suite. Apps left behind are removed by the preflight cleanup workflow. + res := f.FlyBestEffort(time.Minute, "apps destroy --yes %s", appName) + if res.ExitCode() != 0 { + f.Logf("apps destroy %s failed (timed out: %t); leaving it for the preflight cleanup workflow: %s", appName, res.TimedOut(), res.StdErrString()) + } }) return appName }