Add local context to chat operation failures

[onechat] / subagent_run.go

package main

import (
        "context"
        "encoding/json"
        "errors"
        "fmt"
        "log/slog"
        "maps"
        "os"
        "path/filepath"
        "slices"
        "strings"
        "sync"
        "time"
)

const (
        // subagentNote is the first message of the log of a subagent.
        subagentNote = "subagent"

        // subagentNoteEffort follows subagentNote when the subagent has its own
        // effort.
        subagentNoteEffort = " at effort "

        // subagentWorkFileName is the file of the names of the running
        // subagents in the directory of an agent.
        subagentWorkFileName = "work.json"
)

// The statuses of the end of a run, in the work event of its report.
const (
        subagentFinished = "finished"
        subagentStopped  = "stopped"
        subagentFailed   = "failed"
)

// errSubagentClosed tells that the runs of the subagents ended with the loop.
var errSubagentClosed = errors.New("the daemon stops, so no subagent starts")

// SubagentRuns runs the subagents of one agent in the background. Each run is a
// goroutine with its own context, which only Stop and Close end. A run is one
// or more request chains. The first request of each chain holds the view of the
// agent at the start of the run, then the state of the turn, then the whole log
// of the subagent. A message of Tell that comes during a chain joins its next
// request after the tool results. One that comes after the final answer starts
// one more chain, which reads the log again. The report of the run goes to
// report: the final answer of each chain, or the error of a failed call. The
// logger gets one line at the end of a run: done, failed with the cause, or
// stopped. Stop ends one run, and its report says that it stopped. At the stop
// of the daemon the runs end with no report.
//
// work.json in the directory of the agent holds the names of the running
// subagents. Each start and each end of a run writes it whole, but Close does
// not, so after a stop of the daemon it names the runs that the stop cut, and
// Resume goes on with them. The logs alone cannot tell this, because a stop can
// cut a run just after its final reply.
//
// Spawn and Tell split the view with the layout of the agent, which has no
// lock. They are tools, so they run in the goroutine of the turns, as each
// split of a turn does.
type SubagentRuns struct {
        agent     *Agent
        memory    *Memory
        subagents *Subagents
        layout    *ViewLayout
        client    ChainClient
        state     func() string
        report    func(name, text, status string)
        note      func(text string) error
        fail      func(err error)
        logger    *slog.Logger
        notify    func(Event)

        mutex   sync.Mutex
        running map[string]*SubagentRun
        closed  bool
        workers sync.WaitGroup
}

// SubagentRun is one run of a subagent: the view that its requests get, its
// effort, the end of its context, the messages of Tell that wait for a request,
// whether Stop ended it, and the time it started. The mutex of SubagentRuns
// protects the messages and the stop.
type SubagentRun struct {
        subagent *Subagent
        view     []string
        effort   string
        cancel   context.CancelFunc
        pending  []Message
        stopped  bool
        started  time.Time
}

// SubagentWorkFile is the content of work.json.
type SubagentWorkFile struct {
        Running []string `json:"running"`
}

// Spawn starts one subagent for each task and returns their names at once. It
// waits until the view has no pending summary, and gives the view to each
// subagent. A nil effort is the effort of the agent.
func (r *SubagentRuns) Spawn(ctx context.Context, tasks []string, effort *string) (string, error) {
        if len(tasks) == 0 {
                return "", errors.New("no tasks")
        }

        r.mutex.Lock()

        closed := r.closed
        r.mutex.Unlock()

        if closed {
                return "", errSubagentClosed
        }

        note := subagentNote
        runEffort := r.agent.config.Effort
        if effort != nil && !slices.Contains(promptEfforts, *effort) {
                return "", fmt.Errorf("no effort %q: one of %s", *effort, strings.Join(promptEfforts, ", "))
        }

        if effort != nil && *effort != runEffort {
                note += subagentNoteEffort + *effort
                runEffort = *effort
        }

        err := r.memory.Settle(ctx)
        if err != nil {
                return "", fmt.Errorf("wait for the summaries: %w", err)
        }

        view, err := r.layout.Split(r.memory.ViewLines(nil))
        if err != nil {
                return "", fmt.Errorf("split worker view: %w", err)
        }

        names := make([]string, 0, len(tasks))
        for _, task := range tasks {
                name, err := r.create(ctx, note, task, view, runEffort)
                if err != nil && len(names) > 0 {
                        return "", fmt.Errorf("started %s, then: %w", strings.Join(names, ", "), err)
                }

                if err != nil {
                        return "", fmt.Errorf("create worker: %w", err)
                }

                names = append(names, name)
        }

        return "Started " + strings.Join(names, ", ") + ". Each one's report will reach you as a message when it finishes.", nil
}

// create makes a new subagent with its note, its task, and its work directory,
// and starts its run.
func (r *SubagentRuns) create(ctx context.Context, note, task string, view []string, effort string) (string, error) {
        subagent, err := r.subagents.Create(ctx)
        if err != nil {
                return "", fmt.Errorf("create worker log: %w", err)
        }

        for _, message := range [][2]string{{"note", note}, {"user", task}} {
                _, err = subagent.Append(message[0], message[1])
                if err != nil {
                        return "", fmt.Errorf("append worker message: %w", err)
                }
        }

        err = subagent.Flush(ctx)
        if err != nil {
                return "", fmt.Errorf("flush worker log: %w", err)
        }

        err = os.MkdirAll(subagent.WorkDir(), 0o700)
        if err != nil {
                return "", fmt.Errorf("create work directory: %w", err)
        }

        return subagent.name, r.start(ctx, &SubagentRun{
                subagent: subagent,
                view:     view,
                effort:   effort,
        })
}

// start runs run in the background and logs its start. Its context keeps the
// values of ctx, but only Stop and Close end it.
func (r *SubagentRuns) start(ctx context.Context, run *SubagentRun) error {
        ctx, run.cancel = context.WithCancel(context.WithoutCancel(ctx))

        r.mutex.Lock()

        _, found := r.running[run.subagent.name]
        if r.closed || found {
                r.mutex.Unlock()
                run.cancel()

                if found {
                        return fmt.Errorf("%s runs already", run.subagent.name)
                }

                return errSubagentClosed
        }

        r.running[run.subagent.name] = run
        err := r.save()
        if err != nil {
                delete(r.running, run.subagent.name)
                r.mutex.Unlock()
                run.cancel()

                if err != nil {
                        return fmt.Errorf("save running workers: %w", err)
                }

                return nil
        }

        r.workers.Add(1)
        r.mutex.Unlock()

        run.started = r.subagents.clock()
        r.logger.Info("subagent started", "name", run.subagent.name)
        r.notify(Event{
                Kind: "subagent",
                Text: run.subagent.name,
        })

        go r.run(ctx, run)

        return nil
}

// save writes the names of the running subagents to work.json. The caller holds
// the mutex.
func (r *SubagentRuns) save() error {
        file := SubagentWorkFile{
                Running: append([]string{}, slices.Sorted(maps.Keys(r.running))...),
        }

        data, err := json.Marshal(file)
        if err != nil {
                return fmt.Errorf("encode running subagents: %w", err)
        }

        err = writeFileAtomic(r.workPath(), append(data, '\n'))
        if err != nil {
                return fmt.Errorf("save running subagents: %w", err)
        }

        return nil
}

// run runs the chains of run and reports and logs its end with the length of
// the run, unless Close ended it. A chain follows while messages wait after the
// final answer of the chain before it, and no chain failed. A chain that Stop
// ends gives the reply "stopped".
func (r *SubagentRuns) run(ctx context.Context, run *SubagentRun) {
        defer r.workers.Done()
        defer run.cancel()

        var (
                replies []string
                failure error
        )

        stopped := false
        status := subagentFinished
        for more := true; more; {
                reply, err := r.chain(ctx, run)

                r.mutex.Lock()

                stopped = run.stopped
                switch {
                case err != nil && stopped:
                        reply = "stopped"
                case err != nil:
                        reply = "failed: " + err.Error()
                        status = subagentFailed
                        failure = err
                }

                more = err == nil && ctx.Err() == nil && len(run.pending) > 0
                run.pending = nil

                var saveErr error

                if !more {
                        delete(r.running, run.subagent.name)

                        if !r.closed {
                                saveErr = r.save()
                        }
                }

                r.mutex.Unlock()

                if saveErr != nil {
                        r.fail(saveErr)
                }

                replies = append(replies, reply)
        }

        if ctx.Err() != nil && !stopped {
                return
        }

        if stopped {
                status = subagentStopped
        }

        length := r.subagents.clock().Sub(run.started)
        switch status {
        case subagentStopped:
                r.logger.Info("subagent stopped", "name", run.subagent.name, "after", length)
        case subagentFailed:
                r.logger.Error("subagent failed", "name", run.subagent.name, "after", length, "err", failure)
        default:
                r.logger.Info("subagent done", "name", run.subagent.name, "after", length)
        }

        r.report(run.subagent.name, subagentReport(run.subagent.name, replies), status)
}

func (r *SubagentRuns) workPath() string {
        return filepath.Join(r.agent.dir, subagentWorkFileName)
}

// chain runs one request chain of run and returns its final answer.
func (r *SubagentRuns) chain(ctx context.Context, run *SubagentRun) (string, error) {
        instructions, err := r.agent.SubagentPrompt()
        if err != nil {
                return "", fmt.Errorf("read worker instructions: %w", err)
        }

        log, err := run.subagent.Show()
        if err != nil {
                return "", fmt.Errorf("read worker log: %w", err)
        }

        input := make([]any, 0, len(run.view)+2)
        for _, text := range run.view {
                input = append(input, modelUserMessage(text))
        }

        input = append(input, modelUserMessage(r.state()), modelUserMessage(log))
        chain := &Chain{
                client: r.client,
                images: r.agent.Images(),
                tools: &Toolbox{
                        log:       run.subagent,
                        chat:      r.memory,
                        subagents: r.subagents,
                        workdir:   run.subagent.WorkDir(),
                        images:    r.agent.Images(),
                },
                request: ModelRequest{
                        Model:        r.agent.config.Model,
                        Effort:       run.effort,
                        Instructions: instructions,
                        Tools:        promptSubagentTools(),
                        Agent:        run.subagent.name,
                },
                take: func() []Message {
                        return r.take(run)
                },
        }

        return chain.Run(ctx, input)
}

// take returns the messages of Tell that wait for a request of run, and removes
// them.
func (r *SubagentRuns) take(run *SubagentRun) []Message {
        r.mutex.Lock()
        defer r.mutex.Unlock()

        messages := run.pending
        run.pending = nil

        return messages
}

// Stop ends the run of the subagent name and tells if it ran. The chat gets the
// note "Stopped by the user: NAME." under the mutex, so the note comes before
// the report of the run.
func (r *SubagentRuns) Stop(name string) (bool, error) {
        r.mutex.Lock()
        defer r.mutex.Unlock()

        run, found := r.running[name]
        if !found {
                return false, nil
        }

        err := r.note("Stopped by the user: " + name + ".")
        if err != nil {
                return true, err
        }

        run.stopped = true
        run.cancel()

        return true, nil
}

// Resume goes on with the runs that a stop of the daemon cut, as work.json
// names them. The chat gets the note "The daemon restarted, cutting NAMES;
// nothing was lost: go on.", and each cut subagent gets the same text as a
// message of Tell. A subagent that cannot go on gets a failed report.
func (r *SubagentRuns) Resume(ctx context.Context) error {
        names, err := r.load()
        if err != nil || len(names) == 0 {
                if err != nil {
                        return fmt.Errorf("load interrupted workers: %w", err)
                }

                return nil
        }

        text := "The daemon restarted, cutting " + strings.Join(names, ", ") + "; nothing was lost: go on."
        err = r.note(text)
        if err != nil {
                return fmt.Errorf("record interrupted workers: %w", err)
        }

        for _, name := range names {
                _, err = r.Tell(ctx, name, text)
                if err != nil {
                        r.logger.Error("subagent lost at restart", "name", name, "err", err)
                        r.report(name, subagentReport(name, []string{"failed: " + err.Error()}), subagentFailed)
                }
        }

        // A subagent that cannot go on does not run, so work.json no longer
        // names it, and the next start does not try it again.
        r.mutex.Lock()
        defer r.mutex.Unlock()

        return r.save()
}

// load reads the names of work.json. A missing file names none.
func (r *SubagentRuns) load() ([]string, error) {
        data, err := os.ReadFile(r.workPath())
        if errors.Is(err, os.ErrNotExist) {
                return nil, nil
        }

        if err != nil {
                return nil, fmt.Errorf("read running subagents: %w", err)
        }

        var file SubagentWorkFile

        err = json.Unmarshal(data, &file)
        if err != nil {
                return nil, fmt.Errorf("decode running subagents: %w", err)
        }

        return file.Running, nil
}

// Tell sends message to the subagent name. A running subagent reads it between
// its tool calls, and its report answers it. A finished subagent goes on from
// its log with a new run, with the view of now and the effort of its note.
func (r *SubagentRuns) Tell(ctx context.Context, name, message string) (string, error) {
        r.mutex.Lock()

        run, found := r.running[name]
        if found {
                defer r.mutex.Unlock()

                told, err := run.subagent.Append("user", message)
                if err != nil {
                        return "", fmt.Errorf("append running worker message: %w", err)
                }

                run.pending = append(run.pending, told)

                return "Sent. " + name + " reads it between its tool calls, and its report answers it.", nil
        }

        closed := r.closed
        r.mutex.Unlock()

        if closed {
                return "", errSubagentClosed
        }

        subagent, err := r.subagents.Get(ctx, name)
        if err != nil {
                return "", fmt.Errorf("open worker log: %w", err)
        }

        effort, err := r.effort(subagent)
        if err != nil {
                return "", fmt.Errorf("read worker effort: %w", err)
        }

        err = r.memory.Settle(ctx)
        if err != nil {
                return "", fmt.Errorf("wait for the summaries: %w", err)
        }

        view, err := r.layout.Split(r.memory.ViewLines(nil))
        if err != nil {
                return "", fmt.Errorf("split worker view: %w", err)
        }

        _, err = subagent.Append("user", message)
        if err == nil {
                err = subagent.Flush(ctx)
        }

        if err != nil {
                return "", fmt.Errorf("save worker message: %w", err)
        }

        err = r.start(ctx, &SubagentRun{
                subagent: subagent,
                view:     view,
                effort:   effort,
        })
        if err != nil {
                return "", fmt.Errorf("start told worker: %w", err)
        }

        return "Sent. " + name + "'s reply will reach you as a message.", nil
}

// effort returns the effort of subagent from the note at the start of its log:
// the effort of the agent, or the effort that the note names.
func (r *SubagentRuns) effort(subagent *Subagent) (string, error) {
        note, err := subagent.First()
        if err != nil {
                return "", fmt.Errorf("read worker note: %w", err)
        }

        effort, own := strings.CutPrefix(note.Text, subagentNote+subagentNoteEffort)
        switch {
        case note.Kind != "note":
        case own:
                return effort, nil
        case note.Text == subagentNote:
                return r.agent.config.Effort, nil
        }

        return "", fmt.Errorf("the log of %s does not start with a subagent note", subagent.name)
}

// Snapshot locks the run state, memory, and subagent logs while snapshot reads
// the agent files. The lock order agrees with Stop, which logs under the run
// lock.
func (r *SubagentRuns) Snapshot(ctx context.Context, snapshot func() error) error {
        r.mutex.Lock()
        defer r.mutex.Unlock()

        return r.memory.Snapshot(ctx, func() error {
                return r.subagents.Snapshot(ctx, snapshot)
        })
}

// Close ends every run and waits for them. No subagent starts after Close.
func (r *SubagentRuns) Close() {
        r.mutex.Lock()

        r.closed = true
        for _, run := range r.running {
                run.cancel()
        }

        r.mutex.Unlock()

        r.workers.Wait()
}

// subagentReport returns the report of the subagent name with its replies: the
// name in brackets, a new line, the replies, and the zoom that gives its whole
// chat.
func subagentReport(name string, replies []string) string {
        return "[" + name + "]\n" + strings.Join(replies, "\n\n") + "\n\nFull chat: zoom(\"" + name + "\")"
}