Add node fail

jr555se · September 29, 2019, 10:10pm

Hi!

I have moved my stuff from an old and trusty LMCE integration.

I am running the HA in Docker and usb controller is the one from my old setup “seluxit viasens 100”*
All my zwave nodes was found almost. I had to do “add node” on one or more of them and then Heal to get them working. Never really looked at the log to deep until now.

I am trying to get more devices added, same manufacturer as the ones already installed(bought all at the same time loooong time ago) but never used.

Though when I look at the log it seems that the usb controller doesn’t even get the request?
Honestly I do not know if this has been like this from the start… never really looked closely at the log and hunted for the “Learn” …

*Funny thing is that when I do a remove node it replies and waits for the node to speak *

Here is how it looks when doing “add”

2019-09-29 15:37:27.069 Detail, Queuing (Controller) Add Device
2019-09-29 15:37:27.069 Info, Add Device
2019-09-29 15:37:27.070 Detail, contrlr, Queuing (Command) ControllerCommand_AddDevice: 0x01, 0x05, 0x00, 0x4a, 0x81, 0xe2, 0xd3
2019-09-29 15:37:27.070 Detail, Notification: ControllerCommand - Starting
2019-09-29 15:37:27.071 Detail,
2019-09-29 15:37:27.072 Info, contrlr, Sending (Command) message (Callback ID=0xe2, Expected Reply=0x4a) - ControllerCommand_AddDevice: 0x01, 0x05, 0x00, 0x4a, 0x81, 0xe2, 0xd3
2019-09-29 15:37:27.074 Detail, contrlr,   Received: 0x01, 0x07, 0x00, 0x4a, 0xe2, 0x07, 0x00, 0x00, 0x57
2019-09-29 15:37:27.075 Detail,
2019-09-29 15:37:27.075 Info, contrlr, FUNC_ID_ZW_ADD_NODE_TO_NETWORK:
2019-09-29 15:37:27.075 Info, contrlr, ADD_NODE_STATUS_FAILED
2019-09-29 15:37:27.075 Detail, contrlr, Removing current message
2019-09-29 15:37:27.075 Detail, contrlr, Queuing (Command) Add Node Stop: 0x01, 0x04, 0x00, 0x4a, 0x05, 0xb4
2019-09-29 15:37:27.075 Detail, Notification: ControllerCommand - Failed
2019-09-29 15:37:27.077 Detail,
2019-09-29 15:37:27.077 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x00) - Add Node Stop: 0x01, 0x04, 0x00, 0x4a, 0x05, 0xb4
2019-09-29 15:37:27.078 Detail, contrlr, Removing current message

and the remove:

2019-09-29 15:36:40.866 Detail, Queuing (Controller) Remove Device
2019-09-29 15:36:40.866 Info, Remove Device
2019-09-29 15:36:40.867 Detail, contrlr, Queuing (Command) ControllerCommand_RemoveDevice: 0x01, 0x05, 0x00, 0x4b, 0x81, 0xe1, 0xd1
2019-09-29 15:36:40.867 Detail, Notification: ControllerCommand - Starting
2019-09-29 15:36:40.869 Detail,
2019-09-29 15:36:40.870 Info, contrlr, Sending (Command) message (Callback ID=0xe1, Expected Reply=0x4b) - ControllerCommand_RemoveDevice: 0x01, 0x05, 0x00, 0x4b, 0x81, 0xe1, 0xd1
2019-09-29 15:36:40.874 Detail, contrlr,   Received: 0x01, 0x07, 0x00, 0x4b, 0xe1, 0x01, 0x00, 0x00, 0x53
2019-09-29 15:36:40.875 Detail,
2019-09-29 15:36:40.875 Info, FUNC_ID_ZW_REMOVE_NODE_FROM_NETWORK:
2019-09-29 15:36:40.875 Info, REMOVE_NODE_STATUS_LEARN_READY
2019-09-29 15:36:40.876 Detail, Node001,   Expected callbackId was received
2019-09-29 15:36:40.876 Detail, Node001,   Expected reply was received
2019-09-29 15:36:40.876 Detail, Node001,   Message transaction complete
2019-09-29 15:36:40.877 Detail,
2019-09-29 15:36:40.877 Detail, contrlr, Removing current message
2019-09-29 15:36:40.877 Detail, Notification: ControllerCommand - Waiting
2019-09-29 15:36:40.880 Info, WriteNextMsg Controller nothing to do

Now what puzzles me is that my USB controller is node 002, and from what I can see in HA the node 001 is still in initializing state and sort of seem dead.
Controlling everything however is working fine… Can anyone lead me forward to troubleshooting this as I am running out of ideas

snippet from the start of the network:

2019-09-28 17:37:16.053 Info, contrlr, Received reply to FUNC_ID_ZW_GET_VERSION:
2019-09-28 17:37:16.053 Info, contrlr,     Static Controller library, version Z-Wave 2.40
2019-09-28 17:37:16.053 Detail, Node045,   Expected reply was received
2019-09-28 17:37:16.053 Detail, Node045,   Message transaction complete
2019-09-28 17:37:16.053 Detail,
2019-09-28 17:37:16.053 Detail, contrlr, Removing current message
2019-09-28 17:37:16.053 Detail,
2019-09-28 17:37:16.053 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x20) - FUNC_ID_ZW_MEMORY_GET_ID: 0x01, 0x03, 0x00, 0x20, 0xdc
2019-09-28 17:37:16.058 Detail, contrlr,   Received: 0x01, 0x08, 0x01, 0x20, 0x00, 0x00, 0x00, 0x10, 0x02, 0xc4
2019-09-28 17:37:16.058 Detail,
2019-09-28 17:37:16.058 Info, contrlr, Received reply to FUNC_ID_ZW_MEMORY_GET_ID. Home ID = 0x00000010.  Our node ID = 2
2019-09-28 17:37:16.062 Detail,   Expected reply was received
2019-09-28 17:37:16.062 Detail,   Message transaction complete
2019-09-28 17:37:16.062 Detail,
2019-09-28 17:37:16.062 Detail, contrlr, Removing current message
2019-09-28 17:37:16.063 Detail,
2019-09-28 17:37:16.063 Info, contrlr, Sending (Command) message (Callback ID=0x00, Expected Reply=0x05) - FUNC_ID_ZW_GET_CONTROLLER_CAPABILITIES: 0x01, 0x03, 0x00, 0x05, 0xf9
2019-09-28 17:37:16.065 Detail, contrlr,   Received: 0x01, 0x04, 0x01, 0x05, 0x06, 0xf9
2019-09-28 17:37:16.065 Detail,
2019-09-28 17:37:16.066 Info, contrlr, Received reply to FUNC_ID_ZW_GET_CONTROLLER_CAPABILITIES:
2019-09-28 17:37:16.066 Info, contrlr,     There is a SUC ID Server (SIS) in this network.
2019-09-28 17:37:16.066 Info, contrlr,     The PC controller is an inclusion controller which is using a Home ID from another network.
2019-09-28 17:37:16.066 Detail, Node249,   Expected reply was received
2019-09-28 17:37:16.067 Detail, Node249,   Message transaction complete
2019-09-28 17:37:16.067 Detail,
2019-09-28 17:37:16.067 Detail, contrlr, Removing current message

Best Regards
Johan

ski522 · September 30, 2019, 12:06pm

I had this problem with device that were already included in a prior network…have you tried to factory reset the devices, then try to include?

jr555se · September 30, 2019, 12:28pm

The new device that I try to include is never used and I did factory reset it while trying. Though when looking at the Controller output, the time it takes for it to reply fail is Instant and it never enters the “Learning” phase. Almost like it either does not respond and it’s the ozw process that fails. Or like the controller replies but with failure directly.

My fear is that if I try to remove everything including the controller and start from scratch maybe the controller will still reply with failure as it could be some compability issue with the command as such that it’s being sent that it simply does not like or?

-Johan

ski522 · October 1, 2019, 12:39pm

I don’t believe you mention what type of device you’re trying to include, but if it’s battery powered (and you mention long time ago you got it) then I’d try replacing the battery…weak batteries will certainly cause problems.

The other problem is the node might be too far from the controller…I don’t believe Z-Wave will repeat devices until it’s part of the mesh network. I know I had a door lock that was far away from my controller and was a bit temperamental to include…took me about 3 tries…it’s fine now that it’s part of my mesh Z-wave network.

jr555se · October 1, 2019, 1:16pm

True, I forgot that, though I don’t think the node to be included matters as it seems my controller justs borks out or its inside HA.(look at the times and the lack of “Learn”)

However what I try to include is schneider electrics dimmable thing(device that is installed inside the wall under the normal switch(feathered)
It is not battery controlled and I have already a few of these already added but then they where also in use in the old integration. They get registered as “merten” something.

Is it possible to debug the usb message to see if it is the controller replying or if its the process as such?

-Johan