Hi,
I’ve been having trouble getting this specific device (Jasco 14287) to work. It just shows up as an unknown device with no info about manufacturer or type/id.
It seems like it’s already been added to the database. Issue adding new ZWave device to DB
Has anyone been able to get this to work?
Thanks
You need to be on a snapshot version of openHAB (or at least the zwave binding) to make it work.
Which version of openHAB are you running?
I just made a post about this because I was having trouble with the same switch. Might be a little different, might not.
See this post… https://community.openhab.org/t/z-wave-fails-to-initialize-solved/33613
Maybe we can get @chris to take a look. Two in 1 day sounds suspicious.
I am on OH2.1 Release Build, and I have it working.
Sorry - take a look at what?
I had a look at your post, but there is no cache in the binding so my guess is that this was a coincidence. There is a known issue that the binding may need to be restarted in some circumstances for devices to be properly discovered - this is fixed in later versions, but it still exists in master.
If there’s something you want me to look at, then please let me know what it is…
Just that you would read it and comment just as you have. It seemed as if OH didn’t know it needed to Initialize the Thing. If restarting the OH service a couple of times and then rebooting the Rpi doesn’t restart the binding, then please let us know. I’m expecting a replacement FAN switch, I’ll turn on Debug if I have issues adding that switch.
Thanks!
Tony
I tried using the snapshot yesterday but still had the same problem. I’ve also restarted OH multiple times to no avail.
I have three other zwave plus dimmers and switches that work fine without any problem.
I’m suspecting that I might have a defective device but I’m pretty new at this so I’m not sure how to determine that.
I would suggest to enable debug logging and feed it into the log viewed. If you’re not receiving commands from the device, then either it’s out of range, or faulty, or not included properly.
Sometimes inclusion can get messed up where the device thinks it’s one ID, and the controller thinks it’s another ID (the binding believes the controller!). You could also try to exclude the device and re-include it again.
@chris is an awesome resource, and has made some solid suggestions. Let’s get your debug logging enabled, and see what OH is doing. Additionally, turning on the zwave debug logging certainly wouldn’t hurt. Here is a link to his very helpful page(s) for zwave.
I personally would fire up the openhab console. Have you ever done that before? I’m on a RPi, so for me, on the command line ‘ssh -p 8108 openhab@localhost’. Default password is “habopen”. At the openhab> prompt type log and then , it will display the available commands. Then you can tail the console debug log with ‘log:tail’.
You can increase logging using ‘log:set…’ command. I like to look at what is currently set using ‘log:list’. This will also help by showing you the format of the Logger category, and the LEVELs.
openhab> log:set debug org.openhab.binding.zwave
One other thing I did with my Fan Thing, was to change the minimum Polling Period down to 10 minutes in the Paper UI Configuration Parameters.
Definitely Remove the Switch from your Controller and Re-add.
I removed the device and readded it to the controller, then I readded it to as a thing.
23:08:45.260 [WARN ] [wave.discovery.ZWaveDiscoveryService] - NODE 7: Device discovery could not resolve to a thingType! 7FFFFFFF:7FFFFFFF:7FFFFFFF::0.0
23:08:45.260 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zwave:device:4de5148b:node7' to inbox.
23:08:45.261 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave controller start inclusion - mode 2
23:08:45.261 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Setting controller into INCLUSION mode, highPower:true networkWide:true.
23:08:45.261 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
23:08:45.261 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
23:08:45.261 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A C1 01 70
23:08:45.261 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A C1 01 70
23:08:45.263 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 01 01 00 00 B2
23:08:45.263 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
23:08:45.264 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 07 00 4A 01 01 00 00 B2
23:08:45.264 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 07 00 4A 01 01 00 00 B2
23:08:45.264 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=AddNodeToNetwork[0x4A], type=Request[0x00], priority=High, dest=255, callback=0, payload=01 01 00 00
23:08:45.264 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Learn ready.
23:08:45.264 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveInclusionEvent
23:08:45.264 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=AddNodeToNetwork[0x4A], type=Request[0x00], priority=High, dest=255, callback=0, payload=C1 01
23:08:45.265 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=AddNodeToNetwork[0x4A], type=Request[0x00], priority=High, dest=255, callback=0, payload=01 01 00 00
23:08:45.265 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=AddNodeToNetwork, callback id=0, expected=AddNodeToNetwork, cancelled=false transaction complete!
23:08:45.265 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
23:08:45.265 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 255: Response processed after 4ms/438ms.
23:08:45.266 [INFO ] [smarthome.event.InboxAddedEvent ] - Discovery Result with UID 'zwave:device:4de5148b:node7' has been added.
23:08:45.277 [INFO ] [smarthome.event.BindingEvent ] - org.openhab.binding.zwave.event.BindingEvent@21fd8bb3
23:08:51.965 [INFO ] [smarthome.event.InboxRemovedEvent ] - Discovery Result with UID 'zwave:device:4de5148b:node7' has been removed.
23:08:51.967 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.core.status.ConfigStatusProvider}={service.id=316, service.bundleid=182, service.scope=singleton} - org.openhab.binding.zwave
23:08:51.969 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler.
23:08:51.970 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 7: MANUFACTURER not set
23:08:51.970 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 7: Controller status changed to ONLINE.
23:08:51.971 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 7: Controller is ONLINE. Starting device initialisation.
23:08:51.971 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 7: Updating node properties.
23:08:51.971 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 7: Updating node properties. MAN=2147483647
23:08:51.972 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 7: Initialising Thing Node...
23:08:51.973 [INFO ] [smarthome.event.ThingAddedEvent ] - Thing 'zwave:device:4de5148b:node7' has been added.
23:08:51.973 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 7: Polling intialised at 1800 seconds - start in 1800000 milliseconds.
23:08:51.976 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:4de5148b:node7' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline
23:08:51.977 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:4de5148b:node7' changed from UNINITIALIZED to INITIALIZING
23:08:51.980 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:device:4de5148b:node7' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
23:09:15.054 [DEBUG] [ve.internal.protocol.ZWaveController] - Stopping inclusion timer.
23:09:15.054 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.
23:09:15.054 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
23:09:15.054 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
23:09:15.054 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave controller end inclusion
23:09:15.054 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 01 B4
23:09:15.054 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 01 B4
23:09:15.140 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A 01 06 00 00 B5
23:09:15.140 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
23:09:15.140 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 07 00 4A 01 06 00 00 B5
23:09:15.141 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 07 00 4A 01 06 00 00 B5
23:09:15.141 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=AddNodeToNetwork[0x4A], type=Request[0x00], priority=High, dest=255, callback=0, payload=01 06 00 00
23:09:15.141 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Done.
23:09:15.141 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveInclusionEvent
23:09:15.141 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=AddNodeToNetwork[0x4A], type=Request[0x00], priority=High, dest=255, callback=0, payload=05 01
23:09:15.141 [INFO ] [smarthome.event.BindingEvent ] - org.openhab.binding.zwave.event.BindingEvent@4ddfdd76
23:09:15.141 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=AddNodeToNetwork[0x4A], type=Request[0x00], priority=High, dest=255, callback=0, payload=01 06 00 00
23:09:15.141 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=AddNodeToNetwork, callback id=0, expected=AddNodeToNetwork, cancelled=false transaction complete!
23:09:15.141 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
23:09:15.142 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 255: Response processed after 86ms/438ms.
Here’s some logs when I turn off/on the fan control.
23:22:02.173 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 17 00 49 84 07 11 04 11 08 5E 86 72 5A 85 59 73 26 27 70 56 2C 2B 7A 2B
23:22:02.173 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
23:22:02.173 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 17 00 49 84 07 11 04 11 08 5E 86 72 5A 85 59 73 26 27 70 56 2C 2B 7A 2B
23:22:02.173 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 17 00 49 84 07 11 04 11 08 5E 86 72 5A 85 59 73 26 27 70 56 2C 2B 7A 2B
23:22:02.174 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationUpdate[0x49], type=Request[0x00], priority=High, dest=255, callback=0, payload=84 07 11 04 11 08 5E 86 72 5A 85 59 73 26 27 70 56 2C 2B 7A
23:22:02.174 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 7: Application update request. Node information received.
23:22:02.174 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 7: Node is ALIVE. Init stage is PROTOINFO.
23:22:02.174 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveNodeStatusEvent
23:22:02.174 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 7: Node Status event during initialisation - Node is ALIVE
23:22:02.174 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 7: Node advancer - PROTOINFO: queue length(1), free to send(false)
23:22:02.175 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 7: Initialisation retry timer started 5000
23:22:02.175 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 7: Node advancer - queued packet. Queue length is 1
23:22:02.175 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
23:22:02.175 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
23:22:02.175 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 7: Got an event from Z-Wave network: ZWaveNodeStatusEvent
23:22:02.175 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 7: Setting ONLINE
23:22:02.175 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 41 07 BD
23:22:02.175 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 04 00 41 07 BD
23:22:02.176 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 7: Node Status event - Node is ALIVE
23:22:02.176 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 7: Creating new instance of command class ZWAVE_PLUS_INFO
23:22:02.176 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 7: Command class ZWAVE_PLUS_INFO, endpoint null created
23:22:02.176 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 7: Application update is adding command class ZWAVE_PLUS_INFO.
23:22:02.176 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 7: Adding command class ZWAVE_PLUS_INFO to the list of supported command classes.
23:22:02.176 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 7: Creating new instance of command class VERSION
23:22:02.176 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 7: Command class VERSION, endpoint null created
23:22:02.176 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 7: Application update is adding command class VERSION.
23:22:02.176 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 7: Adding command class VERSION to the list of supported command classes.
23:22:02.176 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 7: Creating new instance of command class MANUFACTURER_SPECIFIC
23:22:02.176 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 7: Command class MANUFACTURER_SPECIFIC, endpoint null created
23:22:02.176 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 7: Application update is adding command class MANUFACTURER_SPECIFIC.
23:22:02.176 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 7: Adding command class MANUFACTURER_SPECIFIC to the list of supported command classes.
23:22:02.176 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 7: Creating new instance of command class DEVICE_RESET_LOCALLY
23:22:02.176 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 7: Command class DEVICE_RESET_LOCALLY, endpoint null created
23:22:02.176 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 7: Application update is adding command class DEVICE_RESET_LOCALLY.
23:22:02.177 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 7: Adding command class DEVICE_RESET_LOCALLY to the list of supported command classes.
23:22:02.177 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 7: Creating new instance of command class ASSOCIATION
23:22:02.177 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 7: Command class ASSOCIATION, endpoint null created
23:22:02.177 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 7: Application update is adding command class ASSOCIATION.
23:22:02.177 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 7: Adding command class ASSOCIATION to the list of supported command classes.
23:22:02.177 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 7: Creating new instance of command class ASSOCIATION_GROUP_INFO
23:22:02.177 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 7: Command class ASSOCIATION_GROUP_INFO, endpoint null created
23:22:02.177 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 7: Application update is adding command class ASSOCIATION_GROUP_INFO.
23:22:02.177 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 7: Adding command class ASSOCIATION_GROUP_INFO to the list of supported command classes.
23:22:02.177 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 7: Creating new instance of command class POWERLEVEL
23:22:02.177 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 7: Command class POWERLEVEL, endpoint null created
23:22:02.177 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 7: Application update is adding command class POWERLEVEL.
23:22:02.177 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 7: Adding command class POWERLEVEL to the list of supported command classes.
23:22:02.177 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 7: Creating new instance of command class SWITCH_MULTILEVEL
23:22:02.177 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 7: Command class SWITCH_MULTILEVEL, endpoint null created
23:22:02.177 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 7: Application update is adding command class SWITCH_MULTILEVEL.
23:22:02.177 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 7: Adding command class SWITCH_MULTILEVEL to the list of supported command classes.
23:22:02.178 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 7: Creating new instance of command class SWITCH_ALL
23:22:02.178 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 7: Command class SWITCH_ALL, endpoint null created
23:22:02.178 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 7: Application update is adding command class SWITCH_ALL.
23:22:02.178 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 7: Adding command class SWITCH_ALL to the list of supported command classes.
23:22:02.178 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 7: Creating new instance of command class CONFIGURATION
23:22:02.178 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 7: Command class CONFIGURATION, endpoint null created
23:22:02.178 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 7: Application update is adding command class CONFIGURATION.
23:22:02.178 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 7: Adding command class CONFIGURATION to the list of supported command classes.
23:22:02.178 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 7: Creating new instance of command class CRC_16_ENCAP
23:22:02.178 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 7: Command class CRC_16_ENCAP, endpoint null created
23:22:02.178 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 7: Application update is adding command class CRC_16_ENCAP.
23:22:02.178 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 7: Adding command class CRC_16_ENCAP to the list of supported command classes.
23:22:02.178 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 7: Creating new instance of command class SCENE_ACTUATOR_CONF
23:22:02.178 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 7: Command class SCENE_ACTUATOR_CONF, endpoint null created
23:22:02.178 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 7: Application update is adding command class SCENE_ACTUATOR_CONF.
23:22:02.178 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 7: Adding command class SCENE_ACTUATOR_CONF to the list of supported command classes.
23:22:02.180 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 7: Creating new instance of command class SCENE_ACTIVATION
23:22:02.180 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 7: Command class SCENE_ACTIVATION, endpoint null created
23:22:02.180 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 7: Application update is adding command class SCENE_ACTIVATION.
23:22:02.181 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 7: Adding command class SCENE_ACTIVATION to the list of supported command classes.
23:22:02.181 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 7: Creating new instance of command class FIRMWARE_UPDATE_MD
23:22:02.181 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 7: Command class FIRMWARE_UPDATE_MD, endpoint null created
23:22:02.181 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 7: Application update is adding command class FIRMWARE_UPDATE_MD.
23:22:02.181 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 7: Adding command class FIRMWARE_UPDATE_MD to the list of supported command classes.
23:22:02.181 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=SendData[0x13], type=Request[0x00], priority=Get, dest=4, callback=25, payload=04 02 25 02
23:22:02.181 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=ApplicationUpdate[0x49], type=Request[0x00], priority=High, dest=255, callback=0, payload=84 07 11 04 11 08 5E 86 72 5A 85 59 73 26 27 70 56 2C 2B 7A
23:22:02.181 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=ApplicationUpdate, callback id=25, expected=ApplicationCommandHandler, cancelled=false MISMATCH
23:22:02.180 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 01 41 D3 9C 01 04 11 08 E5
23:22:02.182 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
23:22:02.182 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 01 41 D3 9C 01 04 11 08 E5
23:22:02.182 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 01 41 D3 9C 01 04 11 08 E5
23:22:02.182 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=IdentifyNode[0x41], type=Response[0x01], priority=High, dest=255, callback=0, payload=D3 9C 01 04 11 08
23:22:02.182 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 7: ProtocolInfo
23:22:02.182 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 7: Listening = true
23:22:02.182 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 7: Routing = true
23:22:02.182 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 7: Beaming = true
23:22:02.183 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 07 03 26 03 00 D3
23:22:02.183 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 7: Version = 4
23:22:02.183 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 7: FLIRS = false
23:22:02.183 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 7: Security = false
23:22:02.183 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 7: Max Baud = 40000
23:22:02.184 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 7: Basic = Routing Slave
23:22:02.184 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 7: Generic = Multi-Level Switch
23:22:02.184 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 7: Specific device class 8 not found
23:22:02.184 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
23:22:02.184 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 04 00 07 03 26 03 00 D3
23:22:02.184 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 04 00 07 03 26 03 00 D3
23:22:02.184 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 07 03 26 03 00
23:22:02.184 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 7: Application Command Request (ALIVE:PROTOINFO)
23:22:02.184 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 7: Incoming command class SWITCH_MULTILEVEL
23:22:02.184 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 7: Received SWITCH_MULTILEVEL command V0
23:22:02.184 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 7: Switch Multi Level report, value = 0
23:22:02.184 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveCommandClassValueEvent
23:22:02.184 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 7: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
23:22:02.185 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 7: Got a value event from Z-Wave network, endpoint = 0, command class = SWITCH_MULTILEVEL, value = 0
23:22:02.185 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 255: Transaction not completed: node address inconsistent. lastSent=255, incoming=255
23:22:05.106 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 17 00 49 84 07 11 04 11 08 5E 86 72 5A 85 59 73 26 27 70 56 2C 2B 7A 2B
23:22:05.106 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
23:22:05.107 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 17 00 49 84 07 11 04 11 08 5E 86 72 5A 85 59 73 26 27 70 56 2C 2B 7A 2B
23:22:05.107 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 17 00 49 84 07 11 04 11 08 5E 86 72 5A 85 59 73 26 27 70 56 2C 2B 7A 2B
23:22:05.107 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationUpdate[0x49], type=Request[0x00], priority=High, dest=255, callback=0, payload=84 07 11 04 11 08 5E 86 72 5A 85 59 73 26 27 70 56 2C 2B 7A
23:22:05.107 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 7: Application update request. Node information received.
23:22:05.107 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=IdentifyNode[0x41], type=Request[0x00], priority=High, dest=255, callback=0, payload=07
23:22:05.107 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=ApplicationUpdate[0x49], type=Request[0x00], priority=High, dest=255, callback=0, payload=84 07 11 04 11 08 5E 86 72 5A 85 59 73 26 27 70 56 2C 2B 7A
23:22:05.107 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=ApplicationUpdate, callback id=0, expected=IdentifyNode, cancelled=false MISMATCH
23:22:05.116 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 07 03 26 03 63 B0
23:22:05.116 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
23:22:05.117 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 04 00 07 03 26 03 63 B0
23:22:05.117 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 00 04 00 07 03 26 03 63 B0
23:22:05.117 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], priority=High, dest=255, callback=0, payload=00 07 03 26 03 63
23:22:05.117 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 7: Application Command Request (ALIVE:PROTOINFO)
23:22:05.117 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 7: Incoming command class SWITCH_MULTILEVEL
23:22:05.117 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 7: Received SWITCH_MULTILEVEL command V0
23:22:05.117 [DEBUG] [ss.ZWaveMultiLevelSwitchCommandClass] - NODE 7: Switch Multi Level report, value = 99
23:22:05.117 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveCommandClassValueEvent
23:22:05.117 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 7: Got an event from Z-Wave network: ZWaveCommandClassValueEvent
23:22:05.117 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 7: Got a value event from Z-Wave network, endpoint = 0, command class = SWITCH_MULTILEVEL, value = 99
23:22:05.117 [DEBUG] [ssage.ApplicationCommandMessageClass] - NODE 255: Transaction not completed: node address inconsistent. lastSent=255, incoming=255
23:22:07.175 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 7: Stage PROTOINFO. Initialisation retry timer triggered. Increased to 10000
23:22:07.175 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 7: Node advancer - PROTOINFO: queue length(0), free to send(false)
23:22:07.175 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 7: Initialisation retry timer started 10000
23:22:07.175 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 7: Node advancer: loop - PROTOINFO try 1: stageAdvanced(false)
23:22:07.175 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 7: Node advancer: PROTOINFO - send IdentifyNode
23:22:07.176 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 7: Node advancer - queued packet. Queue length is 1
23:22:07.176 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
23:22:07.178 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 255: Too many retries. Discarding message: Message: class=IdentifyNode[0x41], type=Request[0x00], priority=High, dest=255, callback=0, payload=07
...
23:23:32.178 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 255: Timeout while sending message. Requeueing - 0 attempts left!
23:23:32.178 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
23:23:32.179 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
23:23:32.179 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 41 07 BD
23:23:32.179 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 04 00 41 07 BD
23:23:32.180 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 01 41 D3 9C 01 04 11 08 E5
23:23:32.180 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
23:23:32.181 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 01 41 D3 9C 01 04 11 08 E5
23:23:32.181 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 01 41 D3 9C 01 04 11 08 E5
23:23:32.181 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=IdentifyNode[0x41], type=Response[0x01], priority=High, dest=255, callback=0, payload=D3 9C 01 04 11 08
23:23:32.181 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 7: ProtocolInfo
23:23:32.181 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 7: Listening = true
23:23:32.181 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 7: Routing = true
23:23:32.181 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 7: Beaming = true
23:23:32.181 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 7: Version = 4
23:23:32.181 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 7: FLIRS = false
23:23:32.181 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 7: Security = false
23:23:32.181 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 7: Max Baud = 40000
23:23:32.181 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 7: Basic = Routing Slave
23:23:32.181 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 7: Generic = Multi-Level Switch
23:23:32.181 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 7: Specific device class 8 not found
23:23:37.179 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 255: Too many retries. Discarding message: Message: class=IdentifyNode[0x41], type=Request[0x00], priority=High, dest=255, callback=0, payload=07
23:24:09.797 [WARN ] [e.sshd.server.channel.ChannelSession] - Unknown pty opcode value: 42
Does this indicate that there is something wrong with the device?
It indicates that the binding has not downloaded all the data it needs to discover the device.
I don’t know if my initial installation of 2.2.0 was borked. I just installed the the 2.2.0 zwave binding on my openHAB 2.1.0 installation, it finally detected the fan! Thanks for the help!
Thanks for 2.2, my fan is working now. Question though, since we are using a snapshot, how do we get updates? Will this be incorporated into the main binding at some point?
To update the snapshot binding, just uninstall it using PaperUI/HABmin, wait 30 seconds, and reinstall it.
The snapshot will become the next release, so when the next release is made it will be in 2.2.