Migrate to slog library

Author: tstromberg

cmd/goose/browser_rate_limiter.go

@@ -2,7 +2,7 @@
 package main
 
 import (
-	"log"
+	"log/slog"
 	"sync"
 	"time"
 )
@@ -20,8 +20,8 @@ type BrowserRateLimiter struct {
 
 // NewBrowserRateLimiter creates a new browser rate limiter.
 func NewBrowserRateLimiter(startupDelay time.Duration, maxPerMinute, maxPerDay int) *BrowserRateLimiter {
-	log.Printf("[BROWSER] Initializing rate limiter: startup_delay=%v, max_per_minute=%d, max_per_day=%d",
-		startupDelay, maxPerMinute, maxPerDay)
+	slog.Info("[BROWSER] Initializing rate limiter",
+		"startup_delay", startupDelay, "max_per_minute", maxPerMinute, "max_per_day", maxPerDay)
 	return &BrowserRateLimiter{
 		openedLastMinute: make([]time.Time, 0),
 		openedToday:      make([]time.Time, 0),
@@ -39,14 +39,14 @@ func (b *BrowserRateLimiter) CanOpen(startTime time.Time, prURL string) bool {
 
 	// Check if we've already opened this PR
 	if b.openedPRs[prURL] {
-		log.Printf("[BROWSER] Skipping auto-open: PR already opened - %s", prURL)
+		slog.Debug("[BROWSER] Skipping auto-open: PR already opened", "url", prURL)
 		return false
 	}
 
 	// Check startup delay
 	if time.Since(startTime) < b.startupDelay {
-		log.Printf("[BROWSER] Skipping auto-open: within startup delay period (%v remaining)",
-			b.startupDelay-time.Since(startTime))
+		slog.Debug("[BROWSER] Skipping auto-open: within startup delay period",
+			"remaining", b.startupDelay-time.Since(startTime))
 		return false
 	}
 
@@ -57,15 +57,15 @@ func (b *BrowserRateLimiter) CanOpen(startTime time.Time, prURL string) bool {
 
 	// Check per-minute limit
 	if len(b.openedLastMinute) >= b.maxPerMinute {
-		log.Printf("[BROWSER] Rate limit: already opened %d PRs in the last minute (max: %d)",
-			len(b.openedLastMinute), b.maxPerMinute)
+		slog.Debug("[BROWSER] Rate limit: per-minute limit reached",
+			"opened", len(b.openedLastMinute), "max", b.maxPerMinute)
 		return false
 	}
 
 	// Check per-day limit
 	if len(b.openedToday) >= b.maxPerDay {
-		log.Printf("[BROWSER] Rate limit: already opened %d PRs today (max: %d)",
-			len(b.openedToday), b.maxPerDay)
+		slog.Debug("[BROWSER] Rate limit: daily limit reached",
+			"opened", len(b.openedToday), "max", b.maxPerDay)
 		return false
 	}
 
@@ -82,8 +82,9 @@ func (b *BrowserRateLimiter) RecordOpen(prURL string) {
 	b.openedToday = append(b.openedToday, now)
 	b.openedPRs[prURL] = true
 
-	log.Printf("[BROWSER] Recorded browser open for %s (minute: %d/%d, today: %d/%d)",
-		prURL, len(b.openedLastMinute), b.maxPerMinute, len(b.openedToday), b.maxPerDay)
+	slog.Info("[BROWSER] Recorded browser open",
+		"url", prURL, "minuteCount", len(b.openedLastMinute), "minuteMax", b.maxPerMinute,
+		"todayCount", len(b.openedToday), "todayMax", b.maxPerDay)
 }
 
 // cleanOldEntries removes entries outside the time windows.
@@ -115,5 +116,5 @@ func (b *BrowserRateLimiter) Reset() {
 	defer b.mu.Unlock()
 	previousCount := len(b.openedPRs)
 	b.openedPRs = make(map[string]bool)
-	log.Printf("[BROWSER] Rate limiter reset: cleared %d tracked PRs", previousCount)
+	slog.Info("[BROWSER] Rate limiter reset", "clearedPRs", previousCount)
 }

cmd/goose/cache.go

@@ -7,7 +7,7 @@ import (
 	"encoding/hex"
 	"encoding/json"
 	"fmt"
-	"log"
+	"log/slog"
 	"os"
 	"path/filepath"
 	"strings"
@@ -41,10 +41,10 @@ func (app *App) turnData(ctx context.Context, url string, updatedAt time.Time) (
 		if data, readErr := os.ReadFile(cacheFile); readErr == nil {
 			var entry cacheEntry
 			if unmarshalErr := json.Unmarshal(data, &entry); unmarshalErr != nil {
-				log.Printf("Failed to unmarshal cache data for %s: %v", url, unmarshalErr)
+				slog.Warn("Failed to unmarshal cache data", "url", url, "error", unmarshalErr)
 				// Remove corrupted cache file
 				if removeErr := os.Remove(cacheFile); removeErr != nil {
-					log.Printf("Failed to remove corrupted cache file: %v", removeErr)
+					slog.Error("Failed to remove corrupted cache file", "error", removeErr)
 				}
 			} else if time.Since(entry.CachedAt) < cacheTTL && entry.UpdatedAt.Equal(updatedAt) {
 				// Check if cache is still valid (2 hour TTL)
@@ -55,9 +55,9 @@ func (app *App) turnData(ctx context.Context, url string, updatedAt time.Time) (
 
 	// Cache miss, fetch from API
 	if app.noCache {
-		log.Printf("Cache bypassed for %s (--no-cache), fetching from Turn API", url)
+		slog.Debug("Cache bypassed (--no-cache), fetching from Turn API", "url", url)
 	} else {
-		log.Printf("Cache miss for %s, fetching from Turn API", url)
+		slog.Debug("Cache miss, fetching from Turn API", "url", url)
 	}
 
 	// Use exponential backoff with jitter for Turn API calls
@@ -70,7 +70,7 @@ func (app *App) turnData(ctx context.Context, url string, updatedAt time.Time) (
 		var retryErr error
 		data, retryErr = app.turnClient.Check(turnCtx, url, app.currentUser.GetLogin(), updatedAt)
 		if retryErr != nil {
-			log.Printf("Turn API error (will retry): %v", retryErr)
+			slog.Warn("Turn API error (will retry)", "error", retryErr)
 			return retryErr
 		}
 		return nil
@@ -79,12 +79,12 @@ func (app *App) turnData(ctx context.Context, url string, updatedAt time.Time) (
 		retry.DelayType(retry.CombineDelay(retry.BackOffDelay, retry.RandomDelay)), // Add jitter for better backoff distribution
 		retry.MaxDelay(maxRetryDelay),
 		retry.OnRetry(func(n uint, err error) {
-			log.Printf("[TURN] API retry %d/%d for %s: %v", n+1, maxRetries, url, err)
+			slog.Warn("[TURN] API retry", "attempt", n+1, "maxRetries", maxRetries, "url", url, "error", err)
 		}),
 		retry.Context(ctx),
 	)
 	if err != nil {
-		log.Printf("Turn API error after %d retries (will use PR without metadata): %v", maxRetries, err)
+		slog.Error("Turn API error after retries (will use PR without metadata)", "maxRetries", maxRetries, "error", err)
 		return nil, false, err
 	}
 
@@ -96,13 +96,13 @@ func (app *App) turnData(ctx context.Context, url string, updatedAt time.Time) (
 			UpdatedAt: updatedAt,
 		}
 		if cacheData, marshalErr := json.Marshal(entry); marshalErr != nil {
-			log.Printf("Failed to marshal cache data for %s: %v", url, marshalErr)
+			slog.Error("Failed to marshal cache data", "url", url, "error", marshalErr)
 		} else {
 			// Ensure cache directory exists with secure permissions
 			if dirErr := os.MkdirAll(filepath.Dir(cacheFile), 0o700); dirErr != nil {
-				log.Printf("Failed to create cache directory: %v", dirErr)
+				slog.Error("Failed to create cache directory", "error", dirErr)
 			} else if writeErr := os.WriteFile(cacheFile, cacheData, 0o600); writeErr != nil {
-				log.Printf("Failed to write cache file: %v", writeErr)
+				slog.Error("Failed to write cache file", "error", writeErr)
 			}
 		}
 	}
@@ -114,7 +114,7 @@ func (app *App) turnData(ctx context.Context, url string, updatedAt time.Time) (
 func (app *App) cleanupOldCache() {
 	entries, err := os.ReadDir(app.cacheDir)
 	if err != nil {
-		log.Printf("Failed to read cache directory for cleanup: %v", err)
+		slog.Error("Failed to read cache directory for cleanup", "error", err)
 		return
 	}
 
@@ -126,7 +126,7 @@ func (app *App) cleanupOldCache() {
 
 		info, err := entry.Info()
 		if err != nil {
-			log.Printf("Failed to get file info for cache entry %s: %v", entry.Name(), err)
+			slog.Error("Failed to get file info for cache entry", "entry", entry.Name(), "error", err)
 			errorCount++
 			continue
 		}
@@ -135,7 +135,7 @@ func (app *App) cleanupOldCache() {
 		if time.Since(info.ModTime()) > cacheCleanupInterval {
 			filePath := filepath.Join(app.cacheDir, entry.Name())
 			if removeErr := os.Remove(filePath); removeErr != nil {
-				log.Printf("Failed to remove old cache file %s: %v", filePath, removeErr)
+				slog.Error("Failed to remove old cache file", "file", filePath, "error", removeErr)
 				errorCount++
 			} else {
 				cleanupCount++
@@ -144,6 +144,6 @@ func (app *App) cleanupOldCache() {
 	}
 
 	if cleanupCount > 0 || errorCount > 0 {
-		log.Printf("Cache cleanup completed: %d files removed, %d errors", cleanupCount, errorCount)
+		slog.Info("Cache cleanup completed", "removed", cleanupCount, "errors", errorCount)
 	}
 }

cmd/goose/github.go

@@ -5,7 +5,7 @@ import (
 	"context"
 	"errors"
 	"fmt"
-	"log"
+	"log/slog"
 	"os"
 	"os/exec"
 	"path/filepath"
@@ -65,21 +65,21 @@ func (*App) token(ctx context.Context) (string, error) {
 		if !githubTokenRegex.MatchString(token) {
 			return "", errors.New("GITHUB_TOKEN has invalid format")
 		}
-		log.Println("Using GitHub token from GITHUB_TOKEN environment variable")
+		slog.Info("Using GitHub token from GITHUB_TOKEN environment variable")
 		return token, nil
 	}
 	// Try to find gh in PATH first
 	ghPath, err := exec.LookPath("gh")
 	if err == nil {
-		log.Printf("Found gh in PATH at: %s", ghPath)
+		slog.Debug("Found gh in PATH", "path", ghPath)
 		// Resolve any symlinks to get the real path
 		if realPath, err := filepath.EvalSymlinks(ghPath); err == nil {
 			ghPath = realPath
-			log.Printf("Resolved to: %s", ghPath)
+			slog.Debug("Resolved gh path", "path", ghPath)
 		}
 	} else {
 		// Fall back to checking common installation paths
-		log.Print("gh not found in PATH, checking common locations...")
+		slog.Debug("gh not found in PATH, checking common locations...")
 		var commonPaths []string
 		switch runtime.GOOS {
 		case "windows":
@@ -126,7 +126,7 @@ func (*App) token(ctx context.Context) (string, error) {
 				continue // Skip empty paths from unset env vars
 			}
 			if _, err := os.Stat(path); err == nil {
-				log.Printf("Found gh at common location: %s", path)
+				slog.Debug("Found gh at common location", "path", path)
 				ghPath = path
 				break
 			}
@@ -137,7 +137,7 @@ func (*App) token(ctx context.Context) (string, error) {
 		return "", errors.New("gh CLI not found in PATH or common locations, and GITHUB_TOKEN not set")
 	}
 
-	log.Printf("Executing command: %s auth token", ghPath)
+	slog.Debug("Executing gh command", "command", ghPath+" auth token")
 
 	// Use retry logic for gh CLI command as it may fail temporarily
 	var token string
@@ -149,7 +149,7 @@ func (*App) token(ctx context.Context) (string, error) {
 		cmd := exec.CommandContext(cmdCtx, ghPath, "auth", "token")
 		output, cmdErr := cmd.CombinedOutput()
 		if cmdErr != nil {
-			log.Printf("gh command failed (will retry): %v", cmdErr)
+			slog.Warn("gh command failed (will retry)", "error", cmdErr)
 			return fmt.Errorf("exec 'gh auth token': %w", cmdErr)
 		}
 
@@ -163,15 +163,15 @@ func (*App) token(ctx context.Context) (string, error) {
 		retry.Attempts(3), // Fewer attempts for local command
 		retry.Delay(time.Second),
 		retry.OnRetry(func(n uint, err error) {
-			log.Printf("[GH CLI] Retry %d/3: %v", n+1, err)
+			slog.Warn("[GH CLI] Retry attempt", "attempt", n+1, "maxAttempts", 3, "error", err)
 		}),
 		retry.Context(ctx),
 	)
 	if retryErr != nil {
 		return "", retryErr
 	}
 
-	log.Println("Successfully obtained GitHub token from gh CLI")
+	slog.Info("Successfully obtained GitHub token from gh CLI")
 	return token, nil
 }
 
@@ -199,23 +199,23 @@ func (app *App) executeGitHubQuery(ctx context.Context, query string, opts *gith
 				case httpStatusForbidden:
 					if resp.Header.Get("X-Ratelimit-Remaining") == "0" {
 						resetTime := resp.Header.Get("X-Ratelimit-Reset")
-						log.Printf("GitHub API rate limited, reset at: %s (will retry)", resetTime)
+						slog.Warn("GitHub API rate limited (will retry)", "resetTime", resetTime)
 						return retryErr // Retry on rate limit
 					}
-					log.Print("GitHub API access forbidden (check token permissions)")
+					slog.Error("GitHub API access forbidden (check token permissions)")
 					return retry.Unrecoverable(fmt.Errorf("github API access forbidden: %w", retryErr))
 				case httpStatusUnauthorized:
-					log.Print("GitHub API authentication failed (check token)")
+					slog.Error("GitHub API authentication failed (check token)")
 					return retry.Unrecoverable(fmt.Errorf("github API authentication failed: %w", retryErr))
 				case httpStatusUnprocessable:
-					log.Printf("GitHub API query invalid: %s", query)
+					slog.Error("GitHub API query invalid", "query", query)
 					return retry.Unrecoverable(fmt.Errorf("github API query invalid: %w", retryErr))
 				default:
-					log.Printf("GitHub API error (status %d): %v (will retry)", resp.StatusCode, retryErr)
+					slog.Warn("GitHub API error (will retry)", "statusCode", resp.StatusCode, "error", retryErr)
 				}
 			} else {
 				// Likely network error - retry these
-				log.Printf("GitHub API network error: %v (will retry)", retryErr)
+				slog.Warn("GitHub API network error (will retry)", "error", retryErr)
 			}
 			return retryErr
 		}
@@ -225,7 +225,7 @@ func (app *App) executeGitHubQuery(ctx context.Context, query string, opts *gith
 		retry.DelayType(retry.CombineDelay(retry.BackOffDelay, retry.RandomDelay)), // Add jitter for better backoff distribution
 		retry.MaxDelay(maxRetryDelay),
 		retry.OnRetry(func(n uint, err error) {
-			log.Printf("[GITHUB] Search.Issues retry %d/%d: %v", n+1, maxRetries, err)
+			slog.Warn("[GITHUB] Search.Issues retry", "attempt", n+1, "maxRetries", maxRetries, "error", err)
 		}),
 		retry.Context(ctx),
 	)
@@ -289,7 +289,7 @@ func (app *App) fetchPRsInternal(ctx context.Context) (incoming []PR, outgoing [
 	// Query 1: PRs involving the user
 	go func() {
 		query := fmt.Sprintf("is:open is:pr involves:%s archived:false", user)
-		log.Printf("[GITHUB] Searching for PRs with query: %s", query)
+		slog.Debug("[GITHUB] Searching for PRs", "query", query)
 
 		result, err := app.executeGitHubQuery(ctx, query, opts)
 		if err != nil {
@@ -302,7 +302,7 @@ func (app *App) fetchPRsInternal(ctx context.Context) (incoming []PR, outgoing [
 	// Query 2: PRs in user-owned repos with no reviewers
 	go func() {
 		query := fmt.Sprintf("is:open is:pr user:%s review:none archived:false", user)
-		log.Printf("[GITHUB] Searching for PRs with query: %s", query)
+		slog.Debug("[GITHUB] Searching for PRs", "query", query)
 
 		result, err := app.executeGitHubQuery(ctx, query, opts)
 		if err != nil {
@@ -320,12 +320,12 @@ func (app *App) fetchPRsInternal(ctx context.Context) (incoming []PR, outgoing [
 	for range 2 {
 		result := <-queryResults
 		if result.err != nil {
-			log.Printf("[GITHUB] Query failed: %s - %v", result.query, result.err)
+			slog.Error("[GITHUB] Query failed", "query", result.query, "error", result.err)
 			queryErrors = append(queryErrors, result.err)
 			// Continue processing other query results even if one fails
 			continue
 		}
-		log.Printf("[GITHUB] Query completed: %s - found %d PRs", result.query, len(result.issues))
+		slog.Debug("[GITHUB] Query completed", "query", result.query, "prCount", len(result.issues))
 
 		// Deduplicate PRs based on URL
 		for _, issue := range result.issues {
@@ -336,7 +336,7 @@ func (app *App) fetchPRsInternal(ctx context.Context) (incoming []PR, outgoing [
 			}
 		}
 	}
-	log.Printf("[GITHUB] Both searches completed in %v, found %d unique PRs", time.Since(searchStart), len(allIssues))
+	slog.Info("[GITHUB] Both searches completed", "duration", time.Since(searchStart), "uniquePRs", len(allIssues))
 
 	// If both queries failed, return an error
 	if len(queryErrors) == 2 {
@@ -345,7 +345,7 @@ func (app *App) fetchPRsInternal(ctx context.Context) (incoming []PR, outgoing [
 
 	// Limit PRs for performance
 	if len(allIssues) > maxPRsToProcess {
-		log.Printf("Limiting to %d PRs for performance (total: %d)", maxPRsToProcess, len(allIssues))
+		slog.Info("Limiting PRs for performance", "limit", maxPRsToProcess, "total", len(allIssues))
 		allIssues = allIssues[:maxPRsToProcess]
 	}
 
@@ -361,7 +361,7 @@ func (app *App) fetchPRsInternal(ctx context.Context) (incoming []PR, outgoing [
 		if org != "" {
 			app.mu.Lock()
 			if !app.seenOrgs[org] {
-				log.Printf("[ORG] Discovered new organization: %s", org)
+				slog.Info("[ORG] Discovered new organization", "org", org)
 			}
 			app.seenOrgs[org] = true
 			app.mu.Unlock()
@@ -385,7 +385,7 @@ func (app *App) fetchPRsInternal(ctx context.Context) (incoming []PR, outgoing [
 	}
 
 	// Only log summary, not individual PRs
-	log.Printf("[GITHUB] Found %d incoming, %d outgoing PRs from GitHub", len(incoming), len(outgoing))
+	slog.Info("[GITHUB] GitHub PR summary", "incoming", len(incoming), "outgoing", len(outgoing))
 
 	// Fetch Turn API data
 	// Always synchronous now for simplicity - Turn API calls are fast with caching
@@ -459,7 +459,7 @@ func (app *App) fetchTurnDataSync(ctx context.Context, issues []*github.Issue, u
 				actionReason = action.Reason
 				// Only log fresh API calls
 				if !result.wasFromCache {
-					log.Printf("[TURN] UnblockAction for %s: Reason=%q, Kind=%q", result.url, action.Reason, action.Kind)
+					slog.Debug("[TURN] UnblockAction", "url", result.url, "reason", action.Reason, "kind", action.Kind)
 				}
 			}
 
@@ -487,6 +487,6 @@ func (app *App) fetchTurnDataSync(ctx context.Context, issues []*github.Issue, u
 		}
 	}
 
-	log.Printf("[TURN] Turn API queries completed in %v (%d/%d succeeded)",
-		time.Since(turnStart), turnSuccesses, turnSuccesses+turnFailures)
+	slog.Info("[TURN] Turn API queries completed",
+		"duration", time.Since(turnStart), "succeeded", turnSuccesses, "total", turnSuccesses+turnFailures)
 }