lkn
/
ollie-core
Archived
1
0
Fork 0
Code Issues Pull Requests Packages Projects Releases Wiki Activity

agent: add hook observability; log state changes only on transition 

- Debug-log all hook firings unconditionally (name, cmd, exit, context_len)
- Emit "N hook(s) run" to chat for lifecycle hooks (agentSpawn, pre/postCompact,
  pre/postClear); suppress per-turn hooks (userPromptSubmit, stop) from chat
- Store env.Messages (MCP connections) on agentCore; emit to chat on first turn,
  debug-log unconditionally
- Replace inline s.state assignments with setState() so debug logs emit only
  on state transitions, not on every State() poll

Co-Authored-By: Claude Sonnet 4.6 <noreply@anthropic.com>
This commit is contained in:
Levi Neely 2026-04-19 07:24:44 +02:00
parent d66b8f473f
commit 031dc349e2
2 changed files with 109 additions and 60 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

136
pkg/agent/core.go
View File

@ -258,25 +258,26 @@ type AgentCoreConfig struct {
// agentCore is the Core implementation. It owns all agent and session state
// but has no knowledge of how output is rendered.
type agentCore struct {
session *Session
loopcfg loopConfig
hooks Hooks
agentName string
agentsDir string
sessionsDir string
sessionID string
dispatcher tools.Dispatcher
newDispatcher func() tools.Dispatcher
cwd string
agentPrompt string // agent-specific prompt suffix; kept for system prompt rebuilds
currentAction atomic.Pointer[actionHandle]
fifo PromptFIFO
pendingInject atomic.Pointer[string]
mu sync.RWMutex
state string // "idle", "thinking", "calling: <tool>"
reply string // assistant text from the most recently completed turn
envMu sync.RWMutex
env map[string]string // session-scoped env vars
session *Session
loopcfg loopConfig
hooks Hooks
agentName string
agentsDir string
sessionsDir string
sessionID string
dispatcher tools.Dispatcher
newDispatcher func() tools.Dispatcher
cwd string
agentPrompt string // agent-specific prompt suffix; kept for system prompt rebuilds
startupMessages []string
currentAction atomic.Pointer[actionHandle]
fifo PromptFIFO
pendingInject atomic.Pointer[string]
mu sync.RWMutex
state string // "idle", "thinking", "calling: <tool>"
reply string // assistant text from the most recently completed turn
envMu sync.RWMutex
env map[string]string // session-scoped env vars
}
// SetEnv stores a session-scoped variable and propagates it to the execute server.
@ -331,18 +332,19 @@ func NewAgentCore(cfg AgentCoreConfig) Core {
}
a := &agentCore{
session: cfg.Session,
loopcfg: loopcfg,
hooks: cfg.Env.Hooks,
agentName: cfg.AgentName,
agentsDir: cfg.AgentsDir,
sessionsDir: cfg.SessionsDir,
sessionID: cfg.SessionID,
cwd: cfg.CWD,
agentPrompt: cfg.Env.agentPrompt,
dispatcher: cfg.Env.dispatcher,
newDispatcher: cfg.NewDispatcher,
state: "idle",
session: cfg.Session,
loopcfg: loopcfg,
hooks: cfg.Env.Hooks,
agentName: cfg.AgentName,
agentsDir: cfg.AgentsDir,
sessionsDir: cfg.SessionsDir,
sessionID: cfg.SessionID,
cwd: cfg.CWD,
agentPrompt: cfg.Env.agentPrompt,
startupMessages: cfg.Env.Messages,
dispatcher: cfg.Env.dispatcher,
newDispatcher: cfg.NewDispatcher,
state: "idle",
}
a.pushSessionEnv()
return a
@ -382,10 +384,16 @@ func (s *agentCore) ModelName() string {
func (s *agentCore) State() string {
s.mu.RLock()
defer s.mu.RUnlock()
clog.Debug("State() = %q", s.state)
return s.state
}
func (s *agentCore) setState(state string) {
s.mu.Lock()
s.state = state
s.mu.Unlock()
clog.Debug("state -> %q", state)
}
func (s *agentCore) Reply() string {
s.mu.RLock()
defer s.mu.RUnlock()
@ -689,12 +697,21 @@ func (s *agentCore) Submit(ctx context.Context, input string, handler EventHandl
}
if s.session == nil {
// First turn — fire agentSpawn and inject any context it provides into
// the opening message so the agent sees it from the start.
if spawnResult := s.hooks.Run(ctx, HookAgentSpawn, map[string]string{
// First turn — emit startup messages (e.g. MCP connections) then fire
// agentSpawn, injecting any context it returns into the opening message.
for _, msg := range s.startupMessages {
clog.Debug("startup: %s", msg)
handler(infoEvent(msg))
}
s.startupMessages = nil
spawnResult := s.hooks.Run(ctx, HookAgentSpawn, map[string]string{
"session_id": s.sessionID,
"agent": s.agentName,
}); spawnResult.Context != "" {
})
if spawnResult.Ran {
handler(infoEvent(hooksRan(1)))
}
if spawnResult.Context != "" {
input += "\n" + spawnResult.Context
}
s.session = newSession(input)
@ -702,9 +719,7 @@ func (s *agentCore) Submit(ctx context.Context, input string, handler EventHandl
s.session.appendUserMessage(input)
}
s.mu.Lock()
s.state = "thinking"
s.mu.Unlock()
s.setState("thinking")
actCtx, actCancel := context.WithCancelCause(ctx)
handle := &actionHandle{cancel: actCancel}
@ -716,13 +731,9 @@ func (s *agentCore) Submit(ctx context.Context, input string, handler EventHandl
case "assistant":
replyBuf.WriteString(ev.Content)
case "call":
s.mu.Lock()
s.state = "calling: " + ev.Name
s.mu.Unlock()
s.setState("calling: " + ev.Name)
case "tool":
s.mu.Lock()
s.state = "thinking"
s.mu.Unlock()
s.setState("thinking")
}
if ev.Role == "usage" && s.session != nil {
var in, out, est int
@ -742,10 +753,17 @@ func (s *agentCore) Submit(ctx context.Context, input string, handler EventHandl
if s.session != nil {
if limit := s.autoCompactLimit(ctx); limit > 0 && s.session.estimateTokens() >= limit {
payload := map[string]string{"session_id": s.sessionID, "trigger": "auto"}
if pre := s.hooks.Run(ctx, HookPreCompact, payload); !pre.Blocked {
pre := s.hooks.Run(ctx, HookPreCompact, payload)
if pre.Ran {
handler(infoEvent(hooksRan(1)))
}
if !pre.Blocked {
emit(s.loopcfg, Event{Role: "info", Content: "auto-compacting context...\n"})
s.session.compact(ctx, s.loopcfg.Backend) //nolint:errcheck
s.hooks.Run(ctx, HookPostCompact, payload)
post := s.hooks.Run(ctx, HookPostCompact, payload)
if post.Ran {
handler(infoEvent(hooksRan(1)))
}
}
}
}
@ -756,9 +774,9 @@ func (s *agentCore) Submit(ctx context.Context, input string, handler EventHandl
s.mu.Lock()
s.reply = replyBuf.String()
s.state = "idle"
s.mu.Unlock()
replyBuf.Reset()
s.setState("idle")
if err != nil && !errors.Is(err, context.Canceled) && !errors.Is(err, ErrInterrupted) {
handler(Event{Role: "error", Content: err.Error()})
@ -965,13 +983,20 @@ func (s *agentCore) handleCommand(ctx context.Context, input string, handler Eve
}
// Snapshot history before compaction for persistence.
payload := map[string]string{"session_id": s.sessionID, "trigger": "manual"}
if pre := s.hooks.Run(ctx, HookPreCompact, payload); pre.Blocked {
pre := s.hooks.Run(ctx, HookPreCompact, payload)
if pre.Ran {
handler(infoEvent(hooksRan(1)))
}
if pre.Blocked {
handler(infoEvent("compact cancelled by hook"))
return true
}
snapshot := s.session.PreCompactionSnapshot()
n, _, err := s.session.compact(ctx, s.loopcfg.Backend)
s.hooks.Run(ctx, HookPostCompact, payload)
post := s.hooks.Run(ctx, HookPostCompact, payload)
if post.Ran {
handler(infoEvent(hooksRan(1)))
}
if err != nil {
handler(infoEvent("compact error: " + err.Error()))
} else if n == 0 {
@ -1048,13 +1073,20 @@ func (s *agentCore) handleCommand(ctx context.Context, input string, handler Eve
handler(infoEvent("error: cannot clear while agent is running"))
return true
}
if pre := s.hooks.Run(ctx, HookPreClear, map[string]string{"session_id": s.sessionID}); pre.Blocked {
pre := s.hooks.Run(ctx, HookPreClear, map[string]string{"session_id": s.sessionID})
if pre.Ran {
handler(infoEvent(hooksRan(1)))
}
if pre.Blocked {
handler(infoEvent("clear cancelled by hook"))
return true
}
s.session = nil
s.sessionID = NewSessionID()
s.hooks.Run(ctx, HookPostClear, map[string]string{"session_id": s.sessionID})
post := s.hooks.Run(ctx, HookPostClear, map[string]string{"session_id": s.sessionID})
if post.Ran {
handler(infoEvent(hooksRan(1)))
}
handler(infoEvent("cleared"))
return true

33
pkg/agent/hooks.go
View File

@ -5,6 +5,7 @@ import (
"context"
"encoding/json"
"errors"
"fmt"
"os/exec"
"strings"
"time"
@ -28,6 +29,8 @@ type Hooks map[string]string
// HookResult holds the outcome of running a hook.
type HookResult struct {
// Ran is true when a hook command was configured and executed.
Ran bool
// Blocked is true when the hook wants to prevent the action (exit 2).
// For Stop hooks, Blocked means "don't stop, continue".
Blocked bool
@ -36,7 +39,7 @@ type HookResult struct {
}
// Run executes the hook for the named event, sending payload as JSON on stdin.
// Returns a HookResult describing whether the hook blocked and any context.
// Returns a HookResult describing whether the hook ran, blocked, and any context.
//
// Exit codes:
// - 0: success. Stdout is added as conversation context.
@ -45,6 +48,7 @@ type HookResult struct {
// - other: non-blocking warning (stderr logged, execution continues).
func (h Hooks) Run(ctx context.Context, name string, payload any) HookResult {
cmdStr := h[name]
clog.Debug("hook %s: cmd=%q", name, cmdStr)
if cmdStr == "" {
return HookResult{}
}
@ -60,6 +64,7 @@ func (h Hooks) Run(ctx context.Context, name string, payload any) HookResult {
done := make(chan error, 1)
if err := cmd.Start(); err != nil {
clog.Debug("hook %s: start error: %v", name, err)
return HookResult{}
}
go func() { done <- cmd.Wait() }()
@ -73,31 +78,43 @@ func (h Hooks) Run(ctx context.Context, name string, payload any) HookResult {
if errors.As(err, &exitErr) {
exitCode = exitErr.ExitCode()
} else {
clog.Debug("hook %s: wait error: %v", name, err)
return HookResult{}
}
}
switch exitCode {
case 0:
return HookResult{Context: strings.TrimSpace(stdout.String())}
out := strings.TrimSpace(stdout.String())
clog.Debug("hook %s: exit=0 context_len=%d", name, len(out))
return HookResult{Ran: true, Context: out}
case 2:
return HookResult{
Blocked: true,
Context: strings.TrimSpace(stderr.String()),
}
msg := strings.TrimSpace(stderr.String())
clog.Debug("hook %s: exit=2 (blocked) msg=%q", name, msg)
return HookResult{Ran: true, Blocked: true, Context: msg}
default:
// Non-blocking error — stderr is just a warning, ignore.
return HookResult{}
clog.Debug("hook %s: exit=%d (non-blocking error) stderr=%q", name, exitCode, stderr.String())
return HookResult{Ran: true}
}
case <-ctx.Done():
cmd.Process.Kill() //nolint:errcheck
<-done
clog.Debug("hook %s: cancelled (context done)", name)
return HookResult{}
case <-timeout:
cmd.Process.Kill() //nolint:errcheck
<-done
clog.Debug("hook %s: timed out after %ds", name, defaultHookTimeout)
return HookResult{}
}
}
// hooksRan returns a display string for N hooks having run, e.g. "1 hook run".
func hooksRan(n int) string {
if n == 1 {
return "1 hook run"
}
return fmt.Sprintf("%d hooks run", n)
}