Add logs to cache

esi/cached.go

@@ -39,6 +39,7 @@ func NewCachedESI(direct ESIInterface, db interface {
 		os.Exit(1)
 	}
 
+	logger.Info("Initializing CachedESI with cache validity: %v", cacheValidity)
 	return &CachedESI{
 		direct:        direct,
 		db:            db,
@@ -49,22 +50,41 @@ func NewCachedESI(direct ESIInterface, db interface {
 // GetCharacterPlanets retrieves a list of planets for a character with caching
 func (c *CachedESI) GetCharacterPlanets(ctx context.Context, characterID int, accessToken string) ([]Planet, error) {
 	url := fmt.Sprintf("/v1/characters/%d/planets/", characterID)
+	logger.Info("CachedESI: Getting planets for character %d", characterID)
 
 	fetchFunc := func() ([]Planet, error) {
+		logger.Debug("CachedESI: Calling direct ESI for character %d planets", characterID)
 		return c.direct.GetCharacterPlanets(ctx, characterID, accessToken)
 	}
 
-	return getCachedResponse(c, url, fetchFunc)
+	result, err := getCachedResponse(c, url, fetchFunc)
+	if err != nil {
+		logger.Error("CachedESI: Failed to get planets for character %d: %v", characterID, err)
+		return nil, err
+	}
+
+	logger.Info("CachedESI: Successfully retrieved %d planets for character %d", len(result), characterID)
+	return result, nil
 }
 
 // GetPlanetDetails retrieves detailed information about a specific planet with caching
 func (c *CachedESI) GetPlanetDetails(ctx context.Context, characterID, planetID int, accessToken string) (*PlanetDetail, error) {
 	url := fmt.Sprintf("/v3/characters/%d/planets/%d/", characterID, planetID)
+	logger.Info("CachedESI: Getting planet details for character %d, planet %d", characterID, planetID)
+
 	fetchFunc := func() (*PlanetDetail, error) {
+		logger.Debug("CachedESI: Calling direct ESI for character %d planet %d details", characterID, planetID)
 		return c.direct.GetPlanetDetails(ctx, characterID, planetID, accessToken)
 	}
 
-	return getCachedResponse(c, url, fetchFunc)
+	result, err := getCachedResponse(c, url, fetchFunc)
+	if err != nil {
+		logger.Error("CachedESI: Failed to get planet details for character %d, planet %d: %v", characterID, planetID, err)
+		return nil, err
+	}
+
+	logger.Info("CachedESI: Successfully retrieved planet details for character %d, planet %d", characterID, planetID)
+	return result, nil
 }
 
 // getCachedResponse handles caching logic with generics
@@ -72,35 +92,48 @@ func getCachedResponse[T any](c *CachedESI, url string, fetchFunc func() (T, err
 	// Generate cache key
 	hash := sha256.Sum256([]byte(url))
 	urlHash := hex.EncodeToString(hash[:])
+	logger.Debug("CachedESI: Generated cache key %s for URL: %s", urlHash[:8], url)
 
 	// Check cache using the interface
+	logger.Debug("CachedESI: Checking cache for URL: %s", url)
 	cacheEntry, err := c.db.GetCacheEntry(urlHash)
 	if err == nil {
 		// Check if cache is still valid
-		if time.Since(cacheEntry.CachedAt) < c.cacheValidity {
+		age := time.Since(cacheEntry.CachedAt)
-			logger.Debug("Cache hit for URL: %s", url)
+		if age < c.cacheValidity {
+			logger.Info("Cache HIT for URL: %s (cached %v ago, valid for %v more)", url, age, c.cacheValidity-age)
 			// Parse cached response
 			var result T
 			if err := json.Unmarshal([]byte(cacheEntry.Response), &result); err == nil {
+				logger.Debug("CachedESI: Successfully unmarshaled cached response for URL: %s", url)
 				return result, nil
 			}
+			logger.Warning("Failed to unmarshal cached response for URL: %s: %v", url, err)
+		} else {
+			logger.Info("Cache EXPIRED for URL: %s (cached %v ago, validity: %v)", url, age, c.cacheValidity)
 		}
+	} else {
+		logger.Info("Cache MISS for URL: %s (no cache entry found): %v", url, err)
 	}
 
 	// Cache miss or invalid, fetch from API
-	logger.Debug("Cache miss for URL: %s", url)
+	logger.Info("Fetching from API for URL: %s", url)
 	result, err := fetchFunc()
 	if err != nil {
+		logger.Error("CachedESI: API fetch failed for URL: %s: %v", url, err)
 		var zero T
 		return zero, err
 	}
+	logger.Debug("CachedESI: API fetch successful for URL: %s", url)
 
 	// Store in cache
+	logger.Debug("CachedESI: Marshaling response for caching URL: %s", url)
 	responseBytes, err := json.Marshal(result)
 	if err != nil {
-		logger.Warning("Failed to marshal response for caching: %v", err)
+		logger.Warning("Failed to marshal response for caching URL: %s: %v", url, err)
 		return result, nil
 	}
+	logger.Debug("CachedESI: Response marshaled successfully for URL: %s (%d bytes)", url, len(responseBytes))
 
 	cacheEntry = &types.CacheEntry{
 		URLHash:  urlHash,
@@ -108,10 +141,12 @@ func getCachedResponse[T any](c *CachedESI, url string, fetchFunc func() (T, err
 		CachedAt: time.Now(),
 	}
 
+	logger.Debug("CachedESI: Saving cache entry for URL: %s", url)
 	if err := c.db.SaveCacheEntry(cacheEntry); err != nil {
-		logger.Warning("Failed to cache response: %v", err)
+		logger.Warning("Failed to cache response for URL: %s: %v", url, err)
+	} else {
+		logger.Info("Cached response for URL: %s (valid for %v, %d bytes)", url, c.cacheValidity, len(responseBytes))
 	}
 
-	logger.Debug("Cached response for URL: %s", url)
 	return result, nil
 }