From ced5e3d1a667f4e38ceb4e5b9240233e1490445a Mon Sep 17 00:00:00 2001
From: Graham McIntire <graham@mcintire.me>
Date: Sat, 18 Apr 2026 16:20:59 -0500
Subject: [PATCH] feat(radar): log NEXRAD fetches + worker progress
MIME-Version: 1.0
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 8bit

Previously the CommonVolumeRadarWorker ran silently — no URL logged,
no sign in the logs that it was doing any work. Added info-level
fetch/ok/error logs in NexradClient (same shape as WeatherFetchWorker
RAOB logs) plus start-of-work + ingestion lines in the worker itself.
Unchanged: the existing "no frame" warning and all control flow.
---
 lib/microwaveprop/weather/nexrad_client.ex    | 21 ++++++++++++++++---
 .../workers/common_volume_radar_worker.ex     |  3 +++
 2 files changed, 21 insertions(+), 3 deletions(-)

diff --git a/lib/microwaveprop/weather/nexrad_client.ex b/lib/microwaveprop/weather/nexrad_client.ex
index 897b97eb..f07ef6f7 100644
--- a/lib/microwaveprop/weather/nexrad_client.ex
+++ b/lib/microwaveprop/weather/nexrad_client.ex
@@ -33,14 +33,19 @@ defmodule Microwaveprop.Weather.NexradClient do
 
     req_opts = Application.get_env(:microwaveprop, :nexrad_req_options, [])
 
+    Logger.info("NexradClient: fetching #{url}")
+
     case Req.get(url, [receive_timeout: 60_000, retry: false] ++ req_opts) do
       {:ok, %{status: 200, body: body}} when is_binary(body) ->
+        Logger.info("NexradClient: ok #{byte_size(body)} bytes from #{url}")
         process_frame(body, rounded, points_of_interest)
 
       {:ok, %{status: status}} ->
+        Logger.warning("NexradClient: HTTP #{status} for #{url}")
         {:error, "NEXRAD n0q HTTP #{status}"}
 
       {:error, reason} ->
+        Logger.warning("NexradClient: transport error for #{url}: #{inspect(reason)}")
         {:error, reason}
     end
   end
@@ -109,10 +114,20 @@ defmodule Microwaveprop.Weather.NexradClient do
     url = frame_url(rounded)
     req_opts = Application.get_env(:microwaveprop, :nexrad_req_options, [])
 
+    Logger.info("NexradClient: fetching #{url}")
+
     case Req.get(url, [receive_timeout: 60_000, retry: false] ++ req_opts) do
-      {:ok, %{status: 200, body: body}} when is_binary(body) -> decode_png_to_pixels(body)
-      {:ok, %{status: status}} -> {:error, "NEXRAD n0q HTTP #{status}"}
-      {:error, reason} -> {:error, reason}
+      {:ok, %{status: 200, body: body}} when is_binary(body) ->
+        Logger.info("NexradClient: ok #{byte_size(body)} bytes from #{url}")
+        decode_png_to_pixels(body)
+
+      {:ok, %{status: status}} ->
+        Logger.warning("NexradClient: HTTP #{status} for #{url}")
+        {:error, "NEXRAD n0q HTTP #{status}"}
+
+      {:error, reason} ->
+        Logger.warning("NexradClient: transport error for #{url}: #{inspect(reason)}")
+        {:error, reason}
     end
   end
 
diff --git a/lib/microwaveprop/workers/common_volume_radar_worker.ex b/lib/microwaveprop/workers/common_volume_radar_worker.ex
index 80f731fe..da8a8373 100644
--- a/lib/microwaveprop/workers/common_volume_radar_worker.ex
+++ b/lib/microwaveprop/workers/common_volume_radar_worker.ex
@@ -77,11 +77,14 @@ defmodule Microwaveprop.Workers.CommonVolumeRadarWorker do
     qso_at = contact.qso_timestamp
     rounded = NexradClient.round_to_5min(DateTime.from_naive!(qso_at, "Etc/UTC"))
 
+    Logger.info("CommonVolumeRadarWorker: #{contact.id} fetching n0q frame for #{DateTime.to_iso8601(rounded)}")
+
     case NexradClient.fetch_decoded_frame(rounded) do
       {:ok, pixels, width} ->
         stats = aggregate_stats(pixels, width, pos1, pos2)
         upsert_row!(contact, rounded, stats)
         mark_status(contact, :complete)
+        Logger.info("CommonVolumeRadarWorker: #{contact.id} ingested (max_dbz=#{stats.max_dbz || "nil"})")
         :ok
 
       {:error, reason} ->