Max concurrent commands on Z-Stick, Gen5 (ZW090)

I've been noticing that with some of my more complex action groups, it seems that the Z-wave actions hang up mid way for 20 seconds or so before the rest of the Z-wave actions happen.

Sometimes, the status in the lower right of the window shows "Waiting for ACK" usually after several commands have been sent.

Is there a best practice for sending a bunch of Z-wave commands so they run more efficiently?

And I'm not sure if this is related, but I find some of my devices, if controlling them too frequently (like sending a bunch of on commands in a row) will get a Waiting for ACK error and the log shows "requeuing"

Code: Select all

 Z-Wave                          sent "Bedroom Xmas" on
   Z-Wave Debug                    ignoring duplicate energy request of "002 - Bedroom Xmas" (activity detected)
   Z-Wave Debug                    SENT setMultiLevelValue: 01 0E 00 13 02 07 60 0D 01 01 26 01 FF 25 74 03
   Z-Wave                          sent "Bedroom Xmas" on
   Z-Wave Debug                    ignoring duplicate energy request of "002 - Bedroom Xmas" (activity detected)
   Z-Wave Debug                    SENT setMultiLevelValue: 01 0E 00 13 02 07 60 0D 01 01 26 01 FF 25 75 02
   Z-Wave Debug                    . .  setMultiLevelValue: requeuing 4 unsolicited packets
   Z-Wave                          sent "Bedroom Xmas" on
   Z-Wave Debug                    ignoring duplicate energy request of "002 - Bedroom Xmas" (activity detected)
   Z-Wave Debug                    RCVD dimmerSetLevel: 01 09 00 04 00 02 03 20 03 29 F9
   Z-Wave Debug                    . .  dimmerSetLevel: node 002, endpoint None, value 41
   Z-Wave Debug                    RCVD dimmerSetLevel: 01 09 00 04 10 02 03 20 03 29 E9
   Z-Wave Debug                    . .  dimmerSetLevel: node 002, endpoint None, value 41
   Z-Wave Debug                    RCVD dimmerSetLevel: 01 09 00 04 10 02 03 20 03 29 E9
   Z-Wave Debug                    . .  dimmerSetLevel: node 002, endpoint None, value 41
   Z-Wave Debug                    RCVD dimmerSetLevel: 01 09 00 04 10 02 03 20 03 29 E9
   Z-Wave Debug                    . .  dimmerSetLevel: node 002, endpoint None, value 41
   Z-Wave Debug                    SENT setMultiLevelValue: 01 0E 00 13 02 07 60 0D 01 01 26 01 FF 25 76 01
   Z-Wave                          sent "Bedroom Xmas" on
   Z-Wave Debug                    ignoring duplicate energy request of "002 - Bedroom Xmas" (activity detected)
   Z-Wave Debug                    SENT setMultiLevelValue: 01 0E 00 13 02 07 60 0D 01 01 26 01 FF 25 77 00
   Z-Wave Debug                    . .  setMultiLevelValue: requeuing 4 unsolicited packets

Some add on information from what I'm seeing about... it may not be the number of concurrent commands but the total traffic going through the network that's causing the NO ACK errors and slow retries to happen:

I'm seeing lots of network retries/NO ACK messages in the status when I turn certain devices on and off quickly (manually). Here's an example:

Code: Select all

Jan 26, 2019, 8:06:40 PM
   Z-Wave Debug                    SENT setMultiLevelValue: 01 0E 00 13 02 07 60 0D 01 01 26 01 00 25 F7 7F
   Z-Wave                          sent "Bedroom Xmas" off
   Z-Wave Debug                    queueing energy request of "002 - Bedroom Xmas" (activity detected)
   Z-Wave Debug                    RCVD dimmerSetLevel: 01 09 00 04 00 02 03 20 03 00 D0
   Z-Wave Debug                    . .  dimmerSetLevel: node 002, endpoint None, value 0
   Z-Wave Debug                    SENT setMultiLevelValue: 01 0E 00 13 02 07 60 0D 01 01 26 01 FF 25 F8 8F
   Z-Wave                          sent "Bedroom Xmas" on
   Z-Wave Debug                    ignoring duplicate energy request of "002 - Bedroom Xmas" (activity detected)
   Z-Wave Debug                    RCVD dimmerSetLevel: 01 09 00 04 00 02 03 20 03 24 F4
   Z-Wave Debug                    . .  dimmerSetLevel: node 002, endpoint None, value 36
   Z-Wave Debug                    RCVD requestVarSensorStatus: 01 0C 00 04 00 19 06 31 05 04 22 00 3E C4
   Z-Wave Debug                    . .  requestVarSensorStatus: node 025, endpoint None, type 4, raw value 2200...
   Z-Wave Debug                    . .  requestVarSensorStatus: 6.2 W (float: 6.200000)
   Z-Wave Debug                    received "Rusty Bookcase" power load to 6.2 W
   Z-Wave Debug                    SENT setMultiLevelValue: 01 0E 00 13 02 07 60 0D 01 01 26 01 00 25 F9 71
   Z-Wave                          sent "Bedroom Xmas" off
   Z-Wave Debug                    ignoring duplicate energy request of "002 - Bedroom Xmas" (activity detected)
   Z-Wave Debug                    RCVD dimmerSetLevel: 01 09 00 04 00 02 03 20 03 00 D0
   Z-Wave Debug                    . .  dimmerSetLevel: node 002, endpoint None, value 0
   Z-Wave Debug                    SENT setMultiLevelValue: 01 0E 00 13 02 07 60 0D 01 01 26 01 FF 25 FA 8D
   Z-Wave                          sent "Bedroom Xmas" on
   Z-Wave Debug                    ignoring duplicate energy request of "002 - Bedroom Xmas" (activity detected)
   Z-Wave Debug                    SENT setMultiLevelValue: 01 0E 00 13 02 07 60 0D 01 01 26 01 00 25 FB 73
   Z-Wave                          sent "Bedroom Xmas" off
   Z-Wave Debug                    ignoring duplicate energy request of "002 - Bedroom Xmas" (activity detected)
   Z-Wave Debug                    SENT setMultiLevelValue: 01 0E 00 13 02 07 60 0D 01 01 26 01 FF 25 FC 8B
   Z-Wave                          sent "Bedroom Xmas" on
   Z-Wave Debug                    ignoring duplicate energy request of "002 - Bedroom Xmas" (activity detected)
   Z-Wave Debug                    SENT setMultiLevelValue: 01 0E 00 13 02 07 60 0D 01 01 26 01 00 25 FD 75
   Z-Wave Debug                    . .  setMultiLevelValue: requeuing 4 unsolicited packets
   Z-Wave                          sent "Bedroom Xmas" off
   Z-Wave Debug                    ignoring duplicate energy request of "002 - Bedroom Xmas" (activity detected)
   Z-Wave Debug                    RCVD dimmerSetLevel: 01 09 00 04 00 02 03 20 03 24 F4
   Z-Wave Debug                    . .  dimmerSetLevel: node 002, endpoint None, value 36
   Z-Wave                          received "Bedroom Xmas" status update brightness 36
   Z-Wave Debug                    ignoring duplicate energy request of "002 - Bedroom Xmas" (activity detected)
   Z-Wave Debug                    RCVD dimmerSetLevel: 01 09 00 04 00 02 03 20 03 24 F4
   Z-Wave Debug                    . .  dimmerSetLevel: node 002, endpoint None, value 36
   Z-Wave Debug                    RCVD dimmerSetLevel: 01 09 00 04 00 02 03 20 03 24 F4
   Z-Wave Debug                    . .  dimmerSetLevel: node 002, endpoint None, value 36
   Z-Wave Debug                    RCVD dimmerSetLevel: 01 09 00 04 00 02 03 20 03 00 D0
   Z-Wave Debug                    . .  dimmerSetLevel: node 002, endpoint None, value 0
   Z-Wave                          received "Bedroom Xmas" status update is off
   Z-Wave Debug                    ignoring duplicate energy request of "002 - Bedroom Xmas" (activity detected)
   Z-Wave Debug                    SENT setMultiLevelValue: 01 0E 00 13 02 07 60 0D 01 01 26 01 FF 25 FE 89
   Z-Wave                          sent "Bedroom Xmas" on
   Z-Wave Debug                    ignoring duplicate energy request of "002 - Bedroom Xmas" (activity detected)
   Z-Wave Debug                    RCVD dimmerSetLevel: 01 09 00 04 00 02 03 20 03 24 F4
   Z-Wave Debug                    . .  dimmerSetLevel: node 002, endpoint None, value 36
   Z-Wave Debug                    polling status of node "002 - Bedroom Xmas" (post-activity energy request)
   Z-Wave Debug                    SENT requestMeterLevel: 01 0E 00 13 02 07 60 0D 01 01 32 01 00 25 FF 63
   Z-Wave Debug                    SENT requestMeterLevel: 01 0E 00 13 02 07 60 0D 01 01 32 01 10 25 01 8D
   Z-Wave Debug                    . .  requestMeterLevel: requeuing 1 unsolicited packets
   Z-Wave Debug                    RCVD multiEndPointPacket: 01 18 00 04 00 02 12 60 0D 01 01 32 02 21 64 00 00 A9 58 00 CE 00 00 A9 57 2A
   Z-Wave Debug                    . .  multiEndPointPacket: node 002, endPoint 1
   Z-Wave Debug                    RCVD requestMeterLevel: 01 14 00 04 00 02 0E 32 02 21 64 00 00 A9 58 00 CE 00 00 A9 57 FF
   Z-Wave Debug                    . .  requestMeterLevel: node 002, endpoint 1, meterType 01, raw value 6400...
   Z-Wave Debug                    . .  requestMeterLevel: 43.352 kWh (float: 43.352000)
   Z-Wave                          received "Bedroom Xmas" energy total to 43.352 kWh
   Z-Wave Debug                    RCVD multiEndPointPacket: 01 18 00 04 00 02 12 60 0D 01 01 32 02 21 74 00 00 43 96 00 00 00 00 00 00 2E
   Z-Wave Debug                    . .  multiEndPointPacket: node 002, endPoint 1
   Z-Wave Debug                    RCVD requestMeterLevel: 01 14 00 04 00 02 0E 32 02 21 74 00 00 43 96 00 00 00 00 00 00 FF
   Z-Wave Debug                    . .  requestMeterLevel: node 002, endpoint 1, meterType 01, raw value 7400...
   Z-Wave Debug                    . .  requestMeterLevel: 17.302 W (float: 17.302000)
   Z-Wave                          received "Bedroom Xmas" power load to 17.302 W


[matt (support)]

None of the Event Log snippets above show any NO ACK error messages. They do show some re-queuing of incoming messages. That occurs when Indigo is trying to send a command and an incoming command comes in at the same time. In this case it is the module broadcasting out new brightness values and Watt / kWh data. There isn't really a way to prevent this type of congestion, other than by adding delays between actions, but normally it doesn't cause a problem.

If you are seeing Waiting for ACK messages then you might try optimizing the Z-Wave Network (via the Interfaces->Z-Wave menu). It is possible that routing tables need to be updated. If the Bedroom Xmas module is far away from the Z-Stick then you can try adding a module between them so that it can more reliably relay/route the commands.

None of the Event Log snippets above show any NO ACK error messages.

Yes, I'm surprised the log doesn't show it, but that status area in the lower left hand version of the screen often shows "waiting for ACK" for 10 or more seconds.

What I'm trying to figure out is what is the bottleneck here? Is there a maximum amount of commands the Zstick can send at once, or does it act serially and wait for an ack before sending the next command?

And is the choke point something with the mesh network or the interface itself?

Thanks.

[matt (support)]

The Z-Stick always sends commands serially, waiting for an ACK (or NAK) before continuing on to the next one. But the Z-Stick cannot know if other modules might be sending out commands around the same time it is about to send a command, which may be what is occurring here. In the module you just sent the on/off command to is in the process of broadcasting out information about its new state (on level and watts), while at the same time the Z-Stick is trying to send out the next command. Normally this should be handled okay by the Z-Stick (at least for a vast majority of the time). So the problem might a signal problem or the routing to get to the module is complex (requiring lots of hops). That is why I suggested optimizing the Z-Wave network. I don't know the layout of your modules, but you might also try moving them around before the optimization (ex: if there are a lot of walls or distance between the Z-Stick and the module leading to the delay, then add a module between them to help improve the range/robustness).

Thanks. I did re-optimize the network and started with the modules closest to the z-stick, and then the whole thing. It's much more stable now. I think one of the modules that is in the position to potentially do a lot of relaying was one of the ones getting lots of errors, so I unplugged it and replugged it in before the optimize as well. It's possibly it had gotten into a strange state.

I've also reduced polling where applicable, and slowed down the wake times in the hopes of freeing up the network.

Thanks for helping me understand how the Z-wave net & Zstick works.

[matt (support)]

Great, I'm glad that helped and it is more stable/responsive now!