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

[vossivossi]

@Mike_Bagdanoff

Having to delete and re add all zwave things is quite a task for people with >50 devices so it may be worth looking into a way to automate this as part of the install.

I have 100 Zwave devices but I do not see this critical. I have defined all my items in files and let the things discover automatically. One click on ‘Add all new things’ in the inbox solves the problem quickly.
I even started with fresh installs nearly all 2 weeks when upgrading to the newest dev branch and it is definetly not much work. It only takes some time as first discovery and initialisation takes time with the dev branch (for my 100 devices network about 6-9 hours before all nodes initialize to xml).

[vossivossi]

@chris

What other issues are critical that need resolving?

and one more: there are still some java exceptions in Karaf console like this one:

openhab> Exception in thread "Thread-61" java.lang.NullPointerException
        at org.openhab.binding.zwave.handler.ZWaveThingHandler.getI18nConstant(Z
WaveThingHandler.java:139)
        at org.openhab.binding.zwave.handler.ZWaveThingHandler.ZWaveIncomingEven
t(ZWaveThingHandler.java:1255)
        at org.openhab.binding.zwave.internal.protocol.ZWaveController.notifyEve
ntListeners(ZWaveController.java:549)
        at org.openhab.binding.zwave.internal.protocol.ZWaveNode.setNodeState(ZW
aveNode.java:260)
        at org.openhab.binding.zwave.internal.protocol.serialmessage.IsFailedNod
eMessageClass.handleResponse(IsFailedNodeMessageClass.java:53)
        at org.openhab.binding.zwave.internal.protocol.ZWaveController.handleInc
omingResponseMessage(ZWaveController.java:256)
        at org.openhab.binding.zwave.internal.protocol.ZWaveController.handleInc
omingMessage(ZWaveController.java:193)
        at org.openhab.binding.zwave.internal.protocol.ZWaveTransactionManager$Z
WaveReceiveThread.run(ZWaveTransactionManager.java:546)
list

They decreased from version to version but there are still some uncaught exceptions…

[5iver (Scott Rushworth)]

I also get the following frequently in the Karaf console:

java.lang.reflect.InvocationTargetException
        at sun.reflect.GeneratedMethodAccessor190.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at org.openhab.binding.zwave.internal.protocol.commandclass.ZWaveCommandClass.handleApplicationCommandRequest(ZWaveCommandClass.java:245)
        at org.openhab.binding.zwave.internal.protocol.ZWaveNode.processCommand(ZWaveNode.java:1284)
        at org.openhab.binding.zwave.internal.protocol.ZWaveTransactionManager$ZWaveReceiveThread.run(ZWaveTransactionManager.java:416)
Caused by: java.lang.ArrayIndexOutOfBoundsException: 2
        at org.openhab.binding.zwave.internal.protocol.commandclass.impl.CommandClassSecurityV1.handleSecurityNonceReport(CommandClassSecurityV1.java:533)
        at org.openhab.binding.zwave.internal.protocol.commandclass.ZWaveSecurityCommandClass.handleSecurityNonceReport(ZWaveSecurityCommandClass.java:261)
        ... 6 more

[vossivossi]

I searched my debug logs to get more details for the karaf exception. It seems to be this section:

2017-06-29 22:32:32.626 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveMeterValueEvent
2017-06-29 22:32:32.626 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 97: Got an event from Z-Wave network: ZWaveMeterValueEvent
2017-06-29 22:32:32.627 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 97: Got a value event from Z-Wave network, endpoint = 0, command class = COMMAND_CLASS_METER, value = 0E+1
2017-06-29 22:32:32.627 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 97: Updating channel state zwave:device:ZWOG:node97:meter_watts to 0 [DecimalType]
2017-06-29 22:32:32.629 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 97: Commands processed 1.
2017-06-29 22:32:32.629 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 97: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@d6d6ed9.
2017-06-29 22:32:32.629 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2017-06-29 22:32:32.629 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2017-06-29 22:32:32.629 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2017-06-29 22:32:32.629 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start
2017-06-29 22:32:32.629 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction from controllerQueue
2017-06-29 22:32:32.629 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage nothing
2017-06-29 22:32:32.725 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 10 00 04 00 2C 0A 32 02 21 34 00 00 00 00 00 00 E8 
2017-06-29 22:32:32.726 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
2017-06-29 22:32:32.726 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage inputMessage: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=44, callback=0, payload=00 2C 0A 32 02 21 34 00 00 00 00 00 00 
2017-06-29 22:32:32.726 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lockMessage: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=44, callback=0, payload=00 2C 0A 32 02 21 34 00 00 00 00 00 00 
2017-06-29 22:32:32.726 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=44, callback=0, payload=00 2C 0A 32 02 21 34 00 00 00 00 00 00 
2017-06-29 22:32:32.726 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2017-06-29 22:32:32.726 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 44: Application Command Request (FAILED:FAILED_CHECK)
2017-06-29 22:32:32.727 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveNodeStatusEvent
2017-06-29 22:32:32.727 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 44: Got an event from Z-Wave network: ZWaveNodeStatusEvent
2017-06-29 22:32:32.727 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 44: Setting ONLINE
2017-06-29 22:32:32.727 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 44: Node Status event - Node is ALIVE
2017-06-29 22:32:32.727 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 44: Node is ALIVE. Init stage is FAILED_CHECK.
2017-06-29 22:32:32.727 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 44: Incoming command class COMMAND_CLASS_METER, endpoint 0
2017-06-29 22:32:32.727 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 44: SECURITY not supported
2017-06-29 22:32:32.727 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 44: Received COMMAND_CLASS_METER V3 METER_REPORT
2017-06-29 22:32:32.727 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 44: Meter: Type=Electric(1), Scale=W(2), Value=0E+1
2017-06-29 22:32:32.727 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveMeterValueEvent
2017-06-29 22:32:32.727 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 44: Got an event from Z-Wave network: ZWaveMeterValueEvent
2017-06-29 22:32:32.727 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 44: Got a value event from Z-Wave network, endpoint = 0, command class = COMMAND_CLASS_METER, value = 0E+1
2017-06-29 22:32:32.728 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 44: Updating channel state zwave:device:ZWOG:node44:meter_watts to 0 [DecimalType]
2017-06-29 22:32:32.731 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 44: Commands processed 1.
2017-06-29 22:32:32.731 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 44: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@219709ff.
2017-06-29 22:32:32.731 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2017-06-29 22:32:32.731 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2017-06-29 22:32:32.731 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2017-06-29 22:32:32.731 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start
2017-06-29 22:32:32.731 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction from controllerQueue
2017-06-29 22:32:32.731 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage nothing
2017-06-29 22:32:32.754 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: sendTransaction org.openhab.binding.zwave.internal.protocol.ZWaveSerialPayload@1f24e5bd
2017-06-29 22:32:32.754 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Adding to controller queue
2017-06-29 22:32:32.754 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Added to queue - size 1
2017-06-29 22:32:32.754 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start
2017-06-29 22:32:32.754 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction from controllerQueue
2017-06-29 22:32:32.754 [DEBUG] [nal.protocol.ZWaveTransactionManager] - getTransactionToSend 6
2017-06-29 22:32:32.754 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 62 61 F8 
2017-06-29 22:32:32.754 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 04 00 62 61 F8 
2017-06-29 22:32:32.754 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - Message SENT
2017-06-29 22:32:32.754 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 956: Transaction Start type IsFailedNodeID 
2017-06-29 22:32:32.754 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 956: [WAIT_RESPONSE] requiresResponse=true callback: 0
2017-06-29 22:32:32.754 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd class: null
2017-06-29 22:32:32.755 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd: null
2017-06-29 22:32:32.755 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage Transactions outstanding: 1
2017-06-29 22:32:32.755 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Thu Jun 29 22:32:34 CEST 2017 - 2000ms
2017-06-29 22:32:32.755 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage lastTransaction: TID 956: [WAIT_RESPONSE] requiresResponse=true callback: 0
2017-06-29 22:32:32.755 [DEBUG] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
2017-06-29 22:32:32.755 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Thu Jun 29 22:32:34 CEST 2017 - 2000ms
2017-06-29 22:32:32.757 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 06
2017-06-29 22:32:32.757 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage inputMessage: class=null[0x00], type=ACK[0x02], dest=255, callback=0, payload=
2017-06-29 22:32:32.757 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lockMessage: class=null[0x00], type=ACK[0x02], dest=255, callback=0, payload=
2017-06-29 22:32:32.757 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg Message: class=null[0x00], type=ACK[0x02], dest=255, callback=0, payload=
2017-06-29 22:32:32.757 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 956: [WAIT_RESPONSE] requiresResponse=true callback: 0
2017-06-29 22:32:32.757 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg: ACK
2017-06-29 22:32:32.757 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2017-06-29 22:32:32.757 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 1 out at start
2017-06-29 22:32:32.757 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction lastTransaction outstanding...
2017-06-29 22:32:32.757 [DEBUG] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
2017-06-29 22:32:32.757 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Start transaction timer to Thu Jun 29 22:32:34 CEST 2017 - 1998ms
2017-06-29 22:32:32.759 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 04 01 62 01 99 
2017-06-29 22:32:32.759 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
2017-06-29 22:32:32.759 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage inputMessage: class=IsFailedNodeID[0x62], type=Response[0x01], dest=255, callback=0, payload=01 
2017-06-29 22:32:32.760 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lockMessage: class=IsFailedNodeID[0x62], type=Response[0x01], dest=255, callback=0, payload=01 
2017-06-29 22:32:32.760 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg Message: class=IsFailedNodeID[0x62], type=Response[0x01], dest=255, callback=0, payload=01 
2017-06-29 22:32:32.760 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction TID 956: [WAIT_RESPONSE] requiresResponse=true callback: 0
2017-06-29 22:32:32.760 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 1
2017-06-29 22:32:32.760 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: TID 956: [WAIT_RESPONSE] requiresResponse=true callback: 0
2017-06-29 22:32:32.760 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=IsFailedNodeID[0x62], type=Response[0x01], dest=255, callback=0, payload=01 
2017-06-29 22:32:32.760 [WARN ] [rialmessage.IsFailedNodeMessageClass] - NODE 97: Is currently marked as failed by the controller!
2017-06-29 22:32:32.760 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveNodeStatusEvent
2017-06-29 22:32:32.760 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 97: Got an event from Z-Wave network: ZWaveNodeStatusEvent
2017-06-29 22:32:32.760 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 97: Setting OFFLINE
2017-06-29 22:32:32.760 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 97: Node Status event - Node is FAILED
2017-06-29 22:32:32.761 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 97: Node is DEAD.
2017-06-29 22:32:32.761 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 956: Transaction COMPLETED
2017-06-29 22:32:32.761 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 956: TransactionAdvance ST: DONE
2017-06-29 22:32:32.761 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 956: TransactionAdvance WT: null {}
2017-06-29 22:32:32.761 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 956: TransactionAdvance RX: Message: class=IsFailedNodeID[0x62], type=Response[0x01], dest=255, callback=0, payload=01 
2017-06-29 22:32:32.761 [DEBUG] [e.internal.protocol.ZWaveTransaction] - TID 956: TransactionAdvance TO: DONE
2017-06-29 22:32:32.761 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: Response processed after 7ms
2017-06-29 22:32:32.761 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: TID 956: Transaction completed
2017-06-29 22:32:32.761 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:956 DONE
2017-06-29 22:32:32.761 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
2017-06-29 22:32:32.761 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2017-06-29 22:32:32.761 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start
2017-06-29 22:32:32.761 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction from controllerQueue
2017-06-29 22:32:32.761 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage nothing
2017-06-29 22:32:32.761 [DEBUG] [nal.protocol.ZWaveTransactionManager] - STOP transaction timer
2017-06-29 22:32:32.761 [DEBUG] [nal.protocol.ZWaveTransactionManager] - TID 956: Transaction event listener: DONE: DONE -> 
2017-06-29 22:32:32.761 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 255: -- To notify -- COMPLETE
2017-06-29 22:32:32.762 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ********* Transaction Response Complete 956 -- 
2017-06-29 22:32:32.762 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 97: Node Init response (0) COMPLETE
2017-06-29 22:32:32.762 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 97: Node Init transaction completed with response COMPLETE
2017-06-29 22:32:32.950 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 48 9A 21 09 
2017-06-29 22:32:32.950 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
2017-06-29 22:32:32.951 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage inputMessage: class=RequestNodeNeighborUpdate[0x48], type=Request[0x00], dest=33, callback=154, payload=9A 21 
2017-06-29 22:32:32.951 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lockMessage: class=RequestNodeNeighborUpdate[0x48], type=Request[0x00], dest=33, callback=154, payload=9A 21 
2017-06-29 22:32:32.951 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg Message: class=RequestNodeNeighborUpdate[0x48], type=Request[0x00], dest=33, callback=154, payload=9A 21 
2017-06-29 22:32:32.951 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2017-06-29 22:32:32.951 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 0
2017-06-29 22:32:32.951 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: null
2017-06-29 22:32:32.951 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ****************** Transaction not correlated
2017-06-29 22:32:32.951 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=RequestNodeNeighborUpdate[0x48], type=Request[0x00], dest=33, callback=154, payload=9A 21 
2017-06-29 22:32:32.952 [DEBUG] [equestNodeNeighborUpdateMessageClass] - NodeNeighborUpdate request without transaction
2017-06-29 22:32:32.952 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2017-06-29 22:32:32.952 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start
2017-06-29 22:32:32.952 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction from controllerQueue
2017-06-29 22:32:32.952 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage nothing
2017-06-29 22:32:35.148 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0E 00 04 00 61 08 32 02 21 74 00 00 03 64 9E 
2017-06-29 22:32:35.148 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
2017-06-29 22:32:35.148 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage inputMessage: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=97, callback=0, payload=00 61 08 32 02 21 74 00 00 03 64 
2017-06-29 22:32:35.148 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lockMessage: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=97, callback=0, payload=00 61 08 32 02 21 74 00 00 03 64 
2017-06-29 22:32:35.148 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=97, callback=0, payload=00 61 08 32 02 21 74 00 00 03 64 
2017-06-29 22:32:35.148 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2017-06-29 22:32:35.148 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 97: Application Command Request (FAILED:FAILED_CHECK)
2017-06-29 22:32:35.148 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveNodeStatusEvent
2017-06-29 22:32:35.148 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 97: Got an event from Z-Wave network: ZWaveNodeStatusEvent
2017-06-29 22:32:35.148 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 97: Setting ONLINE
2017-06-29 22:32:35.149 [DEBUG] [ve.internal.protocol.ZWaveController] - NODE 97: Node Status event - Node is ALIVE
2017-06-29 22:32:35.149 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 97: Node is ALIVE. Init stage is FAILED_CHECK.
2017-06-29 22:32:35.149 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 97: Incoming command class COMMAND_CLASS_METER, endpoint 0
2017-06-29 22:32:35.149 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 97: SECURITY not supported
2017-06-29 22:32:35.149 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 97: Received COMMAND_CLASS_METER V3 METER_REPORT
2017-06-29 22:32:35.149 [DEBUG] [.commandclass.ZWaveMeterCommandClass] - NODE 97: Meter: Type=Electric(1), Scale=W(2), Value=0.868
2017-06-29 22:32:35.149 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveMeterValueEvent
2017-06-29 22:32:35.149 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 97: Got an event from Z-Wave network: ZWaveMeterValueEvent
2017-06-29 22:32:35.149 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 97: Got a value event from Z-Wave network, endpoint = 0, command class = COMMAND_CLASS_METER, value = 0.868
2017-06-29 22:32:35.149 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 97: Updating channel state zwave:device:ZWOG:node97:meter_watts to 0.868 [DecimalType]
2017-06-29 22:32:35.152 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 97: Commands processed 1.
2017-06-29 22:32:35.152 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 97: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@6742ee38.
2017-06-29 22:32:35.152 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2017-06-29 22:32:35.152 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2017-06-29 22:32:35.152 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2017-06-29 22:32:35.152 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start
2017-06-29 22:32:35.153 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction from controllerQueue
2017-06-29 22:32:35.153 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage nothing
2017-06-29 22:32:37.161 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 05 00 48 9A 22 0A 
2017-06-29 22:32:37.161 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
2017-06-29 22:32:37.161 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage inputMessage: class=RequestNodeNeighborUpdate[0x48], type=Request[0x00], dest=34, callback=154, payload=9A 22 
2017-06-29 22:32:37.161 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lockMessage: class=RequestNodeNeighborUpdate[0x48], type=Request[0x00], dest=34, callback=154, payload=9A 22 
2017-06-29 22:32:37.161 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg Message: class=RequestNodeNeighborUpdate[0x48], type=Request[0x00], dest=34, callback=154, payload=9A 22 
2017-06-29 22:32:37.161 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2017-06-29 22:32:37.161 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Checking outstanding transactions: 0
2017-06-29 22:32:37.161 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Last transaction: null
2017-06-29 22:32:37.161 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ****************** Transaction not correlated
2017-06-29 22:32:37.161 [DEBUG] [ve.internal.protocol.ZWaveController] - Incoming Message: Message: class=RequestNodeNeighborUpdate[0x48], type=Request[0x00], dest=34, callback=154, payload=9A 22 
2017-06-29 22:32:37.161 [DEBUG] [equestNodeNeighborUpdateMessageClass] - NodeNeighborUpdate request without transaction
2017-06-29 22:32:37.161 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2017-06-29 22:32:37.161 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start
2017-06-29 22:32:37.162 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction from controllerQueue
2017-06-29 22:32:37.162 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage nothing
2017-06-29 22:32:37.778 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0C 00 04 00 3F 06 31 05 01 22 01 1D C5 
2017-06-29 22:32:37.779 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
2017-06-29 22:32:37.779 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage inputMessage: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=63, callback=0, payload=00 3F 06 31 05 01 22 01 1D 
2017-06-29 22:32:37.779 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lockMessage: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=63, callback=0, payload=00 3F 06 31 05 01 22 01 1D 
2017-06-29 22:32:37.779 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=63, callback=0, payload=00 3F 06 31 05 01 22 01 1D 
2017-06-29 22:32:37.779 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2017-06-29 22:32:37.779 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 63: Application Command Request (ALIVE:DONE)
2017-06-29 22:32:37.779 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 63: resetResendCount initComplete=true isDead=false
2017-06-29 22:32:37.780 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 63: Incoming command class COMMAND_CLASS_SENSOR_MULTILEVEL, endpoint 0
2017-06-29 22:32:37.780 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 63: SECURITY not supported
2017-06-29 22:32:37.780 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 63: Received COMMAND_CLASS_SENSOR_MULTILEVEL V6 SENSOR_MULTILEVEL_REPORT
2017-06-29 22:32:37.780 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 63: Sensor Type = Temperature(1), Scale = 0
2017-06-29 22:32:37.780 [DEBUG] [ss.ZWaveMultiLevelSensorCommandClass] - NODE 63: Sensor Value = 28.5
2017-06-29 22:32:37.780 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveMultiLevelSensorValueEvent
2017-06-29 22:32:37.780 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 63: Got an event from Z-Wave network: ZWaveMultiLevelSensorValueEvent
2017-06-29 22:32:37.780 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 63: Got a value event from Z-Wave network, endpoint = 0, command class = COMMAND_CLASS_SENSOR_MULTILEVEL, value = 28.5
2017-06-29 22:32:37.780 [DEBUG] [erter.ZWaveMultiLevelSensorConverter] - NODE 63: Sensor is reporting scale 0, requiring conversion to 0. Value is now 28.5.
2017-06-29 22:32:37.780 [DEBUG] [converter.ZWaveCommandClassConverter] - Converted temperature from 28.5C to 28.5C
2017-06-29 22:32:37.780 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 63: Updating channel state zwave:device:ZWOG:node63:sensor_temperature to 28.5 [DecimalType]
2017-06-29 22:32:37.784 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 63: Commands processed 1.
2017-06-29 22:32:37.784 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 63: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@75ac40be.
2017-06-29 22:32:37.784 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2017-06-29 22:32:37.784 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2017-06-29 22:32:37.784 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2017-06-29 22:32:37.784 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start
2017-06-29 22:32:37.784 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction from controllerQueue
2017-06-29 22:32:37.784 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage nothing
2017-06-29 22:32:38.134 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 0C 00 04 00 45 06 43 03 01 22 00 6E B9 
2017-06-29 22:32:38.134 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
2017-06-29 22:32:38.134 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage inputMessage: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=69, callback=0, payload=00 45 06 43 03 01 22 00 6E 
2017-06-29 22:32:38.135 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lockMessage: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=69, callback=0, payload=00 45 06 43 03 01 22 00 6E 
2017-06-29 22:32:38.135 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg Message: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=69, callback=0, payload=00 45 06 43 03 01 22 00 6E 
2017-06-29 22:32:38.135 [DEBUG] [nal.protocol.ZWaveTransactionManager] - lastTransaction null
2017-06-29 22:32:38.135 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 69: Application Command Request (ALIVE:DONE)
2017-06-29 22:32:38.135 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 69: resetResendCount initComplete=true isDead=false
2017-06-29 22:32:38.135 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 69: Incoming command class COMMAND_CLASS_THERMOSTAT_SETPOINT, endpoint 0
2017-06-29 22:32:38.135 [DEBUG] [ng.zwave.internal.protocol.ZWaveNode] - NODE 69: SECURITY not supported
2017-06-29 22:32:38.135 [DEBUG] [tocol.commandclass.ZWaveCommandClass] - NODE 69: Received COMMAND_CLASS_THERMOSTAT_SETPOINT V1 THERMOSTAT_SETPOINT_REPORT
2017-06-29 22:32:38.135 [DEBUG] [.ZWaveThermostatSetpointCommandClass] - NODE 69: Thermostat Setpoint report Scale = 0
2017-06-29 22:32:38.135 [DEBUG] [.ZWaveThermostatSetpointCommandClass] - NODE 69: Thermostat Setpoint Value = 11
2017-06-29 22:32:38.135 [DEBUG] [.ZWaveThermostatSetpointCommandClass] - NODE 69: Thermostat Setpoint Report, Type Heating (1), value = 11
2017-06-29 22:32:38.135 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveThermostatSetpointValueEvent
2017-06-29 22:32:38.135 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 69: Got an event from Z-Wave network: ZWaveThermostatSetpointValueEvent
2017-06-29 22:32:38.136 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 69: Got a value event from Z-Wave network, endpoint = 0, command class = COMMAND_CLASS_THERMOSTAT_SETPOINT, value = 11
2017-06-29 22:32:38.136 [DEBUG] [converter.ZWaveCommandClassConverter] - Converted temperature from 11C to 11C
2017-06-29 22:32:38.136 [DEBUG] [ding.zwave.handler.ZWaveThingHandler] - NODE 69: Updating channel state zwave:device:ZWOG:node69:thermostat_setpoint_heating to 11 [DecimalType]
2017-06-29 22:32:38.139 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 69: Commands processed 1.
2017-06-29 22:32:38.139 [DEBUG] [nal.protocol.ZWaveTransactionManager] - NODE 69: Checking command org.openhab.binding.zwave.internal.protocol.ZWaveCommandClassPayload@1351f374.
2017-06-29 22:32:38.139 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2017-06-29 22:32:38.139 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction completed - outstandingTransactions 0
2017-06-29 22:32:38.139 [DEBUG] [nal.protocol.ZWaveTransactionManager] - ZWaveReceiveThread queue empty
2017-06-29 22:32:38.139 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start
2017-06-29 22:32:38.139 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction from controllerQueue
2017-06-29 22:32:38.139 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage nothing
2017-06-29 22:32:40.107 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 2C 03 40 03 01 9F 
2017-06-29 22:32:40.109 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
2017-06-29 22:32:40.110 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage inputMessage: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=44, callback=0, payload=00 2C 03 40 03 01 
2017-06-29 22:32:40.110 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lockMessage: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=44, callback=0, payload=00 2C 03 40 03 01 
2017-06-29 22:32:40.197 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 00 04 00 2C 03 40 03 01 9F 
2017-06-29 22:32:40.200 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Response SENT 6
2017-06-29 22:32:40.200 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage inputMessage: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=44, callback=0, payload=00 2C 03 40 03 01 
2017-06-29 22:32:40.200 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage past lockMessage: class=ApplicationCommandHandler[0x04], type=Request[0x00], dest=44, callback=0, payload=00 2C 03 40 03 01 
2017-06-29 22:32:40.201 [ERROR] [WaveSerialHandler$ZWaveReceiveThread] - Exception during ZWave thread. 
java.lang.IllegalStateException: Queue full
	at java.util.AbstractQueue.add(Unknown Source)[:1.8.0_131]
	at java.util.concurrent.ArrayBlockingQueue.add(Unknown Source)[:1.8.0_131]
	at org.openhab.binding.zwave.internal.protocol.ZWaveTransactionManager.processReceiveMessage(ZWaveTransactionManager.java:345)[214:org.openhab.binding.zwave:2.1.0.201706252308]
	at org.openhab.binding.zwave.internal.protocol.ZWaveController.incomingPacket(ZWaveController.java:1216)[214:org.openhab.binding.zwave:2.1.0.201706252308]
	at org.openhab.binding.zwave.handler.ZWaveControllerHandler.incomingMessage(ZWaveControllerHandler.java:650)[214:org.openhab.binding.zwave:2.1.0.201706252308]
	at org.openhab.binding.zwave.handler.ZWaveSerialHandler$ZWaveReceiveThread.run(ZWaveSerialHandler.java:321)[214:org.openhab.binding.zwave:2.1.0.201706252308]
2017-06-29 22:32:40.202 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Stopped ZWave thread: Receive

After the exception one of my 2 controllers stopped working with OH. While one controller and its nodes were still fully functional my 2nd Zwave network was down…

[chris (Chris Jackson)]

Is this with the latest version? these exceptions should now all be caught.

[5iver (Scott Rushworth)]

@chris

What other issues are critical that need resolving?

I also see my Aeon Minimote being marked as dead and sends events just fine. It is a battery device that only wakes up after a manual button press, but it is included in the nightly heal and is marked for initialization after a restart.

My biggest issue is with missed events, which I am still trying to track down. The items say they have changed, event log shows the change, zwave log shows it, but lights didn’t respond. Or motion sensors have passed their timeout and it’s as though the event was completely missed. I have ~100 devices and 5 are secure. I’m currently testing reduction in zwave traffic with less frequent power meter reports. My next test will be to fire up OH1 and see if it is only happening with OH2 and this binding. Then I’ll try the binding in master. I’ll also be replacing my zstick with a HUSBZB-1, in case it’s hardware. So this may not be the binding… and I haven’t seen any similar reports in this thread or elsewhere in the forum (or ESH’s).

[5iver (Scott Rushworth)]

@chris

Is this with the latest version? these exceptions should now all be caught.

Yes, 2.1.0.201706252308. And 2.1 OH release.

[chris (Chris Jackson)]

I’ve made a small update - please provide a new log if this error occurs again. The change won’t fix the problem, but adds some debug.

[crimsondr (Brian Chan)]

Finally got my Yale locks paired! woohoo! And I can control them too.

But now my problem is how do I get the status of the lock? When you manual lock/unlock the state doesn’t change. I’ve read that you need to read the alarm channel for the status. But all my alarm channel gives me is “1” for lock and unlock. My lock is a YRD120. Any ideas?

Thanks.

[mark_leonard_tuil (Mark)]

This binding works much better than the standard one. With the standard binding if I restart openhab I always end up with one or two dead nodes. These dead nodes are always battery devices. With this version of the binding that doesn’t happen. All nodes function perfectly after a restart.

Great work!

[crimsondr (Brian Chan)]

@crimsondr

Finally got my Yale locks paired! woohoo! And I can control them too.

But now my problem is how do I get the status of the lock? When you manual lock/unlock the state doesn’t change. I’ve read that you need to read the alarm channel for the status. But all my alarm channel gives me is “1” for lock and unlock. My lock is a YRD120. Any ideas?

Thanks.

Hmm… I looked at the database and compared YRD220 (which provides alarm codes properly) and YRD120. The YRD120 is not showing alarm number under the ALARM class. I assume this is why I’m not getting anything back other than 1. What needs to be done to get this working?

Thanks.

[crimsondr (Brian Chan)]

@dicksteel

zWaveAlarmDeadBolt.apply (ZW_Lock_backAlarm, ZW_Lock_backBolt, Lut_LR_LockBack)

@crimsondr

@crimsondr

Finally got my Yale locks paired! woohoo! And I can control them too.

But now my problem is how do I get the status of the lock? When you manual lock/unlock the state doesn’t change. I’ve read that you need to read the alarm channel for the status. But all my alarm channel gives me is “1” for lock and unlock. My lock is a YRD120. Any ideas?

Thanks.

Hmm… I looked at the database and compared YRD220 (which provides alarm codes properly) and YRD120. The YRD120 is not showing alarm number under the ALARM class. I assume this is why I’m not getting anything back other than 1. What needs to be done to get this working?

Thanks.

Okay, I added the alarm_number channel manually to the jsondb file and now it works. Can we get this added to the database for YRD120?

How about alarm levels? Is there a channel for that? Does it require additional coding or just adding the channel? I want to be able to determine which PIN was entered on the keypad.

Thanks! Great work on this binding! It’s so much nicer working with openhab than vera!

[vossivossi]

@crimsondr

Okay, I added the alarm_number channel manually to the jsondb file and now it works.

Is it really possible to fix things like this? I always thought the device information needs to be updated in the code of the binding…??

[chris (Chris Jackson)]

@crimsondr

Can we get this added to the database for YRD120?

Yes, please feel free to add this to the database.

@crimsondr

How about alarm levels? Is there a channel for that?

I don’t know what this is? Alarms normally don’t have levels - can you describe what you mean?

@vossivossi

I always thought the device information needs to be updated in the code of the binding

Yes, changes need to be in the binding - but not in code. The database is made up of XML files, so it’s sometimes possible to edit the JAR (which is just a ZIP file) to change the XML. I say “sometimes”, because if the JAR is signed, then this won’t work.

[crimsondr (Brian Chan)]

Chris, can you grant me editor permissions for the database under the same name?

If you look at the yale developer PDF attached to YRD220, there is a chart under COMMAND_CLASS_ALARM. It defines ALARM TYPE, which is the alarm_number we have now. But the next column is ALARM LEVEL which provides additional information. This would include the slot number of the PIN entered to identify the user. I was using this on my Vera Edge to customize notifications based on who unlocked the door.

[chris (Chris Jackson)]

@crimsondr

Chris, can you grant me editor permissions for the database under the same name?

Done.

@crimsondr

It defines ALARM TYPE, which is the alarm_number we have now. But the next column is ALARM LEVEL which provides additional information.

This is where things get sticky. ESH / OH doesn’t allow what I might call “attributes” to be attached to an item state. So, I can either pull this out into a separate channel, or I can make an item using a string that provides both bits of information. In this case, a separate channel will probably be ok - it just means that you need to somehow correlate the state and level later - I don’t know how this can be done unambiguously, but if you’re just going to display the information in the UI, it doesn’t matter I guess.

[crimsondr (Brian Chan)]

If this could be put into a separate channel that would be great. You could do as you suggested, create a new item that combines both alarm type and alarm level as a string and put it into a new channel.

[5iver (Scott Rushworth)]

@chris

I’ve made a small update - please provide a new log if this error occurs again. The change won’t fix the problem, but adds some debug.

I haven’t seen the other errors in Karaf since the last build, but I also haven’t had time to go though the log to see what might have been caught. However, I got this once in the console and have seen it in the past:

openhab> Exception in thread "Thread-345" java.util.ConcurrentModificationException
        at java.util.HashMap$HashIterator.nextNode(HashMap.java:1437)
        at java.util.HashMap$ValueIterator.next(HashMap.java:1466)
        at org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer.doDynamicStages(ZWaveNodeInitStageAdvancer.java:936)
        at org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer.access$10(ZWaveNodeInitStageAdvancer.java:932)
        at org.openhab.binding.zwave.internal.protocol.initialization.ZWaveNodeInitStageAdvancer$1.run(ZWaveNodeInitStageAdvancer.java:202)

[shawnmix]

Been absent for a bit, going to chime in:

• For awhile I had been running the binding fine, and I think it should probably be OK enough to likely put into the snapshot releases.

• I’m hitting the error with the battery percentages being reported oddly, but in HABmin I can see its 0.72 for battery level, hence why the interface showing 1% - I think you have a planned fix for this

• Ran into some issues getting the binding running with the update to ESH, but update to the latest 2.1 release fixed

• Though I am having an odd issue I’d like to share, when the system starts, I’m receiving this detail:

  2017-06-30 21:51:40.396 [WARN ] [org.apache.felix.fileinstall ] - Error while starting bundle: file:/usr/share/openhab2/addons/org.openhab.binding.zwave.jar
  org.osgi.framework.BundleException: Could not resolve module: org.openhab.binding.zwave [9]
  Unresolved requirement: Import-Package: com.thoughtworks.xstream
  Unresolved requirement: Import-Package: com.google.common.collect
  -> Export-Package: com.google.common.collect; bundle-symbolic-name=“com.google.guava”; bundle-version=“18.0.0”; version=“18.0.0”; uses:="com.google.common.base,javax.annotation,com.google.common.primitives,com.google.common.math"
  com.google.guava [12]
  Unresolved requirement: Import-Package: javax.annotation; resolution:=“optional”
  -> Export-Package: javax.annotation; bundle-symbolic-name=“javax.annotation-api”; bundle-version=“1.2.0”; version="1.2.0"
  javax.annotation-api [16]
  Unresolved requirement: Import-Package: com.google.gson
  -> Export-Package: com.google.gson; bundle-symbolic-name=“com.google.gson”; bundle-version=“2.3.1”; version="2.3.1"
  com.google.gson [11]
  No resolution report for the bundle.
  at org.eclipse.osgi.container.Module.start(Module.java:434)[org.eclipse.osgi-3.10.101.v20150820-1432.jar:]
  at org.eclipse.osgi.internal.framework.EquinoxBundle.start(EquinoxBundle.java:392)[org.eclipse.osgi-3.10.101.v20150820-1432.jar:]
  at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundle(DirectoryWatcher.java:1253)[4:org.apache.felix.fileinstall:3.5.6]
  at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundles(DirectoryWatcher.java:1225)[4:org.apache.felix.fileinstall:3.5.6]
  at org.apache.felix.fileinstall.internal.DirectoryWatcher.doProcess(DirectoryWatcher.java:512)[4:org.apache.felix.fileinstall:3.5.6]
  at org.apache.felix.fileinstall.internal.DirectoryWatcher.process(DirectoryWatcher.java:361)[4:org.apache.felix.fileinstall:3.5.6]
  at org.apache.felix.fileinstall.internal.DirectoryWatcher.run(DirectoryWatcher.java:312)[4:org.apache.felix.fileinstall:3.5.6]
  2017-06-30 21:51:41.431 [WARN ] [org.apache.felix.fileinstall ] - Error while starting bundle: file:/usr/share/openhab2/addons/org.openhab.binding.zwave.jar
  org.osgi.framework.BundleException: Could not resolve module: org.openhab.binding.zwave [9]
  Unresolved requirement: Import-Package: com.thoughtworks.xstream
  Unresolved requirement: Import-Package: com.google.common.collect
  -> Export-Package: com.google.common.collect; bundle-symbolic-name=“com.google.guava”; bundle-version=“18.0.0”; version=“18.0.0”; uses:="com.google.common.base,javax.annotation,com.google.common.primitives,com.google.common.math"
  com.google.guava [12]
  Unresolved requirement: Import-Package: javax.annotation; resolution:=“optional”
  -> Export-Package: javax.annotation; bundle-symbolic-name=“javax.annotation-api”; bundle-version=“1.2.0”; version="1.2.0"
  javax.annotation-api [16]
  Unresolved requirement: Import-Package: com.google.gson
  -> Export-Package: com.google.gson; bundle-symbolic-name=“com.google.gson”; bundle-version=“2.3.1”; version="2.3.1"
  com.google.gson [11]
  No resolution report for the bundle.
  at org.eclipse.osgi.container.Module.start(Module.java:434)[org.eclipse.osgi-3.10.101.v20150820-1432.jar:]
  at org.eclipse.osgi.internal.framework.EquinoxBundle.start(EquinoxBundle.java:392)[org.eclipse.osgi-3.10.101.v20150820-1432.jar:]
  at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundle(DirectoryWatcher.java:1253)[4:org.apache.felix.fileinstall:3.5.6]
  at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundles(DirectoryWatcher.java:1225)[4:org.apache.felix.fileinstall:3.5.6]
  at org.apache.felix.fileinstall.internal.DirectoryWatcher.doProcess(DirectoryWatcher.java:512)[4:org.apache.felix.fileinstall:3.5.6]
  at org.apache.felix.fileinstall.internal.DirectoryWatcher.process(DirectoryWatcher.java:361)[4:org.apache.felix.fileinstall:3.5.6]
  at org.apache.felix.fileinstall.internal.DirectoryWatcher.run(DirectoryWatcher.java:312)[4:org.apache.felix.fileinstall:3.5.6]
  2017-06-30 21:51:43.301 [WARN ] [org.apache.felix.fileinstall ] - Error while starting bundle: file:/usr/share/openhab2/addons/org.openhab.binding.zwave.jar
  org.osgi.framework.BundleException: Could not resolve module: org.openhab.binding.zwave [9]
  Unresolved requirement: Import-Package: gnu.io
  Unresolved requirement: Import-Package: com.google.common.collect
  -> Export-Package: com.google.common.collect; bundle-symbolic-name=“com.google.guava”; bundle-version=“18.0.0”; version=“18.0.0”; uses:="com.google.common.base,javax.annotation,com.google.common.primitives,com.google.common.math"
  com.google.guava [12]
  Unresolved requirement: Import-Package: javax.annotation; resolution:=“optional”
  -> Export-Package: javax.annotation; bundle-symbolic-name=“javax.annotation-api”; bundle-version=“1.2.0”; version="1.2.0"
  javax.annotation-api [16]
  Unresolved requirement: Import-Package: com.thoughtworks.xstream.converters
  -> Export-Package: com.thoughtworks.xstream.converters; bundle-symbolic-name=“org.eclipse.smarthome.config.xml”; bundle-version=“0.9.0.b5”; version="0.0.0"
  org.eclipse.smarthome.config.xml [98]
  Unresolved requirement: Import-Package: org.osgi.service.component.annotations; resolution:="optional"
  Unresolved requirement: Import-Package: org.eclipse.smarthome.core.common.osgi
  -> Export-Package: org.eclipse.smarthome.core.common.osgi; bundle-symbolic-name=“org.eclipse.smarthome.core”; bundle-version=“0.9.0.b5”; version=“0.0.0"
  org.eclipse.smarthome.core [99]
  Unresolved requirement: Import-Package: com.google.common.base
  -> Export-Package: com.google.common.base; bundle-symbolic-name=“com.google.guava”; bundle-version=“18.0.0”; version=“18.0.0”; uses:=“javax.annotation"
  Unresolved requirement: Import-Package: org.osgi.service.component
  -> Export-Package: org.osgi.service.component; bundle-symbolic-name=“org.apache.felix.scr”; bundle-version=“2.0.6”; version=“1.3.0”; uses:=“org.osgi.framework"
  org.apache.felix.scr [32]
  Unresolved requirement: Import-Package: org.apache.felix.service.command; version=”[0.6.0,1.0.0)”; status=“provisional”; resolution:=“optional"
  Unresolved requirement: Import-Package: org.apache.felix.shell; version=”[1.0.0,1.1.0)”; resolution:="optional"
  Unresolved requirement: Import-Package: org.apache.commons.lang
  -> Export-Package: org.apache.commons.lang; bundle-symbolic-name=“org.apache.commons.lang”; bundle-version=“2.6.0”; version="2.6.0"
  org.apache.commons.lang [31]
  No resolution report for the bundle. Unresolved requirement: Import-Package: com.google.common.collect
  -> Export-Package: com.google.common.collect; bundle-symbolic-name=“com.google.guava”; bundle-version=“18.0.0”; version=“18.0.0”; uses:="com.google.common.base,javax.annotation,com.google.common.primitives,com.google.common.math"
  Unresolved requirement: Import-Package: com.google.gson
  -> Export-Package: com.google.gson; bundle-symbolic-name=“com.google.gson”; bundle-version=“2.3.1”; version="2.3.1"
  com.google.gson [11]
  No resolution report for the bundle. Unresolved requirement: Import-Package: org.apache.commons.io
  -> Export-Package: org.apache.commons.io; bundle-symbolic-name=“org.apache.commons.io”; bundle-version=“2.2.0”; version="2.2.0"
  org.apache.commons.io [30]
  No resolution report for the bundle. Unresolved requirement: Import-Package: org.eclipse.smarthome.config.core
  -> Export-Package: org.eclipse.smarthome.config.core; bundle-symbolic-name=“org.eclipse.smarthome.config.core”; bundle-version=“0.9.0.b5”; version="0.0.0"
  org.eclipse.smarthome.config.core [95]
  Unresolved requirement: Import-Package: org.apache.commons.lang.reflect
  -> Export-Package: org.apache.commons.lang.reflect; bundle-symbolic-name=“org.apache.commons.lang”; bundle-version=“2.6.0”; version="2.6.0"
  Unresolved requirement: Import-Package: org.eclipse.smarthome.core.common
  -> Export-Package: org.eclipse.smarthome.core.common; bundle-symbolic-name=“org.eclipse.smarthome.core”; bundle-version=“0.9.0.b5”; version="0.0.0"
  Unresolved requirement: Import-Package: com.google.gson
  -> Export-Package: com.google.gson; bundle-symbolic-name=“com.google.gson”; bundle-version=“2.3.1”; version="2.3.1"
  Unresolved requirement: Import-Package: org.eclipse.smarthome.core.common.osgi
  -> Export-Package: org.eclipse.smarthome.core.common.osgi; bundle-symbolic-name=“org.eclipse.smarthome.core”; bundle-version=“0.9.0.b5”; version="0.0.0"
  Unresolved requirement: Import-Package: org.eclipse.smarthome.core.events
  -> Export-Package: org.eclipse.smarthome.core.events; bundle-symbolic-name=“org.eclipse.smarthome.core”; bundle-version=“0.9.0.b5”; version=“0.0.0”; uses:="org.eclipse.smarthome.core.items,org.osgi.service.event,org.eclipse.smarthome.core.types"
  Unresolved requirement: Import-Package: com.google.common.collect
  -> Export-Package: com.google.common.collect; bundle-symbolic-name=“com.google.guava”; bundle-version=“18.0.0”; version=“18.0.0”; uses:="com.google.common.base,javax.annotation,com.google.common.primitives,com.google.common.math"
  Unresolved requirement: Import-Package: com.google.common.base
  -> Export-Package: com.google.common.base; bundle-symbolic-name=“com.google.guava”; bundle-version=“18.0.0”; version=“18.0.0”; uses:="javax.annotation"
  Unresolved requirement: Import-Package: org.osgi.service.component
  -> Export-Package: org.osgi.service.component; bundle-symbolic-name=“org.apache.felix.scr”; bundle-version=“2.0.6”; version=“1.3.0”; uses:="org.osgi.framework"
  Unresolved requirement: Import-Package: org.eclipse.smarthome.core.i18n
  -> Export-Package: org.eclipse.smarthome.core.i18n; bundle-symbolic-name=“org.eclipse.smarthome.core”; bundle-version=“0.9.0.b5”; version="0.0.0"
  Unresolved requirement: Import-Package: org.eclipse.smarthome.core.i18n
  -> Export-Package: org.eclipse.smarthome.core.i18n; bundle-symbolic-name=“org.eclipse.smarthome.core”; bundle-version=“0.9.0.b5”; version="0.0.0"
  Unresolved requirement: Import-Package: org.osgi.service.component
  -> Export-Package: org.osgi.service.component; bundle-symbolic-name=“org.apache.felix.scr”; bundle-version=“2.0.6”; version=“1.3.0”; uses:="org.osgi.framework"
  Unresolved requirement: Import-Package: org.eclipse.smarthome.config.core.i18n
  -> Export-Package: org.eclipse.smarthome.config.core.i18n; bundle-symbolic-name=“org.eclipse.smarthome.config.core”; bundle-version=“0.9.0.b5”; version="0.0.0"
  Unresolved requirement: Import-Package: com.thoughtworks.xstream
  -> Export-Package: com.thoughtworks.xstream; bundle-symbolic-name=“org.eclipse.smarthome.config.xml”; bundle-version=“0.9.0.b5”; version="0.0.0"
  Unresolved requirement: Import-Package: com.thoughtworks.xstream.annotations
  -> Export-Package: com.thoughtworks.xstream.annotations; bundle-symbolic-name=“org.eclipse.smarthome.config.xml”; bundle-version=“0.9.0.b5”; version="0.0.0"
  Unresolved requirement: Import-Package: com.thoughtworks.xstream.io.xml
  -> Export-Package: com.thoughtworks.xstream.io.xml; bundle-symbolic-name=“org.eclipse.smarthome.config.xml”; bundle-version=“0.9.0.b5”; version="0.0.0"
  Unresolved requirement: Import-Package: com.thoughtworks.xstream.io
  -> Export-Package: com.thoughtworks.xstream.io; bundle-symbolic-name=“org.eclipse.smarthome.config.xml”; bundle-version=“0.9.0.b5”; version="0.0.0"
  Unresolved requirement: Import-Package: com.google.gson
  -> Export-Package: com.google.gson; bundle-symbolic-name=“com.google.gson”; bundle-version=“2.3.1”; version="2.3.1"
  at org.eclipse.osgi.container.Module.start(Module.java:434)[org.eclipse.osgi-3.10.101.v20150820-1432.jar:]
  at org.eclipse.osgi.internal.framework.EquinoxBundle.start(EquinoxBundle.java:392)[org.eclipse.osgi-3.10.101.v20150820-1432.jar:]
  at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundle(DirectoryWatcher.java:1253)[4:org.apache.felix.fileinstall:3.5.6]
  at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundles(DirectoryWatcher.java:1225)[4:org.apache.felix.fileinstall:3.5.6]
  at org.apache.felix.fileinstall.internal.DirectoryWatcher.doProcess(DirectoryWatcher.java:512)[4:org.apache.felix.fileinstall:3.5.6]
  at org.apache.felix.fileinstall.internal.DirectoryWatcher.process(DirectoryWatcher.java:361)[4:org.apache.felix.fileinstall:3.5.6]
  at org.apache.felix.fileinstall.internal.DirectoryWatcher.run(DirectoryWatcher.java:312)[4:org.apache.felix.fileinstall:3.5.6]
  2017-06-30 21:51:46.323 [WARN ] [org.apache.felix.fileinstall ] - Error while starting bundle: file:/usr/share/openhab2/addons/org.openhab.binding.zwave.jar
  org.osgi.framework.BundleException: Could not resolve module: org.openhab.binding.zwave [9]
  Unresolved requirement: Import-Package: gnu.io
  at org.eclipse.osgi.container.Module.start(Module.java:434)[org.eclipse.osgi-3.10.101.v20150820-1432.jar:]
  at org.eclipse.osgi.internal.framework.EquinoxBundle.start(EquinoxBundle.java:392)[org.eclipse.osgi-3.10.101.v20150820-1432.jar:]
  at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundle(DirectoryWatcher.java:1253)[4:org.apache.felix.fileinstall:3.5.6]
  at org.apache.felix.fileinstall.internal.DirectoryWatcher.startBundles(DirectoryWatcher.java:1225)[4:org.apache.felix.fileinstall:3.5.6]
  at org.apache.felix.fileinstall.internal.DirectoryWatcher.doProcess(DirectoryWatcher.java:512)[4:org.apache.felix.fileinstall:3.5.6]
  at org.apache.felix.fileinstall.internal.DirectoryWatcher.process(DirectoryWatcher.java:361)[4:org.apache.felix.fileinstall:3.5.6]
  at org.apache.felix.fileinstall.internal.DirectoryWatcher.run(DirectoryWatcher.java:312)[4:org.apache.felix.fileinstall:3.5.6]

• Chris - amazing work as usual, and thanks for keeping an updated timer up top of this post on the latest release dates! It’s helped tremendously understanding what versions I’m running.

[Dim (Angelos)]

Here are the minor problems that I have identified in my system while using the latest refactored Z-Wave binding
OH 2.2.0 Snapshot 976 with 2.1.0.201706302351 org.openhab.binding.zwave

i) Aeotec Z-Stick Gen5 ZW090-C (1 unit)
All ok

i) Aeotec Sensor ZW100 (1 unit)
Battery level reported at 1%
Not using sec inclusion for now (for testing purposes)
NODE 8: Is currently marked as failed by the controller! (every 30 secs) but working and reporting values normally

ii) Fibaro Sensor FGMS-001 (2 units)
All ok

iii) Fibaro Button FGPB-001 (2 units)
Battery level reported at 1%

iv) Fibaro Dimmer FGD-212 (1 unit)
All ok

v) Other issues (related to UIs, not the binding)
Several small problems when trying to change config parameters using PaperUI (I am getting usually error 500)
Some small problems when using HABmin to change config parameters for some devices (null exceptions)
I will capture debug logs and post more info soon

In general: It’s working fine and these small issues don’t bother me