feat: improve logging (#105)

This commit is contained in:
Carlos Florêncio
2026-01-27 00:18:42 +00:00
committed by GitHub
parent 9463ddac9f
commit 7c82ccdf24
16 changed files with 100 additions and 47 deletions
+9 -9
View File
@@ -420,7 +420,7 @@ func main() {
if err != nil {
log.Error("Failed to subscribe to message.added events", zap.Error(err))
} else {
log.Info("Subscribed to message.added events for WebSocket broadcasting")
log.Debug("Subscribed to message.added events for WebSocket broadcasting")
}
// Subscribe to message.updated events and broadcast to WebSocket subscribers
@@ -460,7 +460,7 @@ func main() {
if err != nil {
log.Error("Failed to subscribe to message.updated events", zap.Error(err))
} else {
log.Info("Subscribed to message.updated events for WebSocket broadcasting")
log.Debug("Subscribed to message.updated events for WebSocket broadcasting")
}
// Subscribe to task_session.state_changed events and broadcast to task subscribers
@@ -484,7 +484,7 @@ func main() {
if err != nil {
log.Error("Failed to subscribe to task_session.state_changed events", zap.Error(err))
} else {
log.Info("Subscribed to task_session.state_changed events for WebSocket broadcasting")
log.Debug("Subscribed to task_session.state_changed events for WebSocket broadcasting")
}
// ============================================
@@ -525,22 +525,22 @@ func main() {
log,
)
taskhandlers.RegisterProcessRoutes(router, taskSvc, lifecycleMgr, log)
log.Info("Registered Task Service handlers (HTTP + WebSocket)")
log.Debug("Registered Task Service handlers (HTTP + WebSocket)")
agentsettingshandlers.RegisterRoutes(router, agentSettingsController, gateway.Hub, log)
log.Info("Registered Agent Settings handlers (HTTP)")
log.Debug("Registered Agent Settings handlers (HTTP)")
userhandlers.RegisterRoutes(router, gateway.Dispatcher, userCtrl, log)
log.Info("Registered User handlers (HTTP + WebSocket)")
log.Debug("Registered User handlers (HTTP + WebSocket)")
notificationhandlers.RegisterRoutes(router, notificationCtrl, log)
log.Info("Registered Notification handlers (HTTP)")
log.Debug("Registered Notification handlers (HTTP)")
editorhandlers.RegisterRoutes(router, editorCtrl, log)
log.Info("Registered Editors handlers (HTTP)")
log.Debug("Registered Editors handlers (HTTP)")
prompthandlers.RegisterRoutes(router, promptCtrl, log)
log.Info("Registered Prompts handlers (HTTP)")
log.Debug("Registered Prompts handlers (HTTP)")
// Health check (simple HTTP for load balancers/monitoring)
router.GET("/health", func(c *gin.Context) {
+1 -1
View File
@@ -441,7 +441,7 @@ func (c *Client) Ping(ctx context.Context) error {
_, err := c.cli.Ping(ctx)
if err != nil {
c.logger.Error("Docker ping failed", zap.Error(err))
c.logger.Warn("Docker ping failed", zap.Error(err))
return fmt.Errorf("docker ping failed: %w", err)
}
@@ -603,7 +603,7 @@ func (m *Manager) StopAllAgents(ctx context.Context) error {
// Launch launches a new agent for a task
func (m *Manager) Launch(ctx context.Context, req *LaunchRequest) (*AgentExecution, error) {
m.logger.Info("launching agent",
m.logger.Debug("launching agent",
zap.String("task_id", req.TaskID),
zap.String("agent_profile_id", req.AgentProfileID),
zap.Bool("use_worktree", req.UseWorktree))
@@ -618,7 +618,7 @@ func (m *Manager) Launch(ctx context.Context, req *LaunchRequest) (*AgentExecuti
return nil, fmt.Errorf("failed to resolve agent profile: %w", err)
}
agentTypeName = profileInfo.AgentName
m.logger.Info("resolved agent profile",
m.logger.Debug("resolved agent profile",
zap.String("profile_id", req.AgentProfileID),
zap.String("agent_name", profileInfo.AgentName),
zap.String("agent_type", agentTypeName))
@@ -819,7 +819,7 @@ func (m *Manager) Launch(ctx context.Context, req *LaunchRequest) (*AgentExecuti
// NOTE: This does NOT start the agent process - call StartAgentProcess() explicitly
go m.waitForAgentctlReady(execution)
m.logger.Info("agentctl execution created (agent not started)",
m.logger.Debug("agentctl execution created (agent not started)",
zap.String("execution_id", executionID),
zap.String("task_id", req.TaskID),
zap.String("runtime", execution.RuntimeName))
@@ -993,7 +993,7 @@ func (m *Manager) getOrCreateWorktree(ctx context.Context, req *LaunchRequest) (
}
if worktreeID != "" && wt.ID == worktreeID {
m.logger.Info("reusing existing worktree for session resumption",
m.logger.Debug("reusing existing worktree for session resumption",
zap.String("task_id", req.TaskID),
zap.String("worktree_id", wt.ID),
zap.String("worktree_path", wt.Path),
@@ -1017,7 +1017,7 @@ func (m *Manager) waitForAgentctlReady(execution *AgentExecution) {
ctx, cancel := appctx.Detached(context.Background(), m.stopCh, 60*time.Second)
defer cancel()
m.logger.Info("waiting for agentctl to be ready",
m.logger.Debug("waiting for agentctl to be ready",
zap.String("execution_id", execution.ID),
zap.String("url", execution.agentctl.BaseURL()))
@@ -1038,7 +1038,7 @@ func (m *Manager) waitForAgentctlReady(execution *AgentExecution) {
zap.String("execution_id", execution.ID),
zap.Duration("duration", elapsed))
} else {
m.logger.Info("agentctl ready - shell/workspace access available",
m.logger.Debug("agentctl ready - shell/workspace access available",
zap.String("execution_id", execution.ID),
zap.Duration("duration", elapsed))
}
@@ -126,7 +126,7 @@ func (r *StandaloneRuntime) CreateInstance(ctx context.Context, req *RuntimeCrea
metadata["worktree_branch"] = worktreeBranch
}
r.logger.Info("standalone instance created",
r.logger.Debug("standalone instance created",
zap.String("instance_id", req.InstanceID),
zap.Int("port", resp.Port),
zap.String("workspace", req.WorkspacePath))
@@ -301,7 +301,7 @@ func (r *Registry) LoadFromFile(path string) error {
continue
}
r.agents[config.ID] = config
r.logger.Info("loaded agent type", zap.String("id", config.ID))
r.logger.Debug("loaded agent type", zap.String("id", config.ID))
}
return nil
@@ -316,7 +316,7 @@ func (r *Registry) LoadDefaults() {
for _, config := range defaults {
r.agents[config.ID] = config
r.logger.Info("loaded default agent type", zap.String("id", config.ID))
r.logger.Debug("loaded default agent type", zap.String("id", config.ID))
}
}
@@ -278,8 +278,7 @@ func (l *Launcher) waitForHealthy(ctx context.Context) error {
func (l *Launcher) pipeOutput(name string, scanner *bufio.Scanner) {
for scanner.Scan() {
line := scanner.Text()
// Log at info level with agentctl prefix
l.logger.Info(line, zap.String("stream", name))
l.logger.Debug(line, zap.String("stream", name))
}
}
@@ -41,6 +41,7 @@ func setupTestRepo(t *testing.T) (string, func()) {
runGit(t, localDir, "init", "--initial-branch=main")
runGit(t, localDir, "config", "user.email", "test@test.com")
runGit(t, localDir, "config", "user.name", "Test User")
runGit(t, localDir, "config", "core.hooksPath", "/dev/null") // Disable hooks in test repo
// Create initial commit
writeFile(t, localDir, "README.md", "# Test Repo")
@@ -56,8 +57,11 @@ func setupTestRepo(t *testing.T) (string, func()) {
func runGit(t *testing.T, dir string, args ...string) string {
t.Helper()
cmd := exec.Command("git", args...)
cmd.Dir = dir
// Use git -C flag to ensure we're in the right directory
// This is more reliable than cmd.Dir as it prevents git from
// walking up to find a parent .git directory
fullArgs := append([]string{"-C", dir}, args...)
cmd := exec.Command("git", fullArgs...)
out, err := cmd.CombinedOutput()
if err != nil {
t.Fatalf("git %v failed: %v\nOutput: %s", args, err, out)
@@ -68,7 +72,7 @@ func runGit(t *testing.T, dir string, args ...string) string {
func writeFile(t *testing.T, dir, name, content string) {
t.Helper()
path := filepath.Join(dir, name)
if err := os.WriteFile(path, []byte(content), 0644); err != nil {
if err := os.WriteFile(path, []byte(content), 0o644); err != nil {
t.Fatalf("failed to write file %s: %v", name, err)
}
}
@@ -230,6 +234,7 @@ func TestFilterLocalCommits_PullAndResetScenario(t *testing.T) {
runGit(t, localDir, "init", "--initial-branch=main")
runGit(t, localDir, "config", "user.email", "test@test.com")
runGit(t, localDir, "config", "user.name", "Test User")
runGit(t, localDir, "config", "core.hooksPath", "/dev/null") // Disable hooks in test repo
writeFile(t, localDir, "README.md", "# Test Repo")
runGit(t, localDir, "add", ".")
runGit(t, localDir, "commit", "-m", "Initial commit (X)")
@@ -244,6 +249,7 @@ func TestFilterLocalCommits_PullAndResetScenario(t *testing.T) {
runGit(t, upstreamClone, "clone", remoteDir, ".")
runGit(t, upstreamClone, "config", "user.email", "upstream@test.com")
runGit(t, upstreamClone, "config", "user.name", "Upstream User")
runGit(t, upstreamClone, "config", "core.hooksPath", "/dev/null") // Disable hooks in test repo
// Make upstream commits Y and Z
writeFile(t, upstreamClone, "upstream1.txt", "upstream content 1")
@@ -295,4 +301,3 @@ func TestFilterLocalCommits_PullAndResetScenario(t *testing.T) {
}
}
}
+20 -1
View File
@@ -4,6 +4,7 @@ package config
import (
"fmt"
"os"
"strings"
"time"
@@ -130,6 +131,24 @@ func (a *AuthConfig) TokenDurationTime() time.Duration {
return time.Duration(a.TokenDuration) * time.Second
}
// detectDefaultLogFormat returns the appropriate log format based on environment.
// Returns "json" if running in Kubernetes or other production environments.
// Returns "text" for terminal/development use (human-readable console format).
func detectDefaultLogFormat() string {
// Check if running in Kubernetes
if os.Getenv("KUBERNETES_SERVICE_HOST") != "" {
return "json"
}
// Check for explicit production environment
if env := os.Getenv("KANDEV_ENV"); env == "production" || env == "prod" {
return "json"
}
// Default to text format for terminal use (more readable than JSON)
return "text"
}
// setDefaults configures default values for all configuration options.
func setDefaults(v *viper.Viper) {
// Server defaults
@@ -175,7 +194,7 @@ func setDefaults(v *viper.Viper) {
// Logging defaults
v.SetDefault("logging.level", "info")
v.SetDefault("logging.format", "json")
v.SetDefault("logging.format", detectDefaultLogFormat())
v.SetDefault("logging.outputPath", "stdout")
// Repository discovery defaults
+19 -8
View File
@@ -26,13 +26,24 @@ func RequestLogger(log *logger.Logger, serverName string) gin.HandlerFunc {
size = 0
}
log.Info("http",
zap.String("server", serverName),
zap.String("method", c.Request.Method),
zap.String("path", path),
zap.Int("status", status),
zap.Int64("duration_ms", latency.Milliseconds()),
zap.Int("bytes", size),
)
if status >= 500 {
log.Error("http",
zap.String("server", serverName),
zap.String("method", c.Request.Method),
zap.String("path", path),
zap.Int("status", status),
zap.Int64("duration_ms", latency.Milliseconds()),
zap.Int("bytes", size),
)
} else {
log.Debug("http",
zap.String("server", serverName),
zap.String("method", c.Request.Method),
zap.String("path", path),
zap.Int("status", status),
zap.Int64("duration_ms", latency.Milliseconds()),
zap.Int("bytes", size),
)
}
}
}
+22 -3
View File
@@ -38,13 +38,13 @@ var (
)
// Default returns the global default logger.
// This logger is initialized with default settings (info level, json format, stdout).
// This logger is initialized with default settings (info level, text format for terminals, stdout).
func Default() *Logger {
defaultLoggerOnce.Do(func() {
var err error
defaultLogger, err = NewLogger(LoggingConfig{
Level: "info",
Format: "json",
Format: detectLogFormat(),
OutputPath: "stdout",
})
if err != nil {
@@ -77,7 +77,8 @@ func NewLogger(cfg LoggingConfig) (*Logger, error) {
encoderConfig.EncodeLevel = zapcore.LowercaseLevelEncoder
var encoder zapcore.Encoder
if cfg.Format == "console" {
// Accept both "console" and "text" as aliases for human-readable format
if cfg.Format == "console" || cfg.Format == "text" {
encoderConfig.EncodeLevel = zapcore.CapitalColorLevelEncoder
encoder = zapcore.NewConsoleEncoder(encoderConfig)
} else {
@@ -113,6 +114,24 @@ func parseLevel(level string) (zapcore.Level, error) {
return l, err
}
// detectLogFormat returns the appropriate log format based on environment.
// Returns "json" if running in Kubernetes or other production environments.
// Returns "text" for terminal/development use (human-readable console format).
func detectLogFormat() string {
// Check if running in Kubernetes
if os.Getenv("KUBERNETES_SERVICE_HOST") != "" {
return "json"
}
// Check for explicit production environment
if env := os.Getenv("KANDEV_ENV"); env == "production" || env == "prod" {
return "json"
}
// Default to text format for terminal use (more readable than JSON)
return "text"
}
// Sync flushes any buffered log entries.
func (l *Logger) Sync() error {
return l.zap.Sync()
+2 -2
View File
@@ -168,7 +168,7 @@ func (b *MemoryEventBus) Subscribe(subject string, handler EventHandler) (Subscr
b.subscriptions[subject] = append(b.subscriptions[subject], sub)
b.logger.Info("Subscribed to subject", zap.String("subject", subject))
b.logger.Debug("Subscribed to subject", zap.String("subject", subject))
return sub, nil
}
@@ -202,7 +202,7 @@ func (b *MemoryEventBus) QueueSubscribe(subject, queue string, handler EventHand
}
b.queues[queueKey].subscribers = append(b.queues[queueKey].subscribers, sub)
b.logger.Info("Queue subscribed to subject",
b.logger.Debug("Queue subscribed to subject",
zap.String("subject", subject),
zap.String("queue", queue))
return sub, nil
+2 -2
View File
@@ -102,7 +102,7 @@ func (b *NATSEventBus) Subscribe(subject string, handler EventHandler) (Subscrip
return nil, fmt.Errorf("failed to subscribe to %s: %w", subject, err)
}
b.logger.Info("Subscribed to subject", zap.String("subject", subject))
b.logger.Debug("Subscribed to subject", zap.String("subject", subject))
return &natsSubscription{sub: sub}, nil
}
@@ -113,7 +113,7 @@ func (b *NATSEventBus) QueueSubscribe(subject, queue string, handler EventHandle
return nil, fmt.Errorf("failed to queue subscribe to %s: %w", subject, err)
}
b.logger.Info("Queue subscribed to subject",
b.logger.Debug("Queue subscribed to subject",
zap.String("subject", subject),
zap.String("queue", queue),
)
@@ -56,7 +56,7 @@ func (h *Handler) HandleConnection(c *gin.Context) {
// Create a unique client ID
clientID := uuid.New().String()
h.logger.Info("WebSocket connection established",
h.logger.Debug("WebSocket connection established",
zap.String("client_id", clientID),
zap.String("remote_addr", c.Request.RemoteAddr),
)
@@ -612,7 +612,7 @@ func (e *Executor) ResumeSession(ctx context.Context, session *models.TaskSessio
}
}
e.logger.Info("resuming agent session",
e.logger.Debug("resuming agent session",
zap.String("task_id", session.TaskID),
zap.String("session_id", session.ID),
zap.String("agent_profile_id", session.AgentProfileID),
@@ -443,7 +443,7 @@ func (s *Service) resumeExecutorsOnStartup(ctx context.Context) {
startAgent := running.ResumeToken != "" && running.Resumable
if !startAgent {
s.logger.Warn("resuming workspace without agent session",
s.logger.Debug("resuming workspace without agent session",
zap.String("session_id", sessionID),
zap.String("previous_state", string(previousState)),
zap.Bool("has_resume_token", running.ResumeToken != ""),
@@ -460,7 +460,7 @@ func (s *Service) resumeExecutorsOnStartup(ctx context.Context) {
continue
}
s.logger.Info("resuming session on startup",
s.logger.Debug("resuming session on startup",
zap.String("session_id", sessionID),
zap.String("task_id", running.TaskID),
zap.String("previous_state", string(previousState)),
@@ -496,7 +496,7 @@ func (s *Service) resumeExecutorsOnStartup(ctx context.Context) {
}
}
s.logger.Info("session resumed successfully",
s.logger.Debug("session resumed successfully",
zap.String("session_id", sessionID),
zap.String("task_id", running.TaskID),
zap.Bool("start_agent", startAgent),
+1 -1
View File
@@ -128,7 +128,7 @@ func (m *Manager) Create(ctx context.Context, req CreateRequest) (*Worktree, err
existing, err := m.GetBySessionID(ctx, req.SessionID)
if err == nil && existing != nil {
if m.IsValid(existing.Path) {
m.logger.Info("reusing existing worktree by session ID",
m.logger.Debug("reusing existing worktree by session ID",
zap.String("worktree_id", existing.ID),
zap.String("session_id", req.SessionID),
zap.String("task_id", req.TaskID),