From 372dd13bbb5e08c8a6fb4337ca078545ebcf8424 Mon Sep 17 00:00:00 2001 From: Roman Romenskyi Date: Fri, 30 Oct 2026 21:42:05 -0600 Subject: [PATCH 1/2] Goals: a met goal says how long the work took MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit When the judge confirms a goal, the agent now ends with "✓ goal met — worked 1h12m over 3 runs": the working time of every run at the goal (runDuration: approval waits left out), carried in goal.json across /goal go resumes and restarts, and how many runs that was. A goal replaced with different text starts its own count. Co-Authored-By: Claude Opus 5.5 --- README.md | 5 ++ cmd/agent/goal_time_test.go | 135 ++++++++++++++++++++++++++++++++++++ cmd/agent/main.go | 68 ++++++++++++++++-- cmd/agent/tui.go | 3 + 4 files changed, 205 insertions(+), 6 deletions(-) create mode 100644 cmd/agent/goal_time_test.go diff --git a/README.md b/README.md index 8e40d83..b7cd56a 100644 --- a/README.md +++ b/README.md @@ -824,6 +824,11 @@ any work, it gets **one** push to act before the loop gives up (turn it off with confirming success, it says so plainly — *"goal not confirmed complete, `/goal go` to keep pushing"* — instead of implying it's done. +When the judge confirms the goal, the agent says how long the work took: +*"✓ goal met — worked 1h12m over 3 runs"*. That counts the working time of +every run at the goal, across `/goal go` resumes and restarts, and leaves out +time spent waiting on an approval prompt. + ## Context & auto-compact The status bar shows `ctx 4.1k/8k` — the size of the last prompt vs. the model's diff --git a/cmd/agent/goal_time_test.go b/cmd/agent/goal_time_test.go new file mode 100644 index 0000000..ce763d0 --- /dev/null +++ b/cmd/agent/goal_time_test.go @@ -0,0 +1,135 @@ +package main + +import ( + "bufio" + "context" + "io" + "net/http" + "net/http/httptest" + "slices" + "strings" + "testing" + "time" + + "github.com/ipsupport-llc/ipsupport-code/internal/agent" + "github.com/ipsupport-llc/ipsupport-code/internal/config" +) + +// A met goal says how long it took: the working time of every run at it, +// across a restart, and how many runs that was. +func TestAMetGoalSaysHowLongItTook(t *testing.T) { + a := &app{workspace: t.TempDir(), cfg: config.Default()} + a.setGoal("ship it") + a.addGoalWork(40 * time.Minute) + a.finishGoal(agent.Transcript{}) // not met yet + + b := &app{workspace: a.workspace, cfg: config.Default()} // a restart + b.loadGoal() + b.setGoal("ship it") // /goal go resumes the same goal + b.addGoalWork(32*time.Minute + 20*time.Second) + met, worked, runs := b.finishGoal(agent.Transcript{GoalMet: true}) + if !met || worked != 72*time.Minute+20*time.Second || runs != 2 { + t.Fatalf("finishGoal = (%v, %v, %d), want met after 1h12m20s over 2 runs", met, worked, runs) + } + if got := goalDoneLine(worked, runs); got != "goal met — worked 1h12m over 2 runs" { + t.Errorf("line = %q", got) + } + + // A different goal starts its own count; a run with no goal counts nowhere. + b.setGoal("ship it") + b.addGoalWork(time.Hour) + b.setGoal("something else") + b.addGoalWork(5 * time.Second) + if _, worked, runs := b.finishGoal(agent.Transcript{GoalMet: true}); worked != 5*time.Second || runs != 1 { + t.Errorf("a replaced goal kept the old one's time: %v over %d", worked, runs) + } + b.addGoalWork(time.Minute) + if b.goal.Worked != 0 { + t.Error("time was counted with no goal standing") + } + // Not met: nothing to say yet. + b.setGoal("next") + if met, _, _ := b.finishGoal(agent.Transcript{}); met { + t.Error("an unmet goal reported as met") + } +} + +func TestWorkTimeReadsLikeAPerson(t *testing.T) { + for d, want := range map[time.Duration]string{ + 42 * time.Second: "42s", + 4*time.Minute + 5*time.Second: "4m05s", + 72*time.Minute + 29*time.Second: "1h12m", + 1500 * time.Millisecond: "2s", + 26*time.Hour + 3*time.Minute: "26h03m", + } { + if got := workTime(d); got != want { + t.Errorf("workTime(%v) = %q, want %q", d, got, want) + } + } + if got := goalDoneLine(30*time.Second, 1); got != "goal met — worked 30s" { + t.Errorf("one run: %q", got) + } +} + +// The TUI says it after the answer, from the goal_done event. +func TestTheGoalDoneEventIsShown(t *testing.T) { + m := &tuiModel{app: &app{cfg: config.Default()}} + lines := m.renderEvent(uiEvent{kind: "goal_done", fields: map[string]any{"worked": 4 * time.Minute, "runs": 3}}) + if len(lines) != 1 || !strings.Contains(lines[0], "goal met — worked 4m00s over 3 runs") { + t.Errorf("rendered %q", lines) + } +} + +type goalEvents struct { + kinds []string + done map[string]any +} + +func (g *goalEvents) Emit(kind string, f map[string]any) { + g.kinds = append(g.kinds, kind) + if kind == "goal_done" { + g.done = f + } +} + +// End to end: a run the judge confirms meets the goal ends with goal_done, after +// the answer, its time counted. +func TestARunThatMeetsTheGoalSaysSo(t *testing.T) { + setHome(t, t.TempDir()) + n := 0 + srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + if notFoundOffPOST(w, r) { + return + } + n++ + io.Copy(io.Discard, r.Body) + switch n { + case 1: + io.WriteString(w, toolCallRespWithUsage("calc", `{"expression":"1+1"}`, 10, 5)) + case 2: + io.WriteString(w, contentRespWithUsage("the answer", 10, 5)) + default: // the judge, then anything after + io.WriteString(w, contentRespWithUsage("DONE", 10, 5)) + } + })) + defer srv.Close() + a, cleanup, err := build(t.TempDir(), "", nil, false, bufio.NewReader(strings.NewReader(""))) + if err != nil { + t.Fatal(err) + } + defer cleanup() + a.cfg.LLM.BaseURL, a.cfg.LLM.Model = srv.URL, "fake" + if err := a.wire(); err != nil { + t.Fatal(err) + } + a.setGoal("do the thing") + ev := &goalEvents{} + a.tracer = ev + a.runTaskStreaming(context.Background(), "do the thing", a.taskEpoch.Load()) + if !slices.Contains(ev.kinds, "goal_done") { + t.Fatalf("events %v: no goal_done for a run the judge said met the goal", ev.kinds) + } + if worked, _ := ev.done["worked"].(time.Duration); worked <= 0 || ev.done["runs"] != 1 { + t.Errorf("goal_done = %v, want this run's time counted, one run", ev.done) + } +} diff --git a/cmd/agent/main.go b/cmd/agent/main.go index dd4cc6d..40481a3 100644 --- a/cmd/agent/main.go +++ b/cmd/agent/main.go @@ -1659,6 +1659,45 @@ type goalState struct { // amend it for the judge and every re-feed, across resumes. Cleared with // the goal, or when it is replaced with different text. Corrections []string `json:"corrections,omitempty"` + // Worked is the time runs spent on this goal, across every resume and + // restart, approval waits left out; Runs is how many there were. Both are + // said when the goal is met. Cleared with the goal, or when it is replaced + // with different text. + Worked time.Duration `json:"worked_ns,omitempty"` + Runs int `json:"runs,omitempty"` +} + +// addGoalWork counts a finished run's working time toward the standing goal. +func (a *app) addGoalWork(d time.Duration) { + a.statusMu.Lock() + if a.goal.Status != "" { + a.goal.Worked += d + a.goal.Runs++ + } + a.statusMu.Unlock() +} + +// goalDoneLine says a met goal took how long: its runs' working time, not the +// days it may have stood between them. +func goalDoneLine(worked time.Duration, runs int) string { + s := "goal met — worked " + workTime(worked) + if runs > 1 { + s += fmt.Sprintf(" over %d runs", runs) + } + return s +} + +// workTime is a duration as a person reads it: 1h12m, 4m05s, 42s. +func workTime(d time.Duration) string { + d = d.Round(time.Second) + h, m, s := int(d.Hours()), int(d.Minutes())%60, int(d.Seconds())%60 + switch { + case h > 0: + return fmt.Sprintf("%dh%02dm", h, m) + case m > 0: + return fmt.Sprintf("%dm%02ds", m, s) + } + return fmt.Sprintf("%ds", s) } // target is the goal as the judge accepts it: its text, amended by the user's @@ -1849,11 +1888,14 @@ func (a *app) setGoal(text string) { // and every subsequent run counts toward it — until the judge confirms it met, // or the user explicitly turns it off (/goal off) or clears it (/goal clear). // No other condition (text match, /btw, a clarifying follow-up) knocks it out. -func (a *app) finishGoal(tr agent.Transcript) { +// +// It reports whether the goal was met just now, and if so how long it took +// (see addGoalWork). +func (a *app) finishGoal(tr agent.Transcript) (met bool, worked time.Duration, runs int) { a.statusMu.Lock() if a.goal.Status == "" { a.statusMu.Unlock() - return + return false, 0, 0 } // With the judge loop off (/goal off · ttl 0) GoalMet is never set — the model // decides when it's done, so a clean uninterrupted finish counts as done @@ -1871,6 +1913,7 @@ func (a *app) finishGoal(tr agent.Transcript) { done := !tr.Cancelled && tr.GoalMet if done { // Done: clear it entirely so it never resurfaces after a restart. + worked, runs = a.goal.Worked, a.goal.Runs a.goal = goalState{} } else { // Still unfinished: re-arm one resume offer for the next restart (you @@ -1895,11 +1938,12 @@ func (a *app) finishGoal(tr agent.Transcript) { a.statusMu.Unlock() if done { os.Remove(a.goalPath()) - return + return true, worked, runs } if err := a.saveGoal(); err != nil { slog.Warn("goal status not persisted", "err", err) } + return false, 0, 0 } // markGoalOffered records that the standing goal has been surfaced once after a @@ -4513,6 +4557,9 @@ func (a *app) runOne(ctx context.Context, goal string) error { start := time.Now() tr, err := a.ag.Run(ctx, goal) dur := a.runDuration(start, waitSnapshot) + if !a.readOnly { // a read-only task isn't working on the standing goal + a.addGoalWork(dur) + } if err != nil { a.recordUsage(dur) // the failed attempt may have burned real tokens — don't drop them slog.Error("run failed", "err", err) @@ -4521,8 +4568,11 @@ func (a *app) runOne(ctx context.Context, goal string) error { } a.lastRealContext = tr.PromptTokens // snapshot the real fullness before reflectAndStore (below) can clobber the shared client's own Context() a.recordRun(tr) - if !a.readOnly { // a read-only task isn't working on the standing goal - a.finishGoal(tr) + var met bool + var worked time.Duration + var runs int + if !a.readOnly { + met, worked, runs = a.finishGoal(tr) } a.recordUsage(dur) a.saveSession() // the conversation is decided now — save it before the slower, @@ -4533,6 +4583,9 @@ func (a *app) runOne(ctx context.Context, goal string) error { } else { fmt.Println("(no final answer — step budget exhausted)") } + if met { + fmt.Println("✓ " + goalDoneLine(worked, runs)) + } // Not gated on tr.Stopped any more: a run the harness stopped after repeated // failures is the one that can teach an "avoid" lesson, and excluding it made // that whole lesson kind unreachable (internal/reflect takes a deliberately @@ -4595,6 +4648,7 @@ func (a *app) runTaskStreaming(ctx context.Context, goal string, epoch int64) (a if a.taskEpoch.Load() != epoch { return agent.Transcript{}, false // force-detached mid-run — its results belong to a run the UI abandoned } + a.addGoalWork(dur) if err != nil { a.recordUsage(dur) // the failed attempt may have burned real tokens — don't drop them a.emit("error", map[string]any{"text": err.Error()}) @@ -4602,7 +4656,9 @@ func (a *app) runTaskStreaming(ctx context.Context, goal string, epoch int64) (a } a.lastRealContext = tr.PromptTokens // the real fullness of the task's own client, before anything else touches it a.recordRun(tr) - a.finishGoal(tr) + if met, worked, runs := a.finishGoal(tr); met { + a.emit("goal_done", map[string]any{"worked": worked, "runs": runs}) + } a.recordUsage(dur) a.saveSession() // the conversation is decided now — save it before the slower, // best-effort reflection the caller runs next. That matters because /exit quits diff --git a/cmd/agent/tui.go b/cmd/agent/tui.go index 015278a..23caf91 100644 --- a/cmd/agent/tui.go +++ b/cmd/agent/tui.go @@ -3305,6 +3305,9 @@ func (m *tuiModel) renderEvent(e uiEvent) []string { // "the model is done" and "the model gave up" read the same in dim grey. why, _ := e.fields["why"].(string) return []string{judgingLine(why)} + case "goal_done": + worked, _ := e.fields["worked"].(time.Duration) + return []string{cOk.Render(" ✓ " + goalDoneLine(worked, toInt(e.fields["runs"])))} case "judge": if done, _ := e.fields["done"].(bool); done { return []string{cOk.Render(" ✓ judge: goal met")} From 51f51c7e57bcc0d7684c18df45014a56fcddb560 Mon Sep 17 00:00:00 2001 From: Roman Romenskyi Date: Fri, 30 Oct 2026 21:49:08 -0600 Subject: [PATCH 2/2] Goals: a failed run's working time is saved too addGoalWork saves the goal: a run that failed never reached finishGoal's save, and its time was lost to the next restart. Co-Authored-By: Claude Opus 5.5 --- cmd/agent/goal_time_test.go | 3 +-- cmd/agent/main.go | 13 +++++++++++-- 2 files changed, 12 insertions(+), 4 deletions(-) diff --git a/cmd/agent/goal_time_test.go b/cmd/agent/goal_time_test.go index ce763d0..2584dc3 100644 --- a/cmd/agent/goal_time_test.go +++ b/cmd/agent/goal_time_test.go @@ -20,8 +20,7 @@ import ( func TestAMetGoalSaysHowLongItTook(t *testing.T) { a := &app{workspace: t.TempDir(), cfg: config.Default()} a.setGoal("ship it") - a.addGoalWork(40 * time.Minute) - a.finishGoal(agent.Transcript{}) // not met yet + a.addGoalWork(40 * time.Minute) // a run that failed: finishGoal never ran b := &app{workspace: a.workspace, cfg: config.Default()} // a restart b.loadGoal() diff --git a/cmd/agent/main.go b/cmd/agent/main.go index 40481a3..14dbe39 100644 --- a/cmd/agent/main.go +++ b/cmd/agent/main.go @@ -1667,14 +1667,23 @@ type goalState struct { Runs int `json:"runs,omitempty"` } -// addGoalWork counts a finished run's working time toward the standing goal. +// addGoalWork counts a finished run's working time toward the standing goal, +// and saves it: a run that failed never reaches finishGoal's save, and its time +// was lost to the next restart. func (a *app) addGoalWork(d time.Duration) { a.statusMu.Lock() - if a.goal.Status != "" { + standing := a.goal.Status != "" + if standing { a.goal.Worked += d a.goal.Runs++ } a.statusMu.Unlock() + if !standing { + return + } + if err := a.saveGoal(); err != nil { + slog.Warn("goal not persisted", "err", err) + } } // goalDoneLine says a met goal took how long: its runs' working time, not the