Rest errors

Configuration
1

Hi all.
Im running into some weird rest errors.

I have a number of rest sensors, and they are throwing “Empty reply found when expecting JSON data” errors.
A HA restart brings them back, for a period of time, and they stop working again.

PVOutput it also affected, im not sure what else though.

Im up to date, running 2021.12.8 — I think it only started happening with .12, but i cant be 100% certain. Has anyone else come across this ?

2

Usually this just means that the response did not contain JSON data.
You could increase the log level of the rest integration to see what the response actually looks like - maybe the server-side responds with an error message that gives you some idea.

Is it possible that the server you query has some sort of rate limit?

3

No, i dont think so – most of the requests are local, and work via curl from the HA addon.
I will bump up the logger and see what i can find.

4

The “extra” odd thing is they all go offline at the same time, both my custom locally running ones, and anything cloud based that uses the rest connector such as PVOutput.

5

That is odd indeed. Has the increased logging given you any indication why this is happening?

6

Unfortunately not.

It works, and then suddenly stops working.

2022-01-14 04:17:47 DEBUG (MainThread) [homeassistant.components.rest.data] Updating from http://192.168.1.38/opensky_list.php?token=xxxx
2022-01-14 04:17:47 DEBUG (MainThread) [homeassistant.components.rest.data] Updating from http://192.168.1.58:88/bins.php
2022-01-14 04:17:47 DEBUG (MainThread) [homeassistant.components.rest.data] Updating from http://192.168.1.38/petoneer/device.php?device=xxxx
2022-01-14 04:17:47 DEBUG (MainThread) [homeassistant.components.rest.data] Updating from http://192.168.1.38/bring/web.php?list_uuid=xxxx
2022-01-14 04:17:47 DEBUG (MainThread) [homeassistant.components.rest.sensor] Data fetched from resource: Green
2022-01-14 04:17:47 DEBUG (MainThread) [homeassistant.components.rest.sensor] Data fetched from resource: {"flights":[{"callsign":"None"}]}
2022-01-14 04:17:48 DEBUG (MainThread) [homeassistant.components.rest.sensor] Data fetched from resource: {"level":3,"tds":125,"filtertime":1637840418,"motortime":1635208720,"watertime":1642044896,"time":1642094260,"led":10,"tdslevel":0,"ledmode":0,"section":[0,1439],"switch":1}
2022-01-14 04:17:50 DEBUG (MainThread) [homeassistant.components.rest.sensor] Data fetched from resource: {"items":["Plants","Shed"]}
2022-01-14 04:18:16 DEBUG (MainThread) [homeassistant.components.rest.data] Updating from https://api.solcast.com.au/rooftop_sites/xxxx/forecasts?format=json&api_key=xxxx
2022-01-14 04:18:16 DEBUG (MainThread) [homeassistant.components.rest.data] Updating from https://pvoutput.org/service/r2/getstatus.jsp
2022-01-14 04:18:17 DEBUG (MainThread) [homeassistant.components.rest.data] Updating from http://192.168.1.38/weewx_monitor.php
2022-01-14 04:18:18 DEBUG (MainThread) [homeassistant.components.rest.data] Updating from http://192.168.1.38/opensky_list.php?token=xxxx
2022-01-14 04:18:18 DEBUG (MainThread) [homeassistant.components.rest.data] Updating from http://192.168.1.58:88/bins.php
2022-01-14 04:18:18 DEBUG (MainThread) [homeassistant.components.rest.data] Updating from http://192.168.1.38/petoneer/device.php?device=xxxx
2022-01-14 04:18:18 DEBUG (MainThread) [homeassistant.components.rest.data] Updating from http://192.168.1.38/bring/web.php?list_uuid=xxxx
2022-01-14 04:18:28 ERROR (MainThread) [homeassistant.components.rest.data] Error fetching data: https://api.solcast.com.au/rooftop_sites/xxxx/forecasts?format=json&api_key=xxxx failed with
2022-01-14 04:18:28 DEBUG (MainThread) [homeassistant.components.rest.sensor] Data fetched from resource: None
2022-01-14 04:18:28 WARNING (MainThread) [homeassistant.components.rest.sensor] Empty reply found when expecting JSON data
2022-01-14 04:18:29 ERROR (MainThread) [homeassistant.components.rest.data] Error fetching data: https://pvoutput.org/service/r2/getstatus.jsp failed with
    self._async_update_from_rest_data()
  File "/usr/src/homeassistant/homeassistant/components/pvoutput/sensor.py", line 136, in _async_update_from_rest_data
    self.pvcoutput = self.status._make(self.rest.data.split(","))

The only other useful related thing i can find is this ::

2022-01-14 04:18:18 WARNING (MainThread) [homeassistant.components.sensor] Updating emoncms sensor took longer than the scheduled update interval 0:00:05
2022-01-14 04:18:23 WARNING (MainThread) [homeassistant.components.sensor] Updating emoncms sensor took longer than the scheduled update interval 0:00:05
2022-01-14 04:18:24 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.solcast_forecast_data is taking over 10 seconds
2022-01-14 04:18:25 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.pvoutput is taking over 10 seconds
2022-01-14 04:18:26 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.weewx_last_update is taking over 10 seconds
2022-01-14 04:18:28 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.opensky_list is taking over 10 seconds
2022-01-14 04:18:28 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bin_week is taking over 10 seconds
2022-01-14 04:18:28 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.petoneer is taking over 10 seconds
2022-01-14 04:18:28 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.bunnings_list is taking over 10 seconds

Which makes me wonder if that solcast request is failing, which leads to something weird happening to the rest ecosystem.

7

This has reared its head again over the last week or so.

There is no rhyme or reason to it. Nothing is logged, it just starts throwing blank response errors.

8

So it looks like i am hitting some kind of edge case or race condition where no error is captured, as nothing is logged after failed with

2022-06-06 11:52:33 ERROR (MainThread) [homeassistant.components.rest.data] Error fetching data: http://y.y.y.y/opensky_list.php?token=xxx failed with
2022-06-06 11:52:33 DEBUG (MainThread) [homeassistant.components.rest.sensor] Data fetched from resource: None
2022-06-06 11:52:33 WARNING (MainThread) [homeassistant.components.rest.sensor] Empty reply found when expecting JSON data

I am totally at a loss.

9

I think i have solved this, or atleast fixed the symptom, but still not sure of the cause.

Long story short:
I have a restapi sensor to grab some data from the solcast API. I moved the actual API request outside of HA, and made another linux server grab the data from the API and save it as a JSON file. HA just retrieves the JSON file.

Since making this change, i havent had my rest sensors go offline, and its been 4 days and counting which is the longest ive gotten in a while!

Heres hoping.

1 Like
10

Not solved :frowning:

I noticed this morning that the requests that are faiing never actually hit my web server.

HA logs:

2022-06-22 09:28:33 ERROR (MainThread) [homeassistant.components.rest.data] Error fetching data: http://a.b.c.d/opensky_list.php?token=xxxx failed with
2022-06-22 09:28:33 DEBUG (MainThread) [homeassistant.components.rest.sensor] Data fetched from resource: None

My web server log has no request to that particular endpoint since 6AM this morning.

a.b.c.d- - [22/Jun/2022:06:06:33 +1000] "GET /opensky_list.php?token=xxxx HTTP/1.1" 200 64 "-" "HomeAssistant/2022.6.6 httpx/0.23.0 Python/3.9"
a.b.c.d - - [22/Jun/2022:06:08:21 +1000] "GET /opensky_list.php?token=xxxx HTTP/1.1" 200 64 "-" "HomeAssistant/2022.6.6 httpx/0.23.0 Python/3.9"
a.b.c.d - - [22/Jun/2022:06:08:50 +1000] "GET /opensky_list.php?token=xxxx HTTP/1.1" 200 64 "-" "HomeAssistant/2022.6.6 httpx/0.23.0 Python/3.9"

System times are within a few seconds of one another, so its not just log timestamps being out of sync.