Zwave Network Too Slow

Hi,

i am new to HA and i would like some recommendations on issues i am having with response time.

i have a 3 story house and I have just setup home assistant on rpi4 with aeotec z wave stick. When i first started the setup, i used the old zwave plugin, which i have then swithed to zwave JS. After i switched to zwave JS, i wanted to change modules parameters and according to research i had to install zwavejs2mqtt. i am using around 25 fibaro relay modules (on/off, dimmers) + 4 wall plugs around all the house. Although having all the later devices, i still have lagging issues. Slow response is not all the time.

i have added 2 x repeaters from aeotec. for some reason, these does not work together. When i plug them both, zwave start to give more issues. As soon as i switch off one, all commands start working normally. i also tried placing the HA in different spots of the house, but response time is still slow.

sometimes, even when activating a scene to switch off lights, some lights are kept on and you would have to activate the scene again. i checked the logs for traffic, i noticed that i had some device like the energy meter, that was reporting frequently so i changed all devices to report every 30min or even 6h for once that are not important.

Can any one please help me out what else i can check.

Have you tried healing the network? Probably would be best to do overnight as it can take a while if you have any battery powered devices.

If that doesn’t help can you enable logging in the zwavejs2mqtt in the zwave configuration settings page with a level of at least verbose and post it with a time that you tried something where it was delayed?

Matt

Hi Matt,

thank you for getting back. I did heal network multiple times, but the zwave graph in zwavejs2mqtt never updates. Eg, i have now placed the controller more central and the graph still shows the far devices as first hop.

i have enabled logging as you said, will post log and time of event.

Hi Matt,

please find log below log. issue happened between 21:22:00 - 21:24:00. i turned on movie scene and all devices took long to respond. In fact, between the series of commands, there was 3 - 5 sec delay. appreciate all your help.

2021-05-03 21:09:53.071 INFO ZWAVE: Node 31: value updated: 50-0-value-66049 0 => 0

2021-05-03 21:09:54.708 INFO ZWAVE: Node 44: metadata updated: 49-0-Air temperature

2021-05-03 21:09:54.711 INFO ZWAVE: Node 44: value updated: 49-0-Air temperature 22.4 => 22.3

2021-05-03 21:09:54.819 INFO ZWAVE: Node 44: metadata updated: 49-0-Humidity

2021-05-03 21:09:54.822 INFO ZWAVE: Node 44: value updated: 49-0-Humidity 65 => 64

2021-05-03 21:10:08.026 INFO ZWAVE: Node 51: value updated: 50-0-value-66561 238.17 => 235.059

2021-05-03 21:10:08.309 INFO ZWAVE: Node 51: value updated: 50-0-value-66817 5.785 => 5.716

2021-05-03 21:10:08.590 INFO ZWAVE: Node 51: value updated: 50-0-value-66049 790.703 => 768.71

2021-05-03 21:10:08.871 INFO ZWAVE: Node 51: value updated: 50-0-value-65537 296.588 => 296.601

2021-05-03 21:11:08.027 INFO ZWAVE: Node 51: value updated: 50-0-value-66561 235.059 => 234.773

2021-05-03 21:11:08.311 INFO ZWAVE: Node 51: value updated: 50-0-value-66817 5.716 => 5.7

2021-05-03 21:11:08.591 INFO ZWAVE: Node 51: value updated: 50-0-value-66049 768.71 => 761.084

2021-05-03 21:11:08.872 INFO ZWAVE: Node 51: value updated: 50-0-value-65537 296.601 => 296.613

2021-05-03 21:11:13.000 INFO ZWAVE: Node 15: value updated: 50-1-value-65537 12.51 => 12.55

2021-05-03 21:11:19.931 INFO ZWAVE: Node 20: metadata updated: 49-1-Power

2021-05-03 21:11:19.935 INFO ZWAVE: Node 20: value updated: 49-1-Power 33 => 33.2

2021-05-03 21:11:54.709 INFO ZWAVE: Node 44: metadata updated: 49-0-Air temperature

2021-05-03 21:11:54.715 INFO ZWAVE: Node 44: value updated: 49-0-Air temperature 22.3 => 22.3

2021-05-03 21:11:54.818 INFO ZWAVE: Node 44: metadata updated: 49-0-Humidity

2021-05-03 21:11:54.822 INFO ZWAVE: Node 44: value updated: 49-0-Humidity 64 => 65

2021-05-03 21:12:08.027 INFO ZWAVE: Node 51: value updated: 50-0-value-66561 234.773 => 233.63

2021-05-03 21:12:08.311 INFO ZWAVE: Node 51: value updated: 50-0-value-66817 5.7 => 5.729

2021-05-03 21:12:08.592 INFO ZWAVE: Node 51: value updated: 50-0-value-66049 761.084 => 770.919

2021-05-03 21:12:08.872 INFO ZWAVE: Node 51: value updated: 50-0-value-65537 296.613 => 296.627

2021-05-03 21:13:08.027 INFO ZWAVE: Node 51: value updated: 50-0-value-66561 233.63 => 234.768

2021-05-03 21:13:08.311 INFO ZWAVE: Node 51: value updated: 50-0-value-66817 5.729 => 5.724

2021-05-03 21:13:08.591 INFO ZWAVE: Node 51: value updated: 50-0-value-66049 770.919 => 772.672

2021-05-03 21:13:08.872 INFO ZWAVE: Node 51: value updated: 50-0-value-65537 296.627 => 296.64

2021-05-03 21:13:23.039 INFO ZWAVE: Node 51: value updated: 50-1-value-66561 236.417 => 234.612

2021-05-03 21:13:23.331 INFO ZWAVE: Node 51: value updated: 50-2-value-66561 249.467 => 248.475

2021-05-03 21:13:23.623 INFO ZWAVE: Node 51: value updated: 50-3-value-66561 236.465 => 242.19

2021-05-03 21:13:23.915 INFO ZWAVE: Node 51: value updated: 50-1-value-66817 0.822 => 0.825

2021-05-03 21:13:24.498 INFO ZWAVE: Node 51: value updated: 50-2-value-66817 2.445 => 2.444

2021-05-03 21:13:24.790 INFO ZWAVE: Node 51: value updated: 50-3-value-66817 2.262 => 2.45

2021-05-03 21:13:25.081 INFO ZWAVE: Node 51: value updated: 50-1-value-66049 127.635 => 127.832

2021-05-03 21:13:34.041 INFO ZWAVE: Node 51: value updated: 50-3-value-66049 324.42 => 374.848

2021-05-03 21:13:34.331 INFO ZWAVE: Node 51: value updated: 50-1-value-65537 52.948 => 52.98

2021-05-03 21:13:34.947 INFO ZWAVE: Node 51: value updated: 50-2-value-65537 218.01 => 218.078

2021-05-03 21:13:35.240 INFO ZWAVE: Node 51: value updated: 50-3-value-65537 25.486 => 25.582

2021-05-03 21:13:38.756 INFO ZWAVE: Node 8: metadata updated: 49-0-Air temperature

2021-05-03 21:13:38.761 INFO ZWAVE: Node 8: value updated: 49-0-Air temperature 29.9 => 29.8

2021-05-03 21:13:39.137 INFO ZWAVE: Node 8: metadata updated: 49-0-Air temperature

2021-05-03 21:13:39.142 INFO ZWAVE: Node 8: value updated: 49-0-Air temperature 29.8 => 29.8

2021-05-03 21:13:39.299 INFO ZWAVE: Node 8: metadata updated: 49-0-Air temperature

2021-05-03 21:13:39.302 INFO ZWAVE: Node 8: value updated: 49-0-Air temperature 29.8 => 29.8

2021-05-03 21:13:39.447 INFO ZWAVE: Node 8: metadata updated: 49-0-Air temperature

2021-05-03 21:13:39.450 INFO ZWAVE: Node 8: value updated: 49-0-Air temperature 29.8 => 29.8

2021-05-03 21:13:39.870 INFO ZWAVE: Node 8: metadata updated: 49-0-Air temperature

2021-05-03 21:13:39.872 INFO ZWAVE: Node 8: value updated: 49-0-Air temperature 29.8 => 29.8

2021-05-03 21:13:47.897 INFO ZWAVE: Node 27: value updated: 50-1-value-66049 0 => 0

2021-05-03 21:13:54.707 INFO ZWAVE: Node 44: metadata updated: 49-0-Air temperature

2021-05-03 21:13:54.710 INFO ZWAVE: Node 44: value updated: 49-0-Air temperature 22.3 => 22.3

2021-05-03 21:13:54.818 INFO ZWAVE: Node 44: metadata updated: 49-0-Humidity

2021-05-03 21:13:54.820 INFO ZWAVE: Node 44: value updated: 49-0-Humidity 65 => 65

2021-05-03 21:13:58.947 INFO ZWAVE: Node 8 is now awake

2021-05-03 21:14:00.042 INFO ZWAVE: Node 8 is now asleep

2021-05-03 21:14:01.095 INFO ZWAVE: Node 29: value updated: 50-0-value-66049 0 => 0

2021-05-03 21:14:02.760 INFO ZWAVE: Node 24: value updated: 50-1-value-66049 0 => 0

2021-05-03 21:14:02.832 INFO ZWAVE: Node 24: value updated: 50-2-value-66049 0 => 0

2021-05-03 21:14:08.027 INFO ZWAVE: Node 51: value updated: 50-0-value-66561 234.768 => 237.339

2021-05-03 21:14:08.310 INFO ZWAVE: Node 51: value updated: 50-0-value-66817 5.724 => 7.055

2021-05-03 21:14:08.592 INFO ZWAVE: Node 51: value updated: 50-0-value-66049 772.672 => 1396.091

2021-05-03 21:14:08.872 INFO ZWAVE: Node 51: value updated: 50-0-value-65537 296.64 => 296.653

2021-05-03 21:14:46.655 INFO ZWAVE: Node 30: value updated: 50-0-value-66049 0 => 0

2021-05-03 21:15:08.028 INFO ZWAVE: Node 51: value updated: 50-0-value-66561 237.339 => 237.604

2021-05-03 21:15:08.311 INFO ZWAVE: Node 51: value updated: 50-0-value-66817 7.055 => 6.804

2021-05-03 21:15:08.592 INFO ZWAVE: Node 51: value updated: 50-0-value-66049 1396.091 => 1339.003

2021-05-03 21:15:08.872 INFO ZWAVE: Node 51: value updated: 50-0-value-65537 296.653 => 296.675

2021-05-03 21:15:15.284 INFO ZWAVE: Node 45 is now awake

2021-05-03 21:15:16.391 INFO ZWAVE: Node 45 is now asleep

2021-05-03 21:15:42.464 INFO ZWAVE: Node 47: metadata updated: 49-0-Air temperature

2021-05-03 21:15:42.467 INFO ZWAVE: Node 47: value updated: 49-0-Air temperature 21.1 => 20

2021-05-03 21:15:54.705 INFO ZWAVE: Node 44: metadata updated: 49-0-Air temperature

2021-05-03 21:15:54.708 INFO ZWAVE: Node 44: value updated: 49-0-Air temperature 22.3 => 22.4

2021-05-03 21:15:54.816 INFO ZWAVE: Node 44: metadata updated: 49-0-Humidity

2021-05-03 21:15:54.819 INFO ZWAVE: Node 44: value updated: 49-0-Humidity 65 => 66

2021-05-03 21:16:08.028 INFO ZWAVE: Node 51: value updated: 50-0-value-66561 237.604 => 237.698

2021-05-03 21:16:08.310 INFO ZWAVE: Node 51: value updated: 50-0-value-66817 6.804 => 6.801

2021-05-03 21:16:08.591 INFO ZWAVE: Node 51: value updated: 50-0-value-66049 1339.003 => 1341.861

2021-05-03 21:16:08.872 INFO ZWAVE: Node 51: value updated: 50-0-value-65537 296.675 => 296.697

2021-05-03 21:17:08.027 INFO ZWAVE: Node 51: value updated: 50-0-value-66561 237.698 => 238.575

2021-05-03 21:17:08.428 INFO ZWAVE: Node 51: value updated: 50-0-value-66817 6.801 => 6.788

2021-05-03 21:17:08.709 INFO ZWAVE: Node 51: value updated: 50-0-value-66049 1341.861 => 1344.955

2021-05-03 21:17:09.603 INFO ZWAVE: Node 51: value updated: 50-0-value-65537 296.697 => 296.719

2021-05-03 21:17:54.704 INFO ZWAVE: Node 44: metadata updated: 49-0-Air temperature

2021-05-03 21:17:54.707 INFO ZWAVE: Node 44: value updated: 49-0-Air temperature 22.4 => 22.4

2021-05-03 21:17:54.815 INFO ZWAVE: Node 44: metadata updated: 49-0-Humidity

2021-05-03 21:17:54.819 INFO ZWAVE: Node 44: value updated: 49-0-Humidity 66 => 67

2021-05-03 21:18:08.027 INFO ZWAVE: Node 51: value updated: 50-0-value-66561 238.575 => 239.074

2021-05-03 21:18:08.311 INFO ZWAVE: Node 51: value updated: 50-0-value-66817 6.788 => 6.985

2021-05-03 21:18:08.591 INFO ZWAVE: Node 51: value updated: 50-0-value-66049 1344.955 => 1398.948

2021-05-03 21:18:08.872 INFO ZWAVE: Node 51: value updated: 50-0-value-65537 296.719 => 296.741

2021-05-03 21:19:08.028 INFO ZWAVE: Node 51: value updated: 50-0-value-66561 239.074 => 235.778

2021-05-03 21:19:08.312 INFO ZWAVE: Node 51: value updated: 50-0-value-66817 6.985 => 5.784

2021-05-03 21:19:08.593 INFO ZWAVE: Node 51: value updated: 50-0-value-66049 1398.948 => 786.407

2021-05-03 21:19:08.875 INFO ZWAVE: Node 51: value updated: 50-0-value-65537 296.741 => 296.761

2021-05-03 21:19:54.704 INFO ZWAVE: Node 44: metadata updated: 49-0-Air temperature

2021-05-03 21:19:54.708 INFO ZWAVE: Node 44: value updated: 49-0-Air temperature 22.4 => 22.4

2021-05-03 21:19:54.815 INFO ZWAVE: Node 44: metadata updated: 49-0-Humidity

2021-05-03 21:19:54.819 INFO ZWAVE: Node 44: value updated: 49-0-Humidity 67 => 67

2021-05-03 21:20:08.028 INFO ZWAVE: Node 51: value updated: 50-0-value-66561 235.778 => 237.791

2021-05-03 21:20:08.311 INFO ZWAVE: Node 51: value updated: 50-0-value-66817 5.784 => 5.765

2021-05-03 21:20:08.593 INFO ZWAVE: Node 51: value updated: 50-0-value-66049 786.407 => 778.879

2021-05-03 21:20:08.875 INFO ZWAVE: Node 51: value updated: 50-0-value-65537 296.761 => 296.774

2021-05-03 21:20:58.749 INFO ZWAVE: Node 17: value updated: 37-1-currentValue true => false

2021-05-03 21:20:59.012 INFO ZWAVE: Node 17: value updated: 50-1-value-66049 34.1 => 0

2021-05-03 21:21:08.029 INFO ZWAVE: Node 51: value updated: 50-0-value-66561 237.791 => 238.297

2021-05-03 21:21:08.313 INFO ZWAVE: Node 51: value updated: 50-0-value-66817 5.765 => 5.723

2021-05-03 21:21:08.595 INFO ZWAVE: Node 51: value updated: 50-0-value-66049 778.879 => 744.236

2021-05-03 21:21:08.877 INFO ZWAVE: Node 51: value updated: 50-0-value-65537 296.774 => 296.788

2021-05-03 21:21:54.703 INFO ZWAVE: Node 44: metadata updated: 49-0-Air temperature

2021-05-03 21:21:54.708 INFO ZWAVE: Node 44: value updated: 49-0-Air temperature 22.4 => 22.5

2021-05-03 21:21:54.942 INFO ZWAVE: Node 44: metadata updated: 49-0-Humidity

2021-05-03 21:21:54.945 INFO ZWAVE: Node 44: value updated: 49-0-Humidity 67 => 66

2021-05-03 21:22:08.218 INFO ZWAVE: Node 51: value updated: 50-0-value-66561 238.297 => 237.59

2021-05-03 21:22:08.500 INFO ZWAVE: Node 51: value updated: 50-0-value-66817 5.723 => 5.771

2021-05-03 21:22:08.781 INFO ZWAVE: Node 51: value updated: 50-0-value-66049 744.236 => 758.937

2021-05-03 21:22:09.061 INFO ZWAVE: Node 51: value updated: 50-0-value-65537 296.788 => 296.8

2021-05-03 21:22:59.549 INFO ZWAVE: Node 47 is now awake

2021-05-03 21:23:00.142 INFO ZWAVE: Node 47: value updated: 132-0-wakeUpInterval 21600 => 21600

2021-05-03 21:23:00.146 INFO ZWAVE: Node 47: value updated: 132-0-controllerNodeId 1 => 1

2021-05-03 21:23:01.168 INFO ZWAVE: Node 18: value updated: 38-1-currentValue 10 => 0

2021-05-03 21:23:01.484 INFO ZWAVE: Node 47 is now asleep

2021-05-03 21:23:01.884 INFO ZWAVE: Node 18: metadata updated: 49-1-Power

2021-05-03 21:23:01.888 INFO ZWAVE: Node 18: value updated: 49-1-Power 38.5 => 15.9

2021-05-03 21:23:08.033 INFO ZWAVE: Node 51: value updated: 50-0-value-66561 237.59 => 238.846

2021-05-03 21:23:08.315 INFO ZWAVE: Node 51: value updated: 50-0-value-66817 5.771 => 5.402

2021-05-03 21:23:08.597 INFO ZWAVE: Node 51: value updated: 50-0-value-66049 758.937 => 719.013

2021-05-03 21:23:08.877 INFO ZWAVE: Node 51: value updated: 50-0-value-65537 296.8 => 296.812

2021-05-03 21:23:12.901 INFO ZWAVE: Node 18: metadata updated: 49-1-Power

2021-05-03 21:23:12.904 INFO ZWAVE: Node 18: value updated: 49-1-Power 15.9 => 0

2021-05-03 21:23:12.953 INFO ZWAVE: Node 19: value updated: 37-1-currentValue true => false

2021-05-03 21:23:13.184 INFO ZWAVE: Node 19: value updated: 50-1-value-66049 11.8 => 0

2021-05-03 21:23:45.400 INFO ZWAVE: Node 19: value updated: 37-1-currentValue false => false

2021-05-03 21:23:45.519 INFO ZWAVE: Node 18: value updated: 38-1-currentValue 0 => 0

2021-05-03 21:23:45.699 INFO ZWAVE: Node 18: value updated: 38-1-currentValue 0 => 0

2021-05-03 21:23:45.946 INFO ZWAVE: Node 31: value updated: 37-0-currentValue false => false

2021-05-03 21:23:46.193 INFO ZWAVE: Node 20: value updated: 38-1-currentValue 99 => 0

2021-05-03 21:23:46.441 INFO ZWAVE: Node 21: value updated: 37-1-currentValue true => false

2021-05-03 21:23:46.581 INFO ZWAVE: Node 21: value updated: 37-1-currentValue false => false

2021-05-03 21:23:46.611 INFO ZWAVE: Node 15: value updated: 38-1-currentValue 15 => 0

2021-05-03 21:23:46.882 INFO ZWAVE: Node 21: value updated: 50-1-value-66049 13.3 => 0

2021-05-03 21:23:46.901 INFO ZWAVE: Node 15: value updated: 38-1-currentValue 0 => 0

2021-05-03 21:23:48.265 INFO ZWAVE: Node 15: metadata updated: 49-1-Power

2021-05-03 21:23:48.268 INFO ZWAVE: Node 15: value updated: 49-1-Power 42.6 => 25.3

2021-05-03 21:23:51.833 INFO ZWAVE: Node 19: value updated: 37-1-currentValue false => false

2021-05-03 21:23:51.871 INFO ZWAVE: Node 19: value updated: 50-1-value-66049 0 => 0

2021-05-03 21:23:52.114 INFO ZWAVE: Node 19: value updated: 37-1-currentValue false => false

2021-05-03 21:23:52.560 INFO ZWAVE: Node 19: value updated: 37-1-currentValue false => false

2021-05-03 21:23:52.728 INFO ZWAVE: Node 29: value updated: 37-0-currentValue false => true

2021-05-03 21:23:52.753 INFO ZWAVE: Node 21: value updated: 50-1-value-66049 0 => 0

2021-05-03 21:23:52.993 INFO ZWAVE: Node 21: value updated: 50-1-value-66049 0 => 0

2021-05-03 21:23:54.167 INFO ZWAVE: Node 31: value updated: 37-0-currentValue false => false

2021-05-03 21:23:54.702 INFO ZWAVE: Node 44: metadata updated: 49-0-Air temperature

2021-05-03 21:23:54.706 INFO ZWAVE: Node 44: value updated: 49-0-Air temperature 22.5 => 22.3

2021-05-03 21:23:54.718 INFO ZWAVE: Node 20: value updated: 38-1-currentValue 0 => 0

2021-05-03 21:23:55.936 INFO ZWAVE: Node 29: value updated: 50-0-value-66049 0 => 7.9

2021-05-03 21:23:56.430 INFO ZWAVE: Node 31: value updated: 37-0-currentValue false => false
2021-05-03 21:23:56.513 INFO ZWAVE: Node 29: value updated: 50-0-value-66049 7.9 => 7.9

2021-05-03 21:23:56.675 INFO ZWAVE: Node 20: metadata updated: 49-1-Power

2021-05-03 21:23:56.679 INFO ZWAVE: Node 20: value updated: 49-1-Power 33.2 => 9.3

2021-05-03 21:23:57.035 INFO ZWAVE: Node 20: value updated: 38-1-currentValue 0 => 0

2021-05-03 21:23:57.272 INFO ZWAVE: Node 15: metadata updated: 49-1-Power

2021-05-03 21:23:57.276 INFO ZWAVE: Node 15: value updated: 49-1-Power 25.3 => 0

2021-05-03 21:23:57.380 INFO ZWAVE: Node 44: metadata updated: 49-0-Air temperature

2021-05-03 21:23:57.384 INFO ZWAVE: Node 44: value updated: 49-0-Air temperature 22.3 => 22.3

2021-05-03 21:23:57.625 INFO ZWAVE: Node 23: value updated: 37-1-currentValue true => false

2021-05-03 21:23:58.045 INFO ZWAVE: Node 20: metadata updated: 49-1-Power

2021-05-03 21:23:58.049 INFO ZWAVE: Node 20: value updated: 49-1-Power 9.3 => 0

2021-05-03 21:23:58.363 INFO ZWAVE: Node 20: metadata updated: 49-1-Power

2021-05-03 21:23:58.368 INFO ZWAVE: Node 20: value updated: 49-1-Power 0 => 0

2021-05-03 21:23:58.508 INFO ZWAVE: Node 44: metadata updated: 49-0-Air temperature

2021-05-03 21:23:58.512 INFO ZWAVE: Node 44: value updated: 49-0-Air temperature 22.3 => 22.3

2021-05-03 21:23:59.129 INFO ZWAVE: Node 29: value updated: 37-0-currentValue true => true

2021-05-03 21:23:59.419 INFO ZWAVE: Node 23: value updated: 37-1-currentValue false => false

2021-05-03 21:23:59.729 INFO ZWAVE: Node 29: value updated: 37-0-currentValue true => true

2021-05-03 21:23:59.803 INFO ZWAVE: Node 44: metadata updated: 49-0-Air temperature

2021-05-03 21:23:59.806 INFO ZWAVE: Node 44: value updated: 49-0-Air temperature 22.3 => 22.3

2021-05-03 21:23:59.873 INFO ZWAVE: Node 44: metadata updated: 49-0-Air temperature

2021-05-03 21:23:59.876 INFO ZWAVE: Node 44: value updated: 49-0-Air temperature 22.3 => 22.3

2021-05-03 21:24:00.043 INFO ZWAVE: Node 44: metadata updated: 49-0-Humidity

2021-05-03 21:24:00.046 INFO ZWAVE: Node 44: value updated: 49-0-Humidity 66 => 66

2021-05-03 21:24:00.489 INFO ZWAVE: Node 30: value updated: 37-0-currentValue false => false

2021-05-03 21:24:00.660 INFO ZWAVE: Node 19: value updated: 37-1-currentValue false => false

2021-05-03 21:24:00.749 INFO ZWAVE: Node 19: value updated: 37-1-currentValue false => false

2021-05-03 21:24:00.864 INFO ZWAVE: Node 19: value updated: 37-1-currentValue false => false

2021-05-03 21:24:01.073 INFO ZWAVE: Node 44: metadata updated: 49-0-Humidity

2021-05-03 21:24:01.076 INFO ZWAVE: Node 44: value updated: 49-0-Humidity 66 => 66

2021-05-03 21:24:01.160 INFO ZWAVE: Node 44: metadata updated: 49-0-Humidity

2021-05-03 21:24:01.163 INFO ZWAVE: Node 44: value updated: 49-0-Humidity 66 => 66

2021-05-03 21:24:01.187 INFO ZWAVE: Node 44: metadata updated: 49-0-Humidity

2021-05-03 21:24:01.190 INFO ZWAVE: Node 44: value updated: 49-0-Humidity 66 => 66

2021-05-03 21:24:01.539 INFO ZWAVE: Node 44: metadata updated: 49-0-Humidity

2021-05-03 21:24:01.542 INFO ZWAVE: Node 44: value updated: 49-0-Humidity 66 => 66

2021-05-03 21:24:01.598 INFO ZWAVE: Node 44: metadata updated: 49-0-Humidity

2021-05-03 21:24:01.602 INFO ZWAVE: Node 44: value updated: 49-0-Humidity 66 => 66

2021-05-03 21:24:01.657 INFO ZWAVE: Node 44: metadata updated: 49-0-Humidity

2021-05-03 21:24:01.660 INFO ZWAVE: Node 44: value updated: 49-0-Humidity 66 => 66

2021-05-03 21:24:02.219 INFO ZWAVE: Node 44: metadata updated: 49-0-Humidity

2021-05-03 21:24:02.223 INFO ZWAVE: Node 44: value updated: 49-0-Humidity 66 => 66

2021-05-03 21:24:02.266 INFO ZWAVE: Node 44: metadata updated: 49-0-Humidity

2021-05-03 21:24:02.269 INFO ZWAVE: Node 44: value updated: 49-0-Humidity 66 => 66

2021-05-03 21:24:02.346 INFO ZWAVE: Node 44: metadata updated: 49-0-Humidity

2021-05-03 21:24:02.350 INFO ZWAVE: Node 44: value updated: 49-0-Humidity 66 => 66

2021-05-03 21:24:02.546 INFO ZWAVE: Node 44: metadata updated: 49-0-Humidity

2021-05-03 21:24:02.549 INFO ZWAVE: Node 44: value updated: 49-0-Humidity 66 => 66

2021-05-03 21:24:02.569 INFO ZWAVE: Node 44: metadata updated: 49-0-Humidity

2021-05-03 21:24:02.572 INFO ZWAVE: Node 44: value updated: 49-0-Humidity 66 => 66

2021-05-03 21:24:02.647 INFO ZWAVE: Node 44: metadata updated: 49-0-Humidity

2021-05-03 21:24:02.651 INFO ZWAVE: Node 44: value updated: 49-0-Humidity 66 => 66

2021-05-03 21:24:02.920 INFO ZWAVE: Node 23: value updated: 50-1-value-66049 8.8 => 0

2021-05-03 21:24:02.932 INFO ZWAVE: Node 44: metadata updated: 49-0-Humidity

2021-05-03 21:24:02.934 INFO ZWAVE: Node 44: value updated: 49-0-Humidity 66 => 66

2021-05-03 21:24:02.978 INFO ZWAVE: Node 44: metadata updated: 49-0-Humidity

2021-05-03 21:24:02.982 INFO ZWAVE: Node 44: value updated: 49-0-Humidity 66 => 66

2021-05-03 21:24:03.033 INFO ZWAVE: Node 23: value updated: 50-1-value-66049 0 => 0

2021-05-03 21:24:03.059 INFO ZWAVE: Node 44: metadata updated: 49-0-Humidity

2021-05-03 21:24:03.062 INFO ZWAVE: Node 44: value updated: 49-0-Humidity 66 => 66

2021-05-03 21:24:03.798 INFO ZWAVE: Node 44: metadata updated: 49-0-Humidity

2021-05-03 21:24:03.801 INFO ZWAVE: Node 44: value updated: 49-0-Humidity 66 => 66

2021-05-03 21:24:03.826 INFO ZWAVE: Node 44: metadata updated: 49-0-Humidity

2021-05-03 21:24:03.828 INFO ZWAVE: Node 44: value updated: 49-0-Humidity 66 => 66

2021-05-03 21:24:03.885 INFO ZWAVE: Node 44: metadata updated: 49-0-Humidity

2021-05-03 21:24:03.888 INFO ZWAVE: Node 44: value updated: 49-0-Humidity 66 => 66

2021-05-03 21:24:04.059 INFO ZWAVE: Node 44: metadata updated: 49-0-Humidity

2021-05-03 21:24:04.061 INFO ZWAVE: Node 44: value updated: 49-0-Humidity 66 => 66

2021-05-03 21:24:04.125 INFO ZWAVE: Node 23: value updated: 50-1-value-66049 0 => 0

2021-05-03 21:24:04.414 INFO ZWAVE: Node 23: value updated: 50-1-value-66049 0 => 0

2021-05-03 21:24:04.537 INFO ZWAVE: Node 23: value updated: 50-1-value-66049 0 => 0

2021-05-03 21:24:08.035 INFO ZWAVE: Node 51: value updated: 50-0-value-66561 238.846 => 239.743

2021-05-03 21:24:08.256 INFO ZWAVE: Node 23: value updated: 50-1-value-66049 0 => 0

2021-05-03 21:24:08.458 INFO ZWAVE: Node 51: value updated: 50-0-value-66561 239.743 => 239.743

2021-05-03 21:24:08.739 INFO ZWAVE: Node 51: value updated: 50-0-value-66817 5.402 => 5.869

2021-05-03 21:24:09.028 INFO ZWAVE: Node 51: value updated: 50-0-value-66049 719.013 => 828.538

2021-05-03 21:24:09.310 INFO ZWAVE: Node 51: value updated: 50-0-value-65537 296.812 => 296.825

2021-05-03 21:24:14.797 INFO ZWAVE: Node 12: value updated: 37-0-currentValue true => false

2021-05-03 21:24:16.257 INFO ZWAVE: Node 30: value updated: 37-0-currentValue false => false

2021-05-03 21:24:16.439 INFO ZWAVE: Node 12: value updated: 37-0-currentValue false => false

2021-05-03 21:24:18.309 INFO ZWAVE: Node 12: value updated: 50-0-value-66049 28.9 => 0

2021-05-03 21:24:19.827 INFO ZWAVE: Node 42: value notification: 91-0-scene-003 0

2021-05-03 21:24:19.906 INFO ZWAVE: Node 12: value updated: 37-0-currentValue false => true

2021-05-03 21:24:21.049 INFO ZWAVE: Node 12: value updated: 37-0-currentValue true => true

2021-05-03 21:24:23.870 INFO ZWAVE: Node 12: value updated: 50-0-value-66049 0 => 28.9

2021-05-03 21:24:25.912 INFO ZWAVE: Node 29: value updated: 50-0-value-66049 7.9 => 2.8

2021-05-03 21:24:53.826 INFO ZWAVE: Node 12: value updated: 50-0-value-66049 28.9 => 28.9

2021-05-03 21:25:08.034 INFO ZWAVE: Node 51: value updated: 50-0-value-66561 239.743 => 239.521

2021-05-03 21:25:08.316 INFO ZWAVE: Node 51: value updated: 50-0-value-66817 5.869 => 6.082

2021-05-03 21:25:08.598 INFO ZWAVE: Node 51: value updated: 50-0-value-66049 828.538 => 884.207

2021-05-03 21:25:08.879 INFO ZWAVE: Node 51: value updated: 50-0-value-65537 296.825 => 296.837

2021-05-03 21:25:18.220 INFO ZWAVE: Node 22: value updated: 50-1-value-66049 0 => 0

2021-05-03 21:25:18.296 INFO ZWAVE: Node 22: value updated: 50-2-value-66049 0 => 0

2021-05-03 21:25:54.829 INFO ZWAVE: Node 44: metadata updated: 49-0-Air temperature

2021-05-03 21:25:54.832 INFO ZWAVE: Node 44: value updated: 49-0-Air temperature 22.3 => 22.2

2021-05-03 21:25:54.938 INFO ZWAVE: Node 44: metadata updated: 49-0-Humidity

2021-05-03 21:25:54.942 INFO ZWAVE: Node 44: value updated: 49-0-Humidity 66 => 66

2021-05-03 21:26:08.032 INFO ZWAVE: Node 51: value updated: 50-0-value-66561 239.521 => 239.55

2021-05-03 21:26:08.457 INFO ZWAVE: Node 51: value updated: 50-0-value-66817 6.082 => 4.871

2021-05-03 21:26:08.738 INFO ZWAVE: Node 51: value updated: 50-0-value-66049 884.207 => 603.22

2021-05-03 21:26:09.028 INFO ZWAVE: Node 51: value updated: 50-0-value-65537 296.837 => 296.848

2021-05-03 21:27:08.035 INFO ZWAVE: Node 51: value updated: 50-0-value-66561 239.55 => 238.653

2021-05-03 21:27:08.318 INFO ZWAVE: Node 51: value updated: 50-0-value-66817 4.871 => 4.867

2021-05-03 21:27:08.599 INFO ZWAVE: Node 51: value updated: 50-0-value-66049 603.22 => 605.328

2021-05-03 21:27:08.882 INFO ZWAVE: Node 51: value updated: 50-0-value-65537 296.848 => 296.86

2021-05-03 21:27:25.882 INFO ZWAVE: Node 42: value notification: 91-0-scene-003 0

2021-05-03 21:27:25.960 INFO ZWAVE: Node 12: value updated: 37-0-currentValue true => false

2021-05-03 21:27:27.108 INFO ZWAVE: Node 12: value updated: 37-0-currentValue false => false

2021-05-03 21:27:29.863 INFO ZWAVE: Node 12: value updated: 50-0-value-66049 28.9 => 0

2021-05-03 21:27:54.701 INFO ZWAVE: Node 44: metadata updated: 49-0-Air temperature

2021-05-03 21:27:54.705 INFO ZWAVE: Node 44: value updated: 49-0-Air temperature 22.2 => 22.2

2021-05-03 21:27:54.812 INFO ZWAVE: Node 44: metadata updated: 49-0-Humidity

2021-05-03 21:27:54.816 INFO ZWAVE: Node 44: value updated: 49-0-Humidity 66 => 64

2021-05-03 21:27:59.804 INFO ZWAVE: Node 12: value updated: 50-0-value-66049 0 => 0

2021-05-03 21:28:08.036 INFO ZWAVE: Node 51: value updated: 50-0-value-66561 238.653 => 239.165

2021-05-03 21:28:08.319 INFO ZWAVE: Node 51: value updated: 50-0-value-66817 4.867 => 4.742

2021-05-03 21:28:08.599 INFO ZWAVE: Node 51: value updated: 50-0-value-66049 605.328 => 568.458

2021-05-03 21:28:08.880 INFO ZWAVE: Node 51: value updated: 50-0-value-65537 296.86 => 296.869

2021-05-03 21:28:23.047 INFO ZWAVE: Node 51: value updated: 50-1-value-66561 234.612 => 238.895

2021-05-03 21:28:23.337 INFO ZWAVE: Node 51: value updated: 50-2-value-66561 248.475 => 251.972

2021-05-03 21:28:23.630 INFO ZWAVE: Node 51: value updated: 50-3-value-66561 242.19 => 238.376

2021-05-03 21:28:24.113 INFO ZWAVE: Node 51: value updated: 50-1-value-66817 0.825 => 0.784

2021-05-03 21:28:24.507 INFO ZWAVE: Node 51: value updated: 50-2-value-66817 2.444 => 2.002

2021-05-03 21:28:25.121 INFO ZWAVE: Node 51: value updated: 50-3-value-66817 2.45 => 1.969

2021-05-03 21:28:25.415 INFO ZWAVE: Node 51: value updated: 50-1-value-66049 127.832 => 113.861

2021-05-03 21:28:33.152 INFO ZWAVE: Node 8: metadata updated: 49-0-Air temperature

2021-05-03 21:28:33.155 INFO ZWAVE: Node 8: value updated: 49-0-Air temperature 29.8 => 30

2021-05-03 21:28:34.046 INFO ZWAVE: Node 51: value updated: 50-3-value-66049 374.848 => 281.953

2021-05-03 21:28:34.337 INFO ZWAVE: Node 51: value updated: 50-1-value-65537 52.98 => 53.015

2021-05-03 21:28:34.629 INFO ZWAVE: Node 51: value updated: 50-2-value-65537 218.078 => 218.183

2021-05-03 21:28:34.921 INFO ZWAVE: Node 51: value updated: 50-3-value-65537 25.582 => 25.671

2021-05-03 21:28:55.535 INFO ZWAVE: Node 8 is now awake

2021-05-03 21:28:56.889 INFO ZWAVE: Node 8 is now asleep

You said you switched from the original Z-Wave to Z-Wave JS, and later installed zwavejs2mqtt. Are you sure that there is only one Z-Wave Add-On running? You can’t have more than one Z-Wave Add-On running at the same time as they will compete with each other and result in extremely slow performance. Make sure that if you do still have either the original Z-Wave or Z-Wave JS Add-On’s installed that they are both stopped and disable the “Start on boot” and “Watchdog” options. If either of those continue to run after a restart, check your configuration.yaml for any old, manual entries that may be causing them to auto-start.

yes i confirm that all is disabled. 2 weeks ago i noticed that zwave js add on was still re installing after restarting, so i removed the integration and re-installed without supervision add on. Add on did not appear again.

i am stuck and don’t know what else to check as i have tried almost everything.

Can you increase logging level from INFO to DEBUG and include just the area where the delay is occurring.

Hi Matt,

i have placed log files here

i did not select any nodes as this happens on all. but at the time of testing, mainly i was using the following:

Node12, 15, 20, 21, 23, 29.

Basically this is a move scene which switches off every node above and switch on node 29. the controller is exactly near all these nodes.

So looking through the zwave logs I see a couple of things:

1.) Do you have polling set up for devices? There are some messages about polling, which is unusual (see Z-Wave JS - Home Assistant)
2.) There is lot of energy reporting going on. In the 15 minutes of logs there are over 120 energy/power reports which is a lot. Node 29 by itself reported Watts 29 times in 11 minutes. Z-wave is ok for reporting energy intermittently ( once every few minutes, or when there are large changes) but the network quick gets congested with high speed energy reporting.
3.) There is some oddities (in my opinion) where some messages are being repeated (I’m having a similar problem on my setup), but I think that is relatively minor. Here is an example:

2021-05-04T18:23:07.094Z SERIAL « 0x010d0004001507600d0100250300ae                                    (15 bytes)
2021-05-04T18:23:07.096Z CNTRLR   [Node 021] [~] [Binary Switch] currentValue: false => false       [Endpoint 1]
2021-05-04T18:23:07.103Z SERIAL » [ACK]                                                                   (0x06)
2021-05-04T18:23:07.107Z DRIVER « [Node 021] [REQ] [ApplicationCommand]
                                  └─[MultiChannelCCCommandEncapsulation]
                                    │ source:      1
                                    │ destination: 0
                                    └─[BinarySwitchCCReport]
                                        current value: false
2021-05-04T18:23:08.091Z SERIAL « 0x010d0004001507600d0100250300ae                                    (15 bytes)
2021-05-04T18:23:08.094Z CNTRLR   [Node 021] [~] [Binary Switch] currentValue: false => false       [Endpoint 1]
2021-05-04T18:23:08.099Z SERIAL » [ACK]                                                                   (0x06)
2021-05-04T18:23:08.103Z DRIVER « [Node 021] [REQ] [ApplicationCommand]
                                  └─[MultiChannelCCCommandEncapsulation]
                                    │ source:      1
                                    │ destination: 0
                                    └─[BinarySwitchCCReport]
                                        current value: false
2021-05-04T18:23:08.360Z SERIAL « 0x010d0004001507600d0100250300ae                                    (15 bytes)
2021-05-04T18:23:08.363Z CNTRLR   [Node 021] [~] [Binary Switch] currentValue: false => false       [Endpoint 1]
2021-05-04T18:23:08.368Z SERIAL » [ACK]                                                                   (0x06)
2021-05-04T18:23:08.371Z DRIVER « [Node 021] [REQ] [ApplicationCommand]
                                  └─[MultiChannelCCCommandEncapsulation]
                                    │ source:      1
                                    │ destination: 0
                                    └─[BinarySwitchCCReport]
                                        current value: false
2021-05-04T18:23:08.670Z SERIAL « 0x010d0004001507600d0100250300ae                                    (15 bytes)
2021-05-04T18:23:08.673Z CNTRLR   [Node 021] [~] [Binary Switch] currentValue: false => false       [Endpoint 1]
2021-05-04T18:23:08.679Z SERIAL » [ACK]                                                                   (0x06)
2021-05-04T18:23:08.683Z DRIVER « [Node 021] [REQ] [ApplicationCommand]
                                  └─[MultiChannelCCCommandEncapsulation]
                                    │ source:      1
                                    │ destination: 0
                                    └─[BinarySwitchCCReport]
                                        current value: false
2021-05-04T18:23:08.883Z SERIAL « 0x010d0004001507600d0100250300ae                                    (15 bytes)
2021-05-04T18:23:08.886Z CNTRLR   [Node 021] [~] [Binary Switch] currentValue: false => false       [Endpoint 1]
2021-05-04T18:23:08.892Z SERIAL » [ACK]                                                                   (0x06)
2021-05-04T18:23:08.896Z DRIVER « [Node 021] [REQ] [ApplicationCommand]
                                  └─[MultiChannelCCCommandEncapsulation]
                                    │ source:      1
                                    │ destination: 0
                                    └─[BinarySwitchCCReport]
                                        current value: false
2021-05-04T18:23:09.744Z SERIAL « 0x010d0004001507600d0100250300ae                                    (15 bytes)
2021-05-04T18:23:09.747Z CNTRLR   [Node 021] [~] [Binary Switch] currentValue: false => false       [Endpoint 1]
2021-05-04T18:23:09.754Z SERIAL » [ACK]                                                                   (0x06)
2021-05-04T18:23:09.762Z DRIVER « [Node 021] [REQ] [ApplicationCommand]
                                  └─[MultiChannelCCCommandEncapsulation]
                                    │ source:      1
                                    │ destination: 0
                                    └─[BinarySwitchCCReport]
                                        current value: false

My recommendation to start with it is to adjust the settings on your devices to avoid polling where possible. Then adjust the power reporting settings, reduce power reports to more manageable values where possible. For example if you’re tracking Watt output every minute do you also need to track KWH output every minute, or if the device supports it have it only report when it changes by certain amounts either in Watts or %.

I didn’t see any indication of messages not being sent after startup (search for “was sent: false” in the logs) or received properly. There is a lot of traffic and I don’t quite understand what you’re trying to do. Hope that gives you a starting point :slight_smile:

Matt

Hi Matt,

Thanks again for your help. i did go through all the devices and set reporting to highest for now. these where with the default values. i will check again this evening.

Hi Matt,

Today the delay is less than usual yes after doing changes in the reporting. Though if i run 3 scenes after each other for testing purposes, it will start delaying again and i have to restart it. I am attaching logs again maybe you could see something else. Also you may confirm if you can see less reporting.

Hi Matt,

Do you have time to look into the last logs i sent?

Glancing at it there does seem to be some messages about Node 008 and Node 045 not responding sometimes, but only 18 messages in the whole log.

There are also is a number of entries that say “was sent: false” which means that the zwave program tried to tell the stick to send a command, but the stick did not send it. Unfortunately there is no real reason given by the stick, and it does look like most attempts to resend were fractions of a second later and succeeded, so shouldn’t be contributing majorly to errors.

Other than that, there is still a lot of energy reporting going on. If you’re using the data then it may be okay, but if you aren’t using it consider disabling it. Usually you can do that by setting a 0 for the value, however with the Fibaro it looks like it is 100. For the wall plug there may be multiple settings to adjust like “priority power report” “standard power report” “power reporting interval” “energy reporting threshold” “power and energy periodic reports”.

So in short, not sure why it would work for a while then slow down. I’m trying to troubleshoot my own network right now where I am having it slow down as well, but I don’t have any insights at the moment. I’ll let you know if I learn anything on mine as well. :slight_smile: