From cbace3407c20bd66e39847659ba7d708e9054f98 Mon Sep 17 00:00:00 2001 From: Levi Neely Date: Fri, 27 Feb 2026 12:12:08 +0100 Subject: [PATCH] Update changes --- cmd/Assist/main.go | 5 +++-- cmd/anvillm/main.go | 8 ++++++-- cmd/anvilsrv/main.go | 35 ++++++++++++++++++++++++-------- cmd/anvilweb/main.go | 6 ++++-- cmd/anvilwebgw/main.go | 25 +++++++++++++++-------- internal/backend/tmux/session.go | 7 +++++++ internal/logging/logger.go | 8 +++++++- internal/session/manager.go | 12 +++++++++-- 8 files changed, 80 insertions(+), 26 deletions(-) diff --git a/cmd/Assist/main.go b/cmd/Assist/main.go index de88233..abc759d 100644 --- a/cmd/Assist/main.go +++ b/cmd/Assist/main.go @@ -6,7 +6,6 @@ import ( "encoding/json" "flag" "fmt" - "log" "os" "os/exec" "path/filepath" @@ -71,7 +70,8 @@ var ( func main() { if err := logging.Init(); err != nil { - log.Fatalf("Failed to initialize logging: %v", err) + fmt.Fprintf(os.Stderr, "Failed to initialize logging: %v\n", err) + os.Exit(1) } defer logging.Logger().Sync() @@ -888,6 +888,7 @@ func handleContextWindow(w *acme.Win, sess *SessionInfo) { fmt.Fprintf(os.Stderr, "Error writing context: %v\n", err) } else { w.Ctl("clean") + logging.Logger().Info("context updated", zap.String("session", sess.ID)) fmt.Printf("Context updated for session %s\n", sess.ID) } continue diff --git a/cmd/anvillm/main.go b/cmd/anvillm/main.go index 0b599e3..edd6e4d 100644 --- a/cmd/anvillm/main.go +++ b/cmd/anvillm/main.go @@ -5,7 +5,6 @@ import ( "anvillm/internal/logging" "encoding/json" "fmt" - "log" "os" "os/exec" "path/filepath" @@ -44,7 +43,8 @@ type SessionInfo struct { func main() { if err := logging.Init(); err != nil { - log.Fatalf("Failed to initialize logging: %v", err) + fmt.Fprintf(os.Stderr, "Failed to initialize logging: %v\n", err) + os.Exit(1) } defer logging.Logger().Sync() @@ -1117,6 +1117,7 @@ func attachToSession() { tmuxPath := filepath.Join(sess.ID, "tmux") tmuxData, err := readFile(tmuxPath) if err != nil { + logging.Logger().Error("failed to read tmux session", zap.String("session", sess.ID), zap.Error(err)) fmt.Printf("Error reading tmux session: %v\n", err) fmt.Println("Press Enter to continue...") fmt.Scanln() @@ -1125,6 +1126,7 @@ func attachToSession() { tmuxSession := strings.TrimSpace(string(tmuxData)) if tmuxSession == "" { + logging.Logger().Warn("no tmux session found", zap.String("session", sess.ID)) fmt.Println("No tmux session found for this agent") fmt.Println("Press Enter to continue...") fmt.Scanln() @@ -1132,6 +1134,7 @@ func attachToSession() { } // Attach to tmux + logging.Logger().Info("attaching to tmux session", zap.String("session", sess.ID), zap.String("tmux", tmuxSession)) fmt.Printf("Attaching to tmux session: %s\n", tmuxSession) fmt.Printf("Press Ctrl-b d to detach\n\n") @@ -1141,6 +1144,7 @@ func attachToSession() { cmd.Stderr = os.Stderr if err := cmd.Run(); err != nil { + logging.Logger().Error("failed to attach to tmux", zap.String("tmux", tmuxSession), zap.Error(err)) fmt.Printf("Error attaching to tmux: %v\n", err) fmt.Println("Press Enter to continue...") fmt.Scanln() diff --git a/cmd/anvilsrv/main.go b/cmd/anvilsrv/main.go index c02b6e6..ff8236b 100644 --- a/cmd/anvilsrv/main.go +++ b/cmd/anvilsrv/main.go @@ -10,7 +10,6 @@ import ( "anvillm/internal/session" "context" "fmt" - "log" "os" "os/signal" "path/filepath" @@ -83,7 +82,8 @@ func usage() { func start(daemonize bool) { // Initialize logging first if err := logging.Init(); err != nil { - log.Fatalf("Failed to initialize logging: %v", err) + fmt.Fprintf(os.Stderr, "Failed to initialize logging: %v\n", err) + os.Exit(1) } defer logging.Logger().Sync() @@ -100,6 +100,7 @@ func start(daemonize bool) { logging.Logger().Fatal("agent already running", zap.Int("pid", existingPid)) } // Stale PID file + logging.Logger().Warn("removing stale PID file", zap.Int("pid", existingPid)) os.Remove(pidFile) } @@ -107,10 +108,12 @@ func start(daemonize bool) { if daemonize { // Check if we're already the daemon (via environment variable) if os.Getenv("ANVILSRV_DAEMON") != "1" { + logging.Logger().Info("daemonizing anvilsrv") // Fork the daemon process - use full path to executable cmd, err := os.Executable() if err != nil { - log.Fatalf("Failed to get executable path: %v", err) + fmt.Fprintf(os.Stderr, "Failed to get executable path: %v\n", err) + os.Exit(1) } args := []string{"fgstart"} // Use fgstart to avoid re-daemonizing @@ -122,7 +125,8 @@ func start(daemonize bool) { proc, err := os.StartProcess(cmd, append([]string{cmd}, args...), attr) if err != nil { - log.Fatalf("Failed to daemonize: %v", err) + fmt.Fprintf(os.Stderr, "Failed to daemonize: %v\n", err) + os.Exit(1) } // Wait a moment to ensure daemon starts and writes PID file @@ -146,29 +150,34 @@ func start(daemonize bool) { pid := os.Getpid() pidContent := fmt.Sprintf("%d\n", pid) + logging.Logger().Info("starting anvilsrv", zap.Int("pid", pid), zap.Bool("daemonized", daemonize)) + // Try to create PID file exclusively (fails if exists) f, err := os.OpenFile(pidFile, os.O_CREATE|os.O_EXCL|os.O_WRONLY, 0644) if err != nil { // File exists, check if process is still running if existingPid := readPidFile(); existingPid != 0 { if isProcessRunning(existingPid) { - log.Fatalf("anvilsrv already running (PID %d)", existingPid) + logging.Logger().Fatal("anvilsrv already running", zap.Int("pid", existingPid)) } // Stale PID file, remove and retry + logging.Logger().Warn("removing stale PID file on startup", zap.Int("pid", existingPid)) os.Remove(pidFile) f, err = os.OpenFile(pidFile, os.O_CREATE|os.O_EXCL|os.O_WRONLY, 0644) if err != nil { - log.Fatalf("Failed to create PID file: %v", err) + fmt.Fprintf(os.Stderr, "Failed to create PID file: %v\n", err) + os.Exit(1) } } else { - log.Fatalf("Failed to create PID file: %v", err) + fmt.Fprintf(os.Stderr, "Failed to create PID file: %v\n", err) + os.Exit(1) } } if _, err := f.WriteString(pidContent); err != nil { f.Close() os.Remove(pidFile) - log.Fatalf("Failed to write PID file: %v", err) + logging.Logger().Fatal("failed to write PID file", zap.Error(err)) } f.Close() defer os.Remove(pidFile) @@ -179,6 +188,7 @@ func start(daemonize bool) { // Create all backends nsSuffix := getNamespaceSuffix() + logging.Logger().Debug("initializing backends", zap.String("namespace_suffix", nsSuffix)) backendMap := map[string]backend.Backend{ "kiro-cli": backends.NewKiroCLI(nsSuffix), "claude": backends.NewClaude(nsSuffix), @@ -186,6 +196,7 @@ func start(daemonize bool) { } mgr := session.NewManager(backendMap) + logging.Logger().Info("session manager initialized") // Cleanup tmux sessions on exit defer func() { @@ -205,6 +216,7 @@ func start(daemonize bool) { if beadsDir == "" { beadsDir = filepath.Join(os.Getenv("HOME"), ".beads") } + logging.Logger().Debug("initializing beads store", zap.String("path", beadsDir)) beadsStore, err := bd.OpenFromConfig(context.Background(), beadsDir) if err != nil { logging.Logger().Warn("failed to initialize beads store", zap.Error(err)) @@ -212,6 +224,7 @@ func start(daemonize bool) { } if beadsStore != nil { defer beadsStore.Close() + logging.Logger().Info("beads store initialized", zap.String("path", beadsDir)) } // Start 9P server @@ -228,6 +241,7 @@ func start(daemonize bool) { // Start background monitor for self-healing stopMonitor := make(chan struct{}) + logging.Logger().Debug("starting background session monitor") go func() { defer func() { if r := recover(); r != nil { @@ -245,6 +259,7 @@ func start(daemonize bool) { } } case <-stopMonitor: + logging.Logger().Debug("stopping background session monitor") return } } @@ -282,7 +297,8 @@ func stop() { os.Exit(1) } - fmt.Printf("Sent SIGTERM to anvilsrv (PID %d)\n", pid) + logging.Logger().Info("stopping anvilsrv", zap.Int("pid", pid)) + fmt.Printf("Stopping anvilsrv (PID %d)\n", pid) } func status() { @@ -297,6 +313,7 @@ func status() { os.Exit(1) } + logging.Logger().Info("anvilsrv status check", zap.Int("pid", pid), zap.Bool("running", true)) fmt.Printf("anvilsrv is running (PID %d)\n", pid) } diff --git a/cmd/anvilweb/main.go b/cmd/anvilweb/main.go index 745a251..e8ae4a6 100644 --- a/cmd/anvilweb/main.go +++ b/cmd/anvilweb/main.go @@ -9,11 +9,12 @@ import ( "anvillm/internal/logging" "embed" "flag" + "fmt" "io/fs" - "log" "net/http" "net/http/httputil" "net/url" + "os" "go.uber.org/zap" ) @@ -28,7 +29,8 @@ var ( func main() { if err := logging.Init(); err != nil { - log.Fatalf("Failed to initialize logging: %v", err) + fmt.Fprintf(os.Stderr, "Failed to initialize logging: %v\n", err) + os.Exit(1) } defer logging.Logger().Sync() diff --git a/cmd/anvilwebgw/main.go b/cmd/anvilwebgw/main.go index 4842c2d..fb132ad 100644 --- a/cmd/anvilwebgw/main.go +++ b/cmd/anvilwebgw/main.go @@ -10,7 +10,6 @@ import ( "flag" "fmt" "io" - "log" "net/http" "os" "os/exec" @@ -80,7 +79,8 @@ func usage() { func startCmd(daemonize bool) { if err := logging.Init(); err != nil { - log.Fatalf("Failed to initialize logging: %v", err) + fmt.Fprintf(os.Stderr, "Failed to initialize logging: %v\n", err) + os.Exit(1) } defer logging.Logger().Sync() @@ -92,12 +92,14 @@ func startCmd(daemonize bool) { logging.Logger().Fatal("anvilwebgw already running", zap.Int("pid", existingPid)) } // Stale PID file + logging.Logger().Warn("removing stale PID file", zap.Int("pid", existingPid)) os.Remove(pidFile) } // Daemonize if requested if daemonize { if os.Getenv("ANVILWEBGW_DAEMON") != "1" { + logging.Logger().Info("daemonizing anvilwebgw") cmd, err := os.Executable() if err != nil { logging.Logger().Fatal("failed to get executable path", zap.Error(err)) @@ -116,7 +118,8 @@ func startCmd(daemonize bool) { proc, err := os.StartProcess(cmd, append([]string{cmd}, fwdArgs...), attr) if err != nil { - log.Fatalf("Failed to daemonize: %v", err) + fmt.Fprintf(os.Stderr, "Failed to daemonize: %v\n", err) + os.Exit(1) } proc.Release() @@ -134,25 +137,29 @@ func startCmd(daemonize bool) { // We're the daemon (or running in foreground) pid := os.Getpid() + logging.Logger().Info("starting anvilwebgw", zap.Int("pid", pid), zap.Bool("daemonized", daemonize)) f, err := os.OpenFile(pidFile, os.O_CREATE|os.O_EXCL|os.O_WRONLY, 0644) if err != nil { if existingPid := readPidFile(); existingPid != 0 { if isProcessRunning(existingPid) { - log.Fatalf("anvilwebgw already running (PID %d)", existingPid) + logging.Logger().Fatal("anvilwebgw already running", zap.Int("pid", existingPid)) } + logging.Logger().Warn("removing stale PID file on startup", zap.Int("pid", existingPid)) os.Remove(pidFile) f, err = os.OpenFile(pidFile, os.O_CREATE|os.O_EXCL|os.O_WRONLY, 0644) if err != nil { - log.Fatalf("Failed to create PID file: %v", err) + fmt.Fprintf(os.Stderr, "Failed to create PID file: %v\n", err) + os.Exit(1) } } else { - log.Fatalf("Failed to create PID file: %v", err) + fmt.Fprintf(os.Stderr, "Failed to create PID file: %v\n", err) + os.Exit(1) } } if _, err := fmt.Fprintf(f, "%d\n", pid); err != nil { f.Close() os.Remove(pidFile) - log.Fatalf("Failed to write PID file: %v", err) + logging.Logger().Fatal("failed to write PID file", zap.Error(err)) } f.Close() defer os.Remove(pidFile) @@ -223,7 +230,8 @@ func stopCmd() { os.Exit(1) } - fmt.Printf("Sent SIGTERM to anvilwebgw (PID %d)\n", pid) + logging.Logger().Info("stopping anvilwebgw", zap.Int("pid", pid)) + fmt.Printf("Stopping anvilwebgw (PID %d)\n", pid) } func statusCmd() { @@ -238,6 +246,7 @@ func statusCmd() { os.Exit(1) } + logging.Logger().Info("anvilwebgw status check", zap.Int("pid", pid), zap.Bool("running", true)) fmt.Printf("anvilwebgw is running (PID %d)\n", pid) } diff --git a/internal/backend/tmux/session.go b/internal/backend/tmux/session.go index 82361b4..5117389 100644 --- a/internal/backend/tmux/session.go +++ b/internal/backend/tmux/session.go @@ -139,13 +139,16 @@ func (s *Session) transitionToLocked(newState string) error { s.idleCond.Broadcast() case s.state == "error" && newState == "starting": // Restart from error state + logging.Logger().Info("restarting from error state", zap.String("session", s.id)) s.state = newState case newState == "stopped" || newState == "killed": // Allow transition to stopped/exited from any state + logging.Logger().Info("session stopped", zap.String("session", s.id), zap.String("old_state", oldState), zap.String("new_state", newState)) s.state = newState s.idleCond.Broadcast() case s.state == "stopped" && newState == "starting": // Allow restart from stopped state + logging.Logger().Info("restarting from stopped state", zap.String("session", s.id)) s.state = newState default: return fmt.Errorf("invalid state transition: %s → %s", s.state, newState) @@ -437,6 +440,8 @@ func (s *Session) Send(ctx context.Context, prompt string) (string, error) { } } + logging.Logger().Debug("sending prompt to session", zap.String("session", s.id), zap.Int("prompt_length", len(prompt))) + // Instruction to send response via mailbox (triggers idle transition) outInstruction := fmt.Sprintf("When done, send your response using the send_message tool:\n from: %s\n to: [sender's agent_id, or \"user\"]\n type: [PROMPT_RESPONSE, REVIEW_RESPONSE, QUERY_RESPONSE, or APPROVAL_RESPONSE]\n subject: [brief description of what you did]\n body: YOUR_SUMMARY_HERE\n", s.id) @@ -474,6 +479,8 @@ func (s *Session) Send(ctx context.Context, prompt string) (string, error) { return "", fmt.Errorf("send enter failed: %w", err) } + logging.Logger().Info("prompt sent to session", zap.String("session", s.id)) + // Hook handles state transitions return "", nil } diff --git a/internal/logging/logger.go b/internal/logging/logger.go index 04aec50..323696b 100644 --- a/internal/logging/logger.go +++ b/internal/logging/logger.go @@ -35,8 +35,14 @@ func Init() error { return err } - core := zapcore.NewCore(fileEncoder, zapcore.AddSync(logFile), zapcore.InfoLevel) + logLevel := zapcore.InfoLevel + if os.Getenv("ANVILLM_DEBUG") != "" { + logLevel = zapcore.DebugLevel + } + + core := zapcore.NewCore(fileEncoder, zapcore.AddSync(logFile), logLevel) logger = zap.New(core, zap.AddCaller(), zap.AddStacktrace(zapcore.ErrorLevel)) + logger.Info("logging initialized", zap.String("program", progName), zap.String("log_file", logPath), zap.String("level", logLevel.String())) return nil } diff --git a/internal/session/manager.go b/internal/session/manager.go index 83d2f3c..3109d63 100644 --- a/internal/session/manager.go +++ b/internal/session/manager.go @@ -89,11 +89,14 @@ func (m *Manager) New(opts backend.SessionOptions, backendName string) (backend. m.mu.RUnlock() if !ok { + logging.Logger().Warn("backend not found", zap.String("backend", backendName)) return nil, backend.ErrBackendNotFound } + logging.Logger().Info("creating new session", zap.String("backend", backendName), zap.String("cwd", opts.CWD)) sess, err := b.CreateSession(context.Background(), opts) if err != nil { + logging.Logger().Error("failed to create session", zap.String("backend", backendName), zap.Error(err)) return nil, err } @@ -113,6 +116,7 @@ func (m *Manager) New(opts backend.SessionOptions, backendName string) (backend. // Create mailbox structure for new session m.mailManager.EnsureMailbox(sess.ID()) + logging.Logger().Info("session created", zap.String("id", sess.ID()), zap.String("backend", backendName)) return sess, nil } @@ -165,8 +169,12 @@ func (m *Manager) List() []string { // Remove removes a session from the manager func (m *Manager) Remove(id string) { m.mu.Lock() - delete(m.sessions, id) - m.mu.Unlock() + defer m.mu.Unlock() + + if _, exists := m.sessions[id]; exists { + logging.Logger().Info("removing session", zap.String("id", id)) + delete(m.sessions, id) + } } // Stop stops the mail processing loop