zwave-js-ui icon indicating copy to clipboard operation
zwave-js-ui copied to clipboard

Published 20 hours ago • verified publisher icon zwave-js

UI delays the driver massively when nodes with a lot of values are ready

Open AlCalzone opened this issue 2 years ago • 9 comments

Continuation from https://github.com/zwave-js/node-zwave-js/issues/5088#issuecomment-1255117681

On slower(?) systems, the UI's handling of ready nodes delays the driver for several seconds when a node with lots of values gets ready. Here's the example from the other post. I'm not sure what work ZUI is doing here and why the hell it takes 20 seconds to populate maybe 50 values - maybe there are some inefficiencies like emitting events or rebuilding the UI for each of those?

Driver

2022-09-23T14:47:31.754Z CNTRLR   [Node 002] The node is alive.

... UI goes brr...

2022-09-23T14:47:51.187Z CNTRLR   [Node 002] The node is ready to be used

UI

2022-09-23 10:47:31.752 INFO Z-WAVE: Node 2 is alive
2022-09-23 10:47:33.182 INFO Z-WAVE: Node 2: value added 2-91-0-scene-001 => undefined
2022-09-23 10:47:33.185 INFO Z-WAVE: Node 2: value added 2-91-0-scene-002 => undefined
2022-09-23 10:47:33.189 INFO Z-WAVE: Node 2: value added 2-91-0-scene-003 => undefined
2022-09-23 10:47:33.192 INFO Z-WAVE: Node 2: value added 2-91-0-scene-004 => undefined
2022-09-23 10:47:33.195 INFO Z-WAVE: Node 2: value added 2-91-0-slowRefresh => undefined
2022-09-23 10:47:33.198 INFO Z-WAVE: Node 2: value added 2-112-0-1 => 0
2022-09-23 10:47:33.202 INFO Z-WAVE: Node 2: value added 2-112-0-20 => 2
2022-09-23 10:47:33.205 INFO Z-WAVE: Node 2: value added 2-112-0-21 => 2
2022-09-23 10:47:33.208 INFO Z-WAVE: Node 2: value added 2-112-0-22 => 2
2022-09-23 10:47:33.211 INFO Z-WAVE: Node 2: value added 2-112-0-23 => 2
2022-09-23 10:47:33.214 INFO Z-WAVE: Node 2: value added 2-112-0-62 => 3600
2022-09-23 10:47:33.217 INFO Z-WAVE: Node 2: value added 2-112-0-65 => 10
2022-09-23 10:47:33.220 INFO Z-WAVE: Node 2: value added 2-112-0-66 => 3600
2022-09-23 10:47:33.223 INFO Z-WAVE: Node 2: value added 2-112-0-150 => 0
2022-09-23 10:47:33.227 INFO Z-WAVE: Node 2: value added 2-112-0-151 => 3
2022-09-23 10:47:33.230 INFO Z-WAVE: Node 2: value added 2-112-0-152 => 3
2022-09-23 10:47:33.233 INFO Z-WAVE: Node 2: value added 2-112-0-157 => 0
2022-09-23 10:47:33.236 INFO Z-WAVE: Node 2: value added 2-112-0-40-1 => 1
2022-09-23 10:47:33.239 INFO Z-WAVE: Node 2: value added 2-112-0-40-2 => 1
2022-09-23 10:47:33.242 INFO Z-WAVE: Node 2: value added 2-112-0-40-4 => 1
2022-09-23 10:47:33.245 INFO Z-WAVE: Node 2: value added 2-112-0-40-8 => 1
2022-09-23 10:47:33.248 INFO Z-WAVE: Node 2: value added 2-112-0-41-1 => 1
2022-09-23 10:47:33.251 INFO Z-WAVE: Node 2: value added 2-112-0-41-2 => 1
2022-09-23 10:47:33.253 INFO Z-WAVE: Node 2: value added 2-112-0-41-4 => 1
2022-09-23 10:47:33.256 INFO Z-WAVE: Node 2: value added 2-112-0-41-8 => 1
2022-09-23 10:47:33.259 INFO Z-WAVE: Node 2: value added 2-112-0-42-1 => 1
2022-09-23 10:47:33.262 INFO Z-WAVE: Node 2: value added 2-112-0-42-2 => 1
2022-09-23 10:47:33.265 INFO Z-WAVE: Node 2: value added 2-112-0-42-4 => 1
2022-09-23 10:47:33.268 INFO Z-WAVE: Node 2: value added 2-112-0-42-8 => 1
2022-09-23 10:47:33.271 INFO Z-WAVE: Node 2: value added 2-112-0-43-1 => 1
2022-09-23 10:47:33.274 INFO Z-WAVE: Node 2: value added 2-112-0-43-2 => 1
2022-09-23 10:47:33.277 INFO Z-WAVE: Node 2: value added 2-112-0-43-4 => 1
2022-09-23 10:47:33.280 INFO Z-WAVE: Node 2: value added 2-112-0-43-8 => 1
2022-09-23 10:47:33.283 INFO Z-WAVE: Node 2: value added 2-114-0-manufacturerId => 634
2022-09-23 10:47:33.285 INFO Z-WAVE: Node 2: value added 2-114-0-productType => 2306
2022-09-23 10:47:33.288 INFO Z-WAVE: Node 2: value added 2-114-0-productId => 8192
2022-09-23 10:47:33.291 INFO Z-WAVE: Node 2: value added 2-134-0-libraryType => 3
2022-09-23 10:47:33.295 INFO Z-WAVE: Node 2: value added 2-134-0-protocolVersion => 6.4
2022-09-23 10:47:33.297 INFO Z-WAVE: Node 2: value added 2-134-0-firmwareVersions => 5.0,5.0,1.0
2022-09-23 10:47:33.300 INFO Z-WAVE: Node 2: value added 2-134-0-hardwareVersion => 2
2022-09-23 10:47:33.304 INFO Z-WAVE: Node 2: value added 2-38-1-targetValue => 0
2022-09-23 10:47:33.307 INFO Z-WAVE: Node 2: value added 2-38-1-duration => 0s
2022-09-23 10:47:34.709 INFO Z-WAVE: Node 2: value added 2-38-1-currentValue => 0
2022-09-23 10:47:34.713 INFO Z-WAVE: Node 2: value added 2-38-1-Up => undefined
2022-09-23 10:47:34.717 INFO Z-WAVE: Node 2: value added 2-38-1-Down => undefined
2022-09-23 10:47:34.720 INFO Z-WAVE: Node 2: value added 2-38-1-restorePrevious => undefined
2022-09-23 10:47:34.724 INFO Z-WAVE: Node 2: value added 2-50-1-value-65537 => 4.05
2022-09-23 10:47:34.727 INFO Z-WAVE: Node 2: value added 2-50-1-value-66049 => 0
2022-09-23 10:47:34.730 INFO Z-WAVE: Node 2: value added 2-50-1-reset => undefined
2022-09-23 10:47:34.733 INFO Z-WAVE: Node 2: value added 2-51-1-duration => 0s
2022-09-23 10:47:36.029 INFO Z-WAVE: Node 2: value added 2-51-1-currentColor-0 => 255
2022-09-23 10:47:36.033 INFO Z-WAVE: Node 2: value added 2-51-1-targetColor-0 => 0
2022-09-23 10:47:37.271 INFO Z-WAVE: Node 2: value added 2-51-1-currentColor => [object Object]
2022-09-23 10:47:37.275 INFO Z-WAVE: Node 2: value added 2-51-1-targetColor => [object Object]
2022-09-23 10:47:38.517 INFO Z-WAVE: Node 2: value added 2-51-1-currentColor-2 => 159
2022-09-23 10:47:38.521 INFO Z-WAVE: Node 2: value added 2-51-1-targetColor-2 => 0
2022-09-23 10:47:38.524 INFO Z-WAVE: Node 2: value added 2-51-1-hexColor => 9fe7ff
2022-09-23 10:47:39.761 INFO Z-WAVE: Node 2: value added 2-51-1-currentColor-3 => 231
2022-09-23 10:47:39.764 INFO Z-WAVE: Node 2: value added 2-51-1-targetColor-3 => 0
2022-09-23 10:47:41.004 INFO Z-WAVE: Node 2: value added 2-51-1-currentColor-4 => 255
2022-09-23 10:47:41.008 INFO Z-WAVE: Node 2: value added 2-51-1-targetColor-4 => 0
2022-09-23 10:47:41.012 INFO Z-WAVE: Node 2: value added 2-113-1-Power Management-Over-current status => 0
2022-09-23 10:47:41.016 INFO Z-WAVE: Node 2: value added 2-113-1-System-Hardware status => 0
2022-09-23 10:47:41.019 INFO Z-WAVE: Node 2: value added 2-113-1-alarmType => undefined
2022-09-23 10:47:41.023 INFO Z-WAVE: Node 2: value added 2-113-1-alarmLevel => undefined
2022-09-23 10:47:41.026 INFO Z-WAVE: Node 2: value added 2-117-1-local => 0
2022-09-23 10:47:41.030 INFO Z-WAVE: Node 2: value added 2-117-1-rf => 0
2022-09-23 10:47:41.033 INFO Z-WAVE: Node 2: value added 2-117-1-exclusiveControlNodeId => undefined
2022-09-23 10:47:41.037 INFO Z-WAVE: Node 2: value added 2-117-1-timeout => undefined
2022-09-23 10:47:41.040 INFO Z-WAVE: Node 2: value added 2-38-2-targetValue => 0
2022-09-23 10:47:41.044 INFO Z-WAVE: Node 2: value added 2-38-2-duration => 0s
2022-09-23 10:47:42.286 INFO Z-WAVE: Node 2: value added 2-38-2-currentValue => 0
2022-09-23 10:47:42.290 INFO Z-WAVE: Node 2: value added 2-38-2-Up => undefined
2022-09-23 10:47:42.294 INFO Z-WAVE: Node 2: value added 2-38-2-Down => undefined
2022-09-23 10:47:42.297 INFO Z-WAVE: Node 2: value added 2-38-2-restorePrevious => undefined
2022-09-23 10:47:42.301 INFO Z-WAVE: Node 2: value added 2-38-3-targetValue => 0
2022-09-23 10:47:42.304 INFO Z-WAVE: Node 2: value added 2-38-3-duration => 0s
2022-09-23 10:47:43.570 INFO Z-WAVE: Node 2: value added 2-38-3-currentValue => 0
2022-09-23 10:47:43.574 INFO Z-WAVE: Node 2: value added 2-38-3-Up => undefined
2022-09-23 10:47:43.578 INFO Z-WAVE: Node 2: value added 2-38-3-Down => undefined
2022-09-23 10:47:43.581 INFO Z-WAVE: Node 2: value added 2-38-3-restorePrevious => undefined
2022-09-23 10:47:43.585 INFO Z-WAVE: Node 2: value added 2-38-4-targetValue => 0
2022-09-23 10:47:43.588 INFO Z-WAVE: Node 2: value added 2-38-4-duration => 0s
2022-09-23 10:47:44.846 INFO Z-WAVE: Node 2: value added 2-38-4-currentValue => 0
2022-09-23 10:47:44.850 INFO Z-WAVE: Node 2: value added 2-38-4-Up => undefined
2022-09-23 10:47:44.853 INFO Z-WAVE: Node 2: value added 2-38-4-Down => undefined
2022-09-23 10:47:44.856 INFO Z-WAVE: Node 2: value added 2-38-4-restorePrevious => undefined
2022-09-23 10:47:44.860 INFO Z-WAVE: Node 2: value added 2-38-5-targetValue => 0
2022-09-23 10:47:44.863 INFO Z-WAVE: Node 2: value added 2-38-5-duration => 0s
2022-09-23 10:47:46.095 INFO Z-WAVE: Node 2: value added 2-38-5-currentValue => 0
2022-09-23 10:47:46.099 INFO Z-WAVE: Node 2: value added 2-38-5-Up => undefined
2022-09-23 10:47:46.102 INFO Z-WAVE: Node 2: value added 2-38-5-Down => undefined
2022-09-23 10:47:46.105 INFO Z-WAVE: Node 2: value added 2-38-5-restorePrevious => undefined
2022-09-23 10:47:47.345 INFO Z-WAVE: Node 2: value added 2-32-6-currentValue => 0
2022-09-23 10:47:47.349 INFO Z-WAVE: Node 2: value added 2-32-6-targetValue => undefined
2022-09-23 10:47:47.353 INFO Z-WAVE: Node 2: value added 2-32-6-duration => NaNs
2022-09-23 10:47:47.356 INFO Z-WAVE: Node 2: value added 2-32-6-restorePrevious => undefined
2022-09-23 10:47:47.360 INFO Z-WAVE: Node 2: value added 2-49-6-Voltage => 0
2022-09-23 10:47:48.605 INFO Z-WAVE: Node 2: value added 2-32-7-currentValue => 0
2022-09-23 10:47:48.609 INFO Z-WAVE: Node 2: value added 2-32-7-targetValue => undefined
2022-09-23 10:47:48.613 INFO Z-WAVE: Node 2: value added 2-32-7-duration => NaNs
2022-09-23 10:47:48.616 INFO Z-WAVE: Node 2: value added 2-32-7-restorePrevious => undefined
2022-09-23 10:47:48.620 INFO Z-WAVE: Node 2: value added 2-49-7-Voltage => 0
2022-09-23 10:47:49.856 INFO Z-WAVE: Node 2: value added 2-32-8-currentValue => 0
2022-09-23 10:47:49.860 INFO Z-WAVE: Node 2: value added 2-32-8-targetValue => undefined
2022-09-23 10:47:49.864 INFO Z-WAVE: Node 2: value added 2-32-8-duration => NaNs
2022-09-23 10:47:49.867 INFO Z-WAVE: Node 2: value added 2-32-8-restorePrevious => undefined
2022-09-23 10:47:49.871 INFO Z-WAVE: Node 2: value added 2-49-8-Voltage => 0
2022-09-23 10:47:51.103 INFO Z-WAVE: Node 2: value added 2-32-9-currentValue => 0
2022-09-23 10:47:51.107 INFO Z-WAVE: Node 2: value added 2-32-9-targetValue => undefined
2022-09-23 10:47:51.110 INFO Z-WAVE: Node 2: value added 2-32-9-duration => NaNs
2022-09-23 10:47:51.114 INFO Z-WAVE: Node 2: value added 2-32-9-restorePrevious => undefined
2022-09-23 10:47:51.118 INFO Z-WAVE: Node 2: value added 2-49-9-Voltage => 0
2022-09-23 10:47:51.185 INFO Z-WAVE: Node 2 ready: Zooz - ZEN31 (RGBW Dimmer)

/cc @jcam

AlCalzone avatar Sep 23 '22 15:09 AlCalzone

Possible fix published. Let's try with next 8.0.1 version

robertsLando avatar Sep 26 '22 08:09 robertsLando

@jcam

AlCalzone avatar Sep 26 '22 08:09 AlCalzone

@jcam Did you give that a try?

robertsLando avatar Sep 27 '22 12:09 robertsLando

I currently use the homeassistant addon that frenk maintains, so i either need to manually update / set up a private repo and all that, or wait for him. if he doesn't publish an update in the next day or two i'll build it myself. totally unrelated, i still think it's a bit odd that none of the 'official' addons on 'official' HA's addons repo say who made the thing in them... no attribution at all.

jcam avatar Sep 27 '22 13:09 jcam

totally unrelated, i still think it's a bit odd that none of the 'official' addons on 'official' HA's addons repo say who made the thing in them... no attribution at all.

I don't use HA but I know there is a reference in addon readme at least

robertsLando avatar Sep 27 '22 14:09 robertsLando

Good day! I finally got 8.0.1 installed, unfortunately no change. Let me know if there are more details/debug logs or something I could gather.

jcam avatar Oct 02 '22 12:10 jcam

@jcam could you upload new logs please? Does pinging a node takes lot of time like before?

robertsLando avatar Oct 03 '22 07:10 robertsLando

It's not pinging the node that takes time. It's zui doing sth with the values after the node is considered ready.

AlCalzone avatar Oct 03 '22 11:10 AlCalzone

I need to see logs to see if there is a little bit of improvements or not. I sincerly have no idea about what is causing those delays

robertsLando avatar Oct 03 '22 11:10 robertsLando

Here's a debug log! May include a partial debug log at v8.0.1 and then again at 8.1.0 zwave-js-ui-store.zip

jcam avatar Oct 09 '22 12:10 jcam

Looking at logs I see that the slowdown only happens for first 3 nodes, specifically 2-3-4 nodes takes ~20s from alive to ready.

Starting from node 5 it takes ~1s so I don't think it's something strictly related to z-UI.

any other consideration @AlCalzone ?

@jcam I cannot check the zwave-js driver logs as I think you picked up the wrong file (an old one).

robertsLando avatar Oct 10 '22 08:10 robertsLando

This issue is stale because it has been open 90 days with no activity. Remove the stale label or comment or this will be closed in 5 days. To ignore this issue entirely you can add the no-stale label

github-actions[bot] avatar Feb 07 '23 00:02 github-actions[bot]