Hello All,
I am trying out the new version of OH2 and I am trying to include a secure door lock but I seem to be getting an error and the lock will not include or operate. The lock dose include correctly and function in version 2.2.
Here is the log file.
==> /var/log/openhab2/openhab.log <==
2018-06-20 18:16:05.568 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port ‘/dev/ttyACM1’
2018-06-20 18:16:05.615 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Serial port is initialized
2018-06-20 18:16:05.615 [INFO ] [mmandclass.ZWaveSecurityCommandClass] - Update networkKey
2018-06-20 18:16:05.616 [INFO ] [ve.internal.protocol.ZWaveController] - Starting ZWave controller
2018-06-20 18:16:05.616 [INFO ] [ve.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false.
==> /var/log/openhab2/events.log <==
2018-06-20 18:16:08.622 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_ack changed from NULL to 1
2018-06-20 18:16:08.624 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from NULL to 1
2018-06-20 18:16:08.632 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_ack changed from 1 to 2
2018-06-20 18:16:08.634 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from 1 to 2
2018-06-20 18:16:08.647 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_ack changed from 2 to 3
2018-06-20 18:16:08.647 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from 2 to 3
2018-06-20 18:16:08.655 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_ack changed from 3 to 4
2018-06-20 18:16:08.658 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from 3 to 4
2018-06-20 18:16:08.663 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_ack changed from 4 to 5
2018-06-20 18:16:08.666 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from 4 to 5
2018-06-20 18:16:08.671 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_ack changed from 5 to 6
2018-06-20 18:16:08.765 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from 5 to 6
==> /var/log/openhab2/openhab.log <==
2018-06-20 18:16:08.771 [INFO ] [age.SerialApiGetInitDataMessageClass] - NODE 1: Node found
2018-06-20 18:16:08.772 [INFO ] [age.SerialApiGetInitDataMessageClass] - ZWave Controller using Controller API
2018-06-20 18:16:08.772 [INFO ] [age.SerialApiGetInitDataMessageClass] - ZWave Controller is Primary Controller
2018-06-20 18:16:08.772 [INFO ] [age.SerialApiGetInitDataMessageClass] - ------------Number of Nodes Found Registered to ZWave Controller------------
2018-06-20 18:16:08.772 [INFO ] [age.SerialApiGetInitDataMessageClass] - # Nodes = 1
2018-06-20 18:16:08.773 [INFO ] [age.SerialApiGetInitDataMessageClass] - ----------------------------------------------------------------------------
==> /var/log/openhab2/events.log <==
2018-06-20 18:16:08.778 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_ack changed from 6 to 7
2018-06-20 18:16:08.781 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from 6 to 7
==> /var/log/openhab2/openhab.log <==
2018-06-20 18:16:08.799 [WARN ] [ve.internal.protocol.ZWaveController] - NODE 1: Restore from config: Error. Data invalid, ignoring config.
==> /var/log/openhab2/events.log <==
2018-06-20 18:16:08.810 [hingStatusInfoChangedEvent] - ‘zwave:serial_zstick:n1’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2018-06-20 18:16:08.813 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_ack changed from 7 to 8
2018-06-20 18:16:08.815 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from 7 to 8
2018-06-20 18:16:08.821 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_ack changed from 8 to 9
2018-06-20 18:16:08.824 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from 8 to 9
2018-06-20 18:16:32.895 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_ack changed from 9 to 10
2018-06-20 18:16:32.896 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from 9 to 10
2018-06-20 18:16:32.901 [arthome.event.BindingEvent] - org.openhab.binding.zwave.event.BindingEvent@a8f7dde
2018-06-20 18:16:41.764 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from 10 to 11
2018-06-20 18:16:41.919 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from 11 to 12
==> /var/log/openhab2/openhab.log <==
2018-06-20 18:16:41.922 [INFO ] [mmandclass.ZWaveSecurityCommandClass] - NODE 2: setupNetworkKey useSchemeZero=false
==> /var/log/openhab2/events.log <==
2018-06-20 18:16:41.927 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_ack changed from 10 to 11
2018-06-20 18:16:41.976 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from 12 to 13
==> /var/log/openhab2/openhab.log <==
2018-06-20 18:16:41.980 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing ‘zwave:device:n1:node2’ to inbox.
==> /var/log/openhab2/events.log <==
2018-06-20 18:16:41.981 [home.event.InboxAddedEvent] - Discovery Result with UID ‘zwave:device:n1:node2’ has been added.
2018-06-20 18:16:41.983 [arthome.event.BindingEvent] - org.openhab.binding.zwave.event.BindingEvent@2317f039
2018-06-20 18:16:41.988 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_ack changed from 11 to 12
2018-06-20 18:16:41.991 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from 13 to 14
==> /var/log/openhab2/openhab.log <==
2018-06-20 18:16:41.993 [WARN ] [rialmessage.IdentifyNodeMessageClass] - Got IdentifyNodeMessage without request, ignoring. Last message was SendData.
==> /var/log/openhab2/events.log <==
2018-06-20 18:16:41.995 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_can changed from NULL to 1
2018-06-20 18:16:46.992 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_ack changed from 12 to 13
2018-06-20 18:16:46.995 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_ack changed from 13 to 14
2018-06-20 18:16:47.002 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from 14 to 15
2018-06-20 18:16:47.019 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from 15 to 16
2018-06-20 18:16:47.031 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from 16 to 17
2018-06-20 18:16:51.996 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_ack changed from 14 to 15
2018-06-20 18:16:52.000 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_ack changed from 15 to 16
2018-06-20 18:16:52.010 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from 17 to 18
2018-06-20 18:16:52.023 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from 18 to 19
2018-06-20 18:16:52.035 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from 19 to 20
==> /var/log/openhab2/openhab.log <==
2018-06-20 18:16:52.039 [INFO ] [mmandclass.ZWaveSecurityCommandClass] - NODE 2: setupNetworkKey useSchemeZero=true
2018-06-20 18:16:52.040 [INFO ] [mmandclass.ZWaveSecurityCommandClass] - NODE 2: Using Scheme0 Network Key for Key Exchange since we are in inclusion mode.
==> /var/log/openhab2/events.log <==
2018-06-20 18:16:52.045 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_ack changed from 16 to 17
2018-06-20 18:16:52.051 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from 20 to 21
2018-06-20 18:16:52.067 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from 21 to 22
2018-06-20 18:16:52.081 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from 22 to 23
2018-06-20 18:16:52.092 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_ack changed from 17 to 18
2018-06-20 18:16:52.097 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from 23 to 24
2018-06-20 18:16:52.115 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from 24 to 25
2018-06-20 18:16:52.128 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from 25 to 26
==> /var/log/openhab2/openhab.log <==
2018-06-20 18:16:52.136 [INFO ] [curityCommandClassWithInitialization] - NODE 2: Setting Network Key to real key after SECURITY_NETWORK_KEY_SET
2018-06-20 18:16:52.137 [INFO ] [mmandclass.ZWaveSecurityCommandClass] - NODE 2: setupNetworkKey useSchemeZero=false
==> /var/log/openhab2/events.log <==
2018-06-20 18:16:52.149 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_ack changed from 18 to 19
2018-06-20 18:16:52.157 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from 26 to 27
2018-06-20 18:16:52.184 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from 27 to 28
2018-06-20 18:16:52.228 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from 28 to 29
==> /var/log/openhab2/openhab.log <==
2018-06-20 18:16:52.232 [ERROR] [col.security.ZWaveSecureNonceTracker] - NODE 2: SECURITY_ERROR Device message contained nonce that is unknown to us, id=114.
==> /var/log/openhab2/events.log <==
2018-06-20 18:16:52.237 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_ack changed from 19 to 20
2018-06-20 18:16:52.243 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from 29 to 30
2018-06-20 18:16:52.262 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from 30 to 31
2018-06-20 18:16:52.285 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from 31 to 32
==> /var/log/openhab2/openhab.log <==
2018-06-20 18:16:52.289 [WARN ] [mmandclass.ZWaveSecurityCommandClass] - NODE 2: payloadQueue was empty, returning!
==> /var/log/openhab2/events.log <==
2018-06-20 18:16:57.240 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_ack changed from 20 to 21
2018-06-20 18:16:57.245 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from 32 to 33
2018-06-20 18:16:58.511 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from 33 to 34
2018-06-20 18:17:02.241 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_ack changed from 21 to 22
2018-06-20 18:17:02.247 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from 34 to 35
2018-06-20 18:17:03.565 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from 35 to 36
2018-06-20 18:17:07.243 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_ack changed from 22 to 23
2018-06-20 18:17:07.281 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from 36 to 37
2018-06-20 18:17:08.550 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from 37 to 38
2018-06-20 18:17:12.245 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_ack changed from 23 to 24
2018-06-20 18:17:12.296 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from 38 to 39
2018-06-20 18:17:12.300 [arthome.event.BindingEvent] - org.openhab.binding.zwave.event.BindingEvent@7f3e2333
2018-06-20 18:17:12.307 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_ack changed from 24 to 25
2018-06-20 18:17:12.318 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from 39 to 40
2018-06-20 18:17:13.574 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from 40 to 41
2018-06-20 18:17:13.586 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from 41 to 42
2018-06-20 18:18:16.774 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_ack changed from 25 to 26
2018-06-20 18:18:16.778 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from 42 to 43
2018-06-20 18:18:16.779 [arthome.event.BindingEvent] - org.openhab.binding.zwave.event.BindingEvent@3854c1d3
2018-06-20 18:18:46.771 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_ack changed from 26 to 27
2018-06-20 18:18:46.830 [vent.ItemStateChangedEvent] - zwave_serial_zstick_n1_serial_sof changed from 43 to 44
2018-06-20 18:18:46.831 [arthome.event.BindingEvent] - org.openhab.binding.zwave.event.BindingEvent@59caa1cf
2018-06-20 18:20:27.102 [me.event.InboxRemovedEvent] - Discovery Result with UID ‘zwave:device:n1:node2’ has been removed.
2018-06-20 18:20:27.120 [hingStatusInfoChangedEvent] - ‘zwave:device:n1:node2’ changed from UNINITIALIZED to INITIALIZING
2018-06-20 18:20:27.121 [hingStatusInfoChangedEvent] - ‘zwave:device:n1:node2’ changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline
2018-06-20 18:20:27.122 [hingStatusInfoChangedEvent] - ‘zwave:device:n1:node2’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to UNINITIALIZED
==> /var/log/openhab2/openhab.log <==
2018-06-20 18:20:27.130 [WARN ] [re.thing.internal.ThingFactoryHelper] - Could not create channel ‘alarm_number’ for thing type ‘zwave:device:n1:node2’, because channel type ‘zwave:alarm_number’ could not be found.
==> /var/log/openhab2/events.log <==
2018-06-20 18:20:27.131 [hingStatusInfoChangedEvent] - ‘zwave:device:n1:node2’ changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)
2018-06-20 18:20:27.180 [.ItemChannelLinkAddedEvent] - Link ‘zwave_device_n1_node2_lock_door-zwave:device:n1:node2:lock_door’ has been added.
2018-06-20 18:20:27.204 [.ItemChannelLinkAddedEvent] - Link ‘zwave_device_n1_node2_alarm_raw-zwave:device:n1:node2:alarm_raw’ has been added.
2018-06-20 18:20:27.343 [.ItemChannelLinkAddedEvent] - Link ‘zwave_device_n1_node2_battery_level-zwave:device:n1:node2:battery-level’ has been added.
2018-06-20 18:20:27.345 [hingStatusInfoChangedEvent] - ‘zwave:device:n1:node2’ changed from UNINITIALIZED (HANDLER_MISSING_ERROR) to INITIALIZING
2018-06-20 18:20:27.353 [hingStatusInfoChangedEvent] - ‘zwave:device:n1:node2’ changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline
2018-06-20 18:20:27.415 [hingStatusInfoChangedEvent] - ‘zwave:device:n1:node2’ changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
2018-06-20 18:20:27.417 [me.event.ThingUpdatedEvent] - Thing ‘zwave:device:n1:node2’ has been updated.
2018-06-20 18:20:27.417 [me.event.ThingUpdatedEvent] - Thing ‘zwave:device:n1:node2’ has been updated.
==> /var/log/openhab2/openhab.log <==
2018-06-20 18:20:29.491 [WARN ] [ore.internal.thing.ThingTypeResource] - Cannot find channel type: zwave:alarm_number
==> /var/log/openhab2/events.log <==
2018-06-20 18:20:34.028 [ome.event.ItemCommandEvent] - Item ‘zwave_device_n1_node2_lock_door’ received command ON
==> /var/log/openhab2/openhab.log <==
2018-06-20 18:20:34.030 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method ‘ThingHandler.handleCommand()’ on ‘org.openhab.binding.zwave.handler.ZWaveThingHandler@193d6ac1’: null
java.lang.NullPointerException: null
at org.openhab.binding.zwave.internal.converter.ZWaveDoorLockConverter.receiveCommand(ZWaveDoorLockConverter.java:102) [210:org.openhab.binding.zwave:2.3.0]
at org.openhab.binding.zwave.handler.ZWaveThingHandler.handleCommand(ZWaveThingHandler.java:878) [210:org.openhab.binding.zwave:2.3.0]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
at java.lang.reflect.Method.invoke(Method.java:498) ~[?:?]
at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:153) [101:org.eclipse.smarthome.core:0.10.0.oh230]
at org.eclipse.smarthome.core.internal.common.InvocationHandlerSync.invoke(InvocationHandlerSync.java:59) [101:org.eclipse.smarthome.core:0.10.0.oh230]
at com.sun.proxy.$Proxy131.handleCommand(Unknown Source) [210:org.openhab.binding.zwave:2.3.0]
at org.eclipse.smarthome.core.thing.internal.profiles.ProfileCallbackImpl.handleCommand(ProfileCallbackImpl.java:75) [108:org.eclipse.smarthome.core.thing:0.10.0.oh230]
at org.eclipse.smarthome.core.thing.internal.profiles.SystemDefaultProfile.onCommandFromItem(SystemDefaultProfile.java:49) [108:org.eclipse.smarthome.core.thing:0.10.0.oh230]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
at java.lang.reflect.Method.invoke(Method.java:498) ~[?:?]
at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:153) [101:org.eclipse.smarthome.core:0.10.0.oh230]
at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:53) [101:org.eclipse.smarthome.core:0.10.0.oh230]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
at java.lang.Thread.run(Thread.java:748) [?:?]
==> /var/log/openhab2/events.log <==
2018-06-20 18:20:34.032 [vent.ItemStateChangedEvent] - zwave_device_n1_node2_lock_door changed from NULL to ON