Vectrum
Sign In
CodeyPublic
Like0 likesFork0 forks

Merge ai-response-duration: an answer says how long it took

Browse Files
Jjonicommitted 2 parents ace279a 2960389commitaa469ba

Showing 4 changed files with 150 additions and 1 deletion.

Merge commit — showing changes against the first parent.

+4−1README.mdView File
@@ -140,7 +140,10 @@ above a prompt:
140140 Every event hangs off a dot in the left gutter, and everything belonging to it
141141 is indented under that dot, so a screen of tool output still reads as a
142142 sequence of things that happened. Diffs are shown in full and in colour with a
143- count of what changed; other output is elided after six lines.
143+ count of what changed; other output is elided after six lines. A finished
144+ answer closes with how long it took — `took 1m 30s · 3 turns` — because the
145+ activity line counts those seconds only while the turn runs, and that number
146+ is worth keeping in the scrollback beside the answer it paid for.
144147
145148 What the model says is Markdown, and it is rendered as Markdown — headings,
146149 weight, lists, block quotes, rules, and tables laid out in columns:
+104−0internal/tui/duration_test.goaddedView File
@@ -0,0 +1,104 @@
1+ package tui
2+
3+ import (
4+ "context"
5+ "strings"
6+ "testing"
7+ "time"
8+
9+ "github.com/charmbracelet/x/ansi"
10+ )
11+
12+ func TestElapsed(t *testing.T) {
13+ cases := []struct {
14+ d time.Duration
15+ want string
16+ }{
17+ {0, "0.0s"},
18+ {-time.Second, "0.0s"},
19+ {1500 * time.Millisecond, "1.5s"},
20+ {59900 * time.Millisecond, "59.9s"},
21+ {time.Minute, "1m 0s"},
22+ {72 * time.Second, "1m 12s"},
23+ {59*time.Minute + 59*time.Second, "59m 59s"},
24+ {time.Hour, "1h 0m"},
25+ {2*time.Hour + 5*time.Minute, "2h 5m"},
26+ }
27+ for _, tc := range cases {
28+ if got := elapsed(tc.d); got != tc.want {
29+ t.Errorf("elapsed(%v) = %q, want %q", tc.d, got, tc.want)
30+ }
31+ }
32+ }
33+
34+ // The turn's own timer is what the status line counted while it ran; when the
35+ // turn ends that line is gone, so the number has to land in the scrollback.
36+ func TestTurnDoneReportsHowLongItTook(t *testing.T) {
37+ m := newTestModel(t)
38+ m.opts.SessionDir = t.TempDir()
39+ m.phase = phaseRunning
40+ m.started = time.Now().Add(-90 * time.Second)
41+ m.turn = 3
42+
43+ m.Update(turnDone{})
44+
45+ got := ansi.Strip(m.tr.render())
46+ if !strings.Contains(got, "took 1m 30s") {
47+ t.Errorf("transcript does not report the duration:\n%s", got)
48+ }
49+ if !strings.Contains(got, "3 turns") {
50+ t.Errorf("transcript does not report the turn count:\n%s", got)
51+ }
52+ }
53+
54+ // One turn of the tool loop is the ordinary case and says nothing worth a
55+ // second field.
56+ func TestTurnDoneOmitsASingleTurnCount(t *testing.T) {
57+ m := newTestModel(t)
58+ m.opts.SessionDir = t.TempDir()
59+ m.phase = phaseRunning
60+ m.started = time.Now().Add(-2 * time.Second)
61+ m.turn = 1
62+
63+ m.Update(turnDone{})
64+
65+ got := ansi.Strip(m.tr.render())
66+ if !strings.Contains(got, "took 2.0s") {
67+ t.Errorf("transcript does not report the duration:\n%s", got)
68+ }
69+ if strings.Contains(got, "turns") {
70+ t.Errorf("a one-turn answer reported a turn count:\n%s", got)
71+ }
72+ }
73+
74+ // An interrupted turn still took the time it took, and the report lands under
75+ // the notice that says it was cut short rather than replacing it.
76+ func TestInterruptedTurnStillReportsDuration(t *testing.T) {
77+ m := newTestModel(t)
78+ m.opts.SessionDir = t.TempDir()
79+ m.phase = phaseRunning
80+ m.started = time.Now().Add(-5 * time.Second)
81+
82+ m.Update(turnDone{err: context.Canceled})
83+
84+ got := ansi.Strip(m.tr.render())
85+ if !strings.Contains(got, "interrupted") {
86+ t.Fatalf("the interruption went unreported:\n%s", got)
87+ }
88+ if i, j := strings.Index(got, "interrupted"), strings.Index(got, "took 5.0s"); j < i {
89+ t.Errorf("the duration is not under the answer it belongs to:\n%s", got)
90+ }
91+ }
92+
93+ // A turnDone with no run behind it has nothing to time, and a duration
94+ // measured from the zero time would be nonsense.
95+ func TestTurnDoneWithoutATimerSaysNothing(t *testing.T) {
96+ m := newTestModel(t)
97+ m.opts.SessionDir = t.TempDir()
98+
99+ m.Update(turnDone{})
100+
101+ if got := ansi.Strip(m.tr.render()); strings.Contains(got, "took ") {
102+ t.Errorf("an untimed turn reported a duration:\n%s", got)
103+ }
104+ }
+17−0internal/tui/format.goView File
@@ -5,6 +5,7 @@ import (
55 "net/url"
66 "os"
77 "strings"
8+ "time"
89 "unicode"
910
1011 "codey/internal/llm"
@@ -21,6 +22,22 @@ func human(n int) string {
2122 return fmt.Sprint(n)
2223 }
2324
25+ // elapsed renders how long something ran, in the coarsest unit that still
26+ // says something useful. Under a minute is the common answer and keeps a
27+ // decimal, because the difference between 3.2s and 3.9s is one a person
28+ // notices; past that the tenths stop mattering and the minutes start.
29+ func elapsed(d time.Duration) string {
30+ switch {
31+ case d < 0:
32+ return "0.0s"
33+ case d < time.Minute:
34+ return fmt.Sprintf("%.1fs", d.Seconds())
35+ case d < time.Hour:
36+ return fmt.Sprintf("%dm %ds", int(d/time.Minute), int(d%time.Minute/time.Second))
37+ }
38+ return fmt.Sprintf("%dh %dm", int(d/time.Hour), int(d%time.Hour/time.Minute))
39+ }
40+
2441 // prettyModel turns an API model id into the name a person uses for it:
2542 // claude-opus-5 becomes "Opus 5", claude-haiku-4-5-20251001 becomes
2643 // "Haiku 4.5". An id that does not fit the shape is returned unchanged, which
+25−0internal/tui/model.goView File
@@ -891,6 +891,16 @@ func (m *model) finishTurn(msg turnDone) tea.Cmd {
891891 default:
892892 m.tr.addError(msg.err.Error())
893893 }
894+
895+ // How long that took, under the answer it belongs to. The activity line
896+ // counted the seconds while the turn ran and is gone the moment it ends,
897+ // so without this the one number you wanted to keep is the one the screen
898+ // throws away.
899+ if took := m.turnTook(); took != "" {
900+ m.tr.addNotice(took)
901+ }
902+ m.started = time.Time{}
903+
894904 if !m.bar.hasKeys() {
895905 m.input.Focus()
896906 }
@@ -898,6 +908,21 @@ func (m *model) finishTurn(msg turnDone) tea.Cmd {
898908 return tea.Batch(m.sync(), textarea.Blink, m.deliverReports())
899909 }
900910
911+ // turnTook reports how long the answer took, and over how many turns of the
912+ // tool loop when it took more than one. It is empty when nothing timed the
913+ // turn — a turnDone with no run behind it — because a duration measured from
914+ // the zero time is worse than no duration at all.
915+ func (m *model) turnTook() string {
916+ if m.started.IsZero() {
917+ return ""
918+ }
919+ s := "took " + elapsed(time.Since(m.started))
920+ if m.turn > 1 {
921+ s += fmt.Sprintf(" · %d turns", m.turn)
922+ }
923+ return s
924+ }
925+
901926 func (m *model) onKey(msg tea.KeyMsg) (tea.Model, tea.Cmd) {
902927 if m.phase == phaseApproving {
903928 return m.onApprovalKey(msg)