Z Wave Trouble getting Vision ZD2102 Door and ZG8101 Garage sensors to report

Hi. New to OH but I’ve managed to get everything working with the exception of two Z wave devices. The devices report back as’ ZD2102 Door Window Sensor’ and ‘ZG8101 Garage Door Tilt Sensor’. These devices show up in habmin and the garage sensor occasionally reports it’s battery level. I think the door sensor may have reported the battery sensor level before as well. Neither report their statuses (open/closed). I am using org.openhab.binding.zwave-1.8.3.jar binding. I see that both devices are listed at https://github.com/openhab/openhab/tree/master/bundles/binding/org.openhab.binding.zwave/database/vision

My devices look like this:

Contact	Door_Laundry			"Laundry Door [%s]"			<door>		(Laundry,Doors)		{ zwave="6:command=SENSOR_BINARY,respond_to_basic=true,sensor_type=10" }
Number	Door_Laundry_Battery	        "Laundry Door battery [%d %%]"		<battery>	(Laundry,Battery)	{ zwave="6:command=BATTERY" }
Contact	Door_Garage		        "Garage Door [%s]"			<door>		(Garage,Doors)		{ zwave="7:command=SENSOR_BINARY,respond_to_basic=true,sensor_type=10" }
Number	Door_Garage_Battery		"Garage Door battery [%d %%]"		<battery>	(Garage,Battery)	{ zwave="7:command=BATTERY" }

Can anyone help me troubleshoot this? Many thanks!

  1. check if the association group is set to the controller (via habmin)
  2. try removing the sensor_type=10
  3. make sure the devices are fully initialized (should show green in habmin)

@sihui Thanks for the reply. I’m not at home right now, but This is what I’m seeing in habmin:


Any thoughts?

No, that’s weird:
The green node 7 does work and has no association to the controller?
And the grey node 6 does not work and has an association to the controller???

Or is it the other way around?

In either case: add node 7 to node 1 in the association … like it is for node 6.

Edit: could be you have two problems: first one node 6 is not fully initialized, wake it up several times manually, second, note 7 does not report to the controller because the association is not set.

When you say wake it up, are you saying open/close the door a bunch of times? I’ve added node 7 to node 1. ‘Member’ shows up as yellow which I’m guessing is because the sensor is sleeping.

No, opening/closing doesn’t wake it up, there should be a little button on the device (often the same button you have used to include it to the zwave network), this sends a NIF and sends data to the controller. You may have to do that several times.

< gesendet von Samsung Smartphone >

Hmm… there is a small button used for pairing but that is supposed to be used as a tamper prevention…

You should take a look into the manual if that button is also for NIF/waking up. Sometimes one click is for pairing, three rapid clicks for NIF.

< gesendet von Samsung Smartphone >

@sihui Thanks again for working with me on this. This is what the manual says:

  1. For “Inclusion” in (adding to) a network: Put the Z-Wave™ Interface Controller into
    “inclusion” mode, and following its instruction to add the ZD2102 to your controller. To
    get in the “inclusion” mode, the distance between sensor and controller is suggested
    to be in one meter. Press the program switch of ZD2102 for 1 second at least.
    -1-
    The LED on the ZD2102 should go solid, if not, please try again.
    For “Exclusion” from (removing from) a network: Put the Z-Wave™ Interface
    Controller into “exclusion” mode, and following its instruction to delete the ZD2102 to
    your controller. Press the program switch of ZD2102 for 1 second at least to be
    excluded.
    For “Association”: removing the cover of the ZD2102 to get into the “Awake” mode,
    then put the Z-Wave™ Interface Controller into “Association”, and following its
    instruction to associate the ZD2102 with other device. Close the cover back after
    “association” done, afterward the ZD2102 will get into “Sleep” mode for power saving.
    Support one association group (5 nodes).
    ”Awake” mode: it is to leave the “Sleep” mode by removing the cover of ZD2102, to
    allow the Z-Wave™ Interface Controller to do “Inclusion”, “Exclusion”, “Association”
    and to reply and receive the commands from controller.
    http://download.telldus.se/Manuals/Z-Wave/Vision/ZD2102.pdf

So I’m guessing I need to pull the cover and bring the device close to the controller (Z Stick 2) and it will automatically update? Again, I’m away from home so I can’t try this until this evening.

That is how I understand it too, but my native language is not English, so maybe you are on your own :slight_smile:

< gesendet von Samsung Smartphone >

Did you manage to ‘associate’ this device into a group?
I’ve got 2 exact the same devices, they’re nicely green, but also not associated in a group… :blush:

Yes. I followed the directions sihui provided and the device worked very near the controller but not on location. I changed the battery and it now works on location and has operated without problem for many weeks now. Good luck.

In my case, it was new out of the box, and the distance is about 6meters. And it’s the same for 2 different garage sensors. So I doubt it would be an issue with the battery itself?
I see in the logs a lot of entries when I tamper the key, but no association so for. I’ve also tried to excluded it, and re-included it.

> zwave.log:2016-07-22 19:04:25.638 [INFO ] [rialApiGetInitDataMessageClass:57  ]- NODE 29: Node found
> zwave.log:2016-07-22 19:04:25.646 [DEBUG] [b.z.i.protocol.ZWaveController:493 ]- NODE 29: Init node thread start
> zwave.log:2016-07-22 19:04:25.894 [DEBUG] [.b.z.i.p.i.ZWaveNodeSerializer:138 ]- NODE 29: Serializing from file /var/lib/openhab/zwave/node29.xml
> zwave.log:2016-07-22 19:04:26.309 [DEBUG] [b.z.i.protocol.ZWaveController:529 ]- NODE 29: Restore from config: Ok.
> zwave.log:2016-07-22 19:04:26.341 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:269 ]- NODE 29: Node advancer - EMPTYNODE: queue length(0), free to send(true)
> zwave.log:2016-07-22 19:04:26.341 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:335 ]- NODE 29: Node advancer: loop - EMPTYNODE try 1: stageAdvanced(false)
> zwave.log:2016-07-22 19:04:26.341 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:340 ]- NODE 29: Node advancer: Initialisation starting
> zwave.log:2016-07-22 19:04:26.341 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:868 ]- NODE 29: Node advancer - advancing to PROTOINFO
> zwave.log:2016-07-22 19:04:26.341 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:335 ]- NODE 29: Node advancer: loop - PROTOINFO try 0: stageAdvanced(true)
> zwave.log:2016-07-22 19:04:26.341 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:349 ]- NODE 29: Node advancer: PROTOINFO - send IdentifyNode
> zwave.log:2016-07-22 19:04:26.342 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:242 ]- NODE 29: Node advancer - queued packet. Queue length is 1
> zwave.log:2016-07-22 19:04:26.342 [DEBUG] [b.z.i.protocol.ZWaveController:585 ]- NODE 29: Init node thread finished
> zwave.log:2016-07-22 19:04:26.647 [DEBUG] [i.p.s.IdentifyNodeMessageClass:52  ]- NODE 29: ProtocolInfo
> zwave.log:2016-07-22 19:04:26.647 [DEBUG] [i.p.s.IdentifyNodeMessageClass:68  ]- NODE 29: Listening = false
> zwave.log:2016-07-22 19:04:26.647 [DEBUG] [i.p.s.IdentifyNodeMessageClass:69  ]- NODE 29: Routing = true
> zwave.log:2016-07-22 19:04:26.647 [DEBUG] [i.p.s.IdentifyNodeMessageClass:70  ]- NODE 29: Beaming = true
> zwave.log:2016-07-22 19:04:26.648 [DEBUG] [i.p.s.IdentifyNodeMessageClass:71  ]- NODE 29: Version = 4
> zwave.log:2016-07-22 19:04:26.648 [DEBUG] [i.p.s.IdentifyNodeMessageClass:72  ]- NODE 29: FLIRS = false
> zwave.log:2016-07-22 19:04:26.648 [DEBUG] [i.p.s.IdentifyNodeMessageClass:73  ]- NODE 29: Security = false
> zwave.log:2016-07-22 19:04:26.648 [DEBUG] [i.p.s.IdentifyNodeMessageClass:74  ]- NODE 29: Max Baud = 40000
> zwave.log:2016-07-22 19:04:26.648 [DEBUG] [i.p.s.IdentifyNodeMessageClass:89  ]- NODE 29: Basic = Routing Slave
> zwave.log:2016-07-22 19:04:26.648 [DEBUG] [i.p.s.IdentifyNodeMessageClass:96  ]- NODE 29: Generic = Binary Sensor
> zwave.log:2016-07-22 19:04:26.648 [DEBUG] [i.p.s.IdentifyNodeMessageClass:103 ]- NODE 29: Specific = Routing Binary Sensor
> zwave.log:2016-07-22 19:04:26.648 [DEBUG] [.o.b.z.i.p.c.ZWaveCommandClass:225 ]- NODE 29: Creating new instance of command class NO_OPERATION
> zwave.log:2016-07-22 19:04:26.648 [DEBUG] [.o.b.z.i.p.c.ZWaveCommandClass:225 ]- NODE 29: Creating new instance of command class BASIC
> zwave.log:2016-07-22 19:04:26.648 [DEBUG] [.o.b.z.i.p.c.ZWaveCommandClass:225 ]- NODE 29: Creating new instance of command class SENSOR_BINARY
> zwave.log:2016-07-22 19:04:26.648 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:1013]- NODE 29: Node advancer - PROTOINFO: Transaction complete (IdentifyNode:Request) success(true)
> zwave.log:2016-07-22 19:04:26.648 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:203 ]- NODE 29: Node advancer - checking initialisation queue. Queue size 1.
> zwave.log:2016-07-22 19:04:26.648 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:209 ]- NODE 29: Node advancer - message removed from queue. Queue size 0.
> zwave.log:2016-07-22 19:04:26.648 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:269 ]- NODE 29: Node advancer - PROTOINFO: queue length(0), free to send(true)
> zwave.log:2016-07-22 19:04:26.649 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:335 ]- NODE 29: Node advancer: loop - PROTOINFO try 1: stageAdvanced(false)
> zwave.log:2016-07-22 19:04:26.650 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:868 ]- NODE 29: Node advancer - advancing to NEIGHBORS
> zwave.log:2016-07-22 19:04:26.650 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:335 ]- NODE 29: Node advancer: loop - NEIGHBORS try 0: stageAdvanced(true)
> zwave.log:2016-07-22 19:04:26.650 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:359 ]- NODE 29: Node advancer: NEIGHBORS - send RoutingInfo
> zwave.log:2016-07-22 19:04:26.650 [DEBUG] [p.s.GetRoutingInfoMessageClass:29  ]- NODE 29: Request routing info
> zwave.log:2016-07-22 19:04:26.650 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:242 ]- NODE 29: Node advancer - queued packet. Queue length is 1
> zwave.log:2016-07-22 19:04:26.692 [DEBUG] [.z.internal.ZWaveActiveBinding:192 ]- NODE 29: Polling list: item Sensor10_Batterij is not completed initialisation
> zwave.log:2016-07-22 19:04:26.700 [DEBUG] [.z.internal.ZWaveActiveBinding:192 ]- NODE 29: Polling list: item Sensor10 is not completed initialisation
> zwave.log:2016-07-22 19:04:27.242 [DEBUG] [p.s.GetRoutingInfoMessageClass:47  ]- NODE 29: Got NodeRoutingInfo request.
> zwave.log:2016-07-22 19:04:27.242 [DEBUG] [p.s.GetRoutingInfoMessageClass:78  ]- NODE 29: Neighbor nodes: 1 10 11 27
> zwave.log:2016-07-22 19:04:27.242 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:1013]- NODE 29: Node advancer - NEIGHBORS: Transaction complete (GetRoutingInfo:Request) success(true)
> zwave.log:2016-07-22 19:04:27.242 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:203 ]- NODE 29: Node advancer - checking initialisation queue. Queue size 1.
> zwave.log:2016-07-22 19:04:27.242 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:209 ]- NODE 29: Node advancer - message removed from queue. Queue size 0.
> zwave.log:2016-07-22 19:04:27.243 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:269 ]- NODE 29: Node advancer - NEIGHBORS: queue length(0), free to send(true)
> zwave.log:2016-07-22 19:04:27.243 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:335 ]- NODE 29: Node advancer: loop - NEIGHBORS try 1: stageAdvanced(false)
> zwave.log:2016-07-22 19:04:27.243 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:868 ]- NODE 29: Node advancer - advancing to FAILED_CHECK
> zwave.log:2016-07-22 19:04:27.243 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:335 ]- NODE 29: Node advancer: loop - FAILED_CHECK try 0: stageAdvanced(true)
> zwave.log:2016-07-22 19:04:27.243 [DEBUG] [i.p.s.IsFailedNodeMessageClass:31  ]- NODE 29: Requesting IsFailedNode status from controller.
> zwave.log:2016-07-22 19:04:27.243 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:242 ]- NODE 29: Node advancer - queued packet. Queue length is 1
> zwave.log:2016-07-22 19:04:27.780 [DEBUG] [i.p.s.IsFailedNodeMessageClass:54  ]- NODE 29: Is currently marked as healthy by the controller
> zwave.log:2016-07-22 19:04:27.780 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:1013]- NODE 29: Node advancer - FAILED_CHECK: Transaction complete (IsFailedNodeID:Request) success(true)
> zwave.log:2016-07-22 19:04:27.780 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:203 ]- NODE 29: Node advancer - checking initialisation queue. Queue size 1.
> zwave.log:2016-07-22 19:04:27.780 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:209 ]- NODE 29: Node advancer - message removed from queue. Queue size 0.
> zwave.log:2016-07-22 19:04:27.780 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:269 ]- NODE 29: Node advancer - FAILED_CHECK: queue length(0), free to send(true)
> zwave.log:2016-07-22 19:04:27.780 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:335 ]- NODE 29: Node advancer: loop - FAILED_CHECK try 1: stageAdvanced(false)
> zwave.log:2016-07-22 19:04:27.781 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:868 ]- NODE 29: Node advancer - advancing to WAIT
> zwave.log:2016-07-22 19:04:27.781 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:335 ]- NODE 29: Node advancer: loop - WAIT try 0: stageAdvanced(true)
> zwave.log:2016-07-22 19:04:27.781 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:382 ]- NODE 29: Node advancer: WAIT - Listening=false, FrequentlyListening=false
> zwave.log:2016-07-22 19:04:27.781 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:400 ]- NODE 29: Node advancer: WAIT - Still waiting!
> zwave.log:2016-07-22 19:04:33.660 [DEBUG] [.z.internal.ZWaveActiveBinding:192 ]- NODE 29: Polling list: item Sensor10_Batterij is not completed initialisation
> zwave.log:2016-07-22 19:04:33.675 [DEBUG] [.z.internal.ZWaveActiveBinding:192 ]- NODE 29: Polling list: item Sensor10 is not completed initialisation
> zwave.log:2016-07-22 19:04:33.920 [DEBUG] [.z.internal.ZWaveActiveBinding:192 ]- NODE 29: Polling list: item Sensor10_Batterij is not completed initialisation
> zwave.log:2016-07-22 19:04:33.931 [DEBUG] [.z.internal.ZWaveActiveBinding:192 ]- NODE 29: Polling list: item Sensor10 is not completed initialisation
> zwave.log:2016-07-22 19:04:34.258 [DEBUG] [.z.internal.ZWaveActiveBinding:192 ]- NODE 29: Polling list: item Sensor10_Batterij is not completed initialisation
> zwave.log:2016-07-22 19:04:34.261 [DEBUG] [.z.internal.ZWaveActiveBinding:192 ]- NODE 29: Polling list: item Sensor10 is not completed initialisation
> zwave.log:2016-07-22 19:04:46.275 [DEBUG] [.z.internal.ZWaveActiveBinding:192 ]- NODE 29: Polling list: item Sensor10_Batterij is not completed initialisation
> zwave.log:2016-07-22 19:04:46.281 [DEBUG] [.z.internal.ZWaveActiveBinding:192 ]- NODE 29: Polling list: item Sensor10 is not completed initialisation
> zwave.log:2016-07-22 19:05:12.216 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:999 ]- NODE 29: Node advancer - WAIT: The WAIT is over!
> zwave.log:2016-07-22 19:05:12.216 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:203 ]- NODE 29: Node advancer - checking initialisation queue. Queue size 0.
> zwave.log:2016-07-22 19:05:51.896 [DEBUG] [.z.internal.ZWaveActiveBinding:192 ]- NODE 29: Polling list: item Sensor10_Batterij is not completed initialisation
> zwave.log:2016-07-22 19:05:51.899 [DEBUG] [.z.internal.ZWaveActiveBinding:192 ]- NODE 29: Polling list: item Sensor10 is not completed initialisation
> zwave.log:2016-07-22 19:07:02.307 [DEBUG] [ApplicationCommandMessageClass:38  ]- NODE 29: Application Command Request (ALIVE:PING)
> zwave.log:2016-07-22 19:07:02.307 [DEBUG] [ApplicationCommandMessageClass:56  ]- NODE 29: Incoming command class WAKE_UP
> zwave.log:2016-07-22 19:07:02.307 [DEBUG] [.i.p.c.ZWaveWakeUpCommandClass:136 ]- NODE 29: Received Wake Up Request
> zwave.log:2016-07-22 19:07:02.307 [DEBUG] [.i.p.c.ZWaveWakeUpCommandClass:182 ]- NODE 29: Received WAKE_UP_NOTIFICATION
> zwave.log:2016-07-22 19:07:02.307 [DEBUG] [.i.p.c.ZWaveWakeUpCommandClass:411 ]- NODE 29: Is awake with 0 messages in the wake-up queue.
> zwave.log:2016-07-22 19:07:02.307 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:1036]- NODE 29: Wakeup during initialisation.
> zwave.log:2016-07-22 19:07:02.307 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:269 ]- NODE 29: Node advancer - PING: queue length(0), free to send(true)
> zwave.log:2016-07-22 19:07:02.307 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:335 ]- NODE 29: Node advancer: loop - PING try 1: stageAdvanced(false)
> zwave.log:2016-07-22 19:07:02.307 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:419 ]- NODE 29: Node advancer: PING - send NoOperation
> zwave.log:2016-07-22 19:07:02.307 [DEBUG] [c.ZWaveNoOperationCommandClass:72  ]- NODE 29: Creating new message for command No Operation
> zwave.log:2016-07-22 19:07:02.307 [DEBUG] [o.b.z.i.protocol.SerialMessage:109 ]- NODE 29: Creating empty message of class = SendData (0x13), type = Request (0x00)
> zwave.log:2016-07-22 19:07:02.308 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:242 ]- NODE 29: Node advancer - queued packet. Queue length is 1
> zwave.log:2016-07-22 19:07:02.308 [DEBUG] [WaveController$ZWaveSendThread:1268]- NODE 29: Sending REQUEST Message = 01 08 00 13 1D 01 00 25 32 EF 
> zwave.log:2016-07-22 19:07:02.324 [DEBUG] [b.z.i.p.s.SendDataMessageClass:38  ]- NODE 29: Sent Data successfully placed on stack.
> zwave.log:2016-07-22 19:07:02.424 [DEBUG] [b.z.i.p.s.SendDataMessageClass:74  ]- NODE 29: SendData Request. CallBack ID = 50, Status = Transmission complete and ACK received(0)
> zwave.log:2016-07-22 19:07:02.425 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:1013]- NODE 29: Node advancer - PING: Transaction complete (SendData:Request) success(true)
> zwave.log:2016-07-22 19:07:02.425 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:203 ]- NODE 29: Node advancer - checking initialisation queue. Queue size 1.
> zwave.log:2016-07-22 19:07:02.425 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:209 ]- NODE 29: Node advancer - message removed from queue. Queue size 0.
> zwave.log:2016-07-22 19:07:02.425 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:269 ]- NODE 29: Node advancer - PING: queue length(0), free to send(true)
> zwave.log:2016-07-22 19:07:02.425 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:335 ]- NODE 29: Node advancer: loop - PING try 2: stageAdvanced(false)
> zwave.log:2016-07-22 19:07:02.425 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:868 ]- NODE 29: Node advancer - advancing to DETAILS
> zwave.log:2016-07-22 19:07:02.425 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:335 ]- NODE 29: Node advancer: loop - DETAILS try 0: stageAdvanced(true)
> zwave.log:2016-07-22 19:07:02.425 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:437 ]- NODE 29: Node advancer: Restored from file - skipping static initialisation
> zwave.log:2016-07-22 19:07:02.425 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:868 ]- NODE 29: Node advancer - advancing to DYNAMIC_VALUES
> zwave.log:2016-07-22 19:07:02.425 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:335 ]- NODE 29: Node advancer: loop - DYNAMIC_VALUES try 0: stageAdvanced(true)
> zwave.log:2016-07-22 19:07:02.425 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:781 ]- NODE 29: Node advancer: DYNAMIC_VALUES - checking SENSOR_BINARY
> zwave.log:2016-07-22 19:07:02.425 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:784 ]- NODE 29: Node advancer: DYNAMIC_VALUES - found    SENSOR_BINARY
> zwave.log:2016-07-22 19:07:02.425 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:788 ]- NODE 29: Found 1 instances of SENSOR_BINARY
> zwave.log:2016-07-22 19:07:02.425 [DEBUG] [.ZWaveBinarySensorCommandClass:128 ]- NODE 29: Creating new message for application command SENSOR_BINARY_GET
> zwave.log:2016-07-22 19:07:02.425 [DEBUG] [o.b.z.i.protocol.SerialMessage:109 ]- NODE 29: Creating empty message of class = SendData (0x13), type = Request (0x00)
> zwave.log:2016-07-22 19:07:02.425 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:781 ]- NODE 29: Node advancer: DYNAMIC_VALUES - checking NO_OPERATION
> zwave.log:2016-07-22 19:07:02.425 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:781 ]- NODE 29: Node advancer: DYNAMIC_VALUES - checking BASIC
> zwave.log:2016-07-22 19:07:02.426 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:781 ]- NODE 29: Node advancer: DYNAMIC_VALUES - checking VERSION
> zwave.log:2016-07-22 19:07:02.426 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:781 ]- NODE 29: Node advancer: DYNAMIC_VALUES - checking BATTERY
> zwave.log:2016-07-22 19:07:02.426 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:784 ]- NODE 29: Node advancer: DYNAMIC_VALUES - found    BATTERY
> zwave.log:2016-07-22 19:07:02.426 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:788 ]- NODE 29: Found 1 instances of BATTERY
> zwave.log:2016-07-22 19:07:02.426 [DEBUG] [i.p.c.ZWaveBatteryCommandClass:137 ]- NODE 29: Creating new message for application command BATTERY_GET
> zwave.log:2016-07-22 19:07:02.426 [DEBUG] [o.b.z.i.protocol.SerialMessage:109 ]- NODE 29: Creating empty message of class = SendData (0x13), type = Request (0x00)
> zwave.log:2016-07-22 19:07:02.426 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:781 ]- NODE 29: Node advancer: DYNAMIC_VALUES - checking ASSOCIATION
> zwave.log:2016-07-22 19:07:02.426 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:781 ]- NODE 29: Node advancer: DYNAMIC_VALUES - checking ALARM
> zwave.log:2016-07-22 19:07:02.426 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:784 ]- NODE 29: Node advancer: DYNAMIC_VALUES - found    ALARM
> zwave.log:2016-07-22 19:07:02.426 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:788 ]- NODE 29: Found 1 instances of ALARM
> zwave.log:2016-07-22 19:07:02.426 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:781 ]- NODE 29: Node advancer: DYNAMIC_VALUES - checking WAKE_UP
> zwave.log:2016-07-22 19:07:02.426 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:781 ]- NODE 29: Node advancer: DYNAMIC_VALUES - checking MANUFACTURER_SPECIFIC
> zwave.log:2016-07-22 19:07:02.426 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:816 ]- NODE 29: Node advancer: DYNAMIC_VALUES - queued 2 frames
> zwave.log:2016-07-22 19:07:02.426 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:242 ]- NODE 29: Node advancer - queued packet. Queue length is 2
> zwave.log:2016-07-22 19:07:02.428 [DEBUG] [WaveController$ZWaveSendThread:1327]- NODE 29: Response processed after 120ms/4868ms.
> zwave.log:2016-07-22 19:07:02.428 [DEBUG] [WaveController$ZWaveSendThread:1268]- NODE 29: Sending REQUEST Message = 01 09 00 13 1D 02 30 02 25 33 DE 
> zwave.log:2016-07-22 19:07:02.442 [DEBUG] [b.z.i.p.s.SendDataMessageClass:38  ]- NODE 29: Sent Data successfully placed on stack.
> zwave.log:2016-07-22 19:07:02.489 [DEBUG] [b.z.i.p.s.SendDataMessageClass:74  ]- NODE 29: SendData Request. CallBack ID = 51, Status = Transmission complete and ACK received(0)
> zwave.log:2016-07-22 19:07:02.538 [DEBUG] [ApplicationCommandMessageClass:38  ]- NODE 29: Application Command Request (ALIVE:DYNAMIC_VALUES)
> zwave.log:2016-07-22 19:07:02.538 [DEBUG] [ApplicationCommandMessageClass:56  ]- NODE 29: Incoming command class SENSOR_BINARY
> zwave.log:2016-07-22 19:07:02.538 [DEBUG] [.ZWaveBinarySensorCommandClass:82  ]- NODE 29: Received Sensor Binary Request (v1)
> zwave.log:2016-07-22 19:07:02.538 [DEBUG] [.ZWaveBinarySensorCommandClass:102 ]- NODE 29: Sensor Binary report, type=Unknown, value=255
> zwave.log:2016-07-22 19:07:02.538 [DEBUG] [.z.internal.ZWaveActiveBinding:450 ]- NODE 29: Got a value event from Z-Wave network, endpoint = 0, command class = SENSOR_BINARY, value = 255
> zwave.log:2016-07-22 19:07:02.540 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:1013]- NODE 29: Node advancer - DYNAMIC_VALUES: Transaction complete (SendData:Request) success(true)
> zwave.log:2016-07-22 19:07:02.540 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:203 ]- NODE 29: Node advancer - checking initialisation queue. Queue size 2.
> zwave.log:2016-07-22 19:07:02.540 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:209 ]- NODE 29: Node advancer - message removed from queue. Queue size 1.
> zwave.log:2016-07-22 19:07:02.540 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:269 ]- NODE 29: Node advancer - DYNAMIC_VALUES: queue length(1), free to send(true)
> zwave.log:2016-07-22 19:07:02.540 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:242 ]- NODE 29: Node advancer - queued packet. Queue length is 1
> zwave.log:2016-07-22 19:07:02.540 [DEBUG] [WaveController$ZWaveSendThread:1327]- NODE 29: Response processed after 112ms/4868ms.
> zwave.log:2016-07-22 19:07:02.541 [DEBUG] [WaveController$ZWaveSendThread:1268]- NODE 29: Sending REQUEST Message = 01 09 00 13 1D 02 80 02 25 34 69 
> zwave.log:2016-07-22 19:07:02.553 [DEBUG] [b.z.i.p.s.SendDataMessageClass:38  ]- NODE 29: Sent Data successfully placed on stack.
> zwave.log:2016-07-22 19:07:02.660 [DEBUG] [b.z.i.p.s.SendDataMessageClass:74  ]- NODE 29: SendData Request. CallBack ID = 52, Status = Transmission complete and ACK received(0)
> zwave.log:2016-07-22 19:07:02.715 [DEBUG] [ApplicationCommandMessageClass:38  ]- NODE 29: Application Command Request (ALIVE:DYNAMIC_VALUES)
> zwave.log:2016-07-22 19:07:02.715 [DEBUG] [ApplicationCommandMessageClass:56  ]- NODE 29: Incoming command class BATTERY
> zwave.log:2016-07-22 19:07:02.715 [DEBUG] [i.p.c.ZWaveBatteryCommandClass:81  ]- NODE 29: Received Battery Request
> zwave.log:2016-07-22 19:07:02.715 [DEBUG] [i.p.c.ZWaveBatteryCommandClass:96  ]- NODE 29: Battery report value = 100
> zwave.log:2016-07-22 19:07:02.715 [DEBUG] [.z.internal.ZWaveActiveBinding:450 ]- NODE 29: Got a value event from Z-Wave network, endpoint = 0, command class = BATTERY, value = 100
> zwave.log:2016-07-22 19:07:02.716 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:1013]- NODE 29: Node advancer - DYNAMIC_VALUES: Transaction complete (SendData:Request) success(true)
> zwave.log:2016-07-22 19:07:02.716 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:203 ]- NODE 29: Node advancer - checking initialisation queue. Queue size 1.
> zwave.log:2016-07-22 19:07:02.716 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:209 ]- NODE 29: Node advancer - message removed from queue. Queue size 0.
> zwave.log:2016-07-22 19:07:02.719 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:269 ]- NODE 29: Node advancer - DYNAMIC_VALUES: queue length(0), free to send(true)
> zwave.log:2016-07-22 19:07:02.719 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:335 ]- NODE 29: Node advancer: loop - DYNAMIC_VALUES try 1: stageAdvanced(false)
> zwave.log:2016-07-22 19:07:02.719 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:781 ]- NODE 29: Node advancer: DYNAMIC_VALUES - checking SENSOR_BINARY
> zwave.log:2016-07-22 19:07:02.719 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:784 ]- NODE 29: Node advancer: DYNAMIC_VALUES - found    SENSOR_BINARY
> zwave.log:2016-07-22 19:07:02.719 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:788 ]- NODE 29: Found 1 instances of SENSOR_BINARY
> zwave.log:2016-07-22 19:07:02.719 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:781 ]- NODE 29: Node advancer: DYNAMIC_VALUES - checking NO_OPERATION
> zwave.log:2016-07-22 19:07:02.719 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:781 ]- NODE 29: Node advancer: DYNAMIC_VALUES - checking BASIC
> zwave.log:2016-07-22 19:07:02.719 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:781 ]- NODE 29: Node advancer: DYNAMIC_VALUES - checking VERSION
> zwave.log:2016-07-22 19:07:02.719 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:781 ]- NODE 29: Node advancer: DYNAMIC_VALUES - checking BATTERY
> zwave.log:2016-07-22 19:07:02.720 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:784 ]- NODE 29: Node advancer: DYNAMIC_VALUES - found    BATTERY
> zwave.log:2016-07-22 19:07:02.720 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:788 ]- NODE 29: Found 1 instances of BATTERY
> zwave.log:2016-07-22 19:07:02.720 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:781 ]- NODE 29: Node advancer: DYNAMIC_VALUES - checking ASSOCIATION
> zwave.log:2016-07-22 19:07:02.720 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:781 ]- NODE 29: Node advancer: DYNAMIC_VALUES - checking ALARM
> zwave.log:2016-07-22 19:07:02.720 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:784 ]- NODE 29: Node advancer: DYNAMIC_VALUES - found    ALARM
> zwave.log:2016-07-22 19:07:02.720 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:788 ]- NODE 29: Found 1 instances of ALARM
> zwave.log:2016-07-22 19:07:02.720 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:781 ]- NODE 29: Node advancer: DYNAMIC_VALUES - checking WAKE_UP
> zwave.log:2016-07-22 19:07:02.720 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:781 ]- NODE 29: Node advancer: DYNAMIC_VALUES - checking MANUFACTURER_SPECIFIC
> zwave.log:2016-07-22 19:07:02.720 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:816 ]- NODE 29: Node advancer: DYNAMIC_VALUES - queued 0 frames
> zwave.log:2016-07-22 19:07:02.720 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:868 ]- NODE 29: Node advancer - advancing to DONE
> zwave.log:2016-07-22 19:07:02.720 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:335 ]- NODE 29: Node advancer: loop - DONE try 0: stageAdvanced(true)
> zwave.log:2016-07-22 19:07:02.720 [DEBUG] [.b.z.i.p.i.ZWaveNodeSerializer:107 ]- NODE 29: Serializing to file /var/lib/openhab/zwave/node29.xml
> zwave.log:2016-07-22 19:07:02.732 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:827 ]- NODE 29: Node advancer: Initialisation complete!
> zwave.log:2016-07-22 19:07:02.732 [DEBUG] [.z.internal.ZWaveActiveBinding:425 ]- NODE 29: ZWaveIncomingEvent Called, Network Event, Init Done. Setting device ready.
> zwave.log:2016-07-22 19:07:02.749 [DEBUG] [WaveController$ZWaveSendThread:1327]- NODE 29: Response processed after 208ms/4868ms.
> zwave.log:2016-07-22 19:07:03.716 [DEBUG] [.i.p.c.ZWaveWakeUpCommandClass:506 ]- NODE 29: No more messages, go back to sleep
> zwave.log:2016-07-22 19:07:03.716 [DEBUG] [.i.p.c.ZWaveWakeUpCommandClass:202 ]- NODE 29: Creating new message for application command WAKE_UP_NO_MORE_INFORMATION
> zwave.log:2016-07-22 19:07:03.716 [DEBUG] [o.b.z.i.protocol.SerialMessage:109 ]- NODE 29: Creating empty message of class = SendData (0x13), type = Request (0x00)
> zwave.log:2016-07-22 19:07:08.413 [DEBUG] [WaveController$ZWaveSendThread:1268]- NODE 29: Sending REQUEST Message = 01 09 00 13 1D 02 84 08 25 37 64 
> zwave.log:2016-07-22 19:07:08.423 [DEBUG] [b.z.i.p.s.SendDataMessageClass:38  ]- NODE 29: Sent Data successfully placed on stack.
> zwave.log:2016-07-22 19:07:08.476 [DEBUG] [b.z.i.p.s.SendDataMessageClass:74  ]- NODE 29: SendData Request. CallBack ID = 55, Status = Transmission complete and ACK received(0)
> zwave.log:2016-07-22 19:07:08.476 [DEBUG] [.i.p.c.ZWaveWakeUpCommandClass:372 ]- NODE 29: Went to sleep
> zwave.log:2016-07-22 19:07:08.476 [DEBUG] [.i.p.c.ZWaveWakeUpCommandClass:435 ]- NODE 29: Is sleeping
> zwave.log:2016-07-22 19:07:08.476 [DEBUG] [WaveController$ZWaveSendThread:1327]- NODE 29: Response processed after 63ms/4868ms.
> zwave.log:2016-07-22 19:07:13.420 [DEBUG] [.b.z.i.c.ZWaveBatteryConverter:60  ]- NODE 29: Generating poll message for BATTERY endpoint 0
> zwave.log:2016-07-22 19:07:13.422 [DEBUG] [i.p.c.ZWaveBatteryCommandClass:137 ]- NODE 29: Creating new message for application command BATTERY_GET
> zwave.log:2016-07-22 19:07:13.422 [DEBUG] [o.b.z.i.protocol.SerialMessage:109 ]- NODE 29: Creating empty message of class = SendData (0x13), type = Request (0x00)
> zwave.log:2016-07-22 19:07:13.423 [DEBUG] [.i.p.c.ZWaveWakeUpCommandClass:241 ]- NODE 29: Putting message SendData in wakeup queue.

ps I just noticed that I’m having the same issue for a ‘range extender’. This is a power outlet device, so power and so should not be an issue.

What do you mean by this? What are the messages you’re seeing - are they NIF, or are they tamper messages?

If an association is set, then you will see entries when the tamper, or door sensor is set. If there’s no association set, then you won’t get any messages.

Maybe wrong choice of name.
This is the output when I push the button on the sensor:

2016-07-23 07:25:04.121 [DEBUG] [.ApplicationUpdateMessageClass:47  ]- NODE 29: Application update request. Node information received.
2016-07-23 07:25:04.122 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:1060]- NODE 29: 16 NIF event during initialisation stage PING
2016-07-23 07:25:04.122 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:1060]- NODE 29: 39 NIF event during initialisation stage PING
2016-07-23 07:25:04.122 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:1060]- NODE 29: 32 NIF event during initialisation stage PING
2016-07-23 07:25:04.122 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:1060]- NODE 29: 33 NIF event during initialisation stage PING
2016-07-23 07:25:04.122 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:1060]- NODE 29: 24 NIF event during initialisation stage PING
2016-07-23 07:25:04.123 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:1060]- NODE 29: 31 NIF event during initialisation stage PING
2016-07-23 07:25:04.123 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:1060]- NODE 29: 38 NIF event during initialisation stage PING
2016-07-23 07:25:04.123 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:1060]- NODE 29: 17 NIF event during initialisation stage PING
2016-07-23 07:25:04.123 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:1060]- NODE 29: 30 NIF event during initialisation stage PING
2016-07-23 07:25:04.123 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:1060]- NODE 29: 9 NIF event during initialisation stage PING
2016-07-23 07:25:04.123 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:1060]- NODE 29: 8 NIF event during initialisation stage PING
2016-07-23 07:25:04.123 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:1060]- NODE 29: 26 NIF event during initialisation stage PING
2016-07-23 07:25:04.123 [DEBUG] [.i.p.c.ZWaveWakeUpCommandClass:411 ]- NODE 29: Is awake with 0 messages in the wake-up queue.
2016-07-23 07:25:04.124 [DEBUG] [z.internal.ZWaveNetworkMonitor:701 ]- NODE 29: Heal WakeUp EVENT SAVE
2016-07-23 07:25:04.124 [DEBUG] [z.internal.ZWaveNetworkMonitor:575 ]- NODE 29: NETWORK HEAL - SAVE
2016-07-23 07:25:04.126 [DEBUG] [.b.z.i.p.i.ZWaveNodeSerializer:107 ]- NODE 29: Serializing to file /var/lib/openhab/zwave/node29.xml
2016-07-23 07:25:05.128 [DEBUG] [.i.p.c.ZWaveWakeUpCommandClass:506 ]- NODE 29: No more messages, go back to sleep
2016-07-23 07:25:05.128 [DEBUG] [.i.p.c.ZWaveWakeUpCommandClass:202 ]- NODE 29: Creating new message for application command WAKE_UP_NO_MORE_INFORMATION
2016-07-23 07:25:05.129 [DEBUG] [o.b.z.i.protocol.SerialMessage:109 ]- NODE 29: Creating empty message of class = SendData (0x13), type = Request (0x00)
2016-07-23 07:25:05.130 [DEBUG] [WaveController$ZWaveSendThread:1268]- NODE 29: Sending REQUEST Message = 01 09 00 13 1D 02 84 08 25 F0 A3
2016-07-23 07:25:05.146 [DEBUG] [b.z.i.p.s.SendDataMessageClass:38  ]- NODE 29: Sent Data successfully placed on stack.
2016-07-23 07:25:05.163 [DEBUG] [b.z.i.p.s.SendDataMessageClass:74  ]- NODE 29: SendData Request. CallBack ID = 240, Status = Transmission complete and ACK received(0)
2016-07-23 07:25:05.164 [DEBUG] [.i.p.c.ZWaveWakeUpCommandClass:372 ]- NODE 29: Went to sleep
2016-07-23 07:25:05.164 [DEBUG] [.i.p.c.ZWaveWakeUpCommandClass:435 ]- NODE 29: Is sleeping
2016-07-23 07:25:05.164 [DEBUG] [WaveController$ZWaveSendThread:1327]- NODE 29: Response processed after 34ms/5118ms.

When I check the manual, I should do something with the controller (z-wave gen5 usbstick) to associate it after removing the cover. Not sure what I can do in fe habmin to trigger this.

I’d suggest capturing a full debug log following the binding startup so we can see what is happening. After starting the binding, give it a few minutes then press the button a few times maybe 10 seconds apart and then send me the log.

Hey,

Thanks already for you effort!
You can find the log file here: 201607230511.txt
The new garage door sensors are NODE 29 & 30.

And I guess I’m having the same issue for the range extender, NODE 40. Not that openhab must do (can?) anything with this device, but I’m thinking that it’s not working if it’s not associated.

Let me know if I can do anything else!

Node 29 looks like it’s working perfectly. At least in this log, it completed its initialisation without any problems at all - no timeouts, and all done in a single wakeup (well, one for ping, and one for initialisation).

Node 30 on the other hand looks broken. The controller is reporting that it’s failed, and if this is a battery sensor, this is something I’ve not seen before. I would exclude and re-include node 30.

Node 40 is also initialised fine. I do note that later in the log there is a timeout to a ping, but otherwise it looks ok.

If you want to view the log yourself, you can use the online viewer which will display things in a reasonably nice way.

Sorry!!! I’ve wrote a huge mistake!
It’s node 28 and 29 that are the garage door sensors, and not 30.

Should I take any other actions in order to assiociate them?? In HABmin, I still see 0 member group…

ps indeed a nice log viewer. Going to try to understand a bit what I’m seeing… :wink:

Ok - so still node 29 is looking ok. There’s no information in the log from node 28. The controller thinks it’s healthy (which is good, but doesn’t mean much as the controller almost never marks a battery device as FAILED).

I note in the log that OH doesn’t try to set the association. The OH1 database is configured to do this automatically, but it might have been added after 1.8.3 so I would recommend upgrading to the latest nightly build from cloudbees.