ZWave light service calls never timeout when entities go to Unavailable with turn_off service #98491
Assignees
Comments
|
Thank you for the excellent issue report. I think this is a duplicate of #98073 so we can track there, and we may have a root cause identified. |
allenporter
changed the title
|
Hey there @home-assistant/z-wave, mind taking a look at this issue as it has been labeled with an integration ( Code owner commandsCode owners of
(message by CodeOwnersMention) zwave_js documentation |
|
Some context in #98073 (comment) and PR #98501 |
|
@iDontWantAUsername can you confirm a couple things:
|
|
@raman325 i know you were asking for cases related to z-wave so thought I would flag to you. i asked for some detail about, but feel free to correct me if that isn't the right set of detail. |
|
I've been away and am going away again but have turned on extra logging and will see if I can see a case happen. It doesn't happen often and is sporadic. |
|
Documenting my testing with a test script which turns off a ZWave light and then sends me a notification. I did one case which resulted in a test script stalling, however i didn't have full logging on then. Then in ZWaveJS logs: I haven't seen this error before - it seems like it is semi handled in HA on this occasion - with the script stopping, i assume in this case if i had ZWaveJS: HA: 2023.8.2 |
|
I got a few more cases of the above error so then I turned OFF ZwaveJS debug logging and now i have seen an instance of the error where the node goes Dead BUT ZWaveJS does not respond with a handled error as above, the script is still stuck running 30 minutes later even though the ZWave node is alive again): EDIT: For competness here is a subsequent trace showing that the script it stuck in a running state: I haven't tested with Automations but i am going to assume the same applies as they are just automatically run script which can't be stopped with another service. It looks like there is a a defect where with DebugLogging ON the error with a node going to Unavailable is handled but when DebugLogging is OFF the error is not handled correctly. The HA logbook shows the status of the node changing although i am not sure how accurate the granularity of this is: In the HA logs i saw instances of this with ZWaveJS Debug logging on, however none of these errors (including the Script error) pulled through to HA when the ZWaveJS debug Logging was turned off. Does this help at all? Are there any other specific logs that would help which might not interfere with the error that is happening? |
|
thanks for putting this together! I am still reviewing everything but it's extremely helpful to have a thread that's just focused on Z-Wave. And yes, this is helpful! |
|
So, some questions (editing but sharing there are more coming in case you are attempting to respond):
|
I was turning Debug Logging on an off via the ZWaveJS server: Using Start and Stop here: This seemed to result in more logging in the HA logs as well as in the logging window here.
When DebugLogging is ON (as above) i get a handled error in the Script trace, i.e. In this (first) trace with DebugLogging ON the trace shows that it stopped and went to an errored state due to the state going to unavailable. However when i had DebugLogging OFF (i.e. no logs in ZWaveJS server) the Script just hung in a running state. I hope that is clearer - i can't test now as the lights are in use and probably won't be able to test for a weeks or so as i will be away. |
|
yes that helps clarify what your intent was. That's odd but that may also be the root cause for some of this I guess? |
|
It seems to be a cause perhaps not the whole issue though. |
I checked the Z-Wave JS UI source code, and if I'm not mistaken, all that does is change a variable in the frontend, whether log events should be added to that textbox or not. Does your issue reproduce if you have logging to file enabled? If so, you can trigger the problem and then share the logfile. |
With log to file enabled the Script in HA hangs, here is the output from the zwaveJS log file Node 018 is the one the script runs on, the HA trace has a timestamp of 00:55:43Z and is stuck in a still running state. I am not able to replicate the handled Script error i saw when the node went to Unavailable now - this may have just been a red-herring or perhaps having Debug Logging ON caused a slight delay in processing on my server which allowed the Unavailable response to be returned to the script. The server has had a reboot and update since then with all docker containers restarted so it could have sped things up slightly. It looks like a fix has been committed - unfortunately i won't be able to test this promptly as i won't be home for a bit. |
|
Some observations from that log:
|
|
Update: I can reproduce in a test case. The good news is that zwave-js/node-zwave-js#6219 does fix this issue, so it's just a matter of updating now. |
|
Thank you. I'll update to 11.13.1+ as soon as possible For point 3; thanks for pointing this out, the node was set to update all reports every 30 seconds. I've corrected this to 5 minutes for a subset like the rest of my devices. I'll test this properly when I return in just over a week. If you are happy we can probably close this ticket as the underlying issue should be fixed. |
|
I have been able to test on 11.14.0, it seems that the handled error because the node goes to Unavailable is working and the Automation/Script does not get stuck in a running state. The Script is stopped due to the ZwaveJS returning the error as expected. Using Thanks for your help with this. |
Sign up for free
to subscribe to this conversation on GitHub.
Already have an account?
Sign in.
The problem
If an automation or script issues a
turn_offe.g.light turn_off,switch.turn_offand the target entity doesn't go tooffbut goes toUnavailablethen the script/automation hangs in a running state. A script can only be stopped by ascript.turn_offor a change and automation can only be reset but a reload or updating the automation.What version of Home Assistant Core has the issue?
2023.8.2
What was the last working version of Home Assistant Core?
No response
What type of installation are you running?
Home Assistant Container
Integration causing the issue
Automations/Scripts
Link to integration documentation on our website
No response
Diagnostics information
No response
Example YAML snippet
Anything in the logs that might be useful for us?
Additional information
I don't have any hard evidence of this but I believe this was working pre 2023.5/6 the zwave light that goes to Unavailable has done this for a while and I have other lights which are WiFi on switches which get accidentally turned off and I haven't had an issue with a Good Night script or the driveway lights automation above freezing up until around 2023.7
See some screenshots of the case when a script is stuck and the next case can't run(this is for my good night script):
The text was updated successfully, but these errors were encountered: