diff --git a/app_test.go b/app_test.go index 623acad47..5344389de 100644 --- a/app_test.go +++ b/app_test.go @@ -365,7 +365,7 @@ func TestNewApp(t *testing.T) { defer app.RequireStart().RequireStop() require.Equal(t, - []string{"Provided", "Provided", "Provided", "Provided", "Decorated", "LoggerInitialized", "Invoking", "Run", "Run", "Invoked", "Started"}, + []string{"Provided", "Provided", "Provided", "Provided", "Decorated", "LoggerInitialized", "Invoking", "BeforeRun", "Run", "BeforeRun", "Run", "Invoked", "Started"}, spy.EventTypes()) }) @@ -674,7 +674,7 @@ func TestWithLogger(t *testing.T) { ) assert.Equal(t, []string{ - "Provided", "Provided", "Provided", "Supplied", "Run", "LoggerInitialized", + "Provided", "Provided", "Provided", "Supplied", "BeforeRun", "Run", "LoggerInitialized", }, spy.EventTypes()) spy.Reset() @@ -704,7 +704,7 @@ func TestWithLogger(t *testing.T) { "must provide constructor function, got (type *bytes.Buffer)", ) - assert.Equal(t, []string{"Provided", "Provided", "Provided", "Supplied", "Provided", "Run", "LoggerInitialized"}, spy.EventTypes()) + assert.Equal(t, []string{"Provided", "Provided", "Provided", "Supplied", "Provided", "BeforeRun", "Run", "LoggerInitialized"}, spy.EventTypes()) }) t.Run("logger failed to build", func(t *testing.T) { @@ -989,8 +989,18 @@ func TestRunEventEmission(t *testing.T) { assert.NoError(t, app.Err()) } + gotBeforeEvents := spy.Events().SelectByTypeName("BeforeRun") gotEvents := spy.Events().SelectByTypeName("Run") - require.Len(t, gotEvents, len(tt.wantRunEvents)) + require.Len(t, gotBeforeEvents, len(tt.wantRunEvents), "wrong number of before-run events") + require.Len(t, gotEvents, len(tt.wantRunEvents), "wrong number of run events") + // BeforeRun events are just a reduced-field version of Run events + for i, event := range gotBeforeEvents { + rEvent, ok := event.(*fxevent.BeforeRun) + require.True(t, ok) + + assert.Equal(t, tt.wantRunEvents[i].Name, rEvent.Name) + assert.Equal(t, tt.wantRunEvents[i].Kind, rEvent.Kind) + } for i, event := range gotEvents { rEvent, ok := event.(*fxevent.Run) require.True(t, ok) @@ -1627,12 +1637,12 @@ func TestAppStart(t *testing.T) { ) go func() { - app.Start(context.Background()) + assert.NoError(t, app.Start(context.Background())) close(startReturn) }() <-secondStart - app.Stop(context.Background()) + assert.NoError(t, app.Stop(context.Background())) assert.True(t, stop1Run) }) @@ -1696,7 +1706,9 @@ func TestAppStart(t *testing.T) { "Provided", "Provided", "Provided", "Provided", "LoggerInitialized", "Invoking", + "BeforeRun", "Run", + "BeforeRun", "Run", "Invoked", "OnStartExecuting", "OnStartExecuted", @@ -1734,7 +1746,9 @@ func TestAppStart(t *testing.T) { "Provided", "Provided", "Provided", "Provided", "LoggerInitialized", "Invoking", + "BeforeRun", "Run", + "BeforeRun", "Run", "Invoked", "OnStartExecuting", "OnStartExecuted", @@ -2471,6 +2485,7 @@ func TestCustomLoggerWithLifecycle(t *testing.T) { "Provided", "Provided", "Provided", + "BeforeRun", "Run", "LoggerInitialized", "OnStartExecuting", "OnStartExecuted", diff --git a/docs/go.mod b/docs/go.mod index aefe9f678..6d7545d93 100644 --- a/docs/go.mod +++ b/docs/go.mod @@ -11,7 +11,7 @@ require ( require ( github.com/davecgh/go-spew v1.1.1 // indirect github.com/pmezard/go-difflib v1.0.0 // indirect - go.uber.org/dig v1.18.0 // indirect + go.uber.org/dig v1.19.0 // indirect go.uber.org/multierr v1.10.0 // indirect golang.org/x/sys v0.0.0-20220412211240-33da011f77ad // indirect gopkg.in/yaml.v3 v3.0.1 // indirect diff --git a/docs/go.sum b/docs/go.sum index 63e4d7c0e..2b5e86457 100644 --- a/docs/go.sum +++ b/docs/go.sum @@ -10,8 +10,8 @@ github.com/stretchr/testify v1.7.1/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/ github.com/stretchr/testify v1.8.0/go.mod h1:yNjHg4UonilssWZ8iaSj1OCr/vHnekPRkoO+kdMU+MU= github.com/stretchr/testify v1.8.1 h1:w7B6lhMri9wdJUVmEZPGGhZzrYTPvgJArz7wNPgYKsk= github.com/stretchr/testify v1.8.1/go.mod h1:w2LPCIKwWwSfY2zedu0+kehJoqGctiVI29o6fzry7u4= -go.uber.org/dig v1.18.0 h1:imUL1UiY0Mg4bqbFfsRQO5G4CGRBec/ZujWTvSVp3pw= -go.uber.org/dig v1.18.0/go.mod h1:Us0rSJiThwCv2GteUN0Q7OKvU7n5J4dxZ9JKUXozFdE= +go.uber.org/dig v1.19.0 h1:BACLhebsYdpQ7IROQ1AGPjrXcP5dF80U3gKoFzbaq/4= +go.uber.org/dig v1.19.0/go.mod h1:Us0rSJiThwCv2GteUN0Q7OKvU7n5J4dxZ9JKUXozFdE= go.uber.org/goleak v1.2.0 h1:xqgm/S+aQvhWFTtR0XK3Jvg7z8kGV8P4X14IzwN3Eqk= go.uber.org/goleak v1.2.0/go.mod h1:XJYK+MuIchqpmGmUSAzotztawfKvYLUIgg7guXrwVUo= go.uber.org/multierr v1.10.0 h1:S0h4aNzvfcFsC3dRF1jLoaov7oRaKqRGC/pUEJ2yvPQ= diff --git a/fxevent/console.go b/fxevent/console.go index 5b376c823..d343d1fbe 100644 --- a/fxevent/console.go +++ b/fxevent/console.go @@ -104,6 +104,12 @@ func (l *ConsoleLogger) LogEvent(event Event) { if e.Err != nil { l.logf("Error after options were applied: %+v", e.Err) } + case *BeforeRun: + var moduleStr string + if e.ModuleName != "" { + moduleStr = fmt.Sprintf(" from module %q", e.ModuleName) + } + l.logf("BEFORE RUN\t%s: %s%s", e.Kind, e.Name, moduleStr) case *Run: var moduleStr string if e.ModuleName != "" { diff --git a/fxevent/event.go b/fxevent/event.go index 187a9d8af..f128b28c1 100644 --- a/fxevent/event.go +++ b/fxevent/event.go @@ -39,6 +39,7 @@ func (*Supplied) event() {} func (*Provided) event() {} func (*Replaced) event() {} func (*Decorated) event() {} +func (*BeforeRun) event() {} func (*Run) event() {} func (*Invoking) event() {} func (*Invoked) event() {} @@ -191,6 +192,20 @@ type Decorated struct { Err error } +// BeforeRun is emitted before a constructor, decorator, or supply/replace stub is run by Fx. +// When complete, a Run will be emitted. +type BeforeRun struct { + // Name is the name of the function that will be run. + Name string + + // Kind indicates which Fx option was used to pass along the function. + // It is either "provide", "decorate", "supply", or "replace". + Kind string + + // ModuleName is the name of the module in which the function belongs. + ModuleName string +} + // Run is emitted after a constructor, decorator, or supply/replace stub is run by Fx. type Run struct { // Name is the name of the function that was run. diff --git a/fxevent/event_test.go b/fxevent/event_test.go index 0546b02e0..d1dd65e3e 100644 --- a/fxevent/event_test.go +++ b/fxevent/event_test.go @@ -39,6 +39,7 @@ func TestForCoverage(t *testing.T) { &Provided{}, &Replaced{}, &Decorated{}, + &BeforeRun{}, &Run{}, &Invoking{}, &Invoked{}, diff --git a/fxevent/slog.go b/fxevent/slog.go index 09fb298c7..2c4d2e766 100644 --- a/fxevent/slog.go +++ b/fxevent/slog.go @@ -192,6 +192,12 @@ func (l *SlogLogger) LogEvent(event Event) { slogMaybeModuleField(e.ModuleName), slogErr(e.Err)) } + case *BeforeRun: + l.logEvent("before run", + slog.String("name", e.Name), + slog.String("kind", e.Kind), + slogMaybeModuleField(e.ModuleName), + ) case *Run: if e.Err != nil { l.logError("error returned", diff --git a/fxevent/slog_test.go b/fxevent/slog_test.go index 3b72ed8cc..ceaa5858c 100644 --- a/fxevent/slog_test.go +++ b/fxevent/slog_test.go @@ -340,6 +340,15 @@ func TestSlogLogger(t *testing.T) { "error": "some error", }, }, + { + name: "BeforeRun", + give: &BeforeRun{Name: "bytes.NewBuffer()", Kind: "constructor"}, + wantMessage: "before run", + wantFields: map[string]interface{}{ + "name": "bytes.NewBuffer()", + "kind": "constructor", + }, + }, { name: "Run", give: &Run{Name: "bytes.NewBuffer()", Kind: "constructor", Runtime: 3 * time.Millisecond}, diff --git a/fxevent/zap.go b/fxevent/zap.go index 9d0c71fba..5cce7d0a1 100644 --- a/fxevent/zap.go +++ b/fxevent/zap.go @@ -167,6 +167,12 @@ func (l *ZapLogger) LogEvent(event Event) { moduleField(e.ModuleName), zap.Error(e.Err)) } + case *BeforeRun: + l.logEvent("before run", + zap.String("name", e.Name), + zap.String("kind", e.Kind), + moduleField(e.ModuleName), + ) case *Run: if e.Err != nil { l.logError("error returned", diff --git a/go.mod b/go.mod index 0ca046c07..56407f6c2 100644 --- a/go.mod +++ b/go.mod @@ -4,7 +4,7 @@ go 1.22 require ( github.com/stretchr/testify v1.8.1 - go.uber.org/dig v1.18.0 + go.uber.org/dig v1.19.0 go.uber.org/goleak v1.2.0 go.uber.org/multierr v1.10.0 go.uber.org/zap v1.26.0 diff --git a/go.sum b/go.sum index 12eaae730..ac0978465 100644 --- a/go.sum +++ b/go.sum @@ -14,8 +14,8 @@ github.com/stretchr/testify v1.7.1/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/ github.com/stretchr/testify v1.8.0/go.mod h1:yNjHg4UonilssWZ8iaSj1OCr/vHnekPRkoO+kdMU+MU= github.com/stretchr/testify v1.8.1 h1:w7B6lhMri9wdJUVmEZPGGhZzrYTPvgJArz7wNPgYKsk= github.com/stretchr/testify v1.8.1/go.mod h1:w2LPCIKwWwSfY2zedu0+kehJoqGctiVI29o6fzry7u4= -go.uber.org/dig v1.18.0 h1:imUL1UiY0Mg4bqbFfsRQO5G4CGRBec/ZujWTvSVp3pw= -go.uber.org/dig v1.18.0/go.mod h1:Us0rSJiThwCv2GteUN0Q7OKvU7n5J4dxZ9JKUXozFdE= +go.uber.org/dig v1.19.0 h1:BACLhebsYdpQ7IROQ1AGPjrXcP5dF80U3gKoFzbaq/4= +go.uber.org/dig v1.19.0/go.mod h1:Us0rSJiThwCv2GteUN0Q7OKvU7n5J4dxZ9JKUXozFdE= go.uber.org/goleak v1.2.0 h1:xqgm/S+aQvhWFTtR0XK3Jvg7z8kGV8P4X14IzwN3Eqk= go.uber.org/goleak v1.2.0/go.mod h1:XJYK+MuIchqpmGmUSAzotztawfKvYLUIgg7guXrwVUo= go.uber.org/multierr v1.10.0 h1:S0h4aNzvfcFsC3dRF1jLoaov7oRaKqRGC/pUEJ2yvPQ= diff --git a/internal/e2e/go.mod b/internal/e2e/go.mod index b3770905c..ef8194199 100644 --- a/internal/e2e/go.mod +++ b/internal/e2e/go.mod @@ -10,7 +10,7 @@ require ( require ( github.com/davecgh/go-spew v1.1.1 // indirect github.com/pmezard/go-difflib v1.0.0 // indirect - go.uber.org/dig v1.18.0 // indirect + go.uber.org/dig v1.19.0 // indirect go.uber.org/multierr v1.10.0 // indirect go.uber.org/zap v1.26.0 // indirect golang.org/x/sys v0.0.0-20220412211240-33da011f77ad // indirect diff --git a/internal/e2e/go.sum b/internal/e2e/go.sum index 80f7a975c..55f8360da 100644 --- a/internal/e2e/go.sum +++ b/internal/e2e/go.sum @@ -10,8 +10,8 @@ github.com/stretchr/testify v1.7.1/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/ github.com/stretchr/testify v1.8.0/go.mod h1:yNjHg4UonilssWZ8iaSj1OCr/vHnekPRkoO+kdMU+MU= github.com/stretchr/testify v1.8.2 h1:+h33VjcLVPDHtOdpUCuF+7gSuG3yGIftsP1YvFihtJ8= github.com/stretchr/testify v1.8.2/go.mod h1:w2LPCIKwWwSfY2zedu0+kehJoqGctiVI29o6fzry7u4= -go.uber.org/dig v1.18.0 h1:imUL1UiY0Mg4bqbFfsRQO5G4CGRBec/ZujWTvSVp3pw= -go.uber.org/dig v1.18.0/go.mod h1:Us0rSJiThwCv2GteUN0Q7OKvU7n5J4dxZ9JKUXozFdE= +go.uber.org/dig v1.19.0 h1:BACLhebsYdpQ7IROQ1AGPjrXcP5dF80U3gKoFzbaq/4= +go.uber.org/dig v1.19.0/go.mod h1:Us0rSJiThwCv2GteUN0Q7OKvU7n5J4dxZ9JKUXozFdE= go.uber.org/goleak v1.2.0 h1:xqgm/S+aQvhWFTtR0XK3Jvg7z8kGV8P4X14IzwN3Eqk= go.uber.org/goleak v1.2.0/go.mod h1:XJYK+MuIchqpmGmUSAzotztawfKvYLUIgg7guXrwVUo= go.uber.org/multierr v1.10.0 h1:S0h4aNzvfcFsC3dRF1jLoaov7oRaKqRGC/pUEJ2yvPQ= diff --git a/module.go b/module.go index 4615ad46a..a71fb65a7 100644 --- a/module.go +++ b/module.go @@ -195,6 +195,13 @@ func (m *module) provide(p provide) { opts := []dig.ProvideOption{ dig.FillProvideInfo(&info), dig.Export(!p.Private), + dig.WithProviderBeforeCallback(func(bci dig.BeforeCallbackInfo) { + m.log.LogEvent(&fxevent.BeforeRun{ + Name: funcName, + Kind: "provide", + ModuleName: m.name, + }) + }), dig.WithProviderCallback(func(ci dig.CallbackInfo) { m.log.LogEvent(&fxevent.Run{ Name: funcName, @@ -229,6 +236,13 @@ func (m *module) supply(p provide) { typeName := p.SupplyType.String() opts := []dig.ProvideOption{ dig.Export(!p.Private), + dig.WithProviderBeforeCallback(func(bci dig.BeforeCallbackInfo) { + m.log.LogEvent(&fxevent.BeforeRun{ + Name: fmt.Sprintf("stub(%v)", typeName), + Kind: "supply", + ModuleName: m.name, + }) + }), dig.WithProviderCallback(func(ci dig.CallbackInfo) { m.log.LogEvent(&fxevent.Run{ Name: fmt.Sprintf("stub(%v)", typeName), @@ -352,6 +366,13 @@ func (m *module) decorate(d decorator) (err error) { var info dig.DecorateInfo opts := []dig.DecorateOption{ dig.FillDecorateInfo(&info), + dig.WithDecoratorBeforeCallback(func(bci dig.BeforeCallbackInfo) { + m.log.LogEvent(&fxevent.BeforeRun{ + Name: funcName, + Kind: "decorate", + ModuleName: m.name, + }) + }), dig.WithDecoratorCallback(func(ci dig.CallbackInfo) { m.log.LogEvent(&fxevent.Run{ Name: funcName, @@ -384,6 +405,13 @@ func (m *module) decorate(d decorator) (err error) { func (m *module) replace(d decorator) error { typeName := d.ReplaceType.String() opts := []dig.DecorateOption{ + dig.WithDecoratorBeforeCallback(func(bci dig.BeforeCallbackInfo) { + m.log.LogEvent(&fxevent.BeforeRun{ + Name: fmt.Sprintf("stub(%v)", typeName), + Kind: "replace", + ModuleName: m.name, + }) + }), dig.WithDecoratorCallback(func(ci dig.CallbackInfo) { m.log.LogEvent(&fxevent.Run{ Name: fmt.Sprintf("stub(%v)", typeName), diff --git a/module_test.go b/module_test.go index 3ac20527b..3fa5fdc93 100644 --- a/module_test.go +++ b/module_test.go @@ -262,15 +262,15 @@ func TestModuleSuccess(t *testing.T) { giveWithLogger: fx.NopLogger, wantEvents: []string{ "Provided", "Provided", "Provided", "Supplied", - "Run", "LoggerInitialized", "Invoking", "Invoked", + "BeforeRun", "Run", "LoggerInitialized", "Invoking", "Invoked", }, }, { desc: "Not using a custom logger for module defaults to app logger", giveWithLogger: fx.Options(), wantEvents: []string{ - "Provided", "Provided", "Provided", "Supplied", "Provided", "Run", - "LoggerInitialized", "Invoking", "Run", "Invoked", "Invoking", "Invoked", + "Provided", "Provided", "Provided", "Supplied", "Provided", "BeforeRun", "Run", + "LoggerInitialized", "Invoking", "BeforeRun", "Run", "Invoked", "Invoking", "Invoked", }, }, } @@ -353,8 +353,8 @@ func TestModuleSuccess(t *testing.T) { ) assert.Equal(t, []string{ - "Provided", "Supplied", "Replaced", "Run", "Run", - "LoggerInitialized", "Invoking", "Run", "Invoked", + "Provided", "Supplied", "Replaced", "BeforeRun", "Run", "BeforeRun", "Run", + "LoggerInitialized", "Invoking", "BeforeRun", "Run", "Invoked", }, moduleSpy.EventTypes()) assert.Equal(t, []string{ @@ -413,9 +413,9 @@ func TestModuleSuccess(t *testing.T) { ) assert.Equal(t, []string{ - "Supplied", "Provided", "Replaced", "Run", "Run", "LoggerInitialized", + "Supplied", "Provided", "Replaced", "BeforeRun", "Run", "BeforeRun", "Run", "LoggerInitialized", // Invoke logged twice, once from child and another from grandchild - "Invoking", "Run", "Invoked", "Invoking", "Invoked", + "Invoking", "BeforeRun", "Run", "Invoked", "Invoking", "Invoked", }, childSpy.EventTypes(), "events from grandchild also logged in child logger") assert.Equal(t, []string{ @@ -649,7 +649,7 @@ func TestModuleFailures(t *testing.T) { "must provide constructor function, got (type *bytes.Buffer)", }, wantEvents: []string{ - "Supplied", "Provided", "Run", "LoggerInitialized", + "Supplied", "Provided", "BeforeRun", "Run", "LoggerInitialized", }, }, { @@ -660,7 +660,7 @@ func TestModuleFailures(t *testing.T) { giveAppOpts: spyAsLogger, wantErrContains: []string{"error building logger"}, wantEvents: []string{ - "Provided", "Provided", "Provided", "Supplied", "Run", + "Provided", "Provided", "Provided", "Supplied", "BeforeRun", "Run", "LoggerInitialized", "Provided", "LoggerInitialized", }, }, @@ -678,8 +678,8 @@ func TestModuleFailures(t *testing.T) { giveAppOpts: spyAsLogger, wantErrContains: []string{"error building logger dependency"}, wantEvents: []string{ - "Provided", "Provided", "Provided", "Supplied", "Run", - "LoggerInitialized", "Provided", "Provided", "Run", "LoggerInitialized", + "Provided", "Provided", "Provided", "Supplied", "BeforeRun", "Run", + "LoggerInitialized", "Provided", "Provided", "BeforeRun", "Run", "LoggerInitialized", }, }, { @@ -690,7 +690,7 @@ func TestModuleFailures(t *testing.T) { "fx.WithLogger", "from:", "Failed", }, wantEvents: []string{ - "Provided", "Provided", "Provided", "Supplied", "Run", + "Provided", "Provided", "Provided", "Supplied", "BeforeRun", "Run", "LoggerInitialized", "Provided", "LoggerInitialized", }, },