How to mark as DEAD in order to delete an UNKNOWN node

[frixo3190]

Hi

I have a non fonctionnal node (node 184)
I've try many solution to delete him but don't manage !
Try to ping, not working, but never mark him as dead

Now it's stuck on 'protocol info' mode .

zwavejs_2024-01-09 (7).log

How can I force it to DEAD status in order to kill him et delete it

lot of trouble on my network because of this dead node.

On the driver log , you can see so many 'Failed to execute controller command after 2/3 attempts. Scheduling next try i
n 1100 ms.' because of it

what to do !!!!

[frixo3190]

node_184.json

[robertsLando]

Tried to use remove failed node?

[frixo3190]

Of course i've tried. But this fonction only works when the node is marked as Dead

[robertsLando]

cc @AlCalzone

[AlCalzone]

Hm it seems like the controller goes unresponsive and never really recovers. @robertsLando I think we talked about adding an option to disable all controller recovery mechanisms. If this exists, maybe enabling that option and waiting a longer time (10-15 minutes) before attempting to remove the node could help.

[frixo3190]

You believe it's possible to remove a non dead node ? On the button the text says only dead none could be remove

[AlCalzone]

It's not dead, because Z-Wave JS doesn't even get to ping it due to the controller locking up all the time, so it doesn't know its status.
My hope is that we can get past the problem by disabling the recovery and waiting, then using remove failed node will ping it and hopefully detect that it is dead.

[frixo3190]

Ok

Tomorrow I will try activate this option and delete this fucking node !

I will log all ...

[frixo3190]

Ok, I've done you test

it's doesn't work

the summury
8h48 : start network with the option 'disable controller recovery' activated and the log Info activated
=> the network restart, I'm just waiting doing nothing

I can see the interview of the node 184 is trying but failed "2024-01-10T08:51:28.809Z CNTRLR [Node 184] Interview attempt 2/5 failed, retrying in 10000 ms.."

still waiting, just waiting, doing nothing (but my Home probably doing few commands)
2024-01-10T08:53:07.355Z CNTRLR [Node 184] Interview attempt 4/5 failed, retrying in 20000 ms...

2024-01-10T08:54:10.447Z CNTRLR [Node 184] Failed all interview attempts, giving up.

8h56 : click on the button 'Failed node' on the node 184 in order to kill him as asked
2024-01-10T08:56:17.432Z CNTRLR » [Node 184] pinging the node...
2024-01-10T08:56:57.461Z CNTRLR [Node 184] ping failed: Timeout while waiting for a callback from the controll
er (ZW0200)
2024-01-10T08:56:58.479Z CNTRLR Failed to execute controller command after 1/3 attempts. Scheduling next try i
n 100 ms.
2024-01-10T08:56:59.588Z CNTRLR Failed to execute controller command after 2/3 attempts. Scheduling next try i
n 1100 ms.
2024-01-10T08:57:51.800Z DRIVER unexpected response, discarding...

The full log
zwavejs_2024-01-10 (4).log

The node 184 is still status 'Unknown'

[frixo3190]

New click on button 'failed node' on 184

2024-01-10T09:00:40.542Z CNTRLR « [Node 175] received wakeup notification
2024-01-10T09:00:40.569Z CNTRLR [Node 175] The node is now awake.
2024-01-10T09:00:40.831Z CNTRLR » [Node 175] Sending node back to sleep...
2024-01-10T09:00:40.879Z CNTRLR [Node 175] The node is now asleep.
2024-01-10T09:03:14.560Z CNTRLR » [Node 184] pinging the node...
2024-01-10T09:03:54.612Z CNTRLR [Node 184] ping failed: Timeout while waiting for a callback from the controll
er (ZW0200)
2024-01-10T09:03:55.636Z CNTRLR Failed to execute controller command after 1/3 attempts. Scheduling next try i
n 100 ms.
2024-01-10T09:03:56.747Z CNTRLR Failed to execute controller command after 2/3 attempts. Scheduling next try i
n 1100 ms.
2024-01-10T09:04:49.638Z DRIVER unexpected response, discarding...
2024-01-10T09:05:29.552Z CNTRLR Failed to execute controller command after 1/3 attempts. Scheduling next try i
n 100 ms.
2024-01-10T09:05:31.175Z DRIVER no handlers registered!
2024-01-10T09:06:04.340Z CNTRLR Failed to execute controller command after 1/3 attempts. Scheduling next try i
n 100 ms.
2024-01-10T09:06:05.203Z CNTRLR Failed to execute controller command after 1/3 attempts. Scheduling next try i
n 100 ms.
2024-01-10T09:10:09.299Z CNTRLR Failed to execute controller command after 1/3 attempts. Scheduling next try i
n 100 ms.
zwavejs_2024-01-10 (8).log

full log here :
zwavejs_2024-01-10 (8).log

[frixo3190]

Is it a bug ? Should I flag this post as a bug ?

[robertsLando]

Wait for @AlCalzone response

[frixo3190]

Well

I've started reading the code.

So , with the log I can say

The function removeFailedNode is called, then removeFailedNodeInternal

removeFailedNodeInternal first make a Find which must be FALSE , and my Ping is false

Then the message to remove the node is sent to the driver.

But the Driver can't manage to send the message, but in the log I just have the generic error , so 3 times it's try , and 3 times the driver don't manage to execute the message and no more information.

In order to know why the driver don't manage, I should have more log

[AlCalzone]

The log you posted is not on loglevel "debug", so it does not contain the reason for the command failures.

[frixo3190]

What, i'm sure I've put on débug

Ok I will retry

[frixo3190]

Do you
Ou speak about this ?

[frixo3190]

Or this

There is two debug option

In general or in Zwave

[AlCalzone]

The one in Z-Wave

[frixo3190]

Ok, you're right, this is the good debug Log

2024-01-12T06:59:41.994Z CNTRLR [Node 184] ping failed: Timeout while waiting for an ACK from the controller (
ZW0200)
2024-01-12T06:59:42.007Z SERIAL » 0x01050061b84b68 (7 bytes)
2024-01-12T06:59:42.009Z DRIVER » [REQ] [RemoveFailedNode]
payload: 0xb84b
2024-01-12T06:59:43.013Z CNTRLR Failed to execute controller command after 1/3 attempts. Scheduling next try i
n 100 ms.
2024-01-12T06:59:43.117Z DRIVER » [REQ] [RemoveFailedNode]
payload: 0xb84b
2024-01-12T06:59:43.118Z SERIAL » 0x01050061b84b68 (7 bytes)
2024-01-12T06:59:44.123Z CNTRLR Failed to execute controller command after 2/3 attempts. Scheduling next try i
n 1100 ms.
2024-01-12T06:59:45.226Z DRIVER » [REQ] [RemoveFailedNode]
payload: 0xb84b
2024-01-12T06:59:45.227Z SERIAL » 0x01050061b84b68 (7 bytes)
2024-01-12T06:59:46.240Z DRIVER all queues idle
2024-01-12T07:00:09.972Z DRIVER all queues busy

Full log
zwavejs_2024-01-12 (9).log

[frixo3190]

payload: 0xb84b

so why there is at the enb 4b ? (75 in base 10)

b8 => 184 (10)

so trying to search why....

this is the IsFailedNodeRequest

this is the serialise function on Message (Super of IsFailedNodeRequest)

In log we can see
2024-01-12T06:59:45.226Z DRIVER » [REQ] [RemoveFailedNode]
payload: 0xb84b
2024-01-12T06:59:45.227Z SERIAL » 0x01050061b84b68

0x01050061b84b68 : is the full message BUFFER , I beleive
0xb84b : is the IsFailedNodeRequest payload, so the trouble seem to be the node NodeIDType which must be 1 or 2 and is ... 4b

[kpine]

The node ID is encoded as a single byte when the controller uses 8-bit node IDs, and two bytes for 16-bit node IDs. The type is not part of the payload.

Your controller is using 8-bit node IDs, so:

0xb8 == node ID 184
0x4b == callback ID 75

You can see in the logs the prior and subsequent SendData commands with their callback IDs, NoOperationCC with callback 74 (0x4a) and MultilevelSwitchCCSet with callback 76 (0x4c).

[frixo3190]

Ooo ok, so I don't understand why the removeFailedNode failed !

[AlCalzone]

I don't understand why the removeFailedNode failed !

Here's where it starts:

2024-01-12T06:52:46.042Z DRIVER » [Node 184] [REQ] [SendData]
                                  │ transmit options: 0x25
                                  │ callback id:      54
                                  └─[NoOperationCC]
2024-01-12T06:52:46.043Z SERIAL » 0x01080013b8010025364e                                              (10 bytes)
2024-01-12T06:52:46.049Z SERIAL « [ACK]                                                                   (0x06)
2024-01-12T06:52:56.054Z SERIAL » 0x01030016ea                                                         (5 bytes)
2024-01-12T06:52:56.058Z DRIVER » [REQ] [SendDataAbort]
2024-01-12T06:53:16.058Z SERIAL » 0x01030016ea                                                         (5 bytes)
2024-01-12T06:53:16.061Z DRIVER » [REQ] [SendDataAbort]
2024-01-12T06:53:26.072Z CNTRLR   [Node 184] ping failed: Timeout while waiting for a callback from the controll
                                  er (ZW0200)

After issueing the SendData request, the controller should respond with a SendData response within a few milliseconds (a few seconds tops), then a few seconds later with a callback reporting how it went. This does not happen, and it does not even acknowledge the receipt of the SendDataAbort (notice there's no incoming ACK).
After that, the controller hangs completely and does not acknowledge any commands Z-Wave JS sends it.

In other words, the controller is hanging completely.

There are a few options that could help with this further:

gives the controller more time before aborting the transmission - this should only be temporary to try and solve this issue. If 30000 ms isn't enough, then increasing further is unlikely to help.

allows Z-Wave JS to try and restart the stick when it detects that it is hanging. In some VMs, this may cause the stick to disconnect though. Also, some older sticks are blacklisted from the functionality.

[frixo3190]

Ok

new try

zwavejs_2024-01-13 (7).log

2024-01-13T08:25:34.188Z CNTRLR [Node 184] ping failed: Timeout while waiting for an ACK from the controller (
ZW0200)

same trouble

retstarting with TimeOut 60000...

1rst try : nok
2, 3, 4, 5, 6...=> NOK

last try.... => OK !!!!!! Yataaaaa

So now I've a question : is it possible , only when the removeNodeFailed is launch to temporary put the timeout to the max ? I'm sure I'm note the only whith this trouble !

zwavejs_2024-01-13 (21).log

[frixo3190]

I want to really thanks you for your help and the time you spent reading my log

So thanks

And sorry for my poor English!