improve state tracking for icon changes

Author: Thomas Stromberg

cmd/goose/main.go

@@ -46,7 +46,6 @@ const (
 	maxConcurrentTurnAPICalls = 20
 	defaultMaxBrowserOpensDay = 20
 	startupGracePeriod        = 1 * time.Minute  // Don't play sounds or auto-open for first minute
-	maxAgeForNewlyBlocked     = 1 * time.Hour     // PRs older than this won't be treated as newly blocked
 )
 
 // PR represents a pull request with metadata.
@@ -93,6 +92,7 @@ type App struct {
 	mu                  sync.RWMutex
 	enableAutoBrowser   bool
 	hideStaleIncoming   bool
+	hasPerformedInitialDiscovery bool // Track if we've done the first poll to distinguish from real state changes
 	noCache             bool
 	enableAudioCues     bool
 	initialLoadComplete bool
@@ -522,10 +522,10 @@ func (app *App) updatePRs(ctx context.Context) {
 	slog.Info("[UPDATE] PR counts after update",
 		"incoming_count", len(incoming),
 		"outgoing_count", len(outgoing))
-	// Log ALL outgoing PRs for debugging (temporarily)
-	slog.Info("[UPDATE] Listing ALL outgoing PRs for debugging")
+	// Log ALL outgoing PRs for debugging
+	slog.Debug("[UPDATE] Listing ALL outgoing PRs for debugging")
 	for i, pr := range outgoing {
-		slog.Info("[UPDATE] Outgoing PR details",
+		slog.Debug("[UPDATE] Outgoing PR details",
 			"index", i,
 			"repo", pr.Repository,
 			"number", pr.Number,
@@ -550,6 +550,7 @@ func (app *App) updatePRs(ctx context.Context) {
 
 // updateMenu rebuilds the menu only if there are changes to improve UX.
 func (app *App) updateMenu(ctx context.Context) {
+	slog.Debug("[MENU] updateMenu called, generating current titles")
 	// Generate current menu titles
 	currentTitles := app.generateMenuTitles()
 
@@ -566,6 +567,21 @@ func (app *App) updateMenu(ctx context.Context) {
 
 	// Titles have changed, rebuild menu
 	slog.Info("[MENU] Changes detected, rebuilding menu", "oldCount", len(lastTitles), "newCount", len(currentTitles))
+
+	// Log what changed for debugging
+	for i, current := range currentTitles {
+		if i < len(lastTitles) {
+			if current != lastTitles[i] {
+				slog.Debug("[MENU] Title changed", "index", i, "old", lastTitles[i], "new", current)
+			}
+		} else {
+			slog.Debug("[MENU] New title added", "index", i, "title", current)
+		}
+	}
+	for i := len(currentTitles); i < len(lastTitles); i++ {
+		slog.Debug("[MENU] Title removed", "index", i, "title", lastTitles[i])
+	}
+
 	app.rebuildMenu(ctx)
 
 	// Store new titles
@@ -669,6 +685,7 @@ func (app *App) updatePRsWithWait(ctx context.Context) {
 	if !app.menuInitialized {
 		// Create initial menu with Turn data
 		// Initialize menu structure
+		slog.Info("[FLOW] Creating initial menu (first time)")
 		app.rebuildMenu(ctx)
 		app.menuInitialized = true
 		// Store initial menu titles to prevent unnecessary rebuild on first update
@@ -678,14 +695,17 @@ func (app *App) updatePRsWithWait(ctx context.Context) {
 		app.lastMenuTitles = menuTitles
 		app.mu.Unlock()
 		// Menu initialization complete
+		slog.Info("[FLOW] Initial menu created successfully")
 	} else {
+		slog.Info("[FLOW] Updating existing menu")
 		app.updateMenu(ctx)
+		slog.Info("[FLOW] Menu update completed")
 	}
 
 	// Process notifications using the simplified state manager
-	slog.Debug("[DEBUG] Processing PR state updates and notifications")
+	slog.Info("[FLOW] About to process PR state updates and notifications")
 	app.updatePRStatesAndNotify(ctx)
-	slog.Debug("[DEBUG] Completed PR state updates and notifications")
+	slog.Info("[FLOW] Completed PR state updates and notifications")
 	// Mark initial load as complete after first successful update
 	if !app.initialLoadComplete {
 		app.mu.Lock()

cmd/goose/notifications.go

@@ -26,8 +26,17 @@ func (app *App) processNotifications(ctx context.Context) {
 	copy(outgoing, app.outgoing)
 	app.mu.RUnlock()
 
+	// Determine if this is the initial discovery
+	isInitialDiscovery := !app.hasPerformedInitialDiscovery
+
 	// Let the state manager figure out what needs notifications
-	toNotify := app.stateManager.UpdatePRs(incoming, outgoing, hiddenOrgs)
+	toNotify := app.stateManager.UpdatePRs(incoming, outgoing, hiddenOrgs, isInitialDiscovery)
+
+	// Mark that we've performed initial discovery
+	if isInitialDiscovery {
+		app.hasPerformedInitialDiscovery = true
+		slog.Info("[STATE] Initial discovery completed", "incoming_count", len(incoming), "outgoing_count", len(outgoing))
+	}
 
 	// Update deprecated fields for test compatibility
 	app.mu.Lock()
@@ -81,8 +90,9 @@ func (app *App) processNotifications(ctx context.Context) {
 
 	// Update menu if we sent notifications
 	if len(toNotify) > 0 {
-		slog.Debug("[NOTIFY] Updating menu after notifications")
+		slog.Info("[FLOW] Updating menu after sending notifications", "notified_count", len(toNotify))
 		app.updateMenu(ctx)
+		slog.Info("[FLOW] Menu update after notifications completed")
 	}
 }
 

cmd/goose/pr_state.go

@@ -9,10 +9,11 @@ import (
 
 // PRState tracks the complete state of a PR including blocking history.
 type PRState struct {
-	FirstBlockedAt  time.Time
-	LastSeenBlocked time.Time
-	PR              PR
-	HasNotified     bool
+	FirstBlockedAt     time.Time
+	LastSeenBlocked    time.Time
+	PR                 PR
+	HasNotified        bool
+	IsInitialDiscovery bool // True if this PR was discovered as already blocked during startup
 }
 
 // PRStateManager manages all PR states with proper synchronization.
@@ -34,13 +35,18 @@ func NewPRStateManager(startTime time.Time) *PRStateManager {
 
 // UpdatePRs updates the state with new PR data and returns which PRs need notifications.
 // This function is thread-safe and handles all state transitions atomically.
-func (m *PRStateManager) UpdatePRs(incoming, outgoing []PR, hiddenOrgs map[string]bool) (toNotify []PR) {
+// isInitialDiscovery should be true only on the very first poll to prevent notifications for already-blocked PRs.
+func (m *PRStateManager) UpdatePRs(incoming, outgoing []PR, hiddenOrgs map[string]bool, isInitialDiscovery bool) (toNotify []PR) {
 	m.mu.Lock()
 	defer m.mu.Unlock()
 
 	now := time.Now()
 	inGracePeriod := time.Since(m.startTime) < time.Duration(m.gracePeriodSeconds)*time.Second
 
+	slog.Debug("[STATE] UpdatePRs called",
+		"incoming", len(incoming), "outgoing", len(outgoing),
+		"existing_states", len(m.states), "in_grace_period", inGracePeriod, "is_initial_discovery", isInitialDiscovery)
+
 	// Track which PRs are currently blocked
 	currentlyBlocked := make(map[string]bool)
 
@@ -62,7 +68,10 @@ func (m *PRStateManager) UpdatePRs(incoming, outgoing []PR, hiddenOrgs map[strin
 		if !isBlocked {
 			// PR is not blocked - remove from tracking if it was
 			if state, exists := m.states[pr.URL]; exists && state != nil {
-				slog.Info("[STATE] PR no longer blocked", "repo", pr.Repository, "number", pr.Number)
+				slog.Info("[STATE] State transition: blocked -> unblocked",
+					"repo", pr.Repository, "number", pr.Number, "url", pr.URL,
+					"was_blocked_since", state.FirstBlockedAt.Format(time.RFC3339),
+					"blocked_duration", time.Since(state.FirstBlockedAt).Round(time.Second))
 				delete(m.states, pr.URL)
 			}
 			continue
@@ -73,37 +82,44 @@ func (m *PRStateManager) UpdatePRs(incoming, outgoing []PR, hiddenOrgs map[strin
 		// Get or create state for this PR
 		state, exists := m.states[pr.URL]
 		if !exists {
-			// Check if PR is too old to be considered "newly blocked"
-			// If the PR hasn't been updated in over an hour, don't treat it as new
-			const maxAgeForNewlyBlocked = 1 * time.Hour
-			prAge := time.Since(pr.UpdatedAt)
-
-			if prAge > maxAgeForNewlyBlocked {
-				// Old PR, track it but don't notify
+			// This PR was not in our state before
+			if isInitialDiscovery {
+				// Initial discovery: PR was already blocked when we started, no state transition
 				state = &PRState{
-					PR:              pr,
-					FirstBlockedAt:  now,
-					LastSeenBlocked: now,
-					HasNotified:     true, // Mark as already notified to prevent future notifications
+					PR:                 pr,
+					FirstBlockedAt:     now,
+					LastSeenBlocked:    now,
+					HasNotified:        false, // Don't consider this as notified since no actual notification was sent
+					IsInitialDiscovery: true,  // Mark as initial discovery to prevent notifications and party poppers
 				}
 				m.states[pr.URL] = state
-				slog.Debug("[STATE] Blocked PR detected but too old to notify",
-					"repo", pr.Repository, "number", pr.Number,
-					"age", prAge.Round(time.Minute), "maxAge", maxAgeForNewlyBlocked)
+
+				slog.Info("[STATE] Initial discovery: already blocked PR",
+					"repo", pr.Repository,
+					"number", pr.Number,
+					"url", pr.URL,
+					"pr_updated_at", pr.UpdatedAt.Format(time.RFC3339),
+					"firstBlockedAt", state.FirstBlockedAt.Format(time.RFC3339))
 			} else {
-				// New blocked PR that was recently updated!
+				// Actual state transition: unblocked -> blocked
 				state = &PRState{
-					PR:              pr,
-					FirstBlockedAt:  now,
-					LastSeenBlocked: now,
-					HasNotified:     false,
+					PR:                 pr,
+					FirstBlockedAt:     now,
+					LastSeenBlocked:    now,
+					HasNotified:        false,
+					IsInitialDiscovery: false, // This is a real state transition
 				}
 				m.states[pr.URL] = state
 
-				slog.Info("[STATE] New blocked PR detected", "repo", pr.Repository, "number", pr.Number,
-					"age", prAge.Round(time.Minute))
+				slog.Info("[STATE] State transition: unblocked -> blocked",
+					"repo", pr.Repository,
+					"number", pr.Number,
+					"url", pr.URL,
+					"pr_updated_at", pr.UpdatedAt.Format(time.RFC3339),
+					"firstBlockedAt", state.FirstBlockedAt.Format(time.RFC3339),
+					"inGracePeriod", inGracePeriod)
 
-				// Should we notify?
+				// Should we notify for actual state transitions?
 				if !inGracePeriod && !state.HasNotified {
 					slog.Debug("[STATE] Will notify for newly blocked PR", "repo", pr.Repository, "number", pr.Number)
 					toNotify = append(toNotify, pr)
@@ -113,12 +129,20 @@ func (m *PRStateManager) UpdatePRs(incoming, outgoing []PR, hiddenOrgs map[strin
 				}
 			}
 		} else {
-			// PR was already blocked
+			// PR was already blocked in our state - just update data, preserve FirstBlockedAt
+			originalFirstBlocked := state.FirstBlockedAt
 			state.LastSeenBlocked = now
 			state.PR = pr // Update PR data
 
+			slog.Debug("[STATE] State transition: blocked -> blocked (no change)",
+				"repo", pr.Repository, "number", pr.Number, "url", pr.URL,
+				"original_first_blocked", originalFirstBlocked.Format(time.RFC3339),
+				"time_since_first_blocked", time.Since(originalFirstBlocked).Round(time.Second),
+				"has_notified", state.HasNotified)
+
 			// If we haven't notified yet and we're past grace period, notify now
-			if !state.HasNotified && !inGracePeriod {
+			// But don't notify for initial discovery PRs
+			if !state.HasNotified && !inGracePeriod && !state.IsInitialDiscovery {
 				slog.Info("[STATE] Past grace period, notifying for previously blocked PR",
 					"repo", pr.Repository, "number", pr.Number)
 				toNotify = append(toNotify, pr)
@@ -128,13 +152,26 @@ func (m *PRStateManager) UpdatePRs(incoming, outgoing []PR, hiddenOrgs map[strin
 	}
 
 	// Clean up states for PRs that are no longer in our lists
-	for url := range m.states {
+	// Add more conservative cleanup with logging
+	removedCount := 0
+	for url, state := range m.states {
 		if !currentlyBlocked[url] {
-			slog.Debug("[STATE] Removing stale state for PR", "url", url)
+			timeSinceLastSeen := time.Since(state.LastSeenBlocked)
+			slog.Info("[STATE] Removing stale PR state (no longer blocked)",
+				"url", url, "repo", state.PR.Repository, "number", state.PR.Number,
+				"first_blocked_at", state.FirstBlockedAt.Format(time.RFC3339),
+				"last_seen_blocked", state.LastSeenBlocked.Format(time.RFC3339),
+				"time_since_last_seen", timeSinceLastSeen.Round(time.Second),
+				"was_notified", state.HasNotified)
 			delete(m.states, url)
+			removedCount++
 		}
 	}
 
+	if removedCount > 0 {
+		slog.Info("[STATE] State cleanup completed", "removed_states", removedCount, "remaining_states", len(m.states))
+	}
+
 	return toNotify
 }