Thanks. It shows that the thing configuration is called, and it looks like it’s called before the thing is initialised, which I assume is related to the normalisation of the config.
It never gets called for the DZMX1 though 
. For some reason, it seems the framework doesn’t like this device!
Ok, so I think @mhilbush is right - the problem is when there is no configuration for a device, then the config provider is not called. I’ve managed to replicate the problem by setting one of my devices to leviton_dzmx1_00_000.
I’ll have a look through this to see if I can work how to fix this - I at least understand the problem and can see why it’s happening, which is a good start. If I can’t find a resolution in reasonable time then I’ll just have to raise an issue…
I don’t think this issue will be resolved quickly. I’ll raise an ESH issue, and will update the binding to ensure that all devices have configuration settings until this is resolved.
For reference -:
Binding has been updated with a workaround - please let me know if it’s now working.
@chris
Here is log about DZMX not updating ON/OFF status. Using latest build from 1st post. Could you please check ?
Can you confirm then that the previous problem with the node_id is now resolved?
Well, I’ll tell you what I did. I was using build provided by @5iver, so all my devices were initialized. Then I download latest from 1st post replaced running add-on and restarted OH. I can control DZMX but can’t get updates.
The problem here is that the device is saying it’s BUSY -:
Here you see the NIF being received and the binding sends a GET to find the state, and the device returns that it is BUSY.
Currently the binding doesn’t retry this poll, so there will be no update. To be honest, I don’t think I’ve ever seen a device report that it is busy before…
Ok, to be sure, can you delete the DZMX and add it back?
I also don’t know why it is busy, bud I am sure that it was never busy when I used previous z-wave binding 
Just did. Problem exists. Initializing …
I don’t think this can in any way be attributed to the binding. There is nothing else in the log around the time the NIF is received, so the binding is not doing anything to make the device busy as far as I can tell.
I know it’s easy to say “I changed X, and therefore it must be caused by X” - however - it’s not always the case.
And of course I am not gonna argue. I have snapshot of OH 2.2 and 2.3 with stable Z-wave build, I’ll get logs to confirm.
Thanks - I’m certainly happy to look at the logs, and if we can see an issue, then I’m happy to fix 
.
You are the best. I have to say I am impressed with support you guys provide. Better than enterprise 
Ok, I’m not sure what to do from here. Since I don’t have the device, I can’t check what’s going on - I configured a thing to use the same thing-type, and as best as I can tell, it’s working here.
If you go to edit the thing, do you now see the node ID in the configuration parameters -:
@chris Here is log from 2.2 and stable z-wave when DZMX is not busy and updates on/off status:
Full log - https://paste.ee/p/lVUOL
2018-07-21 06:57:56.598 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 49
2018-07-21 06:57:56.598 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 06 02 26 02 25 43 A3
2018-07-21 06:57:56.599 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 6: Sending REQUEST Message = 01 09 00 13 06 02 26 02 25 43 A3
2018-07-21 06:57:56.608 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2018-07-21 06:57:56.610 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-07-21 06:57:56.610 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
2018-07-21 06:57:56.611 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
2018-07-21 06:57:56.611 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
2018-07-21 06:57:56.611 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 6: Sent Data successfully placed on stack.
2018-07-21 06:57:56.625 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 43 00 00 02 AA
2018-07-21 06:57:56.627 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-07-21 06:57:56.627 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 43 00 00 02 00 00 A4
2018-07-21 06:57:56.627 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 43 00 00 02 00 00 A4
2018-07-21 06:57:56.627 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=43 00 00 02
2018-07-21 06:57:56.628 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 6: SendData Request. CallBack ID = 67, Status = Transmission complete and ACK received(0)
2018-07-21 06:57:56.628 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Starting initialisation from DONE
2018-07-21 06:57:56.628 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@4d91b9db already registered
2018-07-21 06:57:56.628 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Get, dest=6, callback=67, payload=06 02 26 02
2018-07-21 06:57:56.628 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=43 00 00 02
2018-07-21 06:57:56.629 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=67, expected=ApplicationCommandHandler, cancelled=false MISMATCH
2018-07-21 06:57:56.636 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 06 03 26 03 63 B1
2018-07-21 06:57:56.638 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-07-21 06:57:56.639 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 04 00 06 03 26 03 63 B1
2018-07-21 06:57:56.639 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 04 00 06 03 26 03 63 B1
2018-07-21 06:57:56.639 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 06 03 26 03 63
2018-07-21 06:57:56.640 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 6: Application Command Request (ALIVE:DONE)
2018-07-21 06:57:56.640 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Starting initialisation from DONE
2018-07-21 06:57:56.640 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@4d91b9db already registered
2018-07-21 06:57:56.640 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 6: Incoming command class SWITCH_MULTILEVEL
2018-07-21 06:57:56.641 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 6: Received SWITCH_MULTILEVEL command V1
2018-07-21 06:57:56.641 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 6: Switch Multi Level report, value = 99
2018-07-21 06:57:56.642 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveCommandClassValueEvent
2018-07-21 06:57:56.642 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2018-07-21 06:57:56.642 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Got a value event from Z-Wave network, endpoint = 0, command class = SWITCH_MULTILEVEL, value = 99
2018-07-21 06:57:56.642 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Updating channel state zwave:device:1590aeb5569:node6:switch_dimmer to 100 [PercentType]
2018-07-21 06:57:56.660 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Get, dest=6, callback=67, payload=06 02 26 02
2018-07-21 06:57:56.661 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 06 03 26 03 63
2018-07-21 06:57:56.665 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=ApplicationCommandHandler, callback id=67, expected=ApplicationCommandHandler, cancelled=false transaction complete!
2018-07-21 06:57:56.666 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
2018-07-21 06:57:56.666 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2018-07-21 06:57:56.668 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 6: Response processed after 68ms/1857ms.
2018-07-21 06:57:56.668 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 48
2018-07-21 06:57:56.668 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 06 02 26 02 25 44 A4
2018-07-21 06:57:56.668 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 6: Sending REQUEST Message = 01 09 00 13 06 02 26 02 25 44 A4
2018-07-21 06:57:56.678 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8
2018-07-21 06:57:56.680 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-07-21 06:57:56.681 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 01 13 01 E8
2018-07-21 06:57:56.681 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 04 01 13 01 E8
2018-07-21 06:57:56.681 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Response[0x01], priority=High, dest=255, callback=0, payload=01
2018-07-21 06:57:56.681 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 6: Sent Data successfully placed on stack.
2018-07-21 06:57:56.697 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 44 00 00 02 AD
2018-07-21 06:57:56.699 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-07-21 06:57:56.699 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 44 00 00 02 00 00 A3
2018-07-21 06:57:56.700 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 13 44 00 00 02 00 00 A3
2018-07-21 06:57:56.700 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=44 00 00 02
2018-07-21 06:57:56.700 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 6: SendData Request. CallBack ID = 68, Status = Transmission complete and ACK received(0)
2018-07-21 06:57:56.701 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Starting initialisation from DONE
2018-07-21 06:57:56.701 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@4d91b9db already registered
2018-07-21 06:57:56.702 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Get, dest=6, callback=68, payload=06 02 26 02
2018-07-21 06:57:56.702 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=SendData[0x13], type=Request[0x00], priority=High, dest=255, callback=0, payload=44 00 00 02
2018-07-21 06:57:56.702 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=SendData, callback id=68, expected=ApplicationCommandHandler, cancelled=false MISMATCH
2018-07-21 06:57:56.706 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 06 03 26 03 63 B1
2018-07-21 06:57:56.708 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2018-07-21 06:57:56.708 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 04 00 06 03 26 03 63 B1
2018-07-21 06:57:56.709 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 04 00 06 03 26 03 63 B1
2018-07-21 06:57:56.709 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 06 03 26 03 63
2018-07-21 06:57:56.709 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 6: Application Command Request (ALIVE:DONE)
2018-07-21 06:57:56.710 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 6: Starting initialisation from DONE
2018-07-21 06:57:56.710 [DEBUG] [ve.internal.protocol.ZWaveController] - Event Listener org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer@4d91b9db already registered
2018-07-21 06:57:56.710 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 6: Incoming command class SWITCH_MULTILEVEL
2018-07-21 06:57:56.711 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 6: Received SWITCH_MULTILEVEL command V1
2018-07-21 06:57:56.711 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 6: Switch Multi Level report, value = 99
2018-07-21 06:57:56.711 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveCommandClassValueEvent
2018-07-21 06:57:56.712 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
2018-07-21 06:57:56.712 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Got a value event from Z-Wave network, endpoint = 0, command class = SWITCH_MULTILEVEL, value = 99
2018-07-21 06:57:56.712 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Updating channel state zwave:device:1590aeb5569:node6:switch_dimmer to 100 [PercentType]
2018-07-21 06:57:56.720 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Get, dest=6, callback=68, payload=06 02 26 02
2018-07-21 06:57:56.720 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 06 03 26 03 63
2018-07-21 06:57:56.720 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=ApplicationCommandHandler, callback id=68, expected=ApplicationCommandHandler, cancelled=false transaction complete!
2018-07-21 06:57:56.720 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
2018-07-21 06:57:56.721 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2018-07-21 06:57:56.721 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 6: Response processed after 51ms/1857ms.
In both instances, the binding is sending exactly the same thing -:
New binding…
Old binding…
The only difference is that in the first one, there is a NIF sent from the device beforehand - was there a difference in how you are triggering these two events?
Nope, no difference. I just pressed button on actual dimmer to turn on/off lights, Node 6.
@Lolodomo There are some config parameters that can be used trigger a report when a threshold is reached, but I don’t use them. I just have auto-report time set to 30, which generates a report every 15 min.
Yes, this should get you a report every hour.
