Sorry, but this isn’t correct - you’re not looking at the right code. This feature is only available in the development version and you’re not looking at that version. You need to use node_id.
Please see the testing that was performed previously here -:
Hi @chris i read the writeup and its well done. Followed it perfectly.
Unfortunately, “node_id” didnt work. nor did “nodeid”, “zwave_nodeid”, “zwave_node_id”. Also tried with and without quotes on the Number values (to make em strings and ints). Also tried upper and lower cases.
I’m not sure why this is to be honest. node_id is what the binding is looking for, and it certainly used to work. The binding doesn’t know (or care) if this is specified in a file, or through the UI - it looks for node_id in any case. Clearly from the binding perspective, this is working or the binding simply wouldn’t work for anyone.
I’ll see if I can do a quick test…
It seems to work fine for me.
I think this started after updating to snapshot 1212, and it doesn’t seem like anyone else is reporting it. I’ll try my archived version. Very strange!
There’s another thread on this over here -:
Seems to be reported in the dev version and the master version so I don’t think it’s the binding as such. It might be a problem with combining configuration sources as there are two sources in the ZWave binding - the xml files, and some internal definitions. I suspect this might be broken now as only the internal definitions appear to be displayed…
Sorry, I must updated the wrong one. Here is the correct file:
https://pastebin.com/fnNJe9Xg
Look for these errors:
com.thoughtworks.xstream.converters.ConversionException: The document is invalid, it contains further unsupported data
Thanks for the suggestion, but these aren’t files I created, the they are the ones in the binding jar, such as:
/ESH-INF/thing/fibaro_fgsd002_0_0.xml
/ESH-INF/thing/inovelli_nzw37_0_0.xml
Sorry, somehow quoted the wrong post, answer was meant for another user.
For what its worth, here are the debug logs where I get the message about missing NodeID.
http://faure.ca/~paul/missing_node_id.txt
There’s not a lot I can say really. I’ve no idea why the system isn’t passing the configuration into the binding, but as I said earlier, the binding doesn’t have any visibility of how you are configuring your system. Clearly the binding is working, or it wouldn’t work for anyone. There must be something else in the system that is preventing the configuration from being passed through, although it did work when I tested it here.
Chris
Sorry to bother you again. I added my debug log about 14 days ago. I haven’t seen a response.
Is there more that I can do to help you understand my issue. I am stuck and not sure I know what to do next.
Thanks.
Sorry - I missed that (I was unwell at the time 
). However I can’t really use short excerpts of the logs - I really need to see a debug log of the initialisation. I don’t care if it’s 10MB - it’s a lot more useful that 10 lines.
Thanks for getting back to me.
I have uploaded the entirety of my bedug session on the attached pdf.
I hope that’s OK.
B
debug zwave 020318.pdf (440.0 KB)
I’m not quite sure what the log is - I guess it’s been filtered on node 3? In any case, it’s not got the information that I need and it seems to be some sort of combination with the events log?
Best thing is to simply provide the log file - as it comes from OH - as a text file (ie not PDF as I then need to export it so the log reader can process it. Please don’t filter the log though.
Thanks.
Chris
Here is what my log:list shows me:
Logger │ Level
───────────────────────────────────────────────────┼──────
ROOT │ WARN
javax.jmdns │ ERROR
org.apache.karaf.jaas.modules.audit │ INFO
org.apache.karaf.kar.internal.KarServiceImpl │ ERROR
org.apache.karaf.shell.support │ OFF
org.eclipse.smarthome │ INFO
org.jupnp │ ERROR
org.openhab │ INFO
org.openhab.binding.zwave │ DEBUG
org.ops4j.pax.url.mvn.internal.AetherBasedResolver │ ERROR
org.ops4j.pax.web.pax-web-runtime │ OFF
smarthome.event │ INFO
smarthome.event.InboxUpdatedEvent │ ERROR
smarthome.event.ItemAddedEvent │ ERROR
smarthome.event.ItemRemovedEvent │ ERROR
smarthome.event.ItemStateEvent │ ERROR
smarthome.event.ThingAddedEvent │ ERROR
smarthome.event.ThingRemovedEvent │ ERROR
smarthome.event.ThingStatusInfoEvent │ ERROR
Should I have DEBUG at the root level rather than just for org.openhab.binding.zwave?
Bruno
No - just zwave is fine. The issue is not to filter the log which I think you have as I’ve not seen any received data. I think you probably filtered with a “grep node 3” or something like that? This is what removes the useful (and necessary) information.
Chris
Hope this works. I removed my lock and then added it back. It continues to not have security enabled. I then went into Karaf and instituted log:display. What I got is too long to enter in a post and I can’t attach a txt file so I limited the info to the end of the Checking list (the list went on for pages and was just an alphabetical list of every zwave device (I think). The end of the list is below. There was nothing before the list…
Thanks again.
B
10:12:14.690 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - Checking zwave:kichler_15dc200_00_000
10:12:14.691 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - Checking zwave:kwikset_914trl_00_000
10:12:14.696 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - Handler disposed. Unregistering listener.
10:12:14.717 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent UNREGISTERING - {org.eclipse.smarthome.config.core.status.ConfigStatusProvider}={service.id=373, service.bundleid=240, service.scope=singleton} - org.openhab.binding.zwave
10:12:14.720 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'zwave:device:654457c4:node2' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to UNINITIALIZED
10:12:14.727 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'zwave:device:654457c4:node2' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
10:12:14.742 [DEBUG] [org.openhab.binding.zwave ] - ServiceEvent REGISTERED - {org.eclipse.smarthome.config.core.status.ConfigStatusProvider}={service.id=374, service.bundleid=240, service.scope=singleton} - org.openhab.binding.zwave
10:12:14.754 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - Initializing ZWave thing handler zwave:device:654457c4:node2.
10:12:14.756 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'zwave:device:654457c4:node2' changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING
10:12:14.760 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'zwave:device:654457c4:node2' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline
10:12:14.762 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 2: Controller status changed to ONLINE.
10:12:14.764 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 2: Controller is ONLINE. Starting device initialisation.
10:12:14.770 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'zwave:device:654457c4:node2' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
10:12:14.790 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating node properties.
10:12:14.792 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'zwave:device:654457c4:node2' has been updated.
10:12:14.810 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'zwave:device:654457c4:node2' has been updated.
10:12:14.811 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating node properties. MAN=144
10:12:14.812 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 2: Updating node properties. MAN=144. SET. Was 144
10:12:14.813 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 2: Properties synchronised
10:12:14.830 [DEBUG] [ave.internal.protocol.ZWaveController] - Event listener added.
10:12:14.831 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'zwave:device:654457c4:node2' has been updated.
10:12:14.831 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising Thing Node...
10:12:14.833 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising cmd channel zwave:device:654457c4:node2:lock_door for OnOffType
10:12:14.834 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising state channel zwave:device:654457c4:node2:lock_door for OnOffType
10:12:14.836 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising cmd channel zwave:device:654457c4:node2:alarm_number for DecimalType
10:12:14.837 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising state channel zwave:device:654457c4:node2:alarm_number for DecimalType
10:12:14.838 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising cmd channel zwave:device:654457c4:node2:alarm_raw for StringType
10:12:14.839 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising state channel zwave:device:654457c4:node2:alarm_raw for StringType
10:12:14.840 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising cmd channel zwave:device:654457c4:node2:battery-level for PercentType
10:12:14.841 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 2: Initialising state channel zwave:device:654457c4:node2:battery-level for PercentType
10:12:14.842 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 2: Polling intialised at 1800 seconds - start in 1584000 milliseconds.
10:12:14.843 [DEBUG] [nding.zwave.handler.ZWaveThingHandler] - NODE 2: Device initialisation complete.
10:12:14.847 [INFO ] [smarthome.event.ThingUpdatedEvent ] - Thing 'zwave:device:654457c4:node2' has been updated.
10:12:17.286 [ERROR] [home.binding.wemo.handler.WemoHandler] - Failed to get actual state for device 'wemo:lightswitch:Lightswitch-1_0-221628K1300679': Could not call WeMo
10:12:17.834 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'hue:0210:00178846e016:16' changed from ONLINE to OFFLINE: Hue bridge reports light as not reachable.
10:12:33.197 [DEBUG] [nal.protocol.ZWaveInclusionController] - ZWave controller stopping inclusion at IncludeSent
10:12:33.199 [DEBUG] [col.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.
10:12:33.200 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 255: Adding to priority controller queue
10:12:33.201 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 255: Added to queue - size 1
10:12:33.202 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start
10:12:33.203 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - getTransactionToSend 6
10:12:33.204 [DEBUG] [zwave.internal.protocol.SerialMessage] - Assembled message buffer = 01 06 00 4A 05 01 46 F1
10:12:33.206 [DEBUG] [ding.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 06 00 4A 05 01 46 F1
10:12:33.207 [ERROR] [ding.zwave.handler.ZWaveSerialHandler] - Got I/O exception Input/output error in writeArray during sending. exiting thread.
10:12:33.208 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 3135: Transaction Start type AddNodeToNetwork
10:12:33.209 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: TID 3135: [WAIT_REQUEST] requiresResponse=true callback: 70
10:12:33.210 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd class: null
10:12:33.211 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage started: expected cmd: null
10:12:33.212 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage Transactions outstanding: 1
10:12:33.214 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Start transaction timer to Mon Feb 19 10:12:38 EST 2018 - 5000ms
10:12:33.215 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage lastTransaction: TID 3135: [WAIT_REQUEST] requiresResponse=true callback: 70
10:12:33.216 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - STOP transaction timer
10:12:33.218 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Start transaction timer to Mon Feb 19 10:12:38 EST 2018 - 4996ms
10:12:38.213 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - XXXXXXXXX Timeout.......... 1 outstanding transactions
10:12:38.216 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - NODE 255: TID 3135: Timeout at state WAIT_REQUEST. 3 retries remaining.
10:12:38.217 [DEBUG] [nsactionManager$ZWaveTransactionTimer] - TID 3135: Transaction is current transaction, so clearing!!!!!
10:12:38.218 [DEBUG] [ve.internal.protocol.ZWaveTransaction] - TID 3135: Transaction CANCELLED
10:12:38.219 [DEBUG] [ave.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
10:12:38.221 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - NODE 255: notifyTransactionResponse TID:3135 CANCELLED
10:12:38.223 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage 0 out at start
10:12:38.230 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction from controllerQueue
10:12:38.231 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - Transaction SendNextMessage nothing
10:12:38.233 [DEBUG] [rnal.protocol.ZWaveTransactionManager] - STOP transaction timer
10:12:47.309 [ERROR] [home.binding.wemo.handler.WemoHandler] - Failed to get actual state for device 'wemo:lightswitch:Lightswitch-1_0-221628K130068A': Could not call WeMo
10:12:48.224 [DEBUG] [nal.protocol.ZWaveInclusionController] - Inclusion timer at IncludeDone
10:12:58.817 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'hue:0210:00178846e016:14' changed from OFFLINE: Hue bridge reports light as not reachable. to ONLINE
10:13:09.070 [INFO ] [ome.event.ThingStatusInfoChangedEvent] - 'hue:0210:00178846e016:15' changed from OFFLINE: Hue bridge reports light as not reachable. to ONLINE
10:13:19.521 [ERROR] [home.binding.wemo.handler.WemoHandler] - Failed to get actual state for device 'wemo:lightswitch:Lightswitch-1_0-221612K1300F95': Could not call WeMoSorry, but I really need the full log from the point the inclusion starts (ie the discovery command is sent from the UI), up till when it fails. Can you email it to me at chris -at- cd-jackson.com?
Sure. Can you tell me how I get more of the log? As I noted, the log:display command did not seem to start early enough.
B
I have the same problem my locks dont include secure anymore i will post a log in a moment
here is the log from initializing inclusion to the end, the lock i added is node 5, node 3 is a lock i added before both Schlage
Not sure if the XML folder is of any interest…
node 5 xml:
<node>
<homeId>0x2</homeId>
<nodeId>5</nodeId>
<version>4</version>
<manufacturer>0x3b</manufacturer>
<deviceId>0x5044</deviceId>
<deviceType>0x6349</deviceType>
<listening>false</listening>
<frequentlyListening>true</frequentlyListening>
<routing>true</routing>
<security>false</security>
<beaming>true</beaming>
<maxBaudRate>40000</maxBaudRate>
<sleepDelay>1000</sleepDelay>
<associationGroups class="concurrent-hash-map"/>
<endpoints class="concurrent-hash-map">
<entry>
<int>0</int>
<endPoint>
<deviceClass>
<basicDeviceClass>BASIC_TYPE_ROUTING_SLAVE</basicDeviceClass>
<genericDeviceClass>GENERIC_TYPE_ENTRY_CONTROL</genericDeviceClass>
<specificDeviceClass>SPECIFIC_TYPE_SECURE_KEYPAD_DOOR_LOCK</specificDeviceClass>
</deviceClass>
<endpointId>0</endpointId>
<secureCommandClasses/>
<supportedCommandClasses class="concurrent-hash-map">
<entry>
<commandClass>COMMAND_CLASS_APPLICATION_STATUS</commandClass>
<COMMAND__CLASS__APPLICATION__STATUS>
<version>1</version>
<instances>1</instances>
<versionSupported>1</versionSupported>
</COMMAND__CLASS__APPLICATION__STATUS>
</entry>
<entry>
<commandClass>COMMAND_CLASS_FIRMWARE_UPDATE_MD</commandClass>
<COMMAND__CLASS__FIRMWARE__UPDATE__MD>
<version>1</version>
<instances>1</instances>
<versionSupported>2</versionSupported>
</COMMAND__CLASS__FIRMWARE__UPDATE__MD>
</entry>
<entry>
<commandClass>COMMAND_CLASS_NO_OPERATION</commandClass>
<COMMAND__CLASS__NO__OPERATION>
<version>1</version>
<instances>1</instances>
<versionSupported>1</versionSupported>
</COMMAND__CLASS__NO__OPERATION>
</entry>
<entry>
<commandClass>COMMAND_CLASS_VERSION</commandClass>
<COMMAND__CLASS__VERSION>
<version>1</version>
<instances>1</instances>
<versionSupported>1</versionSupported>
<libraryType>LIB_SLAVE_ROUTING</libraryType>
<protocolVersion>3.42</protocolVersion>
<applicationVersion>113.22</applicationVersion>
</COMMAND__CLASS__VERSION>
</entry>
<entry>
<commandClass>COMMAND_CLASS_BASIC</commandClass>
<COMMAND__CLASS__BASIC>
<version>1</version>
<instances>1</instances>
<versionSupported>1</versionSupported>
<isGetSupported>true</isGetSupported>
</COMMAND__CLASS__BASIC>
</entry>
<entry>
<commandClass>COMMAND_CLASS_MANUFACTURER_SPECIFIC</commandClass>
<COMMAND__CLASS__MANUFACTURER__SPECIFIC>
<version>1</version>
<instances>1</instances>
<versionSupported>1</versionSupported>
<initSerialNumber>false</initSerialNumber>
<deviceManufacturer>59</deviceManufacturer>
<deviceType>25417</deviceType>
<deviceId>20548</deviceId>
</COMMAND__CLASS__MANUFACTURER__SPECIFIC>
</entry>
<entry>
<commandClass>COMMAND_CLASS_SECURITY</commandClass>
<COMMAND__CLASS__SECURITY>
<version>1</version>
<instances>1</instances>
<versionSupported>1</versionSupported>
</COMMAND__CLASS__SECURITY>
</entry>
</supportedCommandClasses>
</endPoint>
</entry>
</endpoints>
<nodeNeighbors>
<int>1</int>
<int>2</int>
<int>3</int>
<int>4</int>
</nodeNeighbors>
<lastReceived>2018-02-19 16:50:37.145 UTC</lastReceived>
</node>