diff --git a/apps/web/shared/logger.ts b/apps/web/shared/logger.ts new file mode 100644 index 00000000..3763afda --- /dev/null +++ b/apps/web/shared/logger.ts @@ -0,0 +1,51 @@ +type LogLevel = "debug" | "info" | "warn" | "error"; + +const COLORS: Record = { + debug: "color:#888", + info: "color:#2196F3", + warn: "color:#FF9800", + error: "color:#F44336;font-weight:bold", +}; + +const CONSOLE_METHOD: Record = { + debug: "log", + info: "info", + warn: "warn", + error: "error", +}; + +export interface Logger { + debug(msg: string, ...data: unknown[]): void; + info(msg: string, ...data: unknown[]): void; + warn(msg: string, ...data: unknown[]): void; + error(msg: string, ...data: unknown[]): void; +} + +export function createLogger(namespace: string): Logger { + const make = + (level: LogLevel) => + (msg: string, ...data: unknown[]) => { + const ts = new Date().toISOString().slice(11, 23); + const prefix = `%c${ts} [${namespace}]`; + if (data.length > 0) { + console[CONSOLE_METHOD[level]](prefix, COLORS[level], msg, ...data); + } else { + console[CONSOLE_METHOD[level]](prefix, COLORS[level], msg); + } + }; + + return { + debug: make("debug"), + info: make("info"), + warn: make("warn"), + error: make("error"), + }; +} + +/** No-op logger for when logging is not needed. */ +export const noopLogger: Logger = { + debug() {}, + info() {}, + warn() {}, + error() {}, +}; diff --git a/packages/sdk/src/api-client.ts b/packages/sdk/src/api-client.ts index 3acba400..05cb991b 100644 --- a/packages/sdk/src/api-client.ts +++ b/packages/sdk/src/api-client.ts @@ -24,6 +24,7 @@ import type { UpdateSkillRequest, SetAgentSkillsRequest, } from "@multica/types"; +import { type SDKLogger, noopLogger } from "./logger"; export interface LoginResponse { token: string; @@ -34,9 +35,11 @@ export class ApiClient { private baseUrl: string; private token: string | null = null; private workspaceId: string | null = null; + private logger: SDKLogger; - constructor(baseUrl: string) { + constructor(baseUrl: string, options?: { logger?: SDKLogger }) { this.baseUrl = baseUrl; + this.logger = options?.logger ?? noopLogger; } setToken(token: string | null) { @@ -48,8 +51,13 @@ export class ApiClient { } private async fetch(path: string, init?: RequestInit): Promise { + const rid = crypto.randomUUID().slice(0, 8); + const start = Date.now(); + const method = init?.method ?? "GET"; + const headers: Record = { "Content-Type": "application/json", + "X-Request-ID": rid, ...((init?.headers as Record) ?? {}), }; if (this.token) { @@ -59,6 +67,8 @@ export class ApiClient { headers["X-Workspace-ID"] = this.workspaceId; } + this.logger.info(`→ ${method} ${path}`, { rid }); + const res = await fetch(`${this.baseUrl}${path}`, { ...init, headers, @@ -74,9 +84,12 @@ export class ApiClient { } catch { // Ignore non-JSON error bodies. } + this.logger.error(`← ${res.status} ${path}`, { rid, duration: `${Date.now() - start}ms`, error: message }); throw new Error(message); } + this.logger.info(`← ${res.status} ${path}`, { rid, duration: `${Date.now() - start}ms` }); + // Handle 204 No Content if (res.status === 204) { return undefined as T; @@ -236,6 +249,22 @@ export class ApiClient { return this.fetch("/api/inbox/unread-count"); } + async markAllInboxRead(): Promise<{ count: number }> { + return this.fetch("/api/inbox/mark-all-read", { method: "POST" }); + } + + async archiveAllInbox(): Promise<{ count: number }> { + return this.fetch("/api/inbox/archive-all", { method: "POST" }); + } + + async archiveAllReadInbox(): Promise<{ count: number }> { + return this.fetch("/api/inbox/archive-all-read", { method: "POST" }); + } + + async archiveCompletedInbox(): Promise<{ count: number }> { + return this.fetch("/api/inbox/archive-completed", { method: "POST" }); + } + // Workspaces async listWorkspaces(): Promise { return this.fetch("/api/workspaces"); diff --git a/packages/sdk/src/index.ts b/packages/sdk/src/index.ts index e5bba95e..5aeca125 100644 --- a/packages/sdk/src/index.ts +++ b/packages/sdk/src/index.ts @@ -1,6 +1,8 @@ export { ApiClient } from "./api-client"; export type { LoginResponse } from "./api-client"; export { WSClient } from "./ws-client"; +export { noopLogger } from "./logger"; +export type { SDKLogger } from "./logger"; export interface ContentBlock { type: "text" | "image" | "tool_use" | "tool_result"; diff --git a/packages/sdk/src/logger.ts b/packages/sdk/src/logger.ts new file mode 100644 index 00000000..9a85535e --- /dev/null +++ b/packages/sdk/src/logger.ts @@ -0,0 +1,13 @@ +export interface SDKLogger { + debug(msg: string, ...data: unknown[]): void; + info(msg: string, ...data: unknown[]): void; + warn(msg: string, ...data: unknown[]): void; + error(msg: string, ...data: unknown[]): void; +} + +export const noopLogger: SDKLogger = { + debug() {}, + info() {}, + warn() {}, + error() {}, +}; diff --git a/packages/sdk/src/ws-client.ts b/packages/sdk/src/ws-client.ts index 5bcff6a4..4895011d 100644 --- a/packages/sdk/src/ws-client.ts +++ b/packages/sdk/src/ws-client.ts @@ -1,4 +1,5 @@ import type { WSMessage, WSEventType } from "@multica/types"; +import { type SDKLogger, noopLogger } from "./logger"; type EventHandler = (payload: unknown) => void; @@ -11,9 +12,11 @@ export class WSClient { private reconnectTimer: ReturnType | null = null; private hasConnectedBefore = false; private onReconnectCallbacks = new Set<() => void>(); + private logger: SDKLogger; - constructor(url: string) { + constructor(url: string, options?: { logger?: SDKLogger }) { this.baseUrl = url; + this.logger = options?.logger ?? noopLogger; } setAuth(token: string, workspaceId: string) { @@ -30,7 +33,7 @@ export class WSClient { this.ws = new WebSocket(url.toString()); this.ws.onopen = () => { - console.log("[ws] connected"); + this.logger.info("connected"); if (this.hasConnectedBefore) { for (const cb of this.onReconnectCallbacks) { try { @@ -45,19 +48,19 @@ export class WSClient { this.ws.onmessage = (event) => { const msg = JSON.parse(event.data as string) as WSMessage; - console.log("[ws] received:", msg.type); + this.logger.debug("received", msg.type); const eventHandlers = this.handlers.get(msg.type); if (eventHandlers) { for (const handler of eventHandlers) { handler(msg.payload); } } else { - console.log("[ws] no handlers registered for:", msg.type); + this.logger.debug("unhandled event", msg.type); } }; this.ws.onclose = () => { - console.log("[ws] disconnected, reconnecting in 3s..."); + this.logger.warn("disconnected, reconnecting in 3s"); this.reconnectTimer = setTimeout(() => this.connect(), 3000); }; diff --git a/server/cmd/migrate/main.go b/server/cmd/migrate/main.go index ab190318..8703542d 100644 --- a/server/cmd/migrate/main.go +++ b/server/cmd/migrate/main.go @@ -3,16 +3,19 @@ package main import ( "context" "fmt" - "log" + "log/slog" "os" "path/filepath" "sort" "strings" "github.com/jackc/pgx/v5/pgxpool" + "github.com/multica-ai/multica/server/internal/logger" ) func main() { + logger.Init() + if len(os.Args) < 2 { fmt.Println("Usage: go run ./cmd/migrate ") os.Exit(1) @@ -32,12 +35,14 @@ func main() { ctx := context.Background() pool, err := pgxpool.New(ctx, dbURL) if err != nil { - log.Fatalf("Unable to connect to database: %v", err) + slog.Error("unable to connect to database", "error", err) + os.Exit(1) } defer pool.Close() if err := pool.Ping(ctx); err != nil { - log.Fatalf("Unable to ping database: %v", err) + slog.Error("unable to ping database", "error", err) + os.Exit(1) } // Create migrations tracking table @@ -48,7 +53,8 @@ func main() { ) `) if err != nil { - log.Fatalf("Failed to create migrations table: %v", err) + slog.Error("failed to create migrations table", "error", err) + os.Exit(1) } // Find migration files @@ -61,7 +67,8 @@ func main() { suffix := "." + direction + ".sql" files, err := filepath.Glob(filepath.Join(migrationsDir, "*"+suffix)) if err != nil { - log.Fatalf("Failed to find migration files: %v", err) + slog.Error("failed to find migration files", "error", err) + os.Exit(1) } if direction == "up" { @@ -78,7 +85,8 @@ func main() { var exists bool err := pool.QueryRow(ctx, "SELECT EXISTS(SELECT 1 FROM schema_migrations WHERE version = $1)", version).Scan(&exists) if err != nil { - log.Fatalf("Failed to check migration status: %v", err) + slog.Error("failed to check migration status", "version", version, "error", err) + os.Exit(1) } if exists { fmt.Printf(" skip %s (already applied)\n", version) @@ -89,7 +97,8 @@ func main() { var exists bool err := pool.QueryRow(ctx, "SELECT EXISTS(SELECT 1 FROM schema_migrations WHERE version = $1)", version).Scan(&exists) if err != nil { - log.Fatalf("Failed to check migration status: %v", err) + slog.Error("failed to check migration status", "version", version, "error", err) + os.Exit(1) } if !exists { fmt.Printf(" skip %s (not applied)\n", version) @@ -99,12 +108,14 @@ func main() { sql, err := os.ReadFile(file) if err != nil { - log.Fatalf("Failed to read %s: %v", file, err) + slog.Error("failed to read migration file", "file", file, "error", err) + os.Exit(1) } _, err = pool.Exec(ctx, string(sql)) if err != nil { - log.Fatalf("Failed to run %s: %v", file, err) + slog.Error("failed to run migration", "file", file, "error", err) + os.Exit(1) } if direction == "up" { @@ -113,7 +124,8 @@ func main() { _, err = pool.Exec(ctx, "DELETE FROM schema_migrations WHERE version = $1", version) } if err != nil { - log.Fatalf("Failed to record migration %s: %v", version, err) + slog.Error("failed to record migration", "version", version, "error", err) + os.Exit(1) } fmt.Printf(" %s %s\n", direction, version) diff --git a/server/cmd/multica/cmd_daemon.go b/server/cmd/multica/cmd_daemon.go index e70f2a5f..21c994e9 100644 --- a/server/cmd/multica/cmd_daemon.go +++ b/server/cmd/multica/cmd_daemon.go @@ -3,8 +3,6 @@ package main import ( "context" "errors" - "log" - "os" "os/signal" "syscall" @@ -12,6 +10,7 @@ import ( "github.com/multica-ai/multica/server/internal/cli" "github.com/multica-ai/multica/server/internal/daemon" + logger_pkg "github.com/multica-ai/multica/server/internal/logger" ) var daemonCmd = &cobra.Command{ @@ -61,7 +60,7 @@ func runDaemon(cmd *cobra.Command, _ []string) error { ctx, stop := signal.NotifyContext(context.Background(), syscall.SIGINT, syscall.SIGTERM) defer stop() - logger := log.New(os.Stdout, "multica-daemon: ", log.LstdFlags) + logger := logger_pkg.NewLogger("daemon") d := daemon.New(cfg, logger) if err := d.Run(ctx); err != nil && !errors.Is(err, context.Canceled) { diff --git a/server/cmd/multica/main.go b/server/cmd/multica/main.go index 98aef2b5..08c35a83 100644 --- a/server/cmd/multica/main.go +++ b/server/cmd/multica/main.go @@ -1,6 +1,7 @@ package main import ( + "fmt" "os" "github.com/spf13/cobra" @@ -33,6 +34,7 @@ func init() { func main() { if err := rootCmd.Execute(); err != nil { + fmt.Fprintln(os.Stderr, "Error:", err) os.Exit(1) } } diff --git a/server/cmd/server/main.go b/server/cmd/server/main.go index d47290b1..5ed6d901 100644 --- a/server/cmd/server/main.go +++ b/server/cmd/server/main.go @@ -2,7 +2,7 @@ package main import ( "context" - "log" + "log/slog" "net/http" "os" "os/signal" @@ -12,11 +12,14 @@ import ( "github.com/jackc/pgx/v5/pgxpool" "github.com/multica-ai/multica/server/internal/events" + "github.com/multica-ai/multica/server/internal/logger" "github.com/multica-ai/multica/server/internal/realtime" db "github.com/multica-ai/multica/server/pkg/db/generated" ) func main() { + logger.Init() + port := os.Getenv("PORT") if port == "" { port = "8080" @@ -31,14 +34,16 @@ func main() { ctx := context.Background() pool, err := pgxpool.New(ctx, dbURL) if err != nil { - log.Fatalf("Unable to connect to database: %v", err) + slog.Error("unable to connect to database", "error", err) + os.Exit(1) } defer pool.Close() if err := pool.Ping(ctx); err != nil { - log.Fatalf("Unable to ping database: %v", err) + slog.Error("unable to ping database", "error", err) + os.Exit(1) } - log.Println("Connected to database") + slog.Info("connected to database") bus := events.New() hub := realtime.NewHub() @@ -57,9 +62,10 @@ func main() { // Graceful shutdown go func() { - log.Printf("Server starting on :%s", port) + slog.Info("server starting", "port", port) if err := srv.ListenAndServe(); err != nil && err != http.ErrServerClosed { - log.Fatalf("Server error: %v", err) + slog.Error("server error", "error", err) + os.Exit(1) } }() @@ -67,12 +73,13 @@ func main() { signal.Notify(quit, syscall.SIGINT, syscall.SIGTERM) <-quit - log.Println("Shutting down server...") + slog.Info("shutting down server") shutdownCtx, cancel := context.WithTimeout(context.Background(), 10*time.Second) defer cancel() if err := srv.Shutdown(shutdownCtx); err != nil { - log.Fatalf("Server forced to shutdown: %v", err) + slog.Error("server forced to shutdown", "error", err) + os.Exit(1) } - log.Println("Server stopped") + slog.Info("server stopped") } diff --git a/server/cmd/server/router.go b/server/cmd/server/router.go index b6ca2700..c97a8e04 100644 --- a/server/cmd/server/router.go +++ b/server/cmd/server/router.go @@ -50,13 +50,13 @@ func NewRouter(pool *pgxpool.Pool, hub *realtime.Hub, bus *events.Bus) chi.Route r := chi.NewRouter() // Global middleware - r.Use(chimw.Logger) - r.Use(chimw.Recoverer) r.Use(chimw.RequestID) + r.Use(middleware.RequestLogger) + r.Use(chimw.Recoverer) r.Use(cors.Handler(cors.Options{ AllowedOrigins: allowedOrigins(), AllowedMethods: []string{"GET", "POST", "PUT", "PATCH", "DELETE", "OPTIONS"}, - AllowedHeaders: []string{"Accept", "Authorization", "Content-Type", "X-Workspace-ID"}, + AllowedHeaders: []string{"Accept", "Authorization", "Content-Type", "X-Workspace-ID", "X-Request-ID"}, AllowCredentials: true, MaxAge: 300, })) @@ -159,6 +159,10 @@ func NewRouter(pool *pgxpool.Pool, hub *realtime.Hub, bus *events.Bus) chi.Route r.Route("/api/inbox", func(r chi.Router) { r.Get("/", h.ListInbox) r.Get("/unread-count", h.CountUnreadInbox) + r.Post("/mark-all-read", h.MarkAllInboxRead) + r.Post("/archive-all", h.ArchiveAllInbox) + r.Post("/archive-all-read", h.ArchiveAllReadInbox) + r.Post("/archive-completed", h.ArchiveCompletedInbox) r.Post("/{id}/read", h.MarkInboxRead) r.Post("/{id}/archive", h.ArchiveInboxItem) }) diff --git a/server/go.mod b/server/go.mod index 2e2aaa76..4979d7cd 100644 --- a/server/go.mod +++ b/server/go.mod @@ -16,6 +16,7 @@ require ( github.com/jackc/pgpassfile v1.0.0 // indirect github.com/jackc/pgservicefile v0.0.0-20240606120523-5a60cdf6a761 // indirect github.com/jackc/puddle/v2 v2.2.2 // indirect + github.com/lmittmann/tint v1.1.3 // indirect github.com/spf13/pflag v1.0.9 // indirect golang.org/x/sync v0.20.0 // indirect golang.org/x/text v0.35.0 // indirect diff --git a/server/go.sum b/server/go.sum index 40d399bf..ac4b0055 100644 --- a/server/go.sum +++ b/server/go.sum @@ -20,6 +20,8 @@ github.com/jackc/pgx/v5 v5.8.0 h1:TYPDoleBBme0xGSAX3/+NujXXtpZn9HBONkQC7IEZSo= github.com/jackc/pgx/v5 v5.8.0/go.mod h1:QVeDInX2m9VyzvNeiCJVjCkNFqzsNb43204HshNSZKw= github.com/jackc/puddle/v2 v2.2.2 h1:PR8nw+E/1w0GLuRFSmiioY6UooMp6KJv0/61nB7icHo= github.com/jackc/puddle/v2 v2.2.2/go.mod h1:vriiEXHvEE654aYKXXjOvZM39qJ0q+azkZFrfEOc3H4= +github.com/lmittmann/tint v1.1.3 h1:Hv4EaHWXQr+GTFnOU4VKf8UvAtZgn0VuKT+G0wFlO3I= +github.com/lmittmann/tint v1.1.3/go.mod h1:HIS3gSy7qNwGCj+5oRjAutErFBl4BzdQP6cJZ0NfMwE= github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM= github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4= github.com/russross/blackfriday/v2 v2.1.0/go.mod h1:+Rmxgy9KzJVeS9/2gXHxylqXiyQDYRxCVz55jmeOWTM= diff --git a/server/internal/daemon/daemon.go b/server/internal/daemon/daemon.go index 877afd14..5b746d65 100644 --- a/server/internal/daemon/daemon.go +++ b/server/internal/daemon/daemon.go @@ -3,7 +3,7 @@ package daemon import ( "context" "fmt" - "log" + "log/slog" "strings" "time" @@ -15,11 +15,11 @@ import ( type Daemon struct { cfg Config client *Client - logger *log.Logger + logger *slog.Logger } // New creates a new Daemon instance. -func New(cfg Config, logger *log.Logger) *Daemon { +func New(cfg Config, logger *slog.Logger) *Daemon { return &Daemon{ cfg: cfg, client: NewClient(cfg.ServerBaseURL), @@ -33,8 +33,7 @@ func (d *Daemon) Run(ctx context.Context) error { for name := range d.cfg.Agents { agentNames = append(agentNames, name) } - d.logger.Printf("starting daemon agents=%v workspace=%s server=%s repos_root=%s", - agentNames, d.cfg.WorkspaceID, d.cfg.ServerBaseURL, d.cfg.ReposRoot) + d.logger.Info("starting daemon", "agents", agentNames, "workspace_id", d.cfg.WorkspaceID, "server", d.cfg.ServerBaseURL, "repos_root", d.cfg.ReposRoot) if strings.TrimSpace(d.cfg.WorkspaceID) == "" { workspaceID, err := d.ensurePaired(ctx) @@ -42,7 +41,7 @@ func (d *Daemon) Run(ctx context.Context) error { return err } d.cfg.WorkspaceID = workspaceID - d.logger.Printf("pairing completed for workspace=%s", workspaceID) + d.logger.Info("pairing completed", "workspace_id", workspaceID) } runtimes, err := d.registerRuntimes(ctx) @@ -51,7 +50,7 @@ func (d *Daemon) Run(ctx context.Context) error { } runtimeIDs := make([]string, 0, len(runtimes)) for _, rt := range runtimes { - d.logger.Printf("registered runtime id=%s provider=%s status=%s", rt.ID, rt.Provider, rt.Status) + d.logger.Info("registered runtime", "id", rt.ID, "provider", rt.Provider, "status", rt.Status) runtimeIDs = append(runtimeIDs, rt.ID) } @@ -64,7 +63,7 @@ func (d *Daemon) registerRuntimes(ctx context.Context) ([]Runtime, error) { for name, entry := range d.cfg.Agents { version, err := agent.DetectVersion(ctx, entry.Path) if err != nil { - d.logger.Printf("skip registering %s: %v", name, err) + d.logger.Warn("skip registering runtime", "name", name, "error", err) continue } runtimes = append(runtimes, map[string]string{ @@ -122,9 +121,9 @@ func (d *Daemon) ensurePaired(ctx context.Context) (string, error) { return "", fmt.Errorf("create pairing session: %w", err) } if session.LinkURL != nil { - d.logger.Printf("open this link to pair the daemon: %s", *session.LinkURL) + d.logger.Info("open this link to pair the daemon", "url", *session.LinkURL) } else { - d.logger.Printf("pairing session created: %s", session.Token) + d.logger.Info("pairing session created", "token", session.Token) } for { @@ -176,7 +175,7 @@ func (d *Daemon) heartbeatLoop(ctx context.Context, runtimeIDs []string) { case <-ticker.C: for _, rid := range runtimeIDs { if err := d.client.SendHeartbeat(ctx, rid); err != nil { - d.logger.Printf("heartbeat failed for runtime %s: %v", rid, err) + d.logger.Warn("heartbeat failed", "runtime_id", rid, "error", err) } } } @@ -199,11 +198,11 @@ func (d *Daemon) pollLoop(ctx context.Context, runtimeIDs []string) error { rid := runtimeIDs[(pollOffset+i)%n] task, err := d.client.ClaimTask(ctx, rid) if err != nil { - d.logger.Printf("claim task failed for runtime %s: %v", rid, err) + d.logger.Warn("claim task failed", "runtime_id", rid, "error", err) continue } if task != nil { - d.logger.Printf("poll: got task=%s issue=%s title=%q", task.ID, task.IssueID, task.Context.Issue.Title) + d.logger.Info("task received", "task_id", task.ID, "issue_id", task.IssueID, "title", task.Context.Issue.Title) d.handleTask(ctx, *task) claimed = true pollOffset = (pollOffset + i + 1) % n @@ -214,7 +213,7 @@ func (d *Daemon) pollLoop(ctx context.Context, runtimeIDs []string) error { if !claimed { pollCount++ if pollCount%20 == 1 { - d.logger.Printf("poll: no tasks (runtimes=%v, cycle=%d)", runtimeIDs, pollCount) + d.logger.Debug("poll: no tasks", "runtimes", runtimeIDs, "cycle", pollCount) } pollOffset = (pollOffset + 1) % n if err := sleepWithContext(ctx, d.cfg.PollInterval); err != nil { @@ -228,10 +227,10 @@ func (d *Daemon) pollLoop(ctx context.Context, runtimeIDs []string) error { func (d *Daemon) handleTask(ctx context.Context, task Task) { provider := task.Context.Runtime.Provider - d.logger.Printf("picked task=%s issue=%s provider=%s title=%q", task.ID, task.IssueID, provider, task.Context.Issue.Title) + d.logger.Info("picked task", "task_id", task.ID, "issue_id", task.IssueID, "provider", provider, "title", task.Context.Issue.Title) if err := d.client.StartTask(ctx, task.ID); err != nil { - d.logger.Printf("start task %s failed: %v", task.ID, err) + d.logger.Error("start task failed", "task_id", task.ID, "error", err) return } @@ -239,9 +238,9 @@ func (d *Daemon) handleTask(ctx context.Context, task Task) { result, err := d.runTask(ctx, task) if err != nil { - d.logger.Printf("task %s failed: %v", task.ID, err) + d.logger.Error("task failed", "task_id", task.ID, "error", err) if failErr := d.client.FailTask(ctx, task.ID, err.Error()); failErr != nil { - d.logger.Printf("fail task %s callback failed: %v", task.ID, failErr) + d.logger.Error("fail task callback failed", "task_id", task.ID, "error", failErr) } return } @@ -251,12 +250,12 @@ func (d *Daemon) handleTask(ctx context.Context, task Task) { switch result.Status { case "blocked": if err := d.client.FailTask(ctx, task.ID, result.Comment); err != nil { - d.logger.Printf("report blocked task %s failed: %v", task.ID, err) + d.logger.Error("report blocked task failed", "task_id", task.ID, "error", err) } default: - d.logger.Printf("task %s completed status=%s", task.ID, result.Status) + d.logger.Info("task completed", "task_id", task.ID, "status", result.Status) if err := d.client.CompleteTask(ctx, task.ID, result.Comment, result.BranchName); err != nil { - d.logger.Printf("complete task %s failed: %v", task.ID, err) + d.logger.Error("complete task failed", "task_id", task.ID, "error", err) } } } @@ -291,11 +290,11 @@ func (d *Daemon) runTask(ctx context.Context, task Task) (TaskResult, error) { // Inject runtime-specific config (meta skill) so the agent discovers .agent_context/. if err := execenv.InjectRuntimeConfig(env.WorkDir, provider, taskCtx); err != nil { - d.logger.Printf("execenv: inject runtime config failed (non-fatal): %v", err) + d.logger.Warn("execenv: inject runtime config failed (non-fatal)", "error", err) } defer func() { if cleanupErr := env.Cleanup(!d.cfg.KeepEnvAfterTask); cleanupErr != nil { - d.logger.Printf("cleanup env for task %s: %v", task.ID, cleanupErr) + d.logger.Warn("cleanup env failed", "task_id", task.ID, "error", cleanupErr) } }() @@ -309,10 +308,7 @@ func (d *Daemon) runTask(ctx context.Context, task Task) (TaskResult, error) { return TaskResult{}, fmt.Errorf("create agent backend: %w", err) } - d.logger.Printf( - "starting %s task=%s workdir=%s branch=%s env_type=%s model=%s timeout=%s", - provider, task.ID, env.WorkDir, env.BranchName, env.Type, entry.Model, d.cfg.AgentTimeout, - ) + d.logger.Info("starting agent", "provider", provider, "task_id", task.ID, "workdir", env.WorkDir, "branch", env.BranchName, "env_type", env.Type, "model", entry.Model, "timeout", d.cfg.AgentTimeout.String()) session, err := backend.Execute(ctx, prompt, agent.ExecOptions{ Cwd: env.WorkDir, @@ -328,9 +324,9 @@ func (d *Daemon) runTask(ctx context.Context, task Task) (TaskResult, error) { for msg := range session.Messages { switch msg.Type { case agent.MessageToolUse: - d.logger.Printf("[%s] tool-use: %s (call=%s)", provider, msg.Tool, msg.CallID) + d.logger.Debug("tool-use", "provider", provider, "tool", msg.Tool, "call_id", msg.CallID) case agent.MessageError: - d.logger.Printf("[%s] error: %s", provider, msg.Content) + d.logger.Error("agent error", "provider", provider, "content", msg.Content) } } }() diff --git a/server/internal/daemon/execenv/execenv.go b/server/internal/daemon/execenv/execenv.go index cf92cf3a..a5f427c8 100644 --- a/server/internal/daemon/execenv/execenv.go +++ b/server/internal/daemon/execenv/execenv.go @@ -5,7 +5,7 @@ package execenv import ( "fmt" - "log" + "log/slog" "os" "path/filepath" ) @@ -63,11 +63,11 @@ type Environment struct { BranchName string gitRoot string // source repo root (for cleanup) - logger *log.Logger // for cleanup logging + logger *slog.Logger // for cleanup logging } // Prepare creates an isolated execution environment for a task. -func Prepare(params PrepareParams, logger *log.Logger) (*Environment, error) { +func Prepare(params PrepareParams, logger *slog.Logger) (*Environment, error) { if params.WorkspacesRoot == "" { return nil, fmt.Errorf("execenv: workspaces root is required") } @@ -108,7 +108,7 @@ func Prepare(params PrepareParams, logger *log.Logger) (*Environment, error) { baseRef := getDefaultBranch(gitRoot) if err := setupGitWorktree(gitRoot, workDir, branchName, baseRef); err != nil { - logger.Printf("execenv: git worktree setup failed, falling back to directory mode: %v", err) + logger.Warn("execenv: git worktree setup failed, falling back to directory mode", "error", err) } else { env.Type = WorkspaceTypeGitWorktree env.BranchName = branchName @@ -117,7 +117,7 @@ func Prepare(params PrepareParams, logger *log.Logger) (*Environment, error) { // Exclude injected directories from git tracking. for _, pattern := range []string{".agent_context", ".claude", "AGENTS.md"} { if err := excludeFromGit(workDir, pattern); err != nil { - logger.Printf("execenv: failed to exclude %s from git: %v", pattern, err) + logger.Warn("execenv: failed to exclude from git", "pattern", pattern, "error", err) } } } @@ -129,7 +129,7 @@ func Prepare(params PrepareParams, logger *log.Logger) (*Environment, error) { return nil, fmt.Errorf("execenv: write context files: %w", err) } - logger.Printf("execenv: prepared env root=%s type=%s branch=%s", envRoot, env.Type, env.BranchName) + logger.Info("execenv: prepared env", "root", envRoot, "type", env.Type, "branch", env.BranchName) return env, nil } @@ -148,7 +148,7 @@ func (env *Environment) Cleanup(removeAll bool) error { if removeAll { if err := os.RemoveAll(env.RootDir); err != nil { - env.logger.Printf("execenv: cleanup removeAll failed: %v", err) + env.logger.Warn("execenv: cleanup removeAll failed", "error", err) return err } return nil @@ -156,7 +156,7 @@ func (env *Environment) Cleanup(removeAll bool) error { // Partial cleanup: remove workdir, keep output/ and logs/. if err := os.RemoveAll(env.WorkDir); err != nil { - env.logger.Printf("execenv: cleanup workdir failed: %v", err) + env.logger.Warn("execenv: cleanup workdir failed", "error", err) return err } return nil diff --git a/server/internal/daemon/execenv/execenv_test.go b/server/internal/daemon/execenv/execenv_test.go index da6b9059..4ab8bc49 100644 --- a/server/internal/daemon/execenv/execenv_test.go +++ b/server/internal/daemon/execenv/execenv_test.go @@ -1,7 +1,7 @@ package execenv import ( - "log" + "log/slog" "os" "os/exec" "path/filepath" @@ -9,8 +9,8 @@ import ( "testing" ) -func testLogger() *log.Logger { - return log.New(os.Stderr, "[test] ", log.LstdFlags) +func testLogger() *slog.Logger { + return slog.Default() } func TestShortID(t *testing.T) { diff --git a/server/internal/daemon/execenv/git.go b/server/internal/daemon/execenv/git.go index aa35d06d..97420ceb 100644 --- a/server/internal/daemon/execenv/git.go +++ b/server/internal/daemon/execenv/git.go @@ -2,7 +2,7 @@ package execenv import ( "fmt" - "log" + "log/slog" "os" "os/exec" "path/filepath" @@ -57,18 +57,18 @@ func runGitWorktreeAdd(gitRoot, worktreePath, branchName, baseRef string) error } // removeGitWorktree removes a worktree and its branch. Best-effort: logs errors. -func removeGitWorktree(gitRoot, worktreePath, branchName string, logger *log.Logger) { +func removeGitWorktree(gitRoot, worktreePath, branchName string, logger *slog.Logger) { // Remove the worktree. cmd := exec.Command("git", "-C", gitRoot, "worktree", "remove", "--force", worktreePath) if out, err := cmd.CombinedOutput(); err != nil { - logger.Printf("execenv: git worktree remove: %s: %v", strings.TrimSpace(string(out)), err) + logger.Warn("execenv: git worktree remove failed", "output", strings.TrimSpace(string(out)), "error", err) } // Delete the branch (best-effort). if branchName != "" { cmd = exec.Command("git", "-C", gitRoot, "branch", "-D", branchName) if out, err := cmd.CombinedOutput(); err != nil { - logger.Printf("execenv: git branch -D %s: %s: %v", branchName, strings.TrimSpace(string(out)), err) + logger.Warn("execenv: git branch delete failed", "branch", branchName, "output", strings.TrimSpace(string(out)), "error", err) } } } diff --git a/server/internal/events/bus.go b/server/internal/events/bus.go index 933a863a..3ac233f4 100644 --- a/server/internal/events/bus.go +++ b/server/internal/events/bus.go @@ -1,7 +1,7 @@ package events import ( - "log" + "log/slog" "sync" ) @@ -50,7 +50,7 @@ func (b *Bus) Publish(e Event) { func() { defer func() { if r := recover(); r != nil { - log.Printf("[event-bus] panic in listener for %q: %v", e.Type, r) + slog.Error("panic in event listener", "event_type", e.Type, "recovered", r) } }() h(e) diff --git a/server/internal/handler/agent.go b/server/internal/handler/agent.go index d0ea10e1..d098a5da 100644 --- a/server/internal/handler/agent.go +++ b/server/internal/handler/agent.go @@ -4,11 +4,12 @@ import ( "context" "encoding/json" "fmt" - "log" + "log/slog" "net/http" "github.com/go-chi/chi/v5" "github.com/jackc/pgx/v5/pgtype" + "github.com/multica-ai/multica/server/internal/logger" db "github.com/multica-ai/multica/server/pkg/db/generated" "github.com/multica-ai/multica/server/pkg/protocol" ) @@ -276,9 +277,11 @@ func (h *Handler) CreateAgent(w http.ResponseWriter, r *http.Request) { Triggers: triggers, }) if err != nil { + slog.Warn("create agent failed", append(logger.RequestAttrs(r), "error", err, "workspace_id", workspaceID)...) writeError(w, http.StatusInternalServerError, "failed to create agent: "+err.Error()) return } + slog.Info("agent created", append(logger.RequestAttrs(r), "agent_id", uuidToString(agent.ID), "name", agent.Name, "workspace_id", workspaceID)...) if runtime.Status == "online" { h.TaskService.ReconcileAgentStatus(r.Context(), agent.ID) @@ -331,7 +334,7 @@ func (h *Handler) createAgentInitIssue(ctx context.Context, agent db.Agent, crea // Enqueue the task directly — we know the agent is assigned and status is "todo". if _, err := h.TaskService.EnqueueTaskForIssue(ctx, issue); err != nil { - log.Printf("createAgentInitIssue: enqueue task failed for issue %s: %v", issue.Title, err) + slog.Warn("createAgentInitIssue: enqueue task failed", "issue_title", issue.Title, "error", err) } } @@ -413,11 +416,13 @@ func (h *Handler) UpdateAgent(w http.ResponseWriter, r *http.Request) { agent, err := h.Queries.UpdateAgent(r.Context(), params) if err != nil { + slog.Warn("update agent failed", append(logger.RequestAttrs(r), "error", err, "agent_id", id)...) writeError(w, http.StatusInternalServerError, "failed to update agent: "+err.Error()) return } resp := agentToResponse(agent) + slog.Info("agent updated", append(logger.RequestAttrs(r), "agent_id", id, "workspace_id", uuidToString(agent.WorkspaceID))...) userID := requestUserID(r) h.publish(protocol.EventAgentStatus, uuidToString(agent.WorkspaceID), "member", userID, map[string]any{"agent": resp}) writeJSON(w, http.StatusOK, resp) @@ -438,10 +443,12 @@ func (h *Handler) DeleteAgent(w http.ResponseWriter, r *http.Request) { err := h.Queries.DeleteAgent(r.Context(), parseUUID(id)) if err != nil { + slog.Warn("delete agent failed", append(logger.RequestAttrs(r), "error", err, "agent_id", id)...) writeError(w, http.StatusInternalServerError, "failed to delete agent") return } + slog.Info("agent deleted", append(logger.RequestAttrs(r), "agent_id", id, "workspace_id", wsID)...) userID := requestUserID(r) h.publish(protocol.EventAgentDeleted, wsID, "member", userID, map[string]any{"agent_id": id, "workspace_id": wsID}) w.WriteHeader(http.StatusNoContent) diff --git a/server/internal/handler/auth.go b/server/internal/handler/auth.go index 421b3802..914ed927 100644 --- a/server/internal/handler/auth.go +++ b/server/internal/handler/auth.go @@ -3,6 +3,7 @@ package handler import ( "context" "encoding/json" + "log/slog" "net/http" "strings" "time" @@ -10,6 +11,7 @@ import ( "github.com/golang-jwt/jwt/v5" "github.com/jackc/pgx/v5/pgtype" "github.com/multica-ai/multica/server/internal/auth" + "github.com/multica-ai/multica/server/internal/logger" db "github.com/multica-ai/multica/server/pkg/db/generated" ) @@ -167,6 +169,7 @@ func (h *Handler) Login(w http.ResponseWriter, r *http.Request) { user, err := h.Queries.GetUserByEmail(r.Context(), req.Email) if err != nil { if !isNotFound(err) { + slog.Warn("login failed", append(logger.RequestAttrs(r), "error", err, "email", req.Email)...) writeError(w, http.StatusInternalServerError, "failed to load user") return } @@ -181,9 +184,11 @@ func (h *Handler) Login(w http.ResponseWriter, r *http.Request) { Email: req.Email, }) if err != nil { + slog.Warn("login failed", append(logger.RequestAttrs(r), "error", err, "email", req.Email)...) writeError(w, http.StatusInternalServerError, "failed to create user: "+err.Error()) return } + slog.Info("new user created", append(logger.RequestAttrs(r), "user_id", uuidToString(user.ID), "email", user.Email)...) } else if req.Name != "" && req.Name != user.Name { user, err = h.Queries.UpdateUser(r.Context(), db.UpdateUserParams{ ID: user.ID, @@ -196,6 +201,7 @@ func (h *Handler) Login(w http.ResponseWriter, r *http.Request) { } if err := h.ensureUserWorkspace(r.Context(), user); err != nil { + slog.Warn("login failed", append(logger.RequestAttrs(r), "error", err, "email", req.Email)...) writeError(w, http.StatusInternalServerError, "failed to provision workspace") return } @@ -211,10 +217,12 @@ func (h *Handler) Login(w http.ResponseWriter, r *http.Request) { tokenString, err := token.SignedString(auth.JWTSecret()) if err != nil { + slog.Warn("login failed", append(logger.RequestAttrs(r), "error", err, "email", req.Email)...) writeError(w, http.StatusInternalServerError, "failed to generate token") return } + slog.Info("user logged in", append(logger.RequestAttrs(r), "user_id", uuidToString(user.ID), "email", user.Email)...) writeJSON(w, http.StatusOK, LoginResponse{ Token: tokenString, User: userToResponse(user), diff --git a/server/internal/handler/comment.go b/server/internal/handler/comment.go index 801637d5..3a841d24 100644 --- a/server/internal/handler/comment.go +++ b/server/internal/handler/comment.go @@ -2,9 +2,11 @@ package handler import ( "encoding/json" + "log/slog" "net/http" "github.com/go-chi/chi/v5" + "github.com/multica-ai/multica/server/internal/logger" db "github.com/multica-ai/multica/server/pkg/db/generated" "github.com/multica-ai/multica/server/pkg/protocol" ) @@ -93,11 +95,13 @@ func (h *Handler) CreateComment(w http.ResponseWriter, r *http.Request) { Type: req.Type, }) if err != nil { + slog.Warn("create comment failed", append(logger.RequestAttrs(r), "error", err, "issue_id", issueID)...) writeError(w, http.StatusInternalServerError, "failed to create comment: "+err.Error()) return } resp := commentToResponse(comment) + slog.Info("comment created", append(logger.RequestAttrs(r), "comment_id", uuidToString(comment.ID), "issue_id", issueID)...) h.publish(protocol.EventCommentCreated, uuidToString(issue.WorkspaceID), "member", userID, map[string]any{ "comment": resp, "issue_title": issue.Title, @@ -159,11 +163,13 @@ func (h *Handler) UpdateComment(w http.ResponseWriter, r *http.Request) { Content: req.Content, }) if err != nil { + slog.Warn("update comment failed", append(logger.RequestAttrs(r), "error", err, "comment_id", commentId)...) writeError(w, http.StatusInternalServerError, "failed to update comment") return } resp := commentToResponse(comment) + slog.Info("comment updated", append(logger.RequestAttrs(r), "comment_id", commentId)...) h.publish(protocol.EventCommentUpdated, uuidToString(issue.WorkspaceID), "member", userID, map[string]any{"comment": resp}) writeJSON(w, http.StatusOK, resp) } @@ -203,10 +209,12 @@ func (h *Handler) DeleteComment(w http.ResponseWriter, r *http.Request) { } if err := h.Queries.DeleteComment(r.Context(), parseUUID(commentId)); err != nil { + slog.Warn("delete comment failed", append(logger.RequestAttrs(r), "error", err, "comment_id", commentId)...) writeError(w, http.StatusInternalServerError, "failed to delete comment") return } + slog.Info("comment deleted", append(logger.RequestAttrs(r), "comment_id", commentId, "issue_id", uuidToString(comment.IssueID))...) h.publish(protocol.EventCommentDeleted, uuidToString(issue.WorkspaceID), "member", userID, map[string]any{ "comment_id": commentId, "issue_id": uuidToString(comment.IssueID), diff --git a/server/internal/handler/daemon.go b/server/internal/handler/daemon.go index c127088b..6ac274bd 100644 --- a/server/internal/handler/daemon.go +++ b/server/internal/handler/daemon.go @@ -3,6 +3,7 @@ package handler import ( "encoding/json" "fmt" + "log/slog" "net/http" "strings" @@ -99,6 +100,8 @@ func (h *Handler) DaemonRegister(w http.ResponseWriter, r *http.Request) { resp = append(resp, runtimeToResponse(registered)) } + slog.Info("daemon registered", "workspace_id", req.WorkspaceID, "daemon_id", req.DaemonID, "runtimes_count", len(resp)) + h.publish(protocol.EventDaemonRegister, req.WorkspaceID, "system", "", map[string]any{ "runtimes": resp, }) @@ -128,6 +131,7 @@ func (h *Handler) DaemonHeartbeat(w http.ResponseWriter, r *http.Request) { return } + slog.Debug("daemon heartbeat", "runtime_id", req.RuntimeID) writeJSON(w, http.StatusOK, map[string]string{"status": "ok"}) } @@ -142,10 +146,12 @@ func (h *Handler) ClaimTaskByRuntime(w http.ResponseWriter, r *http.Request) { } if task == nil { + slog.Debug("no task to claim", "runtime_id", runtimeID) writeJSON(w, http.StatusOK, map[string]any{"task": nil}) return } + slog.Info("task claimed by runtime", "task_id", uuidToString(task.ID), "runtime_id", runtimeID, "agent_id", uuidToString(task.AgentID)) writeJSON(w, http.StatusOK, map[string]any{"task": taskToResponse(*task)}) } @@ -177,10 +183,12 @@ func (h *Handler) StartTask(w http.ResponseWriter, r *http.Request) { task, err := h.TaskService.StartTask(r.Context(), parseUUID(taskID)) if err != nil { + slog.Warn("start task failed", "task_id", taskID, "error", err) writeError(w, http.StatusBadRequest, err.Error()) return } + slog.Info("task started", "task_id", taskID, "agent_id", uuidToString(task.AgentID)) writeJSON(w, http.StatusOK, taskToResponse(*task)) } @@ -231,10 +239,12 @@ func (h *Handler) CompleteTask(w http.ResponseWriter, r *http.Request) { result, _ := json.Marshal(req) task, err := h.TaskService.CompleteTask(r.Context(), parseUUID(taskID), result) if err != nil { + slog.Warn("complete task failed", "task_id", taskID, "error", err) writeError(w, http.StatusBadRequest, err.Error()) return } + slog.Info("task completed", "task_id", taskID, "agent_id", uuidToString(task.AgentID)) writeJSON(w, http.StatusOK, taskToResponse(*task)) } @@ -254,9 +264,11 @@ func (h *Handler) FailTask(w http.ResponseWriter, r *http.Request) { task, err := h.TaskService.FailTask(r.Context(), parseUUID(taskID), req.Error) if err != nil { + slog.Warn("fail task failed", "task_id", taskID, "error", err) writeError(w, http.StatusBadRequest, err.Error()) return } + slog.Info("task failed", "task_id", taskID, "agent_id", uuidToString(task.AgentID), "task_error", req.Error) writeJSON(w, http.StatusOK, taskToResponse(*task)) } diff --git a/server/internal/handler/inbox.go b/server/internal/handler/inbox.go index ca46cda6..989cb4e9 100644 --- a/server/internal/handler/inbox.go +++ b/server/internal/handler/inbox.go @@ -1,10 +1,12 @@ package handler import ( + "log/slog" "net/http" "strconv" "github.com/go-chi/chi/v5" + "github.com/multica-ai/multica/server/internal/logger" db "github.com/multica-ai/multica/server/pkg/db/generated" "github.com/multica-ai/multica/server/pkg/protocol" ) @@ -138,3 +140,91 @@ func (h *Handler) CountUnreadInbox(w http.ResponseWriter, r *http.Request) { writeJSON(w, http.StatusOK, map[string]int64{"count": count}) } + +func (h *Handler) MarkAllInboxRead(w http.ResponseWriter, r *http.Request) { + userID, ok := requireUserID(w, r) + if !ok { + return + } + + count, err := h.Queries.MarkAllInboxRead(r.Context(), parseUUID(userID)) + if err != nil { + writeError(w, http.StatusInternalServerError, "failed to mark all inbox read") + return + } + + slog.Info("inbox: mark all read", append(logger.RequestAttrs(r), "user_id", userID, "count", count)...) + workspaceID := r.Header.Get("X-Workspace-ID") + h.publish(protocol.EventInboxBatchRead, workspaceID, "member", userID, map[string]any{ + "recipient_id": userID, + "count": count, + }) + + writeJSON(w, http.StatusOK, map[string]any{"count": count}) +} + +func (h *Handler) ArchiveAllInbox(w http.ResponseWriter, r *http.Request) { + userID, ok := requireUserID(w, r) + if !ok { + return + } + + count, err := h.Queries.ArchiveAllInbox(r.Context(), parseUUID(userID)) + if err != nil { + writeError(w, http.StatusInternalServerError, "failed to archive all inbox") + return + } + + slog.Info("inbox: archive all", append(logger.RequestAttrs(r), "user_id", userID, "count", count)...) + workspaceID := r.Header.Get("X-Workspace-ID") + h.publish(protocol.EventInboxBatchArchived, workspaceID, "member", userID, map[string]any{ + "recipient_id": userID, + "count": count, + }) + + writeJSON(w, http.StatusOK, map[string]any{"count": count}) +} + +func (h *Handler) ArchiveAllReadInbox(w http.ResponseWriter, r *http.Request) { + userID, ok := requireUserID(w, r) + if !ok { + return + } + + count, err := h.Queries.ArchiveAllReadInbox(r.Context(), parseUUID(userID)) + if err != nil { + writeError(w, http.StatusInternalServerError, "failed to archive all read inbox") + return + } + + slog.Info("inbox: archive all read", append(logger.RequestAttrs(r), "user_id", userID, "count", count)...) + workspaceID := r.Header.Get("X-Workspace-ID") + h.publish(protocol.EventInboxBatchArchived, workspaceID, "member", userID, map[string]any{ + "recipient_id": userID, + "count": count, + }) + + writeJSON(w, http.StatusOK, map[string]any{"count": count}) +} + +func (h *Handler) ArchiveCompletedInbox(w http.ResponseWriter, r *http.Request) { + userID, ok := requireUserID(w, r) + if !ok { + return + } + + count, err := h.Queries.ArchiveCompletedInbox(r.Context(), parseUUID(userID)) + if err != nil { + writeError(w, http.StatusInternalServerError, "failed to archive completed inbox") + return + } + + slog.Info("inbox: archive completed", append(logger.RequestAttrs(r), "user_id", userID, "count", count)...) + workspaceID := r.Header.Get("X-Workspace-ID") + h.publish(protocol.EventInboxBatchArchived, workspaceID, "member", userID, map[string]any{ + "recipient_id": userID, + "count": count, + }) + + writeJSON(w, http.StatusOK, map[string]any{"count": count}) +} diff --git a/server/internal/handler/issue.go b/server/internal/handler/issue.go index db824163..40a0e798 100644 --- a/server/internal/handler/issue.go +++ b/server/internal/handler/issue.go @@ -4,12 +4,14 @@ import ( "context" "encoding/json" "io" + "log/slog" "net/http" "strconv" "time" "github.com/go-chi/chi/v5" "github.com/jackc/pgx/v5/pgtype" + "github.com/multica-ai/multica/server/internal/logger" db "github.com/multica-ai/multica/server/pkg/db/generated" "github.com/multica-ai/multica/server/pkg/protocol" ) @@ -229,11 +231,13 @@ func (h *Handler) CreateIssue(w http.ResponseWriter, r *http.Request) { Position: 0, }) if err != nil { + slog.Warn("create issue failed", append(logger.RequestAttrs(r), "error", err, "workspace_id", workspaceID)...) writeError(w, http.StatusInternalServerError, "failed to create issue: "+err.Error()) return } resp := issueToResponse(issue) + slog.Info("issue created", append(logger.RequestAttrs(r), "issue_id", uuidToString(issue.ID), "title", issue.Title, "status", issue.Status, "workspace_id", workspaceID)...) h.publish(protocol.EventIssueCreated, workspaceID, "member", creatorID, map[string]any{"issue": resp}) // Only ready issues in todo are enqueued for agents. @@ -348,11 +352,13 @@ func (h *Handler) UpdateIssue(w http.ResponseWriter, r *http.Request) { issue, err := h.Queries.UpdateIssue(r.Context(), params) if err != nil { + slog.Warn("update issue failed", append(logger.RequestAttrs(r), "error", err, "issue_id", id, "workspace_id", workspaceID)...) writeError(w, http.StatusInternalServerError, "failed to update issue: "+err.Error()) return } resp := issueToResponse(issue) + slog.Info("issue updated", append(logger.RequestAttrs(r), "issue_id", id, "workspace_id", workspaceID)...) assigneeChanged := (req.AssigneeType != nil || req.AssigneeID != nil) && (prevIssue.AssigneeType.String != issue.AssigneeType.String || uuidToString(prevIssue.AssigneeID) != uuidToString(issue.AssigneeID)) @@ -426,5 +432,6 @@ func (h *Handler) DeleteIssue(w http.ResponseWriter, r *http.Request) { userID := requestUserID(r) h.publish(protocol.EventIssueDeleted, uuidToString(issue.WorkspaceID), "member", userID, map[string]any{"issue_id": id}) + slog.Info("issue deleted", append(logger.RequestAttrs(r), "issue_id", id, "workspace_id", uuidToString(issue.WorkspaceID))...) w.WriteHeader(http.StatusNoContent) } diff --git a/server/internal/handler/workspace.go b/server/internal/handler/workspace.go index 482b49ab..fc09ef3b 100644 --- a/server/internal/handler/workspace.go +++ b/server/internal/handler/workspace.go @@ -2,11 +2,13 @@ package handler import ( "encoding/json" + "log/slog" "net/http" "strings" "github.com/go-chi/chi/v5" "github.com/jackc/pgx/v5/pgtype" + "github.com/multica-ai/multica/server/internal/logger" db "github.com/multica-ai/multica/server/pkg/db/generated" "github.com/multica-ai/multica/server/pkg/protocol" ) @@ -158,6 +160,7 @@ func (h *Handler) CreateWorkspace(w http.ResponseWriter, r *http.Request) { return } + slog.Info("workspace created", append(logger.RequestAttrs(r), "workspace_id", uuidToString(ws.ID), "name", ws.Name, "slug", ws.Slug)...) writeJSON(w, http.StatusCreated, workspaceToResponse(ws)) } @@ -204,10 +207,12 @@ func (h *Handler) UpdateWorkspace(w http.ResponseWriter, r *http.Request) { ws, err := h.Queries.UpdateWorkspace(r.Context(), params) if err != nil { + slog.Warn("update workspace failed", append(logger.RequestAttrs(r), "error", err, "workspace_id", id)...) writeError(w, http.StatusInternalServerError, "failed to update workspace: "+err.Error()) return } + slog.Info("workspace updated", append(logger.RequestAttrs(r), "workspace_id", id)...) userID := requestUserID(r) h.publish(protocol.EventWorkspaceUpdated, id, "member", userID, map[string]any{"workspace": workspaceToResponse(ws)}) @@ -363,10 +368,12 @@ func (h *Handler) CreateMember(w http.ResponseWriter, r *http.Request) { writeError(w, http.StatusConflict, "user is already a member") return } + slog.Warn("create member failed", append(logger.RequestAttrs(r), "error", err, "workspace_id", workspaceID, "email", email)...) writeError(w, http.StatusInternalServerError, "failed to create member") return } + slog.Info("member added", append(logger.RequestAttrs(r), "member_id", uuidToString(member.ID), "workspace_id", workspaceID, "email", email, "role", role)...) userID := requestUserID(r) h.publish(protocol.EventMemberAdded, workspaceID, "member", userID, map[string]any{"member": memberWithUserResponse(member, user)}) @@ -479,10 +486,12 @@ func (h *Handler) DeleteMember(w http.ResponseWriter, r *http.Request) { } if err := h.Queries.DeleteMember(r.Context(), target.ID); err != nil { + slog.Warn("delete member failed", append(logger.RequestAttrs(r), "error", err, "member_id", memberID, "workspace_id", workspaceID)...) writeError(w, http.StatusInternalServerError, "failed to delete member") return } + slog.Info("member removed", append(logger.RequestAttrs(r), "member_id", uuidToString(target.ID), "workspace_id", workspaceID, "user_id", uuidToString(target.UserID))...) userID := requestUserID(r) h.publish(protocol.EventMemberRemoved, workspaceID, "member", userID, map[string]any{ "member_id": uuidToString(target.ID), @@ -513,10 +522,12 @@ func (h *Handler) LeaveWorkspace(w http.ResponseWriter, r *http.Request) { } if err := h.Queries.DeleteMember(r.Context(), member.ID); err != nil { + slog.Warn("leave workspace failed", append(logger.RequestAttrs(r), "error", err, "workspace_id", workspaceID)...) writeError(w, http.StatusInternalServerError, "failed to leave workspace") return } + slog.Info("member removed", append(logger.RequestAttrs(r), "member_id", uuidToString(member.ID), "workspace_id", workspaceID, "user_id", uuidToString(member.UserID))...) userID := requestUserID(r) h.publish(protocol.EventMemberRemoved, workspaceID, "member", userID, map[string]any{ "member_id": uuidToString(member.ID), @@ -534,10 +545,12 @@ func (h *Handler) DeleteWorkspace(w http.ResponseWriter, r *http.Request) { } if err := h.Queries.DeleteWorkspace(r.Context(), parseUUID(workspaceID)); err != nil { + slog.Warn("delete workspace failed", append(logger.RequestAttrs(r), "error", err, "workspace_id", workspaceID)...) writeError(w, http.StatusInternalServerError, "failed to delete workspace") return } + slog.Info("workspace deleted", append(logger.RequestAttrs(r), "workspace_id", workspaceID)...) h.publish(protocol.EventWorkspaceDeleted, workspaceID, "member", requestUserID(r), map[string]any{ "workspace_id": workspaceID, }) diff --git a/server/internal/logger/logger.go b/server/internal/logger/logger.go new file mode 100644 index 00000000..ef177da9 --- /dev/null +++ b/server/internal/logger/logger.go @@ -0,0 +1,59 @@ +package logger + +import ( + "log/slog" + "net/http" + "os" + "strings" + + chimw "github.com/go-chi/chi/v5/middleware" + "github.com/lmittmann/tint" +) + +// Init initializes the global slog logger with colored terminal output. +// Reads LOG_LEVEL env var (debug, info, warn, error). Default: debug. +func Init() { + level := parseLevel(os.Getenv("LOG_LEVEL")) + handler := tint.NewHandler(os.Stderr, &tint.Options{ + Level: level, + TimeFormat: "15:04:05.000", + }) + slog.SetDefault(slog.New(handler)) +} + +// NewLogger creates a named slog logger with colored terminal output. +// Useful for standalone processes (daemon, migrate) that want a component prefix. +func NewLogger(component string) *slog.Logger { + level := parseLevel(os.Getenv("LOG_LEVEL")) + handler := tint.NewHandler(os.Stderr, &tint.Options{ + Level: level, + TimeFormat: "15:04:05.000", + }) + return slog.New(handler).With("component", component) +} + +// RequestAttrs extracts request_id and user_id from an HTTP request +// for use in handler-level structured logging. +func RequestAttrs(r *http.Request) []any { + attrs := make([]any, 0, 4) + if rid := chimw.GetReqID(r.Context()); rid != "" { + attrs = append(attrs, "request_id", rid) + } + if uid := r.Header.Get("X-User-ID"); uid != "" { + attrs = append(attrs, "user_id", uid) + } + return attrs +} + +func parseLevel(s string) slog.Level { + switch strings.ToLower(strings.TrimSpace(s)) { + case "info": + return slog.LevelInfo + case "warn", "warning": + return slog.LevelWarn + case "error": + return slog.LevelError + default: + return slog.LevelDebug + } +} diff --git a/server/internal/middleware/auth.go b/server/internal/middleware/auth.go index 4a5342b5..8c3dbe30 100644 --- a/server/internal/middleware/auth.go +++ b/server/internal/middleware/auth.go @@ -1,6 +1,7 @@ package middleware import ( + "log/slog" "net/http" "strings" @@ -14,12 +15,14 @@ func Auth(next http.Handler) http.Handler { return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { authHeader := r.Header.Get("Authorization") if authHeader == "" { + slog.Debug("auth: missing authorization header", "path", r.URL.Path) http.Error(w, `{"error":"missing authorization header"}`, http.StatusUnauthorized) return } tokenString := strings.TrimPrefix(authHeader, "Bearer ") if tokenString == authHeader { + slog.Debug("auth: invalid format", "path", r.URL.Path) http.Error(w, `{"error":"invalid authorization format"}`, http.StatusUnauthorized) return } @@ -31,18 +34,21 @@ func Auth(next http.Handler) http.Handler { return auth.JWTSecret(), nil }) if err != nil || !token.Valid { + slog.Warn("auth: invalid token", "path", r.URL.Path, "error", err) http.Error(w, `{"error":"invalid token"}`, http.StatusUnauthorized) return } claims, ok := token.Claims.(jwt.MapClaims) if !ok { + slog.Warn("auth: invalid claims", "path", r.URL.Path) http.Error(w, `{"error":"invalid claims"}`, http.StatusUnauthorized) return } sub, ok := claims["sub"].(string) if !ok || strings.TrimSpace(sub) == "" { + slog.Warn("auth: invalid claims", "path", r.URL.Path) http.Error(w, `{"error":"invalid claims"}`, http.StatusUnauthorized) return } diff --git a/server/internal/middleware/request_logger.go b/server/internal/middleware/request_logger.go new file mode 100644 index 00000000..95fa7820 --- /dev/null +++ b/server/internal/middleware/request_logger.go @@ -0,0 +1,51 @@ +package middleware + +import ( + "log/slog" + "net/http" + "time" + + chimw "github.com/go-chi/chi/v5/middleware" +) + +// RequestLogger is a structured HTTP request logger using slog. +// It replaces Chi's built-in chimw.Logger with colored, structured output. +func RequestLogger(next http.Handler) http.Handler { + return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + // Skip noisy endpoints. + if r.URL.Path == "/health" { + next.ServeHTTP(w, r) + return + } + + start := time.Now() + ww := chimw.NewWrapResponseWriter(w, r.ProtoMajor) + + next.ServeHTTP(ww, r) + + duration := time.Since(start) + status := ww.Status() + + attrs := []any{ + "method", r.Method, + "path", r.URL.Path, + "status", status, + "duration", duration.Round(time.Microsecond).String(), + } + if rid := chimw.GetReqID(r.Context()); rid != "" { + attrs = append(attrs, "request_id", rid) + } + if uid := r.Header.Get("X-User-ID"); uid != "" { + attrs = append(attrs, "user_id", uid) + } + + switch { + case status >= 500: + slog.Error("http request", attrs...) + case status >= 400: + slog.Warn("http request", attrs...) + default: + slog.Info("http request", attrs...) + } + }) +} diff --git a/server/internal/realtime/hub.go b/server/internal/realtime/hub.go index b648c57f..09ab4294 100644 --- a/server/internal/realtime/hub.go +++ b/server/internal/realtime/hub.go @@ -2,7 +2,7 @@ package realtime import ( "context" - "log" + "log/slog" "net/http" "strings" "sync" @@ -68,7 +68,7 @@ func (h *Hub) Run() { total += len(r) } h.mu.Unlock() - log.Printf("Client connected (workspace=%s). Total: %d", room, total) + slog.Info("ws client connected", "workspace_id", room, "total_clients", total) case client := <-h.unregister: h.mu.Lock() @@ -87,7 +87,7 @@ func (h *Hub) Run() { total += len(r) } h.mu.Unlock() - log.Printf("Client disconnected (workspace=%s). Total: %d", room, total) + slog.Info("ws client disconnected", "workspace_id", room, "total_clients", total) case message := <-h.broadcast: // Global broadcast for daemon events (no workspace filtering) @@ -202,7 +202,7 @@ func HandleWebSocket(hub *Hub, mc MembershipChecker, w http.ResponseWriter, r *h conn, err := upgrader.Upgrade(w, r, nil) if err != nil { - log.Printf("WebSocket upgrade error: %v", err) + slog.Error("websocket upgrade failed", "error", err) return } @@ -226,15 +226,15 @@ func (c *Client) readPump() { }() for { - _, message, err := c.conn.ReadMessage() + _, _, err := c.conn.ReadMessage() if err != nil { if websocket.IsUnexpectedCloseError(err, websocket.CloseGoingAway, websocket.CloseNormalClosure) { - log.Printf("WebSocket read error: %v", err) + slog.Debug("websocket read error", "error", err, "user_id", c.userID, "workspace_id", c.workspaceID) } break } // TODO: Route inbound messages to appropriate handlers - log.Printf("Received message from user=%s workspace=%s: %s", c.userID, c.workspaceID, message) + slog.Debug("ws message received", "user_id", c.userID, "workspace_id", c.workspaceID) } } @@ -243,7 +243,7 @@ func (c *Client) writePump() { for message := range c.send { if err := c.conn.WriteMessage(websocket.TextMessage, message); err != nil { - log.Printf("WebSocket write error: %v", err) + slog.Warn("websocket write error", "error", err) return } } diff --git a/server/internal/service/task.go b/server/internal/service/task.go index aa7d9fa2..9f61e13f 100644 --- a/server/internal/service/task.go +++ b/server/internal/service/task.go @@ -5,6 +5,7 @@ import ( "encoding/json" "errors" "fmt" + "log/slog" "github.com/jackc/pgx/v5" "github.com/jackc/pgx/v5/pgtype" @@ -28,19 +29,23 @@ func NewTaskService(q *db.Queries, hub *realtime.Hub, bus *events.Bus) *TaskServ // EnqueueTaskForIssue creates a task with a context snapshot of the issue. func (s *TaskService) EnqueueTaskForIssue(ctx context.Context, issue db.Issue) (db.AgentTaskQueue, error) { if !issue.AssigneeID.Valid { + slog.Error("task enqueue failed", "issue_id", util.UUIDToString(issue.ID), "error", "issue has no assignee") return db.AgentTaskQueue{}, fmt.Errorf("issue has no assignee") } agent, err := s.Queries.GetAgent(ctx, issue.AssigneeID) if err != nil { + slog.Error("task enqueue failed", "issue_id", util.UUIDToString(issue.ID), "error", err) return db.AgentTaskQueue{}, fmt.Errorf("load agent: %w", err) } if !agent.RuntimeID.Valid { + slog.Error("task enqueue failed", "issue_id", util.UUIDToString(issue.ID), "error", "agent has no runtime") return db.AgentTaskQueue{}, fmt.Errorf("agent has no runtime") } runtime, err := s.Queries.GetAgentRuntime(ctx, agent.RuntimeID) if err != nil { + slog.Error("task enqueue failed", "issue_id", util.UUIDToString(issue.ID), "error", err) return db.AgentTaskQueue{}, fmt.Errorf("load runtime: %w", err) } @@ -64,9 +69,11 @@ func (s *TaskService) EnqueueTaskForIssue(ctx context.Context, issue db.Issue) ( Context: contextJSON, }) if err != nil { + slog.Error("task enqueue failed", "issue_id", util.UUIDToString(issue.ID), "error", err) return db.AgentTaskQueue{}, fmt.Errorf("create task: %w", err) } + slog.Info("task enqueued", "task_id", util.UUIDToString(task.ID), "issue_id", util.UUIDToString(issue.ID), "agent_id", util.UUIDToString(issue.AssigneeID)) return task, nil } @@ -88,17 +95,21 @@ func (s *TaskService) ClaimTask(ctx context.Context, agentID pgtype.UUID) (*db.A return nil, fmt.Errorf("count running tasks: %w", err) } if running >= int64(agent.MaxConcurrentTasks) { + slog.Debug("task claim: no capacity", "agent_id", util.UUIDToString(agentID), "running", running, "max", agent.MaxConcurrentTasks) return nil, nil // No capacity } task, err := s.Queries.ClaimAgentTask(ctx, agentID) if err != nil { if errors.Is(err, pgx.ErrNoRows) { + slog.Debug("task claim: no tasks available", "agent_id", util.UUIDToString(agentID)) return nil, nil // No tasks available } return nil, fmt.Errorf("claim task: %w", err) } + slog.Info("task claimed", "task_id", util.UUIDToString(task.ID), "agent_id", util.UUIDToString(agentID)) + // Update agent status to working s.updateAgentStatus(ctx, agentID, "working") @@ -143,6 +154,8 @@ func (s *TaskService) StartTask(ctx context.Context, taskID pgtype.UUID) (*db.Ag return nil, fmt.Errorf("start task: %w", err) } + slog.Info("task started", "task_id", util.UUIDToString(task.ID), "issue_id", util.UUIDToString(task.IssueID)) + // Sync issue → in_progress issue, err := s.Queries.UpdateIssueStatus(ctx, db.UpdateIssueStatusParams{ ID: task.IssueID, @@ -165,6 +178,8 @@ func (s *TaskService) CompleteTask(ctx context.Context, taskID pgtype.UUID, resu return nil, fmt.Errorf("complete task: %w", err) } + slog.Info("task completed", "task_id", util.UUIDToString(task.ID), "issue_id", util.UUIDToString(task.IssueID)) + // Sync issue → in_review issue, issueErr := s.Queries.UpdateIssueStatus(ctx, db.UpdateIssueStatusParams{ ID: task.IssueID, @@ -204,6 +219,8 @@ func (s *TaskService) FailTask(ctx context.Context, taskID pgtype.UUID, errMsg s return nil, fmt.Errorf("fail task: %w", err) } + slog.Warn("task failed", "task_id", util.UUIDToString(task.ID), "issue_id", util.UUIDToString(task.IssueID), "error", errMsg) + // Sync issue → blocked issue, issueErr := s.Queries.UpdateIssueStatus(ctx, db.UpdateIssueStatusParams{ ID: task.IssueID, @@ -254,6 +271,7 @@ func (s *TaskService) ReconcileAgentStatus(ctx context.Context, agentID pgtype.U if running > 0 { newStatus = "working" } + slog.Debug("agent status reconciled", "agent_id", util.UUIDToString(agentID), "status", newStatus, "running_tasks", running) s.updateAgentStatus(ctx, agentID, newStatus) } diff --git a/server/pkg/agent/agent.go b/server/pkg/agent/agent.go index 96a73de4..e2198f40 100644 --- a/server/pkg/agent/agent.go +++ b/server/pkg/agent/agent.go @@ -6,7 +6,7 @@ package agent import ( "context" "fmt" - "log" + "log/slog" "time" ) @@ -73,14 +73,14 @@ type Result struct { type Config struct { ExecutablePath string // path to CLI binary (claude or codex) Env map[string]string // extra environment variables - Logger *log.Logger + Logger *slog.Logger } // New creates a Backend for the given agent type. // Supported types: "claude", "codex". func New(agentType string, cfg Config) (Backend, error) { if cfg.Logger == nil { - cfg.Logger = log.Default() + cfg.Logger = slog.Default() } switch agentType { diff --git a/server/pkg/agent/claude.go b/server/pkg/agent/claude.go index 1093b739..6c83a288 100644 --- a/server/pkg/agent/claude.go +++ b/server/pkg/agent/claude.go @@ -5,7 +5,7 @@ import ( "context" "encoding/json" "fmt" - "log" + "log/slog" "os" "os/exec" "strings" @@ -72,7 +72,7 @@ func (b *claudeBackend) Execute(ctx context.Context, prompt string, opts ExecOpt return nil, fmt.Errorf("start claude: %w", err) } - b.cfg.Logger.Printf("[claude] started pid=%d cwd=%s model=%s", cmd.Process.Pid, opts.Cwd, opts.Model) + b.cfg.Logger.Info("claude started", "pid", cmd.Process.Pid, "cwd", opts.Cwd, "model", opts.Model) msgCh := make(chan Message, 256) resCh := make(chan Result, 1) @@ -151,8 +151,7 @@ func (b *claudeBackend) Execute(ctx context.Context, prompt string, opts ExecOpt finalError = fmt.Sprintf("claude exited with error: %v", exitErr) } - b.cfg.Logger.Printf("[claude] finished pid=%d status=%s duration=%s", - cmd.Process.Pid, finalStatus, duration.Round(time.Millisecond)) + b.cfg.Logger.Info("claude finished", "pid", cmd.Process.Pid, "status", finalStatus, "duration", duration.Round(time.Millisecond).String()) resCh <- Result{ Status: finalStatus, @@ -244,12 +243,12 @@ func (b *claudeBackend) handleControlRequest(msg claudeSDKMessage, stdin interfa data, err := json.Marshal(response) if err != nil { - b.cfg.Logger.Printf("[claude] failed to marshal control response: %v", err) + b.cfg.Logger.Warn("claude: failed to marshal control response", "error", err) return } data = append(data, '\n') if _, err := stdin.Write(data); err != nil { - b.cfg.Logger.Printf("[claude] failed to write control response: %v", err) + b.cfg.Logger.Warn("claude: failed to write control response", "error", err) } } @@ -329,20 +328,20 @@ func detectCLIVersion(ctx context.Context, execPath string) (string, error) { return strings.TrimSpace(string(data)), nil } -// logWriter adapts a *log.Logger to an io.Writer for capturing stderr. +// logWriter adapts a *slog.Logger to an io.Writer for capturing stderr. type logWriter struct { - logger *log.Logger + logger *slog.Logger prefix string } -func newLogWriter(logger *log.Logger, prefix string) *logWriter { +func newLogWriter(logger *slog.Logger, prefix string) *logWriter { return &logWriter{logger: logger, prefix: prefix} } func (w *logWriter) Write(p []byte) (int, error) { text := strings.TrimSpace(string(p)) if text != "" { - w.logger.Printf("%s%s", w.prefix, text) + w.logger.Debug(w.prefix + text) } return len(p), nil } diff --git a/server/pkg/agent/claude_test.go b/server/pkg/agent/claude_test.go index 8018a2bf..075501a2 100644 --- a/server/pkg/agent/claude_test.go +++ b/server/pkg/agent/claude_test.go @@ -3,7 +3,7 @@ package agent import ( "bytes" "encoding/json" - "log" + "log/slog" "strings" "testing" ) @@ -11,7 +11,7 @@ import ( func TestClaudeHandleAssistantText(t *testing.T) { t.Parallel() - b := &claudeBackend{cfg: Config{Logger: log.Default()}} + b := &claudeBackend{cfg: Config{Logger: slog.Default()}} ch := make(chan Message, 10) var output strings.Builder @@ -43,7 +43,7 @@ func TestClaudeHandleAssistantText(t *testing.T) { func TestClaudeHandleAssistantToolUse(t *testing.T) { t.Parallel() - b := &claudeBackend{cfg: Config{Logger: log.Default()}} + b := &claudeBackend{cfg: Config{Logger: slog.Default()}} ch := make(chan Message, 10) var output strings.Builder @@ -83,7 +83,7 @@ func TestClaudeHandleAssistantToolUse(t *testing.T) { func TestClaudeHandleUserToolResult(t *testing.T) { t.Parallel() - b := &claudeBackend{cfg: Config{Logger: log.Default()}} + b := &claudeBackend{cfg: Config{Logger: slog.Default()}} ch := make(chan Message, 10) msg := claudeSDKMessage{ @@ -115,8 +115,7 @@ func TestClaudeHandleUserToolResult(t *testing.T) { func TestClaudeHandleControlRequestAutoApproves(t *testing.T) { t.Parallel() - var buf bytes.Buffer - b := &claudeBackend{cfg: Config{Logger: log.New(&buf, "", 0)}} + b := &claudeBackend{cfg: Config{Logger: slog.Default()}} var written bytes.Buffer @@ -153,7 +152,7 @@ func TestClaudeHandleControlRequestAutoApproves(t *testing.T) { func TestClaudeHandleAssistantInvalidJSON(t *testing.T) { t.Parallel() - b := &claudeBackend{cfg: Config{Logger: log.Default()}} + b := &claudeBackend{cfg: Config{Logger: slog.Default()}} ch := make(chan Message, 10) var output strings.Builder diff --git a/server/pkg/agent/codex.go b/server/pkg/agent/codex.go index aa1efbbf..a76e42ea 100644 --- a/server/pkg/agent/codex.go +++ b/server/pkg/agent/codex.go @@ -55,7 +55,7 @@ func (b *codexBackend) Execute(ctx context.Context, prompt string, opts ExecOpti return nil, fmt.Errorf("start codex: %w", err) } - b.cfg.Logger.Printf("[codex] started app-server pid=%d cwd=%s", cmd.Process.Pid, opts.Cwd) + b.cfg.Logger.Info("codex started app-server", "pid", cmd.Process.Pid, "cwd", opts.Cwd) msgCh := make(chan Message, 256) resCh := make(chan Result, 1) @@ -171,7 +171,7 @@ func (b *codexBackend) Execute(ctx context.Context, prompt string, opts ExecOpti return } c.threadID = threadID - b.cfg.Logger.Printf("[codex] thread started: %s", threadID) + b.cfg.Logger.Info("codex thread started", "thread_id", threadID) // 3. Send turn and wait for completion _, err = c.request(runCtx, "turn/start", map[string]any{ @@ -205,8 +205,7 @@ func (b *codexBackend) Execute(ctx context.Context, prompt string, opts ExecOpti } duration := time.Since(startTime) - b.cfg.Logger.Printf("[codex] finished pid=%d status=%s duration=%s", - cmd.Process.Pid, finalStatus, duration.Round(time.Millisecond)) + b.cfg.Logger.Info("codex finished", "pid", cmd.Process.Pid, "status", finalStatus, "duration", duration.Round(time.Millisecond).String()) // Close stdin and cancel context to signal the app-server to exit. // Without this, the long-running codex process keeps stdout open and diff --git a/server/pkg/agent/codex_test.go b/server/pkg/agent/codex_test.go index dc3f64b1..2312b4b3 100644 --- a/server/pkg/agent/codex_test.go +++ b/server/pkg/agent/codex_test.go @@ -3,7 +3,7 @@ package agent import ( "encoding/json" "fmt" - "log" + "log/slog" "sync" "testing" ) @@ -15,7 +15,7 @@ func newTestCodexClient(t *testing.T) (*codexClient, *fakeStdin, []Message) { var messages []Message c := &codexClient{ - cfg: Config{Logger: log.Default()}, + cfg: Config{Logger: slog.Default()}, stdin: fs, pending: make(map[int]*pendingRPC), onMessage: func(msg Message) {