Fibaro KeyFob FGKF601 (Z-wave) - unknown device - SOLVED!

archie_n · November 19, 2018, 10:35pm

I’ve been using the FGKF601 successfully for some time together with OH 2.2. However, I had to update OH in order to be able to use the TZWP-102 Telldus socket and energy meter and settled for the 2.4 version (currently built #1431, but I’ve also tried the Milestone built and - before that 2.3.).

The problem is thatKeyFob FGKF601 lacks is shown as “unkown device” even though it’s listed under supported devices (FGKF601 Keyfob, zwave:fibaro_fgkf601_00_000) when using binding-zway - 2.4.0.SNAPSHOT

HabAdmin shows the following
Manufacturer:
Type / ID
Firmware Version: 0.0
Basic Class: BASIC_TYPE_ROUTING_SLAVE
Generic Class: GENERIC_TYPE_WALL_CONTROLLER
Specific Class: SPECIFIC_TYPE_BASIC_WALL_CONTROLLER
Using Security: no
Routing: yes
Listening: no
Frequently Listening: no
Beaming: yes

I’ve tried waiting :-), pressing all buttons multiple times close to the Aeon Z-wave stick, restarting, but am stuck.

Any ideas how I can get the remote back working again?

Thanks for any suggestions.

5iver · November 19, 2018, 11:58pm

Do the zwave debug logs show that the device is waking up after you have manually woken it up?

mhilbush · November 20, 2018, 12:09am

How are you waking up te device? The manual says.

click o and + simultaneously to wake up the device.

archie_n · November 20, 2018, 4:39pm

The log shows:

2018-11-20 17:37:15.862 [vent.ItemStateChangedEvent] - zwave_serial_zstick_512_serial_sof changed from 222 to 223

2018-11-20 17:37:15.868 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:512:node8' has been updated.

HabAdmin reports:

archie_n · November 20, 2018, 4:40pm

That’s the procedure I’m using.

mhilbush · November 20, 2018, 4:47pm

Your next step should be to put the zwave binding into debug mode to get a better idea what’s happening when it wakes up.

archie_n · November 20, 2018, 7:51pm

Here’s the log:

2018-11-20 20:46:39.573 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: ZWaveCommandClassTransactionPayload - send to node
2018-11-20 20:46:39.576 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: SECURITY check internal
2018-11-20 20:46:39.579 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: Command Class COMMAND_CLASS_SECURITY is NOT required to be secured
2018-11-20 20:46:39.582 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@b3d358
2018-11-20 20:46:39.586 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Bump transaction 90 priority from Immediate to Immediate
2018-11-20 20:46:39.588 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Adding to device queue
2018-11-20 20:46:39.591 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Added 90 to queue - size 1
2018-11-20 20:46:39.594 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

mhilbush · November 20, 2018, 7:59pm

This log doesn’t show the device waking up.

Dim · November 20, 2018, 8:05pm

just a quick clarification question: Z-Way or Z-Wave binding is being used? (obviously from the logs it’s Z-Wave… just making sure that this was a typo and you don’t have both installed)

archie_n · November 20, 2018, 8:08pm

Sorry for the confusion, i.e. typo. The Z-Wave binding is being used.

Dim · November 20, 2018, 8:09pm

is your system “clean” from the previous version of the Z-Wave binding?

you can check in the OH2 console:

bundle:list -s |grep zwave

only 1 entry should appear (with the 2.4 snapshot version)

archie_n · November 20, 2018, 8:15pm

Here’s a more comprehensive log.

2018-11-20 21:09:45.082 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-11-20 21:09:45.083 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2018-11-20 21:09:45.084 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2018-11-20 21:09:45.086 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2018-11-20 21:09:45.087 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 90: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 68
2018-11-20 21:09:45.091 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2018-11-20 21:09:45.093 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 90: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 68
2018-11-20 21:09:45.095 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2018-11-20 21:09:45.095 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 44 00 00 02 AD 
2018-11-20 21:09:45.099 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 8: sentData successfully placed on stack.
2018-11-20 21:09:45.102 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=68, payload=44 00 00 02 
2018-11-20 21:09:45.102 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 90: Advanced to WAIT_REQUEST
2018-11-20 21:09:45.108 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: TID 90: Transaction not completed
2018-11-20 21:09:45.111 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=68, payload=44 00 00 02 
2018-11-20 21:09:45.114 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 90: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 68
2018-11-20 21:09:45.117 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2018-11-20 21:09:45.120 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 90: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 68
2018-11-20 21:09:45.123 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 90: (Callback 68)
2018-11-20 21:09:45.125 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2018-11-20 21:09:45.128 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 90: callback 68
2018-11-20 21:09:45.130 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=68, payload=44 00 00 02 
2018-11-20 21:09:45.133 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 8: SendData Request. CallBack ID = 68, Status = Transmission complete and ACK received(0)
2018-11-20 21:09:45.135 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 90: Advanced to WAIT_DATA
2018-11-20 21:09:45.138 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: TID 90: Transaction not completed
2018-11-20 21:09:45.140 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-11-20 21:09:45.142 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2018-11-20 21:09:46.840 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 04 04 08 02 84 07 7E 
2018-11-20 21:09:46.852 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=4, payload=04 08 02 84 07 
2018-11-20 21:09:46.857 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=4, payload=04 08 02 84 07 
2018-11-20 21:09:46.862 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2018-11-20 21:09:46.866 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Application Command Request (ALIVE:SECURITY_REPORT)
2018-11-20 21:09:46.872 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Commands processed 1.
2018-11-20 21:09:46.876 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@59d31a.
2018-11-20 21:09:46.881 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Command NOT verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@59d31a.
2018-11-20 21:09:46.886 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2018-11-20 21:09:46.890 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2018-11-20 21:09:46.895 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-11-20 21:09:46.898 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2018-11-20 21:09:47.312 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: WakeupTimerTask 1 Messages waiting, state SECURITY_REPORT
2018-11-20 21:09:49.358 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 04 04 08 02 84 07 7E 
2018-11-20 21:09:49.369 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=4, payload=04 08 02 84 07 
2018-11-20 21:09:49.376 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=4, payload=04 08 02 84 07 
2018-11-20 21:09:49.379 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2018-11-20 21:09:49.382 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Application Command Request (ALIVE:SECURITY_REPORT)
2018-11-20 21:09:49.386 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Commands processed 1.
2018-11-20 21:09:49.389 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@19ec094.
2018-11-20 21:09:49.392 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Command NOT verified org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@19ec094.
2018-11-20 21:09:49.395 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2018-11-20 21:09:49.398 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 1
2018-11-20 21:09:49.401 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-11-20 21:09:49.404 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start. Holdoff false.
2018-11-20 21:09:49.812 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: WakeupTimerTask 1 Messages waiting, state SECURITY_REPORT
2018-11-20 21:09:50.138 [DEBUG] [sactionManager$ZWaveTransactionTimer] - NODE 8: TID 90: Timeout at state WAIT_DATA. 3 retries remaining.
2018-11-20 21:09:50.143 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 90: Transaction CANCELLED
2018-11-20 21:09:50.146 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2018-11-20 21:09:50.150 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: notifyTransactionResponse TID:90 CANCELLED
2018-11-20 21:09:50.154 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2018-11-20 21:09:50.157 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 90: Transaction event listener: DONE: CANCELLED -> 
2018-11-20 21:09:50.163 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: Node Init response (4) org.openhab.binding.zwave.internal.protocol.ZWaveTransactionResponse@17537ca
2018-11-20 21:09:50.167 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: No data from device, but it was ACK'd. Possibly not supported? (Try 4)
2018-11-20 21:09:51.587 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 08 00 04 04 08 02 84 07 7E 
2018-11-20 21:09:51.594 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=4, payload=04 08 02 84 07 
2018-11-20 21:09:51.599 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=8, callback=4, payload=04 08 02 84 07 
2018-11-20 21:09:51.602 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2018-11-20 21:09:51.606 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Application Command Request (ALIVE:SECURITY_REPORT)
2018-11-20 21:09:51.612 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Commands processed 1.
2018-11-20 21:09:51.615 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@4233a4.
2018-11-20 21:09:51.619 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2018-11-20 21:09:51.623 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2018-11-20 21:09:51.628 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-11-20 21:09:51.632 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2018-11-20 21:09:52.311 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: WakeupTimerTask 0 Messages waiting, state SECURITY_REPORT
2018-11-20 21:09:54.812 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: WakeupTimerTask 0 Messages waiting, state SECURITY_REPORT
2018-11-20 21:09:54.815 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: No more messages, go back to sleep
2018-11-20 21:09:54.818 [DEBUG] [commandclass.ZWaveWakeUpCommandClass] - NODE 8: Creating new message for application command WAKE_UP_NO_MORE_INFORMATION
2018-11-20 21:09:54.822 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: SECURITY NOT required on COMMAND_CLASS_WAKE_UP
2018-11-20 21:09:54.825 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: Command Class COMMAND_CLASS_WAKE_UP is NOT required to be secured
2018-11-20 21:09:54.828 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@460f0f
2018-11-20 21:09:54.832 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Bump transaction 94 priority from Immediate to Immediate
2018-11-20 21:09:54.835 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Adding to device queue
2018-11-20 21:09:54.839 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Added 94 to queue - size 1
2018-11-20 21:09:54.842 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2018-11-20 21:09:54.846 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 00 13 08 02 84 08 25 45 03 
2018-11-20 21:09:54.850 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 8: Sending REQUEST Message = 01 09 00 13 08 02 84 08 25 45 03 
2018-11-20 21:09:54.853 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2018-11-20 21:09:54.856 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 94: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 69
2018-11-20 21:09:54.867 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2018-11-20 21:09:54.871 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2018-11-20 21:09:54.875 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=ACK[2], dest=255, callback=0, payload=
2018-11-20 21:09:54.879 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 94: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 69
2018-11-20 21:09:54.879 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 13 01 E8 
2018-11-20 21:09:54.885 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2018-11-20 21:09:54.890 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2018-11-20 21:09:54.900 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 13 45 00 00 02 AC 
2018-11-20 21:09:54.900 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2018-11-20 21:09:54.908 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=SendData[19], type=Request[0], dest=0, callback=69, payload=45 00 00 02 
2018-11-20 21:09:54.908 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 94: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 69
2018-11-20 21:09:54.913 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2018-11-20 21:09:54.915 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 94: [WAIT_RESPONSE] priority=Immediate, requiresResponse=true, callback: 69
2018-11-20 21:09:54.918 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Response[1], dest=255, callback=0, payload=01 
2018-11-20 21:09:54.921 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 8: sentData successfully placed on stack.
2018-11-20 21:09:54.924 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 94: Advanced to WAIT_REQUEST
2018-11-20 21:09:54.927 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: TID 94: Transaction not completed
2018-11-20 21:09:54.931 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=SendData[19], type=Request[0], dest=0, callback=69, payload=45 00 00 02 
2018-11-20 21:09:54.933 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 94: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 69
2018-11-20 21:09:54.936 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2018-11-20 21:09:54.939 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 94: [WAIT_REQUEST] priority=Immediate, requiresResponse=true, callback: 69
2018-11-20 21:09:54.941 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking TID 94: (Callback 69)
2018-11-20 21:09:54.945 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Callback match!
2018-11-20 21:09:54.948 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Correlated to TID 94: callback 69
2018-11-20 21:09:54.951 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=SendData[19], type=Request[0], dest=0, callback=69, payload=45 00 00 02 
2018-11-20 21:09:54.955 [DEBUG] [l.serialmessage.SendDataMessageClass] - NODE 8: SendData Request. CallBack ID = 69, Status = Transmission complete and ACK received(0)
2018-11-20 21:09:54.958 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 94: Transaction COMPLETED
2018-11-20 21:09:54.961 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Response processed after 106ms
2018-11-20 21:09:54.964 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: TID 94: Transaction completed
2018-11-20 21:09:54.967 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: notifyTransactionResponse TID:94 DONE
2018-11-20 21:09:54.974 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 8: Got an event from Z-Wave network: ZWaveTransactionCompletedEvent
2018-11-20 21:09:54.978 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-11-20 21:09:54.980 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2018-11-20 21:09:54.979 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 94: Transaction event listener: DONE: DONE -> 
2018-11-20 21:09:54.986 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: Went to sleep COMPLETE
2018-11-20 21:10:22.504 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 8: ZWaveCommandClassTransactionPayload - send to node
2018-11-20 21:10:22.506 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: SECURITY check internal
2018-11-20 21:10:22.508 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 8: Command Class COMMAND_CLASS_SECURITY is NOT required to be secured
2018-11-20 21:10:22.509 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: sendTransaction org.openhab.binding.zwave.internal.protocol.transaction.ZWaveCommandClassTransactionPayload@b3d358
2018-11-20 21:10:22.511 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Bump transaction 95 priority from Immediate to Immediate
2018-11-20 21:10:22.513 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Adding to device queue
2018-11-20 21:10:22.515 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 8: Added 95 to queue - size 1
2018-11-20 21:10:22.516 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2018-11-20 21:11:59.393 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 00 04 00 06 0A 32 02 21 74 00 00 00 00 00 00 82 
2018-11-20 21:11:59.407 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=6, callback=0, payload=00 06 0A 32 02 21 74 00 00 00 00 00 00 
2018-11-20 21:11:59.417 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=6, callback=0, payload=00 06 0A 32 02 21 74 00 00 00 00 00 00 
2018-11-20 21:11:59.422 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2018-11-20 21:11:59.425 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 6: Application Command Request (ALIVE:DONE)
2018-11-20 21:11:59.429 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 6: resetResendCount initComplete=true isDead=false
2018-11-20 21:11:59.433 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 6: Incoming command class COMMAND_CLASS_METER, endpoint 0
2018-11-20 21:11:59.437 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 6: SECURITY NOT required on COMMAND_CLASS_METER
2018-11-20 21:11:59.441 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 6: Received COMMAND_CLASS_METER V3 METER_REPORT
2018-11-20 21:11:59.446 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 6: Meter: Type=Electric(1), Scale=W(2), Value=0E+1
2018-11-20 21:11:59.449 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Got an event from Z-Wave network: ZWaveMeterValueEvent
2018-11-20 21:11:59.454 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Got a value event from Z-Wave network, endpoint = 0, command class = COMMAND_CLASS_METER, value = 0E+1
2018-11-20 21:11:59.458 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 6: Updating channel state zwave:device:512:node6:meter_watts to 0 [DecimalType]
2018-11-20 21:11:59.462 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 6: Commands processed 1.
2018-11-20 21:11:59.470 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 00 04 00 07 0A 32 02 21 74 00 00 00 00 00 00 83 
2018-11-20 21:11:59.465 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 6: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@16f9f7e.
2018-11-20 21:11:59.476 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2018-11-20 21:11:59.478 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2018-11-20 21:11:59.480 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-11-20 21:11:59.481 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2018-11-20 21:11:59.481 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=7, callback=0, payload=00 07 0A 32 02 21 74 00 00 00 00 00 00 
2018-11-20 21:11:59.485 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=7, callback=0, payload=00 07 0A 32 02 21 74 00 00 00 00 00 00 
2018-11-20 21:11:59.487 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2018-11-20 21:11:59.488 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 7: Application Command Request (ALIVE:DONE)
2018-11-20 21:11:59.490 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 7: resetResendCount initComplete=true isDead=false
2018-11-20 21:11:59.492 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 7: Incoming command class COMMAND_CLASS_METER, endpoint 0
2018-11-20 21:11:59.493 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 7: SECURITY NOT required on COMMAND_CLASS_METER
2018-11-20 21:11:59.495 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 7: Received COMMAND_CLASS_METER V3 METER_REPORT
2018-11-20 21:11:59.497 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 7: Meter: Type=Electric(1), Scale=W(2), Value=0E+1
2018-11-20 21:11:59.499 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 7: Got an event from Z-Wave network: ZWaveMeterValueEvent
2018-11-20 21:11:59.501 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 7: Got a value event from Z-Wave network, endpoint = 0, command class = COMMAND_CLASS_METER, value = 0E+1
2018-11-20 21:11:59.503 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 7: Updating channel state zwave:device:512:node7:meter_watts to 0 [DecimalType]
2018-11-20 21:11:59.505 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 7: Commands processed 1.
2018-11-20 21:11:59.508 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 7: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1fa498a.
2018-11-20 21:11:59.510 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2018-11-20 21:11:59.513 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2018-11-20 21:11:59.515 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-11-20 21:11:59.517 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.
2018-11-20 21:11:59.933 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 00 04 00 05 0A 32 02 21 74 00 00 00 00 00 00 81 
2018-11-20 21:11:59.939 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 0A 32 02 21 74 00 00 00 00 00 00 
2018-11-20 21:11:59.943 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=ApplicationCommandHandler[4], type=Request[0], dest=5, callback=0, payload=00 05 0A 32 02 21 74 00 00 00 00 00 00 
2018-11-20 21:11:59.945 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2018-11-20 21:11:59.947 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Application Command Request (ALIVE:DONE)
2018-11-20 21:11:59.950 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: resetResendCount initComplete=true isDead=false
2018-11-20 21:11:59.952 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: Incoming command class COMMAND_CLASS_METER, endpoint 0
2018-11-20 21:11:59.955 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: SECURITY NOT required on COMMAND_CLASS_METER
2018-11-20 21:11:59.957 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 5: Received COMMAND_CLASS_METER V3 METER_REPORT
2018-11-20 21:11:59.960 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 5: Meter: Type=Electric(1), Scale=W(2), Value=0E+1
2018-11-20 21:11:59.962 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got an event from Z-Wave network: ZWaveMeterValueEvent
2018-11-20 21:11:59.965 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Got a value event from Z-Wave network, endpoint = 0, command class = COMMAND_CLASS_METER, value = 0E+1
2018-11-20 21:11:59.968 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 5: Updating channel state zwave:device:512:node5:meter_watts to 0 [DecimalType]
2018-11-20 21:11:59.971 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Commands processed 1.
2018-11-20 21:11:59.974 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@79ad01.
2018-11-20 21:11:59.976 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2018-11-20 21:11:59.982 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2018-11-20 21:11:59.986 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2018-11-20 21:11:59.990 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start. Holdoff false.

archie_n · November 20, 2018, 8:16pm

Fresh install

210 │ Active   │  80 │ 2.4.0.201811191745     │ org.openhab.binding.zwave

mhilbush · November 20, 2018, 8:33pm

This log isn’t showing much either.
ZWave%20Log%20Viewer%202018-11-20%2015-29-46
Perhaps you could try to exclude the device, do a factory reset on the device, include it into the network, then wake it up.

Post the entire log from the inclusion. If the log is too big to post in the forum (likely), post it on a file sharing service and include a link here.

archie_n · November 20, 2018, 9:54pm

One wouldn’t believe it …
Reseting the keyfob, changing the battery (even though the existing one was ok), pairing with the controller and everything fell into place.

Thanks for all input!