Inclusion fails: DRIVER no handlers registered!

devanl commented 2 years ago

Is your problem within Home Assistant (Core or Z-Wave JS Integration)?

NO, my problem is NOT within Home Assistant or the ZWave JS integration

Is your problem within Z-Wave JS UI (formerly ZwaveJS2MQTT)?

NO, my problem is NOT within Z-Wave JS UI

Checklist

[X] I have checked the troubleshooting section and my problem is not described there.
[X] I have read the changelog and my problem was not mentioned there.

Describe the bug

What causes the bug?

SmartStart provisioned device failing to be included in network

What do you observe?

Partially added node is failed and lights repeatedly flicker until I disable provisioning.

What did you expect to happen?

node gets added

Steps to reproduce the behavior:

Go to 'watch debug console after provisioning device'

Device information

Controller: Manufacturer: Zooz
Model name: ZST10-700 Node ID in your network: 1 FW: v7.17.2

Device: Manufacturer: Zooz
Model name: ZEN77 V3.0

How are you using `node-zwave-js`?

[ ] zwave-js-ui (formerly zwavejs2mqtt) Docker image (latest)
[ ] zwave-js-ui (formerly zwavejs2mqtt) Docker image (dev)
[ ] zwave-js-ui (formerly zwavejs2mqtt) Docker manually built (please specify branches)
[ ] ioBroker.zwave2 adapter (please specify version)
[ ] HomeAssistant zwave_js integration (please specify version)
[ ] pkg
[ ] node-red-contrib-zwave-js (please specify version, double click node to find out)
[ ] Manually built from GitHub (please specify branch)
[X] Other (please describe)

Which branches or versions?

HA standalone addon 1.2.0 version: zwave-js-ui: 8.2.1 zwave-js: 10.3.0

Did you change anything?

no

If yes, what did you change?

No response

Did this work before?

Don't know, this is a new device

If yes, where did it work?

No response

Attach Driver Logfile

2022-11-02T00:45:52.308Z CNTRLR   Enabling Smart Start listening mode...
2022-11-02T00:45:52.313Z DRIVER       the message was handled
2022-11-02T00:45:52.316Z SERIAL » 0x0105004a4900f9                                                     (7 bytes)
2022-11-02T00:45:52.317Z DRIVER » [REQ] [AddNodeToNetwork]
                                    action: Enable Smart Start listening mode
2022-11-02T00:45:52.321Z SERIAL « [ACK]                                                                   (0x06)
2022-11-02T00:45:52.329Z CNTRLR   Smart Start listening mode enabled
2022-11-02T00:46:25.550Z SERIAL « 0x011e0049850018c98dfa26100411015e26705b858e595586725a87739f6c7a2e  (32 bytes)
2022-11-02T00:46:25.553Z SERIAL » [ACK]                                                                   (0x06)
2022-11-02T00:46:25.558Z DRIVER « [REQ] [ApplicationUpdateRequest]
                                    type:                  SmartStart_HomeId_Received
                                    remote node ID:        0
                                    NWI home ID:           0xc98dfa26
                                    basic device class:    4
                                    generic device class:  17
                                    specific device class: 1
                                    supported CCs:
                                    · Z-Wave Plus Info
                                    · Multilevel Switch
                                    · Configuration
                                    · Central Scene
                                    · Association
                                    · Multi Channel Association
                                    · Association Group Information
                                    · Transport Service
                                    · Version
                                    · Manufacturer Specific
                                    · Device Reset Locally
                                    · Indicator
                                    · Powerlevel
                                    · Security 2
                                    · Supervision
                                    · Firmware Update Meta Data
2022-11-02T00:46:25.562Z CNTRLR   Received Smart Start inclusion request
2022-11-02T00:46:25.563Z CNTRLR   NWI Home ID found in provisioning list, including node...
2022-11-02T00:46:25.563Z CNTRLR   Including SmartStart node with DSK 07998-27769-14313-19606-18829-64038-10964-4
                                  0372
2022-11-02T00:46:25.574Z SERIAL » 0x010d004ac899c98dfa262ad49db5a7                                    (15 bytes)
2022-11-02T00:46:25.575Z DRIVER » [REQ] [AddNodeToNetwork]
                                    action:       Add Smart Start node
                                    NWI Home ID:  0xc98dfa26
                                    high power:   true
                                    network wide: true
                                    callback id:  153
2022-11-02T00:46:25.580Z SERIAL « [ACK]                                                                   (0x06)
2022-11-02T00:46:25.584Z SERIAL « 0x0107004a990100002a                                                 (9 bytes)
2022-11-02T00:46:25.584Z SERIAL » [ACK]                                                                   (0x06)
2022-11-02T00:46:25.589Z DRIVER     no handlers registered!
2022-11-02T00:46:25.592Z DRIVER « [REQ] [AddNodeToNetwork]
                                    status:      Ready
                                    callback id: 153
2022-11-02T00:46:25.597Z DRIVER   handling request AddNodeToNetwork (74)
2022-11-02T00:46:25.598Z DRIVER     1 handler registered!
2022-11-02T00:46:25.598Z DRIVER     invoking handler #0
2022-11-02T00:46:25.598Z CNTRLR   handling add node request (status = Ready)
2022-11-02T00:46:26.382Z SERIAL « 0x012400a814ff001bc96279f70127d39c0111015e26705b858e595586725a87739 (38 bytes)
                                  f6c7a00dc85
2022-11-02T00:46:26.384Z DRIVER   Dropping message because it could not be deserialized: The command class unkno
                                  wn (0xc9) is not implemented (ZW0303)
2022-11-02T00:46:26.385Z SERIAL » [ACK]                                                                   (0x06)
2022-11-02T00:46:26.852Z SERIAL « 0x012400a814ff001bc96279f70127d39c0111015e26705b858e595586725a87739 (38 bytes)
                                  f6c7a00de87
2022-11-02T00:46:26.854Z DRIVER   Dropping message because it could not be deserialized: The command class unkno
                                  wn (0xc9) is not implemented (ZW0303)
2022-11-02T00:46:26.854Z SERIAL » [ACK]                                                                   (0x06)
2022-11-02T00:46:27.136Z SERIAL « 0x012400a814ff001bc96279f70127d39c0111015e26705b858e595586725a87739 (38 bytes)
                                  f6c7a00d48d
2022-11-02T00:46:27.137Z DRIVER   Dropping message because it could not be deserialized: The command class unkno
                                  wn (0xc9) is not implemented (ZW0303)
2022-11-02T00:46:27.137Z SERIAL » [ACK]                                                                   (0x06)
2022-11-02T00:46:29.655Z SERIAL « 0x0107004a9902000029                                                 (9 bytes)
2022-11-02T00:46:29.657Z SERIAL » [ACK]                                                                   (0x06)
2022-11-02T00:46:29.665Z DRIVER « [REQ] [AddNodeToNetwork]
                                    status:      NodeFound
                                    callback id: 153
2022-11-02T00:46:29.669Z DRIVER   handling request AddNodeToNetwork (74)
2022-11-02T00:46:29.670Z DRIVER     1 handler registered!
2022-11-02T00:46:29.670Z DRIVER     invoking handler #0
2022-11-02T00:46:29.670Z CNTRLR   handling add node request (status = NodeFound)
2022-11-02T00:46:31.414Z SERIAL « 0x0107004a990742006e                                                 (9 bytes)
2022-11-02T00:46:31.417Z SERIAL » [ACK]                                                                   (0x06)
2022-11-02T00:46:31.424Z DRIVER « [REQ] [AddNodeToNetwork]
                                    status:      Failed
                                    callback id: 153
2022-11-02T00:46:31.426Z DRIVER   handling request AddNodeToNetwork (74)
2022-11-02T00:46:31.427Z DRIVER     1 handler registered!
2022-11-02T00:46:31.432Z DRIVER     invoking handler #0
2022-11-02T00:46:31.432Z CNTRLR   handling add node request (status = Failed)
2022-11-02T00:46:31.433Z CNTRLR   Adding the node failed
2022-11-02T00:46:31.440Z CNTRLR   stopping inclusion process...
2022-11-02T00:46:31.454Z SERIAL » 0x0105004ac59aef                                                     (7 bytes)
2022-11-02T00:46:31.455Z DRIVER » [REQ] [AddNodeToNetwork]
                                    action:       Stop
                                    high power:   true
                                    network wide: true
                                    callback id:  154
2022-11-02T00:46:31.462Z SERIAL « [ACK]                                                                   (0x06)
2022-11-02T00:46:31.466Z SERIAL « 0x0107004a9a0642006c                                                 (9 bytes)
2022-11-02T00:46:31.468Z SERIAL » [ACK]                                                                   (0x06)
2022-11-02T00:46:31.469Z DRIVER « [REQ] [AddNodeToNetwork]
                                    status:      Done
                                    callback id: 154
2022-11-02T00:46:31.473Z CNTRLR   The inclusion process was stopped
2022-11-02T00:46:31.479Z CNTRLR   Enabling Smart Start listening mode...
2022-11-02T00:46:31.487Z DRIVER       the message was handled
2022-11-02T00:46:31.491Z SERIAL » 0x0105004a4900f9                                                     (7 bytes)
2022-11-02T00:46:31.492Z DRIVER » [REQ] [AddNodeToNetwork]
                                    action: Enable Smart Start listening mode
2022-11-02T00:46:31.496Z SERIAL « [ACK]                                                                   (0x06)
2022-11-02T00:46:31.501Z CNTRLR   Smart Start listening mode enabled

zwave-js-bot commented 2 years ago

👋 Hey @devanl!

It looks like you copied the contents of a logfile. Please attach it as a file instead, so it is easier to work with. Note: You can just drag & drop files into the textbox. Just make sure to use a supported file extension like .log or .txt

AlCalzone commented 2 years ago

The problem is this


2022-11-02T00:46:31.424Z DRIVER « [REQ] [AddNodeToNetwork]
                                    status:      Failed
                                    callback id: 153

Which means the stick failed to communicate and exchange all necessary inclusion commands with the node. Make sure to follow the instructions for controller placement here: https://zwave-js.github.io/node-zwave-js/#/troubleshooting/connectivity-issues?id=general-troubleshooting This is usually the issue when inclusion fails.

devanl commented 2 years ago

I removed the failed node (exclusion did not work for this) and then retried after adding a new device in-between. The inclusion succeeded. A problem I would point out here is that before this happened I was at node 22 and now I appear to be at node 74.

Is there something getting cleaned up too early that results in us thrashing (ie "no handlers registered!")?

Thank you for reviewing this

AlCalzone commented 2 years ago

Maybe but I won't be able to investigate until January.

zwave-js / node-zwave-js