diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index 4e7538b0d1a..c6d2fdf6d56 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -53,8 +53,16 @@ jobs: - 2.38.2 # first version that supports the rebase.updateRefs config - 2.44.0 - latest # We rely on github to have the latest version installed on their VMs + race: + - false + # Additionally run the whole suite once under the race detector. Data + # races live in lazygit's own Go code rather than in git, so a single + # git version is enough; use the latest to skip the git-build steps. + include: + - git-version: latest + race: true runs-on: ubuntu-latest - name: "Integration Tests - git ${{matrix.git-version}}" + name: "Integration Tests - git ${{matrix.git-version}}${{ matrix.race && ' (race)' || '' }}" env: GOFLAGS: -mod=vendor steps: @@ -92,12 +100,23 @@ jobs: run: git --version - name: Test code env: - # See https://go.dev/blog/integration-test-coverage - LAZYGIT_GOCOVERDIR: /tmp/code_coverage + # See https://go.dev/blog/integration-test-coverage. The race variant + # skips coverage: it's redundant with the non-race latest job and + # would only slow the -race build down further. Leaving the dir unset + # makes run_integration_tests.sh take its non-coverage path. + LAZYGIT_GOCOVERDIR: ${{ !matrix.race && '/tmp/code_coverage' || '' }} + # Only set for the race variant. The race detector needs cgo; it's on + # by default on the Linux runner, but we set it explicitly to be safe. + LAZYGIT_RACE_DETECTOR: ${{ matrix.race && '1' || '' }} + CGO_ENABLED: ${{ matrix.race && '1' || '' }} + # Append each test's duration to this file; run_integration_tests.sh + # prints the slowest at the end, to spot slow/anomalous tests. + LAZYGIT_TEST_TIMING: /tmp/test_timings.txt run: | mkdir -p /tmp/code_coverage ./scripts/run_integration_tests.sh - name: Upload code coverage artifacts + if: ${{ !matrix.race }} uses: actions/upload-artifact@v7 with: name: coverage-integration-${{ matrix.git-version }}-${{ github.run_id }} diff --git a/pkg/gui/test_mode.go b/pkg/gui/test_mode.go index c367e056a51..2b2c35647cb 100644 --- a/pkg/gui/test_mode.go +++ b/pkg/gui/test_mode.go @@ -3,6 +3,7 @@ package gui import ( "log" "os" + "runtime/pprof" "time" "github.com/jesseduffield/lazygit/pkg/gocui" @@ -63,9 +64,14 @@ func (gui *Gui) handleTestMode() { }() if os.Getenv(components.WAIT_FOR_DEBUGGER_ENV_VAR) == "" { + timeout := 40 * time.Second * testTimeoutMultiplier go utils.Safe(func() { - time.Sleep(time.Second * 40) - log.Fatal("40 seconds is up, lazygit recording took too long to complete") + time.Sleep(timeout) + // Dump all goroutine stacks before dying, so a hung test shows + // where it got stuck rather than just that it timed out. The + // test harness surfaces this process's stderr on failure. + _ = pprof.Lookup("goroutine").WriteTo(os.Stderr, 2) + log.Fatalf("%v is up, lazygit integration test took too long to complete", timeout) }) } } diff --git a/pkg/gui/test_timeout_norace.go b/pkg/gui/test_timeout_norace.go new file mode 100644 index 00000000000..7f924ea71a7 --- /dev/null +++ b/pkg/gui/test_timeout_norace.go @@ -0,0 +1,5 @@ +//go:build !race + +package gui + +const testTimeoutMultiplier = 1 diff --git a/pkg/gui/test_timeout_race.go b/pkg/gui/test_timeout_race.go new file mode 100644 index 00000000000..7d633def3c6 --- /dev/null +++ b/pkg/gui/test_timeout_race.go @@ -0,0 +1,10 @@ +//go:build race + +package gui + +// The race detector makes everything run several times slower, so the +// recording watchdog needs a correspondingly longer timeout; otherwise it +// fires on tests that are merely slow under -race rather than actually stuck. +// The `race` build tag is set automatically when the binary is built with +// -race, so this can't drift out of sync with the actual build. +const testTimeoutMultiplier = 4 diff --git a/pkg/integration/clients/go_test.go b/pkg/integration/clients/go_test.go index 11f6e754ef2..4c1faa5570a 100644 --- a/pkg/integration/clients/go_test.go +++ b/pkg/integration/clients/go_test.go @@ -11,7 +11,9 @@ import ( "io" "os" "os/exec" + "syscall" "testing" + "time" "github.com/creack/pty" "github.com/jesseduffield/lazycore/pkg/utils" @@ -28,6 +30,7 @@ func TestIntegration(t *testing.T) { parallelTotal := tryConvert(os.Getenv("PARALLEL_TOTAL"), 1) parallelIndex := tryConvert(os.Getenv("PARALLEL_INDEX"), 0) raceDetector := os.Getenv("LAZYGIT_RACE_DETECTOR") != "" + logTimingsPath := os.Getenv("LAZYGIT_TEST_TIMING") // LAZYGIT_GOCOVERDIR is the directory where we write coverage files to. If this directory // is defined, go binaries built with the -cover flag will write coverage files to // to it. @@ -56,7 +59,8 @@ func TestIntegration(t *testing.T) { CodeCoverageDir: codeCoverageDir, InputDelay: 0, // Allow two attempts at each test to get around flakiness - MaxAttempts: 1, + MaxAttempts: 1, + LogTimingsPath: logTimingsPath, }) assert.NoError(t, err) @@ -75,6 +79,17 @@ func runCmdHeadless(cmd *exec.Cmd) (int, error) { stderr := new(bytes.Buffer) cmd.Stderr = stderr + // If lazygit exits but leaves behind a subprocess that inherited its stderr + // pipe, cmd.Wait blocks waiting for that pipe to reach EOF for as long as the + // subprocess stays alive. Unbounded, that hangs the whole test binary until + // its global timeout fires, and the timeout throws away whatever lazygit + // wrote to stderr before exiting (a panic, a -race report) -- the very output + // needed to diagnose the failure. WaitDelay caps the wait: once the process + // has exited, Wait gives the stderr goroutine at most this long to drain, + // then closes the pipe and returns ErrWaitDelay, so the captured stderr + // surfaces as the test error instead of being lost. + cmd.WaitDelay = 5 * time.Second + // these rows and columns are ignored because internally we use tcell's // simulation screen. However we still need the pty for the sake of // running other commands in a pty. @@ -83,12 +98,32 @@ func runCmdHeadless(cmd *exec.Cmd) (int, error) { return -1, err } + // pty.StartWithSize starts lazygit in its own process group, so we can signal + // the whole group at once. Capture the id now, while the process is alive: + // once Wait has reaped it we can no longer look it up. + pgid, pgidErr := syscall.Getpgid(cmd.Process.Pid) + _, _ = io.Copy(io.Discard, f) - if cmd.Wait() != nil { + waitErr := cmd.Wait() + + // On any failure -- including a WaitDelay expiry caused by a leaked + // subprocess -- kill the whole process group so a straggler can't linger and + // wedge a later test or pile up across a CI run. Best effort: usually the + // group is already gone (ESRCH), and a subprocess that called setsid to + // detach into its own group is out of reach, but WaitDelay still unblocks us. + if waitErr != nil && pgidErr == nil { + _ = syscall.Kill(-pgid, syscall.SIGKILL) + } + + if waitErr != nil { _ = f.Close() - // return an error with the stderr output - return cmd.Process.Pid, errors.New(stderr.String()) + // Prefer lazygit's own stderr as the error; fall back to the wait error + // itself (e.g. ErrWaitDelay) when it exited without printing anything. + if stderr.Len() > 0 { + return cmd.Process.Pid, errors.New(stderr.String()) + } + return cmd.Process.Pid, waitErr } return cmd.Process.Pid, f.Close() diff --git a/pkg/integration/components/runner.go b/pkg/integration/components/runner.go index 5640c3e7044..78cb5439f1c 100644 --- a/pkg/integration/components/runner.go +++ b/pkg/integration/components/runner.go @@ -5,6 +5,8 @@ import ( "os" "os/exec" "path/filepath" + "sync" + "time" lazycoreUtils "github.com/jesseduffield/lazycore/pkg/utils" "github.com/jesseduffield/lazygit/pkg/commands/git_commands" @@ -24,6 +26,12 @@ type RunTestArgs struct { CodeCoverageDir string InputDelay int MaxAttempts int + // If set, each test's run duration is appended to this file (as + // " "). run_integration_tests.sh prints the slowest at + // the end, so slow or anomalous tests can be spotted across CI runs. We + // write to a file rather than stdout/stderr because `go test` captures + // those and only shows them with -v. Empty disables it. + LogTimingsPath string } // This function lets you run tests either from within `go test` or from a regular binary. @@ -47,6 +55,11 @@ func RunTests(args RunTestArgs) error { return err } + // Start each run with a fresh timings file (see RunTestArgs.LogTimingsPath). + if args.LogTimingsPath != "" { + _ = os.Remove(args.LogTimingsPath) + } + for _, test := range args.Tests { args.TestWrapper(test, func() error { paths := NewPaths( @@ -99,7 +112,11 @@ func runTest( return err } + start := time.Now() pid, err := args.RunCmd(cmd) + if args.LogTimingsPath != "" { + logTestTiming(args.LogTimingsPath, test.Name(), time.Since(start)) + } // Print race detector log regardless of the command's exit status if args.RaceDetector { @@ -112,6 +129,23 @@ func runTest( return err } +// timingsMutex serializes appends to the timings file, since tests run in +// parallel. +var timingsMutex sync.Mutex + +func logTestTiming(path, name string, duration time.Duration) { + timingsMutex.Lock() + defer timingsMutex.Unlock() + + f, err := os.OpenFile(path, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0o644) + if err != nil { + return + } + defer f.Close() + + fmt.Fprintf(f, "%.2f %s\n", duration.Seconds(), name) +} + func prepareTestDir( test *IntegrationTest, paths Paths, diff --git a/scripts/run_integration_tests.sh b/scripts/run_integration_tests.sh index 579e6d77c15..2bf010f19c4 100755 --- a/scripts/run_integration_tests.sh +++ b/scripts/run_integration_tests.sh @@ -19,7 +19,7 @@ if [ -n "$LAZYGIT_GOCOVERDIR" ]; then # hacky. To capture the coverage data for the test runner we pass the test.gocoverdir positional # arg, but if we do that then the GOCOVERDIR env var (which you typically pass to the test binary) will be overwritten by the test runner. So we're passing LAZYGIT_COCOVERDIR instead # and then internally passing that to the test binary as GOCOVERDIR. - go test -cover -coverpkg=github.com/jesseduffield/lazygit/pkg/... pkg/integration/clients/*.go -args -test.gocoverdir="/tmp/code_coverage" + go test -timeout 30m -cover -coverpkg=github.com/jesseduffield/lazygit/pkg/... pkg/integration/clients/*.go -args -test.gocoverdir="/tmp/code_coverage" EXITCODE=$? # We're merging the coverage data for the sake of having fewer artefacts to upload. @@ -29,7 +29,7 @@ if [ -n "$LAZYGIT_GOCOVERDIR" ]; then rm -rf /tmp/code_coverage mv /tmp/code_coverage_merged /tmp/code_coverage else - go test pkg/integration/clients/*.go + go test -timeout 30m pkg/integration/clients/*.go EXITCODE=$? fi @@ -37,4 +37,12 @@ if test -f ~/.gitconfig.lazygit.bak; then mv ~/.gitconfig.lazygit.bak ~/.gitconfig fi +# If per-test timings were collected (LAZYGIT_TEST_TIMING points at the file the +# harness appends to), print them sorted by slowest first so they show up in the +# CI log. +if [ -n "$LAZYGIT_TEST_TIMING" ] && [ -f "$LAZYGIT_TEST_TIMING" ]; then + echo "Test timings (seconds):" + sort -rn "$LAZYGIT_TEST_TIMING" +fi + exit $EXITCODE