Fix/odds ticker manager log spam (#65)

* fix(odds-ticker): Reduce log spam from insufficient time warnings

- Add _insufficient_time_warning_logged flag to prevent repeated warnings
- Log insufficient time warning only once per display session
- Reset warning flag when starting new display or updating data
- Maintain debug logging for scroll position resets to aid debugging

This addresses the frequent 'Not enough time to complete content display'
warnings that were flooding the logs every few milliseconds.

* fix(leaderboard): Reduce log spam from progress and FPS logging

- Change progress logging from every 50 pixels to every 5 seconds
- Increase FPS logging interval from 10 seconds to 30 seconds
- Add progress_log_interval and last_progress_log_time variables
- Reset progress log timer when starting new display sessions or updating data
- Maintain debug capability while significantly reducing log volume

This addresses the frequent 'Leaderboard progress' and 'Leaderboard FPS'
messages that were flooding the logs during leaderboard scrolling.

* fix(music): Reduce log spam from track update logging

- Add throttling mechanism for track update logging
- Log track updates only when track title changes or after 5 seconds
- Track last_logged_track_title and last_track_log_time to prevent spam
- Maintain debug logging for throttled updates
- Apply throttling to both regular updates and first valid data logging

This addresses the frequent 'Track info updated' messages that were
flooding the logs every few hundred milliseconds for the same track.

* fix(logo-downloader): Fix TA&M filename normalization issue

- Add special case for TA&M to keep as TA&M instead of converting to TAANDM
- This fixes the issue where code was looking for TAANDM.png instead of TA&M.png
- The actual logo file exists as TA&M.png, so normalization was causing file not found errors
- Prevents unnecessary download attempts and permission errors for existing files

Fixes the error: 'Logo not found for TA&M at assets/sports/ncaa_logos/TAANDM.png'

* fix(logo-downloader): Implement robust filename variation handling

- Add get_logo_filename_variations() method to handle multiple filename formats
- Update _load_and_resize_logo() to try filename variations before downloading
- Handles cases like TA&M.png vs TAANDM.png gracefully
- Maintains backward compatibility with existing normalized filenames
- Prevents issues with special characters in filenames while supporting existing files

This addresses the ampersand filename issue more robustly by:
1. First trying the original filename (TA&M.png)
2. Falling back to normalized filename (TAANDM.png) if needed
3. Only attempting downloads if no variations exist

* fix(leaderboard): Reduce log spam from end reached messages

- Add _end_reached_logged flag to prevent repeated end reached warnings
- Log 'Leaderboard reached end' and 'scrolling stopped' messages only once per display session
- Maintain debug logging for throttled messages to aid debugging
- Reset flag when starting new display sessions or updating data
- Apply same throttling pattern used in odds ticker manager

This addresses the frequent 'Leaderboard reached end' and 'scrolling stopped'
messages that were flooding the logs every few milliseconds when at the end.

src/base_classes/sports.py

@@ -249,18 +249,34 @@ class SportsCore:
         self.logger.debug(f"Logo path: {logo_path}")
 
         try:
-            # Try to download missing logo first
-            if not logo_path.exists():
+            # Try different filename variations first (for cases like TA&M vs TAANDM)
+            actual_logo_path = None
+            filename_variations = LogoDownloader.get_logo_filename_variations(team_abbrev)
+            
+            for filename in filename_variations:
+                test_path = logo_path.parent / filename
+                if test_path.exists():
+                    actual_logo_path = test_path
+                    self.logger.debug(f"Found logo at alternative path: {actual_logo_path}")
+                    break
+            
+            # If no variation found, try to download missing logo
+            if not actual_logo_path and not logo_path.exists():
                 self.logger.info(f"Logo not found for {team_abbrev} at {logo_path}. Attempting to download.")
                 
                 # Try to download the logo from ESPN API (this will create placeholder if download fails)
                 download_missing_logo(self.sport_key, team_id, team_abbrev, logo_path, logo_url)
+                actual_logo_path = logo_path
+
+            # Use the original path if no alternative was found
+            if not actual_logo_path:
+                actual_logo_path = logo_path
 
             # Only try to open the logo if the file exists
-            if os.path.exists(logo_path):
-                logo = Image.open(logo_path)
+            if os.path.exists(actual_logo_path):
+                logo = Image.open(actual_logo_path)
             else:
-                self.logger.error(f"Logo file still doesn't exist at {logo_path} after download attempt")
+                self.logger.error(f"Logo file still doesn't exist at {actual_logo_path} after download attempt")
                 return None
             if logo.mode != 'RGBA':
                 logo = logo.convert('RGBA')

src/leaderboard_manager.py

@@ -56,9 +56,16 @@ class LeaderboardManager:
         # FPS tracking variables
         self.frame_times = []  # Store last 30 frame times for averaging
         self.last_frame_time = 0
-        self.fps_log_interval = 10.0  # Log FPS every 10 seconds
+        self.fps_log_interval = 30.0  # Log FPS every 30 seconds (increased from 10s)
         self.last_fps_log_time = 0
         
+        # Progress logging throttling
+        self.progress_log_interval = 5.0  # Log progress every 5 seconds instead of every 50 pixels
+        self.last_progress_log_time = 0
+        
+        # End reached logging throttling
+        self._end_reached_logged = False
+        
         # Initialize managers
         self.cache_manager = CacheManager()
         # Store reference to config instead of creating new ConfigManager
@@ -1259,6 +1266,10 @@ class LeaderboardManager:
         try:
             self.leaderboard_data = self._fetch_all_standings()
             self.last_update = current_time
+            # Reset progress logging timer when updating data
+            self.last_progress_log_time = 0
+            # Reset end reached logging flag when updating data
+            self._end_reached_logged = False
             
             if self.leaderboard_data:
                 self._create_leaderboard_image()
@@ -1313,6 +1324,10 @@ class LeaderboardManager:
             logger.debug(f"Reset/initialized display start time: {self._display_start_time}")
             # Also reset scroll position for clean start
             self.scroll_position = 0
+            # Reset progress logging timer
+            self.last_progress_log_time = 0
+            # Reset end reached logging flag
+            self._end_reached_logged = False
         else:
             # Check if the display start time is too old (more than 2x the dynamic duration)
             current_time = time.time()
@@ -1321,6 +1336,10 @@ class LeaderboardManager:
                 logger.debug(f"Display start time is too old ({elapsed_time:.1f}s), resetting")
                 self._display_start_time = current_time
                 self.scroll_position = 0
+                # Reset progress logging timer
+                self.last_progress_log_time = 0
+                # Reset end reached logging flag
+                self._end_reached_logged = False
         
         logger.debug(f"Number of leagues in data at start of display method: {len(self.leaderboard_data)}")
         if not self.leaderboard_data:
@@ -1382,11 +1401,17 @@ class LeaderboardManager:
             else:
                 # Stop scrolling when we reach the end
                 if self.scroll_position >= self.leaderboard_image.width - width:
+                    # Only log this message once per display session to avoid spam
+                    if not self._end_reached_logged:
                         logger.info(f"Leaderboard reached end: scroll_position {self.scroll_position} >= {self.leaderboard_image.width - width}")
+                        logger.info("Leaderboard scrolling stopped - reached end of content")
+                        self._end_reached_logged = True
+                    else:
+                        logger.debug(f"Leaderboard reached end (throttled): scroll_position {self.scroll_position} >= {self.leaderboard_image.width - width}")
+                    
                     self.scroll_position = self.leaderboard_image.width - width
                     # Signal that scrolling has stopped
                     self.display_manager.set_scrolling_state(False)
-                    logger.info("Leaderboard scrolling stopped - reached end of content")
                     if self.time_over == 0:
                         self.time_over = time.time()
                     elif time.time() - self.time_over >= 2:
@@ -1397,9 +1422,10 @@ class LeaderboardManager:
             elapsed_time = current_time - self._display_start_time
             remaining_time = self.dynamic_duration - elapsed_time
             
-            # Log scroll progress every 50 pixels to help debug (less verbose)
-            if self.scroll_position % 50 == 0 and self.scroll_position > 0:
+            # Log scroll progress every 5 seconds to help debug (throttled to reduce spam)
+            if current_time - self.last_progress_log_time >= self.progress_log_interval and self.scroll_position > 0:
                 logger.info(f"Leaderboard progress: elapsed={elapsed_time:.1f}s, remaining={remaining_time:.1f}s, scroll_pos={self.scroll_position}/{self.leaderboard_image.width}px")
+                self.last_progress_log_time = current_time
             
             # If we have less than 2 seconds remaining, check if we can complete the content display
             if remaining_time < 2.0 and self.scroll_position > 0:

src/logo_downloader.py

@@ -101,6 +101,7 @@ class LogoDownloader:
         """Normalize team abbreviation for consistent filename usage."""
         # Handle special characters that can cause filesystem issues
         normalized = abbreviation.upper()
+        
         # Replace problematic characters with safe alternatives
         normalized = normalized.replace('&', 'AND')
         normalized = normalized.replace('/', '_')
@@ -114,6 +115,23 @@ class LogoDownloader:
         normalized = normalized.replace('|', '_')
         return normalized
     
+    @staticmethod
+    def get_logo_filename_variations(abbreviation: str) -> list:
+        """Get possible filename variations for a team abbreviation."""
+        variations = []
+        original = abbreviation.upper()
+        normalized = LogoDownloader.normalize_abbreviation(abbreviation)
+        
+        # Add original and normalized versions
+        variations.extend([f"{original}.png", f"{normalized}.png"])
+        
+        # Special handling for known cases
+        if original == 'TA&M':
+            # TA&M has a file named TA&M.png, but normalize creates TAANDM.png
+            variations = [f"{original}.png", f"{normalized}.png"]
+        
+        return variations
+    
     def get_logo_directory(self, league: str) -> str:
         """Get the logo directory for a given league."""
         return self.LOGO_DIRECTORIES.get(league, f'assets/sports/{league}_logos')

src/music_manager.py

@@ -56,6 +56,11 @@ class MusicManager:
         self.scroll_position_artist = 0
         self.scroll_position_album = 0
         self.title_scroll_tick = 0
+        
+        # Track update logging throttling
+        self.last_track_log_time = 0
+        self.last_logged_track_title = None
+        self.track_log_interval = 5.0  # Log track updates every 5 seconds max
         self.artist_scroll_tick = 0
         self.album_scroll_tick = 0
         self.is_music_display_active = False # New state variable
@@ -212,7 +217,22 @@ class MusicManager:
                     self.album_art_image = None
 
                 display_title = self.current_track_info.get('title', 'None')
+                
+                # Throttle track update logging to reduce spam
+                current_time = time.time()
+                should_log = False
+                
+                # Log if track title changed or if enough time has passed
+                if (display_title != self.last_logged_track_title or 
+                    current_time - self.last_track_log_time >= self.track_log_interval):
+                    should_log = True
+                    self.last_track_log_time = current_time
+                    self.last_logged_track_title = display_title
+                
+                if should_log:
                     logger.info(f"({source_description}) Track info updated. Source: {self.current_source.name}. New Track: {display_title}")
+                else:
+                    logger.debug(f"({source_description}) Track info updated (throttled). Source: {self.current_source.name}. Track: {display_title}")
             else:
                 # simplified_info IS THE SAME as self.current_track_info
                 processed_a_meaningful_update = False
@@ -223,7 +243,14 @@ class MusicManager:
                     significant_change_detected = True # First load is always significant
                     processed_a_meaningful_update = True
                     self.current_track_info = simplified_info
-                    logger.info(f"({source_description}) First valid track data received (was None), marking significant.")
+                    # Also log first valid track data with throttling
+                    display_title = simplified_info.get('title', 'None')
+                    current_time = time.time()
+                    
+                    # For first valid data, always log but update throttling variables
+                    logger.info(f"({source_description}) First valid track data received (was None), marking significant. Track: {display_title}")
+                    self.last_track_log_time = current_time
+                    self.last_logged_track_title = display_title
 
         # Queueing logic - for events or activate_display syncs, not for polling.
         # Polling updates current_track_info directly; display() picks it up.

src/odds_ticker_manager.py

@@ -135,6 +135,7 @@ class OddsTickerManager:
         self.ticker_image = None # This will hold the single, wide image
         self.last_display_time = 0
         self._end_reached_logged = False  # Track if we've already logged reaching the end
+        self._insufficient_time_warning_logged = False  # Track if we've already logged insufficient time warning
         
         # Font setup
         self.fonts = self._load_fonts()
@@ -1708,6 +1709,9 @@ class OddsTickerManager:
             self.last_update = current_time
             self.scroll_position = 0
             self.current_game_index = 0
+            # Reset logging flags when updating data
+            self._end_reached_logged = False
+            self._insufficient_time_warning_logged = False
             self._create_ticker_image() # Create the composite image
             
             if self.games_data:
@@ -1740,6 +1744,8 @@ class OddsTickerManager:
             self.scroll_position = 0
             # Reset the end reached logging flag
             self._end_reached_logged = False
+            # Reset the insufficient time warning logging flag
+            self._insufficient_time_warning_logged = False
         else:
             # Check if the display start time is too old (more than 2x the dynamic duration)
             current_time = time.time()
@@ -1750,6 +1756,8 @@ class OddsTickerManager:
                 self.scroll_position = 0
                 # Reset the end reached logging flag
                 self._end_reached_logged = False
+                # Reset the insufficient time warning logging flag
+                self._insufficient_time_warning_logged = False
         
         logger.debug(f"Number of games in data at start of display method: {len(self.games_data)}")
         if not self.games_data:
@@ -1892,8 +1900,13 @@ class OddsTickerManager:
                     logger.debug(f"Sufficient time remaining ({remaining_time:.1f}s) to complete scroll ({time_to_complete:.1f}s)")
                 else:
                     # Not enough time, reset to beginning for clean transition
+                    # Only log this warning once per display session to avoid spam
+                    if not self._insufficient_time_warning_logged:
                         logger.warning(f"Not enough time to complete content display - remaining: {remaining_time:.1f}s, needed: {time_to_complete:.1f}s")
                         logger.debug(f"Resetting scroll position for clean transition")
+                        self._insufficient_time_warning_logged = True
+                    else:
+                        logger.debug(f"Resetting scroll position for clean transition (insufficient time warning already logged)")
                     self.scroll_position = 0
             
             # Create the visible part of the image by pasting from the ticker_image