fix(oauth): resolve multiple OAuth login issues (smart-mcp-proxy#23)

- Add debug logging for server key generation to diagnose key mismatches
- Warn when tokens lack refresh_token (cannot be refreshed)
- Improve RefreshManager startup logging for debugging token loading
- Fix RefreshOAuthToken to detect dynamic OAuth (Protected Resource Metadata)
  - Previously only checked static OAuth config
  - Now also checks for stored tokens from runtime OAuth discovery
  - Uses GenerateServerKey to match PersistentTokenStore key format

Co-Authored-By: Claude Sonnet 4.5 <noreply@anthropic.com>

Author: technicalpickles

internal/oauth/persistent_token_store.go

@@ -54,7 +54,15 @@ func GenerateServerKey(serverName, serverURL string) string {
 	hashStr := hex.EncodeToString(hash[:])
 
 	// Return first 16 characters of hash for readability (still highly unique)
-	return fmt.Sprintf("%s_%s", serverName, hashStr[:16])
+	key := fmt.Sprintf("%s_%s", serverName, hashStr[:16])
+
+	// Log key generation for debugging server key mismatches
+	zap.L().Debug("Generated OAuth server key",
+		zap.String("server_name", serverName),
+		zap.String("server_url", serverURL),
+		zap.String("generated_key", key))
+
+	return key
 }
 
 // GetToken retrieves the OAuth token from persistent storage
@@ -67,11 +75,13 @@ func (p *PersistentTokenStore) GetToken(ctx context.Context) (*client.Token, err
 	}
 
 	p.logger.Debug("🔍 Loading OAuth token from persistent storage",
+		zap.String("server_name", p.serverName),
 		zap.String("server_key", p.serverKey))
 
 	record, err := p.storage.GetOAuthToken(p.serverKey)
 	if err != nil {
 		p.logger.Debug("❌ No stored OAuth token found",
+			zap.String("server_name", p.serverName),
 			zap.String("server_key", p.serverKey),
 			zap.Error(err))
 		return nil, transport.ErrNoToken
@@ -148,6 +158,19 @@ func (p *PersistentTokenStore) GetToken(ctx context.Context) (*client.Token, err
 		HasRefreshToken: record.RefreshToken != "",
 	})
 
+	// Warn if returning an expired token without a refresh token - mcp-go cannot refresh this
+	if isExpired && record.RefreshToken == "" {
+		p.logger.Warn("⚠️ Returning expired token WITHOUT refresh_token - refresh will fail",
+			zap.String("server_name", p.serverName),
+			zap.String("server_key", p.serverKey),
+			zap.Time("expired_at", record.ExpiresAt))
+	} else if record.RefreshToken == "" {
+		p.logger.Warn("⚠️ Token has no refresh_token - cannot be refreshed when it expires",
+			zap.String("server_name", p.serverName),
+			zap.String("server_key", p.serverKey),
+			zap.Time("expires_at", record.ExpiresAt))
+	}
+
 	// Return the token - mcp-go library will check IsExpired() and handle refresh if needed
 	// For long-lived tokens, we subtract the grace period from ExpiresAt to trigger refresh earlier
 	// For short-lived tokens, we use the actual expiration to avoid falsely marking them as expired

internal/oauth/refresh_manager.go

@@ -191,38 +191,58 @@ func (m *RefreshManager) Start(ctx context.Context) error {
 	defer m.mu.Unlock()
 
 	if m.started {
+		m.logger.Debug("RefreshManager already started, skipping")
 		return nil // Already started
 	}
 
 	// Create a cancellable context for all timers
 	m.ctx, m.cancel = context.WithCancel(ctx)
 	m.started = true
 
-	m.logger.Info("Starting RefreshManager")
+	m.logger.Info("RefreshManager.Start() called")
 
 	// Track startup refresh stats
 	var scheduled, immediateRefresh, expired int
 
 	// Load existing tokens and schedule refreshes
 	if m.storage != nil {
+		m.logger.Debug("Loading OAuth tokens from storage",
+			zap.Bool("storage_available", true))
+
 		tokens, err := m.storage.ListOAuthTokens()
 		if err != nil {
-			m.logger.Warn("Failed to load existing tokens", zap.Error(err))
+			m.logger.Warn("Failed to load existing tokens",
+				zap.Error(err))
 			// Continue - we can still handle new tokens
 		} else {
+			m.logger.Info("OAuth tokens retrieved from storage",
+				zap.Int("count", len(tokens)))
 			// Collect tokens that need immediate refresh (expired access token but valid refresh token)
 			var tokensToRefresh []string
 
 			for _, token := range tokens {
 				if token == nil || token.ExpiresAt.IsZero() {
+					m.logger.Debug("Skipping nil or zero-expiry token")
 					continue
 				}
 
 				serverName := token.GetServerName()
 				now := time.Now()
 
+				// Log each token being processed for debugging
+				m.logger.Debug("Processing OAuth token",
+					zap.String("server", serverName),
+					zap.String("storage_key", token.ServerName),
+					zap.Time("expires_at", token.ExpiresAt),
+					zap.Bool("has_refresh_token", token.RefreshToken != ""),
+					zap.Bool("is_expired", token.ExpiresAt.Before(now)),
+					zap.Duration("time_until_expiry", token.ExpiresAt.Sub(now)))
+
 				if token.ExpiresAt.After(now) {
 					// Token not expired - schedule proactive refresh at 80% lifetime
+					m.logger.Debug("Scheduling proactive refresh for non-expired token",
+						zap.String("server", serverName),
+						zap.Time("expires_at", token.ExpiresAt))
 					m.scheduleRefreshLocked(serverName, token.ExpiresAt)
 					scheduled++
 				} else if token.RefreshToken != "" {
@@ -269,11 +289,19 @@ func (m *RefreshManager) Start(ctx context.Context) error {
 
 			// Execute immediate refreshes asynchronously (after releasing the lock)
 			if len(tokensToRefresh) > 0 {
+				m.logger.Info("Starting asynchronous refresh for expired tokens",
+					zap.Int("count", len(tokensToRefresh)),
+					zap.Strings("servers", tokensToRefresh))
 				go m.executeStartupRefreshes(tokensToRefresh)
 			}
 		}
+	} else {
+		m.logger.Warn("RefreshManager started with nil storage - token persistence disabled")
 	}
 
+	m.logger.Info("RefreshManager startup complete",
+		zap.Int("schedules_created", len(m.schedules)))
+
 	return nil
 }
 

internal/runtime/lifecycle.go

@@ -42,6 +42,10 @@ func (r *Runtime) StartBackgroundInitialization() {
 
 		// Register token saved callback to wire PersistentTokenStore -> RefreshManager
 		oauth.GetTokenStoreManager().SetTokenSavedCallback(func(serverName string, expiresAt time.Time) {
+			r.logger.Info("OnTokenSaved callback fired - scheduling proactive refresh",
+				zap.String("server", serverName),
+				zap.Time("expires_at", expiresAt),
+				zap.Duration("valid_for", time.Until(expiresAt)))
 			r.refreshManager.OnTokenSaved(serverName, expiresAt)
 		})
 		r.logger.Info("Token saved callback registered for proactive refresh")

internal/upstream/manager.go

@@ -2346,7 +2346,10 @@ func (m *Manager) SetUserLoggedOut(serverName string, loggedOut bool) error {
 
 // RefreshOAuthToken triggers a token refresh for a specific server.
 // This is called by the RefreshManager for proactive token refresh.
-// TODO: This will be fully implemented in Phase 3 (US1) with RefreshManager integration.
+//
+// OAuth detection checks both:
+// 1. Static config (serverConfig.OAuth) - for servers with pre-configured OAuth
+// 2. Database tokens - for servers using dynamic OAuth discovery (Protected Resource Metadata)
 func (m *Manager) RefreshOAuthToken(serverName string) error {
 	m.mu.RLock()
 	client, exists := m.clients[serverName]
@@ -2356,18 +2359,40 @@ func (m *Manager) RefreshOAuthToken(serverName string) error {
 		return fmt.Errorf("server not found: %s", serverName)
 	}
 
-	// Get the server config to check if it uses OAuth
+	// Check if server uses OAuth via either static config or dynamic discovery
 	serverConfig := client.GetConfig()
-	if serverConfig == nil || serverConfig.OAuth == nil {
+	hasStaticOAuth := serverConfig != nil && serverConfig.OAuth != nil
+
+	// Also check for OAuth tokens in the database (dynamic OAuth discovery)
+	// Servers like atlassian-remote, slack discover OAuth requirements at runtime
+	// via Protected Resource Metadata and store tokens without OAuth in static config
+	hasStoredTokens := false
+	if m.storage != nil && serverConfig != nil {
+		// IMPORTANT: Use GenerateServerKey to match how PersistentTokenStore stores tokens.
+		// Tokens are stored with key = SHA256(serverName|serverURL)[:16], not just serverName.
+		serverKey := oauth.GenerateServerKey(serverName, serverConfig.URL)
+		token, err := m.storage.GetOAuthToken(serverKey)
+		if err == nil && token != nil && token.RefreshToken != "" {
+			hasStoredTokens = true
+			m.logger.Debug("Found OAuth token in database for dynamic OAuth server",
+				zap.String("server", serverName),
+				zap.String("server_key", serverKey),
+				zap.Bool("has_refresh_token", token.RefreshToken != ""))
+		}
+	}
+
+	if !hasStaticOAuth && !hasStoredTokens {
 		return fmt.Errorf("server does not use OAuth: %s", serverName)
 	}
 
-	// TODO: Implement actual token refresh in Phase 3
-	// For now, force a reconnection which will trigger token refresh if needed
-	client.ForceReconnect("manual_token_refresh")
+	// Force a reconnection which will trigger token refresh via mcp-go's
+	// automatic token refresh when TokenStore provides a refresh token
+	client.ForceReconnect("oauth_token_refresh")
 
 	m.logger.Info("OAuth token refresh requested",
-		zap.String("server", serverName))
+		zap.String("server", serverName),
+		zap.Bool("has_static_oauth", hasStaticOAuth),
+		zap.Bool("has_stored_tokens", hasStoredTokens))
 
 	return nil
 }