diff --git a/pkg/agent/core.go b/pkg/agent/core.go index c1f1fd1..e8cfa93 100644 --- a/pkg/agent/core.go +++ b/pkg/agent/core.go @@ -182,6 +182,7 @@ type agent struct { changeCond *sync.Cond submitMu sync.Mutex // serializes Submit calls (commands + turns) warnedContext bool // true after a context-usage warning; cleared on compaction + auditLog *olog.Logger } // SetEnv stores a session-scoped variable and propagates it to the execute server. @@ -279,6 +280,7 @@ func NewAgentCore(cfg AgentCoreConfig) Core { cfg: run, hooks: cfg.Env.Hooks, log: log, + auditLog: log.Sub("audit"), agentName: cfg.AgentName, agentsDir: cfg.AgentsDir, sessionsDir: cfg.SessionsDir, @@ -511,6 +513,7 @@ func (s *agent) runCompact(ctx context.Context, trigger string, handler EventHan return 0, err } if n > 0 { + s.auditLog.Debug("compact: removed %d messages trigger=%s session=%s", n, trigger, s.sessionID) s.warnedContext = false if sc := s.spawnContext(ctx, handler); sc != "" { s.session.appendUserMessage(sc) @@ -771,6 +774,8 @@ func (s *agent) executeTurn(ctx context.Context, input string, handler EventHand handle := &actionHandle{cancel: actCancel} s.currentAction.Store(handle) + s.auditLog.Debug("turn: start session=%s", s.sessionID) + var replyBuf strings.Builder s.cfg.Output = func(ev Event) { switch ev.Role { @@ -778,8 +783,12 @@ func (s *agent) executeTurn(ctx context.Context, input string, handler EventHand replyBuf.WriteString(ev.Content) case "call": s.setState("calling: " + ev.Name) + s.auditLog.Debug("call: %s %s", ev.Name, auditTruncate(string(ev.Content))) case "tool": s.setState("thinking") + s.auditLog.Debug("result: %s %s", ev.Name, auditTruncate(ev.Content)) + case "error": + s.auditLog.Debug("error: %s", ev.Content) } if ev.Role == "usage" && s.session != nil { var in, out, est int @@ -894,6 +903,8 @@ func (s *agent) executeTurn(ctx context.Context, input string, handler EventHand if s.session != nil { s.session.recordTurnCost(s.cfg.Backend.Model()) handler(Event{Role: "info", Content: fmt.Sprintf("costLast=$%.4f\n", s.session.LastTurnCostUSD)}) + s.auditLog.Debug("turn: end cost=$%.4f session_total=$%.4f session=%s", + s.session.LastTurnCostUSD, s.session.SessionCostUSD, s.sessionID) s.notifyChange() } s.saveSession() diff --git a/pkg/agent/cost.go b/pkg/agent/cost.go index b3d9a53..d37d6cf 100644 --- a/pkg/agent/cost.go +++ b/pkg/agent/cost.go @@ -2,6 +2,15 @@ package agent import "strings" +// auditTruncate trims s to 200 runes for log output. +func auditTruncate(s string) string { + runes := []rune(s) + if len(runes) <= 200 { + return s + } + return string(runes[:200]) + "…" +} + // modelPrice holds USD per 1M input and output tokens for a model family. type modelPrice struct { inputPer1M float64 diff --git a/pkg/log/log.go b/pkg/log/log.go index d81be93..0000bef 100644 --- a/pkg/log/log.go +++ b/pkg/log/log.go @@ -131,3 +131,14 @@ func (l *Logger) Debug(format string, args ...any) { l.emit(LevelDebug, format, func (l *Logger) Info(format string, args ...any) { l.emit(LevelInfo, format, args...) } func (l *Logger) Warn(format string, args ...any) { l.emit(LevelWarn, format, args...) } func (l *Logger) Error(format string, args ...any) { l.emit(LevelError, format, args...) } + +// Sub returns a new Logger with the given tag sharing the same output writers +// and inheriting this logger's level. The level can be overridden independently +// via the OLLIE_{TAG}_LOG environment variable. +func (l *Logger) Sub(tag string) *Logger { + level := l.level + if env := os.Getenv("OLLIE_" + strings.ToUpper(tag) + "_LOG"); env != "" { + level = ParseLevel(env, level) + } + return &Logger{tag: tag, level: level, out: l.out, errout: l.errout} +}