graham/prop
1
0
Fork 0
Code Issues Pull requests Projects Releases Packages Wiki Activity Actions

Add timing instrumentation to PropagationGridWorker

Browse source 
Logs duration for each phase: HRRR fetch, profile storage, score
computation, and upsert, plus total elapsed time.
This commit is contained in:
Graham McIntire 2026-03-31 16:18:10 -05:00
parent c9112b9280
commit 77db483a27
No known key found for this signature in database
GPG key ID: F4ABF488E6029E59
1 changed files with 20 additions and 5 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

25
lib/microwaveprop/workers/propagation_grid_worker.ex
View file

@ -21,6 +21,8 @@ defmodule Microwaveprop.Workers.PropagationGridWorker do
@impl Oban.Worker
def perform(%Oban.Job{}) do
t_start = System.monotonic_time(:millisecond)
# HRRR takes ~45min to publish after the hour. Use 2 hours ago to ensure availability.
two_hours_ago = DateTime.add(DateTime.utc_now(), -2, :hour)
valid_time = two_hours_ago |> HrrrClient.nearest_hrrr_hour() |> DateTime.truncate(:second)
@ -30,15 +32,14 @@ defmodule Microwaveprop.Workers.PropagationGridWorker do
Enum.each(@pause_queues, &Oban.pause_queue(queue: &1))
result =
with {:ok, grid_data} <- HrrrClient.fetch_grid(points, valid_time) do
# Store HRRR profiles in the database for future reference
store_hrrr_profiles(grid_data, valid_time)
with {:ok, grid_data} <- timed("fetch_hrrr", fn -> HrrrClient.fetch_grid(points, valid_time) end) do
timed("store_profiles", fn -> store_hrrr_profiles(grid_data, valid_time) end)
scores = compute_scores(grid_data, valid_time)
scores = timed("compute_scores", fn -> compute_scores(grid_data, valid_time) end)
Logger.info("PropagationGrid: computed #{length(scores)} scores, upserting")
case Propagation.upsert_scores(scores) do
case timed("upsert_scores", fn -> Propagation.upsert_scores(scores) end) do
{:ok, count} ->
Logger.info("PropagationGrid: upserted #{count} scores for #{valid_time}")
Phoenix.PubSub.broadcast(Microwaveprop.PubSub, "propagation:updated", {:propagation_updated, valid_time})
@ -55,9 +56,23 @@ defmodule Microwaveprop.Workers.PropagationGridWorker do
Weather.prune_old_grid_profiles()
total_ms = System.monotonic_time(:millisecond) - t_start
Logger.info("PropagationGrid: total time #{format_duration(total_ms)}")
result
end
defp timed(label, fun) do
t0 = System.monotonic_time(:millisecond)
result = fun.()
elapsed = System.monotonic_time(:millisecond) - t0
Logger.info("PropagationGrid: #{label} took #{format_duration(elapsed)}")
result
end
defp format_duration(ms) when ms < 1000, do: "#{ms}ms"
defp format_duration(ms), do: "#{Float.round(ms / 1000, 1)}s"
defp store_hrrr_profiles(grid_data, valid_time) do
stored =
Enum.flat_map(grid_data, fn {{lat, lon}, profile} ->