ZWave - AddNodeToNetwork - Newly included node already exists

So I am working on adding security support to the zwave binding, and part of my testing is to add a new node. I have 2 existing nodes: node 2 which is an appliance module and node 3 which is a door lock.

I am trying to include another door lock so I put the controller into include mode via habmin, then trigger the pairing process. But it looks like the new device is getting assigned node #2 which is already in use, this halts the pairing process with the message “Newly included node already exists”.

What can I do to make it use a node number that is not in use? I assume the number is assigned from the openhab code or the controller somehow.

I’ve attached the relevant snippit from my log

Thanks!
Dave

20:46:40.079 [TRACE] [veController$WatchDogTimerTask:1548 ] - Watchdog: Checking Serial threads
20:46:42.445 [TRACE] [.z.i.config.ZWaveConfiguration:883  ] - doAction domain 'binding/network/' to 'Include'
20:46:42.445 [DEBUG] [.b.z.i.p.s.AddNodeMessageClass:43   ] - Setting controller into INCLUSION mode.
20:46:42.446 [DEBUG] [o.b.z.i.protocol.SerialMessage:111  ] - NODE 255: Creating empty message of class = AddNodeToNetwork (0x4A), type = Request (0x00)
20:46:42.446 [DEBUG] [b.z.i.protocol.ZWaveController:598  ] - Enqueueing message. Queue length = 1
20:46:42.446 [DEBUG] [WaveController$ZWaveSendThread:1207 ] - Took message from queue for sending. Queue length = 0
20:46:42.447 [INFO ] [b.z.i.protocol.ZWaveController:800  ] - Starting inclusion mode
20:46:42.447 [TRACE] [o.b.z.i.protocol.SerialMessage:181  ] - Calculated checksum = 0xCE
20:46:42.447 [DEBUG] [o.b.z.i.protocol.SerialMessage:235  ] - Assembled message buffer = 01 05 00 4A 81 FF CE 
20:46:42.447 [DEBUG] [WaveController$ZWaveSendThread:1264 ] - NODE 255: Sending REQUEST Message = 01 05 00 4A 81 FF CE 
20:46:42.448 [TRACE] [WaveController$ZWaveSendThread:1270 ] - Message SENT
20:46:42.449 [TRACE] [eController$ZWaveReceiveThread:1486 ] - Received ACK
20:46:42.451 [DEBUG] [eController$ZWaveReceiveThread:1481 ] - Receive Message = 01 07 00 4A FF 01 00 00 4C 
20:46:42.451 [TRACE] [o.b.z.i.protocol.SerialMessage:138  ] - NODE 255: Creating new SerialMessage from buffer = 01 07 00 4A FF 01 00 00 4C 
20:46:42.451 [TRACE] [o.b.z.i.protocol.SerialMessage:181  ] - Calculated checksum = 0x4C
20:46:42.451 [TRACE] [o.b.z.i.protocol.SerialMessage:143  ] - NODE 255: Checksum matched
20:46:42.451 [TRACE] [o.b.z.i.protocol.SerialMessage:155  ] - NODE 255: Message payload = FF 01 00 00 
20:46:42.452 [TRACE] [eController$ZWaveReceiveThread:1390 ] - Message is valid, sending ACK
20:46:42.452 [TRACE] [eController$ZWaveReceiveThread:1375 ] - Response SENT
20:46:42.452 [DEBUG] [eController$ZWaveReceiveThread:1405 ] - Receive queue ADD: Length=1
20:46:42.452 [DEBUG] [b.z.i.protocol.ZWaveController:1154 ] - Receive queue TAKE: Length=0
20:46:42.453 [TRACE] [o.b.z.i.protocol.SerialMessage:181  ] - Calculated checksum = 0x4C
20:46:42.453 [DEBUG] [o.b.z.i.protocol.SerialMessage:235  ] - Assembled message buffer = 01 07 00 4A FF 01 00 00 4C 
20:46:42.453 [DEBUG] [b.z.i.protocol.ZWaveController:1155 ] - Process Message = 01 07 00 4A FF 01 00 00 4C 
20:46:42.453 [DEBUG] [b.z.i.protocol.ZWaveController:197  ] - Message: class = AddNodeToNetwork (0x4A), type = Request (0x00), payload = FF 01 00 00 , callback id = 0
20:46:42.453 [TRACE] [b.z.i.protocol.ZWaveController:217  ] - Incoming Message type = REQUEST
20:46:42.453 [DEBUG] [.b.z.i.p.s.AddNodeMessageClass:72   ] - Add Node: Learn ready.
20:46:42.454 [DEBUG] [b.z.i.protocol.ZWaveController:613  ] - NODE 255: Notifying event listeners: ZWaveInclusionEvent: ZWaveInclusionEvent [type=IncludeStart, occurred 0ms ago, getNodeId()=255, getEndpoint()=0]
20:46:42.454 [DEBUG] [.z.internal.ZWaveActiveBinding:443  ] - ZwaveIncomingEvent
20:46:42.454 [DEBUG] [b.z.i.protocol.ZWaveController:624  ] - NODE 255: Processing event ourselves
20:46:42.454 [DEBUG] [.z.i.p.s.ZWaveCommandProcessor:63   ] - Sent message Message: class = AddNodeToNetwork (0x4A), type = Request (0x00), payload = 81 FF , callback id = 0
20:46:42.455 [DEBUG] [.z.i.p.s.ZWaveCommandProcessor:64   ] - Recv message Message: class = AddNodeToNetwork (0x4A), type = Request (0x00), payload = FF 01 00 00 , callback id = 0
20:46:42.455 [DEBUG] [.z.i.p.s.ZWaveCommandProcessor:67   ] - Checking transaction complete: class=AddNodeToNetwork, expected=AddNodeToNetwork, cancelled=false        transaction complete!
20:46:42.455 [DEBUG] [b.z.i.protocol.ZWaveController:613  ] - NODE 255: Notifying event listeners: ZWaveTransactionCompletedEvent: ZWaveTransactionCompletedEvent [completedMessage=Message: class = AddNodeToNetwork (0x4A), type = Request (0x00), payload = 81 FF , callback id = 0, state=true]
20:46:42.455 [DEBUG] [.z.internal.ZWaveActiveBinding:443  ] - ZwaveIncomingEvent
20:46:42.456 [DEBUG] [b.z.i.protocol.ZWaveController:624  ] - NODE 255: Processing event ourselves
20:46:42.456 [TRACE] [b.z.i.protocol.ZWaveController:232  ] - Released. Transaction completed permit count -> 1
20:46:42.456 [DEBUG] [WaveController$ZWaveSendThread:1323 ] - NODE 255: Response processed after 8ms/3699ms.
20:46:42.456 [TRACE] [WaveController$ZWaveSendThread:1324 ] - Acquired. Transaction completed permit count -> 0
20:46:50.080 [TRACE] [veController$WatchDogTimerTask:1548 ] - Watchdog: Checking Serial threads
20:46:55.585 [DEBUG] [eController$ZWaveReceiveThread:1481 ] - Receive Message = 01 0D 00 4A FF 02 02 06 04 40 03 72 86 98 6A 
20:46:55.586 [TRACE] [o.b.z.i.protocol.SerialMessage:138  ] - NODE 255: Creating new SerialMessage from buffer = 01 0D 00 4A FF 02 02 06 04 40 03 72 86 98 6A 
20:46:55.587 [TRACE] [o.b.z.i.protocol.SerialMessage:181  ] - Calculated checksum = 0x6A
20:46:55.587 [TRACE] [o.b.z.i.protocol.SerialMessage:143  ] - NODE 255: Checksum matched
20:46:55.588 [TRACE] [o.b.z.i.protocol.SerialMessage:155  ] - NODE 255: Message payload = FF 02 02 06 04 40 03 72 86 98 
20:46:55.589 [TRACE] [eController$ZWaveReceiveThread:1390 ] - Message is valid, sending ACK
20:46:55.590 [TRACE] [eController$ZWaveReceiveThread:1375 ] - Response SENT
20:46:55.590 [DEBUG] [eController$ZWaveReceiveThread:1405 ] - Receive queue ADD: Length=1
20:46:55.590 [DEBUG] [b.z.i.protocol.ZWaveController:1154 ] - Receive queue TAKE: Length=0
20:46:55.591 [TRACE] [o.b.z.i.protocol.SerialMessage:181  ] - Calculated checksum = 0x6A
20:46:55.592 [DEBUG] [o.b.z.i.protocol.SerialMessage:235  ] - Assembled message buffer = 01 0D 00 4A FF 02 02 06 04 40 03 72 86 98 6A 
20:46:55.593 [DEBUG] [b.z.i.protocol.ZWaveController:1155 ] - Process Message = 01 0D 00 4A FF 02 02 06 04 40 03 72 86 98 6A 
20:46:55.593 [DEBUG] [b.z.i.protocol.ZWaveController:197  ] - Message: class = AddNodeToNetwork (0x4A), type = Request (0x00), payload = FF 02 02 06 04 40 03 72 86 98 , callback id = 0
20:46:55.594 [TRACE] [b.z.i.protocol.ZWaveController:217  ] - Incoming Message type = REQUEST
20:46:55.595 [DEBUG] [.b.z.i.p.s.AddNodeMessageClass:76   ] - Add Node: New node found.
20:46:55.595 [DEBUG] [.z.i.p.s.ZWaveCommandProcessor:63   ] - Sent message Message: class = AddNodeToNetwork (0x4A), type = Request (0x00), payload = 81 FF , callback id = 0
20:46:55.596 [DEBUG] [.z.i.p.s.ZWaveCommandProcessor:64   ] - Recv message Message: class = AddNodeToNetwork (0x4A), type = Request (0x00), payload = FF 02 02 06 04 40 03 72 86 98 , callback id = 0
20:46:55.597 [DEBUG] [.z.i.p.s.ZWaveCommandProcessor:67   ] - Checking transaction complete: class=AddNodeToNetwork, expected=AddNodeToNetwork, cancelled=false        transaction complete!
20:46:55.598 [DEBUG] [b.z.i.protocol.ZWaveController:613  ] - NODE 255: Notifying event listeners: ZWaveTransactionCompletedEvent: ZWaveTransactionCompletedEvent [completedMessage=Message: class = AddNodeToNetwork (0x4A), type = Request (0x00), payload = 81 FF , callback id = 0, state=true]
20:46:55.599 [DEBUG] [.z.internal.ZWaveActiveBinding:443  ] - ZwaveIncomingEvent
20:46:55.600 [DEBUG] [b.z.i.protocol.ZWaveController:624  ] - NODE 255: Processing event ourselves
20:46:55.600 [TRACE] [b.z.i.protocol.ZWaveController:232  ] - Released. Transaction completed permit count -> 1
20:46:55.601 [DEBUG] [eController$ZWaveReceiveThread:1481 ] - Receive Message = 01 0D 00 4A FF 03 02 06 04 40 03 72 86 98 6B 
20:46:55.602 [TRACE] [o.b.z.i.protocol.SerialMessage:138  ] - NODE 255: Creating new SerialMessage from buffer = 01 0D 00 4A FF 03 02 06 04 40 03 72 86 98 6B 
20:46:55.603 [TRACE] [o.b.z.i.protocol.SerialMessage:181  ] - Calculated checksum = 0x6B
20:46:55.603 [TRACE] [o.b.z.i.protocol.SerialMessage:143  ] - NODE 255: Checksum matched
20:46:55.604 [TRACE] [o.b.z.i.protocol.SerialMessage:155  ] - NODE 255: Message payload = FF 03 02 06 04 40 03 72 86 98 
20:46:55.605 [TRACE] [eController$ZWaveReceiveThread:1390 ] - Message is valid, sending ACK
20:46:55.606 [TRACE] [eController$ZWaveReceiveThread:1375 ] - Response SENT
20:46:55.606 [DEBUG] [eController$ZWaveReceiveThread:1405 ] - Receive queue ADD: Length=1
20:46:55.606 [DEBUG] [b.z.i.protocol.ZWaveController:1154 ] - Receive queue TAKE: Length=0
20:46:55.607 [TRACE] [o.b.z.i.protocol.SerialMessage:181  ] - Calculated checksum = 0x6B
20:46:55.608 [DEBUG] [o.b.z.i.protocol.SerialMessage:235  ] - Assembled message buffer = 01 0D 00 4A FF 03 02 06 04 40 03 72 86 98 6B 
20:46:55.608 [DEBUG] [b.z.i.protocol.ZWaveController:1155 ] - Process Message = 01 0D 00 4A FF 03 02 06 04 40 03 72 86 98 6B 
20:46:55.609 [DEBUG] [b.z.i.protocol.ZWaveController:197  ] - Message: class = AddNodeToNetwork (0x4A), type = Request (0x00), payload = FF 03 02 06 04 40 03 72 86 98 , callback id = 0
20:46:55.610 [TRACE] [b.z.i.protocol.ZWaveController:217  ] - Incoming Message type = REQUEST
20:46:55.611 [DEBUG] [.b.z.i.p.s.AddNodeMessageClass:79   ] - NODE 2: Adding slave.
20:46:55.611 [DEBUG] [b.z.i.protocol.ZWaveController:613  ] - NODE 2: Notifying event listeners: ZWaveInclusionEvent: ZWaveInclusionEvent [type=IncludeSlaveFound, occurred 0ms ago, getNodeId()=2, getEndpoint()=0]
20:46:55.612 [DEBUG] [.z.internal.ZWaveActiveBinding:443  ] - ZwaveIncomingEvent
20:46:55.612 [DEBUG] [b.z.i.protocol.ZWaveController:624  ] - NODE 2: Processing event ourselves
20:46:55.613 [DEBUG] [b.z.i.protocol.ZWaveController:632  ] - NODE 2: Including node.
20:46:55.614 [DEBUG] [b.z.i.protocol.ZWaveController:635  ] - NODE 2: Newly included node already exists - not initialising.

@chris and @dbadia Am i mistaken in thinking that the node ID is assigned by the controller? I am refering to the wili entry at https://github.com/cdjackson/HABmin/wiki/ZWave-SUC-Controller-Mode
The aeon ZStick controller is supposed to be a static controller and should it also be enabled as SUC in the binding config?

No - you are not mistaken. The controller assigns the ID when the device is included.