Hi everyone,
I’ve been playing with openHAB for a while now and I’ve slowly been getting things working the way I want. Recently though I’ve really struggled to get an old Aeon Door Sensor, 1st generation I believe, DSB04100-ZWUS working with my network. It worked fine under my old Vera, and I followed the proper steps to exclude the device from Vera and then include it under openHAB with HABmin. For some reason serialization just never completes. I have two 2nd gen Aeon Door Sensors (and a bunch of other stuff) and no issues including anything else. Despite my best efforts I don’t know if this is a ZWave database problem, or something else.
I had the problem with openHAB v1.8.2, and I just updated to v1.8.3 late night but the issue persists. I have also gone as high as v1.9.0 for the zwave binding with no win.
Controller is a Gen 5 Aeon Zwave Stick, openHAB is running under VirtualBox, Ubuntu Server latest LTS.
I’m guessing to get any help some entries from the zwave.log are needed, so I’ll include some. Sorry about the wrapping.
2016-05-25 14:18:39.963 [DEBUG] [ApplicationCommandMessageClass:38 ]- NODE 8: Application Command Request (ALIVE:PING)
2016-05-25 14:18:39.964 [DEBUG] [ApplicationCommandMessageClass:56 ]- NODE 8: Incoming command class WAKE_UP
2016-05-25 14:18:39.964 [DEBUG] [ApplicationCommandMessageClass:62 ]- NODE 8: Command class WAKE_UP not found, trying
to add it.
2016-05-25 14:18:39.964 [DEBUG] [.o.b.z.i.p.c.ZWaveCommandClass:225 ]- NODE 8: Creating new instance of command class
WAKE_UP
2016-05-25 14:18:39.964 [DEBUG] [ApplicationCommandMessageClass:68 ]- NODE 8: Adding command class WAKE_UP
2016-05-25 14:18:39.964 [DEBUG] [.z.internal.protocol.ZWaveNode:571 ]- NODE 8: Adding command class WAKE_UP to the
list of supported command classes.
2016-05-25 14:18:39.964 [DEBUG] [.i.p.c.ZWaveWakeUpCommandClass:136 ]- NODE 8: Received Wake Up Request
2016-05-25 14:18:39.965 [DEBUG] [.i.p.c.ZWaveWakeUpCommandClass:182 ]- NODE 8: Received WAKE_UP_NOTIFICATION
2016-05-25 14:18:39.965 [DEBUG] [.i.p.c.ZWaveWakeUpCommandClass:411 ]- NODE 8: Is awake with 0 messages in the wake-up
queue.
2016-05-25 14:18:39.965 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:1036]- NODE 8: Wakeup during initialisation.
2016-05-25 14:18:39.965 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:269 ]- NODE 8: Node advancer - PING: queue length(0),
free to send(true)
2016-05-25 14:18:39.965 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:335 ]- NODE 8: Node advancer: loop - PING try 1:
stageAdvanced(false)
2016-05-25 14:18:39.966 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:419 ]- NODE 8: Node advancer: PING - send NoOperation
2016-05-25 14:18:39.966 [DEBUG] [c.ZWaveNoOperationCommandClass:72 ]- NODE 8: Creating new message for command No
Operation
2016-05-25 14:18:39.966 [DEBUG] [o.b.z.i.protocol.SerialMessage:109 ]- NODE 8: Creating empty message of class =
SendData (0x13), type = Request (0x00)
2016-05-25 14:18:39.969 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:242 ]- NODE 8: Node advancer - queued packet. Queue
length is 1
2016-05-25 14:18:39.969 [DEBUG] [WaveController$ZWaveSendThread:1268]- NODE 8: Sending REQUEST Message = 01 08 00 13
08 01 00 25 46 8E
2016-05-25 14:18:39.981 [DEBUG] [b.z.i.p.s.SendDataMessageClass:38 ]- NODE 8: Sent Data successfully placed on stack.
2016-05-25 14:18:40.028 [DEBUG] [b.z.i.p.s.SendDataMessageClass:74 ]- NODE 8: SendData Request. CallBack ID = 70,
Status = Transmission complete and ACK received(0)
2016-05-25 14:18:40.029 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:1013]- NODE 8: Node advancer - PING: Transaction
complete (SendData:Request) success(true)
2016-05-25 14:18:40.029 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:203 ]- NODE 8: Node advancer - checking initialisation
queue. Queue size 1.
2016-05-25 14:18:40.030 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:209 ]- NODE 8: Node advancer - message removed from
queue. Queue size 0.
2016-05-25 14:18:40.030 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:269 ]- NODE 8: Node advancer - PING: queue length(0),
free to send(true)
2016-05-25 14:18:40.030 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:335 ]- NODE 8: Node advancer: loop - PING try 2:
stageAdvanced(false)
2016-05-25 14:18:40.030 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:868 ]- NODE 8: Node advancer - advancing to DETAILS
2016-05-25 14:18:40.030 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:335 ]- NODE 8: Node advancer: loop - DETAILS try 0:
stageAdvanced(true)
2016-05-25 14:18:40.030 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:448 ]- NODE 8: Node advancer: DETAILS - send
RequestNodeInfo
2016-05-25 14:18:40.031 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:242 ]- NODE 8: Node advancer - queued packet. Queue
length is 1
2016-05-25 14:18:40.031 [DEBUG] [WaveController$ZWaveSendThread:1327]- NODE 8: Response processed after 61ms/1832ms.
2016-05-25 14:18:40.140 [DEBUG] [.ApplicationUpdateMessageClass:47 ]- NODE 8: Application update request. Node
information received.
2016-05-25 14:18:40.140 [DEBUG] [.o.b.z.i.p.c.ZWaveCommandClass:225 ]- NODE 8: Creating new instance of command class
SENSOR_BINARY
2016-05-25 14:18:40.140 [DEBUG] [.o.b.z.i.p.c.ZWaveCommandClass:225 ]- NODE 8: Creating new instance of command class
BATTERY
2016-05-25 14:18:40.141 [DEBUG] [.z.internal.protocol.ZWaveNode:571 ]- NODE 8: Adding command class BATTERY to the
list of supported command classes.
2016-05-25 14:18:40.141 [DEBUG] [.o.b.z.i.p.c.ZWaveCommandClass:225 ]- NODE 8: Creating new instance of command class
WAKE_UP
2016-05-25 14:18:40.141 [DEBUG] [.o.b.z.i.p.c.ZWaveCommandClass:225 ]- NODE 8: Creating new instance of command class
ALARM
2016-05-25 14:18:40.141 [DEBUG] [.z.internal.protocol.ZWaveNode:571 ]- NODE 8: Adding command class ALARM to the list
of supported command classes.
2016-05-25 14:18:40.141 [DEBUG] [.o.b.z.i.p.c.ZWaveCommandClass:225 ]- NODE 8: Creating new instance of command class
SENSOR_ALARM
2016-05-25 14:18:40.142 [DEBUG] [.z.internal.protocol.ZWaveNode:571 ]- NODE 8: Adding command class SENSOR_ALARM to
the list of supported command classes.
2016-05-25 14:18:40.142 [DEBUG] [.o.b.z.i.p.c.ZWaveCommandClass:225 ]- NODE 8: Creating new instance of command class
CONFIGURATION
2016-05-25 14:18:40.142 [DEBUG] [.z.internal.protocol.ZWaveNode:571 ]- NODE 8: Adding command class CONFIGURATION to
the list of supported command classes.
2016-05-25 14:18:40.142 [DEBUG] [.o.b.z.i.p.c.ZWaveCommandClass:225 ]- NODE 8: Creating new instance of command class
ASSOCIATION
2016-05-25 14:18:40.142 [DEBUG] [.z.internal.protocol.ZWaveNode:571 ]- NODE 8: Adding command class ASSOCIATION to the
list of supported command classes.
2016-05-25 14:18:40.143 [DEBUG] [.o.b.z.i.p.c.ZWaveCommandClass:225 ]- NODE 8: Creating new instance of command class
VERSION
2016-05-25 14:18:40.143 [DEBUG] [.z.internal.protocol.ZWaveNode:571 ]- NODE 8: Adding command class VERSION to the
list of supported command classes.
2016-05-25 14:18:40.143 [DEBUG] [.o.b.z.i.p.c.ZWaveCommandClass:225 ]- NODE 8: Creating new instance of command class
MANUFACTURER_SPECIFIC
2016-05-25 14:18:40.143 [DEBUG] [.z.internal.protocol.ZWaveNode:571 ]- NODE 8: Adding command class
MANUFACTURER_SPECIFIC to the list of supported command classes.
2016-05-25 14:18:40.143 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:1060]- NODE 8: 8 NIF event during initialisation stage
DETAILS
2016-05-25 14:18:40.143 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:1069]- NODE 8: NIF event during initialisation stage
DETAILS
2016-05-25 14:18:40.144 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:269 ]- NODE 8: Node advancer - DETAILS: queue
length(1), free to send(false)
2016-05-25 14:18:40.144 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:242 ]- NODE 8: Node advancer - queued packet. Queue
length is 1
2016-05-25 14:18:40.144 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:1060]- NODE 8: 4 NIF event during initialisation stage
PING
2016-05-25 14:18:40.144 [DEBUG] [.i.p.c.ZWaveWakeUpCommandClass:411 ]- NODE 8: Is awake with 0 messages in the wake-up
queue.
2016-05-25 14:18:40.145 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:1036]- NODE 8: Wakeup during initialisation.
2016-05-25 14:18:40.145 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:269 ]- NODE 8: Node advancer - DETAILS: queue
length(1), free to send(false)
2016-05-25 14:18:40.145 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:242 ]- NODE 8: Node advancer - queued packet. Queue
length is 1
2016-05-25 14:18:40.146 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:1013]- NODE 8: Node advancer - DETAILS: Transaction
complete (RequestNodeInfo:Request) success(true)
2016-05-25 14:18:40.146 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:203 ]- NODE 8: Node advancer - checking initialisation
queue. Queue size 1.
2016-05-25 14:18:40.146 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:209 ]- NODE 8: Node advancer - message removed from
queue. Queue size 0.
2016-05-25 14:18:40.146 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:269 ]- NODE 8: Node advancer - DETAILS: queue
length(0), free to send(true)
2016-05-25 14:18:40.146 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:335 ]- NODE 8: Node advancer: loop - DETAILS try 1:
stageAdvanced(false)
2016-05-25 14:18:40.146 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:444 ]- NODE 8: Node advancer: received RequestNodeInfo
2016-05-25 14:18:40.147 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:868 ]- NODE 8: Node advancer - advancing to
MANUFACTURER
2016-05-25 14:18:40.147 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:335 ]- NODE 8: Node advancer: loop - MANUFACTURER try
0: stageAdvanced(true)
2016-05-25 14:18:40.147 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:466 ]- NODE 8: Node advancer: MANUFACTURER - send
ManufacturerSpecific
2016-05-25 14:18:40.147 [DEBUG] [nufacturerSpecificCommandClass:101 ]- NODE 8: Creating new message for command
MANUFACTURER_SPECIFIC_GET
2016-05-25 14:18:40.147 [DEBUG] [o.b.z.i.protocol.SerialMessage:109 ]- NODE 8: Creating empty message of class =
SendData (0x13), type = Request (0x00)
2016-05-25 14:18:40.148 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:242 ]- NODE 8: Node advancer - queued packet. Queue
length is 1
2016-05-25 14:18:40.148 [DEBUG] [WaveController$ZWaveSendThread:1268]- NODE 8: Sending REQUEST Message = 01 09 00 13
08 02 72 04 25 47 FB
2016-05-25 14:18:40.165 [DEBUG] [b.z.i.p.s.SendDataMessageClass:38 ]- NODE 8: Sent Data successfully placed on stack.
2016-05-25 14:18:40.247 [DEBUG] [b.z.i.p.s.SendDataMessageClass:74 ]- NODE 8: SendData Request. CallBack ID = 71,
Status = Transmission complete and ACK received(0)
2016-05-25 14:18:40.299 [DEBUG] [ApplicationCommandMessageClass:38 ]- NODE 8: Application Command Request
(ALIVE:MANUFACTURER)
2016-05-25 14:18:40.299 [DEBUG] [ApplicationCommandMessageClass:56 ]- NODE 8: Incoming command class
MANUFACTURER_SPECIFIC
2016-05-25 14:18:40.299 [DEBUG] [nufacturerSpecificCommandClass:66 ]- NODE 8: Received Manufacture Specific
Information
2016-05-25 14:18:40.299 [DEBUG] [nufacturerSpecificCommandClass:83 ]- NODE 8: Manufacturer ID = 0x0086
2016-05-25 14:18:40.299 [DEBUG] [nufacturerSpecificCommandClass:84 ]- NODE 8: Device Type = 0x0002
2016-05-25 14:18:40.299 [DEBUG] [nufacturerSpecificCommandClass:85 ]- NODE 8: Device ID = 0x0004
2016-05-25 14:18:40.300 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:1013]- NODE 8: Node advancer - MANUFACTURER:
Transaction complete (SendData:Request) success(true)
2016-05-25 14:18:40.300 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:203 ]- NODE 8: Node advancer - checking initialisation
queue. Queue size 1.
2016-05-25 14:18:40.300 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:209 ]- NODE 8: Node advancer - message removed from
queue. Queue size 0.
2016-05-25 14:18:40.301 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:269 ]- NODE 8: Node advancer - MANUFACTURER: queue
length(0), free to send(true)
2016-05-25 14:18:40.301 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:335 ]- NODE 8: Node advancer: loop - MANUFACTURER try
1: stageAdvanced(false)
2016-05-25 14:18:40.301 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:868 ]- NODE 8: Node advancer - advancing to VERSION
2016-05-25 14:18:40.301 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:335 ]- NODE 8: Node advancer: loop - VERSION try 0:
stageAdvanced(true)
2016-05-25 14:18:40.301 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:479 ]- NODE 8: Node advancer: VERSION - checking
ASSOCIATION, version is 0
2016-05-25 14:18:40.301 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:487 ]- NODE 8: Node advancer: VERSION - VERSION
default to 1
2016-05-25 14:18:40.301 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:479 ]- NODE 8: Node advancer: VERSION - checking
BATTERY, version is 0
2016-05-25 14:18:40.302 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:487 ]- NODE 8: Node advancer: VERSION - VERSION
default to 1
2016-05-25 14:18:40.302 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:479 ]- NODE 8: Node advancer: VERSION - checking
SENSOR_ALARM, version is 0
2016-05-25 14:18:40.302 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:487 ]- NODE 8: Node advancer: VERSION - VERSION
default to 1
2016-05-25 14:18:40.302 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:479 ]- NODE 8: Node advancer: VERSION - checking
WAKE_UP, version is 0
2016-05-25 14:18:40.302 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:482 ]- NODE 8: Node advancer: VERSION - queued
WAKE_UP
2016-05-25 14:18:40.302 [DEBUG] [i.p.c.ZWaveVersionCommandClass:169 ]- NODE 8: Creating new message for application
command VERSION_COMMAND_CLASS_GET command class WAKE_UP
2016-05-25 14:18:40.302 [DEBUG] [o.b.z.i.protocol.SerialMessage:109 ]- NODE 8: Creating empty message of class =
SendData (0x13), type = Request (0x00)
2016-05-25 14:18:40.302 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:479 ]- NODE 8: Node advancer: VERSION - checking
SENSOR_BINARY, version is 0
2016-05-25 14:18:40.302 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:482 ]- NODE 8: Node advancer: VERSION - queued
SENSOR_BINARY
2016-05-25 14:18:40.303 [DEBUG] [i.p.c.ZWaveVersionCommandClass:169 ]- NODE 8: Creating new message for application
command VERSION_COMMAND_CLASS_GET command class SENSOR_BINARY
2016-05-25 14:18:40.303 [DEBUG] [o.b.z.i.protocol.SerialMessage:109 ]- NODE 8: Creating empty message of class =
SendData (0x13), type = Request (0x00)
2016-05-25 14:18:40.303 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:479 ]- NODE 8: Node advancer: VERSION - checking
CONFIGURATION, version is 0
2016-05-25 14:18:40.303 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:487 ]- NODE 8: Node advancer: VERSION - VERSION
default to 1
2016-05-25 14:18:40.303 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:479 ]- NODE 8: Node advancer: VERSION - checking
BASIC, version is 0
2016-05-25 14:18:40.303 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:487 ]- NODE 8: Node advancer: VERSION - VERSION
default to 1
2016-05-25 14:18:40.303 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:479 ]- NODE 8: Node advancer: VERSION - checking
ALARM, version is 0
2016-05-25 14:18:40.303 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:487 ]- NODE 8: Node advancer: VERSION - VERSION
default to 1
2016-05-25 14:18:40.304 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:479 ]- NODE 8: Node advancer: VERSION - checking
MANUFACTURER_SPECIFIC, version is 0
2016-05-25 14:18:40.304 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:487 ]- NODE 8: Node advancer: VERSION - VERSION
default to 1
2016-05-25 14:18:40.304 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:479 ]- NODE 8: Node advancer: VERSION - checking
VERSION, version is 0
2016-05-25 14:18:40.304 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:487 ]- NODE 8: Node advancer: VERSION - VERSION
default to 1
2016-05-25 14:18:40.304 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:479 ]- NODE 8: Node advancer: VERSION - checking
NO_OPERATION, version is 0
2016-05-25 14:18:40.304 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:487 ]- NODE 8: Node advancer: VERSION - VERSION
default to 1
2016-05-25 14:18:40.304 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:491 ]- NODE 8: Node advancer: VERSION - queued 2 frames
2016-05-25 14:18:40.305 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:242 ]- NODE 8: Node advancer - queued packet. Queue
length is 2
2016-05-25 14:18:40.305 [DEBUG] [WaveController$ZWaveSendThread:1327]- NODE 8: Response processed after 157ms/1832ms.
2016-05-25 14:18:40.305 [DEBUG] [WaveController$ZWaveSendThread:1268]- NODE 8: Sending REQUEST Message = 01 0A 00 13
08 03 86 13 84 25 48 91
2016-05-25 14:18:40.322 [DEBUG] [b.z.i.p.s.SendDataMessageClass:38 ]- NODE 8: Sent Data successfully placed on stack.
2016-05-25 14:18:40.411 [DEBUG] [b.z.i.p.s.SendDataMessageClass:74 ]- NODE 8: SendData Request. CallBack ID = 72,
Status = Transmission complete and ACK received(0)
2016-05-25 14:18:40.456 [DEBUG] [ApplicationCommandMessageClass:38 ]- NODE 8: Application Command Request
(ALIVE:VERSION)
2016-05-25 14:18:40.456 [DEBUG] [ApplicationCommandMessageClass:56 ]- NODE 8: Incoming command class VERSION
2016-05-25 14:18:40.457 [DEBUG] [i.p.c.ZWaveVersionCommandClass:78 ]- NODE 8: Received Version Request
2016-05-25 14:18:40.457 [DEBUG] [i.p.c.ZWaveVersionCommandClass:98 ]- NODE 8: Process Version Command Class Report
2016-05-25 14:18:40.457 [DEBUG] [i.p.c.ZWaveVersionCommandClass:108 ]- NODE 8: Requested Command Class = WAKE_UP,
Version = 1
2016-05-25 14:18:40.457 [DEBUG] [i.p.c.ZWaveVersionCommandClass:135 ]- NODE 8: Version = 1, version set. Enabling
extra functionality.
2016-05-25 14:18:40.458 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:1013]- NODE 8: Node advancer - VERSION: Transaction
complete (SendData:Request) success(true)
2016-05-25 14:18:40.458 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:203 ]- NODE 8: Node advancer - checking initialisation
queue. Queue size 2.
2016-05-25 14:18:40.458 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:209 ]- NODE 8: Node advancer - message removed from
queue. Queue size 1.
2016-05-25 14:18:40.458 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:269 ]- NODE 8: Node advancer - VERSION: queue
length(1), free to send(true)
2016-05-25 14:18:40.458 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:242 ]- NODE 8: Node advancer - queued packet. Queue
length is 1
2016-05-25 14:18:40.459 [DEBUG] [WaveController$ZWaveSendThread:1327]- NODE 8: Response processed after 154ms/1832ms.
2016-05-25 14:18:40.459 [DEBUG] [WaveController$ZWaveSendThread:1268]- NODE 8: Sending REQUEST Message = 01 0A 00 13
08 03 86 13 30 25 49 24
2016-05-25 14:18:40.474 [DEBUG] [b.z.i.p.s.SendDataMessageClass:38 ]- NODE 8: Sent Data successfully placed on stack.
2016-05-25 14:18:40.570 [DEBUG] [b.z.i.p.s.SendDataMessageClass:74 ]- NODE 8: SendData Request. CallBack ID = 73,
Status = Transmission complete and ACK received(0)
2016-05-25 14:18:40.618 [DEBUG] [ApplicationCommandMessageClass:38 ]- NODE 8: Application Command Request
(ALIVE:VERSION)
2016-05-25 14:18:40.618 [DEBUG] [ApplicationCommandMessageClass:56 ]- NODE 8: Incoming command class VERSION
2016-05-25 14:18:40.618 [DEBUG] [i.p.c.ZWaveVersionCommandClass:78 ]- NODE 8: Received Version Request
2016-05-25 14:18:40.618 [DEBUG] [i.p.c.ZWaveVersionCommandClass:98 ]- NODE 8: Process Version Command Class Report
2016-05-25 14:18:40.618 [DEBUG] [i.p.c.ZWaveVersionCommandClass:108 ]- NODE 8: Requested Command Class =
SENSOR_BINARY, Version = 1
2016-05-25 14:18:40.618 [DEBUG] [i.p.c.ZWaveVersionCommandClass:135 ]- NODE 8: Version = 1, version set. Enabling
extra functionality.
2016-05-25 14:18:40.619 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:1013]- NODE 8: Node advancer - VERSION: Transaction
complete (SendData:Request) success(true)
2016-05-25 14:18:40.619 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:203 ]- NODE 8: Node advancer - checking initialisation
queue. Queue size 1.
2016-05-25 14:18:40.620 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:209 ]- NODE 8: Node advancer - message removed from
queue. Queue size 0.
2016-05-25 14:18:40.620 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:269 ]- NODE 8: Node advancer - VERSION: queue
length(0), free to send(true)
2016-05-25 14:18:40.620 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:335 ]- NODE 8: Node advancer: loop - VERSION try 1:
stageAdvanced(false)
2016-05-25 14:18:40.620 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:479 ]- NODE 8: Node advancer: VERSION - checking
ASSOCIATION, version is 1
2016-05-25 14:18:40.620 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:479 ]- NODE 8: Node advancer: VERSION - checking
BATTERY, version is 1
2016-05-25 14:18:40.620 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:479 ]- NODE 8: Node advancer: VERSION - checking
SENSOR_ALARM, version is 1
2016-05-25 14:18:40.620 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:479 ]- NODE 8: Node advancer: VERSION - checking
WAKE_UP, version is 1
2016-05-25 14:18:40.620 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:479 ]- NODE 8: Node advancer: VERSION - checking
SENSOR_BINARY, version is 1
2016-05-25 14:18:40.621 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:479 ]- NODE 8: Node advancer: VERSION - checking
CONFIGURATION, version is 1
2016-05-25 14:18:40.621 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:479 ]- NODE 8: Node advancer: VERSION - checking
BASIC, version is 1
2016-05-25 14:18:40.621 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:479 ]- NODE 8: Node advancer: VERSION - checking
ALARM, version is 1
2016-05-25 14:18:40.621 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:479 ]- NODE 8: Node advancer: VERSION - checking
MANUFACTURER_SPECIFIC, version is 1
2016-05-25 14:18:40.621 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:479 ]- NODE 8: Node advancer: VERSION - checking
VERSION, version is 1
2016-05-25 14:18:40.621 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:479 ]- NODE 8: Node advancer: VERSION - checking
NO_OPERATION, version is 1
2016-05-25 14:18:40.621 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:491 ]- NODE 8: Node advancer: VERSION - queued 0 frames
2016-05-25 14:18:40.621 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:868 ]- NODE 8: Node advancer - advancing to APP_VERSION
2016-05-25 14:18:40.622 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:335 ]- NODE 8: Node advancer: loop - APP_VERSION try
0: stageAdvanced(true)
2016-05-25 14:18:40.622 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:509 ]- NODE 8: Node advancer: APP_VERSION - send
VersionMessage
2016-05-25 14:18:40.622 [DEBUG] [i.p.c.ZWaveVersionCommandClass:151 ]- NODE 8: Creating new message for command
VERSION_GET
2016-05-25 14:18:40.622 [DEBUG] [o.b.z.i.protocol.SerialMessage:109 ]- NODE 8: Creating empty message of class =
SendData (0x13), type = Request (0x00)
2016-05-25 14:18:40.622 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:242 ]- NODE 8: Node advancer - queued packet. Queue
length is 1
2016-05-25 14:18:40.623 [DEBUG] [WaveController$ZWaveSendThread:1327]- NODE 8: Response processed after 164ms/1832ms.
2016-05-25 14:18:40.623 [DEBUG] [WaveController$ZWaveSendThread:1268]- NODE 8: Sending REQUEST Message = 01 09 00 13
08 02 86 11 25 4A 17
2016-05-25 14:18:40.640 [DEBUG] [b.z.i.p.s.SendDataMessageClass:38 ]- NODE 8: Sent Data successfully placed on stack.
2016-05-25 14:18:40.731 [DEBUG] [b.z.i.p.s.SendDataMessageClass:74 ]- NODE 8: SendData Request. CallBack ID = 74,
Status = Transmission complete and ACK received(0)
2016-05-25 14:18:40.775 [DEBUG] [ApplicationCommandMessageClass:38 ]- NODE 8: Application Command Request
(ALIVE:APP_VERSION)
2016-05-25 14:18:40.775 [DEBUG] [ApplicationCommandMessageClass:56 ]- NODE 8: Incoming command class VERSION
2016-05-25 14:18:40.775 [DEBUG] [i.p.c.ZWaveVersionCommandClass:78 ]- NODE 8: Received Version Request
2016-05-25 14:18:40.775 [DEBUG] [i.p.c.ZWaveVersionCommandClass:86 ]- NODE 8: Process Version Report
2016-05-25 14:18:40.775 [DEBUG] [i.p.c.ZWaveVersionCommandClass:93 ]- NODE 8: Library Type = 6 (Routing Slave)
2016-05-25 14:18:40.776 [DEBUG] [i.p.c.ZWaveVersionCommandClass:94 ]- NODE 8: Protocol Version = 2.78
2016-05-25 14:18:40.776 [DEBUG] [i.p.c.ZWaveVersionCommandClass:95 ]- NODE 8: Application Version = 3.6
2016-05-25 14:18:40.777 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:1013]- NODE 8: Node advancer - APP_VERSION:
Transaction complete (SendData:Request) success(true)
2016-05-25 14:18:40.777 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:203 ]- NODE 8: Node advancer - checking initialisation
queue. Queue size 1.
2016-05-25 14:18:40.777 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:209 ]- NODE 8: Node advancer - message removed from
queue. Queue size 0.
2016-05-25 14:18:40.777 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:269 ]- NODE 8: Node advancer - APP_VERSION: queue
length(0), free to send(true)
2016-05-25 14:18:40.777 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:335 ]- NODE 8: Node advancer: loop - APP_VERSION try
1: stageAdvanced(false)
2016-05-25 14:18:40.777 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:868 ]- NODE 8: Node advancer - advancing to ENDPOINTS
2016-05-25 14:18:40.777 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:335 ]- NODE 8: Node advancer: loop - ENDPOINTS try 0:
stageAdvanced(true)
2016-05-25 14:18:40.778 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:524 ]- NODE 8: Node advancer: ENDPOINTS -
MultiInstance not supported.
2016-05-25 14:18:40.778 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:868 ]- NODE 8: Node advancer - advancing to
UPDATE_DATABASE
2016-05-25 14:18:40.778 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:335 ]- NODE 8: Node advancer: loop - UPDATE_DATABASE
try 0: stageAdvanced(true)
2016-05-25 14:18:40.778 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:534 ]- NODE 8: Node advancer: UPDATE_DATABASE
2016-05-25 14:18:40.812 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:868 ]- NODE 8: Node advancer - advancing to
STATIC_VALUES
2016-05-25 14:18:40.812 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:335 ]- NODE 8: Node advancer: loop - STATIC_VALUES try
0: stageAdvanced(true)
2016-05-25 14:18:40.812 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:582 ]- NODE 8: Node advancer: STATIC_VALUES - checking
ASSOCIATION
2016-05-25 14:18:40.812 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:585 ]- NODE 8: Node advancer: STATIC_VALUES - found
ASSOCIATION
2016-05-25 14:18:40.812 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:589 ]- NODE 8: Found 1 instances of ASSOCIATION
2016-05-25 14:18:40.812 [DEBUG] [c.ZWaveAssociationCommandClass:309 ]- NODE 8: Creating new message for application
command ASSOCIATIONCMD_GROUPINGSGET
2016-05-25 14:18:40.813 [DEBUG] [o.b.z.i.protocol.SerialMessage:109 ]- NODE 8: Creating empty message of class =
SendData (0x13), type = Request (0x00)
2016-05-25 14:18:40.813 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:582 ]- NODE 8: Node advancer: STATIC_VALUES - checking
BATTERY
2016-05-25 14:18:40.813 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:582 ]- NODE 8: Node advancer: STATIC_VALUES - checking
SENSOR_ALARM
2016-05-25 14:18:40.813 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:585 ]- NODE 8: Node advancer: STATIC_VALUES - found
SENSOR_ALARM
2016-05-25 14:18:40.813 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:589 ]- NODE 8: Found 1 instances of SENSOR_ALARM
2016-05-25 14:18:40.813 [DEBUG] [c.ZWaveAlarmSensorCommandClass:234 ]- NODE 8: Creating new message for command
SENSOR_ALARM_SUPPORTED_GET
2016-05-25 14:18:40.813 [DEBUG] [o.b.z.i.protocol.SerialMessage:109 ]- NODE 8: Creating empty message of class =
SendData (0x13), type = Request (0x00)
2016-05-25 14:18:40.814 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:582 ]- NODE 8: Node advancer: STATIC_VALUES - checking
WAKE_UP
2016-05-25 14:18:40.814 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:585 ]- NODE 8: Node advancer: STATIC_VALUES - found
WAKE_UP
2016-05-25 14:18:40.814 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:589 ]- NODE 8: Found 1 instances of WAKE_UP
2016-05-25 14:18:40.814 [DEBUG] [.i.p.c.ZWaveWakeUpCommandClass:253 ]- NODE 8: Creating new message for application
command WAKE_UP_INTERVAL_GET
2016-05-25 14:18:40.814 [DEBUG] [o.b.z.i.protocol.SerialMessage:109 ]- NODE 8: Creating empty message of class =
SendData (0x13), type = Request (0x00)
2016-05-25 14:18:40.814 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:582 ]- NODE 8: Node advancer: STATIC_VALUES - checking
SENSOR_BINARY
2016-05-25 14:18:40.814 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:582 ]- NODE 8: Node advancer: STATIC_VALUES - checking
CONFIGURATION
2016-05-25 14:18:40.814 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:582 ]- NODE 8: Node advancer: STATIC_VALUES - checking
BASIC
2016-05-25 14:18:40.814 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:582 ]- NODE 8: Node advancer: STATIC_VALUES - checking
ALARM
2016-05-25 14:18:40.814 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:582 ]- NODE 8: Node advancer: STATIC_VALUES - checking
MANUFACTURER_SPECIFIC
2016-05-25 14:18:40.814 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:582 ]- NODE 8: Node advancer: STATIC_VALUES - checking
VERSION
2016-05-25 14:18:40.814 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:582 ]- NODE 8: Node advancer: STATIC_VALUES - checking
NO_OPERATION
2016-05-25 14:18:40.814 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:617 ]- NODE 8: Node advancer: STATIC_VALUES - queued 3
frames
2016-05-25 14:18:40.814 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:242 ]- NODE 8: Node advancer - queued packet. Queue
length is 3
2016-05-25 14:18:40.814 [DEBUG] [WaveController$ZWaveSendThread:1327]- NODE 8: Response processed after 191ms/1832ms.
2016-05-25 14:18:40.815 [DEBUG] [WaveController$ZWaveSendThread:1268]- NODE 8: Sending REQUEST Message = 01 09 00 13
08 02 85 05 25 4B 01
2016-05-25 14:18:40.830 [DEBUG] [b.z.i.p.s.SendDataMessageClass:38 ]- NODE 8: Sent Data successfully placed on stack.
2016-05-25 14:18:40.886 [DEBUG] [b.z.i.p.s.SendDataMessageClass:74 ]- NODE 8: SendData Request. CallBack ID = 75,
Status = Transmission complete and ACK received(0)
2016-05-25 14:18:40.935 [DEBUG] [ApplicationCommandMessageClass:38 ]- NODE 8: Application Command Request
(ALIVE:STATIC_VALUES)
2016-05-25 14:18:40.935 [DEBUG] [ApplicationCommandMessageClass:56 ]- NODE 8: Incoming command class ASSOCIATION
2016-05-25 14:18:40.935 [DEBUG] [c.ZWaveAssociationCommandClass:96 ]- NODE 8: Received Association Request
2016-05-25 14:18:40.935 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:1013]- NODE 8: Node advancer - STATIC_VALUES:
Transaction complete (SendData:Request) success(true)
2016-05-25 14:18:40.935 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:203 ]- NODE 8: Node advancer - checking initialisation
queue. Queue size 3.
2016-05-25 14:18:40.936 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:209 ]- NODE 8: Node advancer - message removed from
queue. Queue size 2.
2016-05-25 14:18:40.936 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:269 ]- NODE 8: Node advancer - STATIC_VALUES: queue
length(2), free to send(true)
2016-05-25 14:18:40.936 [DEBUG] [z.i.p.i.ZWaveNodeStageAdvancer:242 ]- NODE 8: Node advancer - queued packet. Queue
length is 2
2016-05-25 14:18:40.936 [DEBUG] [WaveController$ZWaveSendThread:1327]- NODE 8: Response processed after 121ms/1832ms.
2016-05-25 14:18:40.936 [DEBUG] [WaveController$ZWaveSendThread:1268]- NODE 8: Sending REQUEST Message = 01 09 00 13
08 02 9C 03 25 4C 19
2016-05-25 14:18:40.953 [DEBUG] [b.z.i.p.s.SendDataMessageClass:38 ]- NODE 8: Sent Data successfully placed on stack.
2016-05-25 14:18:41.099 [DEBUG] [b.z.i.p.s.SendDataMessageClass:74 ]- NODE 8: SendData Request. CallBack ID = 76,
Status = Transmission complete and ACK received(0)
2016-05-25 14:18:45.941 [ERROR] [WaveController$ZWaveSendThread:1309]- NODE 8: Timeout while sending message.
Requeueing - 2 attempts left!