Error fetching hourly data from NOAA
I came home several days ago to see a flashing wrench symbol on the display of my RainMachine HD-16. When I investigated on the HD-16 touchscreen I got a Diagnostics display that said:
Wifi connection: OK
Weather data internet connectivity: FAIL
Location set: OK
System time set: OK
I have only selected the NOAA weather data, no other sources. I see a signal strength of -50dbm to my mesh Wifi device (Google Wifi). I have not set a static IP on the RainMachine.
On my Android phone app and my computer web app it appeared that the temperature forecast was showing constant 32F going into the future and no precipitation predicted (despite lots of rain in the near future from every news prediction). Despite my previous debug attempts (see below), my RainMachine did some watering this morning during an intense rain storm that has left our city saturated with water. Please help resolve this issue fetching NOAA data!
I've tried the "Reboot Device" option. The problem returns.
I've tried navigating to the NOAA setting and forcing a "refresh". This seems to get accurate weather forecast data. But eventually the problem returns.
I've tried resetting my home address. This clears the previous weather history. Does not fix the problem.
I've not yet tried the "Factory Reset" but that seems like maybe the only option left.
I've used the web app to "View Log". I see lots of ERRORs during fetching of weather data. Not every time. Apparently this has been ongoing for a while, since I see it back at the beginning of the log, several weeks ago. Here's a good fetch:
2019-02-21 11:40:37,334 - INFO - noaa-parser:83 - Fetching Hourly data from https://noaa.rainmachine.com/xml/sample_products/browser_interface/ndfdXMLclient.php
2019-02-21 11:40:38,898 - INFO - noaa-parser:87 - Fetching Daily data from https://noaa.rainmachine.com/xml/sample_products/browser_interface/ndfdBrowserClientByDay.php
2019-02-21 11:40:40,467 - INFO - rmSimulator:571 - * Correction: Zone 2 et0Delta=-9.48, qpfDelta=9.39, rain=None, realPrecip=9.39, qpfUsedLimited=0.00
Here's a fetch that failed to get NOAA hourly data but pulled from rainmachine.com instead. I didn't know that was an option:
2019-02-21 23:41:37,511 - INFO - noaa-parser:83 - Fetching Hourly data from https://noaa.rainmachine.com/xml/sample_products/browser_interface/ndfdXMLclient.php
2019-02-21 23:41:38,243 - ERROR - noaa-parser:114 - *** No hourly information found in response!
2019-02-21 23:41:38,245 - INFO - noaa-parser:87 - Fetching Daily data from https://noaa.rainmachine.com/xml/sample_products/browser_interface/ndfdBrowserClientByDay.php
2019-02-21 23:41:38,648 - INFO - noaa-parser:83 - Fetching Hourly data from https://forecast.rainmachine.com/xml/sample_products/browser_interface/ndfdXMLclient.php
2019-02-21 23:41:41,978 - INFO - rmSimulator:571 - * Correction: Zone 2 et0Delta=-9.79, qpfDelta=2.26, rain=None, realPrecip=2.26, qpfUsedLimited=0.00
Here's a fetch that fails completely:
2019-02-22 11:42:37,889 - INFO - noaa-parser:83 - Fetching Hourly data from https://noaa.rainmachine.com/xml/sample_products/browser_interface/ndfdXMLclient.php
2019-02-22 11:42:38,344 - ERROR - noaa-parser:114 - *** No hourly information found in response!
2019-02-22 11:42:38,347 - INFO - noaa-parser:87 - Fetching Daily data from https://noaa.rainmachine.com/xml/sample_products/browser_interface/ndfdBrowserClientByDay.php
2019-02-22 11:42:38,670 - INFO - noaa-parser:83 - Fetching Hourly data from https://forecast.rainmachine.com/xml/sample_products/browser_interface/ndfdXMLclient.php
2019-02-22 11:42:39,513 - ERROR - noaa-parser:114 - *** No hourly information found in response!
2019-02-22 11:42:39,516 - INFO - noaa-parser:83 - Fetching Hourly data from https://graphical.weather.gov/xml/sample_products/browser_interface/ndfdXMLclient.php
2019-02-22 11:42:39,675 - ERROR - noaa-parser:114 - *** No hourly information found in response!
2019-02-22 11:42:40,247 - INFO - rmMixer:250 - Cannot compute ET0 for 2019-02-23 00:00:00 missing min/max temperatures.
2019-02-22 11:42:40,251 - INFO - rmMixer:250 - Cannot compute ET0 for 2019-02-25 00:00:00 missing min/max temperatures.
2019-02-22 11:42:40,254 - INFO - rmMixer:250 - Cannot compute ET0 for 2019-02-27 00:00:00 missing min/max temperatures.
2019-02-22 11:42:40,258 - INFO - rmMixer:250 - Cannot compute ET0 for 2019-02-26 00:00:00 missing min/max temperatures.
2019-02-22 11:42:40,261 - INFO - rmMixer:250 - Cannot compute ET0 for 2019-02-24 00:00:00 missing min/max temperatures.
2019-02-22 11:42:40,502 - INFO - rmSimulator:571 - * Correction: Zone 2 et0Delta=-9.79, qpfDelta=1.51, rain=None, realPrecip=1.51, qpfUsedLimited=0.00
Here's an odd thing I only saw once:
2019-02-28 20:36:22,852 - INFO - rmThreadWatcher:301 - Refreshed WIFI Information. (old: '192.168.86.51' new ip: None)
2019-02-28 22:23:58,778 - INFO - rmThreadWatcher:301 - Refreshed WIFI Information. (old: None new ip: '192.168.86.51')
Here's when I rebooted. Note how the date changed from 3/8 to 3/5 before/after the reboot. At the end it complains that the last run timestamp is in the future. Weird:
2019-03-08 22:47:43,135 - INFO - rmParserThread:212 - ParserThread postRun() complete!
2019-03-08 22:47:43,138 - INFO - rmHTTPServerThread:67 - RMHTTPServerThread.stop
2019-03-08 22:47:43,167 - INFO - rmProgramSchedulerCommands:67 - Shutting down watering thread...
2019-03-08 22:47:43,423 - INFO - rmHTTPServerThread:74 - RMHTTPServerThread.stop finished!
2019-03-08 22:47:43,797 - INFO - rmProgramSchedulerWatering:76 - Watering thread is shutting down...
2019-03-08 22:47:43,799 - INFO - rmProgramSchedulerWatering:82 - Watering thread is stopping remaining programs and zones...
2019-03-08 22:47:43,802 - INFO - rmProgramSchedulerWatering:88 - Watering thread has stopped!
2019-03-08 22:47:43,804 - INFO - rmProgramSchedulerCommands:69 - Shutting down watering thread... DONE!
2019-03-08 22:47:43,809 - INFO - rmProgramSchedulerCommands:72 - Program Scheduler shutdown completely!
2019-03-08 22:47:44,857 - INFO - rmLocalNetworkAdvertise:130 - RMLocalNetworkAdvertise shutdown completed
2019-03-08 22:47:44,900 - INFO - rmMemoryUsageStats:40 - Memory Usage Stats:
2019-03-08 22:47:44,902 - INFO - rmMemoryUsageStats:41 - * as reported by pyresource 14060
2019-03-08 22:47:44,905 - INFO - rmMemoryUsageStats:43 - * as reported by /proc peak: 22160 rss: 13820
2019-03-08 22:47:44,907 - INFO - main:247 - Platform 3 Reboot: True
2019-03-08 22:47:44,909 - INFO - rmUtils:114 - REBOOTING MACHINE...
2019-03-08 22:47:44,911 - INFO - rmUtils:127 - reboot
2019-03-05 22:48:20,560 - INFO - main:50 - RainMachine v2 Copyright (c) 2015 Green Electronics LLC
2019-03-05 22:48:20,566 - INFO - main:51 - Running on platform Android
2019-03-05 22:48:20,579 - INFO - main:66 - Waiting for IP address (0/40) Current: None
2019-03-05 22:48:21,583 - INFO - main:66 - Waiting for IP address (1/40) Current: None
2019-03-05 22:48:22,587 - INFO - main:66 - Waiting for IP address (2/40) Current: None
2019-03-05 22:48:23,593 - INFO - main:66 - Waiting for IP address (3/40) Current: None
2019-03-05 22:48:24,597 - INFO - main:66 - Waiting for IP address (4/40) Current: None
2019-03-05 22:48:25,601 - INFO - main:66 - Waiting for IP address (5/40) Current: None
2019-03-05 22:48:26,605 - INFO - main:66 - Waiting for IP address (6/40) Current: None
2019-03-05 22:48:27,609 - INFO - main:66 - Waiting for IP address (7/40) Current: None
2019-03-05 22:48:28,613 - INFO - main:66 - Waiting for IP address (8/40) Current: None
2019-03-05 22:48:31,045 - INFO - main:66 - Waiting for IP address (9/40) Current: None
2019-03-05 22:48:32,065 - INFO - main:66 - Waiting for IP address (10/40) Current: None
2019-03-05 22:48:33,096 - INFO - main:66 - Waiting for IP address (11/40) Current: None
2019-03-05 22:48:34,100 - INFO - main:66 - Waiting for IP address (12/40) Current: None
2019-03-05 22:48:35,106 - INFO - main:66 - Waiting for IP address (13/40) Current: None
2019-03-05 22:48:36,110 - INFO - main:66 - Waiting for IP address (14/40) Current: None
2019-03-05 22:48:37,114 - INFO - main:66 - Waiting for IP address (15/40) Current: None
2019-03-05 22:48:38,118 - INFO - main:66 - Waiting for IP address (16/40) Current: None
2019-03-05 22:48:39,122 - INFO - main:66 - Waiting for IP address (17/40) Current: None
2019-03-05 22:48:40,126 - INFO - main:66 - Waiting for IP address (18/40) Current: None
2019-03-05 22:48:41,131 - INFO - main:66 - Waiting for IP address (19/40) Current: None
2019-03-05 22:48:42,135 - INFO - main:66 - Waiting for IP address (20/40) Current: None
2019-03-05 22:48:43,139 - INFO - main:66 - Waiting for IP address (21/40) Current: None
2019-03-05 22:48:44,147 - INFO - main:66 - Waiting for IP address (22/40) Current: None
2019-03-05 22:48:45,150 - INFO - main:66 - Waiting for IP address (23/40) Current: None
2019-03-05 22:48:46,155 - INFO - main:73 - WIRELESS Interface wlan0, Mode: None, IP: 192.168.86.51, MAC: 50:3e:aa:3f:c4:cf, hasClientLink: 0, Mode: None
2019-03-05 22:48:46,163 - INFO - main:110 - Valves available 16
2019-03-05 22:48:46,292 - INFO - rmRestrictions:394 - *** Populating week weather data from database.
2019-03-05 22:48:46,355 - INFO - rmTimeZoneAndroid:49 - Setting timezone to: America/Chicago Olson: CST6CDT,M3.2.0,M11.1.0
2019-03-05 22:48:46,478 - INFO - rmStationDownloader:27 - Downloading station info: http://54.186.186.3/api/et_stats/nearby_stations?latitude=(redacted)&longitude=(redacted)&elevation=(redacted)
2019-03-05 22:48:46,920 - INFO - rmDoyDownloader:22 - Downloading DOY database: http://54.186.186.3/api/et_stats/eto?station_id=7041&source=station
2019-03-05 22:48:47,413 - INFO - rmDoyDownloader:48 - Got 365 values for et0 and 5.51 as et0Avg
2019-03-05 22:48:47,591 - INFO - rmUserSettings:138 - ---------------------------------------------------------------------------------------------
2019-03-05 22:48:47,593 - INFO - rmUserSettings:160 - Version ('4.0.974') Running for:
- name: '(redacted address)'
- timezone: 'America/Chicago'
- latitude: (redacted)
- longitude: (redacted)
- elevation: (redacted)
- et0Average: 6.0609999999999999
- krs: 0.16
- rainSensitivity: 0.80000000000000004
- windSensitivity: 0.5
- wsDays: 2
- database path: '/rainmachine-app/DB/Default'
- httpsServerPort: 8080 (ssl)
- httpServerPort: 18080
- wizardHasRun: 1
2019-03-05 22:48:47,595 - INFO - rmUserSettings:161 - ---------------------------------------------------------------------------------------------
2019-03-05 22:48:47,603 - INFO - rmThreadWatcher:136 - ThreadWatcher running True
2019-03-05 22:48:47,629 - INFO - rmLocalNetworkAdvertise:111 - Local Network Advertiser starting
2019-03-05 22:48:47,662 - INFO - rmParserManager:228 - *** BEGIN Loading parsers from '/rainmachine-app/RMParserFramework/parsers'
2019-03-05 22:48:47,679 - INFO - rmParser:69 - *** Registering parser My Example Parser with interval 21600
2019-03-05 22:48:47,707 - INFO - rmParser:69 - *** Registering parser CIMIS Parser with interval 21600
2019-03-05 22:48:47,768 - INFO - rmParser:69 - *** Registering parser OpenWeatherMap Parser with interval 21600
2019-03-05 22:48:47,881 - INFO - rmParser:69 - *** Registering parser NOAA Parser with interval 21600
2019-03-05 22:48:47,968 - INFO - rmParser:69 - *** Registering parser WUnderground Parser with interval 21600
2019-03-05 22:48:48,019 - INFO - rmParser:69 - *** Registering parser WeatherDisplay Parser with interval 21600
2019-03-05 22:48:48,071 - INFO - rmParser:69 - *** Registering parser Netatmo Parser with interval 21600
2019-03-05 22:48:48,124 - INFO - rmParser:69 - *** Registering parser METNO Parser with interval 21600
2019-03-05 22:48:48,148 - INFO - rmParser:69 - *** Registering parser ForecastIO Parser with interval 21600
2019-03-05 22:48:48,196 - INFO - rmParser:69 - *** Registering parser FAWN Parser with interval 21600
2019-03-05 22:48:48,246 - INFO - rmParser:69 - *** Registering parser Simulator Parser with interval 10800
2019-03-05 22:48:48,361 - INFO - rmParser:69 - *** Registering parser Weather Rules Parser with interval 3600
2019-03-05 22:48:48,435 - INFO - rmParserManager:313 - *** END Loading parsers
2019-03-05 22:48:49,812 - INFO - rmMainManager:136 - Starting bonjour service
2019-03-05 22:48:49,815 - INFO - rmBonjourService:16 - Not available for this platform
2019-03-05 22:48:49,886 - INFO - noaa-parser:83 - Fetching Hourly data from https://noaa.rainmachine.com/xml/sample_products/browser_interface/ndfdXMLclient.php
2019-03-05 22:48:52,936 - INFO - noaa-parser:87 - Fetching Daily data from https://noaa.rainmachine.com/xml/sample_products/browser_interface/ndfdBrowserClientByDay.php
2019-03-05 22:48:54,076 - INFO - rmMixer:45 - * MIXER WILL RUN FORCED as lastRun timestamp is in the future
Here is later when it catches the time back up:
2019-03-05 22:48:55,268 - INFO - rmSimulator:571 - * Correction: Zone 15 et0Delta=-0.43, qpfDelta=0.00, rain=None, realPrecip=0.00, qpfUsedLimited=0.00
2019-03-08 22:48:47,641 - INFO - noaa-parser:83 - Fetching Hourly data from https://noaa.rainmachine.com/xml/sample_products/browser_interface/ndfdXMLclient.php
2019-03-08 22:48:49,069 - WARNING - rmThreadWatcher:204 - System time has changed (from 2019-03-05 22:49:01, to 2019-03-08 22:48:49)! Resetting thread watcher!
2019-03-08 22:48:49,073 - INFO - rmThreadWatcher:404 - ** Automatic Update: Starting update check as interval to next watering program is bigger than 3600
And this unclear warning:
2019-03-09 19:52:07,294 - WARNING - rmUserSettings:274 - Krs not set
2019-03-09 19:52:07,773 - INFO - rmStationDownloader:27 - Downloading station info: http://54.186.186.3/api/et_stats/nearby_stations?latitude=(redacted)&longitude=(redacted)&elevation=(redacted)
2019-03-09 19:52:08,082 - INFO - rmDoyDownloader:22 - Downloading DOY database: http://54.186.186.3/api/et_stats/eto?station_id=7041&source=station
2019-03-09 19:52:08,550 - INFO - rmDoyDownloader:48 - Got 365 values for et0 and 5.51 as et0Avg
2019-03-09 19:52:08,552 - INFO - rmParserManager:425 - **** BEGIN Reset parsers and mixer to default
2019-03-09 19:52:08,555 - INFO - rmMixer:300 - **** BEGIN Reset mixer to default
2019-03-09 19:52:08,587 - INFO - rmMixer:306 - **** END Reset mixer to default
2019-03-09 19:52:08,674 - INFO - rmParserManager:452 - **** END Reset parsers and mixer to default
2019-03-09 19:52:08,676 - INFO - rmSimulator:955 - **** BEGIN Reset simulator to default
2019-03-09 19:52:08,814 - INFO - rmSimulator:967 - **** END Reset simulator to default
-
Yes, NOAA had some trouble lately but it will automatically retry. It should automatically fix after a few retries even if the "wrench" led still blinks.
It doesn't happen on all locations and so far we haven't been able to pinpoint an actual location based pattern.
We found out that if we reduce the number of data points requested from NOAA it works faultlessly. So far for 2 weeks in our internal testing, requesting smaller chunks of data, worked without any issue. The next update will contain this workaround.
Please sign in to leave a comment.
Comments
3 comments