feat(orch): add execution stats to subagent completion notifications

Track tool call count, per-tool breakdown, and duration in ToolLoopResult,
propagate via bus Metadata, and format as "📋 scout-1 completed (3.2s, 5 tool calls)."

Co-Authored-By: Claude Opus 4.6 <noreply@anthropic.com>

pkg/agent/loop.go

@@ -820,10 +820,11 @@ func (al *AgentLoop) processSystemMessage(ctx context.Context, msg bus.InboundMe
 	if idx := strings.LastIndex(label, ":"); idx >= 0 {
 		label = label[idx+1:]
 	}
+	notification := formatSubagentCompletion(label, msg.Metadata)
 	_ = al.bus.PublishOutbound(ctx, bus.OutboundMessage{
 		Channel:         originChannel,
 		ChatID:          originChatID,
-		Content:         fmt.Sprintf("📋 %s completed.", label),
+		Content:         notification,
 		SkipPlaceholder: true,
 	})
 
@@ -837,6 +838,56 @@ func (al *AgentLoop) processSystemMessage(ctx context.Context, msg bus.InboundMe
 	return "", nil
 }
 
+// formatSubagentCompletion builds the user-facing notification for a completed subagent.
+// If metadata contains duration_ms and tool_calls it produces e.g.:
+//
+//	"📋 scout-1 completed (3.2s, 5 tool calls)."
+//
+// Without metadata it falls back to the plain "📋 scout-1 completed." format.
+func formatSubagentCompletion(label string, metadata map[string]string) string {
+	if len(metadata) == 0 {
+		return fmt.Sprintf("📋 %s completed.", label)
+	}
+	durationMs, _ := strconv.ParseInt(metadata["duration_ms"], 10, 64)
+	toolCalls, _ := strconv.Atoi(metadata["tool_calls"])
+
+	if durationMs <= 0 && toolCalls <= 0 {
+		return fmt.Sprintf("📋 %s completed.", label)
+	}
+
+	parts := make([]string, 0, 2)
+	if durationMs > 0 {
+		parts = append(parts, formatDurationMs(durationMs))
+	}
+	if toolCalls > 0 {
+		if toolCalls == 1 {
+			parts = append(parts, "1 tool call")
+		} else {
+			parts = append(parts, fmt.Sprintf("%d tool calls", toolCalls))
+		}
+	}
+	return fmt.Sprintf("📋 %s completed (%s).", label, strings.Join(parts, ", "))
+}
+
+// formatDurationMs converts milliseconds to a human-readable duration string.
+// Examples: 800 → "0.8s", 1200 → "1.2s", 65000 → "1m5s", 3661000 → "61m1s".
+func formatDurationMs(ms int64) string {
+	if ms < 1000 {
+		return fmt.Sprintf("%dms", ms)
+	}
+	totalSec := ms / 1000
+	if totalSec < 60 {
+		tenths := (ms % 1000) / 100
+		return fmt.Sprintf("%d.%ds", totalSec, tenths)
+	}
+	min := totalSec / 60
+	sec := totalSec % 60
+	if sec == 0 {
+		return fmt.Sprintf("%dm", min)
+	}
+	return fmt.Sprintf("%dm%ds", min, sec)
+}
+
 // acquireSessionLock gets or creates a per-session semaphore and acquires it.
 // Returns false if the context is canceled before the lock is acquired.
 func (al *AgentLoop) acquireSessionLock(ctx context.Context, sessionKey string) bool {

pkg/agent/loop_test.go

@@ -2991,3 +2991,91 @@ func TestHandleReasoning(t *testing.T) {
 		}
 	})
 }
+
+func TestFormatDurationMs(t *testing.T) {
+	tests := []struct {
+		ms   int64
+		want string
+	}{
+		{0, "0ms"},
+		{500, "500ms"},
+		{999, "999ms"},
+		{1000, "1.0s"},
+		{1200, "1.2s"},
+		{3500, "3.5s"},
+		{59900, "59.9s"},
+		{60000, "1m"},
+		{61000, "1m1s"},
+		{65000, "1m5s"},
+		{120000, "2m"},
+		{3661000, "61m1s"},
+	}
+	for _, tt := range tests {
+		t.Run(fmt.Sprintf("%dms", tt.ms), func(t *testing.T) {
+			got := formatDurationMs(tt.ms)
+			if got != tt.want {
+				t.Errorf("formatDurationMs(%d) = %q, want %q", tt.ms, got, tt.want)
+			}
+		})
+	}
+}
+
+func TestFormatSubagentCompletion(t *testing.T) {
+	tests := []struct {
+		name     string
+		label    string
+		metadata map[string]string
+		want     string
+	}{
+		{
+			"no metadata",
+			"scout-1",
+			nil,
+			"📋 scout-1 completed.",
+		},
+		{
+			"empty metadata",
+			"scout-1",
+			map[string]string{},
+			"📋 scout-1 completed.",
+		},
+		{
+			"duration and tool calls",
+			"scout-1",
+			map[string]string{"duration_ms": "3200", "tool_calls": "5"},
+			"📋 scout-1 completed (3.2s, 5 tool calls).",
+		},
+		{
+			"single tool call",
+			"coder-1",
+			map[string]string{"duration_ms": "1200", "tool_calls": "1"},
+			"📋 coder-1 completed (1.2s, 1 tool call).",
+		},
+		{
+			"duration only",
+			"scout-2",
+			map[string]string{"duration_ms": "65000", "tool_calls": "0"},
+			"📋 scout-2 completed (1m5s).",
+		},
+		{
+			"tool calls only",
+			"scout-3",
+			map[string]string{"duration_ms": "0", "tool_calls": "10"},
+			"📋 scout-3 completed (10 tool calls).",
+		},
+		{
+			"zero everything",
+			"scout-4",
+			map[string]string{"duration_ms": "0", "tool_calls": "0"},
+			"📋 scout-4 completed.",
+		},
+	}
+	for _, tt := range tests {
+		t.Run(tt.name, func(t *testing.T) {
+			got := formatSubagentCompletion(tt.label, tt.metadata)
+			if got != tt.want {
+				t.Errorf("formatSubagentCompletion(%q, %v) = %q, want %q", tt.label, tt.metadata, got, tt.want)
+			}
+		})
+	}
+}

pkg/tools/sandbox_test.go

@@ -173,7 +173,10 @@ func TestPresetAllowRules_Coder(t *testing.T) {
 		t.Fatalf("coder rules missing or empty")
 	}
 
-	exec := NewExecTool(t.TempDir(), true)
+	exec, err := NewExecTool(t.TempDir(), true)
+	if err != nil {
+		t.Fatalf("NewExecTool: %v", err)
+	}
 	exec.SetAllowRules(rules)
 
 	tests := []struct {
@@ -224,7 +227,10 @@ func TestPresetAllowRules_Analyst(t *testing.T) {
 		t.Fatalf("analyst rules missing or empty")
 	}
 
-	exec := NewExecTool(t.TempDir(), true)
+	exec, err := NewExecTool(t.TempDir(), true)
+	if err != nil {
+		t.Fatalf("NewExecTool: %v", err)
+	}
 	exec.SetAllowRules(rules)
 
 	tests := []struct {
@@ -264,7 +270,10 @@ func TestPresetAllowRules_Worker(t *testing.T) {
 		t.Fatalf("worker rules missing or empty")
 	}
 
-	exec := NewExecTool(t.TempDir(), true)
+	exec, err := NewExecTool(t.TempDir(), true)
+	if err != nil {
+		t.Fatalf("NewExecTool: %v", err)
+	}
 	exec.SetAllowRules(rules)
 
 	tests := []struct {
@@ -306,7 +315,10 @@ func TestPresetAllowRules_Coordinator(t *testing.T) {
 		t.Fatalf("coordinator rules missing or empty")
 	}
 
-	exec := NewExecTool(t.TempDir(), true)
+	exec, err := NewExecTool(t.TempDir(), true)
+	if err != nil {
+		t.Fatalf("NewExecTool: %v", err)
+	}
 	exec.SetAllowRules(rules)
 
 	tests := []struct {

pkg/tools/shell_test.go

@@ -573,15 +573,12 @@ func TestGuardCommand_DenyPattern_IncludesPattern(t *testing.T) {
 	}
 }
 
-// TestGuardCommand_Allowlist_ShowsPatterns verifies that allowlist violation
+// TestGuardCommand_Allowlist_ShowsRules verifies that allowlist violation
-// messages include all configured patterns.
+// messages include all configured rules.
-func TestGuardCommand_Allowlist_ShowsPatterns(t *testing.T) {
+func TestGuardCommand_Allowlist_ShowsRules(t *testing.T) {
 	workspace := t.TempDir()
 	tool, _ := NewExecTool(workspace, true)
-	err := tool.SetAllowPatterns([]string{`^go\b`, `^git\b`})
+	tool.SetAllowRules([]string{"go test", "git"})
-	if err != nil {
-		t.Fatalf("SetAllowPatterns failed: %v", err)
-	}
 
 	result := tool.guardCommand("curl http://example.com", workspace)
 	if result == "" {
@@ -590,8 +587,8 @@ func TestGuardCommand_Allowlist_ShowsPatterns(t *testing.T) {
 	if !strings.Contains(result, "not in allowlist") {
 		t.Errorf("expected 'not in allowlist' in message, got: %s", result)
 	}
-	if !strings.Contains(result, `^go\b`) || !strings.Contains(result, `^git\b`) {
+	if !strings.Contains(result, "go test") || !strings.Contains(result, "git") {
-		t.Errorf("expected allowlist patterns in message, got: %s", result)
+		t.Errorf("expected allowlist rules in message, got: %s", result)
 	}
 }
 
@@ -1054,7 +1051,7 @@ func TestCheckCurlLocalNet(t *testing.T) {
 
 // TestExecTool_LocalNetOnly verifies curl/wget blocking via SetLocalNetOnly.
 func TestExecTool_LocalNetOnly(t *testing.T) {
-	tool := NewExecTool("", false)
+	tool, _ := NewExecTool("", false)
 	tool.SetLocalNetOnly(true)
 
 	tests := []struct {

pkg/tools/subagent.go

@@ -3,6 +3,9 @@ package tools
 import (
 	"context"
 	"fmt"
+	"sort"
+	"strconv"
+	"strings"
 	"sync"
 	"time"
 
@@ -21,6 +24,10 @@ type SubagentTask struct {
 	Status        string
 	Result        string
 	Created       int64
+	CompletedAt   int64          `json:"-"`
+	Iterations    int            `json:"-"`
+	ToolCalls     int            `json:"-"`
+	ToolStats     map[string]int `json:"-"`
 }
 
 type SubagentManager struct {
@@ -241,14 +248,19 @@ After completing, provide a clear summary of what was done and how it was verifi
 	} else {
 		task.Status = "completed"
 		task.Result = loopResult.Content
+		task.CompletedAt = time.Now().UnixMilli()
+		task.Iterations = loopResult.Iterations
+		task.ToolCalls = loopResult.ToolCalls
+		task.ToolStats = loopResult.ToolStats
 		// Notify conductor of the result
 		sm.reporter.ReportConversation(task.ID, "conductor", loopResult.Content)
 		sm.reporter.ReportGC(task.ID, "completed")
 		result = &ToolResult{
 			ForLLM: fmt.Sprintf(
-				"Subagent '%s' completed (iterations: %d): %s",
+				"Subagent '%s' completed (iterations: %d, tool calls: %d): %s",
 				task.Label,
 				loopResult.Iterations,
+				loopResult.ToolCalls,
 				loopResult.Content,
 			),
 			ForUser: loopResult.Content,
@@ -261,6 +273,14 @@ After completing, provide a clear summary of what was done and how it was verifi
 	// Send announce message back to main agent
 	if sm.bus != nil {
 		announceContent := fmt.Sprintf("Task '%s' completed.\n\nResult:\n%s", task.Label, task.Result)
+		metadata := map[string]string{
+			"duration_ms": strconv.FormatInt(task.CompletedAt-task.Created, 10),
+			"iterations":  strconv.Itoa(task.Iterations),
+			"tool_calls":  strconv.Itoa(task.ToolCalls),
+		}
+		if len(task.ToolStats) > 0 {
+			metadata["tool_stats"] = formatToolStats(task.ToolStats)
+		}
 		pubCtx, pubCancel := context.WithTimeout(context.Background(), 5*time.Second)
 		defer pubCancel()
 		sm.bus.PublishInbound(pubCtx, bus.InboundMessage{
@@ -269,6 +289,7 @@ After completing, provide a clear summary of what was done and how it was verifi
 			// Format: "original_channel:original_chat_id" for routing back
 			ChatID:   fmt.Sprintf("%s:%s", task.OriginChannel, task.OriginChatID),
 			Content:  announceContent,
+			Metadata: metadata,
 		})
 	}
 }
@@ -481,8 +502,8 @@ func (t *SubagentTool) Execute(ctx context.Context, args map[string]any) *ToolRe
 	if labelStr == "" {
 		labelStr = "(unnamed)"
 	}
-	llmContent := fmt.Sprintf("Subagent task completed:\nLabel: %s\nIterations: %d\nResult: %s",
+	llmContent := fmt.Sprintf("Subagent task completed:\nLabel: %s\nIterations: %d\nTool calls: %d\nResult: %s",
-		labelStr, loopResult.Iterations, loopResult.Content)
+		labelStr, loopResult.Iterations, loopResult.ToolCalls, loopResult.Content)
 
 	return &ToolResult{
 		ForLLM:  llmContent,
@@ -492,3 +513,18 @@ func (t *SubagentTool) Execute(ctx context.Context, args map[string]any) *ToolRe
 		Async:   false,
 	}
 }
+
+// formatToolStats formats a tool stats map as a compact string: "exec:3,read_file:5".
+// Keys are sorted alphabetically for deterministic output.
+func formatToolStats(stats map[string]int) string {
+	keys := make([]string, 0, len(stats))
+	for k := range stats {
+		keys = append(keys, k)
+	}
+	sort.Strings(keys)
+	parts := make([]string, 0, len(keys))
+	for _, k := range keys {
+		parts = append(parts, k+":"+strconv.Itoa(stats[k]))
+	}
+	return strings.Join(parts, ",")
+}

pkg/tools/subagent_tool_test.go

@@ -4,6 +4,7 @@ import (
 	"context"
 	"strings"
 	"testing"
+	"time"
 
 	"github.com/sipeed/picoclaw/pkg/bus"
 	"github.com/sipeed/picoclaw/pkg/orch"
@@ -355,3 +356,65 @@ func TestSubagentTool_ForUserTruncation(t *testing.T) {
 		t.Error("ForLLM should contain reference to original task")
 	}
 }
+
+func TestFormatToolStats(t *testing.T) {
+	tests := []struct {
+		name  string
+		stats map[string]int
+		want  string
+	}{
+		{"empty", map[string]int{}, ""},
+		{"single", map[string]int{"exec": 3}, "exec:3"},
+		{"multiple sorted", map[string]int{"read_file": 5, "exec": 3, "write_file": 1}, "exec:3,read_file:5,write_file:1"},
+	}
+	for _, tt := range tests {
+		t.Run(tt.name, func(t *testing.T) {
+			got := formatToolStats(tt.stats)
+			if got != tt.want {
+				t.Errorf("formatToolStats(%v) = %q, want %q", tt.stats, got, tt.want)
+			}
+		})
+	}
+}
+
+// TestSubagentManager_Spawn_SetsMetadata verifies that the bus message from a
+// completed spawn includes execution statistics in Metadata.
+func TestSubagentManager_Spawn_SetsMetadata(t *testing.T) {
+	provider := &MockLLMProvider{}
+	msgBus := bus.NewMessageBus()
+	mgr := NewSubagentManager(provider, "test-model", "/tmp/test", msgBus, orch.Noop, WebSearchToolOptions{})
+
+	_, err := mgr.Spawn(
+		context.Background(),
+		"say hello", "meta-test", "", "cli", "direct", "",
+		nil,
+	)
+	if err != nil {
+		t.Fatalf("Spawn() error: %v", err)
+	}
+
+	// Consume the inbound message from the bus
+	ctx, cancel := context.WithTimeout(context.Background(), 3*time.Second)
+	defer cancel()
+	received, ok := msgBus.ConsumeInbound(ctx)
+	if !ok {
+		t.Fatal("timed out waiting for bus message")
+	}
+
+	if received.Channel != "system" {
+		t.Fatalf("expected channel 'system', got %q", received.Channel)
+	}
+	if received.Metadata == nil {
+		t.Fatal("Metadata should not be nil")
+	}
+	if received.Metadata["iterations"] != "1" {
+		t.Errorf("iterations = %q, want %q", received.Metadata["iterations"], "1")
+	}
+	if received.Metadata["tool_calls"] != "0" {
+		t.Errorf("tool_calls = %q, want %q", received.Metadata["tool_calls"], "0")
+	}
+	// duration_ms should be a non-negative number
+	if received.Metadata["duration_ms"] == "" {
+		t.Error("duration_ms should be present")
+	}
+}

pkg/tools/toolloop.go

@@ -36,6 +36,8 @@ type ToolLoopConfig struct {
 type ToolLoopResult struct {
 	Content    string
 	Iterations int
+	ToolCalls  int            // total tool call count across all iterations
+	ToolStats  map[string]int // tool name → call count
 }
 
 // RunToolLoop executes the LLM + tool call iteration loop.
@@ -52,6 +54,8 @@ func RunToolLoop(
 	}
 
 	iteration := 0
+	totalToolCalls := 0
+	toolStats := map[string]int{}
 	var finalContent string
 
 	for iteration < config.MaxIterations {
@@ -144,6 +148,8 @@ func RunToolLoop(
 					"iteration": iteration,
 				})
 			reporter.ReportStateChange(config.AgentID, orch.AgentStateToolCall, tc.Name)
+			totalToolCalls++
+			toolStats[tc.Name]++
 
 			// Execute tool (no async callback for subagents - they run independently)
 			var toolResult *ToolResult
@@ -172,5 +178,7 @@ func RunToolLoop(
 	return &ToolLoopResult{
 		Content:    finalContent,
 		Iterations: iteration,
+		ToolCalls:  totalToolCalls,
+		ToolStats:  toolStats,
 	}, nil
 }

pkg/tools/toolloop_reporter_test.go

@@ -163,6 +163,51 @@ func TestToolLoop_Reporter_ToolcallOrderedAfterWaiting(t *testing.T) {
 	}
 }
 
+// TestToolLoop_ToolCallStats verifies that ToolLoopResult.ToolCalls and
+// ToolStats are populated correctly after a tool call iteration.
+func TestToolLoop_ToolCallStats(t *testing.T) {
+	reg := NewToolRegistry()
+	reg.Register(&echoTool{})
+
+	result, err := RunToolLoop(context.Background(), ToolLoopConfig{
+		Provider:      &sequenceMockProvider{},
+		Model:         "test",
+		Tools:         reg,
+		MaxIterations: 5,
+	}, []providers.Message{{Role: "user", Content: "do it"}}, "cli", "direct")
+	if err != nil {
+		t.Fatalf("unexpected error: %v", err)
+	}
+	if result.ToolCalls != 1 {
+		t.Errorf("ToolCalls = %d, want 1", result.ToolCalls)
+	}
+	if result.ToolStats["echo_tool"] != 1 {
+		t.Errorf("ToolStats[echo_tool] = %d, want 1", result.ToolStats["echo_tool"])
+	}
+	if result.Iterations != 2 {
+		t.Errorf("Iterations = %d, want 2", result.Iterations)
+	}
+}
+
+// TestToolLoop_NoToolCalls_ZeroStats verifies that a direct answer (no tool
+// calls) produces zero ToolCalls and an empty ToolStats map.
+func TestToolLoop_NoToolCalls_ZeroStats(t *testing.T) {
+	result, err := RunToolLoop(context.Background(), ToolLoopConfig{
+		Provider:      &MockLLMProvider{},
+		Model:         "test",
+		MaxIterations: 1,
+	}, []providers.Message{{Role: "user", Content: "hi"}}, "cli", "direct")
+	if err != nil {
+		t.Fatalf("unexpected error: %v", err)
+	}
+	if result.ToolCalls != 0 {
+		t.Errorf("ToolCalls = %d, want 0", result.ToolCalls)
+	}
+	if len(result.ToolStats) != 0 {
+		t.Errorf("ToolStats = %v, want empty", result.ToolStats)
+	}
+}
+
 // TestToolLoop_Reporter_NoopImplementsInterface is a compile-time check that
 // orch.Noop satisfies the orch.AgentReporter interface accepted by
 // ToolLoopConfig.Reporter. If Noop ever stops implementing the interface the