Fix backend jobs failing #38
Description
I've been having mixed success using test_run_requests.py. Attempting one run after another sometimes works and sometimes fails. Here's an example failure:
backend-1 | 172.18.0.5 - - [19/Mar/2026 20:50:13] "POST /APIs/run HTTP/1.1" 202 -
nfgda-service-1 | 2026-03-19 20:50:13,625 [INFO] __main__: dequeued job fa472475-d6a2-5fb6-b654-4233d7b4552d
nfgda-service-1 | 2026-03-19 20:50:13,650 [INFO] __main__: processing job fa472475-d6a2-5fb6-b654-4233d7b4552d
nfgda-service-1 | 2026-03-19 20:50:13,652 [INFO] nfgda_runner: timebox parameters set to start_utc: 2026-03-19T20:03:45Z, end_utc: 2026-03-19T20:23:45Z
nfgda-service-1 | 2026-03-19 20:50:13,659 [INFO] nfgda_runner: config times: start=2026-03-19T20:03:45Z -> 2026,3,19,20,3,45, end=2026-03-19T20:23:45Z -> 2026,3,19,20,23,45
nfgda-service-1 | 2026-03-19 20:50:13,674 [INFO] nfgda_runner: temporary config file created at /tmp/nfgda_ovhkihst.ini
nfgda-service-1 | 2026-03-19 20:50:13,675 [INFO] nfgda_runner: setting environment variable NFGDA_CONFIG_PATH to /tmp/nfgda_ovhkihst.ini
nfgda-service-1 | 2026-03-19 20:50:13,675 [INFO] nfgda_runner: running algorithm for job fa472475-d6a2-5fb6-b654-4233d7b4552d
nfgda-service-1 | 2026-03-19 20:50:14,714 [INFO] nfgda_runner: [NFGDA_Host stdout]
nfgda-service-1 | 2026-03-19 20:50:14,714 [INFO] nfgda_runner: [NFGDA_Host stdout] ## You are using the Python ARM Radar Toolkit (Py-ART), an open source
nfgda-service-1 | 2026-03-19 20:50:14,714 [INFO] nfgda_runner: [NFGDA_Host stdout] ## library for working with weather radar data. Py-ART is partly
nfgda-service-1 | 2026-03-19 20:50:14,714 [INFO] nfgda_runner: [NFGDA_Host stdout] ## supported by the U.S. Department of Energy as part of the Atmospheric
nfgda-service-1 | 2026-03-19 20:50:14,714 [INFO] nfgda_runner: [NFGDA_Host stdout] ## Radiation Measurement (ARM) Climate Research Facility, an Office of
nfgda-service-1 | 2026-03-19 20:50:14,714 [INFO] nfgda_runner: [NFGDA_Host stdout] ## Science user facility.
nfgda-service-1 | 2026-03-19 20:50:14,714 [INFO] nfgda_runner: [NFGDA_Host stdout] ##
nfgda-service-1 | 2026-03-19 20:50:14,714 [INFO] nfgda_runner: [NFGDA_Host stdout] ## If you use this software to prepare a publication, please cite:
nfgda-service-1 | 2026-03-19 20:50:14,714 [INFO] nfgda_runner: [NFGDA_Host stdout] ##
nfgda-service-1 | 2026-03-19 20:50:14,715 [INFO] nfgda_runner: [NFGDA_Host stdout] ## JJ Helmus and SM Collis, JORS 2016, doi: 10.5334/jors.119
nfgda-service-1 | 2026-03-19 20:50:14,715 [INFO] nfgda_runner: [NFGDA_Host stdout]
backend-1 | 172.18.0.5 - - [19/Mar/2026 20:50:18] "GET /APIs/status?job_id=fa472475-d6a2-5fb6-b654-4233d7b4552d HTTP/1.1" 200 -
nfgda-service-1 | 2026-03-19 20:50:19,048 [INFO] nfgda_runner: [NFGDA_Host stderr] 20:50:19 [__main__] INFO: NFGDA_Host starting, custom_start_time=2026-03-19 20:03:45+00:00, custom_end_time=2026-03-19 20:23:45+00:00
nfgda-service-1 | 2026-03-19 20:50:19,048 [INFO] nfgda_runner: [NFGDA_Host stderr] 20:50:19 [__main__] INFO: initializing in HISTORICAL mode, cstart=2026-03-19 20:03:45+00:00, cend=2026-03-19 20:23:45+00:00
nfgda-service-1 | 2026-03-19 20:50:19,056 [INFO] nfgda_runner: [NFGDA_Host stderr] 20:50:19 [__main__] INFO: starting HostDaemon.run() — spawning 4 worker tasks
nfgda-service-1 | 2026-03-19 20:50:19,056 [INFO] nfgda_runner: [NFGDA_Host stderr] 20:50:19 [__main__] INFO: checking for [KCYS] updates, latest nexrad=2026-03-19 20:02:44+00:00
nfgda-service-1 | 2026-03-19 20:50:19,056 [INFO] nfgda_runner: [NFGDA_Host stdout] [20:50:19] [Host] Checking for [KCYS] updates... latest nexrad = 2026-03-19 20:02:44+00:00
nfgda-service-1 | 2026-03-19 20:50:19,612 [INFO] nfgda_runner: [NFGDA_Host stderr] 20:50:19 [__main__] INFO: found 2 new volume(s), advancing last_nexrad to 2026-03-19 20:17:22+00:00
nfgda-service-1 | 2026-03-19 20:50:19,612 [INFO] nfgda_runner: [NFGDA_Host stdout] [20:50:19] [Downloader] Find 2 volumes.
nfgda-service-1 | 2026-03-19 20:50:19,612 [INFO] nfgda_runner: [NFGDA_Host stdout] [20:50:19] [Host] 2026-03-19 20:17:22+00:00 2026-03-19 20:23:45+00:00 False
nfgda-service-1 | 2026-03-19 20:50:19,612 [INFO] nfgda_runner: [NFGDA_Host stderr] 20:50:19 [__main__] INFO: download_worker started
nfgda-service-1 | 2026-03-19 20:50:19,612 [INFO] nfgda_runner: [NFGDA_Host stderr] 20:50:19 [__main__] INFO: download_worker picked up vol=KCYS20260319_200822_V06 idx=0 (queue size=1)
nfgda-service-1 | 2026-03-19 20:50:19,683 [INFO] nfgda_runner: [NFGDA_Host stderr] 20:50:19 [__main__] INFO: nfgda_worker started
nfgda-service-1 | 2026-03-19 20:50:19,683 [INFO] nfgda_runner: [NFGDA_Host stderr] 20:50:19 [__main__] INFO: d_forecast_worker started
nfgda-service-1 | 2026-03-19 20:50:19,683 [INFO] nfgda_runner: [NFGDA_Host stderr] 20:50:19 [__main__] INFO: s_forecast_worker started
(2/5s)Downloaded KCYS20260319_200822_V0652 [INFO] nfgda_runner: [NFGDA_Host stdout]
nfgda-service-1 | 2026-03-19 20:50:20,952 [INFO] nfgda_runner: [NFGDA_Host stdout] 1 out of 1 files downloaded...0 errors
nfgda-service-1 | 2026-03-19 20:50:20,952 [INFO] nfgda_runner: [NFGDA_Host stdout] [20:50:20] [Downloader] Got Volume: KCYS20260319_200822_V06
nfgda-service-1 | 2026-03-19 20:50:20,952 [INFO] nfgda_runner: [NFGDA_Host stdout] [20:50:20] [Converter] Processing KCYS20260319_200822_V06
nfgda-service-1 | 2026-03-19 20:50:22,088 [INFO] nfgda_runner: [NFGDA_Host stderr] 20:50:22 [__main__] INFO: download complete for idx=0, setting nfgda_ready
nfgda-service-1 | 2026-03-19 20:50:22,088 [INFO] nfgda_runner: [NFGDA_Host stderr] 20:50:22 [__main__] INFO: download_worker picked up vol=KCYS20260319_201721_V06 idx=1 (queue size=0)
(3/5s)[20:50:22] [Downloader] nfgda_ready [0] set nfgda_runner: [NFGDA_Host stdout]
(4/5s)Downloaded KCYS20260319_201721_V0614 [INFO] nfgda_runner: [NFGDA_Host stdout]
nfgda-service-1 | 2026-03-19 20:50:23,015 [INFO] nfgda_runner: [NFGDA_Host stdout] 1 out of 1 files downloaded...0 errors
nfgda-service-1 | 2026-03-19 20:50:23,015 [INFO] nfgda_runner: [NFGDA_Host stdout] [20:50:23] [Downloader] Got Volume: KCYS20260319_201721_V06
nfgda-service-1 | 2026-03-19 20:50:23,015 [INFO] nfgda_runner: [NFGDA_Host stdout] [20:50:23] [Converter] Processing KCYS20260319_201721_V06
backend-1 | 172.18.0.5 - - [19/Mar/2026 20:50:23] "GET /APIs/status?job_id=fa472475-d6a2-5fb6-b654-4233d7b4552d HTTP/1.1" 200 -
nfgda-service-1 | 2026-03-19 20:50:24,266 [INFO] nfgda_runner: [NFGDA_Host stderr] 20:50:24 [__main__] INFO: download complete for idx=1, setting nfgda_ready
nfgda-service-1 | 2026-03-19 20:50:24,267 [INFO] nfgda_runner: [NFGDA_Host stderr] 20:50:24 [__main__] INFO: nfgda_worker picked up idx=1 (queue size=0)
(5/5s)[20:50:24] [Downloader] nfgda_ready [1] set nfgda_runner: [NFGDA_Host stdout]
nfgda-service-1 | 2026-03-19 20:50:24,267 [INFO] nfgda_runner: [NFGDA_Host stdout] [20:50:24] [NFGDA] KCYS20260319_201721_V06 [1] wait nfgda_ready[0]
nfgda-service-1 | 2026-03-19 20:50:24,305 [INFO] nfgda_runner: [NFGDA_Host stdout] [20:50:24] [NFGDA] KCYS20260319_200822_V06 -> KCYS20260319_201721_V06
nfgda-service-1 | 2026-03-19 20:50:24,635 [INFO] nfgda_runner: [NFGDA_Host stdout]
nfgda-service-1 | 2026-03-19 20:50:24,635 [INFO] nfgda_runner: [NFGDA_Host stderr] 20:50:24 [__main__] INFO: checking for [KCYS] updates, latest nexrad=2026-03-19 20:17:21+00:00
nfgda-service-1 | 2026-03-19 20:50:24,635 [INFO] nfgda_runner: [NFGDA_Host stdout] [20:50:24] [Host] Checking for [KCYS] updates... latest nexrad = 2026-03-19 20:17:21+00:00
nfgda-service-1 | 2026-03-19 20:50:24,870 [INFO] nfgda_runner: [NFGDA_Host stderr] 20:50:24 [__main__] INFO: found 2 new volume(s), advancing last_nexrad to 2026-03-19 20:35:19+00:00
nfgda-service-1 | 2026-03-19 20:50:24,870 [INFO] nfgda_runner: [NFGDA_Host stdout] [20:50:24] [Downloader] Find 2 volumes.
nfgda-service-1 | 2026-03-19 20:50:24,870 [INFO] nfgda_runner: [NFGDA_Host stdout] [20:50:24] [Host] 2026-03-19 20:35:19+00:00 2026-03-19 20:23:45+00:00 True
nfgda-service-1 | 2026-03-19 20:50:24,870 [INFO] nfgda_runner: [NFGDA_Host stderr] 20:50:24 [__main__] INFO: last_nexrad 2026-03-19 20:35:19+00:00 exceeded exit_time 2026-03-19 20:23:45+00:00 — stopping main loop
nfgda-service-1 | 2026-03-19 20:50:24,870 [INFO] nfgda_runner: [NFGDA_Host stderr] 20:50:24 [__main__] INFO: download_worker picked up vol=KCYS20260319_202620_V06 idx=2 (queue size=1)
(2/5s)Downloaded KCYS20260319_202620_V0698 [INFO] nfgda_runner: [NFGDA_Host stdout]
nfgda-service-1 | 2026-03-19 20:50:25,899 [INFO] nfgda_runner: [NFGDA_Host stdout] 1 out of 1 files downloaded...0 errors
nfgda-service-1 | 2026-03-19 20:50:25,899 [INFO] nfgda_runner: [NFGDA_Host stdout] [20:50:25] [Downloader] Got Volume: KCYS20260319_202620_V06
nfgda-service-1 | 2026-03-19 20:50:25,899 [INFO] nfgda_runner: [NFGDA_Host stdout] [20:50:25] [Converter] Processing KCYS20260319_202620_V06
nfgda-service-1 | 2026-03-19 20:50:26,244 [INFO] nfgda_runner: [NFGDA_Host stderr] 20:50:26 [__main__] INFO: nfgda step complete for idx=1, clearing nfgda_ready[0], setting df_ready[1]
nfgda-service-1 | 2026-03-19 20:50:26,244 [INFO] nfgda_runner: [NFGDA_Host stdout] [20:50:26] [NFGDA] KCYS20260319_201721_V06[1] nfgda_ready[0] clear; df_ready[1] set
nfgda-service-1 | 2026-03-19 20:50:26,244 [INFO] nfgda_runner: [NFGDA_Host stderr] 20:50:26 [__main__] INFO: d_forecast_worker picked up idx=1 (queue size=0)
nfgda-service-1 | 2026-03-19 20:50:26,244 [INFO] nfgda_runner: [NFGDA_Host stdout] [20:50:26] [FORECAST] KCYS20260319_201721_V06[1] wait df_ready[2]
nfgda-service-1 | 2026-03-19 20:50:27,148 [INFO] nfgda_runner: [NFGDA_Host stderr] 20:50:27 [__main__] INFO: download complete for idx=2, setting nfgda_ready
(3/5s)[20:50:27] [Downloader] nfgda_ready [2] set nfgda_runner: [NFGDA_Host stdout]
nfgda-service-1 | 2026-03-19 20:50:27,150 [INFO] nfgda_runner: [NFGDA_Host stderr] 20:50:27 [__main__] INFO: download_worker picked up vol=KCYS20260319_203518_V06 idx=3 (queue size=0)
nfgda-service-1 | 2026-03-19 20:50:27,150 [INFO] nfgda_runner: [NFGDA_Host stderr] 20:50:27 [__main__] INFO: nfgda_worker picked up idx=2 (queue size=0)
nfgda-service-1 | 2026-03-19 20:50:27,150 [INFO] nfgda_runner: [NFGDA_Host stdout] [20:50:27] [NFGDA] KCYS20260319_202620_V06 [2] wait nfgda_ready[1]
nfgda-service-1 | 2026-03-19 20:50:27,152 [INFO] nfgda_runner: [NFGDA_Host stdout] [20:50:27] [NFGDA] KCYS20260319_201721_V06 -> KCYS20260319_202620_V06
(4/5s)Downloaded KCYS20260319_203518_V0694 [INFO] nfgda_runner: [NFGDA_Host stdout]
nfgda-service-1 | 2026-03-19 20:50:28,094 [INFO] nfgda_runner: [NFGDA_Host stdout] 1 out of 1 files downloaded...0 errors
nfgda-service-1 | 2026-03-19 20:50:28,094 [INFO] nfgda_runner: [NFGDA_Host stdout] [20:50:28] [Downloader] Got Volume: KCYS20260319_203518_V06
nfgda-service-1 | 2026-03-19 20:50:28,094 [INFO] nfgda_runner: [NFGDA_Host stdout] [20:50:28] [Converter] Processing KCYS20260319_203518_V06
backend-1 | 172.18.0.5 - - [19/Mar/2026 20:50:29] "GET /APIs/status?job_id=fa472475-d6a2-5fb6-b654-4233d7b4552d HTTP/1.1" 200 -
nfgda-service-1 | 2026-03-19 20:50:29,731 [INFO] nfgda_runner: [NFGDA_Host stderr] 20:50:29 [__main__] INFO: nfgda step complete for idx=2, clearing nfgda_ready[1], setting df_ready[2]
(5/5s)[20:50:29] [NFGDA] KCYS20260319_202620_V06[2] nfgda_ready[1] clear; df_ready[2] set
nfgda-service-1 | 2026-03-19 20:50:29,934 [INFO] nfgda_runner: [NFGDA_Host stdout]
nfgda-service-1 | 2026-03-19 20:50:29,934 [INFO] nfgda_runner: [NFGDA_Host stderr] 20:50:29 [__main__] INFO: delay_shutdown started (timeout=3600s), waiting for queues to drain
nfgda-service-1 | 2026-03-19 20:50:29,934 [INFO] nfgda_runner: [NFGDA_Host stderr] 20:50:29 [__main__] INFO: queue sizes — download=0, nfgda=0, d_forecast=1, s_forecast=0
nfgda-service-1 | 2026-03-19 20:50:29,935 [INFO] nfgda_runner: [NFGDA_Host stdout] [20:50:29] [Host] Delay Shutdown. Wait for Queues drained
nfgda-service-1 | 2026-03-19 20:50:33,374 [INFO] nfgda_runner: [NFGDA_Host stderr] 20:50:33 [__main__] ERROR: download_worker fatal error for idx=3
nfgda-service-1 | 2026-03-19 20:50:33,376 [INFO] nfgda_runner: [NFGDA_Host stderr] Traceback (most recent call last):
nfgda-service-1 | 2026-03-19 20:50:33,376 [INFO] nfgda_runner: [NFGDA_Host stderr] File "/app/scripts/NFGDA_Host.py", line 127, in download_worker
nfgda-service-1 | 2026-03-19 20:50:33,376 [INFO] nfgda_runner: [NFGDA_Host stderr] await loop.run_in_executor(
nfgda-service-1 | 2026-03-19 20:50:33,378 [INFO] nfgda_runner: [NFGDA_Host stderr] concurrent.futures.process.BrokenProcessPool: A process in the process pool was terminated abruptly while the future was running or pending.
nfgda-service-1 | 2026-03-19 20:50:33,378 [INFO] nfgda_runner: [NFGDA_Host stderr] Traceback (most recent call last):
nfgda-service-1 | 2026-03-19 20:50:33,378 [INFO] nfgda_runner: [NFGDA_Host stderr] File "/app/scripts/NFGDA_Host.py", line 127, in download_worker
nfgda-service-1 | 2026-03-19 20:50:33,378 [INFO] nfgda_runner: [NFGDA_Host stderr] await loop.run_in_executor(
nfgda-service-1 | 2026-03-19 20:50:33,378 [INFO] nfgda_runner: [NFGDA_Host stderr] concurrent.futures.process.BrokenProcessPool: A process in the process pool was terminated abruptly while the future was running or pending.
nfgda-service-1 | 2026-03-19 20:50:33,378 [INFO] nfgda_runner: [NFGDA_Host stdout] [20:50:33] [Downloader] Fatal Error.
backend-1 | 172.18.0.5 - - [19/Mar/2026 20:50:33] "GET /APIs/status?job_id=fa472475-d6a2-5fb6-b654-4233d7b4552d HTTP/1.1" 200 -
backend-1 | 172.18.0.5 - - [19/Mar/2026 20:50:38] "GET /APIs/status?job_id=fa472475-d6a2-5fb6-b654-4233d7b4552d HTTP/1.1" 200 -
nfgda-service-1 | 2026-03-19 20:50:41,019 [INFO] nfgda_runner: [NFGDA_Host stdout] [20:50:41] [FORECAST] df_ready[1] clear.
nfgda-service-1 | 2026-03-19 20:50:41,020 [INFO] nfgda_runner: [NFGDA_Host stdout] [20:50:41] [FORECAST] KCYS20260319_202620_V06[2] wait df_ready[3]
nfgda-service-1 | 2026-03-19 20:50:41,020 [INFO] nfgda_runner: [NFGDA_Host stderr] 20:50:41 [__main__] INFO: d_forecast_worker picked up idx=2 (queue size=0)
nfgda-service-1 | 2026-03-19 20:50:41,020 [INFO] nfgda_runner: [NFGDA_Host stderr] 20:50:41 [__main__] INFO: s_forecast_worker picked up idx=1 (queue size=0)
nfgda-service-1 | 2026-03-19 20:50:41,055 [INFO] nfgda_runner: [NFGDA_Host stdout] [20:50:41] [S FORECAST] No forecast for summary.