agent: audit logging via OLLIE_AUDIT_LOG=debug

Logger.Sub(tag) derives a child logger with a new tag from the same
writers, with level inherited from the parent but independently
overridable via OLLIE_{TAG}_LOG.

The agent creates an "audit" sub-logger at startup. Key events are
logged at debug level through it:
  audit: call: <tool> <args (truncated)>
  audit: result: <tool> <content (truncated)>
  audit: error: <message>
  audit: turn: start/end with cost and session ID
  audit: compact: messages removed, trigger, session ID

Enable with OLLIE_AUDIT_LOG=debug.

Co-Authored-By: Claude Sonnet 4.6 <noreply@anthropic.com>
This commit is contained in:
Levi Neely 2026-04-27 18:21:13 +02:00
parent 59ee25b010
commit 4b96e0cae1
3 changed files with 31 additions and 0 deletions

View File

@ -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()

View File

@ -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

View File

@ -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}
}