Record the node, reply size, and time of each call

Each line of usage.jsonl also gives the length of the call in seconds,
the size of the text of the reply in bytes, and, for a compaction, the
node [l, i] that it builds. With these fields the records show the size
of each try of a node, the time per call, and how many calls ran at
once, also when eight builds run in parallel and the order of the calls
no longer tells which node a call belongs to.

The compactor names the node on its requests. The node goes only to the
usage file and never to the endpoint.

Issue: b14d537

diff --git a/compactor.go b/compactor.go
index ac5fd1d56541e416e981c013cbe20f289afb281a..16303b0c342cc7a45784754076501e53344918e2 100644 (file)
--- a/compactor.go
+++ b/compactor.go
@@ -68,6 +68,7 @@ func (c *Compactor) Summarize(ctx context.Context, task Task) (string, error) {
                        Instructions: c.instructions,
                        Tools:        c.tools,
                        Input:        []any{userMessage(parts...)},
+                       Node:         &nodeKey{task.Level, task.Index},
                })
                if err != nil {
                        break

diff --git a/compactor_test.go b/compactor_test.go
index cd6311ad52b612b21f802024a528e5afc143a799..35e09eb28b4562530af8dae474fa13d62b49ad8f 100644 (file)
--- a/compactor_test.go
+++ b/compactor_test.go
@@ -72,11 +72,19 @@ func TestCompactorRetriesALongLineWithTheNewestNote(t *testing.T) {
                writeEvents(w, completedEvent([]any{messageItem(long[call.number])}, 100, 0, 5))
        }
 
-       line, err := newTestCompactor(t, server).Summarize(t.Context(), leafTask())
+       compactor := newTestCompactor(t, server)
+       line, err := compactor.Summarize(t.Context(), leafTask())
        require.NoError(t, err)
        require.Equal(t, long[2], line)
        require.Equal(t, 3, server.Calls())
 
+       records := readUsage(t, compactor.client.usage.path)
+       require.Len(t, records, 3)
+       for n, record := range records {
+               require.Equal(t, &[2]int{0, 0}, record.Node)
+               require.Equal(t, len(long[n]), record.TextBytes)
+       }
+
        first := inputParts(t, server.Call(0))
        require.Len(t, first, 2)
        for n, want := range []string{long[0], long[1]} {

diff --git a/responses.go b/responses.go
index 096439f5cc9564d92f8fcfed7636ae60960c91a6..fddec7378650a7ca9c25e6ac1c960f5f53313f19 100644 (file)
--- a/responses.go
+++ b/responses.go
@@ -66,13 +66,16 @@ type Client struct {
 }
 
 // Request is one model call. Input holds the input items in order, such as
-// userMessage values or output items of an earlier response.
+// userMessage values or output items of an earlier response. Node names the
+// node that a compaction builds, or is nil. It goes only to the usage file,
+// never to the endpoint.
 type Request struct {
        Model        string
        Effort       string
        Instructions string
        Tools        []Tool
        Input        []any
+       Node         *nodeKey
 }
 
 // Tool is the definition of a function tool.
@@ -224,19 +227,26 @@ func (c *Client) Create(ctx context.Context, request Request) (Response, error)
                httpRequest.Header.Set("session_id", c.cacheKey)
        }
 
+       start := time.Now()
        record := usageRecord{
-               Date:  time.Now().Format(time.RFC3339Nano),
+               Date:  start.Format(time.RFC3339Nano),
                Model: request.Model,
        }
 
+       if request.Node != nil {
+               record.Node = &[2]int{request.Node.level, request.Node.index}
+       }
+
        response, err := c.send(httpRequest, &record)
        if err != nil {
                record.Error = err.Error()
        }
 
+       record.Seconds = time.Since(start).Seconds()
        record.InputTokens = response.Usage.Input
        record.CachedTokens = response.Usage.Cached
        record.OutputTokens = response.Usage.Output
+       record.TextBytes = len(response.Text)
 
        return response, errors.Join(err, c.usage.Write(record))
 }
@@ -272,16 +282,21 @@ type usageLog struct {
        path  string
 }
 
-// usageRecord is one line of usage.jsonl. Status is the HTTP status, or 0 when
-// no response came. Quota holds the x-codex-* headers of the response, without
-// the turn state.
+// usageRecord is one line of usage.jsonl. Date is the start of the call, and
+// Seconds its length. Node is the node [l, i] of a compaction. Status is the
+// HTTP status, or 0 when no response came. TextBytes is the size of the text of
+// the reply. Quota holds the x-codex-* headers of the response, without the
+// turn state.
 type usageRecord struct {
        Date         string            `json:"date"`
+       Seconds      float64           `json:"seconds"`
        Model        string            `json:"model"`
+       Node         *[2]int           `json:"node,omitempty"`
        Status       int               `json:"status"`
        InputTokens  int               `json:"input_tokens"`
        CachedTokens int               `json:"cached_tokens"`
        OutputTokens int               `json:"output_tokens"`
+       TextBytes    int               `json:"text_bytes"`
        Quota        map[string]string `json:"quota,omitempty"`
        Error        string            `json:"error,omitempty"`
 }

diff --git a/responses_test.go b/responses_test.go
index de928bd426ccd0f32f9ddfa0274d448fe1cb183a..6017ad791e03f64859d5331ffeb911e80b4885c0 100644 (file)
--- a/responses_test.go
+++ b/responses_test.go
@@ -151,8 +151,12 @@ func TestClientRecordsEachCall(t *testing.T) {
        }
 
        client := newTestClient(t, server)
-       _, err := client.Create(t.Context(), testRequest())
+       request := testRequest()
+       request.Node = &nodeKey{2, 5}
+       _, err := client.Create(t.Context(), request)
        require.NoError(t, err)
+       require.NotContains(t, server.Call(0).body, "node")
+       require.NotContains(t, string(server.Call(0).raw), "[2,5]")
 
        _, err = client.Create(t.Context(), testRequest())
        require.ErrorContains(t, err, "HTTP 429")
@@ -171,9 +175,15 @@ func TestClientRecordsEachCall(t *testing.T) {
        require.Equal(t, 400, records[0].CachedTokens)
        require.Equal(t, 7, records[0].OutputTokens)
        require.Equal(t, quota, records[0].Quota)
+       require.Equal(t, &[2]int{2, 5}, records[0].Node)
+       require.Equal(t, len("ok"), records[0].TextBytes)
+       require.Greater(t, records[0].Seconds, 0.0)
        require.Empty(t, records[0].Error)
        require.NotEmpty(t, records[0].Date)
 
+       require.Nil(t, records[1].Node)
+       require.Zero(t, records[1].TextBytes)
+
        require.Equal(t, http.StatusTooManyRequests, records[1].Status)
        require.Equal(t, quota, records[1].Quota)
        require.Contains(t, records[1].Error, "HTTP 429")