diff --git a/esi/cached.go b/esi/cached.go index 4dc5708..ed83c24 100644 --- a/esi/cached.go +++ b/esi/cached.go @@ -50,40 +50,60 @@ 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) + logger.Info("CachedESI.GetCharacterPlanets: Starting 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) + logger.Info("CachedESI.GetCharacterPlanets: Calling direct ESI for character %d planets", characterID) + result, err := c.direct.GetCharacterPlanets(ctx, characterID, accessToken) + if err != nil { + logger.Error("CachedESI.GetCharacterPlanets: Direct ESI call failed for character %d: %v", characterID, err) + return nil, err + } + logger.Info("CachedESI.GetCharacterPlanets: Direct ESI returned %d planets for character %d", len(result), characterID) + return result, nil } result, err := getCachedResponse(c, url, fetchFunc) if err != nil { - logger.Error("CachedESI: Failed to get planets for character %d: %v", characterID, err) + logger.Error("CachedESI.GetCharacterPlanets: 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) + logger.Info("CachedESI.GetCharacterPlanets: 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) + logger.Info("CachedESI.GetPlanetDetails: Starting 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) + logger.Info("CachedESI.GetPlanetDetails: Calling direct ESI for character %d planet %d details", characterID, planetID) + result, err := c.direct.GetPlanetDetails(ctx, characterID, planetID, accessToken) + if err != nil { + logger.Error("CachedESI.GetPlanetDetails: Direct ESI call failed for character %d planet %d: %v", characterID, planetID, err) + return nil, err + } + if result != nil { + logger.Info("CachedESI.GetPlanetDetails: Direct ESI returned planet details with %d pins for character %d planet %d", len(result.Pins), characterID, planetID) + } else { + logger.Info("CachedESI.GetPlanetDetails: Direct ESI returned nil planet details for character %d planet %d", characterID, planetID) + } + return result, nil } 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) + logger.Error("CachedESI.GetPlanetDetails: 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) + if result != nil { + logger.Info("CachedESI.GetPlanetDetails: Successfully retrieved planet details with %d pins for character %d, planet %d", len(result.Pins), characterID, planetID) + } else { + logger.Info("CachedESI.GetPlanetDetails: Successfully retrieved nil planet details for character %d, planet %d", characterID, planetID) + } return result, nil } @@ -154,19 +174,33 @@ func getCachedResponse[T any](c *CachedESI, url string, fetchFunc func() (T, err // GetPlanetName retrieves planet name with caching func (c *CachedESI) GetPlanetName(ctx context.Context, planetID int) (*PlanetName, error) { url := fmt.Sprintf("/v1/universe/planets/%d/", planetID) - logger.Info("CachedESI: Getting planet name for planet %d", planetID) + logger.Info("CachedESI.GetPlanetName: Starting for planet %d", planetID) fetchFunc := func() (*PlanetName, error) { - logger.Debug("CachedESI: Calling direct ESI for planet %d name", planetID) - return c.direct.GetPlanetName(ctx, planetID) + logger.Info("CachedESI.GetPlanetName: Calling direct ESI for planet %d name", planetID) + result, err := c.direct.GetPlanetName(ctx, planetID) + if err != nil { + logger.Error("CachedESI.GetPlanetName: Direct ESI call failed for planet %d: %v", planetID, err) + return nil, err + } + if result != nil { + logger.Info("CachedESI.GetPlanetName: Direct ESI returned planet name '%s' for planet %d", result.Name, planetID) + } else { + logger.Info("CachedESI.GetPlanetName: Direct ESI returned nil planet name for planet %d", planetID) + } + return result, nil } result, err := getCachedResponse(c, url, fetchFunc) if err != nil { - logger.Error("CachedESI: Failed to get planet name for planet %d: %v", planetID, err) + logger.Error("CachedESI.GetPlanetName: Failed to get planet name for planet %d: %v", planetID, err) return nil, err } - logger.Info("CachedESI: Successfully retrieved planet name for planet %d: %s", planetID, result.Name) + if result != nil { + logger.Info("CachedESI.GetPlanetName: Successfully retrieved planet name '%s' for planet %d", result.Name, planetID) + } else { + logger.Info("CachedESI.GetPlanetName: Successfully retrieved nil planet name for planet %d", planetID) + } return result, nil } diff --git a/orchestrator.go b/orchestrator.go index af11732..d1d614a 100644 --- a/orchestrator.go +++ b/orchestrator.go @@ -84,50 +84,62 @@ func (o *Orchestrator) Start() { // refetchAllData fetches data for all characters and checks thresholds func (o *Orchestrator) refetchAllData() { - logger.Info("Starting data refetch for all characters") + logger.Info("Orchestrator.refetchAllData: Starting data refetch for all characters") // Get all characters from database characters, err := o.database.Character().GetAllCharacters() if err != nil { - logger.Error("Failed to get all characters: %v", err) + logger.Error("Orchestrator.refetchAllData: Failed to get all characters: %v", err) return } - logger.Info("Found %d characters to process", len(characters)) + logger.Info("Orchestrator.refetchAllData: Found %d characters to process", len(characters)) + + if len(characters) == 0 { + logger.Info("Orchestrator.refetchAllData: No characters found in database") + return + } // Process each character - for _, char := range characters { + for i, char := range characters { + logger.Info("Orchestrator.refetchAllData: Processing character %d/%d: %s", i+1, len(characters), char.CharacterName) o.processCharacter(char) } - logger.Info("Completed data refetch for all characters") + logger.Info("Orchestrator.refetchAllData: Completed data refetch for all characters") } // processCharacter processes a single character's data func (o *Orchestrator) processCharacter(char types.Character) { - logger.Debug("Processing character: %s", char.CharacterName) + logger.Info("Orchestrator.processCharacter: Starting processing for character: %s (ID: %d)", char.CharacterName, char.ID) // Get extractors for this character + logger.Info("Orchestrator.processCharacter: Getting extractors for character %s", char.CharacterName) extractors, err := routes.GetExtractorsForCharacter(o.esiClient, int(char.ID), char.AccessToken) if err != nil { - logger.Warning("Failed to get extractors for character %s: %v", char.CharacterName, err) + logger.Warning("Orchestrator.processCharacter: Failed to get extractors for character %s: %v", char.CharacterName, err) return } + logger.Info("Orchestrator.processCharacter: Got %d extractors for character %s", len(extractors), char.CharacterName) // Get storage for this character + logger.Info("Orchestrator.processCharacter: Getting storage for character %s", char.CharacterName) storage, err := routes.GetStorageForCharacter(o.esiClient, int(char.ID), char.AccessToken) if err != nil { - logger.Warning("Failed to get storage for character %s: %v", char.CharacterName, err) + logger.Warning("Orchestrator.processCharacter: Failed to get storage for character %s: %v", char.CharacterName, err) return } + logger.Info("Orchestrator.processCharacter: Got %d storage facilities for character %s", len(storage), char.CharacterName) // Check storage thresholds + logger.Info("Orchestrator.processCharacter: Checking storage thresholds for character %s", char.CharacterName) o.checkStorageThresholds(char.CharacterName, storage) // Update expiry timers for extractors + logger.Info("Orchestrator.processCharacter: Updating expiry timers for character %s", char.CharacterName) o.updateExpiryTimers(char.CharacterName, extractors) - logger.Debug("Completed processing character: %s", char.CharacterName) + logger.Info("Orchestrator.processCharacter: Completed processing for character %s", char.CharacterName) } // checkStorageThresholds checks storage utilization against configured thresholds diff --git a/routes/data.go b/routes/data.go index b6547c5..bfcaf3e 100644 --- a/routes/data.go +++ b/routes/data.go @@ -28,41 +28,52 @@ type StorageInfo struct { // GetExtractorsForCharacter retrieves extractor information for a character func GetExtractorsForCharacter(esiClient esi.ESIInterface, characterID int, accessToken string) ([]ExtractorInfo, error) { - logger.Debug("Getting extractors for character ID %d", characterID) + logger.Info("GetExtractorsForCharacter: Starting for character ID %d", characterID) // Get character planets planets, err := esiClient.GetCharacterPlanets(context.Background(), characterID, accessToken) if err != nil { - logger.Error("Failed to get planets for character %d: %v", characterID, err) + logger.Error("GetExtractorsForCharacter: Failed to get planets for character %d: %v", characterID, err) return nil, err } + logger.Info("GetExtractorsForCharacter: Found %d planets for character %d", len(planets), characterID) var extractors []ExtractorInfo - for _, planet := range planets { + for i, planet := range planets { + logger.Info("GetExtractorsForCharacter: Processing planet %d/%d (ID: %d)", i+1, len(planets), planet.PlanetID) + // Get planet details details, err := esiClient.GetPlanetDetails(context.Background(), characterID, planet.PlanetID, accessToken) if err != nil { - logger.Warning("Failed to fetch details for planet %d: %v", planet.PlanetID, err) + logger.Warning("GetExtractorsForCharacter: Failed to fetch details for planet %d: %v", planet.PlanetID, err) continue } + logger.Info("GetExtractorsForCharacter: Got planet details for planet %d with %d pins", planet.PlanetID, len(details.Pins)) if details != nil { // Get planet name from universe endpoint planetNameData, err := esiClient.GetPlanetName(context.Background(), planet.PlanetID) if err != nil { - logger.Error("Failed to get planet name for planet ID %d: %v", planet.PlanetID, err) + logger.Error("GetExtractorsForCharacter: Failed to get planet name for planet ID %d: %v", planet.PlanetID, err) continue } + logger.Info("GetExtractorsForCharacter: Planet %d name: %s", planet.PlanetID, planetNameData.Name) // Count extractors and get expiry dates extractorCount := 0 - for _, pin := range details.Pins { + for j, pin := range details.Pins { + logger.Info("GetExtractorsForCharacter: Processing pin %d/%d (TypeID: %d) on planet %s", j+1, len(details.Pins), pin.TypeID, planetNameData.Name) + if pin.ExtractorDetails != nil { + logger.Info("GetExtractorsForCharacter: Found extractor (TypeID: %d) on planet %s", pin.TypeID, planetNameData.Name) extractorCount++ expiryDate := "N/A" if pin.ExpiryTime != nil { expiryDate = *pin.ExpiryTime + logger.Info("GetExtractorsForCharacter: Extractor expiry: %s", expiryDate) + } else { + logger.Info("GetExtractorsForCharacter: Extractor has no expiry time") } extractors = append(extractors, ExtractorInfo{ @@ -70,80 +81,105 @@ func GetExtractorsForCharacter(esiClient esi.ESIInterface, characterID int, acce ExtractorNumber: extractorCount, ExpiryDate: expiryDate, }) + logger.Info("GetExtractorsForCharacter: Added extractor %d to results", extractorCount) + } else { + logger.Info("GetExtractorsForCharacter: Pin %d is not an extractor (TypeID: %d)", j+1, pin.TypeID) } } + logger.Info("GetExtractorsForCharacter: Found %d extractors on planet %s", extractorCount, planetNameData.Name) } } + logger.Info("GetExtractorsForCharacter: Returning %d total extractors for character %d", len(extractors), characterID) return extractors, nil } // GetStorageForCharacter retrieves storage information for a character func GetStorageForCharacter(esiClient esi.ESIInterface, characterID int, accessToken string) ([]StorageInfo, error) { - logger.Debug("Getting storage for character ID %d", characterID) + logger.Info("GetStorageForCharacter: Starting for character ID %d", characterID) // Get character planets planets, err := esiClient.GetCharacterPlanets(context.Background(), characterID, accessToken) if err != nil { - logger.Error("Failed to get planets for character %d: %v", characterID, err) + logger.Error("GetStorageForCharacter: Failed to get planets for character %d: %v", characterID, err) return nil, err } + logger.Info("GetStorageForCharacter: Found %d planets for character %d", len(planets), characterID) var storage []StorageInfo - for _, planet := range planets { + for i, planet := range planets { + logger.Info("GetStorageForCharacter: Processing planet %d/%d (ID: %d)", i+1, len(planets), planet.PlanetID) + // Get planet details details, err := esiClient.GetPlanetDetails(context.Background(), characterID, planet.PlanetID, accessToken) if err != nil { - logger.Warning("Failed to fetch details for planet %d: %v", planet.PlanetID, err) + logger.Warning("GetStorageForCharacter: Failed to fetch details for planet %d: %v", planet.PlanetID, err) continue } + logger.Info("GetStorageForCharacter: Got planet details for planet %d with %d pins", planet.PlanetID, len(details.Pins)) if details != nil { // Get planet name from universe endpoint planetNameData, err := esiClient.GetPlanetName(context.Background(), planet.PlanetID) if err != nil { - logger.Error("Failed to get planet name for planet ID %d: %v", planet.PlanetID, err) + logger.Error("GetStorageForCharacter: Failed to get planet name for planet ID %d: %v", planet.PlanetID, err) continue } + logger.Info("GetStorageForCharacter: Planet %d name: %s", planet.PlanetID, planetNameData.Name) // Analyze storage utilization - for _, pin := range details.Pins { + storageCount := 0 + for j, pin := range details.Pins { + logger.Info("GetStorageForCharacter: Processing pin %d/%d (TypeID: %d) on planet %s", j+1, len(details.Pins), pin.TypeID, planetNameData.Name) + // Check if this pin is actually a storage facility _, isStorage := constants.StorageCapacities[pin.TypeID] if !isStorage { - // Skip non-storage facilities (like industry facilities) + logger.Info("GetStorageForCharacter: Pin %d is not a storage facility (TypeID: %d), skipping", j+1, pin.TypeID) continue } - - totalVolume := 0.0 - for _, content := range pin.Contents { - volume, exists := constants.PIProductVolumes[content.TypeID] - if !exists { - logger.Error("Missing product volume data for type ID %d - cannot calculate storage utilization", content.TypeID) - return nil, fmt.Errorf("missing product volume data for type ID %d", content.TypeID) - } - totalVolume += float64(content.Amount) * volume - } + logger.Info("GetStorageForCharacter: Pin %d is a storage facility (TypeID: %d)", j+1, pin.TypeID) storageType, exists := constants.PI_TYPES_MAP[pin.TypeID] if !exists { - logger.Error("Unknown storage type ID %d for planet %s - this should not happen", pin.TypeID, planetNameData.Name) + logger.Error("GetStorageForCharacter: Unknown storage type ID %d for planet %s - this should not happen", pin.TypeID, planetNameData.Name) return nil, fmt.Errorf("unknown storage type ID %d", pin.TypeID) } + logger.Info("GetStorageForCharacter: Storage type: %s", storageType) + + totalVolume := 0.0 + logger.Info("GetStorageForCharacter: Processing %d contents for storage facility %s", len(pin.Contents), storageType) + for k, content := range pin.Contents { + logger.Info("GetStorageForCharacter: Processing content %d/%d (TypeID: %d, Amount: %d)", k+1, len(pin.Contents), content.TypeID, content.Amount) + + volume, exists := constants.PIProductVolumes[content.TypeID] + if !exists { + logger.Error("GetStorageForCharacter: Missing product volume data for type ID %d - cannot calculate storage utilization", content.TypeID) + return nil, fmt.Errorf("missing product volume data for type ID %d", content.TypeID) + } + itemVolume := float64(content.Amount) * volume + totalVolume += itemVolume + logger.Info("GetStorageForCharacter: Content TypeID %d: Amount %d, Volume %f, ItemVolume %f", content.TypeID, content.Amount, volume, itemVolume) + } storageCapacity := constants.StorageCapacities[pin.TypeID] utilization := (totalVolume / float64(storageCapacity)) * 100.0 + logger.Info("GetStorageForCharacter: Storage calculation: %s on %s - TotalVolume: %f, Capacity: %d, Utilization: %f%%", storageType, planetNameData.Name, totalVolume, storageCapacity, utilization) storage = append(storage, StorageInfo{ PlanetName: planetNameData.Name, StorageType: storageType, Utilization: utilization, }) + storageCount++ + logger.Info("GetStorageForCharacter: Added storage facility %d to results", storageCount) } + logger.Info("GetStorageForCharacter: Found %d storage facilities on planet %s", storageCount, planetNameData.Name) } } + logger.Info("GetStorageForCharacter: Returning %d total storage facilities for character %d", len(storage), characterID) return storage, nil }