uber-go/fx

Fx exiting program before panic in OnStart hook gets reported

Closed this issue · 1 comments

Describe the bug
When a panic happens in a start hook, this line in a deferred function signals the main goroutine to continue executing. it seems like a race then happens between the main goroutine running this line, exiting the program due to the error, and the panic from the hook-running goroutine being reported.

To Reproduce
Run this test:

package main

import (
	"context"
	"errors"
	"os"
	"os/exec"
	"testing"
	"go.uber.org/fx"
	"github.com/stretchr/testify/require"
	"github.com/stretchr/testify/assert"
)

const (
	_insideTest    = "INSIDE_TEST"
	_panicExitCode = 2
)

func TestMain(m *testing.M) {
	if len(os.Getenv(_insideTest)) > 0 {
		fakeFxMain()
		return
	}

	os.Exit(m.Run())
}

// An Fx application that crashes on start.
func fakeFxMain() {
	crashOnStart := func(lc fx.Lifecycle) {
		lc.Append(fx.Hook{
			OnStart: func(context.Context) error {
				panic("great sadness")
			},
		})
	}

	fx.New(fx.Invoke(crashOnStart)).Run()
}

func TestPanicRace(t *testing.T) {
	N := 1000
	for i := 0; i < N; i++ {
		output, code := RunApp(t)
		if code != _panicExitCode {
			assert.Failf(t, "Expected panic, got %v", output)
		}
	}
}

func RunApp(t *testing.T) (output string, exitCode int) {
	t.Helper()
	cmd := exec.Command(os.Args[0])
	cmd.Env = append(cmd.Env, _insideTest+"=1")

	out, err := cmd.CombinedOutput()
	require.Error(t, err)
	
	var exitErr *exec.ExitError
	require.Truef(t, errors.As(err, &exitErr),
		"expected ExitError, got %v", err)
	return string(out), exitErr.ExitCode()
}

You'll see output like the following:

    main_test.go:46:
                Error Trace:    src/code.uber.internal/go/fx_fdsafdsa/main_test.go:46
                Error:          Expected panic, got %v
                Test:           TestPanicRace
                Messages:       [Fx] PROVIDE    fx.Lifecycle <= go.uber.org/fx.New.func1()
                                [Fx] PROVIDE    fx.Shutdowner <= go.uber.org/fx.(*App).shutdowner-fm()
                                [Fx] PROVIDE    fx.DotGraph <= go.uber.org/fx.(*App).dotGraph-fm()
                                [Fx] INVOKE             code.uber.internal/go/fx_fdsafdsa.fakeFxMain.func1()
                                [Fx] RUN        provide: go.uber.org/fx.New.func1()
                                [Fx] HOOK OnStart               code.uber.internal/go/fx_fdsafdsa.fakeFxMain.func1.1() executing (caller: code.uber.internal/go/fx_fdsafdsa.fakeFxMain.func1)
                                [Fx] HOOK OnStart               code.uber.internal/go/fx_fdsafdsa.fakeFxMain.func1.1() called by code.uber.internal/go/fx_fdsafdsa.fakeFxMain.func1 ran successfully in 0s
                                [Fx] ERROR              Failed to start: goroutine exited without returning

Expected behavior
The test should pass, since the program should exit with the panic exit code every time, but occasionally it does not.

After some discussion w/ other contributors, we decided there isn't much that Fx can/should do in this case. Closing this issue.