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

[tommyjlong]

Version
1.0.0-beta.0.6e2a0f7

Build/Run method

• Docker
• PKG
• Manually built (git clone - npm install - npm run build )

zwavejs2mqtt version: 1.0.0-beta.0.6e2a0f7

Describe the bug
Aeotec Multisensor6 is showing up in GUI Unknown manufacturer undefined and Unknown product undefined
There are no numbers saying what manufacturer/product was actually found.

Important Note: This was working in release 1.0.0-alpha.2.51f715c (~2 days ago)

Everything else appears correct as is in the GUI including the configuration parameters.

I checked the zwave-js device files (ZW100), and they appear to be there and correct.
My device's info: Mfg=0x0086 (134), Type=x0102(258), ID=x0064(100).

[robertsLando]

Could you show me a log output of zwavejs2mqtt? I'm currently working on a fix for this #240

[tommyjlong]

OK...

1. I started it up (with cached files) with the logs enabled and this time it worked (it found the correct manufacturing/Product)!
2. Repeated 1) again and it worked!
3. Cleared the cache files, restarted and the problem reoccurs :( .

Here is the zwavejs2mqtt log with 'silly' level (I snipped a few of the other nodes' log entries to shorten things up)

....
2021-01-15 12:15:41.082 INFO ZWAVE: Zwave driver is ready
2021-01-15 12:15:41.090 DEBUG MQTT: Publishing to z2mqtt/nodeID_1/status: false with options { qos: 0, retain: false }
2021-01-15 12:15:41.083 INFO ZWAVE: Controller status: Driver ready
2021-01-15 12:15:41.092 INFO ZWAVE: Node added 1
2021-01-15 12:15:41.095 INFO ZWAVE: Node added 2
....
2021-01-15 12:15:41.113 INFO ZWAVE: Scanning network with homeid: blah blah
2021-01-15 12:15:41.094 DEBUG MQTT: Publishing to z2mqtt/nodeID_2/status: false with options { qos: 0, retain: false }
2021-01-15 12:15:41.097 DEBUG MQTT: Publishing to z2mqtt/nodeID_3/status: false with options { qos: 0, retain: false }
...
2021-01-15 12:15:41.557 INFO ZWAVE: Node 9 is awake
2021-01-15 12:15:41.560 DEBUG MQTT: Publishing to z2mqtt/nodeID_9/status: false with options { qos: 0, retain: false }
2021-01-15 12:15:42.090 DEBUG MQTT: Publishing to z2mqtt/nodeID_2/status: false with options { qos: 0, retain: false }
2021-01-15 12:15:42.091 INFO ZWAVE: Node 2 is alive
2021-01-15 12:15:42.107 INFO ZWAVE: Node 2: metadata updated: 49-0-Humidity
2021-01-15 12:15:42.110 INFO ZWAVE: Node 2: value added: 49-0-Humidity => 40
2021-01-15 12:15:42.351 DEBUG MQTT: Publishing to z2mqtt/nodeID_3/status: false with options { qos: 0, retain: false }
...
2021-01-15 12:15:46.902 INFO ZWAVE: Node 2: metadata updated: 49-0-Ultraviolet
2021-01-15 12:15:46.904 INFO ZWAVE: Node 2: value added: 49-0-Ultraviolet => 0
2021-01-15 12:15:47.409 INFO ZWAVE: Node 3: value added: 134-0-libraryType => 3
....
2021-01-15 12:16:47.513 INFO ZWAVE: Node 9 is now asleep
2021-01-15 12:16:47.515 DEBUG MQTT: Publishing to z2mqtt/nodeID_9/status: false with options { qos: 0, retain: false }
2021-01-15 12:16:47.584 INFO ZWAVE: Node 2: value added: 128-0-level => 100
2021-01-15 12:16:47.585 INFO ZWAVE: Node 2: value added: 128-0-isLow => false
2021-01-15 12:16:47.891 INFO ZWAVE: Node 2: metadata updated: 49-0-Illuminance
2021-01-15 12:16:47.893 INFO ZWAVE: Node 2: value added: 49-0-Illuminance => 22
2021-01-15 12:16:48.020 INFO ZWAVE: Node 2: metadata updated: 49-0-Ultraviolet
2021-01-15 12:16:48.022 INFO ZWAVE: Node 2: value updated: 49-0-Ultraviolet 0 => 0
2021-01-15 12:16:55.868 INFO ZWAVE: Node 6: value updated: 50-0-value-66561 121.675 => 122.297
...
2021-01-15 12:17:08.339 DEBUG MQTT: Publishing to z2mqtt/nodeID_6/status: false with options { qos: 0, retain: false }
2021-01-15 12:17:08.374 INFO ZWAVE: Node 2: value added: 132-0-wakeUpInterval => 3600
2021-01-15 12:17:08.379 INFO ZWAVE: Node 2: value added: 132-0-controllerNodeId => 1
2021-01-15 12:17:08.599 DEBUG MQTT: Publishing to z2mqtt/nodeID_11/status: false with options { qos: 0, retain: false }
2021-01-15 12:17:08.600 INFO ZWAVE: Node 11 is alive
2021-01-15 12:17:18.810 DEBUG MQTT: Publishing to z2mqtt/nodeID_10/status: false with options { qos: 0, retain: false }
2021-01-15 12:17:18.811 INFO ZWAVE: Node 10 is alive
2021-01-15 12:17:29.101 WARN ZWAVE: Node 2 doesn't support groups associations
2021-01-15 12:17:29.119 DEBUG MQTT: Publishing to z2mqtt/nodeID_2/status: true with options { qos: 0, retain: false }
2021-01-15 12:17:29.109 INFO ZWAVE: Node 2: value added 2-49-0-Humidity => 40
2021-01-15 12:17:29.111 INFO ZWAVE: Node 2: value added 2-49-0-Ultraviolet => 0
2021-01-15 12:17:29.112 INFO ZWAVE: Node 2: value added 2-49-0-Illuminance => 22
2021-01-15 12:17:29.115 INFO ZWAVE: Node 2: value added 2-132-0-wakeUpInterval => 3600
2021-01-15 12:17:29.116 INFO ZWAVE: Node 2: value added 2-132-0-controllerNodeId => 1
2021-01-15 12:17:29.121 INFO ZWAVE: Node 2 ready: Unknown manufacturer undefined - Unknown product undefined (Unknown)
2021-01-15 12:17:29.124 INFO ZWAVE: Node 2: interview completed, all values are updated
2021-01-15 12:17:29.126 DEBUG MQTT: Publishing to z2mqtt/nodeID_2/status: true with options { qos: 0, retain: false }
2021-01-15 12:17:29.242 INFO ZWAVE: Node 11: value added: 114-0-manufacturerId => 881
...
2021-01-15 12:17:39.538 DEBUG MQTT: Publishing to z2mqtt/nodeID_6/status: false with options { qos: 0, retain: false }
2021-01-15 12:17:39.590 INFO ZWAVE: Node 2: metadata updated: 49-0-Air temperature
2021-01-15 12:17:39.600 INFO ZWAVE: Node 2: value added: 49-0-Air temperature => 72.8
2021-01-15 12:17:40.964 INFO ZWAVE: Node 2: metadata updated: 49-0-Humidity
2021-01-15 12:17:40.967 INFO ZWAVE: Node 2: value added: 49-0-Humidity => 40
...
2021-01-15 12:17:43.363 INFO ZWAVE: Node 10: value added: 134-0-firmwareVersions => 1.1
2021-01-15 12:17:43.885 INFO ZWAVE: Node 2: value added: 128-0-level => 100
2021-01-15 12:17:43.886 INFO ZWAVE: Node 2: value added: 128-0-isLow => false
2021-01-15 12:17:55.866 INFO ZWAVE: Node 6: value updated: 50-0-value-66561 122.297 => 122.68
....
2021-01-15 12:19:39.992 INFO ZWAVE: Node 7: interview completed, all values are updated
2021-01-15 12:19:39.995 DEBUG MQTT: Publishing to z2mqtt/nodeID_7/status: true with options { qos: 0, retain: false }
2021-01-15 12:19:45.563 INFO ZWAVE: Node 2: metadata updated: 49-0-Illuminance
2021-01-15 12:19:45.564 INFO ZWAVE: Node 2: value added: 49-0-Illuminance => 24
2021-01-15 12:19:48.273 INFO ZWAVE: Node 2: metadata updated: 49-0-Ultraviolet
2021-01-15 12:19:48.276 INFO ZWAVE: Node 2: value added: 49-0-Ultraviolet => 0
2021-01-15 12:19:55.866 INFO ZWAVE: Node 6: value updated: 50-0-value-66561 122.766 => 122.752
...
2021-01-15 12:20:32.145 INFO APP: Closing clients...
2021-01-15 12:20:32.146 INFO GATEWAY: Closing Gateway...
2021-01-15 12:20:32.154 INFO MQTT: MQTT client closed

[robertsLando]

@tommyjlong Does this comes from a ontainer built with #240 changes or not?

Does this only happen when the caceh file is not present or after a restart?

[tommyjlong]

@robertsLando . I cloned from main last Wednesday, and changes from 240 are not present, so no I did not test with your fix. Problem only occurs when starting with cache files not present.

[robertsLando]

I think we figured out the problem with #240 , seems that if the interview fails the ready event could be emitted anyway without the devive config informations. This will be fixed in next release

[tommyjlong]

Just tested with 1.0.0-rc.1.5846763. This works now. I will go ahead and close.