Cyrene_v2/internal/runtime/loop/spanlog.go

package loop

import (
	"sort"
	"time"

	"git.yeij.top/AskaEth/Cyrene_v2/internal/runtime/agent"
	"git.yeij.top/AskaEth/Cyrene_v2/internal/runtime/trace"
)

// Log event types recorded on a span so the flow graph's node log[] shows what
// happened at each step (design/19 §1 节点实时日志). An event is appended only when
// the step really finished, so the log never announces work that did not run.
const (
	// EventLLMDone is recorded on an llm_call span once the model call returned.
	EventLLMDone = "llm.done"
	// EventToolDone is recorded on a tool_call span once the tool call settled.
	EventToolDone = "tool.done"
)

// maxLogSummaryRunes bounds a log value before publication. The graph redacts and
// truncates again on the way out; this only keeps an individual span small.
const maxLogSummaryRunes = 240

// recordLLMDone appends a desensitized summary of a finished model call to its
// span: the model that served the turn, both stop reasons, how many tool calls were
// requested and how long the call took. No prompt or completion text is recorded,
// so an llm node's log can never carry conversation content. ag is the turn's agent
// (the per-role pool entry), so a multi-role process reports the model that actually
// served the call rather than the default role's.
func (l *Loop) recordLLMDone(span *trace.Span, out *stepOutcome, ag *agent.Agent) {
	if span == nil || out == nil {
		return
	}
	props := map[string]any{
		"stop_reason": out.stopReason,
		"tool_calls":  len(out.toolCalls),
		"elapsed_ms":  elapsedMS(span),
	}
	if m := modelName(out, ag); m != "" {
		props["model"] = m
	}
	if out.modelStopReason != "" {
		props["model_stop_reason"] = out.modelStopReason
	}
	_ = span.Record(trace.Event{Type: EventLLMDone, Props: props})
}

// recordToolDone appends a desensitized summary of one tool call to its span: the
// tool name, whether it succeeded, the argument NAMES (never their values), the
// error kind on failure, and a truncated result summary. Argument values are
// deliberately omitted — a tool argument is exactly where a credential, a message
// body or a file path with a secret would appear — and everything recorded here is
// scrubbed again by the graph before publication.
func (l *Loop) recordToolDone(span *trace.Span, tc agent.ToolCall, out ToolOutcome) {
	if span == nil {
		return
	}
	props := map[string]any{
		"tool":       tc.Name,
		"ok":         out.Err == nil,
		"args_keys":  argKeys(tc.Args),
		"elapsed_ms": elapsedMS(span),
	}
	if out.Err != nil {
		if out.ErrKind != "" {
			props["error_kind"] = out.ErrKind
		}
		props["error"] = trimSummary(out.Err.Error())
	} else {
		props["result_summary"] = trimSummary(formatToolResult(out.Result))
	}
	_ = span.Record(trace.Event{Type: EventToolDone, Props: props})
}

// modelName reports the model that served a step: the routed request model when
// the streaming path knows it, else the turn's agent's configured model. It is
// empty when neither is available.
func modelName(out *stepOutcome, ag *agent.Agent) string {
	if out.model != "" {
		return out.model
	}
	if ag == nil {
		return ""
	}
	return ag.Model()
}

// elapsedMS reports how long a span has been open so far. A span's Duration is
// only stamped by Finish, so a log event recorded before Finish measures it here.
func elapsedMS(span *trace.Span) int64 {
	if span == nil || span.StartedAt.IsZero() {
		return 0
	}
	return time.Since(span.StartedAt).Milliseconds()
}

// argKeys returns a tool call's argument names in sorted order. Only the names are
// logged; the values stay out of the trace (see recordToolDone).
func argKeys(args map[string]any) []string {
	if len(args) == 0 {
		return nil
	}
	keys := make([]string, 0, len(args))
	for k := range args {
		keys = append(keys, k)
	}
	sort.Strings(keys)
	return keys
}

// trimSummary shortens a log value to maxLogSummaryRunes runes without splitting a
// multi-byte rune.
func trimSummary(s string) string {
	r := []rune(s)
	if len(r) <= maxLogSummaryRunes {
		return s
	}
	return string(r[:maxLogSummaryRunes]) + "…"
}