Request for help with: Zwave.log shows node but dev.log state node is not known

144 views
Skip to first unread message

Jeremy Niedens

unread,
Dec 10, 2016, 3:10:44 PM12/10/16
to OpenRemote
All, having trouble getting Zwave going with OR 2.6 Beta (2.6Beta with ZWave jar 3.1.2-Beta1, Windows 7, Java jdk1.8.0_111)


Zwave reads the nodes and seems to be communicating but I get "Send Request Error Command not found." when I activate the switches from the panels and "N/A" show for the sensors.  

The Zwave.log shows the node (see #4 below), but the dev.log says "is not known by the Z-Wave controller"

TCP/IP Protocols work fine so I assume it's Zwave specific.


Zwave Log:
[INFO 2016-12-10 13:48:07,496 (Z-Wave): 

--------------------------------------------------------------------

  OpenRemote Z-Wave protocol version : '3.1.2-Beta1'

--------------------------------------------------------------------

DEBUG 2016-12-10 13:48:08,120 (Z-Wave): Connection_Manager          : Adding shutdown hook to manage unclosed Z-Wave connections in case of controller exit.
INFO 2016-12-10 13:48:08,151 (Z-Wave):  Serial_Port                 : Opening the serial port [COM port: COM4, Communication Layer: RXTX]...
DEBUG 2016-12-10 13:48:09,009 (Z-Wave): Command_Builder             : Building Z-Wave command
DEBUG 2016-12-10 13:48:09,009 (Z-Wave): Command_Builder             : Z-Wave command: nodeId = '10', endPoint = '1'
DEBUG 2016-12-10 13:48:09,009 (Z-Wave): Command_Builder             : Z-Wave command: command = LUMINANCE_SCALE_LUX
DEBUG 2016-12-10 13:48:09,024 (Z-Wave): Command_Builder             : Building Z-Wave command
DEBUG 2016-12-10 13:48:09,024 (Z-Wave): Command_Builder             : Z-Wave command: nodeId = '10', endPoint = '1'
DEBUG 2016-12-10 13:48:09,024 (Z-Wave): Command_Builder             : Z-Wave command: command = AIR_TEMPERATURE_SCALE_FAHRENHEIT
DEBUG 2016-12-10 13:48:09,024 (Z-Wave): Command_Builder             : Building Z-Wave command
DEBUG 2016-12-10 13:48:09,040 (Z-Wave): Command_Builder             : Z-Wave command: nodeId = '22', endPoint = '1'
DEBUG 2016-12-10 13:48:09,040 (Z-Wave): Command_Builder             : Z-Wave command: command = status
DEBUG 2016-12-10 13:48:09,071 (Z-Wave): Command_Builder             : Building Z-Wave command
DEBUG 2016-12-10 13:48:09,071 (Z-Wave): Command_Builder             : Z-Wave command: nodeId = '3', endPoint = '1'
DEBUG 2016-12-10 13:48:09,071 (Z-Wave): Command_Builder             : Z-Wave command: command = status
DEBUG 2016-12-10 13:48:09,071 (Z-Wave): Command_Builder             : Building Z-Wave command
DEBUG 2016-12-10 13:48:09,071 (Z-Wave): Command_Builder             : Z-Wave command: nodeId = '13', endPoint = '1'
DEBUG 2016-12-10 13:48:09,071 (Z-Wave): Command_Builder             : Z-Wave command: command = status
DEBUG 2016-12-10 13:48:09,087 (Z-Wave): Command_Builder             : Building Z-Wave command
DEBUG 2016-12-10 13:48:09,087 (Z-Wave): Command_Builder             : Z-Wave command: nodeId = '11', endPoint = '1'
DEBUG 2016-12-10 13:48:09,087 (Z-Wave): Command_Builder             : Z-Wave command: command = status
DEBUG 2016-12-10 13:48:09,118 (Z-Wave): Command_Builder             : Building Z-Wave command
DEBUG 2016-12-10 13:48:09,118 (Z-Wave): Command_Builder             : Z-Wave command: nodeId = '15', endPoint = '1'
DEBUG 2016-12-10 13:48:09,118 (Z-Wave): Command_Builder             : Z-Wave command: command = AIR_TEMPERATURE_SCALE_FAHRENHEIT
DEBUG 2016-12-10 13:48:09,118 (Z-Wave): Command_Builder             : Building Z-Wave command
DEBUG 2016-12-10 13:48:09,118 (Z-Wave): Command_Builder             : Z-Wave command: nodeId = '15', endPoint = '1'
DEBUG 2016-12-10 13:48:09,118 (Z-Wave): Command_Builder             : Z-Wave command: command = LUMINANCE_SCALE_LUX
DEBUG 2016-12-10 13:48:09,149 (Z-Wave): Command_Builder             : Building Z-Wave command
DEBUG 2016-12-10 13:48:09,149 (Z-Wave): Command_Builder             : Z-Wave command: nodeId = '14', endPoint = '1'
DEBUG 2016-12-10 13:48:09,149 (Z-Wave): Command_Builder             : Z-Wave command: command = status
DEBUG 2016-12-10 13:48:09,274 (Z-Wave): Command_Builder             : Building Z-Wave command
DEBUG 2016-12-10 13:48:09,274 (Z-Wave): Command_Builder             : Z-Wave command: nodeId = '19', endPoint = '1'
DEBUG 2016-12-10 13:48:09,274 (Z-Wave): Command_Builder             : Z-Wave command: command = status
DEBUG 2016-12-10 13:48:09,290 (Z-Wave): Command_Builder             : Building Z-Wave command
DEBUG 2016-12-10 13:48:09,290 (Z-Wave): Command_Builder             : Z-Wave command: nodeId = '20', endPoint = '1'
DEBUG 2016-12-10 13:48:09,290 (Z-Wave): Command_Builder             : Z-Wave command: command = status
DEBUG 2016-12-10 13:48:09,290 (Z-Wave): Command_Builder             : Building Z-Wave command
DEBUG 2016-12-10 13:48:09,290 (Z-Wave): Command_Builder             : Z-Wave command: nodeId = '21', endPoint = '1'
DEBUG 2016-12-10 13:48:09,290 (Z-Wave): Command_Builder             : Z-Wave command: command = status
DEBUG 2016-12-10 13:48:09,305 (Z-Wave): Command_Builder             : Building Z-Wave command
DEBUG 2016-12-10 13:48:09,305 (Z-Wave): Command_Builder             : Z-Wave command: nodeId = '20', endPoint = '1'
DEBUG 2016-12-10 13:48:09,305 (Z-Wave): Command_Builder             : Z-Wave command: command = BATTERY
DEBUG 2016-12-10 13:48:09,305 (Z-Wave): Command_Builder             : Building Z-Wave command
DEBUG 2016-12-10 13:48:09,305 (Z-Wave): Command_Builder             : Z-Wave command: nodeId = '21', endPoint = '1'
DEBUG 2016-12-10 13:48:09,305 (Z-Wave): Command_Builder             : Z-Wave command: command = BATTERY
DEBUG 2016-12-10 13:48:09,305 (Z-Wave): Command_Builder             : Building Z-Wave command
DEBUG 2016-12-10 13:48:09,305 (Z-Wave): Command_Builder             : Z-Wave command: nodeId = '19', endPoint = '1'
DEBUG 2016-12-10 13:48:09,305 (Z-Wave): Command_Builder             : Z-Wave command: command = BATTERY
DEBUG 2016-12-10 13:48:09,321 (Z-Wave): Command_Builder             : Building Z-Wave command
DEBUG 2016-12-10 13:48:09,321 (Z-Wave): Command_Builder             : Z-Wave command: nodeId = '60', endPoint = '1'
DEBUG 2016-12-10 13:48:09,321 (Z-Wave): Command_Builder             : Z-Wave command: command = status
DEBUG 2016-12-10 13:48:09,336 (Z-Wave): Command_Builder             : Building Z-Wave command
DEBUG 2016-12-10 13:48:09,336 (Z-Wave): Command_Builder             : Z-Wave command: nodeId = '220', endPoint = '1'
DEBUG 2016-12-10 13:48:09,336 (Z-Wave): Command_Builder             : Z-Wave command: command = status
DEBUG 2016-12-10 13:48:09,383 (Z-Wave): Command_Builder             : Building Z-Wave command
DEBUG 2016-12-10 13:48:09,383 (Z-Wave): Command_Builder             : Z-Wave command: nodeId = '2', endPoint = '1'
DEBUG 2016-12-10 13:48:09,383 (Z-Wave): Command_Builder             : Z-Wave command: command = status
DEBUG 2016-12-10 13:48:09,399 (Z-Wave): Command_Builder             : Building Z-Wave command
DEBUG 2016-12-10 13:48:09,399 (Z-Wave): Command_Builder             : Z-Wave command: nodeId = '4', endPoint = '1'
DEBUG 2016-12-10 13:48:09,399 (Z-Wave): Command_Builder             : Z-Wave command: command = status
DEBUG 2016-12-10 13:48:28,993 (Z-Wave): Command_Builder             : Building Z-Wave command
DEBUG 2016-12-10 13:48:28,993 (Z-Wave): Command_Builder             : Z-Wave command: nodeId = '4', endPoint = '1'
DEBUG 2016-12-10 13:48:28,993 (Z-Wave): Command_Builder             : Z-Wave command: command = on
DEBUG 2016-12-10 13:48:53,609 (Z-Wave): Command_Builder             : Building Z-Wave command
DEBUG 2016-12-10 13:48:53,609 (Z-Wave): Command_Builder             : Z-Wave command: nodeId = '4', endPoint = '1'
DEBUG 2016-12-10 13:48:53,609 (Z-Wave): Command_Builder             : Z-Wave command: command = on]

Dev.log:

[2016-12-10 14:07:17,341 ERROR [HTTP-Thread-3]: Error executing command '/1210/on' : The node '4' is not known by the Z-Wave controller
org.openremote.controller.exception.NoSuchCommandException: The node '4' is not known by the Z-Wave controller
at org.openremote.controller.protocol.zwave.ZWaveCommandBuilder.build(ZWaveCommandBuilder.java:212)
at org.openremote.controller.command.CommandFactory.getCommand(CommandFactory.java:164)
at org.openremote.controller.component.control.switchtoggle.SwitchBuilder.build(SwitchBuilder.java:105)
at org.openremote.controller.component.control.switchtoggle.SwitchBuilder.build(SwitchBuilder.java:47)
at org.openremote.controller.component.ComponentFactory.getComponent(ComponentFactory.java:56)
at org.openremote.controller.service.impl.ControlCommandServiceImpl.getControl(ControlCommandServiceImpl.java:155)
at org.openremote.controller.service.impl.ControlCommandServiceImpl.trigger(ControlCommandServiceImpl.java:79)
at org.openremote.controller.rest.ControlCommandRESTServlet.handleRequest(ControlCommandRESTServlet.java:77)
at org.openremote.controller.rest.RESTAPI.doPost(RESTAPI.java:174)
at org.openremote.controller.rest.RESTAPI.doGet(RESTAPI.java:127)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:617)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.openremote.controller.rest.support.json.JSONCallbackFilter.doFilter(JSONCallbackFilter.java:63)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:96)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:75)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:128)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:286)
at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:845)
at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:583)
at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:354)
at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Unknown Source)]

Rainer Hitz

unread,
Dec 11, 2016, 2:44:01 AM12/11/16
to OpenRemote
The beginning of the Z-Wave log  file '<OpenRemote-Controller>/logs/zwave/zwave.log' should look like the following :

--------------------------------------------------------------------


 
OpenRemote Z-Wave protocol version : '3.1.2-Beta1'


--------------------------------------------------------------------



DEBUG
2016-12-11 08:35:15,273 (Z-Wave): Connection_Manager          : Adding shutdown hook to manage unclosed Z-Wave connections in case of controller exit.
INFO
2016-12-11 08:35:15,310 (Z-Wave):  Serial_Port                 : Opening the serial port [COM port: /dev/cu.usbmodem1421, Communication Layer: RXTX]...
INFO
2016-12-11 08:35:15,363 (Z-Wave):  Serial_Port                 : The serial port [COM port: /dev/cu.usbmodem1421, Communication Layer: RXTX] has been successfully opened.
...
...

Do you see the log message that the serial port has been successfully opened ?

Jeremy Niedens

unread,
Dec 11, 2016, 7:57:32 AM12/11/16
to OpenRemote
Looks like my log is missing the opening acknowledgement (see below).

OZWForm can see all of my nodes without OR running so not sure what to try next.

Thanks in advance for your help.

[INFO 2016-12-10 13:48:07,496 (Z-Wave):

--------------------------------------------------------------------

OpenRemote Z-Wave protocol version : '3.1.2-Beta1'

--------------------------------------------------------------------

DEBUG 2016-12-10 13:48:08,120 (Z-Wave): Connection_Manager : Adding shutdown hook to manage unclosed Z-Wave connections in case of controller exit.
INFO 2016-12-10 13:48:08,151 (Z-Wave): Serial_Port : Opening the serial port [COM port: COM4, Communication Layer: RXTX]...]

Michał J

unread,
Dec 12, 2016, 6:52:54 AM12/12/16
to OpenRemote
Do you run OR as regular user or root?
I have similar errors when run OR as regular user. Please use try with sudo.

Jeremy Niedens

unread,
Dec 12, 2016, 8:43:25 PM12/12/16
to OpenRemote
Its a Windows machine but I will make sure I am running OR as an administrator and report back.

My old version of OR with java 1.6 launched from the same batch file (as admin) and zwave works just fine.

Rainer Hitz

unread,
Dec 13, 2016, 12:13:47 AM12/13/16
to OpenRemote
Which version of Windows (7, 8, 10 - 32/64 bit) do you have ?


Do you see an error in the log like the following ?

--------------------------------------------------------------------


 
OpenRemote Z-Wave protocol version : '3.1.2-Beta1'


--------------------------------------------------------------------



DEBUG
2016-12-13 06:08:33,674 (Z-Wave): Connection_Manager          : Adding shutdown hook to manage unclosed Z-Wave connections in case of controller exit.
INFO
2016-12-13 06:08:33,714 (Z-Wave):  Serial_Port                 : Opening the serial port [COM port: /dev/cu.usbmodem1421, Communication Layer: RXTX]...
ERROR
2016-12-13 06:08:33,749 (Z-Wave): Serial_Port_RXTX            : Failed to configure the serial port [Name: '/dev/cu.usbmodem1421', Communication Layer: RXTX] because it does not exist.
ERROR
2016-12-13 06:08:33,749 (Z-Wave): Serial_Port                 : Failed to open the serial port [COM port: /dev/cu.usbmodem1421, Communication Layer: RXTX].

Rainer Hitz

unread,
Dec 13, 2016, 3:17:21 AM12/13/16
to openremot...@googlegroups.com
I've executed the following Windows tests and it worked as expected.

Windows 10 32 bit
Aeon Labs Z-Stick Gen5

Windows 10 64 bit
Aeon Labs Z-Stick Gen5

Windows 10 64 bit
Aeon Labs Z-Stick Gen5


Unfortunately I do not have a Windows 7 system at hand - I'll let you know when I've made the Windows 7 test.

Jeremy Niedens

unread,
Dec 15, 2016, 4:33:12 PM12/15/16
to OpenRemote
Win 7 64bit.  Running as administrator and no confirmation of the com port opening (log below):

[INFO 2016-12-15 15:33:18,829 (Z-Wave): 

--------------------------------------------------------------------

  OpenRemote Z-Wave protocol version : '3.1.2-Beta1'

--------------------------------------------------------------------

DEBUG 2016-12-15 15:33:19,506 (Z-Wave): Connection_Manager          : Adding shutdown hook to manage unclosed Z-Wave connections in case of controller exit.
INFO 2016-12-15 15:33:19,548 (Z-Wave):  Serial_Port                 : Opening the serial port [COM port: COM4, Communication Layer: RXTX]...
DEBUG 2016-12-15 15:33:19,626 (Z-Wave): Command_Builder             : Building Z-Wave command
DEBUG 2016-12-15 15:33:19,626 (Z-Wave): Command_Builder             : Z-Wave command: nodeId = '10', endPoint = '1'
DEBUG 2016-12-15 15:33:19,626 (Z-Wave): Command_Builder             : Z-Wave command: command = LUMINANCE_SCALE_LUX]

Jeremy Niedens

unread,
Dec 15, 2016, 4:52:10 PM12/15/16
to OpenRemote
Just tried Java 1.6, 1.7, and 1.8 with controller V2.6 beta and non of them show the com port opening confirmation (ran as administrator).  Not sure what to try next.


On Tuesday, December 13, 2016 at 2:17:21 AM UTC-6, Rainer Hitz wrote:

Clyde Bell

unread,
Jan 6, 2017, 6:38:49 PM1/6/17
to OpenRemote
Hi, I'm having issues running the same builds on Windows 8

Windows 8 64 bit
The node is successfully added but it never seems to finish initialization / inclusion and never creates the nodexx.xml file. Get java.exceptions which look to be related straight after it receives node info. Any ideas would be appreciated. I've tried several different machines / java versions.

ERROR [HTTP-Thread-4]: Failed to execute REST API call 'http://192.168.0.8:8688/
controller/rest/commands' : Invalid URL format -- expected format '/rest/devices
/{device_name}/commands?name={command_name}', got '/rest/commandsnull'.
Jan 06, 2017 11:29:51 PM org.restlet.engine.connector.HttpClientHelper start
INFO: Starting the internal HTTP client
INFO 2017-01-06 23:30:02,804 : Inclusion_Manager           : Node '19' : Z-Wave
node has been successfully added to the *SECURE* Z-Wave network.
Jan 06, 2017 11:30:02 PM org.restlet.engine.connector.HttpClientHelper stop
INFO: Stopping the internal HTTP client
Jan 06, 2017 11:30:02 PM org.restlet.engine.connector.HttpClientHelper stop
INFO: Stopping the internal HTTP client
Jan 06, 2017 11:30:02 PM org.restlet.engine.connector.HttpClientHelper stop
INFO: Stopping the internal HTTP client
Jan 06, 2017 11:30:02 PM org.restlet.engine.connector.HttpClientHelper stop
INFO: Stopping the internal HTTP client
INFO 2017-01-06 23:30:02,851 :  Controller                  : Z-Wave node info (
ID=19) : [[Device Classes : 'BASIC_TYPE_ROUTING_SLAVE','GENERIC_TYPE_SWITCH_MULT
ILEVEL','SPECIFIC_TYPE_POWER_SWITCH_MULTILEVEL'],[Capabilities : 'NODEINFO_CAPAB
ILITY_ROUTING','NODEINFO_CAPABILITY_LISTENING'],[Security : 'NODEINFO_SECURITY_O
PTIONAL_FUNC_SUPPORT']].
Exception in thread "pool-1-thread-5" java.lang.ClassCastException: org.openremo
te.protocol.zwave.model.commandclasses.CCMultiChannelV2FuncDecorator cannot be c
ast to org.openremote.protocol.zwave.port.function.ZWSendDataFunc
        at org.openremote.protocol.zwave.model.commandclasses.CCSecurityFuncDeco
rator.<init>(CCSecurityFuncDecorator.java:144)
        at org.openremote.protocol.zwave.model.commandclasses.Context.decorateFu
nction(Context.java:322)
        at org.openremote.protocol.zwave.model.commandclasses.Context.decorateFu
nction(Context.java:294)
        at org.openremote.protocol.zwave.model.commandclasses.CCSecurity.enqueue
GetSupportedFunc(CCSecurity.java:1752)
        at org.openremote.protocol.zwave.model.ZWNodeInitializer.nextSecureEndPo
int(ZWNodeInitializer.java:1573)
        at org.openremote.protocol.zwave.model.ZWNodeInitializer.access$5000(ZWN
odeInitializer.java:36)
        at org.openremote.protocol.zwave.model.ZWNodeInitializer$13.ccMultiChann
elV2GetCapabilityCallback(ZWNodeInitializer.java:1512)
        at org.openremote.protocol.zwave.model.commandclasses.CCMultiChannelV2$G
etEndPointCapabilityFunc$1.run(CCMultiChannelV2.java:1152)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.
java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor
.java:617)
        at java.lang.Thread.run(Thread.java:745)
Jan 06, 2017 11:30:23 PM org.restlet.engine.connector.HttpClientHelper start
INFO: Starting the internal HTTP client
Jan 06, 2017 11:30:56 PM org.restlet.engine.connector.HttpClientHelper start
INFO: Starting the internal HTTP client

Rainer Hitz

unread,
Jan 9, 2017, 11:39:09 AM1/9/17
to OpenRemote
There seems to be a bug with security enabled multi channel devices - presumably this combination (security/multi channel) hasn't been tested so far.

What type of device do you have ? 

Clyde Bell

unread,
Jan 14, 2017, 10:54:16 AM1/14/17
to OpenRemote
I have a Fibaro FGD-212 (dimmer 2)

Rainer Hitz

unread,
Jan 16, 2017, 2:36:52 AM1/16/17
to OpenRemote
I'm currently working on a bugfix and let let you know when a new version is available.
Reply all
Reply to author
Forward
0 new messages