home-assistant / core

:house_with_garden: Open source home automation that puts local control and privacy first.
https://www.home-assistant.io
Apache License 2.0
72.17k stars 30.2k forks source link

Z-Wave JS Unable To Connect Error #68741

Closed Spiffieman closed 2 years ago

Spiffieman commented 2 years ago

The problem

Hi there - I have experienced a couple of times where I had a power outage (with the HASS NUC still running on UPS) but when the power comes back on (and all of my z-wave switches, etc. also come back online) that I get this below error and I cannot obviously control any of my z-wave devices. Using a Zooz ZST10 for my controller.

Logger: homeassistant.components.zwave_js Source: components/zwave_js/init.py:505 Integration: Z-Wave JS (documentation, issues) First occurred: March 26, 2022, 05:05:51 (4 occurrences) Last logged: March 26, 2022, 07:55:05

Failed to connect: Cannot connect to host core-zwave-js:3000 ssl:default [Connect call failed ('172.30.33.2', 3000)]

I tried to fix the error by restarting HASS from the Configuration/Server controls page but the only thing that really fixes it is after I do a HASS restart I have to restart the Z-Wave JS add-on.

My Z-Wave JS logs do not go back far enough to grab any errors from what I can tell, unless there is a better place to check?

What version of Home Assistant Core has the issue?

core-2022.3.5

What was the last working version of Home Assistant Core?

No response

What type of installation are you running?

Home Assistant OS

Integration causing the issue

Z-Wave JS

Link to integration documentation on our website

https://www.home-assistant.io/integrations/zwave_js/

Diagnostics information

config_entry-zwave_js-ca0cc7e5bb7fb141a0f6033c2ba32a4d.json.txt

Example YAML snippet

No response

Anything in the logs that might be useful for us?

No response

Additional information

No response

probot-home-assistant[bot] commented 2 years ago

Hey there @home-assistant/z-wave, mind taking a look at this issue as it has been labeled with an integration (zwave_js) you are listed as a code owner for? Thanks! (message by CodeOwnersMention)


zwave_js documentation zwave_js source (message by IssueLinks)

MartinHjelmare commented 2 years ago

You can check the add-on logs when it happens.

Sounds like a possible hardware issue with insufficient/bad power to the USB controller when running or switching to/from UPS which could cause the driver to error and the add-on to fail. But would be good to see the add-on logs to know more.

Spiffieman commented 2 years ago

What is the best way to get those particular logs? In the ui, the add-on logs only go back so far.

On Sun, Mar 27, 2022, 11:55 Martin Hjelmare @.***> wrote:

You can check the add-on logs when it happens.

Sounds like a possible hardware issue with insufficient/bad power to the USB controller when running or switching to/from UPS which could cause the driver to error and the add-on to fail. But would be good to see the add-on logs to know more.

— Reply to this email directly, view it on GitHub https://github.com/home-assistant/core/issues/68741#issuecomment-1079959093, or unsubscribe https://github.com/notifications/unsubscribe-auth/ASH5EGPACXHGGLND6OXLJYTVCCHG7ANCNFSM5RY3RGMQ . You are receiving this because you authored the thread.Message ID: @.***>

MartinHjelmare commented 2 years ago

It's best to check the logs just after it happens.

andershelmerqlik commented 2 years ago

Just got the same symptom. I got the problem after upgrading to 0.1.56 What I can find in the logs:

2022-04-19 19:29:05 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [548316277632] Error handling message: Unknown error (unknown_error)
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/websocket_api/decorators.py", line 27, in _handle_async_response
    await func(hass, connection, msg)
  File "/usr/src/homeassistant/homeassistant/components/recorder/websocket_api.py", line 86, in ws_get_statistics_metadata
    statistic_ids = await instance.async_add_executor_job(
  File "/usr/local/lib/python3.9/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/src/homeassistant/homeassistant/components/recorder/statistics.py", line 814, in list_statistic_ids
    for platform in hass.data[DOMAIN].values():
RuntimeError: dictionary changed size during iteration
2022-04-19 19:29:09 ERROR (MainThread) [homeassistant.components.websocket_api.http.connection] [548316277632] Error handling message: Unknown error (unknown_error)
Traceback (most recent call last):
  File "/usr/src/homeassistant/homeassistant/components/websocket_api/decorators.py", line 27, in _handle_async_response
    await func(hass, connection, msg)
  File "/usr/src/homeassistant/homeassistant/components/recorder/websocket_api.py", line 86, in ws_get_statistics_metadata
    statistic_ids = await instance.async_add_executor_job(
  File "/usr/local/lib/python3.9/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/usr/src/homeassistant/homeassistant/components/recorder/statistics.py", line 814, in list_statistic_ids
    for platform in hass.data[DOMAIN].values():
RuntimeError: dictionary changed size during iteration
2022-04-19 19:34:39 ERROR (MainThread) [graphql_subscription_manager] No data, reconnecting.
2022-04-19 20:00:18 ERROR (MainThread) [homeassistant.components.zwave_js] Failed to connect: Cannot connect to host core-zwave-js:3000 ssl:default [Connect call failed ('172.30.33.4', 3000)]
2022-04-19 20:00:18 WARNING (MainThread) [homeassistant.config_entries] Config entry 'Z-Wave JS' for zwave_js integration not ready yet: Cannot connect to host core-zwave-js:3000 ssl:default [Connect call failed ('172.30.33.4', 3000)]; Retrying in background
MartinHjelmare commented 2 years ago

What does the add-on log say?

andershelmerqlik commented 2 years ago
                                protocol type:             Z-Wave
                                protocol version:          4.54.0

2022-04-19T18:00:34.398Z CNTRLR supported Z-Wave features: 2022-04-19T18:00:34.399Z CNTRLR querying controller capabilities... 2022-04-19T18:00:34.474Z CNTRLR received controller capabilities: controller role: primary is in other network: false is SIS present: true was real primary: true is a SUC: true 2022-04-19T18:00:34.475Z CNTRLR finding SUC... 2022-04-19T18:00:34.514Z CNTRLR This is the SUC 2022-04-19T18:00:34.515Z CNTRLR querying node information... 2022-04-19T18:00:34.645Z CNTRLR received node information: controller role: primary controller is a SUC: true controller is a slave: false controller supports timers: false nodes in the network: 1, 4, 6, 11, 17 2022-04-19T18:00:34.808Z CNTRLR [Node 001] Embedded device config loaded 2022-04-19T18:00:34.832Z CNTRLR [Node 004] Embedded device config loaded 2022-04-19T18:00:34.848Z CNTRLR [Node 006] Embedded device config loaded 2022-04-19T18:00:34.881Z CNTRLR [Node 011] Embedded device config loaded 2022-04-19T18:00:34.907Z CNTRLR [Node 017] Embedded device config loaded 2022-04-19T18:00:34.939Z CNTRLR setting serial API timeouts: ack = 1000 ms, byte = 150 ms 2022-04-19T18:00:34.966Z CNTRLR serial API timeouts overwritten. The old values were: ack = 1000 ms, byte = 15 0 ms 2022-04-19T18:00:34.967Z CNTRLR Interview completed Starting server on 0.0.0.0:3000 2022-04-19T18:00:35.005Z CNTRLR [Node 001] The node is alive. 2022-04-19T18:00:35.008Z CNTRLR [Node 001] The node is ready to be used 2022-04-19T18:00:35.011Z CNTRLR [Node 004] The node is asleep. 2022-04-19T18:00:35.018Z CNTRLR [Node 004] Beginning interview - last completed stage: ProtocolInfo 2022-04-19T18:00:35.021Z CNTRLR » [Node 004] querying node info... 2022-04-19T18:00:35.242Z CNTRLR [Node 006] The node is asleep. 2022-04-19T18:00:35.245Z CNTRLR [Node 006] The node is ready to be used 2022-04-19T18:00:35.247Z CNTRLR » [Node 011] pinging the node... 2022-04-19T18:00:35.317Z CNTRLR » [Node 017] pinging the node... ZwaveJS server listening on 0.0.0.0:3000 2022-04-19T18:00:35.360Z CNTRLR [Node 011] The node is alive. 2022-04-19T18:00:35.361Z CNTRLR [Node 011] The node is ready to be used 2022-04-19T18:00:35.369Z CNTRLR « [Node 011] ping successful 2022-04-19T18:00:35.428Z CNTRLR [Node 017] The node is alive. 2022-04-19T18:00:35.430Z CNTRLR [Node 017] The node is ready to be used 2022-04-19T18:00:35.434Z CNTRLR « [Node 017] ping successful New client Client disconnected Code 1000: New client Starting logging event forwarder at info level Stopping logging event forwarder Starting logging event forwarder at info level Stopping logging event forwarder 2022-04-19T18:07:57.650Z CNTRLR « [Node 004] received wakeup notification 2022-04-19T18:07:57.653Z CNTRLR [Node 004] The node is now awake. 2022-04-19T18:07:57.809Z CNTRLR « [Node 004] node info received supported CCs: · Z-Wave Plus Info · Supervision · Transport Service · Security · Security 2 controlled CCs: 2022-04-19T18:07:57.817Z CNTRLR [Node 004] Interview stage completed: NodeInfo 2022-04-19T18:07:57.825Z CNTRLR » [Node 004] Querying securely supported commands (S0)... 2022-04-19T18:07:58.988Z CNTRLR [Node 004] Timed out while waiting for a response from the node (ZW0201) 2022-04-19T18:07:58.989Z CNTRLR [Node 004] The node was not granted the S0 security class. Continuing intervie w non-securely. 2022-04-19T18:07:59.000Z CNTRLR [Node 004] Interview stage completed: CommandClasses 2022-04-19T18:07:59.002Z CNTRLR [Node 004] Interview stage completed: OverwriteConfig 2022-04-19T18:07:59.004Z CNTRLR [Node 004] Interview completed 2022-04-19T18:07:59.005Z CNTRLR [Node 004] The node is ready to be used 2022-04-19T18:07:59.007Z CNTRLR All nodes are ready to be used 2022-04-19T18:07:59.166Z CNTRLR » [Node 004] Assigning SUC return route... 2022-04-19T18:08:00.569Z CNTRLR » [Node 004] Sending node back to sleep... 2022-04-19T18:08:00.659Z CNTRLR [Node 004] The node is now asleep. 2022-04-19T18:51:02.905Z DRIVER Dropping message with invalid payload 2022-04-19T18:56:20.164Z CNTRLR [Node 004] Healing node... 2022-04-19T18:56:20.170Z CNTRLR [Node 004] healing node... 2022-04-19T18:56:20.171Z CNTRLR » [Node 004] refreshing neighbor list (attempt 1)... 2022-04-19T18:57:13.169Z CNTRLR » [Node 006] pinging the node... 2022-04-19T18:57:18.353Z CNTRLR [Node 006] The node did not respond after 1 attempts. It is probably asleep, m oving its messages to the wakeup queue. 2022-04-19T18:57:18.360Z CNTRLR [Node 006] ping failed: Failed to send the command after 1 attempts (Status No Ack) (ZW0204) Client disconnected Code 1000: New client Client disconnected Code 1000: New client New client Client disconnected Code 1000: 2022-04-19T19:34:03.884Z DRIVER Dropping message with invalid payload 2022-04-19T19:47:03.715Z DRIVER Dropping message with invalid payload 2022-04-19T19:58:20.181Z CNTRLR « [Node 006] received wakeup notification 2022-04-19T19:58:20.189Z CNTRLR [Node 006] The node is now awake. 2022-04-19T19:58:21.194Z CNTRLR » [Node 006] Sending node back to sleep... 2022-04-19T19:58:21.275Z CNTRLR [Node 006] The node is now asleep.

andershelmerqlik commented 2 years ago

The node with temperature and humidity sensors report those but not motion.

MartinHjelmare commented 2 years ago

@andershelmerqlik Does the integration connect to the zwave-js-server after a while again or does it never reconnect? When upgrading the add-on it's normal to see one failed connection error as the server is shutdown when upgrading the add-on.

andershelmerqlik commented 2 years ago

Well from what I can see the nodes are alive and sleeping. But the motion sensors are "unavailable" temperature and humidity are available, that are on the same node, so it seems that there are some connection to the server.
Is this "ZwaveJS server listening on 0.0.0.0:3000" really correct?

MartinHjelmare commented 2 years ago

From the point of view of the server I think it's correct.

andershelmerqlik commented 2 years ago

Isn't "2022-04-19T18:07:58.989Z CNTRLR [Node 004] The node was not granted the S0 security class. Continuing intervie w non-securely." a clue. Something with 0.1.56 made secure inclusion stop working.

MartinHjelmare commented 2 years ago

That's not what this issue is about. This issue is older than the Z-Wave JS add-on version 0.1.56. Please open a separate issue if you think there's a problem with the changes made in 0.1.56 of the add-on.

andershelmerqlik commented 2 years ago

https://github.com/home-assistant/core/issues/70866

github-actions[bot] commented 2 years ago

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates. Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍 This issue has now been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.