I’ve had OpenRemote running fairly successfully and reliably for about a year.
when I first set it up I struggled to get the Zwave Z-Stick to work.
I recently re-built my qnap with a new OS - 4.2.1 and i thought I’d re-install OpenRemote and go straight for 2.5 - seems I have the same problem.
with all the logging turned up to Max all I see in the ZWave Log is:
INFO 2016-06-15 18:11:04,767 :
I may have made some progress here:
I tried putting in a simple switch/sensor on Port 2 to try and kick the ZWave protocol into gear.
This was the output - it seems to suggest that the Serial Port is opened successfully and it sends data onto the port - but never gets anything back.
anyone got any ideas where to look next - I’m stumped.
Thanks in advance.
NFO 2016-06-15 19:34:01,134 : Serial_Port : Opening the serial port [COM port: /dev/ttyUSB0, Communication Layer: RXTX]…
INFO [Controller Definition File Watcher for Default Deployer]: Serial_Port : Opening the serial port [COM port: /dev/ttyUSB0, Communication Layer: RXTX]…
INFO [Controller Definition File Watcher for Default Deployer]: CommPortIdentifier:static initialization(), OS: Linux, arch: i386
INFO [Controller Definition File Watcher for Default Deployer]: Load the driver.
INFO [Controller Definition File Watcher for Default Deployer]: RXTXCommDriver : static initializer.
INFO [Controller Definition File Watcher for Default Deployer]: Load native library.
INFO [Controller Definition File Watcher for Default Deployer]: Load lib: NRJavaSerial
INFO [Controller Definition File Watcher for Default Deployer]: Loading from file: /native/linux/x86_32/libNRJavaSerial.so
INFO [Controller Definition File Watcher for Default Deployer]: Copy resources to: /share/CACHEDEV1_DATA/.qpkg/OpenRemote/temp/libNRJavaSerial_admin_0/libNRJavaSerial.so
INFO [Controller Definition File Watcher for Default Deployer]: Load resource from absolute path: /share/CACHEDEV1_DATA/.qpkg/OpenRemote/temp/libNRJavaSerial_admin_0/libNRJavaSerial.so
INFO [Controller Definition File Watcher for Default Deployer]: Loading from file: /native/linux/x86_32/libNRJavaSerial_legacy.so
INFO [Controller Definition File Watcher for Default Deployer]: Copy resources to: /share/CACHEDEV1_DATA/.qpkg/OpenRemote/temp/libNRJavaSerial_legacy_admin_0/libNRJavaSerial_legacy.so
INFO [Controller Definition File Watcher for Default Deployer]: Load resource from absolute path: /share/CACHEDEV1_DATA/.qpkg/OpenRemote/temp/libNRJavaSerial_legacy_admin_0/libNRJavaSerial_legacy.so
INFO [Controller Definition File Watcher for Default Deployer]: static CommPortIdentifier:getPortIdentifiers()
INFO [Controller Definition File Watcher for Default Deployer]: RXTXCommDriver:initialize(), osName: Linux
INFO [Controller Definition File Watcher for Default Deployer]: scanning device directory /dev/ for ports of type 1
INFO [Controller Definition File Watcher for Default Deployer]: RXTXCommDriver:initialize(), osName: Linux
INFO [Controller Definition File Watcher for Default Deployer]: scanning device directory /dev/ for ports of type 1
INFO [Controller Definition File Watcher for Default Deployer]: RXTXCommDriver:getCommPort(/dev/ttyUSB0,1)
INFO 2016-06-15 19:34:01,446 : Serial_Port : The serial port [COM port: /dev/ttyUSB0, Communication Layer: RXTX] has been successfully opened.
INFO [Controller Definition File Watcher for Default Deployer]: Serial_Port : The serial port [COM port: /dev/ttyUSB0, Communication Layer: RXTX] has been successfully opened.
DEBUG [Controller Definition File Watcher for Default Deployer]: Controller : Retrieving Z-Wave controller firmware version and library type…
DEBUG [Z-Wave ControllerAPI thread]: Controller_API : Dequeue (queue count=0) Z-Wave function call ‘ZW_Version’.
DEBUG [Controller Definition File Watcher for Default Deployer]: Controller_API : Enqueue (queue count=1) Z-Wave function call ‘ZW_Version’.
DEBUG [Z-Wave ControllerAPI thread]: TX_Session_Layer : Executing Z-Wave function call ‘ZW_Version’…
DEBUG [Z-Wave ControllerAPI thread]: TX_Frame_Layer : Send data frame [0x01, 0x03, 0x00, 0x15, 0xE9].
DEBUG [RXTX port reader]: RX_Serial_Port_RXTX : Data bytes read : [0x06]
DEBUG [ComPortAdapterRXThread]: RX_Frame_Layer : ACK -> Data frame [0x01, 0x03, 0x00, 0x15, 0xE9] transmission OK.
DEBUG [ComPortAdapterRXThread]: RX_Session_Layer : ACK -> Z-Wave function ‘ZW_Version’ has been successfully sent - waiting 5,000 [ms] for response frame.
DEBUG [RXTX port reader]: RX_Serial_Port_RXTX : Data bytes read : [0x01]
DEBUG [RXTX port reader]: RX_Serial_Port_RXTX : Data bytes read : [0x01]
WARN 2016-06-15 19:34:06,088 : RX_Frame_Layer : Failed to assemble frame because of invalid frame length 0x01, valid range : [0x03 <= length <= 0x58]
WARN [ComPortAdapterRXThread]: RX_Frame_Layer : Failed to assemble frame because of invalid frame length 0x01, valid range : [0x03 <= length <= 0x58]
WARN 2016-06-15 19:34:06,595 : RX_Session_Layer : Response timeout expired -> Failed to execute Z-Wave function ‘ZW_Version’.
WARN [Z-Wave request/response timeout timer thread]: RX_Session_Layer : Response timeout expired -> Failed to execute Z-Wave function ‘ZW_Version’.
ERROR 2016-06-15 19:34:06,760 : Controller : Failed to retrieve Z-Wave controller firmware version and library type because of communication error.
ERROR [pool-3-thread-2]: Controller : Failed to retrieve Z-Wave controller firmware version and library type because of communication error.
DEBUG [Controller Definition File Watcher for Default Deployer]: Controller : Retrieving serial API capabilities…
DEBUG [Z-Wave ControllerAPI thread]: Controller_API : Dequeue (queue count=0) Z-Wave function call ‘SERIAL_API_GetCapabilities’.
DEBUG [Z-Wave ControllerAPI thread]: TX_Session_Layer : Executing Z-Wave function call ‘SERIAL_API_GetCapabilities’…
DEBUG [Controller Definition File Watcher for Default Deployer]: Controller_API : Enqueue (queue count=0) Z-Wave function call ‘SERIAL_API_GetCapabilities’.
DEBUG [Z-Wave ControllerAPI thread]: TX_Frame_Layer : Send data frame [0x01, 0x03, 0x00, 0x07, 0xFB].
DEBUG [RXTX port reader]: RX_Serial_Port_RXTX : Data bytes read : [0x18]
DEBUG [ComPortAdapterRXThread]: RX_Frame_Layer : CAN -> Failed to send data frame [0x01, 0x03, 0x00, 0x07, 0xFB] because the Z-Wave firmware has an ACK expected instead of the sent frame
DEBUG [ComPortAdapterRXThread]: TX_Frame_Layer : CAN -> Wait 100 [ms] before next retransmission attempt.
DEBUG [Z-Wave FrameLayerStateManager timer thread]: TX_Frame_Layer : Retransmission attempt 1, data frame [0x01, 0x03, 0x00, 0x07, 0xFB]
WARN 2016-06-15 19:34:08,488 : TX_Frame_Layer : ACK timeout -> Failed to send data frame [0x01, 0x03, 0x00, 0x07, 0xFB] because did not receive ACK within expected time period (1600 [ms]).
WARN [Z-Wave FrameLayerStateManager timer thread]: TX_Frame_Layer : ACK timeout -> Failed to send data frame [0x01, 0x03, 0x00, 0x07, 0xFB] because did not receive ACK within expected time period (1600 [ms]).
DEBUG [Z-Wave FrameLayerStateManager timer thread]: TX_Frame_Layer : Wait 0 [ms] before next retransmission attempt.
DEBUG [Z-Wave FrameLayerStateManager timer thread]: TX_Frame_Layer : Retransmission attempt 2, data frame [0x01, 0x03, 0x00, 0x07, 0xFB]
DEBUG [RXTX port reader]: RX_Serial_Port_RXTX : Data bytes read : [0x06]
DEBUG [ComPortAdapterRXThread]: RX_Frame_Layer : ACK -> Data frame [0x01, 0x03, 0x00, 0x07, 0xFB] transmission OK.
DEBUG [ComPortAdapterRXThread]: RX_Session_Layer : ACK -> Z-Wave function ‘SERIAL_API_GetCapabilities’ has been successfully sent - waiting 5,000 [ms] for response frame.
DEBUG [RXTX port reader]: RX_Serial_Port_RXTX : Data bytes read : [0x01]
WARN 2016-06-15 19:34:13,505 : RX_Session_Layer : Response timeout expired -> Failed to execute Z-Wave function ‘SERIAL_API_GetCapabilities’.
WARN [Z-Wave request/response timeout timer thread]: RX_Session_Layer : Response timeout expired -> Failed to execute Z-Wave function ‘SERIAL_API_GetCapabilities’.
ERROR 2016-06-15 19:34:13,509 : Controller : Failed to retrieve serial API capabilities because of communication error.
ERROR [pool-3-thread-2]: Controller : Failed to retrieve serial API capabilities because of communication error.
DEBUG [Controller Definition File Watcher for Default Deployer]: Controller : Retrieving Z-Wave node list…
DEBUG [Controller Definition File Watcher for Default Deployer]: Controller_API : Enqueue (queue count=1) Z-Wave function call ‘SERIAL_API_GetInitData’.
DEBUG [Z-Wave ControllerAPI thread]: Controller_API : Dequeue (queue count=0) Z-Wave function call ‘SERIAL_API_GetInitData’.
DEBUG [Z-Wave ControllerAPI thread]: TX_Session_Layer : Executing Z-Wave function call ‘SERIAL_API_GetInitData’…
DEBUG [Z-Wave ControllerAPI thread]: TX_Frame_Layer : Send data frame [0x01, 0x03, 0x00, 0x02, 0xFE].
WARN 2016-06-15 19:34:15,126 : TX_Frame_Layer : ACK timeout -> Failed to send data frame [0x01, 0x03, 0x00, 0x02, 0xFE] because did not receive ACK within expected time period (1600 [ms]).
WARN [Z-Wave FrameLayerStateManager timer thread]: TX_Frame_Layer : ACK timeout -> Failed to send data frame [0x01, 0x03, 0x00, 0x02, 0xFE] because did not receive ACK within expected time period (1600 [ms]).
DEBUG [Z-Wave FrameLayerStateManager timer thread]: TX_Frame_Layer : Wait 0 [ms] before next retransmission attempt.
DEBUG [Z-Wave FrameLayerStateManager timer thread]: TX_Frame_Layer : Retransmission attempt 1, data frame [0x01, 0x03, 0x00, 0x02, 0xFE]
DEBUG [RXTX port reader]: RX_Serial_Port_RXTX : Data bytes read : [0x01]
WARN 2016-06-15 19:34:15,183 : RX_Frame_Layer : Failed to assemble frame because of invalid frame length 0x01, valid range : [0x03 <= length <= 0x58]
WARN [ComPortAdapterRXThread]: RX_Frame_Layer : Failed to assemble frame because of invalid frame length 0x01, valid range : [0x03 <= length <= 0x58]
DEBUG [RXTX port reader]: RX_Serial_Port_RXTX : Data bytes read : [0x01]
WARN 2016-06-15 19:34:16,732 : TX_Frame_Layer : ACK timeout -> Failed to send data frame [0x01, 0x03, 0x00, 0x02, 0xFE] because did not receive ACK within expected time period (1600 [ms]).
WARN [Z-Wave FrameLayerStateManager timer thread]: TX_Frame_Layer : ACK timeout -> Failed to send data frame [0x01, 0x03, 0x00, 0x02, 0xFE] because did not receive ACK within expected time period (1600 [ms]).
DEBUG [Z-Wave FrameLayerStateManager timer thread]: TX_Frame_Layer : Wait 0 [ms] before next retransmission attempt.
DEBUG [Z-Wave FrameLayerStateManager timer thread]: TX_Frame_Layer : Retransmission attempt 2, data frame [0x01, 0x03, 0x00, 0x02, 0xFE]
DEBUG [RXTX port reader]: RX_Serial_Port_RXTX : Data bytes read : [0x01]
WARN 2016-06-15 19:34:18,180 : RX_Frame_Layer : Failed to assemble frame because of invalid frame length 0x01, valid range : [0x03 <= length <= 0x58]
WARN [ComPortAdapterRXThread]: RX_Frame_Layer : Failed to assemble frame because of invalid frame length 0x01, valid range : [0x03 <= length <= 0x58]
WARN 2016-06-15 19:34:19,047 : TX_Frame_Layer : ACK timeout -> Failed to send data frame [0x01, 0x03, 0x00, 0x02, 0xFE] because did not receive ACK within expected time period (1600 [ms]).
WARN [Z-Wave FrameLayerStateManager timer thread]: TX_Frame_Layer : ACK timeout -> Failed to send data frame [0x01, 0x03, 0x00, 0x02, 0xFE] because did not receive ACK within expected time period (1600 [ms]).
DEBUG [Z-Wave FrameLayerStateManager timer thread]: TX_Frame_Layer : Wait 500 [ms] before next retransmission attempt.
DEBUG [Z-Wave FrameLayerStateManager timer thread]: TX_Frame_Layer : Retransmission attempt 3, data frame [0x01, 0x03, 0x00, 0x02, 0xFE]
DEBUG [RXTX port reader]: RX_Serial_Port_RXTX : Data bytes read : [0x18]
DEBUG [ComPortAdapterRXThread]: RX_Frame_Layer : CAN -> Failed to send data frame [0x01, 0x03, 0x00, 0x02, 0xFE] because the Z-Wave firmware has an ACK expected instead of the sent frame
WARN 2016-06-15 19:34:19,561 : TX_Session_Layer : Failed to send the Z-Wave function ‘SERIAL_API_GetInitData’ because no ACK was received.
WARN [ComPortAdapterRXThread]: TX_Session_Layer : Failed to send the Z-Wave function ‘SERIAL_API_GetInitData’ because no ACK was received.
ERROR 2016-06-15 19:34:19,565 : Controller : Failed to retrieve Z-Wave node list from controller because of communication error.
ERROR [pool-3-thread-2]: Controller : Failed to retrieve Z-Wave node list from controller because of communication error.
DEBUG [Controller Definition File Watcher for Default Deployer]: Controller : Configuring Z-Wave controller as SUC…
DEBUG [Controller Definition File Watcher for Default Deployer]: Controller_API : Enqueue (queue count=1) Z-Wave function call ‘ZW_SetSUCNodeID(NodeID=0, IsLocalNode=true, State=ENABLE_SUC, TxOption=LOW_POWER, Capability=ZW_SUC_FUNC_NODEID_SERVER)’.
DEBUG [Z-Wave ControllerAPI thread]: Controller_API : Dequeue (queue count=0) Z-Wave function call ‘ZW_SetSUCNodeID(NodeID=0, IsLocalNode=true, State=ENABLE_SUC, TxOption=LOW_POWER, Capability=ZW_SUC_FUNC_NODEID_SERVER)’.
DEBUG [Z-Wave ControllerAPI thread]: TX_Session_Layer : Executing Z-Wave function call ‘ZW_SetSUCNodeID(NodeID=0, IsLocalNode=true, State=ENABLE_SUC, TxOption=LOW_POWER, Capability=ZW_SUC_FUNC_NODEID_SERVER)’…
DEBUG [Z-Wave ControllerAPI thread]: TX_Frame_Layer : Send data frame [0x01, 0x08, 0x00, 0x54, 0x00, 0x01, 0x01, 0x01, 0x01, 0xA3].
DEBUG [RXTX port reader]: RX_Serial_Port_RXTX : Data bytes read : [0x18]
DEBUG [ComPortAdapterRXThread]: RX_Frame_Layer : CAN -> Failed to send data frame [0x01, 0x08, 0x00, 0x54, 0x00, 0x01, 0x01, 0x01, 0x01, 0xA3] because the Z-Wave firmware has an ACK expected instead of the sent frame
DEBUG [ComPortAdapterRXThread]: TX_Frame_Layer : CAN -> Wait 100 [ms] before next retransmission attempt.
DEBUG [RXTX port reader]: RX_Serial_Port_RXTX : Data bytes read : [0x01]
DEBUG [Z-Wave FrameLayerStateManager timer thread]: TX_Frame_Layer : Retransmission attempt 1, data frame [0x01, 0x08, 0x00, 0x54, 0x00, 0x01, 0x01, 0x01, 0x01, 0xA3]
DEBUG [RXTX port reader]: RX_Serial_Port_RXTX : Data bytes read : [0x18]
WARN 2016-06-15 19:34:21,331 : TX_Frame_Layer : ACK timeout -> Failed to send data frame [0x01, 0x08, 0x00, 0x54, 0x00, 0x01, 0x01, 0x01, 0x01, 0xA3] because did not receive ACK within expected time period (1600 [ms]).
WARN [Z-Wave FrameLayerStateManager timer thread]: TX_Frame_Layer : ACK timeout -> Failed to send data frame [0x01, 0x08, 0x00, 0x54, 0x00, 0x01, 0x01, 0x01, 0x01, 0xA3] because did not receive ACK within expected time period (1600 [ms]).
DEBUG [Z-Wave FrameLayerStateManager timer thread]: TX_Frame_Layer : Wait 0 [ms] before next retransmission attempt.
DEBUG [Z-Wave FrameLayerStateManager timer thread]: TX_Frame_Layer : Retransmission attempt 2, data frame [0x01, 0x08, 0x00, 0x54, 0x00, 0x01, 0x01, 0x01, 0x01, 0xA3]
DEBUG [RXTX port reader]: RX_Serial_Port_RXTX : Data bytes read : [0x01]
DEBUG [DiscoveredDevicesAnnouncement]: checking for discovered devices…
WARN 2016-06-15 19:34:22,938 : TX_Frame_Layer : ACK timeout -> Failed to send data frame [0x01, 0x08, 0x00, 0x54, 0x00, 0x01, 0x01, 0x01, 0x01, 0xA3] because did not receive ACK within expected time period (1600 [ms]).
WARN [Z-Wave FrameLayerStateManager timer thread]: TX_Frame_Layer : ACK timeout -> Failed to send data frame [0x01, 0x08, 0x00, 0x54, 0x00, 0x01, 0x01, 0x01, 0x01, 0xA3] because did not receive ACK within expected time period (1600 [ms]).
DEBUG [Z-Wave FrameLayerStateManager timer thread]: TX_Frame_Layer : Wait 500 [ms] before next retransmission attempt.
DEBUG [Z-Wave FrameLayerStateManager timer thread]: TX_Frame_Layer : Retransmission attempt 3, data frame [0x01, 0x08, 0x00, 0x54, 0x00, 0x01, 0x01, 0x01, 0x01, 0xA3]
DEBUG [RXTX port reader]: RX_Serial_Port_RXTX : Data bytes read : [0x18]
DEBUG [RXTX port reader]: RX_Serial_Port_RXTX : Data bytes read : [0x01]
WARN 2016-06-15 19:34:25,106 : TX_Frame_Layer : ACK timeout -> Failed to send data frame [0x01, 0x08, 0x00, 0x54, 0x00, 0x01, 0x01, 0x01, 0x01, 0xA3] because did not receive ACK within expected time period (1600 [ms]).
WARN [Z-Wave FrameLayerStateManager timer thread]: TX_Frame_Layer : ACK timeout -> Failed to send data frame [0x01, 0x08, 0x00, 0x54, 0x00, 0x01, 0x01, 0x01, 0x01, 0xA3] because did not receive ACK within expected time period (1600 [ms]).
WARN 2016-06-15 19:34:25,108 : TX_Session_Layer : Failed to send the Z-Wave function ‘ZW_SetSUCNodeID(NodeID=0, IsLocalNode=true, State=ENABLE_SUC, TxOption=LOW_POWER, Capability=ZW_SUC_FUNC_NODEID_SERVER)’ because no ACK was received.
WARN [Z-Wave FrameLayerStateManager timer thread]: TX_Session_Layer : Failed to send the Z-Wave function ‘ZW_SetSUCNodeID(NodeID=0, IsLocalNode=true, State=ENABLE_SUC, TxOption=LOW_POWER, Capability=ZW_SUC_FUNC_NODEID_SERVER)’ because no ACK was received.
ERROR 2016-06-15 19:34:25,115 : Controller : Failed to configure the Z-Wave controller as SUC.
ERROR [pool-3-thread-2]: Controller : Failed to configure the Z-Wave controller as SUC.