Add detailed logging and live status updates; instrument NOMADS discovery, open_dataset, indexing, fetch timings. Stream status to UI and console.

app.py

@@ -1,5 +1,7 @@
 import os
 import re
+import time
+import logging
 from datetime import timezone
 
 import gradio as gr
@@ -16,44 +18,48 @@ INTRO = (
 
 
 def run_forecast(lat, lon, hours=24):
+    """Generator to provide live status updates to the UI and console logs."""
+    logging.basicConfig(level=logging.INFO)
+    t0 = time.perf_counter()
+
+    def y(msg, df=None):
+        print(msg, flush=True)
+        return gr.update(value=msg), df
+
     if lat is None or lon is None:
-        return gr.update(value="Click map or enter lat/lon."), None
+        yield y("Click map or enter lat/lon.")
+        return
+
+    try:
+        lat = float(lat)
+        lon = float(lon)
+    except Exception:
+        yield y("Invalid lat/lon.")
+        return
 
-    lat = float(lat)
-    lon = float(lon)
+    yield y(f"Starting forecast for lat={lat:.5f}, lon={lon:.5f}; hours={hours}")
 
     try:
+        yield y("Discovering latest NBM hourly dataset on NOMADS ...")
         dataset_url = get_latest_hourly_dataset_url()
+        yield y(f"Dataset selected: {dataset_url}")
     except Exception as e:
-        return (
-            gr.update(
-                value=(
-                    f"Failed to locate latest NBM dataset: {e}\n"
-                    "Try again in a few minutes."
-                )
-            ),
-            None,
-        )
+        yield y(f"Failed to locate latest NBM dataset: {e}")
+        return
 
     try:
+        yield y("Opening dataset and indexing nearest grid point ...")
         df, meta = fetch_point_forecast_df(dataset_url, lat, lon, hours=hours)
     except Exception as e:
-        return (
-            gr.update(
-                value=(
-                    f"Error fetching forecast at {lat:.3f}, {lon:.3f}: {e}\n"
-                    f"Dataset: {dataset_url}"
-                )
-            ),
-            None,
-        )
+        yield y(f"Error fetching forecast at {lat:.3f}, {lon:.3f}: {e}\nDataset: {dataset_url}")
+        return
 
     header = (
         f"NBM hourly forecast (next {len(df)} hrs) at "
         f"{meta['lat']:.3f}, {meta['lon']:.3f} (grid: lat[{meta['ilat']}], lon[{meta['ilon']}])\n"
-        f"Dataset: {dataset_url}"
+        f"Dataset: {dataset_url} | total time {time.perf_counter()-t0:.1f}s"
     )
-    return header, df
+    yield y(header, df)
 
 
 with gr.Blocks(title="NBM Point Forecast (NOAA NOMADS)") as demo:

nbm_client.py

@@ -1,4 +1,6 @@
 import re
+import time
+import logging
 from dataclasses import dataclass
 from typing import Dict, List, Tuple
 
@@ -16,6 +18,7 @@ class NBMError(Exception):
 
 
 def _http_get(url: str, timeout: float = 10.0) -> str:
+    logging.info(f"HTTP GET {url}")
     r = requests.get(url, timeout=timeout)
     r.raise_for_status()
     return r.text
@@ -28,6 +31,8 @@ def get_latest_hourly_dataset_url(base_root: str = BASE_ROOT) -> str:
     Returns an OPeNDAP dataset base URL like:
     https://nomads.ncep.noaa.gov/dods/blend/blendYYYYMMDD/blend_1hr_HHz
     """
+    logging.info("Discovering latest NBM hourly dataset ...")
+    t0 = time.perf_counter()
     root_html = _http_get(base_root)
 
     # Find available day directories like 'blend20251004'
@@ -38,8 +43,10 @@ def get_latest_hourly_dataset_url(base_root: str = BASE_ROOT) -> str:
     # Deduplicate and sort descending to prefer newest
     unique_days = sorted(set(days), reverse=True)
 
+    logging.info(f"Found day directories: {unique_days[:3]} ... (total {len(unique_days)})")
     for day in unique_days:
         day_url = f"{base_root}blend{day}/"
+        logging.info(f"Scanning day {day} at {day_url}")
         html = _http_get(day_url)
         # Find datasets named 'blend_1hr_XXz'
         hours = re.findall(r"blend_1hr_(\d{2})z", html)
@@ -47,11 +54,13 @@ def get_latest_hourly_dataset_url(base_root: str = BASE_ROOT) -> str:
             continue
         # pick the highest hour suffix present
         hour_ints = sorted({int(h) for h in hours}, reverse=True)
+        logging.info(f"Available hours for {day}: {hour_ints}")
         for hh in hour_ints:
             ds_url = f"{base_root}blend{day}/blend_1hr_{hh:02d}z"
             # Lightweight existence check by fetching the DDS header
             try:
                 _ = _http_get(ds_url + ".dds")
+                logging.info(f"Selected dataset: {ds_url} (discovered in {time.perf_counter()-t0:.2f}s)")
                 return ds_url
             except Exception:
                 continue
@@ -111,8 +120,12 @@ def fetch_point_forecast_df(
     Returns (DataFrame, meta_dict)
     DataFrame columns: time_utc, temp_F, dewpoint_F, wind_mph, gust_mph, cloud_cover_pct, precip_in
     """
+    logger = logging.getLogger(__name__)
+    logger.info(f"Opening dataset via pydap: {dataset_url}")
+    t_open = time.perf_counter()
     # Open via pydap engine to avoid compiled netcdf dependencies on Spaces
     ds = xr.open_dataset(dataset_url, engine="pydap", decode_cf=True)
+    logger.info(f"Dataset opened in {time.perf_counter()-t_open:.2f}s; variables: {list(ds.variables)[:8]} ...")
 
     # Ensure required variables exist; if not, raise a clear error
     needed = ["tmp2m", "dpt2m", "wind10m", "gust10m", "tcdcsfc", "apcpsfc"]
@@ -123,17 +136,22 @@ def fetch_point_forecast_df(
     # Fetch coordinate arrays locally to compute nearest grid index
     lat_vals = ds["lat"].values  # 1D
     lon_vals = ds["lon"].values  # 1D
+    logger.info(f"Coords loaded. Lat size={lat_vals.size}, Lon size={lon_vals.size}")
 
     ilat = _nearest_index(lat_vals, lat)
     ilon = _nearest_index(lon_vals, lon)
 
     # Extract a small subset across time at single gridpoint
+    logger.info(f"Nearest gridpoint indices: ilat={ilat}, ilon={ilon}; lat={lat_vals[ilat]:.5f}, lon={lon_vals[ilon]:.5f}")
     subset = ds[needed].isel(lat=ilat, lon=ilon)
 
     # Determine how many time steps are available
     t_index = _to_datetime_index(subset["time"])
     n = min(len(t_index), max(1, int(hours)))
+    logger.info(f"Time steps available={len(t_index)}; requesting first {n} hours")
+    t_fetch = time.perf_counter()
     subset = subset.isel(time=slice(0, n)).load()
+    logger.info(f"Fetched subset data in {time.perf_counter()-t_fetch:.2f}s")
     t_index = t_index[:n]
 
     # Build output arrays
@@ -167,5 +185,5 @@ def fetch_point_forecast_df(
         "ilon": int(ilon),
     }
 
+    logger.info(f"Built DataFrame rows={len(df)}")
     return df, meta
-