feat: add runtime to fxevent.Run events

fxevent/console.go

@@ -109,7 +109,7 @@ func (l *ConsoleLogger) LogEvent(event Event) {
 		if e.ModuleName != "" {
 			moduleStr = fmt.Sprintf(" from module %q", e.ModuleName)
 		}
-		l.logf("RUN\t%v: %v%v", e.Kind, e.Name, moduleStr)
+		l.logf("RUN\t%v: %v in %s%v", e.Kind, e.Name, e.Runtime, moduleStr)
 		if e.Err != nil {
 			l.logf("Error returned: %+v", e.Err)
 		}

fxevent/console_test.go

@@ -267,27 +267,29 @@ func TestConsoleLogger(t *testing.T) {
 		},
 		{
 			name: "Run",
-			give: &Run{Name: "bytes.NewBuffer()", Kind: "constructor"},
-			want: "[Fx] RUN\tconstructor: bytes.NewBuffer()\n",
+			give: &Run{Name: "bytes.NewBuffer()", Kind: "constructor", Runtime: 10 * time.Nanosecond},
+			want: "[Fx] RUN\tconstructor: bytes.NewBuffer() in 10ns\n",
 		},
 		{
 			name: "Run with module",
 			give: &Run{
 				Name:       "bytes.NewBuffer()",
 				Kind:       "constructor",
+				Runtime:    50 * time.Millisecond,
 				ModuleName: "myModule",
 			},
-			want: "[Fx] RUN\tconstructor: bytes.NewBuffer() from module \"myModule\"\n",
+			want: "[Fx] RUN\tconstructor: bytes.NewBuffer() in 50ms from module \"myModule\"\n",
 		},
 		{
 			name: "RunError",
 			give: &Run{
-				Name: "bytes.NewBuffer()",
-				Kind: "constructor",
-				Err:  errors.New("terrible constructor error"),
+				Name:    "bytes.NewBuffer()",
+				Kind:    "constructor",
+				Runtime: 5 * time.Second,
+				Err:     errors.New("terrible constructor error"),
 			},
 			want: joinLines(
-				"[Fx] RUN\tconstructor: bytes.NewBuffer()",
+				"[Fx] RUN\tconstructor: bytes.NewBuffer() in 5s",
 				"[Fx] Error returned: terrible constructor error",
 			),
 		},

fxevent/event.go

@@ -203,6 +203,9 @@ type Run struct {
 	// ModuleName is the name of the module in which the function belongs.
 	ModuleName string
 
+	// Runtime specifies how long it took to run this function.
+	Runtime time.Duration
+
 	// Err is non-nil if the function returned an error.
 	// If fx.RecoverFromPanics is used, this will include panics.
 	Err error

fxevent/slog.go

@@ -204,6 +204,7 @@ func (l *SlogLogger) LogEvent(event Event) {
 			l.logEvent("run",
 				slog.String("name", e.Name),
 				slog.String("kind", e.Kind),
+				slog.String("runtime", e.Runtime.String()),
 				slogMaybeModuleField(e.ModuleName),
 			)
 		}

fxevent/slog_test.go

@@ -342,11 +342,12 @@ func TestSlogLogger(t *testing.T) {
 		},
 		{
 			name:        "Run",
-			give:        &Run{Name: "bytes.NewBuffer()", Kind: "constructor"},
+			give:        &Run{Name: "bytes.NewBuffer()", Kind: "constructor", Runtime: 3 * time.Millisecond},
 			wantMessage: "run",
 			wantFields: map[string]interface{}{
-				"name": "bytes.NewBuffer()",
-				"kind": "constructor",
+				"name":    "bytes.NewBuffer()",
+				"kind":    "constructor",
+				"runtime": "3ms",
 			},
 		},
 		{
@@ -355,12 +356,14 @@ func TestSlogLogger(t *testing.T) {
 				Name:       "bytes.NewBuffer()",
 				Kind:       "constructor",
 				ModuleName: "myModule",
+				Runtime:    3 * time.Millisecond,
 			},
 			wantMessage: "run",
 			wantFields: map[string]interface{}{
-				"name":   "bytes.NewBuffer()",
-				"kind":   "constructor",
-				"module": "myModule",
+				"name":    "bytes.NewBuffer()",
+				"kind":    "constructor",
+				"module":  "myModule",
+				"runtime": "3ms",
 			},
 		},
 		{

fxevent/zap.go

@@ -179,6 +179,7 @@ func (l *ZapLogger) LogEvent(event Event) {
 			l.logEvent("run",
 				zap.String("name", e.Name),
 				zap.String("kind", e.Kind),
+				zap.String("runtime", e.Runtime.String()),
 				moduleField(e.ModuleName),
 			)
 		}

fxevent/zap_test.go

@@ -274,11 +274,12 @@ func TestZapLogger(t *testing.T) {
 		},
 		{
 			name:        "Run",
-			give:        &Run{Name: "bytes.NewBuffer()", Kind: "constructor"},
+			give:        &Run{Name: "bytes.NewBuffer()", Kind: "constructor", Runtime: time.Second},
 			wantMessage: "run",
 			wantFields: map[string]interface{}{
-				"name": "bytes.NewBuffer()",
-				"kind": "constructor",
+				"name":    "bytes.NewBuffer()",
+				"kind":    "constructor",
+				"runtime": "1s",
 			},
 		},
 		{
@@ -287,12 +288,14 @@ func TestZapLogger(t *testing.T) {
 				Name:       "bytes.NewBuffer()",
 				Kind:       "constructor",
 				ModuleName: "myModule",
+				Runtime:    time.Millisecond,
 			},
 			wantMessage: "run",
 			wantFields: map[string]interface{}{
-				"name":   "bytes.NewBuffer()",
-				"kind":   "constructor",
-				"module": "myModule",
+				"name":    "bytes.NewBuffer()",
+				"kind":    "constructor",
+				"module":  "myModule",
+				"runtime": "1ms",
 			},
 		},
 		{

module.go

@@ -200,6 +200,7 @@ func (m *module) provide(p provide) {
 				Name:       funcName,
 				Kind:       "provide",
 				ModuleName: m.name,
+				Runtime:    ci.Runtime,
 				Err:        ci.Error,
 			})
 		}),
@@ -232,6 +233,7 @@ func (m *module) supply(p provide) {
 			m.log.LogEvent(&fxevent.Run{
 				Name:       fmt.Sprintf("stub(%v)", typeName),
 				Kind:       "supply",
+				Runtime:    ci.Runtime,
 				ModuleName: m.name,
 			})
 		}),
@@ -356,6 +358,7 @@ func (m *module) decorate(d decorator) (err error) {
 				Name:       funcName,
 				Kind:       "decorate",
 				ModuleName: m.name,
+				Runtime:    ci.Runtime,
 				Err:        ci.Error,
 			})
 		}),
@@ -387,6 +390,7 @@ func (m *module) replace(d decorator) error {
 				Name:       fmt.Sprintf("stub(%v)", typeName),
 				Kind:       "replace",
 				ModuleName: m.name,
+				Runtime:    ci.Runtime,
 				Err:        ci.Error,
 			})
 		}),