Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Closed
AlCalzone opened this issue Sep 23, 2022 · 12 comments
Closed

Comments

@AlCalzone
Copy link
Member

AlCalzone commented Sep 23, 2022

Continuation from zwave-js/node-zwave-js#5088 (comment)

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

@robertsLando
Copy link
Member

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

@AlCalzone
Copy link
Member Author

@jcam

@robertsLando
Copy link
Member

@jcam Did you give that a try?

@jcam
Copy link
Contributor

jcam commented Sep 27, 2022

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.

@robertsLando
Copy link
Member

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

@jcam
Copy link
Contributor

jcam commented Oct 2, 2022

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.

@robertsLando
Copy link
Member

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

@AlCalzone
Copy link
Member Author

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

@robertsLando
Copy link
Member

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

@jcam
Copy link
Contributor

jcam commented Oct 9, 2022

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

@robertsLando
Copy link
Member

robertsLando commented Oct 10, 2022

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).

@github-actions
Copy link
Contributor

github-actions bot commented Feb 7, 2023

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

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

3 participants