fix: better node initialization #240

robertsLando · 2021-01-14T16:35:33Z

Fixes #217
Fixes #256

Fixes #217

robertsLando · 2021-01-14T17:06:19Z

@ahochsteger could you give this a try?

coveralls · 2021-01-17T13:26:30Z

Pull Request Test Coverage Report for Build 493662310

0 of 35 (0.0%) changed or added relevant lines in 1 file are covered.
No unchanged relevant lines lost coverage.
Overall coverage decreased (-0.04%) to 23.603%

Changes Missing Coverage	Covered Lines	Changed/Added Lines	%
lib/ZwaveClient.js	0	35	0.0%

Totals
Change from base Build 491605456:	-0.04%
Covered Lines:	1957
Relevant Lines:	8470

💛 - Coveralls

ahochsteger · 2021-01-17T19:49:00Z

@robertsLando I just tried out this branch with your changes.

Unfortunately it happened again that a battery-powered device (Fibaro Button) results in an "Unknown manufacturer" / "Unknown product", even though zwave-js was able to detect the manufacturer after a "Refresh info":

Here are the full logs:
zwavejs2mqtt.log
zwavejs_63428.log

I suspect that the problem lies in the fact that if a battery-powered device cannot be fully initialized, zwave-js will eventually set the node to ready without knowing the manufacturer and product.
When a full "Refresh info" is done at some time later zwave-js correctly updates the missing manufacturer / product data and even zwavejs2mqtt recognizes them but it seems that manufacturer and product are not updated in the UI.

Here are the relevant parts of the logfiles from above:

...
# zwave-js: Ping failed on sleeping device
14:37:15.715 CNTRLR   [Node 013] ping failed: The node is asleep
14:37:15.715 CNTRLR » [Node 013] querying node info...
...
# zwave-js: NodeInfo stage completes (failed):
15:12:22.635 CNTRLR   [Node 013] querying the node info failed
15:12:22.643 CNTRLR   [Node 013] Interview stage completed: NodeInfo
15:12:22.643 CNTRLR   [Node 013] WakeUpCC: doing a complete interview...
15:12:22.644 CNTRLR » [Node 013] retrieving wakeup interval from the device...
...
# Button is pressed on the device:
2021-01-17 15:34:42.494 INFO ZWAVE: Node 13: value added: 113-0-Home Security-Sensor status => 2
2021-01-17 15:34:42.554 INFO ZWAVE: Node 13: metadata updated: 91-0-scene-001
2021-01-17 15:34:42.561 INFO ZWAVE: Node 13: value notification: 91-0-scene-001 0
...
# zwave-js signals that the node is now ready to be used (although no manufacturer id and product id is known):
15:59:30.756 CNTRLR   [Node 013] Interview completed
15:59:30.779 CNTRLR   [Node 013] The node is ready to be used
2021-01-17 15:59:30.542 INFO ZWAVE: Node 13: value added: 132-0-wakeUpInterval => 3600
2021-01-17 15:59:30.542 INFO ZWAVE: Node 13: value added: 132-0-controllerNodeId => 1
2021-01-17 15:59:30.743 INFO ZWAVE: Node 13: value updated: 132-0-wakeUpInterval 3600 => 3600
2021-01-17 15:59:30.745 INFO ZWAVE: Node 13: value updated: 132-0-controllerNodeId 1 => 1
2021-01-17 15:59:30.779 DEBUG GATEWAY: Publishing discovery: {
  type: 'sensor',
  object_id: 'scene_state_001_scene',
  discovery_payload: {
    state_topic: 'zwavejs2mqtt/nodeID_13/91/0/scene/001',
    value_template: '{{ value_json.value}}',
    json_attributes_topic: 'zwavejs2mqtt/nodeID_13/91/0/scene/001',
    device: {
      identifiers: [ 'zwavejs2mqtt_0xcb10ff7c_node13', [length]: 1 ],
      manufacturer: 'Unknown manufacturer undefined',
      model: 'undefined (Unknown product undefined)',
      name: 'nodeID_13',
      sw_version: '1.0.0-beta.0'
    },
    name: 'nodeID_13_scene_state_001_scene',
    unique_id: 'zwavejs2mqtt_0xcb10ff7c_13-91-0-scene-001'
  },
  discoveryTopic: 'sensor/nodeID_13/scene_state_001_scene/config',
  values: [ '91-0-scene-001', [length]: 1 ],
  persistent: false,
  ignoreDiscovery: false
}
2021-01-17 15:59:30.768 INFO ZWAVE: Node 13: value added 13-132-0-wakeUpInterval => 3600
2021-01-17 15:59:30.778 INFO ZWAVE: Node 13: value added 13-132-0-controllerNodeId => 1
# zwavejs2mqtt completes node initialization as "unknown manufacturer/product":
2021-01-17 15:59:30.779 INFO ZWAVE: Node 13 ready: Unknown manufacturer undefined - Unknown product undefined (Unknown)
2021-01-17 15:59:30.780 INFO ZWAVE: Node 13: interview completed, all values are updated
2021-01-17 15:59:31.860 INFO ZWAVE: Node 13 is now asleep
...
# Manually trigger "Refresh info" for node 13 from zwavejs2mqtt and pressing Fibaro button 6x (for wakeup and send node info)
2021-01-17 19:19:29.797 INFO APP: Zwave api call: refreshInfo [ 13, [length]: 1 ]
2021-01-17 19:19:29.836 INFO ZWAVE: Success zwave api call refreshInfo
2021-01-17 19:19:38.790 INFO ZWAVE: Node 13 is now asleep
2021-01-17 19:19:44.271 INFO ZWAVE: Node 13 is now awake
# Here the manufacturerId, productType and productId are correctly updated:
2021-01-17 19:19:45.380 INFO ZWAVE: Node 13: value added: 114-0-manufacturerId => 271
2021-01-17 19:19:45.382 INFO ZWAVE: Node 13: value added: 114-0-productType => 3841
2021-01-17 19:19:45.383 INFO ZWAVE: Node 13: value added: 114-0-productId => 4096
# zwavejs2mqtt does not update manufacturer and product name in the UI and still shows it as "unknown"
...

robertsLando · 2021-01-17T20:05:46Z

@AlCalzone what I don't understand here is why the ready event is triggered if the node isn't really ready? At least based on the supposition of @ahochsteger seems that when the ready event is triggered we are missing the manufacturer product type and id CCs

AlCalzone · 2021-01-17T20:24:36Z

That's it:

# zwave-js: Ping failed on sleeping device
14:37:15.715 CNTRLR   [Node 013] ping failed: The node is asleep
14:37:15.715 CNTRLR » [Node 013] querying node info...
...
# zwave-js: NodeInfo stage completes (failed):
15:12:22.635 CNTRLR   [Node 013] querying the node info failed
15:12:22.643 CNTRLR   [Node 013] Interview stage completed: NodeInfo

Querying the node info fails for some reason, meaning we don't know which CCs are supported.
Because we don't know that, no CCs are queried except WakeUp CC (which is mandatory for Battery-powered devices).
After that, the interview is quickly finished, emitting the "ready" event.

AlCalzone · 2021-01-17T20:38:14Z

So with the linked PR, we now abort the interview if requesting the node info fails.

bdbogjoe · 2021-01-17T20:52:12Z

here my logs from linux using npm

zwavejs2mqtt.log
zwavejs_3944233.log

the same devices are well found from raspberry but here there is in logs :
2021-01-17 21:45:12.420 INFO ZWAVE: Node 6 ready: Unknown manufacturer undefined - Unknown product undefined (Unknown)

here the logs from the raspberry using npm:

zwavejs2mqtt.log
zwavejs_5363.log

INFO ZWAVE: Node 6 ready: Fibargroup - FGBS222 (Smart Implant)
INFO ZWAVE: Node 7 ready: Fibargroup - FGS223 (Double Switch 2)

AlCalzone · 2021-01-17T21:05:17Z

@bdbogjoe the difference is that log one shows a restart from cache and log two a complete interview, including manufacturer info.
In the first one, that info should already be in the cache, but I can't tell without those files.

bdbogjoe · 2021-01-17T22:08:20Z

here the logs from linux, now works fine with this branch !

zwavejs2mqtt.log
zwavejs_3984622.log

e86a487a.zip

AlCalzone · 2021-01-18T08:58:21Z

Hm, probably was a fluke. If the issue persists after a refreshInfo, let me know.

fix: better node initialization

e352e90

Fixes #217

robertsLando requested a review from ahochsteger January 14, 2021 16:35

fix: some more checks

e5d6b02

This was referenced Jan 14, 2021

[bug] Node rename is not always respected in MQTT #217

Closed

[bug] Aeotec Multisensor 6 now shows up Unknown/undefined Manufacturer/Product #244

Closed

robertsLando and others added 3 commits January 15, 2021 17:15

Merge branch 'master' into fix-init-node

e332f94

Merge branch 'master' into fix-init-node

20a8b9f

fix: lint errors

81fdbc4

AlCalzone mentioned this pull request Jan 17, 2021

fix: abort interview when requesting node info fails zwave-js/node-zwave-js#1439

Merged

robertsLando mentioned this pull request Jan 18, 2021

After restarting, most of the devices show Unknown manufacturer undefined [bug] #256

Closed

3 tasks

robertsLando added 2 commits January 18, 2021 14:05

chore: bumped zwave-js beta 2

377e835

fix: removed inited prop

6e3848b

robertsLando merged commit 3724e3f into master Jan 18, 2021

robertsLando deleted the fix-init-node branch January 18, 2021 13:09

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

fix: better node initialization #240

fix: better node initialization #240

robertsLando commented Jan 14, 2021 •

edited

Loading

robertsLando commented Jan 14, 2021

coveralls commented Jan 17, 2021 •

edited

Loading

ahochsteger commented Jan 17, 2021

robertsLando commented Jan 17, 2021

AlCalzone commented Jan 17, 2021

AlCalzone commented Jan 17, 2021

bdbogjoe commented Jan 17, 2021 •

edited

Loading

AlCalzone commented Jan 17, 2021

bdbogjoe commented Jan 17, 2021 •

edited

Loading

AlCalzone commented Jan 18, 2021

fix: better node initialization #240

fix: better node initialization #240

Conversation

robertsLando commented Jan 14, 2021 • edited Loading

robertsLando commented Jan 14, 2021

coveralls commented Jan 17, 2021 • edited Loading

Pull Request Test Coverage Report for Build 493662310

💛 - Coveralls

ahochsteger commented Jan 17, 2021

robertsLando commented Jan 17, 2021

AlCalzone commented Jan 17, 2021

AlCalzone commented Jan 17, 2021

bdbogjoe commented Jan 17, 2021 • edited Loading

AlCalzone commented Jan 17, 2021

bdbogjoe commented Jan 17, 2021 • edited Loading

AlCalzone commented Jan 18, 2021

robertsLando commented Jan 14, 2021 •

edited

Loading

coveralls commented Jan 17, 2021 •

edited

Loading

bdbogjoe commented Jan 17, 2021 •

edited

Loading

bdbogjoe commented Jan 17, 2021 •

edited

Loading