X-Git-Url: http://git.giacomolli.uk/onechat/blobdiff_plain/2daf91497c2cc70d7156f7c0d99b1451933a818a..refs/heads/master:/subagent_run_test.go?ds=sidebyside diff --git a/subagent_run_test.go b/subagent_run_test.go index d784b89..c5ad299 100644 --- a/subagent_run_test.go +++ b/subagent_run_test.go @@ -3,6 +3,7 @@ package main import ( "context" "io" + "log/slog" "net/http" "os" "path/filepath" @@ -21,7 +22,9 @@ const subagentTestFullContext = `{"error": {"message": "Your input exceeds the c func TestSpawnRunsASubagentInTheBackground(t *testing.T) { server := newModelFake(t) + var test *TurnTestLoop + server.reply = func(w http.ResponseWriter, call ModelFakeCall) { last := subagentTestLastItem(call) switch { @@ -47,6 +50,7 @@ func TestSpawnRunsASubagentInTheBackground(t *testing.T) { name := test.events.Last("subagent") require.True(t, subagentNameValid(name), name) + work := filepath.Join(test.loop.runs.subagents.dir, name, "work") require.DirExists(t, work) @@ -66,9 +70,10 @@ func TestSpawnRunsASubagentInTheBackground(t *testing.T) { Source: name, Status: subagentFinished, }, test.events.LastEvent("work")) - require.Equal(t, "subagent "+name+" is done, and its report goes to the agent\n", test.logs.String()) + require.Equal(t, "<6>subagent started name="+name+"\n<6>subagent done name="+name+" after=0s\n", test.logs.String()) var first, second *ModelFakeCall + for n := range server.Calls() { call := server.Call(n) if !subagentTestCall(call) { @@ -97,6 +102,7 @@ func TestSpawnRunsASubagentInTheBackground(t *testing.T) { require.Equal(t, instructions, first.body["instructions"]) var tools []string + for _, tool := range first.body["tools"].([]any) { tools = append(tools, tool.(map[string]any)["name"].(string)) } @@ -112,6 +118,7 @@ func TestSpawnRunsASubagentInTheBackground(t *testing.T) { require.Equal(t, "0|note: subagent\n\n1|user: Count the files.\n\n2|tool: shell {\"command\":\"pwd\"}\n\n3|echo: "+work+"\n\n\n4|reply: There are 3 files.", log) var agents []string + for _, record := range modelReadUsage(t, test.usagePath) { agents = append(agents, record.Agent) } @@ -140,6 +147,7 @@ func TestReportJoinsTheNextRequestOfARunningTurn(t *testing.T) { require.NoError(t, err) <-arrived + report := subagentReport("GreenOtter", []string{"It is done."}) test.loop.Report("GreenOtter", report, subagentFinished) close(release) @@ -170,6 +178,7 @@ func TestFullContextGivesAFailedReport(t *testing.T) { server.reply = func(w http.ResponseWriter, call ModelFakeCall) { if subagentTestCall(call) { w.WriteHeader(http.StatusBadRequest) + _, _ = io.WriteString(w, subagentTestFullContext) return @@ -185,11 +194,11 @@ func TestFullContextGivesAFailedReport(t *testing.T) { name := test.events.Last("subagent") require.Equal(t, []string{ - "work: [" + name + "]\nfailed: model call: HTTP 400: " + subagentTestFullContext + "\n\nFull chat: zoom(\"" + name + "\")", + "work: [" + name + "]\nfailed: create model response: model call: HTTP 400: " + subagentTestFullContext + "\n\nFull chat: zoom(\"" + name + "\")", "reply: It failed.", }, test.Log(t)) require.Equal(t, subagentFailed, test.events.LastEvent("work").Status) - require.Equal(t, "subagent "+name+" failed, and its report tells the agent: model call: HTTP 400: "+subagentTestFullContext+"\n", test.logs.String()) + require.Equal(t, "<6>subagent started name="+name+"\n<3>subagent failed name="+name+" after=0s: create model response: model call: HTTP 400: "+subagentTestFullContext+"\n", test.logs.String()) } func TestSubagentHasItsOwnEffortAndNoSpawn(t *testing.T) { @@ -260,6 +269,7 @@ func TestTellReachesARunningSubagentBetweenItsToolCalls(t *testing.T) { require.NoError(t, err) <-arrived + name := test.events.Last("subagent") output, err := runs.Tell(t.Context(), name, "Use the second disk.") require.NoError(t, err) @@ -294,6 +304,7 @@ func TestTellAfterTheFinalAnswerStartsAnotherChain(t *testing.T) { require.NoError(t, err) <-arrived + name := test.events.Last("subagent") _, err = runs.Tell(t.Context(), name, "Count again.") require.NoError(t, err) @@ -344,7 +355,7 @@ func TestTellToAFinishedSubagentGoesOnFromItsLog(t *testing.T) { func TestStopEndsASubagentAndItsCommand(t *testing.T) { server := newModelFake(t) - server.reply = func(w http.ResponseWriter, call ModelFakeCall) { + server.reply = func(w http.ResponseWriter, _ ModelFakeCall) { modelWriteEvents(w, modelCompletedEvent([]any{modelFunctionCallItem("fc_1", "call_1", "shell", `{"command":"touch started && sleep 30"}`)}, 100, 0, 5)) } @@ -374,7 +385,7 @@ func TestStopEndsASubagentAndItsCommand(t *testing.T) { "work: " + subagentReport(name, []string{"stopped"}), }, test.Log(t)) require.Equal(t, subagentStopped, test.events.LastEvent("work").Status) - require.Equal(t, "subagent "+name+" is stopped by the user\n", test.logs.String()) + require.Equal(t, "<6>subagent started name="+name+"\n<6>subagent stopped name="+name+" after=0s\n", test.logs.String()) log, err := subagent.Show() require.NoError(t, err) @@ -396,7 +407,7 @@ func TestCloseEndsTheSubagentsWithNoReport(t *testing.T) { close(release) }) - server.reply = func(w http.ResponseWriter, call ModelFakeCall) { + server.reply = func(_ http.ResponseWriter, _ ModelFakeCall) { close(arrived) <-release } @@ -428,10 +439,12 @@ func TestRestartResumesTheCutSubagents(t *testing.T) { }) var restarted atomic.Bool + server.reply = func(w http.ResponseWriter, call ModelFakeCall) { switch { case subagentTestCall(call) && !restarted.Load(): arrived <- struct{}{} + <-release case subagentTestCall(call): modelWriteEvents(w, modelCompletedEvent([]any{modelMessageItem("Built.")}, 100, 0, 5)) @@ -444,12 +457,14 @@ func TestRestartResumesTheCutSubagents(t *testing.T) { require.NoError(t, err) first := &TurnEventRecorder{} - loop, _, stop := subagentTestStart(t, agent, server, first) + loop, _, stop := subagentTestStart(t, agent, server, first, discardLog()) _, err = loop.runs.Spawn(t.Context(), []string{"Build the project."}, nil) require.NoError(t, err) <-arrived + name := first.Last("subagent") + stop() require.Zero(t, first.Count("work")) @@ -458,11 +473,13 @@ func TestRestartResumesTheCutSubagents(t *testing.T) { require.JSONEq(t, `{"running": ["`+name+`"]}`, string(data)) restarted.Store(true) + second := &TurnEventRecorder{} - loop, memory, stop := subagentTestStart(t, agent, server, second) + loop, memory, stop := subagentTestStart(t, agent, server, second, discardLog()) defer stop() second.WaitFor(t, "idle", 1) + note := "The daemon restarted, cutting " + name + "; nothing was lost: go on." log := subagentTestChat(t, memory) require.Equal(t, []string{ @@ -490,7 +507,8 @@ func TestRestartReportsASubagentThatCannotGoOn(t *testing.T) { require.NoError(t, os.WriteFile(filepath.Join(agent.dir, subagentWorkFileName), []byte(`{"running": ["BlueFox"]}`), 0o600)) events := &TurnEventRecorder{} - _, memory, stop := subagentTestStart(t, agent, server, events) + logs := &SyncBuffer{} + _, memory, stop := subagentTestStart(t, agent, server, events, daemonTestLogger(logs)) defer stop() events.WaitFor(t, "idle", 1) @@ -500,6 +518,7 @@ func TestRestartReportsASubagentThatCannotGoOn(t *testing.T) { "reply: a line", }, subagentTestChat(t, memory)) require.Equal(t, subagentFailed, events.LastEvent("work").Status) + require.Equal(t, "<3>subagent lost at restart name=BlueFox: no agent BlueFox\n", logs.String()) data, err := os.ReadFile(filepath.Join(agent.dir, subagentWorkFileName)) require.NoError(t, err) @@ -509,7 +528,7 @@ func TestRestartReportsASubagentThatCannotGoOn(t *testing.T) { // subagentTestStart runs a loop of agent with its memory and subagents in the // agent directory, as the daemon does. The returned function stops the loop // and closes the files. -func subagentTestStart(t *testing.T, agent *Agent, server *ModelFake, events *TurnEventRecorder) (*TurnLoop, *Memory, func()) { +func subagentTestStart(t *testing.T, agent *Agent, server *ModelFake, events *TurnEventRecorder, logger *slog.Logger) (*TurnLoop, *Memory, func()) { t.Helper() agent.config.Workdir = t.TempDir() @@ -520,7 +539,7 @@ func subagentTestStart(t *testing.T, agent *Agent, server *ModelFake, events *Tu subagents := newSubagents(filepath.Join(agent.dir, subagentDirName), clock.Now, subagentNameRandom) client := newModelClient(server.URL, ModelAPIKey(modelTestKey), agent.CacheKey(), filepath.Join(agent.dir, "usage.jsonl")) whatsapp, _, _ := whatsappStartTest(t, t.TempDir(), clock) - loop, err := newTurnLoop(agent, memory, subagents, whatsapp, newTestSchedules(t, clock.Now), client, clock.Now, discardLog(), events.Add) + loop, err := newTurnLoop(agent, memory, subagents, whatsapp, newTestSchedules(t, clock.Now), client, clock.Now, logger, events.Add) require.NoError(t, err) ctx, cancel := context.WithCancel(t.Context()) @@ -543,6 +562,7 @@ func subagentTestChat(t *testing.T, memory *Memory) []string { t.Helper() var lines []string + for id := range memory.Len() { message, err := memory.Message(id) require.NoError(t, err) @@ -571,7 +591,9 @@ func subagentTestLastItem(call ModelFakeCall) map[string]any { // another item. func subagentTestText(item map[string]any) string { content, _ := item["content"].([]any) + var text strings.Builder + for _, part := range content { value, _ := part.(map[string]any)["text"].(string) text.WriteString(value)