Vectrum
Sign In
CodeyPublic
Like0 likesFork0 forks

metrics: stamp every event with the agent that produced it

Several agents write to one log now. Logger.For(id) derives a logger that
shares the writer and its lock — one file, one mutex, whole lines — and adds
the agent id to everything it writes, so events.jsonl can be split per agent
afterwards. The session's own logger is unchanged and unmarked.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Browse Files
Jjonicommitted 1 parent e40c80ccommitcb063ce

Showing 2 changed files with 103 additions and 11 deletions.

+52−11internal/metrics/log.goView File
@@ -71,13 +71,42 @@ func (e Event) MarshalJSON() ([]byte, error) {
7171 return json.Marshal(m)
7272 }
7373
74+ // sink is the writer a logger and everything derived from it share. Derived
75+ // loggers exist so a subagent can stamp its id on every line without opening a
76+ // second file, and sharing the lock is what keeps their lines whole.
77+ type sink struct {
78+ mu sync.Mutex
79+ w io.Writer
80+ closer io.Closer
81+ }
82+
7483 // Logger appends events to a writer. The zero value and a nil *Logger are both
7584 // usable and simply drop events, so callers never need a nil check.
7685 type Logger struct {
77- mu sync.Mutex
78- w io.Writer
79- closer io.Closer
86+ sink *sink
8087 session string
88+ // agent is the subagent this logger belongs to, empty for the session's
89+ // own. It is stamped into every event so one log file can be split by
90+ // agent afterwards.
91+ agent string
92+ }
93+
94+ // For returns a logger that stamps every event with an agent id and writes to
95+ // the same place this one does. Closing the original closes both; a derived
96+ // logger owns no file of its own.
97+ func (l *Logger) For(agent string) *Logger {
98+ if l == nil {
99+ return nil
100+ }
101+ return &Logger{sink: l.sink, session: l.session, agent: agent}
102+ }
103+
104+ // Agent reports which subagent this logger stamps, empty for the session's own.
105+ func (l *Logger) Agent() string {
106+ if l == nil {
107+ return ""
108+ }
109+ return l.agent
81110 }
82111
83112 // Open appends to path, creating parent directories as needed.
@@ -91,13 +120,13 @@ func Open(path, session string) (*Logger, error) {
91120 if err != nil {
92121 return nil, fmt.Errorf("metrics: %w", err)
93122 }
94- return &Logger{w: f, closer: f, session: session}, nil
123+ return &Logger{sink: &sink{w: f, closer: f}, session: session}, nil
95124 }
96125
97126 // NewWriter logs to an arbitrary writer. Useful in tests and in the eval runner,
98127 // which keeps a separate log per run.
99128 func NewWriter(w io.Writer, session string) *Logger {
100- return &Logger{w: w, session: session}
129+ return &Logger{sink: &sink{w: w}, session: session}
101130 }
102131
103132 // Session returns the session id stamped onto every event.
@@ -111,7 +140,7 @@ func (l *Logger) Session() string {
111140 // Log writes one event. Errors are dropped: a broken metrics file must never
112141 // take down a run.
113142 func (l *Logger) Log(ev Event) {
114- if l == nil || l.w == nil {
143+ if l == nil || l.sink == nil || l.sink.w == nil {
115144 return
116145 }
117146 if ev.Time.IsZero() {
@@ -120,13 +149,25 @@ func (l *Logger) Log(ev Event) {
120149 if ev.Session == "" {
121150 ev.Session = l.session
122151 }
152+ if l.agent != "" {
153+ // A copy, because the caller's map is theirs: stamping it in place
154+ // would mutate a map they may reuse or share with another goroutine.
155+ extra := make(map[string]any, len(ev.Extra)+1)
156+ for k, v := range ev.Extra {
157+ extra[k] = v
158+ }
159+ if _, taken := extra["agent"]; !taken {
160+ extra["agent"] = l.agent
161+ }
162+ ev.Extra = extra
163+ }
123164 b, err := json.Marshal(ev)
124165 if err != nil {
125166 return
126167 }
127- l.mu.Lock()
128- defer l.mu.Unlock()
129- l.w.Write(append(b, '\n'))
168+ l.sink.mu.Lock()
169+ defer l.sink.mu.Unlock()
170+ l.sink.w.Write(append(b, '\n'))
130171 }
131172
132173 // ToolCall records one dispatch. err nil means success.
@@ -147,8 +188,8 @@ func (l *Logger) ToolCall(name string, d time.Duration, err error, extra map[str
147188
148189 // Close closes the underlying file, if there is one.
149190 func (l *Logger) Close() error {
150- if l == nil || l.closer == nil {
191+ if l == nil || l.sink == nil || l.sink.closer == nil {
151192 return nil
152193 }
153- return l.closer.Close()
194+ return l.sink.closer.Close()
154195 }
+51−0internal/metrics/log_test.goView File
@@ -146,3 +146,54 @@ func TestConcurrentLogLinesStayIntact(t *testing.T) {
146146 decode(t, ln)
147147 }
148148 }
149+
150+ // Subagents write to the same log as the session that spawned them, so every
151+ // line they produce has to say which agent it came from — otherwise four
152+ // agents' tool calls are one indistinguishable stream.
153+ func TestForStampsTheAgentOnEveryEvent(t *testing.T) {
154+ var buf bytes.Buffer
155+ l := NewWriter(&buf, "sess")
156+ child := l.For("a1")
157+
158+ l.Log(Event{Type: "turn"})
159+ child.Log(Event{Type: "turn"})
160+ child.ToolCall("bash", time.Millisecond, nil, map[string]any{"output_bytes": 3})
161+
162+ lines := strings.Split(strings.TrimSpace(buf.String()), "\n")
163+ if len(lines) != 3 {
164+ t.Fatalf("wrote %d lines, want 3:\n%s", len(lines), buf.String())
165+ }
166+ if strings.Contains(lines[0], `"agent"`) {
167+ t.Errorf("the session's own event carries an agent field: %s", lines[0])
168+ }
169+ for _, line := range lines[1:] {
170+ if !strings.Contains(line, `"agent":"a1"`) {
171+ t.Errorf("child event missing its agent: %s", line)
172+ }
173+ if !strings.Contains(line, `"session":"sess"`) {
174+ t.Errorf("child event lost the session: %s", line)
175+ }
176+ }
177+ }
178+
179+ // A derived logger is the same log, not a copy of it: everything lands in one
180+ // file, in the order it happened.
181+ func TestForSharesTheWriter(t *testing.T) {
182+ var buf bytes.Buffer
183+ l := NewWriter(&buf, "sess")
184+ l.For("a1").Log(Event{Type: "first"})
185+ l.Log(Event{Type: "second"})
186+
187+ if got := strings.Count(buf.String(), "\n"); got != 2 {
188+ t.Fatalf("want both events in one writer, got %d lines", got)
189+ }
190+ if i, j := strings.Index(buf.String(), "first"), strings.Index(buf.String(), "second"); i > j {
191+ t.Error("events landed out of order")
192+ }
193+ }
194+
195+ // The nil logger is usable everywhere, and deriving from it must stay usable.
196+ func TestForOnANilLoggerStillDrops(t *testing.T) {
197+ var l *Logger
198+ l.For("a1").Log(Event{Type: "turn"})
199+ }