Add detailed logging for wave downloader

gefs_wave.py

@@ -1,4 +1,5 @@
 import json
+import logging
 import re
 import tarfile
 import threading
@@ -15,6 +16,14 @@ FORECAST_HOURS: List[int] = list(range(0, 387, 3))
 STATE_FILENAME = "state.json"
 TARBALL_FILENAME = "gefswave-wave0-latest.tar.gz"
 
+logger = logging.getLogger("gefs_wave")
+if not logger.handlers:
+    handler = logging.StreamHandler()
+    handler.setFormatter(logging.Formatter("%(asctime)s %(levelname)s %(message)s"))
+    logger.addHandler(handler)
+logger.setLevel(logging.INFO)
+logger.propagate = False
+
 
 @dataclass
 class Cycle:
@@ -44,16 +53,21 @@ class WaveDownloader:
 
     def ensure_latest_cycle(self) -> Dict:
         """Ensure the latest available control-member dataset is present locally."""
+        logger.info("Ensuring latest GEFS wave control-member cycle for %s", self.data_root)
         cycle = self._find_latest_cycle()
         if not cycle:
+            logger.error("No GEFS wave cycle found in the recent window.")
             raise WaveDownloadError("Could not locate a recent GEFS wave cycle.")
 
         state = self._read_state()
         if state and state.get("cycle") == cycle.label and self._cycle_complete(cycle):
+            logger.info("Cycle %s already cached; using existing files.", cycle.label)
             return state
 
+        logger.info("Downloading cycle %s", cycle.label)
         files = self._download_cycle(cycle)
         tarball_path = self._build_tarball(cycle, files)
+        logger.info("Packaged cycle %s into tarball %s", cycle.label, tarball_path.name)
         state = {
             "cycle": cycle.label,
             "files": [str(path.relative_to(self.data_root)) for path in files],
@@ -73,8 +87,11 @@ class WaveDownloader:
 
         for day in candidate_days:
             for cycle in cycles:
+                logger.info("Probing cycle %s %sz", day, cycle)
                 if self._cycle_available(day, cycle):
+                    logger.info("Cycle %s %sz is available.", day, cycle)
                     return Cycle(date=day, cycle=cycle)
+        logger.warning("No GEFS wave cycle found in the last %d days.", max_days_back)
         return None
 
     def _cycle_available(self, day: str, cycle: str) -> bool:
@@ -82,10 +99,12 @@ class WaveDownloader:
         try:
             response = self.session.get(url, timeout=20)
             if not response.ok:
+                logger.debug("Cycle %s %sz check failed with HTTP %s.", day, cycle, response.status_code)
                 return False
             pattern = re.compile(rf"gefswave\.t{cycle}z\.c00\.global\.0p25\.f000\.grib2")
             return bool(pattern.search(response.text))
-        except requests.RequestException:
+        except requests.RequestException as exc:
+            logger.debug("Error probing cycle %s %sz: %s", day, cycle, exc)
             return False
 
     def _download_cycle(self, cycle: Cycle) -> List[Path]:
@@ -98,8 +117,10 @@ class WaveDownloader:
             url = f"{BASE_URL}/{cycle.directory}/wave/gridded/{filename}"
             destination = target_dir / filename
             if destination.exists() and destination.stat().st_size > 0:
+                logger.debug("File %s already exists; skipping download.", destination)
                 files.append(destination)
                 continue
+            logger.info("Downloading %s", filename)
             self._stream_to_file(url, destination)
             files.append(destination)
         return files
@@ -125,6 +146,7 @@ class WaveDownloader:
         except requests.RequestException as exc:
             if tmp_path.exists():
                 tmp_path.unlink()
+            logger.error("Failed to download %s: %s", url, exc)
             raise WaveDownloadError(f"Failed to download {url}: {exc}") from exc
 
     def _cycle_complete(self, cycle: Cycle) -> bool:
@@ -161,7 +183,9 @@ class WaveDownloadManager:
     def trigger_refresh(self) -> None:
         with self._lock:
             if self._worker and self._worker.is_alive():
+                logger.info("Refresh already in progress; ignoring new trigger.")
                 return
+            logger.info("Starting GEFS wave refresh thread.")
             self._status = {"status": "running"}
             self._worker = threading.Thread(target=self._run_refresh, daemon=True)
             self._worker.start()
@@ -179,6 +203,8 @@ class WaveDownloadManager:
             result = self.downloader.ensure_latest_cycle()
             with self._lock:
                 self._status = {"status": "ready", "latest_state": result}
+            logger.info("GEFS wave refresh completed successfully.")
         except Exception as exc:
             with self._lock:
                 self._status = {"status": "error", "message": str(exc)}
+            logger.exception("GEFS wave refresh failed: %s", exc)