Yes, please @chris would you mind to prepare a jar of the code right before you added holdoff changes, but to include the current database ? Or current code with the holdoff stuff disabled if that’s easy to do.
I will see what I can do. I fear though if we go down this route, it will not be possible to find the problem now and I will have to remove this 
.
Thanks. I’ll be volunteering to keep testing latest bindings to include holdoff, but I really need a stable jar to fall back to, else my wife won’t allow me to 
No idea how you laid out the code so no idea if that can be done easily, but maybe you could instead introduce a config option (?) or other parameter that can be changed at runtime to enable/disable holdoff ?
If another log of a run to end in ‘queue full’ would be of help, let me know. I can also include TRACE level if you like.
Thank you for your reply !! This stuff has got me all excited and am learning a lot!
Thanks for this.
From a quick look, I think the issue is that the initial GET request, which results in the “try again later” response, doesn’t actually complete as a result of the “try again later” message. It times out 5 seconds later (5 seconds is the standard transaction timeout). This gives us the 6 second delay (At least in this log, it’s 6 seconds rather than 8).
I will take a look at how this can be fixed, but at least it is understood why it’s not the 2 seconds which was my main concern.
1 Like
Seems like these APPLICATION_BUSY responses are a fact of life with Leviton devices. FWIW, I see several of these a day from a variety of nodes with no obvious reason why they happen.
zwave.log.20180730170811:2018-07-30 16:51:38.247 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 73: Received COMMAND_CLASS_APPLICATION_STATUS V0 APPLICATION_BUSY
zwave.log.20180731021619:2018-07-30 19:51:03.757 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 21: Received COMMAND_CLASS_APPLICATION_STATUS V0 APPLICATION_BUSY
zwave.log.20180731133958:2018-07-31 09:54:32.742 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 78: Received COMMAND_CLASS_APPLICATION_STATUS V0 APPLICATION_BUSY
zwave.log.20180731215103:2018-07-31 19:30:12.035 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 50: Received COMMAND_CLASS_APPLICATION_STATUS V0 APPLICATION_BUSY
zwave.log.20180801215422:2018-08-01 13:30:11.138 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 50: Received COMMAND_CLASS_APPLICATION_STATUS V0 APPLICATION_BUSY
zwave.log.20180801215422:2018-08-01 13:30:11.200 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 50: Received COMMAND_CLASS_APPLICATION_STATUS V0 APPLICATION_BUSY
zwave.log.20180801215422:2018-08-01 17:59:55.535 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 48: Received COMMAND_CLASS_APPLICATION_STATUS V0 APPLICATION_BUSY
zwave.log.20180801215422:2018-08-01 19:07:11.521 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 54: Received COMMAND_CLASS_APPLICATION_STATUS V0 APPLICATION_BUSY
zwave.log.20180802140605:2018-08-02 06:15:58.673 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 56: Received COMMAND_CLASS_APPLICATION_STATUS V0 APPLICATION_BUSY
zwave.log.20180802230700:2018-08-02 15:15:59.967 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 57: Received COMMAND_CLASS_APPLICATION_STATUS V0 APPLICATION_BUSY
zwave.log.20180802230700:2018-08-02 15:16:04.317 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 57: Received COMMAND_CLASS_APPLICATION_STATUS V0 APPLICATION_BUSY
zwave.log.20180802230700:2018-08-02 16:30:11.059 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 50: Received COMMAND_CLASS_APPLICATION_STATUS V0 APPLICATION_BUSY
zwave.log.20180802230700:2018-08-02 17:50:51.325 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 51: Received COMMAND_CLASS_APPLICATION_STATUS V0 APPLICATION_BUSY
zwave.log.20180803154608:2018-08-03 09:09:14.631 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 56: Received COMMAND_CLASS_APPLICATION_STATUS V0 APPLICATION_BUSY
zwave.log.20180803154608:2018-08-03 10:59:16.131 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 45: Received COMMAND_CLASS_APPLICATION_STATUS V0 APPLICATION_BUSY
zwave.log.20180803154608:2018-08-03 12:17:57.290 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 73: Received COMMAND_CLASS_APPLICATION_STATUS V0 APPLICATION_BUSY
zwave.log.20180803154608:2018-08-03 13:07:15.333 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 54: Received COMMAND_CLASS_APPLICATION_STATUS V0 APPLICATION_BUSY
zwave.log.20180804003918:2018-08-03 16:07:18.692 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 54: Received COMMAND_CLASS_APPLICATION_STATUS V0 APPLICATION_BUSY
zwave.log.20180804003918:2018-08-03 19:07:21.489 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 54: Received COMMAND_CLASS_APPLICATION_STATUS V0 APPLICATION_BUSY
zwave.log.20180804003918:2018-08-03 19:59:18.503 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 45: Received COMMAND_CLASS_APPLICATION_STATUS V0 APPLICATION_BUSY
zwave.log.20180805174619:2018-08-05 09:31:55.070 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 73: Received COMMAND_CLASS_APPLICATION_STATUS V0 APPLICATION_BUSY
zwave.log.20180805174619:2018-08-05 09:31:55.118 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 73: Received COMMAND_CLASS_APPLICATION_STATUS V0 APPLICATION_BUSY
zwave.log.20180805174619:2018-08-05 12:31:53.147 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 78: Received COMMAND_CLASS_APPLICATION_STATUS V0 APPLICATION_BUSY
zwave.log.20180805174619:2018-08-05 12:31:55.805 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 78: Received COMMAND_CLASS_APPLICATION_STATUS V0 APPLICATION_BUSY
zwave.log.20180806014458:2018-08-05 19:03:38.512 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 51: Received COMMAND_CLASS_APPLICATION_STATUS V0 APPLICATION_BUSY
zwave.log.20180806014458:2018-08-05 20:10:45.290 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 51: Received COMMAND_CLASS_APPLICATION_STATUS V0 APPLICATION_BUSY
zwave.log.20180806081510:2018-08-06 04:59:20.671 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 45: Received COMMAND_CLASS_APPLICATION_STATUS V0 APPLICATION_BUSY
zwave.log.20180806081510:2018-08-06 04:59:22.899 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 45: Received COMMAND_CLASS_APPLICATION_STATUS V0 APPLICATION_BUSY
zwave.log.20180806081510:2018-08-06 07:59:25.683 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 45: Received COMMAND_CLASS_APPLICATION_STATUS V0 APPLICATION_BUSY
zwave.log.20180806231500:2018-08-06 21:09:16.844 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 56: Received COMMAND_CLASS_APPLICATION_STATUS V0 APPLICATION_BUSY
zwave.log.20180807151457:2018-08-07 06:30:02.533 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 78: Received COMMAND_CLASS_APPLICATION_STATUS V0 APPLICATION_BUSY
zwave.log.20180807151457:2018-08-07 06:30:46.224 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 46: Received COMMAND_CLASS_APPLICATION_STATUS V0 APPLICATION_BUSY
zwave.log.20180808002630:2018-08-07 22:59:28.248 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 45: Received COMMAND_CLASS_APPLICATION_STATUS V0 APPLICATION_BUSY
zwave.log.20180808074812:2018-08-08 03:17:27.770 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 56: Received COMMAND_CLASS_APPLICATION_STATUS V0 APPLICATION_BUSY
zwave.log.20180808171539:2018-08-08 09:59:22.353 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 46: Received COMMAND_CLASS_APPLICATION_STATUS V0 APPLICATION_BUSY
zwave.log.20180808171539:2018-08-08 12:29:37.269 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 73: Received COMMAND_CLASS_APPLICATION_STATUS V0 APPLICATION_BUSY
zwave.log.20180808171539:2018-08-08 15:29:39.817 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 73: Received COMMAND_CLASS_APPLICATION_STATUS V0 APPLICATION_BUSY
zwave.log.20180809095525:2018-08-09 06:34:40.264 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 51: Received COMMAND_CLASS_APPLICATION_STATUS V0 APPLICATION_BUSY
zwave.log.20180809095525:2018-08-09 06:34:41.026 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 51: Received COMMAND_CLASS_APPLICATION_STATUS V0 APPLICATION_BUSY
zwave.log.20180809095525:2018-08-09 09:34:45.205 [DEBUG] [e.internal.protocol.commandclass.ZWaveCommandClass] - NODE 51: Received COMMAND_CLASS_APPLICATION_STATUS V0 APPLICATION_BUSY
Is there a Lifeline issue currently?
I freshly included some new devices. Whenever I mess around manually in the “Association” in Habmin those devices dont get any lifeline updates anymore. Even if I restore the same state as the default.
only deleting the thing + xml and rediscover it solves my issues
I did not follow the discussion for a while… after updating to the latest build I see quite some queuing and therefore bad reaction times for devices. whats the background for holdoff function?
Also on current build I have a device that is sending temperature that is randomly interpreted in Celsius OR Fahrenheit. Is there something known yet?
When the item goes from 25 to 74 … my fire alarm rule triggers 
Have you defined the item using the UoM syntax.
Number:Temperature
uhm thats new to me.
but from maaaaaany devices only one has that behaviour
thanks for the hint… will try
It was implemented to avoid retransmitting a message immediately after getting a busy response from the controller. Without the holdoff (250 ms, I think), it’s almost guaranteed to get another busy response.
Yeah, I saw that behavior from one of my devices (I forget which one). Using Number:Temperature resolved the issue for me.
Hi Chris
I am running:
openhab> bundle:list | grep Z
223 │ Active │ 80 │ 2.4.0.201807071112 │ ZWave Binding
openhab>
Is it worth upgrading if I use FIbaro devices? I get alot off odd behaviour now and then (lights going on off) need to reboot the whole system and reinitialise the Motion Sensor as an example. And updates taking AGES for lux/temp
Cheers
I’ve just made an update to the binding - sorry it’s taken a few days but I’ve been very busy with trying to iron out some updates on ZigBee which were required elsewhere.
I’ve made some changes to the way the hold-off timer works to try and reduce synchronisation issues - no guarantees that it’s solved of course, so please let me know your milage…
Probably not, but without sifting through the history I couldn’t be sure.
It sounds like you need to look at your logs to find out what’s happening? It doesn’t sound like this would be binding related if lights are randomly turning on and off - delays could be attributed to the binding, but probably caused by something external such as a device timing out. Again though, logs are your friend as they will help you work out what’s going on - otherwise, you, or I, can just guess 
.
@chris just installed the binding with very positive results. At first I thought something was wrong, as debug logging was very light and seemed to stop after 2 minutes ( this is with 60+ mains devices), but this was because everything initialized quickly without needing retries, which was probably a bulk of the logging before. Commands are very snappy and do not seem to have any lag, which they did before. Also, previously I had a ton of zwave threads always present (transaction manager i think), which would persist even when the binding was stopped, now I only have a single thread (ZWaveSerialHandler.java). I’ll poke at it today some more, but right now this looks very promising!
Did you also change OH ? I think there were recent changes in ESH w.r.t. the serial interface.
I’m running stock 2.3.0 and now this latest binding, too. Yes it’s snappy but that it has been before as well.