[SOLVED] ZWave devices recognized but not working/communicating

Ben_P · March 18, 2020, 9:57am

(Note I cannot add additional tags because I get a Internal server error then, but they are zwave, bindings, aeotec)

Openhab 2.5.1 from Qnap Club
QNAP TS-453 Pro (x86_64)

I had my Zwave and Zigbee devices on a Smartthings V3 hub which worked well but I want to process local and not cloud. So I got a Zigbee USB Stick, working great, and a Aeotec Zwave Stick Gen5.
I installed the Z-wave binding, and installed the stick as a serial controller. Works fine, device online.
I unplug my Smartthings Hub, factory reset my devices and put them in pairing mode (Fibaro Motion detector and Aeotec Trisensor).
They get recognized straight away and I can add them as things with all the expected channels.
They get an online status in the PaperUI Things:
And then…nothing happens. I try to trigger the motion sensor, try to read values, …nothing.
Both motion sensors will light up when motion is detected normally (on my Smartthings they did), and now not even that. Not only do they not communicate but they don’t seem to work even.
I put the logging to debug and observe…nothing again
I see all the messages flying through when pairing is ongoing, it all seems normal. And as you can see, 5 minutes of nothing. Total silence.
After that time, I press the action button to wake up the device and immediately logging occurs again. If I press the button to check network status, it gives the response it is connected.
I tried to pair the devices in inclusion mode (take stick to device and pair it there, then plug again and it shows up in Inbox but as an unknown device), or serial mode (plugged in and Openhab search).
Also tried the things from other topics where Fibaro Motion Detectors were not working but nothing.
Serial controller set up with no security, and network wide inclusion mode.
What is going on here ?
Thanks

Log extract showing 1 device discovered, paired (23:20), and then communication when action button pressed (23:26 and again 23:30). Inbetween tried to trigger device all the time without result (and started to create some rules)

2020-03-17 23:20:22.750 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:55f456ae:node2.
2020-03-17 23:20:22.751 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Checking zwave:nietech_nzw96_00_000
2020-03-17 23:20:22.752 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Checking zwave:nietech_zw31_00_000
 ----------------     Plenty of lines like this removed to fit max size of topic ----------------
2020-03-17 23:20:22.924 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Handler disposed. Unregistering listener.
2020-03-17 23:20:23.035 [DEBUG] [al.protocol.ZWaveInclusionController] - ZWave inclusion controller finalised
2020-03-17 23:20:23.141 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:55f456ae:node2.
2020-03-17 23:20:23.144 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Controller status changed to ONLINE.
2020-03-17 23:20:23.144 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Controller is ONLINE. Starting device initialisation.
2020-03-17 23:20:23.148 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating node properties.
2020-03-17 23:20:23.154 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating node properties. MAN=881
2020-03-17 23:20:23.155 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating node properties. MAN=881. SET. Was 881
2020-03-17 23:20:23.158 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Properties synchronised
2020-03-17 23:20:23.163 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Configuration synchronised
2020-03-17 23:20:23.180 [DEBUG] [ve.internal.protocol.ZWaveController] - Event listener added.
2020-03-17 23:20:23.181 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising Thing Node...
2020-03-17 23:20:23.223 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising cmd channel zwave:device:55f456ae:node2:sensor_temperature for QuantityType
2020-03-17 23:20:23.224 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising state channel zwave:device:55f456ae:node2:sensor_temperature for QuantityType
2020-03-17 23:20:23.225 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising cmd channel zwave:device:55f456ae:node2:sensor_luminance for DecimalType
2020-03-17 23:20:23.225 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising state channel zwave:device:55f456ae:node2:sensor_luminance for DecimalType
2020-03-17 23:20:23.240 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising cmd channel zwave:device:55f456ae:node2:alarm_motion for OnOffType
2020-03-17 23:20:23.241 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising state channel zwave:device:55f456ae:node2:alarm_motion for OnOffType
2020-03-17 23:20:23.242 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising cmd channel zwave:device:55f456ae:node2:battery-level for PercentType
2020-03-17 23:20:23.244 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising state channel zwave:device:55f456ae:node2:battery-level for PercentType
2020-03-17 23:20:23.246 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Polling initialised at 1800 seconds - start in 1744200 milliseconds.
2020-03-17 23:20:23.246 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Device initialisation complete.
2020-03-17 23:20:41.786 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - ZWave discovery: Stop zwave:serial_zstick:55f456ae
2020-03-17 23:20:41.787 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave inclusion process not running - nothing to do
2020-03-17 23:20:58.572 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Channel zwave:device:55f456ae:node2:sensor_temperature linked - polling started.
2020-03-17 23:21:05.476 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Channel zwave:device:55f456ae:node2:sensor_luminance linked - polling started.
2020-03-17 23:21:14.741 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Channel zwave:device:55f456ae:node2:battery-level linked - polling started.
2020-03-17 23:23:02.942 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'zwave.rules'
2020-03-17 23:23:02.943 [WARN ] [el.core.internal.ModelRepositoryImpl] - Configuration model 'zwave.rules' is either empty or cannot be parsed correctly!
2020-03-17 23:25:33.565 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'zwave.rules'
2020-03-17 23:26:08.261 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Channel zwave:device:55f456ae:node2:alarm_motion linked - polling started.
2020-03-17 23:26:36.481 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 1C 00 49 84 02 16 04 07 01 5E 98 9F 55 86 73 85 8E 59 72 5A 80 84 30 71 31 70 6C 7A A9 
2020-03-17 23:26:36.483 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationUpdate[73], type=Request[0], dest=2, callback=132, payload=84 02 16 04 07 01 5E 98 9F 55 86 73 85 8E 59 72 5A 80 84 30 71 31 70 6C 7A 
2020-03-17 23:26:36.483 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationUpdate[73], type=Request[0], dest=2, callback=132, payload=84 02 16 04 07 01 5E 98 9F 55 86 73 85 8E 59 72 5A 80 84 30 71 31 70 6C 7A 
2020-03-17 23:26:36.484 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2020-03-17 23:26:36.484 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 0
2020-03-17 23:26:36.484 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: null
2020-03-17 23:26:36.485 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=ApplicationUpdate[73], type=Request[0], dest=2, callback=132, payload=84 02 16 04 07 01 5E 98 9F 55 86 73 85 8E 59 72 5A 80 84 30 71 31 70 6C 7A 
2020-03-17 23:26:36.488 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Unsupported command class COMMAND_CLASS_SECURITY_2
2020-03-17 23:26:36.488 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Unsupported command class COMMAND_CLASS_TRANSPORT_SERVICE
2020-03-17 23:26:36.488 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Unsupported command class COMMAND_CLASS_SUPERVISION
2020-03-17 23:26:36.490 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-03-17 23:26:36.491 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-03-17 23:26:36.741 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Is awake with 1 messages in the queue
2020-03-17 23:26:36.742 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Start sleep timer at 5000ms
2020-03-17 23:26:36.742 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveNodeStatusEvent
2020-03-17 23:26:36.746 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 2: Node Status event - Node is AWAKE
2020-03-17 23:26:39.242 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: WakeupTimerTask 1 Messages waiting, state STATIC_VALUES
2020-03-17 23:26:41.742 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: WakeupTimerTask 1 Messages waiting, state STATIC_VALUES
2020-03-17 23:26:41.743 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: No more messages, go back to sleep
2020-03-17 23:26:41.743 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 2: Creating new message for application command WAKE_UP_NO_MORE_INFORMATION
2020-03-17 23:26:41.744 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: SECURITY NOT required on COMMAND_CLASS_WAKE_UP
2020-03-17 23:26:41.744 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Command Class COMMAND_CLASS_WAKE_UP is NOT required to be secured
2020-03-17 23:26:41.744 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@4ca4798e
2020-03-17 23:26:41.745 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Bump transaction 33 priority from Immediate to Immediate
2020-03-17 23:26:41.745 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Adding to device queue
2020-03-17 23:26:41.746 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Added 33 to queue - size 2
2020-03-17 23:26:41.746 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-03-17 23:26:41.746 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 02 02 30 01 25 18 E9 
2020-03-17 23:26:41.747 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 09 00 13 02 02 30 01 25 18 E9 
2020-03-17 23:26:41.747 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2020-03-17 23:26:41.748 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 32: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 24
2020-03-17 23:26:41.748 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2020-03-17 23:26:41.749 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-03-17 23:26:41.749 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-03-17 23:26:41.749 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 32: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 24
2020-03-17 23:26:41.750 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2020-03-17 23:26:41.750 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-03-17 23:26:41.750 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-03-17 23:26:41.755 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2020-03-17 23:26:41.755 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2020-03-17 23:26:41.756 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2020-03-17 23:26:41.756 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 32: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 24
2020-03-17 23:26:41.757 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2020-03-17 23:26:41.757 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 32: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 24
2020-03-17 23:26:41.757 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2020-03-17 23:26:41.758 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 32: Advanced to WAIT_REQUEST
2020-03-17 23:26:41.758 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 32: Transaction not completed
2020-03-17 23:26:41.758 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-03-17 23:26:41.759 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-03-17 23:26:45.989 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 18 01 01 A8 5B 
2020-03-17 23:26:45.992 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=1, callback=24, payload=18 01 01 A8 
2020-03-17 23:26:45.993 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=1, callback=24, payload=18 01 01 A8 
2020-03-17 23:26:45.993 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 32: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 24
2020-03-17 23:26:45.993 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2020-03-17 23:26:45.994 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 32: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 24
2020-03-17 23:26:45.994 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 32: (Callback 24)
2020-03-17 23:26:45.994 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2020-03-17 23:26:45.994 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 32: callback 24
2020-03-17 23:26:45.995 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=1, callback=24, payload=18 01 01 A8 
2020-03-17 23:26:45.996 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 32: Transaction CANCELLED
2020-03-17 23:26:45.996 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2020-03-17 23:26:45.996 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Transaction failed waiting for REQUEST, assume sleeping device.
2020-03-17 23:26:45.997 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: CANCEL while sending message. Requeueing - 2 attempts left!
2020-03-17 23:26:45.997 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 32: Transaction RESET with 2 retries remaining.
2020-03-17 23:26:45.998 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Adding to device queue
2020-03-17 23:26:45.998 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Added 32 to queue - size 2
2020-03-17 23:26:45.998 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-03-17 23:26:45.999 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 32: Transaction not completed
2020-03-17 23:26:45.999 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-03-17 23:26:45.999 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-03-17 23:30:04.824 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 1C 00 49 84 02 16 04 07 01 5E 98 9F 55 86 73 85 8E 59 72 5A 80 84 30 71 31 70 6C 7A A9 
2020-03-17 23:30:04.825 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationUpdate[73], type=Request[0], dest=2, callback=132, payload=84 02 16 04 07 01 5E 98 9F 55 86 73 85 8E 59 72 5A 80 84 30 71 31 70 6C 7A 
2020-03-17 23:30:04.826 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationUpdate[73], type=Request[0], dest=2, callback=132, payload=84 02 16 04 07 01 5E 98 9F 55 86 73 85 8E 59 72 5A 80 84 30 71 31 70 6C 7A 
2020-03-17 23:30:04.826 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2020-03-17 23:30:04.826 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 0
2020-03-17 23:30:04.827 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: null
2020-03-17 23:30:04.827 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=ApplicationUpdate[73], type=Request[0], dest=2, callback=132, payload=84 02 16 04 07 01 5E 98 9F 55 86 73 85 8E 59 72 5A 80 84 30 71 31 70 6C 7A 
2020-03-17 23:30:04.828 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Unsupported command class COMMAND_CLASS_SECURITY_2
2020-03-17 23:30:04.828 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Unsupported command class COMMAND_CLASS_TRANSPORT_SERVICE
2020-03-17 23:30:04.828 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Unsupported command class COMMAND_CLASS_SUPERVISION
2020-03-17 23:30:04.829 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-03-17 23:30:04.830 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-03-17 23:30:05.080 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Is awake with 2 messages in the queue
2020-03-17 23:30:05.080 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Start sleep timer at 5000ms
2020-03-17 23:30:05.081 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveNodeStatusEvent
2020-03-17 23:30:05.083 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 2: Node Status event - Node is AWAKE

5iver · March 18, 2020, 12:22pm

Battery powered devices need to wake up possibly several times in order to complete initialization. There will be a message in the log when this has completed. Have you created Items and linked them to the Channels yet? You’ll need these to see the states.

Ben_P · March 18, 2020, 6:39pm

Yeah I read it as well but I’m skeptical sicne the SmartThings Hub has the device paired and working immediately.
Nevertheless you are right, the initialisation is not over yet.
I paired the device, then let it sit for a while, nothing seems to happen, then woke it up about 10 times in 10 minutes.
Log extract below, it is not from all wake up attempts but they are all the same.

Meanwhile upgraded OpenHab and Z-wave binding to 2.5.2 but no difference.

2020-03-18 18:57:00.533 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Polling...
2020-03-18 18:57:00.533 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Polling deferred until initialisation complete
2020-03-18 19:27:00.533 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Polling...
2020-03-18 19:27:00.533 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Polling deferred until initialisation complete
2020-03-18 19:28:09.003 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 1C 00 49 84 02 16 04 07 01 5E 98 9F 55 86 73 85 8E 59 72 5A 80 84 30 71 31 70 6C 7A A9 
2020-03-18 19:28:09.004 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationUpdate[73], type=Request[0], dest=2, callback=132, payload=84 02 16 04 07 01 5E 98 9F 55 86 73 85 8E 59 72 5A 80 84 30 71 31 70 6C 7A 
2020-03-18 19:28:09.004 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationUpdate[73], type=Request[0], dest=2, callback=132, payload=84 02 16 04 07 01 5E 98 9F 55 86 73 85 8E 59 72 5A 80 84 30 71 31 70 6C 7A 
2020-03-18 19:28:09.005 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2020-03-18 19:28:09.005 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 0
2020-03-18 19:28:09.005 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: null
2020-03-18 19:28:09.006 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=ApplicationUpdate[73], type=Request[0], dest=2, callback=132, payload=84 02 16 04 07 01 5E 98 9F 55 86 73 85 8E 59 72 5A 80 84 30 71 31 70 6C 7A 
2020-03-18 19:28:09.006 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update request. Node information received. Transaction null
2020-03-18 19:28:09.006 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Unsupported command class COMMAND_CLASS_SECURITY_2
2020-03-18 19:28:09.007 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Unsupported command class COMMAND_CLASS_TRANSPORT_SERVICE
2020-03-18 19:28:09.007 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Unsupported command class COMMAND_CLASS_SUPERVISION
2020-03-18 19:28:09.007 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update - no transaction.
2020-03-18 19:28:09.008 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-03-18 19:28:09.008 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-03-18 19:28:09.259 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Is awake with 2 messages in the queue
2020-03-18 19:28:09.259 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Start sleep timer at 5000ms
2020-03-18 19:28:09.311 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveNodeStatusEvent
2020-03-18 19:28:09.318 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Channel zwave:device:ac720982:node2:battery-level unlinked - polling stopped.
2020-03-18 19:28:09.321 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Channel zwave:device:ac720982:node2:battery-level linked - polling started.
2020-03-18 19:28:09.332 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 2: Node Status event - Node is AWAKE
2020-03-18 19:28:09.344 [INFO ] [g.eclipse.smarthome.model.script.log] - Aeotec_Motion_1_Bat with state 0.0
2020-03-18 19:28:09.572 [INFO ] [hings.internal.SmartthingsHttpClient] - Sent message "{"capabilityKey": "battery", "deviceDisplayName": "Aeotec TriSensor", "capabilityAttribute": "battery", "openHabStartTime": 1584556089321}" with path "/state" to the Smartthings hub, recieved HTTP status 202
2020-03-18 19:28:09.699 [INFO ] [g.eclipse.smarthome.model.script.log] - Aeotec_Motion_1_Bat with state 0.0
2020-03-18 19:28:15.534 [INFO ] [g.eclipse.smarthome.model.script.log] - Fibaro_Motion_1_State with state inactive passed to Loxone
2020-03-18 19:28:15.537 [INFO ] [g.eclipse.smarthome.model.script.log] - Fibaro Motion 1 OFF passed to Loxone
2020-03-18 19:28:17.270 [INFO ] [.eclipse.smarthome.model.script.log ] - Fetched Reolink token: bad661bd103bdb2
2020-03-18 19:29:01.582 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 1C 00 49 84 02 16 04 07 01 5E 98 9F 55 86 73 85 8E 59 72 5A 80 84 30 71 31 70 6C 7A A9 
2020-03-18 19:29:01.583 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationUpdate[73], type=Request[0], dest=2, callback=132, payload=84 02 16 04 07 01 5E 98 9F 55 86 73 85 8E 59 72 5A 80 84 30 71 31 70 6C 7A 
2020-03-18 19:29:01.583 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationUpdate[73], type=Request[0], dest=2, callback=132, payload=84 02 16 04 07 01 5E 98 9F 55 86 73 85 8E 59 72 5A 80 84 30 71 31 70 6C 7A 
2020-03-18 19:29:01.584 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2020-03-18 19:29:01.584 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 0
2020-03-18 19:29:01.584 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: null
2020-03-18 19:29:01.584 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=ApplicationUpdate[73], type=Request[0], dest=2, callback=132, payload=84 02 16 04 07 01 5E 98 9F 55 86 73 85 8E 59 72 5A 80 84 30 71 31 70 6C 7A 
2020-03-18 19:29:01.585 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update request. Node information received. Transaction null
2020-03-18 19:29:01.585 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Unsupported command class COMMAND_CLASS_SECURITY_2
2020-03-18 19:29:01.585 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Unsupported command class COMMAND_CLASS_TRANSPORT_SERVICE
2020-03-18 19:29:01.585 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Unsupported command class COMMAND_CLASS_SUPERVISION
2020-03-18 19:29:01.585 [DEBUG] [essage.ApplicationUpdateMessageClass] - NODE 2: Application update - no transaction.
2020-03-18 19:29:01.586 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-03-18 19:29:01.586 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-03-18 19:29:01.586 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 02 02 84 05 25 31 70 
2020-03-18 19:29:01.587 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 09 00 13 02 02 84 05 25 31 70 
2020-03-18 19:29:01.587 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2020-03-18 19:29:01.587 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 77: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 49
2020-03-18 19:29:01.588 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2020-03-18 19:29:01.588 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-03-18 19:29:01.589 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-03-18 19:29:01.589 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 77: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 49
2020-03-18 19:29:01.589 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2020-03-18 19:29:01.590 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-03-18 19:29:01.590 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-03-18 19:29:01.598 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2020-03-18 19:29:01.599 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2020-03-18 19:29:01.599 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2020-03-18 19:29:01.600 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 77: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 49
2020-03-18 19:29:01.600 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2020-03-18 19:29:01.600 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 77: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 49
2020-03-18 19:29:01.600 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2020-03-18 19:29:01.601 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: sentData successfully placed on stack.
2020-03-18 19:29:01.601 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 77: Advanced to WAIT_REQUEST
2020-03-18 19:29:01.601 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 77: Transaction not completed
2020-03-18 19:29:01.601 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-03-18 19:29:01.601 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-03-18 19:29:01.616 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 31 00 00 02 D8 
2020-03-18 19:29:01.617 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=49, payload=31 00 00 02 
2020-03-18 19:29:01.617 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=49, payload=31 00 00 02 
2020-03-18 19:29:01.617 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 77: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 49
2020-03-18 19:29:01.618 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2020-03-18 19:29:01.618 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 77: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 49
2020-03-18 19:29:01.618 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 77: (Callback 49)
2020-03-18 19:29:01.618 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2020-03-18 19:29:01.619 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 77: callback 49
2020-03-18 19:29:01.619 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=49, payload=31 00 00 02 
2020-03-18 19:29:01.619 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: SendData Request. CallBack ID = 49, Status = Transmission complete and ACK received(0)
2020-03-18 19:29:01.619 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 77: Advanced to WAIT_DATA
2020-03-18 19:29:01.620 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 77: Transaction not completed
2020-03-18 19:29:01.620 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-03-18 19:29:01.620 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-03-18 19:29:01.635 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0C 00 04 00 02 06 84 06 00 70 80 00 81 
2020-03-18 19:29:01.636 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=0, payload=00 02 06 84 06 00 70 80 00 
2020-03-18 19:29:01.637 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=0, payload=00 02 06 84 06 00 70 80 00 
2020-03-18 19:29:01.637 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2020-03-18 19:29:01.637 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Application Command Request (ALIVE:STATIC_VALUES)
2020-03-18 19:29:01.637 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Incoming command class COMMAND_CLASS_WAKE_UP, endpoint 0
2020-03-18 19:29:01.638 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: SECURITY NOT required on COMMAND_CLASS_WAKE_UP
2020-03-18 19:29:01.638 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Received COMMAND_CLASS_WAKE_UP V2 WAKE_UP_INTERVAL_REPORT
2020-03-18 19:29:01.638 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 2: Wake up interval report, value = 28800 seconds, targetNodeId = 0
2020-03-18 19:29:01.639 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveWakeUpEvent
2020-03-18 19:29:01.642 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Channel zwave:device:ac720982:node2:battery-level unlinked - polling stopped.
2020-03-18 19:29:01.644 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Channel zwave:device:ac720982:node2:battery-level linked - polling started.
2020-03-18 19:29:01.657 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Commands processed 1.
2020-03-18 19:29:01.657 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@6ef6a09d.
2020-03-18 19:29:01.658 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Command verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@6ef6a09d.
2020-03-18 19:29:01.658 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: notifyTransactionResponse TID:77 DONE
2020-03-18 19:29:01.659 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2020-03-18 19:29:01.659 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 77: Transaction event listener: DONE: DONE -> 
2020-03-18 19:29:01.659 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2020-03-18 19:29:01.659 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@38d938c8
2020-03-18 19:29:01.661 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node Init transaction completed with response COMPLETE
2020-03-18 19:29:01.661 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: SECURITY NOT required on COMMAND_CLASS_WAKE_UP
2020-03-18 19:29:01.662 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Command Class COMMAND_CLASS_WAKE_UP is NOT required to be secured
2020-03-18 19:29:01.662 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: ZWaveCommandClassTransactionPayload - send to node
2020-03-18 19:29:01.663 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: SECURITY NOT required on COMMAND_CLASS_WAKE_UP
2020-03-18 19:29:01.663 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Command Class COMMAND_CLASS_WAKE_UP is NOT required to be secured
2020-03-18 19:29:01.663 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@92b4b76
2020-03-18 19:29:01.659 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2020-03-18 19:29:01.664 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-03-18 19:29:01.664 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Bump transaction 79 priority from Config to Immediate
2020-03-18 19:29:01.664 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-03-18 19:29:01.665 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 02 02 84 08 25 32 7E 
2020-03-18 19:29:01.665 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 09 00 13 02 02 84 08 25 32 7E 
2020-03-18 19:29:01.666 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2020-03-18 19:29:01.666 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 78: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 50
2020-03-18 19:29:01.667 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Adding to device queue
2020-03-18 19:29:01.667 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Added 79 to queue - size 1
2020-03-18 19:29:01.667 [INFO ] [g.eclipse.smarthome.model.script.log] - Aeotec_Motion_1_Bat with state 0.0
2020-03-18 19:29:01.667 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-03-18 19:29:01.668 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2020-03-18 19:29:01.668 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-03-18 19:29:01.669 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-03-18 19:29:01.669 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 78: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 50
2020-03-18 19:29:01.669 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2020-03-18 19:29:01.669 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-03-18 19:29:01.669 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-03-18 19:29:01.673 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2020-03-18 19:29:01.674 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2020-03-18 19:29:01.674 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2020-03-18 19:29:01.675 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 78: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 50
2020-03-18 19:29:01.675 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2020-03-18 19:29:01.675 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 78: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 50
2020-03-18 19:29:01.675 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2020-03-18 19:29:01.676 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: sentData successfully placed on stack.
2020-03-18 19:29:01.676 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 78: Advanced to WAIT_REQUEST
2020-03-18 19:29:01.676 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 78: Transaction not completed
2020-03-18 19:29:01.676 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-03-18 19:29:01.676 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-03-18 19:29:01.689 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 32 00 00 02 DB 
2020-03-18 19:29:01.690 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=50, payload=32 00 00 02 
2020-03-18 19:29:01.690 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=50, payload=32 00 00 02 
2020-03-18 19:29:01.691 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 78: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 50
2020-03-18 19:29:01.691 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2020-03-18 19:29:01.691 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 78: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 50
2020-03-18 19:29:01.691 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 78: (Callback 50)
2020-03-18 19:29:01.692 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2020-03-18 19:29:01.692 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 78: callback 50
2020-03-18 19:29:01.692 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=50, payload=32 00 00 02 
2020-03-18 19:29:01.692 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: SendData Request. CallBack ID = 50, Status = Transmission complete and ACK received(0)
2020-03-18 19:29:01.693 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 78: Transaction COMPLETED
2020-03-18 19:29:01.693 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Response processed after 27ms
2020-03-18 19:29:01.693 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 78: Transaction completed
2020-03-18 19:29:01.693 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: notifyTransactionResponse TID:78 DONE
2020-03-18 19:29:01.694 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2020-03-18 19:29:01.694 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 78: Transaction event listener: DONE: DONE -> 
2020-03-18 19:29:01.694 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-03-18 19:29:01.694 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-03-18 19:29:01.696 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Went to sleep COMPLETE
2020-03-18 19:29:01.696 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 02 02 84 09 25 33 7E 
2020-03-18 19:29:01.697 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 2: Sending REQUEST Message = 01 09 00 13 02 02 84 09 25 33 7E 
2020-03-18 19:29:01.697 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2020-03-18 19:29:01.697 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 79: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 51
2020-03-18 19:29:01.700 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2020-03-18 19:29:01.701 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-03-18 19:29:01.702 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2020-03-18 19:29:01.703 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 79: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 51
2020-03-18 19:29:01.703 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2020-03-18 19:29:01.704 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-03-18 19:29:01.704 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2020-03-18 19:29:01.704 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-03-18 19:29:01.705 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2020-03-18 19:29:01.710 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2020-03-18 19:29:01.710 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 79: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 51
2020-03-18 19:29:01.711 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2020-03-18 19:29:01.711 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 79: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 51
2020-03-18 19:29:01.712 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2020-03-18 19:29:01.713 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: sentData successfully placed on stack.
2020-03-18 19:29:01.713 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 79: Advanced to WAIT_REQUEST
2020-03-18 19:29:01.714 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 79: Transaction not completed
2020-03-18 19:29:01.714 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-03-18 19:29:01.715 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-03-18 19:29:01.720 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 33 00 00 02 DA 
2020-03-18 19:29:01.721 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=51, payload=33 00 00 02 
2020-03-18 19:29:01.722 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=51, payload=33 00 00 02 
2020-03-18 19:29:01.723 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 79: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 51
2020-03-18 19:29:01.723 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2020-03-18 19:29:01.723 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 79: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 51
2020-03-18 19:29:01.724 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 79: (Callback 51)
2020-03-18 19:29:01.724 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2020-03-18 19:29:01.725 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 79: callback 51
2020-03-18 19:29:01.726 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=51, payload=33 00 00 02 
2020-03-18 19:29:01.726 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 2: SendData Request. CallBack ID = 51, Status = Transmission complete and ACK received(0)
2020-03-18 19:29:01.727 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 79: Advanced to WAIT_DATA
2020-03-18 19:29:01.727 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: TID 79: Transaction not completed
2020-03-18 19:29:01.728 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-03-18 19:29:01.728 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2020-03-18 19:29:01.739 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 14 00 04 00 02 0E 84 0A 00 07 08 00 FD 20 00 70 80 00 00 3C 73 
2020-03-18 19:29:01.740 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=0, payload=00 02 0E 84 0A 00 07 08 00 FD 20 00 70 80 00 00 3C 
2020-03-18 19:29:01.741 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=2, callback=0, payload=00 02 0E 84 0A 00 07 08 00 FD 20 00 70 80 00 00 3C 
2020-03-18 19:29:01.741 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2020-03-18 19:29:01.742 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Application Command Request (ALIVE:STATIC_VALUES)
2020-03-18 19:29:01.742 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Incoming command class COMMAND_CLASS_WAKE_UP, endpoint 0
2020-03-18 19:29:01.742 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: SECURITY NOT required on COMMAND_CLASS_WAKE_UP
2020-03-18 19:29:01.743 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 2: Received COMMAND_CLASS_WAKE_UP V2 WAKE_UP_INTERVAL_CAPABILITIES_REPORT
2020-03-18 19:29:01.743 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 2: Wake up interval capabilities report
2020-03-18 19:29:01.743 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 2: Minimum interval = 1800
2020-03-18 19:29:01.743 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 2: Maximum interval = 64800
2020-03-18 19:29:01.744 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 2: Default interval = 28800
2020-03-18 19:29:01.744 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 2: Interval step    = 60
2020-03-18 19:29:01.744 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveWakeUpEvent
2020-03-18 19:29:01.744 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Commands processed 1.
2020-03-18 19:29:01.744 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@558b9a03.
2020-03-18 19:29:01.745 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Command verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@558b9a03.
2020-03-18 19:29:01.745 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: notifyTransactionResponse TID:79 DONE
2020-03-18 19:29:01.745 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2020-03-18 19:29:01.745 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 79: Transaction event listener: DONE: DONE -> 
2020-03-18 19:29:01.746 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2020-03-18 19:29:01.746 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2020-03-18 19:29:01.747 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node Init response (0) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@2d1cae6b
2020-03-18 19:29:01.748 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node Init transaction completed with response COMPLETE
2020-03-18 19:29:01.748 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: STATIC_VALUES - checking COMMAND_CLASS_MANUFACTURER_SPECIFIC
2020-03-18 19:29:01.748 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2020-03-18 19:29:01.748 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Found 1 instances of COMMAND_CLASS_MANUFACTURER_SPECIFIC for endpoint 0
2020-03-18 19:29:01.748 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: STATIC_VALUES - checking COMMAND_CLASS_VERSION
2020-03-18 19:29:01.748 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-03-18 19:29:01.749 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Node advancer: STATIC_VALUES - checking COMMAND_CLASS_SENSOR_MULTILEVEL
2020-03-18 19:29:01.749 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: Found 1 instances of COMMAND_CLASS_SENSOR_MULTILEVEL for endpoint 0
2020-03-18 19:29:01.749 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 2: Creating new message for command SENSOR_MULTILEVEL_SUPPORTED_GET
2020-03-18 19:29:01.750 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: SECURITY NOT required on COMMAND_CLASS_SENSOR_MULTILEVEL
2020-03-18 19:29:01.750 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Command Class COMMAND_CLASS_SENSOR_MULTILEVEL is NOT required to be secured
2020-03-18 19:29:01.750 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 2: ZWaveCommandClassTransactionPayload - send to node
2020-03-18 19:29:01.750 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: SECURITY NOT required on COMMAND_CLASS_SENSOR_MULTILEVEL
2020-03-18 19:29:01.750 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Command Class COMMAND_CLASS_SENSOR_MULTILEVEL is NOT required to be secured
2020-03-18 19:29:01.751 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@7be87920
2020-03-18 19:29:01.751 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Bump transaction 80 priority from Config to Immediate
2020-03-18 19:29:01.751 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Adding to device queue
2020-03-18 19:29:01.751 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 2: Added 80 to queue - size 1
2020-03-18 19:29:01.752 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2020-03-18 19:29:01.837 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Is awake with 1 messages in the queue
2020-03-18 19:29:01.838 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 2: Start sleep timer at 5000ms
2020-03-18 19:29:01.838 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Got an event from Z-Wave network: ZWaveNodeStatusEvent
2020-03-18 19:29:01.945 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Channel zwave:device:ac720982:node2:battery-level unlinked - polling stopped.
2020-03-18 19:29:01.949 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 2: Channel zwave:device:ac720982:node2:battery-level linked - polling started.
2020-03-18 19:29:01.958 [INFO ] [g.eclipse.smarthome.model.script.log] - Aeotec_Motion_1_Bat with state 0.0
2020-03-18 19:29:01.959 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 2: Node Status event - Node is AWAKE

Ben_P · March 19, 2020, 12:29am

Update : Installed Openhab on Raspberry Pi (RaspBian) and also here Zwave devices get recognized but not working.
As anotehr test, I flashed Home Assistant on the same Raspberry later on, and with the same stick it recognized, added the devices straight away. They work without issues there.
So either I am missing some configuration step, or it is Openhab itself that is causing the issue. Please don’t make me move over to Home Assistant

Andrew_Rowe · March 19, 2020, 2:31am

yeah that is one problem right off the bat dude… multiple controllers bugger everything up

what ever… you’ll be back

Bruce_Osborne · March 19, 2020, 10:34am

Another option would be to use SmartThings.

Ben_P · March 19, 2020, 11:35am

Yeah I am moving away from it because my internet connection went down recently for couple of hours and all of a sudden lot of lights, switches, motion detectors were also gone… I knew but never realized it was actually doing all device handling in the cloud. That’s fine for temperature sensors but not for more “critical” infrastructure. Also, switching to locaL is reducing latency from 1-2s to almost not noticeable.

Bruce_Osborne · March 19, 2020, 11:48am

Most any other program is trying to work around your hub. We have an excellent Z-Wave binding here authored & supported by a Euro Space satellite engineer. He is actually working on a complete rewrite to make it even better. He also supports our Zigbee binding.

I am impressed with his dedication & support. That would involve rebuilding your Z-Wave network to use a different controller though. There are many good USB sticks.

Andrew_Rowe · March 19, 2020, 1:21pm

yep… SmartThings dies when the internet goes down

Ben_P · March 19, 2020, 2:42pm

That’s why I don’t understand, I know that CJ is very active and admire his work. So why would one of the most used Zwave sticks not work properly with some very common devices? I’m pretty sure I’m doing something wrong because the same issue on 2 different Openhab installs with nobody else complaining about it? And the stick/sensors themselves work on another platform so they are not faulty.
What then is a good alternative stick ?

Bruce_Osborne · March 19, 2020, 2:54pm

In what region are you located?

chris · March 19, 2020, 4:31pm

I very much doubt that this is related to the stick. Please can you provide a debug log showing what happens during a device initialisation. There is an option in the device parameters to perform the reinitialisation - select this, then wake up the device a bunch of times so I can see what is happening.

Or, better still, exclude the device and reinclude it so I can see the logs - this is better as it ensures the device is in a known state.

It would also be useful to know exactly what the device is (eg the database ID).

Ben_P · March 19, 2020, 9:28pm

Belgium, Europe

Bruce_Osborne · March 19, 2020, 9:58pm

Chris is in UK which is Europe region too. I would try his advice first. He is very good working with unfiltered debug logs.

Ben_P · March 19, 2020, 11:16pm

Update: managed to bind one of them, and half-bind the other one.
Did everything I did before : I tried this whole procedure about 15 times for controller + devices.

Factory reset Stick
Factory reset devices
Removed devices and serial controller through PaperUI
Add stick
Put devices in pairing/inclusion mode

However, I increased the inclusion timeout to 60s and within this time, the device shows up in the inbox, I add it and then I trigger the device’s wakeup mode.
That seems to work. So first poster 5iver was partially right, just didn’t realize the timing.

Doing it after the inclusion search will fail to initialize the device fully.
In the second log, I first add the Fibaro FGMS001. This is then mapped as NODE1
Next, I try to add the Aeotec Trisensor ZWA005, multiple times. Did not wake up device in time, or doing the incorrect action on the button. This resulted in in 4 failed attempts.
Then I try to add and wakeup and this gives NODE6 which does work. It is not passing the temperature and battery yet, only motion and brightness, but I figure this should come later, I’ll give it some hours.
There are 2 logs now, the first one, zwave_not_working, is from an earlier attempt where it did’t work out at all,
Next log where it worked for first device, some failed attempts for second, then success. Note that NODE2,3,4,5,6 are all the same device I tried to add
Will mark as solved if the missing values come in and everything runs stable:

zwave_not_working.log (903.0 KB)
Working (but failed attempts as before) : https://drive.google.com/open?id=1t4SXWBjiha0eZ9_qby6jOD-GAXt7BFXZ

Thanks already for your responses and help!

chris · March 19, 2020, 11:30pm

The inclusion timer will not make any difference - if the device is included, then it’s included. The timer is only there to disable inclusion after a certain time. In all cases I see here, the device is including ok, and given that even in your earlier attempts you say it was recognised, then clearly the inclusion was working ok, so this is not the issue.

In the first log, there are no wakeup messages - the one that worked does have wakeups. It seems that in the first log you haven’t woken up the device so that the binding can communicate with the device. This is needed for battery devices otherwise the binding thinks the device is asleep.

Note that waking a device up is not the same as triggering it - eg making it sense motion. There’s normally a specific button, or button sequence required to wake up the device or send a NIF - the manual should say what this is. In the second log, I think this is only seen in the node 2 instance.

I suspect that this is probably the reason it was not working.

Note that the device is node 2 - not node 1. Node 1 is the controller.

Ben_P · March 20, 2020, 9:05am

Note that the device is node 2 - not node 1. Node 1 is the controller.

You are right sorry about that.

The inclusion timer will not make any difference - if the device is included, then it’s included. The timer is only there to disable inclusion after a certain time.

Agree. But extending it to 60s allowed me to get it into inclusion mode, add it as a Thing from the inbox, then press the action button to wake up the device which it seems I need to do before the inclusion ends. That was the only thing I did different in regards to failed attempts.
Didn’t expected that I needed to do this since the same hardware setup worked under Home Assistant without wakeup, and on SmartThings also without wakeup.

Happy got it to work - battery on Trisensor not reporting but apparently it never did on other setups so that is a device problem.

Thanks for all the awesome work and your help!

chris · March 20, 2020, 9:25am

No - that’s not required. The only thing that needs to be done within the inclusion time, is the inclusion. All the wakeup and creating the thing can be done at any time - days, weeks etc later.