Zwave - Unknown Device - Device Not In Database, device initialisation is not complete

chris · August 27, 2017, 9:28pm

The log doesn’t contain any communications with the device so there’s not much I can comment on about why it’s not discovered -:

I would suggest to get a longer log and looking at the log viewer yourself to see if there’s communication with node 5. If there is I’m happy to check it out…

(when pasting in a log, please format with the </> button as it’s much easier to read).

gismofx · August 27, 2017, 9:35pm

@chris Can you suggest some ways to elicit some communication with the device? I have the log open and the switch is able to control the fan, but I’m not seeing anything in the log.

chris · August 27, 2017, 10:01pm

Is it reasonably close to the controller? Let’s say 20 to 30 feet max? If so, I suspect that it needs to be excluded and then included again - I know you’ve done that, but I’d suggest to do it again, and get the full debug log so we can see what’s going on (if anything).

If there’s still nothing happening, then I’m not sure - if it excludes and reincludes again then it should be able to communicate…

gismofx · August 28, 2017, 12:40am

@chris Yes, less than 15ft from the controller. I’ve tried to exclude and re-include and get the same results. Now, I am getting two nodes found. Both have the same ID:

Time	Node	Entry
20:20:18.889	2	
THING TYPE zwave:ge_12718_00_000
20:20:19.043	3	
THING TYPE zwave:homeseer_hswd100_00_000
20:20:19.231	4	
THING TYPE zwave:homeseer_hswd100_00_000
20:20:19.716		
TX REQ AddNodeToNetwork ADD_NODE_ANY HIGH POWER NWI
20:20:24.717		
Message retry (2 attempts remaining)
20:20:24.729		
TX REQ AddNodeToNetwork ADD_NODE_ANY HIGH POWER NWI
20:20:29.730		
Message retry (1 attempts remaining)
20:20:29.747		
TX REQ AddNodeToNetwork ADD_NODE_ANY HIGH POWER NWI
20:20:34.749		
Message retry (0 attempts remaining)
20:20:34.758		
TX REQ AddNodeToNetwork ADD_NODE_ANY HIGH POWER NWI
20:20:48.752		
TX REQ AddNodeToNetwork ADD_NODE_STOP
20:20:53.754		
Message retry (2 attempts remaining)
20:20:53.765		
TX REQ AddNodeToNetwork ADD_NODE_STOP
20:20:58.767		
Message retry (1 attempts remaining)
20:20:58.795		
TX REQ AddNodeToNetwork ADD_NODE_STOP
20:21:03.802		
Message retry (0 attempts remaining)
20:21:03.825		
TX REQ AddNodeToNetwork ADD_NODE_STOP
20:21:08.849		
TX REQ RemoveFailedNodeID
20:21:13.853		
Message retry (2 attempts remaining)
20:21:13.863		
TX REQ RemoveFailedNodeID
20:21:18.865		
Message retry (1 attempts remaining)
20:21:18.875		
TX REQ RemoveFailedNodeID
20:21:23.879		
Message retry (0 attempts remaining)
20:21:23.882		
TX REQ RemoveFailedNodeID

chris · August 28, 2017, 8:48am

I’m not sure what you mean by this - one is node ID 5 and the other node ID 6…

Toneus · August 28, 2017, 1:04pm

Does this mean that it was not properly excluded from the controller?

Chad, what zwave controller are you using?

gismofx · August 28, 2017, 1:08pm

I think you may be right. I think they are not being excluded properly. They immediately show up when I try to search for devices. I have an Aeotek Z Stick Gen 5. I’m going to try a full reset of the stick this evening and try again.

Toneus · August 28, 2017, 1:27pm

For that stick, it’s a long press of the button and wait for the Yellow light to flash. Then actuate the switch. Here are the instructions from the Aeon site.

Removing devices via its button (Example).

Remove the Z-Stick from your PC USB port (disconnect)
Press and hold the Z-Stick Gen5 button until its LED should blinks yellow rapidly, then release its button.
Now go to your Switch or Z-Wave device, and tap its button quickly (most devices use a single tap, but some Z-Wave devices may have special operations to unpair, please refer to your Z-Wave devices manual to unpair it from the Z-Stick).
If successful, you’ll notice that the Z-Stick Gen5s LED will become solid blue for 2 seconds to indicate a successful unpair, then it will return to blinking yellow rapidly to allow you to continue removing other devices.
You can continue to remove devices while it is blinking yellow rapidly (follow steps 3-4 with each device you want to remove then continue to step 6 when you are done)
Once you are done, tap the Z-Sticks button once and the LED should stop blinking.

At this time you don’t have a lot of devices so a reset isn’t a massive exercise. You can take backups of your stick. Download the Backup Software from Aeon here.

gismofx · August 28, 2017, 10:00pm

I manually removed the bogus inclusions/devices via this:
http://docs.incontrolha.com/home/remove-a-failed-device via [SOLVED] How to delete a dead node from a zwave stick

Then I tried to add the device again via paperUI and still the old “unknown” devices keep showing up the in the list. So, I switched back to Zensys and manually included the fan control there. I was able to turn the fan on and off via Zensys.

Anyway, I reboot the pi, and got everything all cleared up.

Now, I started paperUI and tried to discover the switch by searching and pressing a button on the switch. Here’s my log @chris :

17:52:32.294 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 9: Stage PROTOINFO. Initialisation retry timer triggered. Increased to 160000
17:52:32.295 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 9: Node advancer - PROTOINFO: queue length(0), free to send(false)
17:52:32.296 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 9: Initialisation retry timer started 160000
17:52:32.296 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 9: Node advancer: loop - PROTOINFO try 5: stageAdvanced(false)
17:52:32.297 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 9: Node advancer: PROTOINFO - send IdentifyNode
17:52:32.298 [DEBUG] [alization.ZWaveNodeInitStageAdvancer] - NODE 9: Node advancer - queued packet. Queue length is 1
17:52:32.299 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
17:52:32.299 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
17:52:32.300 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 41 09 B3
17:52:32.302 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 04 00 41 09 B3
17:52:32.310 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 01 41 D3 9C 01 04 11 08 E5
17:52:32.313 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
17:52:32.314 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 01 41 D3 9C 01 04 11 08 E5
17:52:32.315 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 01 41 D3 9C 01 04 11 08 E5
17:52:32.316 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=IdentifyNode[0x41], type=Response[0x01], priority=High, dest=255, callback=0, payload=D3 9C 01 04 11 08
17:52:32.317 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: ProtocolInfo
17:52:32.318 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: Listening = true
17:52:32.318 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: Routing = true
17:52:32.319 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: Beaming = true
17:52:32.320 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: Version = 4
17:52:32.320 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: FLIRS = false
17:52:32.321 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: Security = false
17:52:32.321 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: Max Baud = 40000
17:52:32.322 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: Basic = Routing Slave
17:52:32.323 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: Generic = Multi-Level Switch
17:52:32.323 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: Specific device class 8 not found
17:52:37.304 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 255: Timeout while sending message. Requeueing - 2 attempts left!
17:52:37.305 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
17:52:37.306 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
17:52:37.307 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 41 09 B3
17:52:37.309 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 04 00 41 09 B3
17:52:37.316 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 01 41 D3 9C 01 04 11 08 E5
17:52:37.318 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
17:52:37.319 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 01 41 D3 9C 01 04 11 08 E5
17:52:37.320 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 01 41 D3 9C 01 04 11 08 E5
17:52:37.321 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=IdentifyNode[0x41], type=Response[0x01], priority=High, dest=255, callback=0, payload=D3 9C 01 04 11 08
17:52:37.322 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: ProtocolInfo
17:52:37.323 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: Listening = true
17:52:37.324 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: Routing = true
17:52:37.324 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: Beaming = true
17:52:37.325 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: Version = 4
17:52:37.325 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: FLIRS = false
17:52:37.326 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: Security = false
17:52:37.326 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: Max Baud = 40000
17:52:37.327 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: Basic = Routing Slave
17:52:37.328 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: Generic = Multi-Level Switch
17:52:37.328 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: Specific device class 8 not found
17:52:42.310 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 255: Timeout while sending message. Requeueing - 1 attempts left!
17:52:42.311 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
17:52:42.311 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
17:52:42.312 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 41 09 B3
17:52:42.314 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 04 00 41 09 B3
17:52:42.322 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 01 41 D3 9C 01 04 11 08 E5
17:52:42.324 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
17:52:42.325 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 01 41 D3 9C 01 04 11 08 E5
17:52:42.326 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 01 41 D3 9C 01 04 11 08 E5
17:52:42.327 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=IdentifyNode[0x41], type=Response[0x01], priority=High, dest=255, callback=0, payload=D3 9C 01 04 11 08
17:52:42.328 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: ProtocolInfo
17:52:42.329 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: Listening = true
17:52:42.330 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: Routing = true
17:52:42.330 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: Beaming = true
17:52:42.331 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: Version = 4
17:52:42.331 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: FLIRS = false
17:52:42.332 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: Security = false
17:52:42.332 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: Max Baud = 40000
17:52:42.333 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: Basic = Routing Slave
17:52:42.334 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: Generic = Multi-Level Switch
17:52:42.334 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: Specific device class 8 not found
17:52:47.315 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 255: Timeout while sending message. Requeueing - 0 attempts left!
17:52:47.316 [DEBUG] [ve.internal.protocol.ZWaveController] - Message queued. Queue length = 1. Queue={}
17:52:47.321 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - Took message from queue for sending. Queue length = 0
17:52:47.322 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 04 00 41 09 B3
17:52:47.323 [DEBUG] [ing.zwave.handler.ZWaveSerialHandler] - NODE 255: Sending REQUEST Message = 01 04 00 41 09 B3
17:52:47.330 [DEBUG] [WaveSerialHandler$ZWaveReceiveThread] - Receive Message = 01 09 01 41 D3 9C 01 04 11 08 E5
17:52:47.332 [DEBUG] [ve.internal.protocol.ZWaveController] - Receive queue TAKE: Length=0
17:52:47.333 [DEBUG] [wave.internal.protocol.SerialMessage] - Assembled message buffer = 01 09 01 41 D3 9C 01 04 11 08 E5
17:52:47.334 [DEBUG] [ve.internal.protocol.ZWaveController] - Process Message = 01 09 01 41 D3 9C 01 04 11 08 E5
17:52:47.335 [DEBUG] [ve.internal.protocol.ZWaveController] - Message: class=IdentifyNode[0x41], type=Response[0x01], priority=High, dest=255, callback=0, payload=D3 9C 01 04 11 08
17:52:47.336 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: ProtocolInfo
17:52:47.336 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: Listening = true
17:52:47.337 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: Routing = true
17:52:47.338 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: Beaming = true
17:52:47.338 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: Version = 4
17:52:47.339 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: FLIRS = false
17:52:47.339 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: Security = false
17:52:47.340 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: Max Baud = 40000
17:52:47.340 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: Basic = Routing Slave
17:52:47.341 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: Generic = Multi-Level Switch
17:52:47.341 [DEBUG] [rialmessage.IdentifyNodeMessageClass] - NODE 9: Specific device class 8 not found
17:52:52.325 [DEBUG] [ocol.ZWaveController$ZWaveSendThread] - NODE 255: Too many retries. Discarding message: Message: class=IdentifyNode[0x41], type=Request[0x00], priority=High, dest=255, callback=0, payload=09

Any ideas?

chris · August 29, 2017, 6:56am

Yes - I see the problem and I’ll take a look at this tonight.

gismofx · August 31, 2017, 7:25pm

@chris Any luck with this issue? Should I submit an issue on github? Thanks.

chris · August 31, 2017, 8:52pm

I made the changes that I think should have solved it a few days ago. I guess it didn’t work? .

gismofx · August 31, 2017, 10:33pm

@chris how do I get the updates? I haven’t tried anything yet.

chris · September 1, 2017, 6:42am

Ah - ok, maybe there’s still hope .

You need to update to the latest snapshot version of the binding. If you’re running snapshot runtime, then just go to PaperUI and uninstall the binding, wait 30 seconds and reinstall it again.

gismofx · September 1, 2017, 1:31pm

getting a little side-tracked:
I’ve attempted to upgrade from 2.1 stable to 2.2 snapshot. It looks like the I have the 2.2 zwave snapshot binding installed after the upgrade. No errors during the upgrade. I have some UI errors and also can’t seem to get to device discovery in paperUI:

Nothing happens after I select the Zwave binding

HABmin:
I tried in HABmin and the items list is empty. I receive an error when I click/switch from the things menu to the bindings menu. Switching to any other menu, I don’t get the error message. Also, the binding menu never populates with bindings :

chris · September 2, 2017, 11:23am

That’s correct - there’s nothing implemented here. What are you expecting to find?

There’s a bug in ESH that’s preventing this working. I think it was fixed yesterday so hopefully it will flow into the system today or tomorrow.

gismofx · September 2, 2017, 12:18pm

In the typical workflow in OH2.1, when trying to discover new devices(clicking the + button), the UI shows the lists of bindings and you must the select which binding to scan for new devices. In this case it should start scanning for zwave devices after selecting the zwave binding. For the record, when selecting any binding, nothing happens. I think it’s a PaperUI issue.

Anyway, I’d really like to try the updated zwave binding, but I’m not experienced enough with OH to work through the bugs in the snapshot release.(or maybe I just tried at the wrong moment and got a buggy snapshot). I tried downgrading back to 2.1 and something else got corrupted in the process. I’m going to start over with a fresh image/install of openhabian.

Is there a “clear” way I can pull the zwave binding into the stable release?

chris · September 2, 2017, 12:40pm

No - this interface just allows you to configure the binding, and ZWave has no configuration at binding level. I think you want to go to the inbox to do discovery.

As I said earlier, there’s a bug in ESH which should be fixed today (it was fixed yesterday, but it might take a day to flow through the downstream builds depending on what you’re using). You will need to use a snapshot after this is fixed.

It’s possible, but it needs to be done manually and is not especially simple - I would suggest to use the snapshot build once the error I mentioned above is fixed.

Rip_Van_Wookie · September 3, 2017, 3:16am

I have the same switch and had the same problem described in the first part of the thread. Thanks to this thread I have the fan speed controller working. Thank you very much for your contributions!

gismofx · September 8, 2017, 8:47pm

@chris Confirmed that it’s working now. I’m able to discover and operate the fan! Thank you for quickly resolving this! Also, the items menu bug in paperUI is fixed as well: https://github.com/eclipse/smarthome/issues/4179