KeyError with single HRRR hourly run

[williamhobbs]

Issue:

I just started fetching the HRRR hourly (using the update in #794 to get 48 hours ahead [edit: turns out I'm using an earlier test version where I'm only grabbing 47 hours ahead]) and I get an error I haven't seen on the .grib2 files for a single run, 2022-09-21 06Z: KeyError: 'ASNOW_surface' (full output is below).

I'm not sure if this should be a common issue, but more robust error handling might be needed. I think this would have jammed up my fetch process for 1-2 days until the old files rolled off of NOMADS.

Details:

I manually removed the folder of .grib2 files and restarted the fetch, getting the same error, but noticed that the downloaded .grib2 files had different sizes the second time. The files downloaded the second time are attached here:
06_error2.zip.

The files from the first download were larger and the full folder is too large to upload to GitHub, so here's a partial set (first 24 of 48 .grib2 files):
06_error_partial.zip.

I tried downloading the files a third time and they appeared to be the same as the second time.

There was a reported data outage on NOMADS at 0605Z on 2022-09-21, so maybe that is related. See mailing list email screenshot below.

Again, note that I'm using #794 to get 48 hours ahead [edit: I'm not using that exact version, instead grabbing 47 hours ahead], and I'm using a custom reduced DOMAIN (see #686), but I think (hope?) that those changes are not relevant.

Extra details:

Full error output:

2022-09-21 14:04:22,871 INFO Fetching NWP forecasts for hrrr_hourly
2022-09-21 14:04:23,482 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf00.grib2
2022-09-21 14:04:23,588 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf01.grib2
2022-09-21 14:04:23,728 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf02.grib2
2022-09-21 14:04:23,801 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf03.grib2
2022-09-21 14:04:23,862 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf04.grib2
2022-09-21 14:04:23,927 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf05.grib2
2022-09-21 14:04:23,987 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf06.grib2
2022-09-21 14:04:24,047 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf07.grib2
2022-09-21 14:04:24,111 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf08.grib2
2022-09-21 14:04:24,175 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf09.grib2
2022-09-21 14:04:24,240 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf10.grib2
2022-09-21 14:04:24,383 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf11.grib2
2022-09-21 14:04:24,639 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf12.grib2
2022-09-21 14:04:28,547 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf13.grib2
2022-09-21 14:04:28,611 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf14.grib2
2022-09-21 14:04:28,720 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf15.grib2
2022-09-21 14:04:28,856 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf16.grib2
2022-09-21 14:04:28,916 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf17.grib2
2022-09-21 14:04:28,983 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf18.grib2
2022-09-21 14:04:29,042 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf19.grib2
2022-09-21 14:04:29,105 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf20.grib2
2022-09-21 14:04:29,332 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf21.grib2
2022-09-21 14:04:29,400 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf22.grib2
2022-09-21 14:04:29,466 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf23.grib2
2022-09-21 14:04:29,544 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf24.grib2
2022-09-21 14:04:29,635 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf25.grib2
2022-09-21 14:04:29,747 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf26.grib2
2022-09-21 14:04:29,880 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf27.grib2
2022-09-21 14:04:30,061 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf28.grib2
2022-09-21 14:04:30,131 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf29.grib2
2022-09-21 14:04:30,279 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf30.grib2
2022-09-21 14:04:30,368 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf31.grib2
2022-09-21 14:04:30,620 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf32.grib2
2022-09-21 14:04:30,694 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf33.grib2
2022-09-21 14:04:30,768 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf34.grib2
2022-09-21 14:04:30,832 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf35.grib2
2022-09-21 14:04:30,901 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf36.grib2
2022-09-21 14:04:31,139 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf37.grib2
2022-09-21 14:04:31,200 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf38.grib2
2022-09-21 14:04:31,297 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf39.grib2
2022-09-21 14:04:31,412 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf40.grib2
2022-09-21 14:04:31,534 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf41.grib2
2022-09-21 14:04:31,645 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf42.grib2
2022-09-21 14:04:31,984 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf43.grib2
2022-09-21 14:04:32,114 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf44.grib2
2022-09-21 14:04:32,186 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf45.grib2
2022-09-21 14:04:32,248 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf46.grib2
2022-09-21 14:04:32,312 INFO Getting file /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr.t06z.wrfsfcf47.grib2
2022-09-21 14:04:33,757 INFO Converting GRIB files to NetCDF with wgrib2 
2022-09-21 14:04:43,184 INFO Optimizing NetCDF file to save at /home/pi/Downloads/sfa/hrrr_hourly/2022/09/21/06/hrrr_hourly.nc
2022-09-21 14:04:43,701 ERROR Uncaught exception
loky.process_executor._RemoteTraceback: 
"""
Traceback (most recent call last):
  File "/home/pi/test_venv/lib/python3.7/site-packages/loky/process_executor.py", line 431, in _process_worker
    r = call_item()
  File "/home/pi/test_venv/lib/python3.7/site-packages/loky/process_executor.py", line 285, in __call__
    return self.fn(*self.args, **self.kwargs)
  File "/home/pi/test_venv/lib/python3.7/site-packages/solarforecastarbiter/io/fetch/nwp.py", line 562, in _optimize_netcdf
    for key in ds.keys()})
  File "/home/pi/test_venv/lib/python3.7/site-packages/solarforecastarbiter/io/fetch/nwp.py", line 562, in <dictcomp>
    for key in ds.keys()})
KeyError: 'ASNOW_surface'
"""

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/home/pi/test_venv/bin/solararbiter", line 10, in <module>
    sys.exit(cli())
  File "/home/pi/test_venv/lib/python3.7/site-packages/click/core.py", line 1137, in __call__
    return self.main(*args, **kwargs)
  File "/home/pi/test_venv/lib/python3.7/site-packages/click/core.py", line 1062, in main
    rv = self.invoke(ctx)
  File "/home/pi/test_venv/lib/python3.7/site-packages/click/core.py", line 1668, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
  File "/home/pi/test_venv/lib/python3.7/site-packages/click/core.py", line 1404, in invoke
    return ctx.invoke(self.callback, **ctx.params)
  File "/home/pi/test_venv/lib/python3.7/site-packages/click/core.py", line 763, in invoke
    return __callback(*args, **kwargs)
  File "/home/pi/test_venv/lib/python3.7/site-packages/solarforecastarbiter/cli.py", line 293, in fetchnwp
    loop.run_until_complete(fut)
  File "/usr/lib/python3.7/asyncio/base_events.py", line 584, in run_until_complete
    return future.result()
  File "/home/pi/test_venv/lib/python3.7/site-packages/solarforecastarbiter/io/fetch/nwp.py", line 699, in run
    await _run_loop(session, model, modelpath, chunksize, once, use_tmp)
  File "/home/pi/test_venv/lib/python3.7/site-packages/solarforecastarbiter/io/fetch/nwp.py", line 678, in _run_loop
    await optimize_netcdf(nctmpfile, finalpath)
  File "/home/pi/test_venv/lib/python3.7/site-packages/solarforecastarbiter/io/fetch/nwp.py", line 582, in optimize_netcdf
    await run_in_executor(_optimize_netcdf, nctmpfile, tmp_path)
  File "/home/pi/test_venv/lib/python3.7/site-packages/solarforecastarbiter/io/fetch/__init__.py", line 28, in run_in_executor
    exc, partial(func, *args, **kwargs))
KeyError: 'ASNOW_surface'

Mailing list email screenshot about NOMADS data outage:

[williamhobbs]

I tried two additional things:

1. I updated my install to match Update nwp.py #794 and actually get 48 hours instead of 47. Resulting error was the same. The zipped folder of .grib2 files is just barely too large to upload here.
2. I manually grabbed the .grib2 files with a bunch of curl commands in Windows, e.g., curl "https://nomads.ncep.noaa.gov/cgi-bin/filter_hrrr_2d.pl?file=hrrr.t06z.wrfsfcf00.grib2&lev_10_m_above_ground=on&lev_2_m_above_ground=on&lev_entire_atmosphere=on&lev_surface=on&var_DSWRF=on&var_TCDC=on&var_TMP=on&var_UGRD=on&var_VBDSF=on&var_VDDSF=on&var_VGRD=on&subregion=&leftlon=-90.5&rightlon=-80.5&toplat=35.2&bottomlat=30&dir=%2Fhrrr.20220921%2Fconus" --output "hrrr.t06z.wrfsfcf00.grib2", moved the files over to the system I'm running solarforecastarbiter-core on, and tried re-running the fetch process. I got the same error when it tried converting the .grib2 files to NetCDF. Here are the .grib2 files:
   06_manual_48h.zip (note that these files came out about 20% smaller than the ones grabbed with the arbiter fetch tool...).

[dplarson]

I'm working to reproduce the issue. But in the meantime, based on the error (and associated line of code), I'm wondering if there is an inconsistency with that ASNOW_surface variable in the latest HRRR files related to that outage.

[williamhobbs]

Here's something I noticed with the 20220921 0600Z files: f15 includes snowfall data when it shouldn't. I grabbed the f14 and f15 GRIB files for 20220921 0600Z and 20220922 0600Z using:

curl "https://nomads.ncep.noaa.gov/cgi-bin/filter_hrrr_2d.pl?file=hrrr.t06z.wrfsfcf14.grib2&lev_10_m_above_ground=on&lev_2_m_above_ground=on&lev_entire_atmosphere=on&lev_surface=on&var_DSWRF=on&var_TCDC=on&var_TMP=on&var_UGRD=on&var_VBDSF=on&var_VDDSF=on&var_VGRD=on&dir=%2Fhrrr.20220921%2Fconus" --output "20220921.hrrr.t06z.wrfsfcf14.grib2"
curl "https://nomads.ncep.noaa.gov/cgi-bin/filter_hrrr_2d.pl?file=hrrr.t06z.wrfsfcf15.grib2&lev_10_m_above_ground=on&lev_2_m_above_ground=on&lev_entire_atmosphere=on&lev_surface=on&var_DSWRF=on&var_TCDC=on&var_TMP=on&var_UGRD=on&var_VBDSF=on&var_VDDSF=on&var_VGRD=on&dir=%2Fhrrr.20220921%2Fconus" --output "20220921.hrrr.t06z.wrfsfcf15.grib2"
curl "https://nomads.ncep.noaa.gov/cgi-bin/filter_hrrr_2d.pl?file=hrrr.t06z.wrfsfcf14.grib2&lev_10_m_above_ground=on&lev_2_m_above_ground=on&lev_entire_atmosphere=on&lev_surface=on&var_DSWRF=on&var_TCDC=on&var_TMP=on&var_UGRD=on&var_VBDSF=on&var_VDDSF=on&var_VGRD=on&dir=%2Fhrrr.20220922%2Fconus" --output "20220922.hrrr.t06z.wrfsfcf14.grib2"
curl "https://nomads.ncep.noaa.gov/cgi-bin/filter_hrrr_2d.pl?file=hrrr.t06z.wrfsfcf15.grib2&lev_10_m_above_ground=on&lev_2_m_above_ground=on&lev_entire_atmosphere=on&lev_surface=on&var_DSWRF=on&var_TCDC=on&var_TMP=on&var_UGRD=on&var_VBDSF=on&var_VDDSF=on&var_VGRD=on&dir=%2Fhrrr.20220922%2Fconus" --output "20220922.hrrr.t06z.wrfsfcf15.grib2"

And then opened them with the NOAA Weather and Climate Tool (https://www.ncdc.noaa.gov/wct/).

f14 for the 21st includes expected grid variables:

but f15 for the 21st has some unexpected ones, including snow accumulation (and some expected variables missing):

f14 and f15 for the 22nd have the expected variables.

[dplarson]

So maybe it is a temporary issue? Though even if it is, there's no guarantee it won't happen again and therefore it would still be good to find a way to make the NWP fetch code more robust to such issues.

[williamhobbs]

Yeah, that's what I'm thinking - a temporary issue that shouldn't be common, but could happen again.