yao/agent/context/log.go
Max f6b917afe1 Remove TUI support from start command
The bubbletea-based TUI for agent request visualization was not
practical and added significant binary size. This removes the TUI
entirely: the --tui flag, the agent context TUI model/messages, and
all SendTUI/GetTUIProgram call sites. Development-mode logging now
always prints ANSI-colored output to stdout.

Drops direct dependencies on charmbracelet/bubbletea and lipgloss.

Made-with: Cursor
2026-03-06 20:55:57 +08:00

590 lines
16 KiB
Go
Raw Permalink Blame History

This file contains ambiguous Unicode characters

This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.

package context
import (
"fmt"
"strings"
"sync"
"time"
kunlog "github.com/yaoapp/kun/log"
"github.com/yaoapp/yao/config"
)
// =============================================================================
// ANSI Color Codes
// =============================================================================
const (
colorReset = "\033[0m"
colorRed = "\033[31m"
colorGreen = "\033[32m"
colorYellow = "\033[33m"
colorBlue = "\033[34m"
colorMagenta = "\033[35m"
colorCyan = "\033[36m"
colorWhite = "\033[37m"
colorGray = "\033[90m"
colorBoldRed = "\033[1;31m"
colorBoldGreen = "\033[1;32m"
colorBoldYellow = "\033[1;33m"
colorBoldBlue = "\033[1;34m"
colorBoldMagenta = "\033[1;35m"
colorBoldCyan = "\033[1;36m"
)
// =============================================================================
// Log Level
// =============================================================================
// LogLevel represents log severity
type LogLevel int
const (
// LogLevelTrace represents the most verbose logging level for detailed tracing
LogLevelTrace LogLevel = iota
// LogLevelDebug represents debug level logging for development diagnostics
LogLevelDebug
// LogLevelInfo represents informational messages for normal operation
LogLevelInfo
// LogLevelWarn represents warning messages for potentially harmful situations
LogLevelWarn
// LogLevelError represents error messages for serious problems
LogLevelError
)
// =============================================================================
// Log Entry
// =============================================================================
// LogEntry represents a single log entry
type LogEntry struct {
Level LogLevel
Message string
Timestamp time.Time
Phase string // For phase logging
Elapsed time.Duration
}
// =============================================================================
// Request Logger
// =============================================================================
// RequestLogger provides request-scoped async logging
type RequestLogger struct {
assistantIDStack []string // Stack-based: delegate calls push, pop on exit; top = current
chatID string
requestID string
shortID string // Short version of requestID for display
parentID string // Parent request ID for A2A tree structure
startTime time.Time
ch chan LogEntry
done chan struct{}
once sync.Once
closed bool
noop bool // noop logger does nothing (for nil safety)
mu sync.RWMutex
}
// LoggerOption configures a RequestLogger
type LoggerOption func(*RequestLogger)
// WithParentID sets the parent request ID for A2A tree structure
func WithParentID(parentID string) LoggerOption {
return func(l *RequestLogger) {
l.parentID = parentID
}
}
// noopLogger is a shared no-op logger instance
var noopLogger = &RequestLogger{noop: true}
// NewRequestLogger creates a new request-scoped logger with async processing
func NewRequestLogger(assistantID, chatID, requestID string, opts ...LoggerOption) *RequestLogger {
l := &RequestLogger{
assistantIDStack: []string{assistantID},
chatID: chatID,
requestID: requestID,
shortID: shortID(requestID),
startTime: time.Now(),
ch: make(chan LogEntry, 100), // Buffered channel
done: make(chan struct{}),
}
for _, opt := range opts {
opt(l)
}
// Start consumer goroutine
go l.consume()
return l
}
// Noop returns a no-op logger that does nothing (nil-safe)
func Noop() *RequestLogger {
return noopLogger
}
// SetAssistantID pushes a new assistant ID onto the stack (called when entering Stream).
// Each SetAssistantID must be paired with a RestoreAssistantID on exit.
func (l *RequestLogger) SetAssistantID(id string) {
if l.noop {
return
}
l.mu.Lock()
l.assistantIDStack = append(l.assistantIDStack, id)
l.mu.Unlock()
}
// RestoreAssistantID pops the current assistant ID, reverting to the previous one.
// Safe to call even if the stack has only one entry (the initial ID is never removed).
func (l *RequestLogger) RestoreAssistantID() {
if l.noop {
return
}
l.mu.Lock()
if len(l.assistantIDStack) > 1 {
l.assistantIDStack = l.assistantIDStack[:len(l.assistantIDStack)-1]
}
l.mu.Unlock()
}
func (l *RequestLogger) currentAssistantID() string {
if len(l.assistantIDStack) == 0 {
return ""
}
return l.assistantIDStack[len(l.assistantIDStack)-1]
}
// Close closes the logger and waits for all entries to be processed
func (l *RequestLogger) Close() {
if l.noop {
return
}
l.once.Do(func() {
l.mu.Lock()
l.closed = true
l.mu.Unlock()
close(l.ch)
<-l.done // Wait for consumer to finish
})
}
// consume processes log entries from the channel
func (l *RequestLogger) consume() {
defer close(l.done)
for entry := range l.ch {
l.processEntry(entry)
}
}
// processEntry handles a single log entry based on mode
func (l *RequestLogger) processEntry(entry LogEntry) {
if config.IsDevelopment() {
l.printDev(entry)
l.writeLog(entry, true)
} else {
l.writeLog(entry, false)
}
}
// printDev prints colored output to stdout in development mode
func (l *RequestLogger) printDev(entry LogEntry) {
switch entry.Level {
case LogLevelTrace:
fmt.Printf("%s → %s%s\n", colorGray, entry.Message, colorReset)
case LogLevelDebug:
fmt.Printf("%s • %s%s\n", colorGray, entry.Message, colorReset)
case LogLevelInfo:
fmt.Printf("%s %s%s\n", colorCyan, entry.Message, colorReset)
case LogLevelWarn:
fmt.Printf("%s ⚠ %s%s\n", colorYellow, entry.Message, colorReset)
case LogLevelError:
fmt.Printf("%s ✗ %s%s\n", colorRed, entry.Message, colorReset)
}
}
// writeLog writes structured events to kun/log
func (l *RequestLogger) writeLog(entry LogEntry, devMode bool) {
prefix := fmt.Sprintf("[AGENT] %s ", l.shortID)
if devMode {
kunlog.Trace("%s%s", prefix, entry.Message)
return
}
switch entry.Level {
case LogLevelTrace:
kunlog.Trace("%s%s", prefix, entry.Message)
case LogLevelDebug:
// Skip debug in production
case LogLevelInfo:
kunlog.Info("%s%s", prefix, entry.Message)
case LogLevelWarn:
kunlog.Warn("%s%s", prefix, entry.Message)
case LogLevelError:
kunlog.Error("%s%s", prefix, entry.Message)
}
}
// send sends an entry to the channel (non-blocking if closed)
func (l *RequestLogger) send(entry LogEntry) {
if l.noop {
return
}
l.mu.RLock()
closed := l.closed
l.mu.RUnlock()
if closed {
return
}
entry.Timestamp = time.Now()
select {
case l.ch <- entry:
default:
// Channel full, drop the log (shouldn't happen with buffered channel)
}
}
// =============================================================================
// Standard Log Interface
// =============================================================================
// Trace logs a trace level message
func (l *RequestLogger) Trace(format string, args ...interface{}) {
l.send(LogEntry{
Level: LogLevelTrace,
Message: fmt.Sprintf(format, args...),
})
}
// Debug logs a debug level message
func (l *RequestLogger) Debug(format string, args ...interface{}) {
l.send(LogEntry{
Level: LogLevelDebug,
Message: fmt.Sprintf(format, args...),
})
}
// Info logs an info level message
func (l *RequestLogger) Info(format string, args ...interface{}) {
l.send(LogEntry{
Level: LogLevelInfo,
Message: fmt.Sprintf(format, args...),
})
}
// Warn logs a warning level message
func (l *RequestLogger) Warn(format string, args ...interface{}) {
l.send(LogEntry{
Level: LogLevelWarn,
Message: fmt.Sprintf(format, args...),
})
}
// Error logs an error level message
func (l *RequestLogger) Error(format string, args ...interface{}) {
l.send(LogEntry{
Level: LogLevelError,
Message: fmt.Sprintf(format, args...),
})
}
// =============================================================================
// Business Quick Functions
// =============================================================================
// Start logs the start of a request with visual separator
func (l *RequestLogger) Start() {
if l.noop {
return
}
kunlog.Trace("[AGENT] Request %s started: assistant=%s, chat=%s, request=%s",
l.shortID, l.currentAssistantID(), shortID(l.chatID), shortID(l.requestID))
if !config.IsDevelopment() {
return
}
fmt.Println()
fmt.Printf("%s%s%s\n", colorBoldCyan, strings.Repeat("═", 60), colorReset)
fmt.Printf("%s AGENT REQUEST %s%s\n", colorBoldCyan, l.shortID, colorReset)
fmt.Printf("%s%s%s\n", colorBoldCyan, strings.Repeat("─", 60), colorReset)
fmt.Printf("%s Assistant: %s%s%s\n", colorGray, colorWhite, l.currentAssistantID(), colorReset)
fmt.Printf("%s Chat ID: %s%s%s\n", colorGray, colorWhite, l.chatID, colorReset)
fmt.Printf("%s Request: %s%s%s\n", colorGray, colorWhite, l.requestID, colorReset)
fmt.Printf("%s Time: %s%s%s\n", colorGray, colorWhite, l.startTime.Format("15:04:05.000"), colorReset)
fmt.Printf("%s%s%s\n", colorCyan, strings.Repeat("─", 60), colorReset)
}
// End logs the end of a request with summary
func (l *RequestLogger) End(success bool, err error) {
if l.noop {
return
}
duration := time.Since(l.startTime)
if success {
kunlog.Trace("[AGENT] Request %s completed: assistant=%s, duration=%v",
l.shortID, l.currentAssistantID(), duration.Round(time.Millisecond))
} else {
kunlog.Error("[AGENT] Request %s failed: assistant=%s, duration=%v, error=%v",
l.shortID, l.currentAssistantID(), duration.Round(time.Millisecond), err)
}
if !config.IsDevelopment() {
return
}
fmt.Printf("%s%s%s\n", colorCyan, strings.Repeat("─", 60), colorReset)
if success {
fmt.Printf("%s REQUEST %s COMPLETED%s\n", colorBoldGreen, l.shortID, colorReset)
} else {
fmt.Printf("%s REQUEST %s FAILED%s\n", colorBoldRed, l.shortID, colorReset)
if err != nil {
fmt.Printf("%s Error: %s%v%s\n", colorGray, colorRed, err, colorReset)
}
}
fmt.Printf("%s Assistant: %s%s%s\n", colorGray, colorWhite, l.currentAssistantID(), colorReset)
fmt.Printf("%s Duration: %s%v%s\n", colorGray, colorWhite, duration.Round(time.Millisecond), colorReset)
fmt.Printf("%s%s%s\n", colorCyan, strings.Repeat("─", 60), colorReset)
fmt.Println()
}
// Phase logs a major phase in the request lifecycle
func (l *RequestLogger) Phase(name string) {
if l.noop {
return
}
elapsed := time.Since(l.startTime).Round(time.Millisecond)
kunlog.Trace("[AGENT] %s Phase: %s (+%v)", l.shortID, name, elapsed)
if !config.IsDevelopment() {
return
}
fmt.Printf("%s > %s%s %s[+%v]%s\n", colorBoldBlue, name, colorReset, colorGray, elapsed, colorReset)
}
// PhaseComplete logs the completion of a phase
func (l *RequestLogger) PhaseComplete(name string) {
if l.noop {
return
}
elapsed := time.Since(l.startTime).Round(time.Millisecond)
kunlog.Trace("[AGENT] %s Phase completed: %s (+%v)", l.shortID, name, elapsed)
if !config.IsDevelopment() {
return
}
fmt.Printf("%s + %s%s %s[+%v]%s\n", colorGreen, name, colorReset, colorGray, elapsed, colorReset)
}
// PhaseSkip logs a skipped phase (development only)
func (l *RequestLogger) PhaseSkip(name, reason string) {
if l.noop {
return
}
if !config.IsDevelopment() {
return
}
fmt.Printf("%s - %s (%s)%s\n", colorGray, name, reason, colorReset)
}
// LLMStart logs the start of an LLM call
func (l *RequestLogger) LLMStart(connector, model string, messageCount int) {
if l.noop {
return
}
elapsed := time.Since(l.startTime).Round(time.Millisecond)
kunlog.Trace("[AGENT] %s LLM call: connector=%s, model=%s, messages=%d (+%v)", l.shortID, connector, model, messageCount, elapsed)
if !config.IsDevelopment() {
return
}
fmt.Printf("%s LLM Call%s %s[+%v]%s\n", colorBoldMagenta, colorReset, colorGray, elapsed, colorReset)
fmt.Printf("%s Connector: %s%s%s\n", colorGray, colorWhite, connector, colorReset)
if model != "" {
fmt.Printf("%s Model: %s%s%s\n", colorGray, colorWhite, model, colorReset)
}
fmt.Printf("%s Messages: %s%d%s\n", colorGray, colorWhite, messageCount, colorReset)
}
// LLMComplete logs the completion of an LLM call
func (l *RequestLogger) LLMComplete(tokens int, hasToolCalls bool) {
if l.noop {
return
}
elapsed := time.Since(l.startTime).Round(time.Millisecond)
status := "streaming"
if hasToolCalls {
status = "tool_calls"
}
kunlog.Trace("[AGENT] %s LLM response: status=%s, tokens=%d (+%v)", l.shortID, status, tokens, elapsed)
if !config.IsDevelopment() {
return
}
fmt.Printf("%s + LLM Response (%s)%s", colorGreen, status, colorReset)
if tokens > 0 {
fmt.Printf(" %s[tokens: %d]%s", colorGray, tokens, colorReset)
}
fmt.Printf(" %s[+%v]%s\n", colorGray, elapsed, colorReset)
}
// ToolStart logs the start of tool execution
func (l *RequestLogger) ToolStart(toolName string) {
if l.noop {
return
}
kunlog.Trace("[AGENT] %s Tool call: %s", l.shortID, toolName)
if !config.IsDevelopment() {
return
}
fmt.Printf("%s Tool: %s%s\n", colorYellow, toolName, colorReset)
}
// ToolComplete logs the completion of tool execution
func (l *RequestLogger) ToolComplete(toolName string, success bool) {
if l.noop {
return
}
if success {
kunlog.Trace("[AGENT] %s Tool completed: %s", l.shortID, toolName)
} else {
kunlog.Error("[AGENT] %s Tool failed: %s", l.shortID, toolName)
}
if !config.IsDevelopment() {
return
}
if success {
fmt.Printf("%s + %s completed%s\n", colorGreen, toolName, colorReset)
} else {
fmt.Printf("%s x %s failed%s\n", colorRed, toolName, colorReset)
}
}
// HookStart logs the start of a hook execution
func (l *RequestLogger) HookStart(hookName string) {
if l.noop {
return
}
elapsed := time.Since(l.startTime).Round(time.Millisecond)
kunlog.Trace("[AGENT] %s Hook: %s (+%v)", l.shortID, hookName, elapsed)
if !config.IsDevelopment() {
return
}
fmt.Printf("%s Hook: %s%s %s[+%v]%s\n", colorMagenta, hookName, colorReset, colorGray, elapsed, colorReset)
}
// HookComplete logs the completion of a hook
func (l *RequestLogger) HookComplete(hookName string) {
if l.noop {
return
}
kunlog.Trace("[AGENT] %s Hook completed: %s", l.shortID, hookName)
if !config.IsDevelopment() {
return
}
fmt.Printf("%s + %s done%s\n", colorGreen, hookName, colorReset)
}
// Cleanup logs resource cleanup
func (l *RequestLogger) Cleanup(resource string) {
if l.noop {
return
}
kunlog.Trace("[AGENT] %s Cleanup: %s", l.shortID, resource)
if !config.IsDevelopment() {
return
}
fmt.Printf("%s + %s%s\n", colorGray, resource, colorReset)
}
// HistoryLoad logs history loading
func (l *RequestLogger) HistoryLoad(count, maxSize int) {
if l.noop {
return
}
kunlog.Trace("[AGENT] %s History loaded: %d/%d messages", l.shortID, count, maxSize)
if !config.IsDevelopment() {
return
}
fmt.Printf("%s Loaded %d/%d history messages%s\n", colorGray, count, maxSize, colorReset)
}
// HistoryOverlap logs overlap detection
func (l *RequestLogger) HistoryOverlap(overlapCount int) {
if l.noop {
return
}
if overlapCount > 0 {
kunlog.Trace("[AGENT] %s History overlap removed: %d messages", l.shortID, overlapCount)
if !config.IsDevelopment() {
return
}
fmt.Printf("%s Removed %d overlapping messages%s\n", colorYellow, overlapCount, colorReset)
}
}
// Release logs the start of resource release phase
func (l *RequestLogger) Release() {
if l.noop {
return
}
kunlog.Trace("[AGENT] %s Release started", l.shortID)
if !config.IsDevelopment() {
return
}
fmt.Printf("%s RELEASE %s%s %s(%s)%s\n", colorBoldYellow, l.shortID, colorReset, colorGray, l.currentAssistantID(), colorReset)
}
// =============================================================================
// Helper
// =============================================================================
// shortID returns first 8 characters of an ID
func shortID(id string) string {
if len(id) > 8 {
return id[:8]
}
return id
}