Ambient Weather Station ClientConnectionError

garyak commented 4 years ago

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.

bachya commented 4 years ago

Are you seeing this error consistently since upgrading to 0.107.0?

pgenera commented 4 years ago

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.

jwoodard80 commented 4 years ago

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.

bachya commented 4 years ago

In everyone’s cases: does the integration recover and continue to report data at some point, or does no data get reported again until you restart?

pgenera commented 4 years ago

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

garyak commented 4 years ago

I get no new data until I restart HA.

jwoodard80 commented 4 years ago

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 .

bachya commented 4 years ago

Unfortunately, I'm not seeing this: my HASS has continued to run, been rebooted several times, etc. and data continues to be reported:

Screen Shot 2020-03-23 at 11 53 26 AM

So, I'm 🤷‍♂ on this one for the moment.

jwoodard80 commented 4 years ago

What can I do to help narrow this down with you???

bachya commented 4 years ago

I rely on python-socketio for websocket connections and according to its author:

the "Broken Pipe" error indicates that the client closed the connection. I haven't used the OSX client so I can't comment on what situation would cause this, but when you have a web browser client, this error happens when the tab that has the client application is closed. Receiving this error on the server is expected in that case.

So I think you need to see why the connection is being dropped from your client.

You need to figure out why you are getting Broken pipe messages – something in your environment is forcefully closing the connection.

You can use the test_websocket.py script in aioambient to dig further. Make sure you follow the instructions on the repo's homepage to get the environment set up before running the script.

grantalewis commented 4 years ago

Seeing the same:

2020-03-24 19:49:24 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.

I'd be happy to help troubleshoot but will need clearer direction on what steps to take. I'm a little mystified by "You can use the test_websocket.py script in aioambient to dig further. Make sure you follow the instructions on the repo's homepage to get the environment set up before running the script."

jeffkjolley commented 4 years ago

Seeing the same thing here. In response to an earlier question, in my case, HA will start and load Ambient Weather and run fine for several hours before it throws this error (exact same as above), and it will not recover until HA is restarted.

Edit: I ran the test_websock.py script you linked but I get this error- File "./test_websocket.py", line 31 async def main() -> None: ^ SyntaxError: invalid syntax I'm no good with python so if you could point me in the right direction to fix that error I'll try again.

bachya commented 4 years ago

Clone the latest version of aioambient and cd into it:

$ git clone https://github.com/bachya/aioambient.git
$ cd aioambient/

Set up and activate a Python virtual environment:

$ python3 -m virtualenv .venv
$ source .venv/bin/activate

Initialize the dev environment for aioambient:

$ script/setup

Open examples/test_websocket.py in a text editor and put your Ambient API and app keys into lines 12-13, respectively – once you're done, save and close the file:

API_KEY = "<YOUR API KEY>"
APP_KEY = "<YOUR APPLICATION KEY>"

Back on the command line, run examples/test_websocket.py:

$ python3 examples/test_websocket.py

This will start reporting data from the Ambient websocket as it's received. It will run until you stop it with a CMD-c (or ctrl-c if you're on Windows). Ideally, let this run for 20-ish minutes and then post back here; I'm particularly interested in any errors or unhandled exceptions.

jeffkjolley commented 4 years ago

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.

jeffkjolley commented 4 years ago

So it's been running for 25 minutes-ish now and no errors so far. Like I said, it usually takes a few hours before it stops working for me, so I'm going to output this to a file and head to bed. I'll check it in the morning and report back.

bachya commented 4 years ago

Thanks much, @jeffkjolley. I'll do the same and we can check in in the morning.

garyak commented 4 years ago

Yesterday's history. Reporting stopped around 6:00 pm for about an hour until I restarted HA. temp

grantalewis commented 4 years ago

1. Clone the latest version of `aioambient` and `cd` into it:
Thanks for this. I'm getting stuck at the source .venv/bin/activate step:

~/aioambient$ source .venv/bin/activate
-bash: .venv/bin/activate: No such file or directory

I've tried uninstalling/reinstalling virtualenv without luck. Got a nudge for me?

bachya commented 4 years ago

@grantalewis Did you create the virtualenv?

$ python3 -m virtualenv .venv

grantalewis commented 4 years ago

@bachya Yes, I did -- and apologies, I should have mentioned that it was actually the step prior where I had problems. Here's a more complete c&p of the terminal output:

~$ git clone https://github.com/bachya/aioambient.git
fatal: destination path 'aioambient' already exists and is not an empty directory.
~$ cd aioambient/
~/aioambient$ python3 -m virtualenv .venv
/usr/bin/python3: No module named virtualenv
~/aioambient$ pip install virtualenv
Collecting virtualenv
  Using cached https://files.pythonhosted.org/packages/90/9a/d5b295801f94bbc8c6e575563b87ae38dc2ebeb52f93cc4c070ab3836fe8/virtualenv-20.0.14-py2.py3-none-any.whl
Collecting filelock<4,>=3.0.0 (from virtualenv)
<snip>
Installing collected packages: filelock, six, distlib, appdirs, contextlib2, zipp, configparser, scandir, pathlib2, importlib-metadata, singledispatch, typing, importlib-resources, virtualenv
Successfully installed appdirs-1.4.3 configparser-4.0.2 contextlib2-0.6.0.post1 distlib-0.3.0 filelock-3.0.12 importlib-metadata-1.5.0 importlib-resources-1.4.0 pathlib2-2.3.5 scandir-1.10.0 singledispatch-3.4.0.3 six-1.14.0 typing-3.7.4.1 virtualenv-20.0.14 zipp-1.2.0
~/aioambient$ python3 -m virtualenv .venv
/usr/bin/python3: No module named virtualenv

jeffkjolley commented 4 years ago

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

jeffkjolley commented 4 years ago

@bachya, idk if this will be helpful, but this here is (what I think is) the relevant output from my .venv test. I see the same thing in the HA logs when it fails. Let me know if you need something else.

INFO:root:Simulating some other task occurring...
INFO:root:Simulating some other task occurring...
INFO:engineio.client:Sending packet PING data None
INFO:root:Simulating some other task occurring...
INFO:root:Simulating some other task occurring...
INFO:root:Simulating some other task occurring...
INFO:root:Simulating some other task occurring...
INFO:root:Simulating some other task occurring...
INFO:engineio.client:PONG response has not been received, aborting
INFO:engineio.client:Exiting ping task
INFO:engineio.client:Exiting write loop task
INFO:root:Simulating some other task occurring...
INFO:root:Simulating some other task occurring...
INFO:root:Simulating some other task occurring...
INFO:root:Simulating some other task occurring...
INFO:root:Simulating some other task occurring...
INFO:root:Simulating some other task occurring...
INFO:root:Simulating some other task occurring...
INFO:root:Simulating some other task occurring...
INFO:root:Simulating some other task occurring...
INFO:root:Simulating some other task occurring...
INFO:root:Simulating some other task occurring...
INFO:root:Simulating some other task occurring...
INFO:root:Simulating some other task occurring...
INFO:root:Simulating some other task occurring...

grantalewis commented 4 years ago

@bachya Great - believe everything is working now. BTW in that last step you meant

python3 examples/test_websocket.py

right?

I'm seeing pretty much the same thing as jeffkjolley:

~/aioambient$ python3 examples/test_websocket.py
INFO:engineio.client:Attempting WebSocket connection to wss://dash2.ambientweather.net/socket.io/?api=1&applicationKey=<redacted>&transport=websocket&EIO=3
INFO:engineio.client:WebSocket connection accepted with {'sid': '<redacted>', 'upgrades': [], 'pingInterval': 25000, 'pingTimeout': 60000}
INFO:socketio.client:Engine.IO connection established
INFO:root:Simulating some other task occurring...
INFO:engineio.client:Sending packet PING data None
INFO:engineio.client:Received packet MESSAGE data 4"You are using an apiKey as your applicationKey. Please contact support@ambientweather.net to get an applicationKey"
INFO:socketio.client:Connection to namespace / was rejected
INFO:engineio.client:Received packet PONG data None
INFO:root:Simulating some other task occurring...
INFO:root:Simulating some other task occurring...
INFO:root:Simulating some other task occurring...
INFO:root:Simulating some other task occurring...
INFO:engineio.client:Sending packet PING data None
INFO:root:Simulating some other task occurring...
INFO:engineio.client:Received packet PONG data None

If there's a separate log that's being written to, let me know where I can access that and I'll send.

Now I'm going to restart HA to see if anything different pops up.

bachya commented 4 years ago

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.

grantalewis commented 4 years ago

@bachya Great -- glad you're seeing it on your end, and many thanks for your work on this.

FWIW my error occurs fairly quickly after rebooting.

I rebooted at 10:28:42. Then <10 mins later:


2020-03-25 10:36:33 WARNING (MainThread) [aiohttp.websocket] websocket connection is closing.
2020-03-25 10:36:33 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved

pgenera commented 4 years ago

I've noticed something potentially related: my weatherstation is dropping off the network and stops reporting for hours at a time, which would explain the interruption of data and the watchdog firing.

bachya commented 4 years ago

Thanks, @pgenera. That certainly is a problem.

igloo15 commented 4 years ago

I believe the problem is ambient weather is dropping connection constant over the last week or so and this dropped connection is causing the websocket connection to be lost in Home Assistant. There does not appear to be a recovery of the websocket connecting in Home Assistant until restart.

jeffkjolley commented 4 years ago

@bachya, I don't know if this will be helpful but I saw this just a few minutes ago in my logs after I restarted HA because ambient weather stopped working, once again. It looks like it did what it was supposed to, at least this once.

2020-03-25 14:27:38 INFO (MainThread) [engineio.client] Received packet MESSAGE data 2["data",{"dateutc":1585168020000,"tempinf":72,"tempf":43.3,"humidityin":48,"humidity":69,"windspeedmph":7.6,"windgustmph":9.8,"maxdailygust":24.8,"winddir":127,"baromabsin":25.54,"baromrelin":29.82,"hourlyrainin":0,"dailyrainin":0.37,"weeklyrainin":0.39,"monthlyrainin":1.18,"yearlyrainin":4.04,"solarradiation":531.46,"uv":9,"feelsLike":38.8,"dewPoint":33.82,"feelsLikein":71.2,"dewPointin":51.2,"lastRain":"2020-03-25T16:44:00.000Z","tz":"America/Denver","date":"2020-03-25T20:27:00.000Z","macAddress":"C0:21:0D:1F:08:9C"}]
2020-03-25 14:27:38 INFO (MainThread) [socketio.client] Received event "data" [/]
2020-03-25 14:27:47 INFO (MainThread) [engineio.client] Sending packet PING data None
2020-03-25 14:27:47 INFO (MainThread) [engineio.client] Received packet PONG data None
2020-03-25 14:28:12 INFO (MainThread) [engineio.client] Sending packet PING data None
2020-03-25 14:28:12 INFO (MainThread) [engineio.client] Received packet PONG data None
2020-03-25 14:28:37 INFO (MainThread) [engineio.client] Sending packet PING data None
2020-03-25 14:29:02 INFO (MainThread) [engineio.client] PONG response has not been received, aborting
2020-03-25 14:29:02 INFO (MainThread) [engineio.client] Unexpected error "WebSocket read returned None", aborting
2020-03-25 14:29:02 INFO (MainThread) [engineio.client] Waiting for write loop task to end
2020-03-25 14:29:02 INFO (MainThread) [engineio.client] Exiting ping task
2020-03-25 14:29:02 INFO (MainThread) [engineio.client] Exiting write loop task
2020-03-25 14:29:02 INFO (MainThread) [engineio.client] Waiting for ping loop task to end
2020-03-25 14:29:02 INFO (MainThread) [socketio.client] Engine.IO connection dropped
2020-03-25 14:29:02 INFO (MainThread) [homeassistant.components.ambient_station] Disconnected from websocket
2020-03-25 14:29:02 INFO (MainThread) [engineio.client] Exiting read loop task
2020-03-25 14:29:02 INFO (MainThread) [socketio.client] Connection failed, new attempt in 1.31 seconds
2020-03-25 14:29:04 INFO (MainThread) [engineio.client] Attempting WebSocket connection to wss://dash2.ambientweather.net/socket.io/?api=1&applicationKey=REDACTED&transport=websocket&EIO=3
2020-03-25 14:29:04 INFO (MainThread) [engineio.client] WebSocket connection accepted with {'sid': 'rGCbYw1dFLUaliUJAOm7', 'upgrades': [], 'pingInterval': 25000, 'pingTimeout': 60000}
2020-03-25 14:29:04 INFO (MainThread) [socketio.client] Engine.IO connection established
2020-03-25 14:29:04 INFO (MainThread) [socketio.client] Reconnection successful
2020-03-25 14:29:04 INFO (MainThread) [engineio.client] Sending packet PING data None
2020-03-25 14:29:04 INFO (MainThread) [engineio.client] Received packet MESSAGE data 0
2020-03-25 14:29:04 INFO (MainThread) [socketio.client] Namespace / is connected
2020-03-25 14:29:04 INFO (MainThread) [socketio.client] Emitting event "subscribe" [/]
2020-03-25 14:29:04 INFO (MainThread) [engineio.client] Sending packet MESSAGE data 2["subscribe",{"apiKeys":["REDACTED"]}]
2020-03-25 14:29:04 INFO (MainThread) [homeassistant.components.ambient_station] Connected to websocket
2020-03-25 14:29:04 INFO (MainThread) [engineio.client] Received packet PONG data None
2020-03-25 14:29:04 INFO (MainThread) [engineio.client] Received packet MESSAGE data 2["subscribed",{"devices":[{"macAddress":"C0:21:0D:1F:08:9C","lastData":{"dateutc":1585168080000,"tempinf":72,"tempf":43.3,"humidityin":48,"humidity":69,"windspeedmph":0.9,"windgustmph":2.5,"maxdailygust":24.8,"winddir":119,"baromabsin":25.53,"baromrelin":29.82,"hourlyrainin":0,"dailyrainin":0.37,"weeklyrainin":0.39,"monthlyrainin":1.18,"yearlyrainin":4.04,"solarradiation":533.87,"uv":9,"feelsLike":43.3,"dewPoint":33.82,"feelsLikein":71.2,"dewPointin":51.2,"lastRain":"2020-03-25T16:44:00.000Z","deviceId":"5a8118371f451f00045d1e5b","tz":"America/Denver","date":"2020-03-25T20:28:00.000Z"},"info":{"name":"PWS - 3458 S 500 E","location":"Home","coords":{"coords":{"lat":X,"lon":-Y},"address":"3458 500 E, South Salt Lake, UT 84106, USA","location":"South Salt Lake","elevation":"1305","geo":{"type":"Point","coordinates":[-X,Y]}}},"apiKey":"REDACTED"}],"method":"subscribe"}]
2020-03-25 14:29:04 INFO (MainThread) [socketio.client] Received event "subscribed" [/]
2020-03-25 14:29:29 INFO (MainThread) [engineio.client] Sending packet PING data None
2020-03-25 14:29:29 INFO (MainThread) [engineio.client] Received packet PONG data None
2020-03-25 14:29:38 INFO (MainThread) [engineio.client] Received packet MESSAGE data 2["data",{"dateutc":1585168140000,"tempinf":72,"tempf":43.3,"humidityin":48,"humidity":68,"windspeedmph":4,"windgustmph":7.4,"maxdailygust":24.8,"winddir":96,"baromabsin":25.53,"baromrelin":29.82,"hourlyrainin":0,"dailyrainin":0.37,"weeklyrainin":0.39,"monthlyrainin":1.18,"yearlyrainin":4.04,"solarradiation":540.31,"uv":9,"feelsLike":41.13,"dewPoint":33.46,"feelsLikein":71.2,"dewPointin":51.2,"lastRain":"2020-03-25T16:44:00.000Z","tz":"America/Denver","date":"2020-03-25T20:29:00.000Z","macAddress":"C0:21:0D:1F:08:9C"}]
2020-03-25 14:29:38 INFO (MainThread) [socketio.client] Received event "data" [/]
2020-03-25 14:29:54 INFO (MainThread) [engineio.client] Sending packet PING data None
2020-03-25 14:29:54 INFO (MainThread) [engineio.client] Received packet PONG data None

igloo15 commented 4 years ago

Ambient weather is having issues on their side which might be causing the issues here. I know my dashboard on ambient is showing data missing at regular intervals. Additionally there is a banner on the dashboard saying they are having database issues and are working with IBM to fix.

grantalewis commented 4 years ago

Ambient weather is having issues on their side

Interesting. This morning, although it would load in Chrome, I was getting a blank Ambient Dashboard page in Firefox. Everything was fine after I completely reset FF, but now I’m wondering if the problem wasn’t on my end at all.

bachya commented 4 years ago

Mine has gone offline again – no indication that the watchdog has failed: it just looks like data isn’t coming through. I see the same banner that @igloo15 mentions. Unfortunately, we’ll have to wait and see.

igloo15 commented 4 years ago

Regardless of ambient weather there is definitely a bug in home assistant because it does not seem to be able to reconnect.

Ambient Weather is having outages that is causing the websocket connection to drop but I feel like Home Assistant should be able to reconnect without restarting.

bachya commented 4 years ago

That isn’t necessarily accurate. I just witnessed my Ambient reconnect without a HASS restart. I can’t speak to how their websocket infrastructure is set up, but it’s not unreasonable that the connection pool might be flaky during a database outage.

The fact is that as long as they have database issues – especially after this integration was working fine for so long – there’s a variable in the equation that we can’t control.

Codelica commented 4 years ago

Seeing similar to @igloo15 in that my install will log data for a while after startup, then stop receiving data until HA is restarted. I haven't seen it restart data on its own (after waiting for 10+ hours), but it definitely does after a restart of HA.

Here is a few mins ago with it stalled and no active socket connection to ambientweather.net (checked with netstat):

Home Assistant 2020-03-26 00-37-46

Then I just restarted:

Home Assistant 2020-03-26 00-52-26

And netstat now shows an active connection:

tcp 0 0 jade.moonshine:34918 104.31.82.184:https ESTABLISHED

Perhaps their recent problems are just exposing some connect/re-connect issue. I don't mind helping to test, given instructions. Love the integration. 👍

fancygaphtrn commented 4 years ago

FWIW, this is my environment

arch	x86_64
dev	false
docker	false
hassio	false
os_name	Linux
os_version	4.19.0-6-amd64
python_version	3.7.3
timezone	America/New_York
version	0.107.5
virtualenv	true

Getting the same log errors as everyone else, but pasting anyway. I am also glad to help in diag/testing. Also am setting to debug this way. Will post back if logging give more insite.

logger:
  default: info
  logs:
    homeassistant.components.ambient_station: debug

2020-03-25 08:53:56 INFO (MainThread) [engineio.client] Sending packet MESSAGE data 1
2020-03-25 08:53:56 INFO (MainThread) [engineio.client] Sending packet CLOSE data None
2020-03-25 08:53:56 INFO (MainThread) [socketio.client] Engine.IO connection dropped
2020-03-25 08:53:56 INFO (MainThread) [engineio.client] Attempting WebSocket connection to wss://dash2.ambientweather.net/socket.io/?api=1&applicationKey=redacted&transport=websocket&EIO=3
2020-03-25 08:53:56 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.7/site-packages/homeassistant/components/ambient_station/__init__.py", line 366, in _ws_reconnect
    await self._attempt_connect()
  File "/srv/homeassistant/lib/python3.7/site-packages/homeassistant/components/ambient_station/__init__.py", line 353, in _attempt_connect
    await self.client.websocket.connect()
  File "/srv/homeassistant/lib/python3.7/site-packages/aioambient/websocket.py", line 76, in connect
    transports=["websocket"],
  File "/srv/homeassistant/lib/python3.7/site-packages/socketio/asyncio_client.py", line 108, in connect
    engineio_path=socketio_path)
  File "/srv/homeassistant/lib/python3.7/site-packages/engineio/asyncio_client.py", line 76, in connect
    url, headers, engineio_path)
  File "/srv/homeassistant/lib/python3.7/site-packages/engineio/asyncio_client.py", line 256, in _connect_websocket
    headers=headers)
  File "/srv/homeassistant/lib/python3.7/site-packages/aiohttp/client.py", line 728, in _ws_connect
    proxy_headers=proxy_headers)
  File "/srv/homeassistant/lib/python3.7/site-packages/aiohttp/client.py", line 483, in _request
    timeout=real_timeout
  File "/srv/homeassistant/lib/python3.7/site-packages/aiohttp/connector.py", line 526, in connect
    raise ClientConnectionError("Connector is closed.")
aiohttp.client_exceptions.ClientConnectionError: Connector is closed.

fancygaphtrn commented 4 years ago

Today it had an error and recover once Here is the debug logs of the recovery. socketio does the recovery it appears. Then I got the hard error.

It appears to me that the watchdog kicks in before the socketio can reopen the websocket.

Recovered:

2020-03-26 14:18:23 INFO (MainThread) [engineio.client] Sending packet PING data None
2020-03-26 14:18:23 INFO (MainThread) [engineio.client] Received packet PONG data None
2020-03-26 14:18:48 INFO (MainThread) [engineio.client] Sending packet PING data None
2020-03-26 14:19:04 INFO (MainThread) [engineio.client] Unexpected error "WebSocket read returned None", aborting
2020-03-26 14:19:04 INFO (MainThread) [engineio.client] Waiting for write loop task to end
2020-03-26 14:19:04 INFO (MainThread) [engineio.client] Exiting write loop task
2020-03-26 14:19:04 INFO (MainThread) [engineio.client] Waiting for ping loop task to end
2020-03-26 14:19:04 INFO (MainThread) [engineio.client] PONG response has not been received, aborting
2020-03-26 14:19:04 INFO (MainThread) [engineio.client] Exiting ping task
2020-03-26 14:19:04 INFO (MainThread) [socketio.client] Engine.IO connection dropped
2020-03-26 14:19:04 INFO (MainThread) [custom_components.ambient_station] Disconnected from websocket
2020-03-26 14:19:04 INFO (MainThread) [engineio.client] Exiting read loop task
2020-03-26 14:19:04 INFO (MainThread) [socketio.client] Connection failed, new attempt in 1.35 seconds
2020-03-26 14:19:06 INFO (MainThread) [engineio.client] Attempting WebSocket connection to wss://dash2.ambientweather.net/socket.io/?api=1&applicationKey=redacted&transport=websocket&EIO=3
2020-03-26 14:19:07 INFO (MainThread) [engineio.client] WebSocket connection accepted with {'sid': '8uJfnJnlP1lAsZSeAdJd', 'upgrades': [], 'pingInterval': 25000, 'pingTimeout': 60000}
2020-03-26 14:19:07 INFO (MainThread) [socketio.client] Engine.IO connection established
2020-03-26 14:19:07 INFO (MainThread) [socketio.client] Reconnection successful
2020-03-26 14:19:07 INFO (MainThread) [engineio.client] Sending packet PING data None
2020-03-26 14:19:07 INFO (MainThread) [engineio.client] Received packet MESSAGE data 0
2020-03-26 14:19:07 INFO (MainThread) [socketio.client] Namespace / is connected
2020-03-26 14:19:07 INFO (MainThread) [socketio.client] Emitting event "subscribe" [/]
2020-03-26 14:19:07 INFO (MainThread) [engineio.client] Sending packet MESSAGE data 2["subscribe",{"apiKeys":["redacted"]}]
2020-03-26 14:19:07 INFO (MainThread) [custom_components.ambient_station] Connected to websocket
2020-03-26 14:19:07 DEBUG (MainThread) [custom_components.ambient_station] Watchdog starting
2020-03-26 14:19:07 INFO (MainThread) [engineio.client] Received packet PONG data None
2020-03-26 14:19:07 INFO (MainThread) [engineio.client] Received packet MESSAGE data 2["subscribed",{"devices":[{"macAddress":"80:7D:3A:7C:1D:5E","lastData":{"dateutc":1585246680000,"winddir":338,"windspeedmph":2.5,"windgustmph":3.4,"maxdailygust":11.4,"tempf":45.9,"hourlyrainin":0,"eventrainin":0,"dailyrainin":0.01,"weeklyrainin":1.49,"monthlyrainin":3.27,"totalrainin":69.99,"baromrelin":30.3,"baromabsin":27.39,"humidity":99,"tempinf":67.3,"humidityin":53,"uv":1,"solarradiation":134.44,"feelsLike":45.9,"dewPoint":45.63,"feelsLikein":67.3,"dewPointin":49.6,"lastRain":"2020-03-26T13:27:00.000Z","deviceId":"5c9ba066b4458b494561f268","tz":"America/New_York","date":"2020-03-26T18:18:00.000Z"},"info":{"name":"Fancy Gap","location":"Home","coords":{"coords":{"lat":36.71275712719849,"lon":-80.71363942229004},"address":"1482 Walton Branscome Rd, Hillsville, VA 24343, USA","location":"Hillsville","elevation":782.1527099609375,"geo":{"type":"Point","coordinates":[-80.71363942229004,36.71275712719849]}}},"apiKey":"redacted"}],"method":"subscribe"}]
2020-03-26 14:19:07 INFO (MainThread) [socketio.client] Received event "subscribed" [/]
2020-03-26 14:19:32 INFO (MainThread) [engineio.client] Sending packet PING data None
2020-03-26 14:19:32 INFO (MainThread) [engineio.client] Received packet PONG data None
2020-03-26 14:19:55 INFO (MainThread) [engineio.client] Received packet MESSAGE data 2["data",{"dateutc":1585246740000,"winddir":88,"windspeedmph":2.2,"windgustmph":3.4,"maxdailygust":11.4,"tempf":46,"hourlyrainin":0,"eventrainin":0,"dailyrainin":0.01,"weeklyrainin":1.49,"monthlyrainin":3.27,"totalrainin":69.99,"baromrelin":30.3,"baromabsin":27.4,"humidity":99,"tempinf":67.5,"humidityin":53,"uv":1,"solarradiation":133.1,"feelsLike":46,"dewPoint":45.73,"feelsLikein":67.5,"dewPointin":49.8,"lastRain":"2020-03-26T13:27:00.000Z","tz":"America/New_York","date":"2020-03-26T18:19:00.000Z","macAddress":"80:7D:3A:7C:1D:5E"}]
2020-03-26 14:19:55 INFO (MainThread) [socketio.client] Received event "data" [/]
2020-03-26 14:19:55 DEBUG (MainThread) [custom_components.ambient_station] New data received: {'dateutc': 1585246740000, 'winddir': 88, 'windspeedmph': 2.2, 'windgustmph': 3.4, 'maxdailygust': 11.4, 'tempf': 46, 'hourlyrainin': 0, 'eventrainin': 0, 'dailyrainin': 0.01, 'weeklyrainin': 1.49, 'monthlyrainin': 3.27, 'totalrainin': 69.99, 'baromrelin': 30.3, 'baromabsin': 27.4, 'humidity': 99, 'tempinf': 67.5, 'humidityin': 53, 'uv': 1, 'solarradiation': 133.1, 'feelsLike': 46, 'dewPoint': 45.73, 'feelsLikein': 67.5, 'dewPointin': 49.8, 'lastRain': '2020-03-26T13:27:00.000Z', 'tz': 'America/New_York', 'date': '2020-03-26T18:19:00.000Z', 'macAddress': '80:7D:3A:7C:1D:5E'}
2020-03-26 14:19:55 DEBUG (MainThread) [custom_components.ambient_station] Resetting watchdog
2020-03-26 14:19:57 INFO (MainThread) [engineio.client] Sending packet PING data None
2020-03-26 14:19:57 INFO (MainThread) [engineio.client] Received packet PONG data None

Then later it is the hard failure:

2020-03-26 14:35:47 INFO (MainThread) [engineio.client] Sending packet PING data None
2020-03-26 14:36:12 INFO (MainThread) [engineio.client] PONG response has not been received, aborting
2020-03-26 14:36:12 INFO (MainThread) [engineio.client] Exiting ping task
2020-03-26 14:36:12 INFO (MainThread) [engineio.client] Exiting write loop task

2020-03-26 14:39:55 DEBUG (MainThread) [custom_components.ambient_station] Watchdog expired; forcing socket reconnection
2020-03-26 14:39:55 INFO (MainThread) [engineio.client] Sending packet MESSAGE data 1
2020-03-26 14:39:55 INFO (MainThread) [engineio.client] Sending packet CLOSE data None
2020-03-26 14:39:55 INFO (MainThread) [socketio.client] Engine.IO connection dropped
2020-03-26 14:39:55 INFO (MainThread) [engineio.client] Attempting WebSocket connection to wss://dash2.ambientweather.net/socket.io/?api=1&applicationKey=redacted&transport=websocket&EIO=3
2020-03-26 14:39:55 ERROR (MainThread) [homeassistant.core] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/home/homeassistant/.homeassistant/custom_components/ambient_station/__init__.py", line 366, in _ws_reconnect
    await self._attempt_connect()
  File "/home/homeassistant/.homeassistant/custom_components/ambient_station/__init__.py", line 353, in _attempt_connect
    await self.client.websocket.connect()
  File "/srv/homeassistant/lib/python3.7/site-packages/aioambient/websocket.py", line 76, in connect
    transports=["websocket"],
  File "/srv/homeassistant/lib/python3.7/site-packages/socketio/asyncio_client.py", line 108, in connect
    engineio_path=socketio_path)
  File "/srv/homeassistant/lib/python3.7/site-packages/engineio/asyncio_client.py", line 76, in connect
    url, headers, engineio_path)
  File "/srv/homeassistant/lib/python3.7/site-packages/engineio/asyncio_client.py", line 256, in _connect_websocket
    headers=headers)
  File "/srv/homeassistant/lib/python3.7/site-packages/aiohttp/client.py", line 728, in _ws_connect
    proxy_headers=proxy_headers)
  File "/srv/homeassistant/lib/python3.7/site-packages/aiohttp/client.py", line 483, in _request
    timeout=real_timeout
  File "/srv/homeassistant/lib/python3.7/site-packages/aiohttp/connector.py", line 526, in connect
    raise ClientConnectionError("Connector is closed.")
aiohttp.client_exceptions.ClientConnectionError: Connector is closed.

bachya commented 4 years ago

How's everyone looking today? I haven't had data loss in a while:

Screen Shot 2020-03-27 at 10 58 15 AM

grantalewis commented 4 years ago

I've been doing lots of tinkering/restarting today (tweaks not related to Ambient) and so Ambient has had plenty of opportunities to reset itself from any earlier problems. But still seeing errors:


2020-03-27 12:10:22 WARNING (MainThread) [aiohttp.websocket] websocket connection is closing.
2020-03-27 12:10:22 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.

psperry commented 4 years ago

I've had two disconnects.

garyak commented 4 years ago

temp

jeffkjolley commented 4 years ago

Same. I had an unrecoverable disconnect happen sometime last night.

bachya commented 4 years ago

@psperry and @garyak: Did your disconnects resolve themselves, or did you need to restart HASS?

psperry commented 4 years ago

The first one did not. The second on happened while I was doing some other work and was resolved by reboot.

garyak commented 4 years ago

I waited six hours to see if it would self-resolve, it did not so I restarted HA.

bachya commented 4 years ago

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.

bachya commented 4 years ago

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.

psperry commented 4 years ago

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!

etymotic commented 4 years ago

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

grantalewis commented 4 years ago

Sorry to be thick-headed, but what's the best way to download the folder? I don't see a link like "download .zip", etc.

home-assistant / core