diff --git a/desktop/wire.go b/desktop/wire.go index 95db13670..bf2fffcaa 100644 --- a/desktop/wire.go +++ b/desktop/wire.go @@ -55,16 +55,17 @@ type wireAsk struct { } type wireTool struct { - ID string `json:"id,omitempty"` - Name string `json:"name"` - Args string `json:"args,omitempty"` - Output string `json:"output,omitempty"` - Err string `json:"err,omitempty"` - ReadOnly bool `json:"readOnly"` - Truncated bool `json:"truncated,omitempty"` - Partial bool `json:"partial,omitempty"` - ParentID string `json:"parentId,omitempty"` - Profile *wireProfile `json:"profile,omitempty"` + ID string `json:"id,omitempty"` + Name string `json:"name"` + Args string `json:"args,omitempty"` + Output string `json:"output,omitempty"` + Err string `json:"err,omitempty"` + ReadOnly bool `json:"readOnly"` + Truncated bool `json:"truncated,omitempty"` + DurationMs int64 `json:"durationMs,omitempty"` + Partial bool `json:"partial,omitempty"` + ParentID string `json:"parentId,omitempty"` + Profile *wireProfile `json:"profile,omitempty"` } type wireProfile struct { @@ -157,7 +158,8 @@ func toWire(e event.Event) wireEvent { ID: e.Tool.ID, Name: e.Tool.Name, Args: e.Tool.Args, Output: e.Tool.Output, Err: e.Tool.Err, ReadOnly: e.Tool.ReadOnly, Truncated: e.Tool.Truncated, - Partial: e.Tool.Partial, ParentID: e.Tool.ParentID, + DurationMs: e.Tool.DurationMs, Partial: e.Tool.Partial, + ParentID: e.Tool.ParentID, } if e.Tool.Profile != nil { wt.Profile = &wireProfile{Model: e.Tool.Profile.Model, Effort: e.Tool.Profile.Effort} diff --git a/desktop/wire_test.go b/desktop/wire_test.go index 4ac2e8ef8..c63df32ee 100644 --- a/desktop/wire_test.go +++ b/desktop/wire_test.go @@ -79,9 +79,9 @@ func TestToWireToolDispatchProfile(t *testing.T) { } func TestToWireToolResult(t *testing.T) { - e := event.Event{Kind: event.ToolResult, Tool: event.Tool{ID: "1", Output: "ok", Truncated: true}} + e := event.Event{Kind: event.ToolResult, Tool: event.Tool{ID: "1", Output: "ok", Truncated: true, DurationMs: 522}} w := toWire(e) - if w.Tool == nil || w.Tool.Output != "ok" || !w.Tool.Truncated { + if w.Tool == nil || w.Tool.Output != "ok" || !w.Tool.Truncated || w.Tool.DurationMs != 522 { t.Errorf("tool result = %+v", w.Tool) } } diff --git a/internal/agent/agent.go b/internal/agent/agent.go index 7d4941eee..6d13cfd45 100644 --- a/internal/agent/agent.go +++ b/internal/agent/agent.go @@ -8,6 +8,7 @@ import ( "strings" "sync" "sync/atomic" + "time" "unicode/utf8" "reasonix/internal/diff" @@ -729,8 +730,11 @@ func (a *Agent) executeBatch(ctx context.Context, calls []provider.ToolCall) []s results := make([]string, len(calls)) outcomes := make([]toolOutcome, len(calls)) + durations := make([]int64, len(calls)) run := func(i int) { + start := time.Now() outcomes[i] = a.executeOne(ctx, calls[i]) + durations[i] = time.Since(start).Milliseconds() results[i] = outcomes[i].output } @@ -748,13 +752,14 @@ func (a *Agent) executeBatch(ctx context.Context, calls []provider.ToolCall) []s o := outcomes[i] t, ok := a.tools.Get(c.Name) a.sink.Emit(event.Event{Kind: event.ToolResult, Tool: event.Tool{ - ID: c.ID, - Name: c.Name, - Args: c.Arguments, - Output: o.output, - Err: o.errMsg, - ReadOnly: ok && t.ReadOnly(), - Truncated: o.truncated, + ID: c.ID, + Name: c.Name, + Args: c.Arguments, + Output: o.output, + Err: o.errMsg, + ReadOnly: ok && t.ReadOnly(), + Truncated: o.truncated, + DurationMs: durations[i], }}) if o.truncated && o.truncMsg != "" { a.sink.Emit(event.Event{Kind: event.Notice, Level: event.LevelInfo, Text: o.truncMsg}) diff --git a/internal/control/controller.go b/internal/control/controller.go index 04bf36e8b..0b2723d81 100644 --- a/internal/control/controller.go +++ b/internal/control/controller.go @@ -624,26 +624,28 @@ func (c *Controller) RunShell(command string) { }}) cmd.Stdout = w cmd.Stderr = w + start := time.Now() err := cmd.Run() + durationMs := time.Since(start).Milliseconds() out := buf.String() if ctx.Err() == context.DeadlineExceeded { c.sink.Emit(event.Event{ Kind: event.ToolResult, - Tool: event.Tool{ID: id, Name: "bash", Output: out, Err: fmt.Sprintf(i18n.M.ShellExecTimeoutFmt, shellTimeout)}, + Tool: event.Tool{ID: id, Name: "bash", Output: out, Err: fmt.Sprintf(i18n.M.ShellExecTimeoutFmt, shellTimeout), DurationMs: durationMs}, }) return nil } if err != nil { c.sink.Emit(event.Event{ Kind: event.ToolResult, - Tool: event.Tool{ID: id, Name: "bash", Output: out, Err: fmt.Sprintf(i18n.M.ShellExecFailedFmt, err)}, + Tool: event.Tool{ID: id, Name: "bash", Output: out, Err: fmt.Sprintf(i18n.M.ShellExecFailedFmt, err), DurationMs: durationMs}, }) return nil } c.sink.Emit(event.Event{ Kind: event.ToolResult, - Tool: event.Tool{ID: id, Name: "bash", Output: out}, + Tool: event.Tool{ID: id, Name: "bash", Output: out, DurationMs: durationMs}, }) return nil }) diff --git a/internal/event/event.go b/internal/event/event.go index 5a8b3c7ee..fbcbf17e4 100644 --- a/internal/event/event.go +++ b/internal/event/event.go @@ -103,13 +103,14 @@ type Profile struct { // only ID/Name/Args/ReadOnly are set; on result Output/Err/Truncated are filled // in. Args is the raw JSON arguments — a sink compacts it for display. type Tool struct { - ID string - Name string - Args string - Output string // ToolResult: the result text fed to the model - Err string // ToolResult: non-empty when the call failed or was blocked - ReadOnly bool - Truncated bool // ToolResult: Output was head+tailed before display/model + ID string + Name string + Args string + Output string // ToolResult: the result text fed to the model + Err string // ToolResult: non-empty when the call failed or was blocked + ReadOnly bool + Truncated bool // ToolResult: Output was head+tailed before display/model + DurationMs int64 // ToolResult: wall-clock execution time in milliseconds // Partial marks an early ToolDispatch emitted when a call begins (ID/Name set, // Args still streaming) so a frontend can show the card immediately; a second, // full ToolDispatch (Partial false, Args set) follows when the call completes. diff --git a/internal/serve/wire.go b/internal/serve/wire.go index 07462cb6f..566192ff3 100644 --- a/internal/serve/wire.go +++ b/internal/serve/wire.go @@ -54,16 +54,17 @@ type wireProfile struct { } type wireTool struct { - ID string `json:"id,omitempty"` - Name string `json:"name"` - Args string `json:"args,omitempty"` - Output string `json:"output,omitempty"` - Err string `json:"err,omitempty"` - ReadOnly bool `json:"readOnly"` - Truncated bool `json:"truncated,omitempty"` - Partial bool `json:"partial,omitempty"` - ParentID string `json:"parentId,omitempty"` - Profile *wireProfile `json:"profile,omitempty"` + ID string `json:"id,omitempty"` + Name string `json:"name"` + Args string `json:"args,omitempty"` + Output string `json:"output,omitempty"` + Err string `json:"err,omitempty"` + ReadOnly bool `json:"readOnly"` + Truncated bool `json:"truncated,omitempty"` + DurationMs int64 `json:"durationMs,omitempty"` + Partial bool `json:"partial,omitempty"` + ParentID string `json:"parentId,omitempty"` + Profile *wireProfile `json:"profile,omitempty"` } type wireUsage struct { @@ -150,7 +151,8 @@ func toWire(e event.Event) wireEvent { ID: e.Tool.ID, Name: e.Tool.Name, Args: e.Tool.Args, Output: e.Tool.Output, Err: e.Tool.Err, ReadOnly: e.Tool.ReadOnly, Truncated: e.Tool.Truncated, - Partial: e.Tool.Partial, ParentID: e.Tool.ParentID, + DurationMs: e.Tool.DurationMs, Partial: e.Tool.Partial, + ParentID: e.Tool.ParentID, } if e.Tool.Profile != nil { wt.Profile = &wireProfile{Model: e.Tool.Profile.Model, Effort: e.Tool.Profile.Effort} diff --git a/internal/serve/wire_test.go b/internal/serve/wire_test.go index 722bd4c6f..9ad7f8799 100644 --- a/internal/serve/wire_test.go +++ b/internal/serve/wire_test.go @@ -26,6 +26,13 @@ func TestToWire(t *testing.T) { } }) + t.Run("tool result duration", func(t *testing.T) { + w := toWire(event.Event{Kind: event.ToolResult, Tool: event.Tool{Name: "web_fetch", Output: "ok", DurationMs: 522}}) + if w.Tool == nil || w.Tool.Output != "ok" || w.Tool.DurationMs != 522 { + t.Errorf("tool result duration = %+v", w.Tool) + } + }) + t.Run("usage with cost", func(t *testing.T) { w := toWire(event.Event{ Kind: event.Usage,