Hello everyone,
I’ve been trying, unsuccessfully, to add my Danalock BTZE125 to OpenHAB 2. It never seems to initialize properly.
This is what I get in the log:
09:25:32.813 [INFO ] [basic.internal.servlet.WebAppServlet] - Started Basic UI at /basicui/app
09:25:32.846 [INFO ] [assic.internal.servlet.WebAppServlet] - Started Classic UI at /classicui/app
09:25:32.893 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /ui
09:25:32.914 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at /start
09:25:32.989 [INFO ] [smarthome.event.ExtensionEvent ] - Extension 'binding-zwave' has been installed.
09:25:49.244 [INFO ] [ui.habmin.internal.servlet.HABminApp] - Started HABmin servlet at /habmin
09:25:49.263 [INFO ] [smarthome.event.ExtensionEvent ] - Extension 'ui-habmin' has been installed.
09:26:08.428 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'zwave_serial_zstick_285e17c4_serial_sof-zwave:serial_zstick:285e17c4:serial_sof' has been added.
09:26:08.567 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'zwave_serial_zstick_285e17c4_serial_ack-zwave:serial_zstick:285e17c4:serial_ack' has been added.
09:26:08.704 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'zwave_serial_zstick_285e17c4_serial_nak-zwave:serial_zstick:285e17c4:serial_nak' has been added.
09:26:08.869 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'zwave_serial_zstick_285e17c4_serial_can-zwave:serial_zstick:285e17c4:serial_can' has been added.
09:26:09.028 [INFO ] [home.event.ItemChannelLinkAddedEvent] - Link 'zwave_serial_zstick_285e17c4_serial_oof-zwave:serial_zstick:285e17c4:serial_oof' has been added.
09:26:09.034 [INFO ] [smarthome.event.ItemAddedEvent ] - Item 'zwave_serial_zstick_285e17c4_serial_sof' has been added.
09:26:09.034 [INFO ] [smarthome.event.ItemAddedEvent ] - Item 'zwave_serial_zstick_285e17c4_serial_ack' has been added.
09:26:09.035 [INFO ] [smarthome.event.ItemAddedEvent ] - Item 'zwave_serial_zstick_285e17c4_serial_nak' has been added.
09:26:09.035 [INFO ] [smarthome.event.ItemAddedEvent ] - Item 'zwave_serial_zstick_285e17c4_serial_can' has been added.
09:26:09.036 [INFO ] [smarthome.event.ItemAddedEvent ] - Item 'zwave_serial_zstick_285e17c4_serial_oof' has been added.
09:26:09.039 [INFO ] [smarthome.event.ThingAddedEvent ] - Thing 'zwave:serial_zstick:285e17c4' has been added.
09:26:09.070 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:serial_zstick:285e17c4' changed from UNINITIALIZED to INITIALIZING
09:26:09.072 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port 'COM4'
09:26:09.073 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:serial_zstick:285e17c4' changed from INITIALIZING to OFFLINE (BRIDGE_OFFLINE): Controller is offline
09:26:14.073 [WARN ] [ome.core.thing.internal.ThingManager] - Initializing handler for thing 'zwave:serial_zstick:285e17c4' takes more than 5000ms.
09:26:23.658 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Serial port is initialized
09:26:23.664 [INFO ] [mmandclass.ZWaveSecurityCommandClass] - Update networkKey
09:26:23.671 [INFO ] [ve.internal.protocol.ZWaveController] - Starting ZWave controller
09:26:23.674 [INFO ] [ve.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false.
09:26:26.683 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from NULL to 1
09:26:26.699 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_ack changed from NULL to 1
09:26:26.699 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 1 to 2
09:26:26.711 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_ack changed from 1 to 2
09:26:26.716 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 2 to 3
09:26:26.718 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_ack changed from 2 to 3
09:26:26.720 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 3 to 4
09:26:26.722 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_ack changed from 3 to 4
09:26:26.726 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 4 to 5
09:26:26.732 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_ack changed from 4 to 5
09:26:26.818 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 5 to 6
09:26:26.822 [INFO ] [age.SerialApiGetInitDataMessageClass] - NODE 1: Node found
09:26:26.824 [INFO ] [age.SerialApiGetInitDataMessageClass] - ZWave Controller using Controller API
09:26:26.824 [INFO ] [age.SerialApiGetInitDataMessageClass] - ZWave Controller is Primary Controller
09:26:26.824 [INFO ] [age.SerialApiGetInitDataMessageClass] - ------------Number of Nodes Found Registered to ZWave Controller------------
09:26:26.824 [INFO ] [age.SerialApiGetInitDataMessageClass] - # Nodes = 1
09:26:26.825 [INFO ] [age.SerialApiGetInitDataMessageClass] - ----------------------------------------------------------------------------
09:26:26.830 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:serial_zstick:285e17c4' changed from OFFLINE (BRIDGE_OFFLINE): Controller is offline to ONLINE
09:26:26.831 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_ack changed from 5 to 6
09:26:26.834 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 6 to 7
09:26:26.922 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_ack changed from 6 to 7
09:26:26.926 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 7 to 8
09:26:26.935 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_ack changed from 7 to 8
09:26:26.938 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 8 to 9
09:26:47.609 [ERROR] [ve.internal.protocol.ZWaveController] - Neither inclusion nor exclusion was active!
09:26:47.614 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_ack changed from 8 to 9
09:26:47.619 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 9 to 10
09:26:47.620 [INFO ] [smarthome.event.BindingEvent ] - org.openhab.binding.zwave.event.BindingEvent@297754d2
09:26:52.120 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 10 to 11
09:26:52.292 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 11 to 12
09:26:52.295 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_ack changed from 9 to 10
09:26:52.297 [INFO ] [mmandclass.ZWaveSecurityCommandClass] - NODE 2: setupNetworkKey useSchemeZero=false
09:26:52.348 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 12 to 13
09:26:52.348 [WARN ] [nternal.DiscoveryServiceRegistryImpl] - Inbox not set
09:26:52.530 [INFO ] [g.discovery.internal.PersistentInbox] - Added new thing 'zwave:device:285e17c4:node2' to inbox.
09:26:52.530 [INFO ] [smarthome.event.InboxAddedEvent ] - Discovery Result with UID 'zwave:device:285e17c4:node2' has been added.
09:26:52.530 [INFO ] [smarthome.event.BindingEvent ] - org.openhab.binding.zwave.event.BindingEvent@22934258
09:26:52.533 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_ack changed from 10 to 11
09:26:52.534 [WARN ] [rialmessage.IdentifyNodeMessageClass] - Got IdentifyNodeMessage without request, ignoring. Last message was SendData.
09:26:52.534 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 13 to 14
09:26:52.536 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_can changed from NULL to 1
09:26:57.533 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 2: Timeout while sending message. Requeueing - 2 attempts left!
09:26:57.534 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 2: Got an error while sending data. Resending message.
09:26:57.534 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_ack changed from 11 to 12
09:26:57.537 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_ack changed from 12 to 13
09:26:57.543 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 14 to 15
09:26:57.564 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 15 to 16
09:26:57.592 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 16 to 17
09:27:02.536 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 2: Timeout while sending message. Requeueing - 1 attempts left!
09:27:02.537 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 2: Got an error while sending data. Resending message.
09:27:02.538 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_ack changed from 13 to 14
09:27:02.539 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_ack changed from 14 to 15
09:27:02.545 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 17 to 18
09:27:02.566 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 18 to 19
09:27:02.595 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 19 to 20
09:27:02.597 [INFO ] [mmandclass.ZWaveSecurityCommandClass] - NODE 2: setupNetworkKey useSchemeZero=true
09:27:02.597 [INFO ] [mmandclass.ZWaveSecurityCommandClass] - NODE 2: Using Scheme0 Network Key for Key Exchange since we are in inclusion mode.
09:27:02.607 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_ack changed from 15 to 16
09:27:02.610 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 20 to 21
09:27:02.631 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 21 to 22
09:27:02.660 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 22 to 23
09:27:02.668 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_ack changed from 16 to 17
09:27:02.670 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 23 to 24
09:27:02.694 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 24 to 25
09:27:02.726 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 25 to 26
09:27:02.730 [INFO ] [curityCommandClassWithInitialization] - NODE 2: Setting Network Key to real key after SECURITY_NETWORK_KEY_SET
09:27:02.730 [INFO ] [mmandclass.ZWaveSecurityCommandClass] - NODE 2: setupNetworkKey useSchemeZero=false
09:27:02.736 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_ack changed from 17 to 18
09:27:02.744 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 26 to 27
09:27:02.771 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 27 to 28
09:27:02.814 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 28 to 29
09:27:02.814 [ERROR] [col.security.ZWaveSecureNonceTracker] - NODE 2: SECURITY_ERROR Device message contained nonce that is unknown to us, id=-45.
09:27:02.818 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_ack changed from 18 to 19
09:27:02.824 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 29 to 30
09:27:02.849 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 30 to 31
09:27:02.885 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 31 to 32
09:27:02.890 [WARN ] [mmandclass.ZWaveSecurityCommandClass] - NODE 2: payloadQueue was empty, returning!
09:27:02.890 [ERROR] [ssage.ApplicationCommandMessageClass] - NODE 2: Unknown command class 0xffffff98
09:27:07.816 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 2: Timeout while sending message. Requeueing - 2 attempts left!
09:27:07.816 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 2: Got an error while sending data. Resending message.
09:27:07.819 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_ack changed from 19 to 20
09:27:07.825 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 32 to 33
09:27:07.848 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 33 to 34
09:27:12.817 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 2: Timeout while sending message. Requeueing - 1 attempts left!
09:27:12.817 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 2: Got an error while sending data. Resending message.
09:27:12.820 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_ack changed from 20 to 21
09:27:12.826 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 34 to 35
09:27:12.853 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 35 to 36
09:27:17.819 [ERROR] [ocol.ZWaveController$ZWaveSendThread] - NODE 2: Timeout while sending message. Requeueing - 0 attempts left!
09:27:17.820 [ERROR] [l.serialmessage.SendDataMessageClass] - NODE 2: Got an error while sending data. Resending message.
09:27:17.824 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_ack changed from 21 to 22
09:27:17.829 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 36 to 37
09:27:17.851 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 37 to 38
09:27:22.822 [WARN ] [ocol.ZWaveController$ZWaveSendThread] - NODE 2: Too many retries. Discarding message: Message: class=SendData[0x13], type=Request[0x00], priority=Immediate, dest=2, callback=12, payload=02 0A 98 80 D3 4B 4C 65 8D 7B 7B 99
09:27:22.824 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_ack changed from 22 to 23
09:27:22.874 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 38 to 39
09:27:22.874 [WARN ] [nternal.DiscoveryServiceRegistryImpl] - Inbox not set
09:27:23.053 [INFO ] [smarthome.event.BindingEvent ] - org.openhab.binding.zwave.event.BindingEvent@27f3584f
09:27:23.055 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_ack changed from 23 to 24
09:27:23.061 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 39 to 40
09:27:23.081 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 40 to 41
09:27:23.110 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 41 to 42
09:27:28.857 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 42 to 43
09:27:28.857 [ERROR] [col.security.ZWaveSecureNonceTracker] - NODE 2: SECURITY_ERROR Device message contained nonce that is unknown to us, id=9.
09:27:28.861 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_ack changed from 24 to 25
09:27:28.866 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 43 to 44
09:27:28.892 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 44 to 45
09:27:28.928 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 45 to 46
09:27:28.933 [WARN ] [mmandclass.ZWaveSecurityCommandClass] - NODE 2: payloadQueue was empty, returning!
09:27:28.933 [ERROR] [ssage.ApplicationCommandMessageClass] - NODE 2: Unknown command class 0xffffff8b
09:27:39.860 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 46 to 47
09:27:39.860 [ERROR] [col.security.ZWaveSecureNonceTracker] - NODE 2: SECURITY_ERROR Device message contained nonce that is unknown to us, id=-20.
09:27:39.865 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_ack changed from 25 to 26
09:27:39.871 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 47 to 48
09:27:39.894 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 48 to 49
09:27:39.930 [INFO ] [marthome.event.ItemStateChangedEvent] - zwave_serial_zstick_285e17c4_serial_sof changed from 49 to 50
09:27:39.933 [WARN ] [mmandclass.ZWaveSecurityCommandClass] - NODE 2: payloadQueue was empty, returning!
09:27:39.933 [ERROR] [ssage.ApplicationCommandMessageClass] - NODE 2: Unknown command class 0xffffff8a
And what I did:
- Reset the lock
- Reset the controller
- Compile a fresh snapshot and extract it
- Install Z-Wave binding and HABmin
- Add the Z-Wave controller in Paper UI, setting the port and a network key
- Launch NWI using HABmin
- Put the lock in association mode (press until 2 beeps)
- Wait for a few seconds, refresh HABmin, add from the inbox
Interestingly, the device is detected as BTZW125, which seems to refer to a slightly different version of the lock (perhaps another region? BTZU125 is the US version, BTZE125 the EU). Not sure if this change would impact the Z-Wave side of things though. No XML file is generated so I can’t compare to the current information in the database.
Any clue on what can be wrong?
Thanks for your help,
Franck
