prop/test/microwaveprop/workers/era5_poll_worker_test.exs
Graham McIntire 9a78f8c70c
ERA5: tighten stuck threshold to 8h and pause prod queues for diagnosis
Prod has 0 era5_profiles rows after ~500 submit cycles: every CDS job
either gets marked "rejected" (likely cap mismatch) or runs for 13+h
without transitioning to successful, so the handle_both_done branch
has literally never fired and the ERA5Batch: stored log line has
never been emitted once. Tighten Era5PollWorker's @stuck_after_seconds
from 18h to 8h so dead rows recycle within a work shift instead of a
full day, and pause the era5 / era5_submit / era5_poll / era5_batch
queues in runtime.exs so existing rows stay put for inspection while
we figure out why CDS is rejecting everything. Flip paused: true back
once the root cause is identified.
2026-04-15 16:04:12 -05:00

337 lines
12 KiB
Elixir

defmodule Microwaveprop.Workers.Era5PollWorkerTest do
use Microwaveprop.DataCase, async: false
use Oban.Testing, repo: Microwaveprop.Repo
alias Microwaveprop.Weather.Era5CdsJob
alias Microwaveprop.Weather.Era5Client
alias Microwaveprop.Workers.Era5PollWorker
alias Microwaveprop.Workers.Era5SubmitWorker
setup do
System.put_env("ERA5_CDS_API_KEY", "test-key")
on_exit(fn -> System.delete_env("ERA5_CDS_API_KEY") end)
:ok
end
defp insert_cds_job(overrides \\ %{}) do
# Default to "just now" so the stuck-after guard doesn't misfire
# and re-submit in tests that want to exercise status-specific
# branches. Tests that care about the stuck path pass a stale
# submitted_at explicitly.
fresh_submit = DateTime.truncate(DateTime.utc_now(), :second)
attrs =
Map.merge(
%{
year: 2014,
month: 3,
tile_lat: 32,
tile_lon: -98,
single_job_id: "cds-single-123",
pressure_job_id: "cds-pressure-456",
submitted_at: fresh_submit
},
overrides
)
{:ok, row} = %Era5CdsJob{} |> Era5CdsJob.changeset(attrs) |> Repo.insert()
row
end
describe "perform/1 — row lifecycle" do
test "returns :ok and does nothing when the era5_cds_jobs row no longer exists" do
# Row was already processed/deleted by a previous poll run; snooze is
# scheduled behind us in time; just no-op.
Req.Test.stub(Era5Client, fn _ -> raise "CDS should not be contacted" end)
missing_id = Ecto.UUID.generate()
assert :ok =
Era5PollWorker.perform(%Oban.Job{args: %{"era5_cds_job_id" => missing_id}})
end
end
describe "perform/1 — still running" do
test "returns {:snooze, seconds} and bumps poll_count when either CDS job is still running" do
row = insert_cds_job()
Req.Test.stub(Era5Client, fn conn ->
assert conn.method == "GET"
Req.Test.json(conn, %{"status" => "running"})
end)
assert {:snooze, snooze_s} =
Era5PollWorker.perform(%Oban.Job{args: %{"era5_cds_job_id" => row.id}})
assert snooze_s > 0
reloaded = Repo.get!(Era5CdsJob, row.id)
assert reloaded.poll_count == 1
assert reloaded.last_polled_at
end
end
describe "perform/1 — CDS job vanished (404)" do
test "deletes the row, deletes the other CDS job, re-enqueues Era5SubmitWorker, and discards" do
row = insert_cds_job()
test_pid = self()
Req.Test.stub(Era5Client, fn conn ->
cond do
conn.method == "GET" and String.contains?(conn.request_path, "cds-single-123") ->
conn
|> Plug.Conn.put_resp_content_type("application/json")
|> Plug.Conn.resp(404, ~s({"detail":"job deleted","title":"job not found"}))
conn.method == "GET" and String.contains?(conn.request_path, "cds-pressure-456") ->
Req.Test.json(conn, %{"status" => "running"})
conn.method == "DELETE" ->
send(test_pid, {:delete, conn.request_path})
Plug.Conn.resp(conn, 204, "")
end
end)
# Run with manual Oban testing so the re-enqueued Era5SubmitWorker is
# inserted into the queue but not executed inline — we only want to
# assert that the row was deleted and the re-submit was scheduled.
result =
Oban.Testing.with_testing_mode(:manual, fn ->
Era5PollWorker.perform(%Oban.Job{args: %{"era5_cds_job_id" => row.id}})
end)
assert {:discard, reason} = result
assert reason =~ "deleted"
refute Repo.get(Era5CdsJob, row.id)
# The sibling CDS job gets cleaned up too so it doesn't linger on CDS.
assert_received {:delete, "/api/retrieve/v1/jobs/cds-pressure-456"}
# A fresh Era5SubmitWorker job is enqueued so the month gets re-fetched.
assert_enqueued(
worker: Era5SubmitWorker,
args: %{year: 2014, month: 3, tile_lat: 32, tile_lon: -98}
)
end
end
describe "perform/1 — CDS job rejected (over-cap)" do
test "deletes the row, cleans up the sibling CDS job, re-enqueues submit, and discards" do
row = insert_cds_job()
test_pid = self()
Req.Test.stub(Era5Client, fn conn ->
cond do
conn.method == "GET" and String.contains?(conn.request_path, "cds-single-123") ->
Req.Test.json(conn, %{
"jobID" => "cds-single-123",
"status" => "rejected",
"metadata" => %{"origin" => "api"}
})
conn.method == "GET" and String.contains?(conn.request_path, "cds-pressure-456") ->
Req.Test.json(conn, %{"status" => "running"})
conn.method == "DELETE" ->
send(test_pid, {:delete, conn.request_path})
Plug.Conn.resp(conn, 204, "")
end
end)
result =
Oban.Testing.with_testing_mode(:manual, fn ->
Era5PollWorker.perform(%Oban.Job{args: %{"era5_cds_job_id" => row.id}})
end)
assert {:discard, reason} = result
assert reason =~ "rejected"
refute Repo.get(Era5CdsJob, row.id)
# Sibling CDS job is cleaned up so we don't burn queue slots waiting on
# a request we've already abandoned.
assert_received {:delete, "/api/retrieve/v1/jobs/cds-pressure-456"}
# A fresh Era5SubmitWorker job is enqueued so the tile-month gets
# re-submitted once the CDS cap has room.
assert_enqueued(
worker: Era5SubmitWorker,
args: %{year: 2014, month: 3, tile_lat: 32, tile_lon: -98}
)
end
end
describe "perform/1 — stuck in CDS queue" do
# A CDS job that's been in 'accepted' state for many hours is stuck in
# the server's queue and unlikely to ever run. We track submitted_at
# on era5_cds_jobs, so once the row ages past @stuck_after, poll
# treats it as terminal and re-submits — same path as :not_found /
# :rejected.
#
# Threshold is 8h (see @stuck_after_seconds in Era5PollWorker). We
# observed the previous 18h threshold held a row polling for ~13h
# without catching a stuck state while 0 profiles were being
# ingested. 8h is a diagnostic compromise: short enough to recycle
# stuck rows within a shift, still above the ~90 min pressure-level
# normal completion time so healthy runs aren't interrupted.
test "re-submits when submitted_at is older than 8h and at least one leg is still running" do
stale_submit =
DateTime.utc_now()
|> DateTime.add(-9 * 3600, :second)
|> DateTime.truncate(:second)
row = insert_cds_job(%{submitted_at: stale_submit})
test_pid = self()
Req.Test.stub(Era5Client, fn conn ->
cond do
conn.method == "GET" ->
Req.Test.json(conn, %{"status" => "accepted"})
conn.method == "DELETE" ->
send(test_pid, {:delete, conn.request_path})
Plug.Conn.resp(conn, 204, "")
end
end)
result =
Oban.Testing.with_testing_mode(:manual, fn ->
Era5PollWorker.perform(%Oban.Job{args: %{"era5_cds_job_id" => row.id}})
end)
assert {:discard, reason} = result
assert reason =~ "stuck"
refute Repo.get(Era5CdsJob, row.id)
assert_enqueued(
worker: Era5SubmitWorker,
args: %{year: 2014, month: 3, tile_lat: 32, tile_lon: -98}
)
end
test "does NOT re-submit a 6h-old row that's still running (under the 8h threshold)" do
# Observed in prod: CDS pressure-level completes in ~90 min, so
# anything under the 8h diagnostic threshold should keep snoozing,
# not trigger a re-submit storm. The single-level leg is allowed
# to keep running — only the combined age is stale, and 6h is
# still well within the envelope.
slowish_submit =
DateTime.utc_now()
|> DateTime.add(-6 * 3600, :second)
|> DateTime.truncate(:second)
row = insert_cds_job(%{submitted_at: slowish_submit})
Req.Test.stub(Era5Client, fn conn ->
Req.Test.json(conn, %{"status" => "running"})
end)
assert {:snooze, _} =
Era5PollWorker.perform(%Oban.Job{args: %{"era5_cds_job_id" => row.id}})
assert Repo.get(Era5CdsJob, row.id)
end
test "does NOT re-submit when submitted_at is recent even if running" do
# A 30-minute-old row with both legs running is normal — snooze.
fresh_submit =
DateTime.utc_now()
|> DateTime.add(-30 * 60, :second)
|> DateTime.truncate(:second)
row = insert_cds_job(%{submitted_at: fresh_submit})
Req.Test.stub(Era5Client, fn conn ->
Req.Test.json(conn, %{"status" => "running"})
end)
assert {:snooze, _} =
Era5PollWorker.perform(%Oban.Job{args: %{"era5_cds_job_id" => row.id}})
assert Repo.get(Era5CdsJob, row.id)
end
end
describe "perform/1 — transient CDS HTTP error" do
# Observed in prod 2026-04-15: a brief CDS network blip returned HTTP
# 5xx on check_status. The old {:error, _} branches consumed attempts
# and max_attempts=10 burned out in seconds, so 13 rows became
# orphaned (discarded with no cleanup, no active poll worker). The
# fix: treat HTTP errors as transient — snooze without counting an
# attempt. Terminal states (:failed, :rejected, :not_found) still
# drive the fail/resubmit paths.
test "snoozes and keeps the row when single-level check_status returns a transient HTTP error" do
row = insert_cds_job()
Req.Test.stub(Era5Client, fn conn ->
cond do
conn.method == "GET" and String.contains?(conn.request_path, "cds-single-123") ->
conn
|> Plug.Conn.put_resp_content_type("application/json")
|> Plug.Conn.resp(503, ~s({"error":"service unavailable"}))
conn.method == "GET" and String.contains?(conn.request_path, "cds-pressure-456") ->
Req.Test.json(conn, %{"status" => "running"})
end
end)
assert {:snooze, snooze_s} =
Era5PollWorker.perform(%Oban.Job{args: %{"era5_cds_job_id" => row.id}})
assert snooze_s > 0
assert Repo.get(Era5CdsJob, row.id)
end
test "snoozes and keeps the row when pressure-level check_status returns a transient HTTP error" do
row = insert_cds_job()
Req.Test.stub(Era5Client, fn conn ->
cond do
conn.method == "GET" and String.contains?(conn.request_path, "cds-single-123") ->
Req.Test.json(conn, %{"status" => "running"})
conn.method == "GET" and String.contains?(conn.request_path, "cds-pressure-456") ->
conn
|> Plug.Conn.put_resp_content_type("application/json")
|> Plug.Conn.resp(502, ~s({"error":"bad gateway"}))
end
end)
assert {:snooze, snooze_s} =
Era5PollWorker.perform(%Oban.Job{args: %{"era5_cds_job_id" => row.id}})
assert snooze_s > 0
assert Repo.get(Era5CdsJob, row.id)
end
end
describe "perform/1 — failure" do
test "returns {:error, _}, deletes the row, and deletes both CDS jobs when a leg fails" do
row = insert_cds_job()
test_pid = self()
Req.Test.stub(Era5Client, fn conn ->
cond do
conn.method == "GET" and String.contains?(conn.request_path, "cds-single-123") ->
Req.Test.json(conn, %{"status" => "failed", "message" => "bad input"})
conn.method == "GET" and String.contains?(conn.request_path, "cds-pressure-456") ->
Req.Test.json(conn, %{"status" => "running"})
conn.method == "DELETE" ->
send(test_pid, {:delete, conn.request_path})
Plug.Conn.resp(conn, 204, "")
end
end)
assert {:error, reason} =
Era5PollWorker.perform(%Oban.Job{args: %{"era5_cds_job_id" => row.id}})
assert reason =~ "bad input"
refute Repo.get(Era5CdsJob, row.id)
# Both CDS jobs are deleted to free server-side quota.
assert_received {:delete, "/api/retrieve/v1/jobs/cds-single-123"}
assert_received {:delete, "/api/retrieve/v1/jobs/cds-pressure-456"}
end
end
end