Group of 8 Z-TRM2 modes sometimes only updates part of the group

(2.4.0-SNAPSHOT Build #1344, Z-Wave dev binding 27. Aug)

I’m preparing for the arrival of differentiated time-of-day power tariff here in Norway.
8 Z-Wave floor thermostats are installed and now I’m testing changing their modes between Off, Heat and ECO.

Have defined the following group:

Group:Number hvacMode

The following items are part of this group:

Number HVAC1Mode (hvacMode) { channel = “zwave:device:f180343d:node85:thermostat_mode” }
Number HVAC2Mode (hvacMode) { channel = “zwave:device:f180343d:node88:thermostat_mode” }
Number HVAC3Mode (hvacMode) { channel = “zwave:device:f180343d:node90:thermostat_mode” }
Number HVAC4Mode (hvacMode) { channel = “zwave:device:f180343d:node94:thermostat_mode” }
Number HVAC5Mode (hvacMode) { channel = “zwave:device:f180343d:node95:thermostat_mode” }
Number HVAC6Mode (hvacMode) { channel = “zwave:device:f180343d:node96:thermostat_mode” }
Number HVAC7Mode (hvacMode) { channel = “zwave:device:f180343d:node97:thermostat_mode” }
Number HVAC8Mode (hvacMode) { channel = “zwave:device:f180343d:node98:thermostat_mode” }

Sitemap:

Frame label="Floors Settings" {
Switch item=hvacMode mappings=["0"="Off", "1"="Heat", "11"="ECO"] label="HVAC Mode"
}

Rule: (for monitoring)

rule 'HVACMode'
when Item hvacMode changed
then
    logInfo(name12, "Update: hvacMode triggerd by " + triggeringItem.name)
    hvacMode.allMembers.forEach[i|
    logInfo(name12, i.name +"=" + i.state)        
    ]
end

Every HVAC has a rule like this as well:

rule 'HVAC1Mode'
when
    Item HVAC1Mode changed
then
    logInfo(name1, "Update: HVAC1Mode=" + HVAC1Mode.state)
end      

log:

2018-09-02 20:57:02.477 [INFO ] [smarthome.model.script.HVAC:Bad oppe] - Update: HVAC1Mode=0
2018-09-02 20:57:02.479 [INFO ] [pse.smarthome.model.script.HVAC:Mode] - Update: hvacMode triggerd by hvacMode
2018-09-02 20:57:02.481 [INFO ] [pse.smarthome.model.script.HVAC:Mode] - HVAC7Mode=1
2018-09-02 20:57:02.481 [INFO ] [pse.smarthome.model.script.HVAC:Mode] - HVAC6Mode=1
2018-09-02 20:57:02.482 [INFO ] [pse.smarthome.model.script.HVAC:Mode] - HVAC3Mode=1
2018-09-02 20:57:02.483 [INFO ] [pse.smarthome.model.script.HVAC:Mode] - HVAC1Mode=0
2018-09-02 20:57:02.484 [INFO ] [pse.smarthome.model.script.HVAC:Mode] - HVAC2Mode=1
2018-09-02 20:57:02.484 [INFO ] [pse.smarthome.model.script.HVAC:Mode] - HVAC4Mode=1
2018-09-02 20:57:02.485 [INFO ] [pse.smarthome.model.script.HVAC:Mode] - HVAC5Mode=1
2018-09-02 20:57:02.486 [INFO ] [pse.smarthome.model.script.HVAC:Mode] - HVAC8Mode=1

This logs shows that hvac1 does not change state from Off th Heat (0->1).
Also verified on device. Display is dark.
This happens in about 1 of 5 attempts.

@chris Any ideas?

Does the change come from a manualy change over the sitemap?
It seem to come from the zwave-device.

Do you use OH2.3+? There’s a neat new way to cope with changes of items within a group:
Member of hvacMode changed

see https://www.openhab.org/docs/configuration/rules-dsl.html#member-of-triggers for more info.
This way you could easily find the item which changed. Should work better?

Even though it looks like you are using a recent version of the binding, the snapshots really only have had device database updates for quite some time. Before putting much effort into troubleshooting, I suggest you update to the development version of the binding, which has a lot of improvements and fixes, or wait for it to get into the snapshots…

Thanks for chiming in.
@hr3 it is initiated manually in the sitemap,yes. Rules, I guess, triggers on both.

@binderth Will give it a try, but I doubt it is the problem. The display is dark on the device itself, so it has not received the command.

@5iver have been using the dev binding since (my) day 1

Oops, sorry, I missed that! Guess it’s good to check though… :wink:

Do you have a log with the zwave binding in debug while this occurs? Is it always HVAC1Mode, or does it occur with other devices too? Does it always work if you send a single command directly to HVAC1Mode? You can do this through Karaf, without fiddling with a sitemap…

smarthome:send HVAC1Mode 1

Every now and then, it seems like I’ve had some lights not responding to commands sent while iterating through a group. This is not quite what you are doing, but similar, since we’re both rapidly sending multiple commands to the binding. This is very intermittent and I haven’t tried tracking it down yet. I’m currently using snapshot 1341 and the latest dev binding.

@binderth changed my rule to:

rule 'HVACMode'
when Member of hvacMode changed
then
    logInfo(name12, "Update: hvacMode triggerd by " + triggeringItem.name + " Command=" + triggeringItem.state)
end

It worked nicely. See log below:

@5iver

Always! I did as you suggested and issued the group commands from Karaf.
Just as I was about to give up getting it to fail, it happened.

Log

I did these commands in Karaf:

openhab> log:set debug org.openhab.binding.zwave  @2018-09-03 22:49:44.372
openhab> smarthome:send hvacMode 0                @2018-09-03 22:49:47.354
Command has been sent successfully.
openhab> smarthome:send hvacMode 1                @2018-09-03 22:49:55.544
Command has been sent successfully.
openhab> log:set info org.openhab.binding.zwave

I have not run this throug Chris’s log viewer since I’m not sure hvat to look for, but it looks to me that the:

openhab> smarthome:send hvacMode 0
Command has been sent successfully.

command was only sent to 5 out of the 8 nodes.

Sending single commands to a node at a time always work.

Good test! I’m busy holding down a hammock, but I’ll take a look later tonight.

@OMR, I’m having trouble downloading your log file. It seems to just take me to a blank page. Never mind… had to find a Windows pc.

The log is interesting, but I think a longer section, about 30s after sending the command, would be more helpful. There is a lot going on when sending these commands, and it takes a while for everything to settle. Also, sending 1 to hvacMode at 2018-09-03 22:49:55.544 makes it difficult to piece it all together.

But hold off until @chris has time to take a look at it… this may be enough.

How are are you confirming the command fails to be sent to the device? The display on the device lights up when the mode is changed?

Right, but it always reflects the settled state of the mode displayed in the logs.
Issuing the command a second time puts the whole group to the correct mode.

@chris, just did a new test on 2.4.0-SNAPSHOT Build #1361 (from yesterday). Z-Wave binding now also from snapshot.
This is still an issue. Sending a Mode change to a group of 8 devices fails 50% of the time.
Let me know if you need more than the log I made previously.
Thanks.

Sorry - I missed this.

Can you provide the XML file for node 85 please.

I also note node 30 is sending a lot of spam - you might want to reset it.

Sure, here is node85.

network_e0b2d700__node_85.xml (38.4 KB)

Are you able to set the thermostat mode of node 85 outside of the group command?

Affirmative. Both from paperUI and Karaf.
One thing though. Not all of these 8 ztrm2 has been deleted and re-included after the latest database update.
Could that be an issue?

No - it shouldn’t be a problem…

@OMR can you enable trace logging and try again please and send me the log…

Thanks.

As before, seems like enabling debug logging has an effect.
This time I’m unable to get it to fail with debug on.

Tried 14 times from Karaf and 6 times from site map.

Could it be marginal timing somewhere?

Yes - I’m thinking it’s something related to the queue management as the commands probably all come in different threads. However I just went through this and checked that all queue interactions are synchronised, so I can’t see where this is if it is a synchronisation issue.

I’ve spent most of the afternoon looking at this - I think it’s soon time for beer! :confounded:

Sleep on it. Maybe something pops to mind :slight_smile: