OH2 Z-Wave refactoring and testing... and SECURITY

Hey,

Following another topic, I’ve installed the latest zwave binding. In short, after a while, my zwave setup stops working, all other things (knx, weather, pushover…) worked.
No idea why zwave goes dead. I’m running OH2 on Ubuntu17.10 as VM under proxmox. And I’m using 2(!) GEN5 USB sticks. This worked for about 1 year without problems. It’s possible that it’s a hardware/KV issue. But after 4 complete reinstalls (OS and OH), reset of 30 zwave nodes, I don’t have any clue more how to proceed. :blush:

I did following steps right now:

1. Remove zwave binding from paperUI
2. cd /etc/openhab2/addons/
3. wget http://www.cd-jackson.com/downloads/openhab2/org.openhab.binding.zwave-2.2.0-SNAPSHOT.jar
4. ssh openhab@localhost -p8101
    feature:install openhab-transport-serial
    bundle:start org.openhab.binding.zwave
    bundle:list
       215 | Installed |  80 | 2.2.0.201710172006     | ZWave Binding

A lot of logs passes by, but all my zwave nodes stay UNINITIALIZED.
I would guess that the outlet powered devices come online after 1 hour?

2017-10-24 09:40:19.620 [DEBUG] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
2017-10-24 09:40:19.620 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Tue Oct 24 09:40:21 CEST 2017 - 2000ms
2017-10-24 09:40:19.622 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2017-10-24 09:40:19.622 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0x00], type=ACK[0x02], dest=255, callback=0, payload=
2017-10-24 09:40:19.622 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=null[0x00], type=ACK[0x02], dest=255, callback=0, payload=
2017-10-24 09:40:19.622 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0x00], type=ACK[0x02], dest=255, callback=0, payload=
2017-10-24 09:40:19.622 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 1101: [WAIT_RESPONSE] requiresResponse=true callback: 0
2017-10-24 09:40:19.622 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2017-10-24 09:40:19.622 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2017-10-24 09:40:19.622 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start
2017-10-24 09:40:19.622 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding...
2017-10-24 09:40:19.622 [DEBUG] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
2017-10-24 09:40:19.622 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Tue Oct 24 09:40:21 CEST 2017 - 1998ms
2017-10-24 09:40:19.626 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 62 01 99 
2017-10-24 09:40:19.630 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
2017-10-24 09:40:19.630 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=IsFailedNodeID[0x62], type=Response[0x01], dest=255, callback=0, payload=01 
2017-10-24 09:40:19.630 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lock Message: class=IsFailedNodeID[0x62], type=Response[0x01], dest=255, callback=0, payload=01 
2017-10-24 09:40:19.632 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=IsFailedNodeID[0x62], type=Response[0x01], dest=255, callback=0, payload=01 
2017-10-24 09:40:19.632 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 1101: [WAIT_RESPONSE] requiresResponse=true callback: 0
2017-10-24 09:40:19.632 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2017-10-24 09:40:19.632 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 1101: [WAIT_RESPONSE] requiresResponse=true callback: 0
2017-10-24 09:40:19.632 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=IsFailedNodeID[0x62], type=Response[0x01], dest=255, callback=0, payload=01 
2017-10-24 09:40:19.632 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 1101: Transaction COMPLETED
2017-10-24 09:40:19.632 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 1101: TransactionAdvance ST: DONE
2017-10-24 09:40:19.632 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 1101: TransactionAdvance WT: null {}
2017-10-24 09:40:19.632 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 1101: TransactionAdvance RX: Message: class=IsFailedNodeID[0x62], type=Response[0x01], dest=255, callback=0, payload=01 
2017-10-24 09:40:19.632 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 1101: TransactionAdvance TO: DONE
2017-10-24 09:40:19.632 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 12ms
2017-10-24 09:40:19.632 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 1101: Transaction completed
2017-10-24 09:40:19.633 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:1101 DONE
2017-10-24 09:40:19.633 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
2017-10-24 09:40:19.633 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2017-10-24 09:40:19.633 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start
2017-10-24 09:40:19.633 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 3: listening == false, frequentlyListening == false, awake == false
2017-10-24 09:40:19.633 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 3: Node not awake!
2017-10-24 09:40:19.633 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 21: listening == false, frequentlyListening == false, awake == false
2017-10-24 09:40:19.633 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 21: Node not awake!
2017-10-24 09:40:19.633 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 19: listening == false, frequentlyListening == false, awake == false
2017-10-24 09:40:19.633 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 19: Node not awake!
2017-10-24 09:40:19.633 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 16: listening == false, frequentlyListening == false, awake == false
2017-10-24 09:40:19.633 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 16: Node not awake!
2017-10-24 09:40:19.633 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 15: listening == false, frequentlyListening == false, awake == false
2017-10-24 09:40:19.633 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 15: Node not awake!
2017-10-24 09:40:19.633 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 5: listening == false, frequentlyListening == false, awake == false
2017-10-24 09:40:19.633 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 5: Node not awake!
2017-10-24 09:40:19.633 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 23: listening == false, frequentlyListening == false, awake == false
2017-10-24 09:40:19.633 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 23: Node not awake!
2017-10-24 09:40:19.633 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 4: listening == false, frequentlyListening == false, awake == false
2017-10-24 09:40:19.633 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 4: Node not awake!
2017-10-24 09:40:19.633 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: listening == false, frequentlyListening == false, awake == false
2017-10-24 09:40:19.633 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 12: Node not awake!
2017-10-24 09:40:19.633 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 20: listening == false, frequentlyListening == false, awake == false
2017-10-24 09:40:19.633 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 20: Node not awake!
2017-10-24 09:40:19.633 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 17: listening == false, frequentlyListening == false, awake == false
2017-10-24 09:40:19.633 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 17: Node not awake!
2017-10-24 09:40:19.633 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction from controllerQueue
2017-10-24 09:40:19.633 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage nothing
2017-10-24 09:40:19.633 [DEBUG] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
2017-10-24 09:40:19.633 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 1101: Transaction event listener: DONE: DONE -> 
2017-10-24 09:40:19.633 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: -- To notify -- COMPLETE
2017-10-24 09:40:19.634 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ********* Transaction Response Complete 1101 -- 
2017-10-24 09:40:19.637 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 7: Node Init response (0) COMPLETE
2017-10-24 09:40:19.637 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 7: Node Init transaction completed with response COMPLETE