ZWave Inclusion Mode

Starting on a Fresh Install and an Aeon ZWave Gen 5 Stick with no devices currently on it.

I’m trying to start by hopefully pairing a KwikSet lock with. But I actually can’t seem to get Aeon Stick to enter inclusion mode from Habmin.

The Stick/Controller in is recognized in Habmin. But when I tell it go into discovery mode, all I see in the log is this?

2016-05-14 11:56:49.086 [INFO ] [age.SerialApiGetInitDataMessageClass] - NODE 1: Node found
2016-05-14 11:56:49.086 [INFO ] [age.SerialApiGetInitDataMessageClass] - ZWave Controller using Controller API
2016-05-14 11:56:49.086 [INFO ] [age.SerialApiGetInitDataMessageClass] - ZWave Controller is Primary Controller
2016-05-14 11:56:49.086 [INFO ] [age.SerialApiGetInitDataMessageClass] - ------------Number of Nodes Found Registered to ZWave Controller------------
2016-05-14 11:56:49.086 [INFO ] [age.SerialApiGetInitDataMessageClass] - # Nodes = 1
2016-05-14 11:56:49.086 [INFO ] [age.SerialApiGetInitDataMessageClass] - ----------------------------------------------------------------------------
2016-05-14 11:56:49.086 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:serial_zstick:154aff7fe80' changed from OFFLINE to ONLINE
2016-05-14 12:09:06.541 [ERROR] [ve.internal.protocol.ZWaveController] - Neither inclusion nor exclusion was active!

Can you provide a log please and I’ll take a look?

Is there a separate zwave log? If so, i’m not certain where to find that.

The openhab log doesn’t have much else besides that. All I’ve done is Start a fresh download of OH2, enabled the zwave binding and added habmin so far.

this is the entire openhab log. Note, this actually the log after starting OH2 in debug mode as well.

2016-05-14 13:27:08.626 [INFO ] [ui.habmin.internal.servlet.HABminApp] - Started HABmin servlet at /habmin
2016-05-14 13:27:14.229 [INFO ] [smarthome.event.ThingAddedEvent     ] - Thing 'zwave:serial_zstick:154aff7fe80' has been added.
2016-05-14 13:27:17.674 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /ui
2016-05-14 13:27:17.721 [INFO ] [.dashboard.internal.DashboardService] - Started dashboard at /start
2016-05-14 13:27:17.955 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port 'COM5'
2016-05-14 13:27:17.986 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:serial_zstick:154aff7fe80' changed from UNINITIALIZED to INITIALIZING
2016-05-14 13:27:17.986 [INFO ] [assic.internal.servlet.WebAppServlet] - Started Classic UI at /classicui/app
2016-05-14 13:27:18.002 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:serial_zstick:154aff7fe80' changed from INITIALIZING to OFFLINE
2016-05-14 13:27:18.017 [INFO ] [basic.internal.servlet.WebAppServlet] - Started Basic UI at /basicui/app
2016-05-14 13:27:19.585 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Serial port is initialized
2016-05-14 13:27:19.585 [INFO ] [mmandclass.ZWaveSecurityCommandClass] - Update networkKey
2016-05-14 13:27:19.601 [INFO ] [ve.internal.protocol.ZWaveController] - Starting ZWave controller
2016-05-14 13:27:19.601 [INFO ] [ve.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false.
2016-05-14 13:27:22.697 [INFO ] [age.SerialApiGetInitDataMessageClass] - NODE 1: Node found
2016-05-14 13:27:22.697 [INFO ] [age.SerialApiGetInitDataMessageClass] - ZWave Controller using Controller API
2016-05-14 13:27:22.697 [INFO ] [age.SerialApiGetInitDataMessageClass] - ZWave Controller is Primary Controller
2016-05-14 13:27:22.697 [INFO ] [age.SerialApiGetInitDataMessageClass] - ------------Number of Nodes Found Registered to ZWave Controller------------
2016-05-14 13:27:22.697 [INFO ] [age.SerialApiGetInitDataMessageClass] - # Nodes = 1
2016-05-14 13:27:22.697 [INFO ] [age.SerialApiGetInitDataMessageClass] - ----------------------------------------------------------------------------
2016-05-14 13:27:22.712 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'zwave:serial_zstick:154aff7fe80' changed from OFFLINE to ONLINE
2016-05-14 13:32:04.703 [ERROR] [ve.internal.protocol.ZWaveController] - Neither inclusion nor exclusion was active!
2016-05-14 13:33:20.216 [ERROR] [ve.internal.protocol.ZWaveController] - Neither inclusion nor exclusion was active!

No, but I need to see the debug information - INFO and ERROR level data is enough to show there might be an issue, but totally useless to work out what or why.

Take a look here -:
http://www.cd-jackson.com/index.php/openhab/5-zwave-debugging-openhab

It’s just my notes, but the first section says how to enable debug.

ok, turned that on, and then tried it again. Perhaps it is starting?

2016-05-14 13:33:20.216 [ERROR] [ve.internal.protocol.ZWaveController] - Neither inclusion nor exclusion was active!
2016-05-14 13:47:00.421 [DEBUG] [ve.internal.protocol.ZWaveController] - Stopping inclusion timer.
2016-05-14 13:47:00.421 [ERROR] [ve.internal.protocol.ZWaveController] - Neither inclusion nor exclusion was active!
2016-05-14 13:47:00.421 [DEBUG] [wave.discovery.ZWaveDiscoveryService] - Starting ZWave inclusion scan for zwave:serial_zstick:154aff7fe80
2016-05-14 13:47:00.421 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave controller start inclusion - mode 2
2016-05-14 13:47:00.421 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Setting controller into INCLUSION mode, highPower:true networkWide:true.
2016-05-14 13:47:00.421 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
2016-05-14 13:47:00.425 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2016-05-14 13:47:00.425 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A C1 FF 8E 
2016-05-14 13:47:00.429 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A C1 FF 8E 
2016-05-14 13:47:00.429 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A FF 01 00 00 4C 
2016-05-14 13:47:00.429 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2016-05-14 13:47:00.437 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 07 00 4A FF 01 00 00 4C 
2016-05-14 13:47:00.437 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 07 00 4A FF 01 00 00 4C 
2016-05-14 13:47:00.437 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=AddNodeToNetwork[0x4A], type=Request[0x00], priority=High, dest=255, callback=0, payload=FF 01 00 00 
2016-05-14 13:47:00.437 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Learn ready.
2016-05-14 13:47:00.437 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveInclusionEvent
2016-05-14 13:47:00.437 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=AddNodeToNetwork[0x4A], type=Request[0x00], priority=High, dest=255, callback=0, payload=C1 FF 
2016-05-14 13:47:00.437 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=AddNodeToNetwork[0x4A], type=Request[0x00], priority=High, dest=255, callback=0, payload=FF 01 00 00 
2016-05-14 13:47:00.437 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=AddNodeToNetwork, callback id=0, expected=AddNodeToNetwork, cancelled=false        transaction complete!
2016-05-14 13:47:00.437 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
2016-05-14 13:47:00.437 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 255: Response processed after 8ms/84ms.
2016-05-14 13:47:30.432 [DEBUG] [ve.internal.protocol.ZWaveController] - Stopping inclusion timer.
2016-05-14 13:47:30.432 [DEBUG] [ve.internal.protocol.ZWaveController] - Ending inclusion mode.
2016-05-14 13:47:30.432 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Ending INCLUSION mode.
2016-05-14 13:47:30.432 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
2016-05-14 13:47:30.432 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
2016-05-14 13:47:30.432 [DEBUG] [ve.internal.protocol.ZWaveController] - ZWave controller end inclusion
2016-05-14 13:47:30.432 [DEBUG] [ve.internal.protocol.ZWaveController] - Stopping inclusion timer.
2016-05-14 13:47:30.432 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 05 00 4A 05 FE 4B 
2016-05-14 13:47:30.432 [ERROR] [ve.internal.protocol.ZWaveController] - Neither inclusion nor exclusion was active!
2016-05-14 13:47:30.432 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 05 00 4A 05 FE 4B 
2016-05-14 13:47:30.510 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 07 00 4A FE 06 00 00 4A 
2016-05-14 13:47:30.510 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
2016-05-14 13:47:30.510 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 07 00 4A FE 06 00 00 4A 
2016-05-14 13:47:30.510 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 07 00 4A FE 06 00 00 4A 
2016-05-14 13:47:30.510 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=AddNodeToNetwork[0x4A], type=Request[0x00], priority=High, dest=255, callback=0, payload=FE 06 00 00 
2016-05-14 13:47:30.510 [DEBUG] [ol.serialmessage.AddNodeMessageClass] - Add Node: Done.
2016-05-14 13:47:30.510 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Sent Message: class=AddNodeToNetwork[0x4A], type=Request[0x00], priority=High, dest=255, callback=0, payload=05 FE 
2016-05-14 13:47:30.510 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: Recv Message: class=AddNodeToNetwork[0x4A], type=Request[0x00], priority=High, dest=255, callback=0, payload=FE 06 00 00 
2016-05-14 13:47:30.510 [DEBUG] [.serialmessage.ZWaveCommandProcessor] - Checking transaction complete: class=AddNodeToNetwork, callback id=0, expected=AddNodeToNetwork, cancelled=false        transaction complete!
2016-05-14 13:47:30.510 [DEBUG] [ve.internal.protocol.ZWaveController] - Notifying event listeners: ZWaveTransactionCompletedEvent
2016-05-14 13:47:30.510 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 255: Response processed after 78ms/84ms.

Yes - it’s working ok. It’s enabled for 30 seconds as it should be. I guess the error needs looking at though :wink:

Ok, I wonder why the lock doesn’t want to be found and pair then. I know locks can be tricky and I am right next to the lock when trying to pair it.

I’ll try on a light switch later as well first. And see how that goes before trying the lock again.

Locks are difficult as you say, and I fear it won’t work (I have issues here also at the moment). However, the initial inclusion should work even if the secure inclusion fails - since you aren’t seeing anything at all, there’s something fundimentally wrong I think.

Hi,

I have the same Z-Wave stick and here is how I succeeded in adding devices (actually 13 added) :

  • I stop openHab
  • I remove the stick from the USB port
  • I click on the big button on the stick : It flashes in blue and the stick is in inclusion mode.
  • I include the new device(s)
  • I put the stick back ON THE SAME USB PORT (the same because if you change the port used, the device name - /dev/xxxxxx - will change)
  • I start openHab
  • I wait a little and the new Thing(s) appear(s) in the inbox

I.e. : Habmin had nothing to do in this part of my process !

I am not sure it is a good idea to stop openHab during the process. It is just the way I do things for the moment.

I hope this helps.

This will NOT work at all for secure devices. Inclusion with HABmin should work fine but absolutely must be used for secure inclusion.

Oops. I did not notice this was for secure devices.

FYI : I process this way because all my devices are already in place (I am moving from another software to OpenHab) and it is easier to bring the stick close to the devices.

Yes - I also do this occasionally, but it’s also worth noting that if your network contains a lot of ZWave+ devices, it should be possible to use Network Wide Inclusion in OH2.