core: Ambient Weather Station ClientConnectionError

The problem

Environment

  • Home Assistant release with the issue: 107.0
  • Last working Home Assistant release (if known): 106.6
  • Operating environment (Hass.io/Docker/Windows/etc.): Home Assistant/Ubuntu/Docker CE
  • Integration causing this issue: Ambient Weather
  • Link to integration documentation on our website:

Problem-relevant configuration.yaml


Traceback/Error logs

2020-03-18 14:49:18 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/ambient_station/__init__.py", line 366, in _ws_reconnect
    await self._attempt_connect()
  File "/usr/src/homeassistant/homeassistant/components/ambient_station/__init__.py", line 353, in _attempt_connect
    await self.client.websocket.connect()
  File "/usr/local/lib/python3.7/site-packages/aioambient/websocket.py", line 76, in connect
    transports=["websocket"],
  File "/usr/local/lib/python3.7/site-packages/socketio/asyncio_client.py", line 108, in connect
    engineio_path=socketio_path)
  File "/usr/local/lib/python3.7/site-packages/engineio/asyncio_client.py", line 76, in connect
    url, headers, engineio_path)
  File "/usr/local/lib/python3.7/site-packages/engineio/asyncio_client.py", line 256, in _connect_websocket
    headers=headers)
  File "/usr/local/lib/python3.7/site-packages/aiohttp/client.py", line 728, in _ws_connect
    proxy_headers=proxy_headers)
  File "/usr/local/lib/python3.7/site-packages/aiohttp/client.py", line 483, in _request
    timeout=real_timeout
  File "/usr/local/lib/python3.7/site-packages/aiohttp/connector.py", line 526, in connect
    raise ClientConnectionError("Connector is closed.")
aiohttp.client_exceptions.ClientConnectionError: Connector is closed.

Additional information

Ambient reporting stops shortly after an HA restart occurs. Reporting resumes if HA is restarted again.

About this issue

  • Original URL
  • State: closed
  • Created 4 years ago
  • Reactions: 3
  • Comments: 71 (17 by maintainers)

Most upvoted comments

Glad to hear it’s looking good for everyone. I’ll wait one more day to confirm; if we’re still looking good tomorrow, I’ll get a PR submitted.

No errors overnight! I certainly would have seen errors by now, so things are looking up.

The new component ran overnight, and looks good. It’s managed to recover after my station stopped sending data (for whatever reason) for 3 hours.

Thanks for this! Whatever is going on on the cloud side has also motivated me to get rtl_433 working with the outdoor unit, which is nice too!

Just want to say thanks @bachya . This is one of the most useful components, I’m glad you’re on the case.

Thanks, all – I appreciate everyone’s efforts. I think I have some new info to share, so don’t worry about testing further just yet.

I ran examples/text_websocket.py overnight and finally saw something comparable to what you all are seeing. For several hours (from about 9 PM to 3:59 AM), I saw data come down the websocket every minute or so:

2020-03-25 03:58:27,785 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 03:58:32,345 - __main__ - INFO - Data received: {'dateutc': 1585130280000, 'tempinf': 68.7, 'humidityin': 31, 'baromrelin': 29.912, 'baromabsin': 24.573, 'tempf': 42.3, 'humidity': 52, 'winddir': 119, 'windspeedmph': 0.7, 'windgustmph': 1.1, 'maxdailygust': 3.4, 'hourlyrainin': 0, 'eventrainin': 0, 'dailyrainin': 0, 'weeklyrainin': 0, 'monthlyrainin': 1.72, 'totalrainin': 13.76, 'solarradiation': 0, 'uv': 0, 'feelsLike': 42.3, 'dewPoint': 25.94, 'feelsLikein': 66.7, 'dewPointin': 36.8, 'lastRain': '2020-03-21T20:48:00.000Z', 'tz': 'America/Denver', 'date': '2020-03-25T09:58:00.000Z', 'macAddress': 'XX:XX:XX:XX:XX:XX'}
2020-03-25 03:58:32,786 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 03:58:37,792 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 03:58:42,798 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 03:58:47,801 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 03:58:52,803 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 03:58:57,808 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 03:59:02,814 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 03:59:07,819 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 03:59:12,822 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 03:59:17,828 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 03:59:22,833 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 03:59:27,839 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 03:59:31,880 - __main__ - INFO - Data received: {'dateutc': 1585130340000, 'tempinf': 68.5, 'humidityin': 31, 'baromrelin': 29.912, 'baromabsin': 24.573, 'tempf': 42.1, 'humidity': 52, 'winddir': 118, 'windspeedmph': 0, 'windgustmph': 0, 'maxdailygust': 3.4, 'hourlyrainin': 0, 'eventrainin': 0, 'dailyrainin': 0, 'weeklyrainin': 0, 'monthlyrainin': 1.72, 'totalrainin': 13.76, 'solarradiation': 0, 'uv': 0, 'feelsLike': 42.1, 'dewPoint': 25.76, 'feelsLikein': 66.5, 'dewPointin': 36.7, 'lastRain': '2020-03-21T20:48:00.000Z', 'tz': 'America/Denver', 'date': '2020-03-25T09:59:00.000Z', 'macAddress': 'XX:XX:XX:XX:XX:XX'}
2020-03-25 03:59:32,842 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 03:59:37,843 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 03:59:42,848 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 03:59:47,854 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 03:59:52,860 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 03:59:57,865 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:00:02,869 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:00:07,874 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:00:12,880 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:00:17,885 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:00:22,891 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:00:27,894 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:00:32,898 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:00:34,289 - __main__ - INFO - Data received: {'dateutc': 1585130400000, 'tempinf': 68.7, 'humidityin': 31, 'baromrelin': 29.924, 'baromabsin': 24.584, 'tempf': 42.1, 'humidity': 51, 'winddir': 118, 'windspeedmph': 0, 'windgustmph': 0, 'maxdailygust': 3.4, 'hourlyrainin': 0, 'eventrainin': 0, 'dailyrainin': 0, 'weeklyrainin': 0, 'monthlyrainin': 1.72, 'totalrainin': 13.76, 'solarradiation': 0, 'uv': 0, 'feelsLike': 42.1, 'dewPoint': 25.29, 'feelsLikein': 66.7, 'dewPointin': 36.8, 'lastRain': '2020-03-21T20:48:00.000Z', 'tz': 'America/Denver', 'date': '2020-03-25T10:00:00.000Z', 'macAddress': 'XX:XX:XX:XX:XX:XX'}

However, after that, I didn’t receive updates for the rest of the night:

2020-03-25 04:00:37,902 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:00:42,904 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:00:47,909 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:00:52,912 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:00:57,918 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:01:02,923 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:01:07,929 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:01:12,935 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:01:17,938 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:01:22,943 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:01:27,949 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:01:32,953 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:01:37,959 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:01:42,964 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:01:47,970 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:01:52,976 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:01:57,981 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:02:02,983 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:02:07,985 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:02:12,990 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:02:17,996 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:02:23,001 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:02:28,007 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:02:33,013 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:02:38,018 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:02:43,023 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:02:48,028 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:02:53,031 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:02:58,036 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:03:03,042 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:03:08,047 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:03:13,051 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:03:18,056 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:03:23,059 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:03:28,064 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:03:33,067 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:03:38,072 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:03:43,078 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:03:48,083 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:03:53,089 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:03:58,091 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:04:03,096 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:04:08,102 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:04:13,108 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:04:18,112 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:04:23,117 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:04:28,119 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:04:33,124 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:04:38,127 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:04:43,132 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:04:48,138 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:04:53,143 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:04:58,149 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:05:03,154 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:05:08,160 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:05:13,166 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:05:18,171 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:05:23,176 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:05:28,182 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:05:33,187 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:05:38,193 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:05:43,198 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:05:48,203 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:05:53,208 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:05:58,211 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:06:03,216 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:06:08,222 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:06:13,227 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:06:18,233 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:06:23,238 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:06:28,244 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:06:33,249 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:06:38,251 - __main__ - INFO - Simulating some other task occurring...
2020-03-25 04:06:43,256 - __main__ - INFO - Simulating some other task occurring...
...

I didn’t see any exceptions or errors logged – no mention of aiohttp.client_exceptions.ClientOSError or aiohttp.client_exceptions.ClientConnectionError, unfortunately. This leads me to believe that as far as aioambient is concerned, everything is “working” – the Ambient websocket simply stopped returning data.

I have a theory. The HASS ambient integration has a software watchdog in place – if new data doesn’t arrive in a 5-minute window, the watchdog is supposed to forcefully close and reconnect the websocket. Looking closer, everyone’s logs – regardless of what exception is ultimately thrown – shows the same beginning:

File "/opt/assistant/homeassistant/lib/python3.7/site-packages/homeassistant/components/ambient_station/__init__.py", line 444, in ws_connect
...

I have a hunch that my watchdog may be attempting to reconnect too quickly; put another way, the watchdog forcefully closes the connection and without waiting at all, immediately attempts to reconnect. I’m not an aiohttp expert, but from work I did in the simplisafe component, I’m curious whether adding a small delay (even 1 or 2 seconds) would allow the reconnection to succeed.

I’m going to experiment and see if it makes a difference in my production HASS. I’ll follow up today with what I find.

I get no new data until I restart HA.

Two days without error or dropout in reporting. Updates vary from seconds to minutes, but I haven’t had to restart to restore service. Thank you @bachya.

Great work on this! Thanks a million.

I haven’t seen any errors either. I’m not ready to call it yet because it made it through the night for me the prior night too. But it’s looking promising!

@Codelica thank you for saving me from the vagaries of GitHub.

@bachya thanks again for your work on this. I’ve got the custom_component installed and running. Will report back.

Installed… thanks!

@grantalewis you could download the “full” ZIP file off his main project page here. Then just take the folder located inside at:

smart-home/home-assistant/settings/custom_components/ambient_station

New code installed and running. Thanks!

Alright, I have my new functionality in testing. I’d love for you all to give it a try if you’re willing. Simply download this folder and put it inside <config>/custom_components, then restart HASS. Keep me posted.

Okay. I have it installed and will let you know how it goes. Thanks for your help!

Thanks for the info. I’m working on a new theory that the watchdog works correctly in some cases, but not in others (specifically, in cases where I’m not properly catching all of the exceptions that aiohttp can produce, thus halting the watchdog at times). Testing now and will follow up.

@grantalewis I ran into the same thing. you want- pip3 install virtualenv the rest should work for you as is.

When I get to step 2- /usr/bin/python3: No module named virtualenv

Sorry I really am nearly useless with python.

Edit Never mind I got it. Standby.

As with everyone else… no new data is received.

On Monday, March 23, 2020, Gary Kelley notifications@github.com wrote:

I get no new data until I restart HA.

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/home-assistant/core/issues/32956#issuecomment-602695869, or unsubscribe https://github.com/notifications/unsubscribe-auth/ACOEE45HQSKBWJI4XUKODRLRI6B63ANCNFSM4LO345DQ .

No data gets reported ever; I haven’t had it work after a restart since my initial report.

I would also like to add that I am seeing this as well. I have nothing log wise to provide that has not already been provided. Happy to provide help to diagnose if needed though.

I’m seeing something similar (websocket connection error on startup) about 50% of restarts on 0.107 and 0.107.1:

2020-03-19 12:30:20 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/opt/assistant/homeassistant/lib/python3.7/site-packages/homeassistant/components/ambient_station/__init__.py", line 444, in ws_connect
    await self._attempt_connect()
  File "/opt/assistant/homeassistant/lib/python3.7/site-packages/homeassistant/components/ambient_station/__init__.py", line 353, in _attempt_connect
    await self.client.websocket.connect()
  File "/opt/assistant/homeassistant/lib/python3.7/site-packages/aioambient/websocket.py", line 76, in connect
    transports=["websocket"],
  File "/opt/assistant/homeassistant/lib/python3.7/site-packages/socketio/asyncio_client.py", line 108, in connect
    engineio_path=socketio_path)
  File "/opt/assistant/homeassistant/lib/python3.7/site-packages/engineio/asyncio_client.py", line 76, in connect
    url, headers, engineio_path)
  File "/opt/assistant/homeassistant/lib/python3.7/site-packages/engineio/asyncio_client.py", line 256, in _connect_websocket
    headers=headers)
  File "/opt/assistant/homeassistant/lib/python3.7/site-packages/aiohttp/client.py", line 728, in _ws_connect
    proxy_headers=proxy_headers)
  File "/opt/assistant/homeassistant/lib/python3.7/site-packages/aiohttp/client.py", line 504, in _request
    await resp.start(conn)
  File "/opt/assistant/homeassistant/lib/python3.7/site-packages/aiohttp/client_reqrep.py", line 847, in start
    message, payload = await self._protocol.read()  # type: ignore  # noqa
  File "/opt/assistant/homeassistant/lib/python3.7/site-packages/aiohttp/streams.py", line 591, in read
    await self._waiter
aiohttp.client_exceptions.ClientOSError: [Errno 32] Broken pipe

No idea what the flakiness is about; it doesn’t appear to be rate-limiting.