[Z-Wave] Maximum Awake time period reached

Add-ons Bindings
,
1

Hi guys,

Since some time (probably since upgrade to 3.3.0 - Release Build) I am observing in the log file entries from Z-Wave:

2022-07-30 16:58:37.643 [INFO ] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: Maximum Awake time period reached, state REQUEST_NIF count 20, messages 0
2022-07-30 17:22:05.458 [INFO ] [ng.zwave.internal.protocol.ZWaveNode] - NODE 24: Maximum Awake time period reached, state REQUEST_NIF count 20, messages 1
2022-07-30 17:55:49.470 [INFO ] [ng.zwave.internal.protocol.ZWaveNode] - NODE 36: Maximum Awake time period reached, state REQUEST_NIF count 20, messages 1
2022-07-30 19:27:25.983 [INFO ] [ng.zwave.internal.protocol.ZWaveNode] - NODE 26: Maximum Awake time period reached, state REQUEST_NIF count 20, messages 1
2022-07-31 00:03:32.918 [INFO ] [ng.zwave.internal.protocol.ZWaveNode] - NODE 36: Maximum Awake time period reached, state DYNAMIC_VALUES count 20, messages 1
2022-07-31 01:19:53.812 [INFO ] [ng.zwave.internal.protocol.ZWaveNode] - NODE 26: Maximum Awake time period reached, state REQUEST_NIF count 20, messages 1
2022-07-31 03:32:57.796 [INFO ] [ng.zwave.internal.protocol.ZWaveNode] - NODE 25: Maximum Awake time period reached, state SUC_ROUTE count 20, messages 1
2022-07-31 04:56:09.242 [INFO ] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: Maximum Awake time period reached, state UPDATE_NEIGHBORS count 20, messages 1
2022-07-31 05:20:42.792 [INFO ] [ng.zwave.internal.protocol.ZWaveNode] - NODE 24: Maximum Awake time period reached, state UPDATE_NEIGHBORS count 20, messages 1
2022-07-31 06:11:15.829 [INFO ] [ng.zwave.internal.protocol.ZWaveNode] - NODE 36: Maximum Awake time period reached, state DYNAMIC_VALUES count 20, messages 1
2022-07-31 07:22:36.566 [INFO ] [ng.zwave.internal.protocol.ZWaveNode] - NODE 6: Maximum Awake time period reached, state UPDATE_NEIGHBORS count 20, messages 1
2022-07-31 07:42:31.906 [INFO ] [ng.zwave.internal.protocol.ZWaveNode] - NODE 42: Maximum Awake time period reached, state UPDATE_NEIGHBORS count 20, messages 1
2022-07-31 11:20:09.392 [INFO ] [ng.zwave.internal.protocol.ZWaveNode] - NODE 24: Maximum Awake time period reached, state DELETE_SUC_ROUTES count 20, messages 0
2022-07-31 13:36:06.674 [INFO ] [ng.zwave.internal.protocol.ZWaveNode] - NODE 42: Maximum Awake time period reached, state UPDATE_NEIGHBORS count 20, messages 1
2022-07-31 16:14:09.697 [INFO ] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: Maximum Awake time period reached, state SUC_ROUTE count 20, messages 0
2022-07-31 16:15:24.919 [INFO ] [ng.zwave.internal.protocol.ZWaveNode] - NODE 6: Maximum Awake time period reached, state DELETE_ROUTES count 20, messages 1
2022-07-31 17:19:18.416 [INFO ] [ng.zwave.internal.protocol.ZWaveNode] - NODE 24: Maximum Awake time period reached, state SUC_ROUTE count 20, messages 0
2022-07-31 19:29:36.947 [INFO ] [ng.zwave.internal.protocol.ZWaveNode] - NODE 42: Maximum Awake time period reached, state RETURN_ROUTES count 20, messages 1
2022-07-31 20:43:59.728 [INFO ] [ng.zwave.internal.protocol.ZWaveNode] - NODE 36: Maximum Awake time period reached, state DYNAMIC_VALUES count 20, messages 0
2022-07-31 22:12:49.821 [INFO ] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: Maximum Awake time period reached, state SUC_ROUTE count 20, messages 0
2022-07-31 23:18:27.914 [INFO ] [ng.zwave.internal.protocol.ZWaveNode] - NODE 24: Maximum Awake time period reached, state RETURN_ROUTES count 20, messages 1
2022-08-01 02:51:43.569 [INFO ] [ng.zwave.internal.protocol.ZWaveNode] - NODE 36: Maximum Awake time period reached, state DYNAMIC_VALUES count 20, messages 0
2022-08-01 03:33:01.002 [INFO ] [ng.zwave.internal.protocol.ZWaveNode] - NODE 25: Maximum Awake time period reached, state SUC_ROUTE count 20, messages 1
2022-08-01 04:11:48.722 [INFO ] [ng.zwave.internal.protocol.ZWaveNode] - NODE 10: Maximum Awake time period reached, state SUC_ROUTE count 20, messages 0
2022-08-01 04:15:44.739 [INFO ] [ng.zwave.internal.protocol.ZWaveNode] - NODE 6: Maximum Awake time period reached, state UPDATE_NEIGHBORS count 20, messages 1
2022-08-01 04:31:16.728 [INFO ] [ng.zwave.internal.protocol.ZWaveNode] - NODE 12: Maximum Awake time period reached, state UPDATE_NEIGHBORS count 20, messages 1
2022-08-01 05:17:42.617 [INFO ] [ng.zwave.internal.protocol.ZWaveNode] - NODE 24: Maximum Awake time period reached, state RETURN_ROUTES count 20, messages 1
2022-08-01 06:37:41.303 [INFO ] [ng.zwave.internal.protocol.ZWaveNode] - NODE 26: Maximum Awake time period reached, state UPDATE_NEIGHBORS count 20, messages 1
2022-08-01 07:16:16.041 [INFO ] [ng.zwave.internal.protocol.ZWaveNode] - NODE 42: Maximum Awake time period reached, state SUC_ROUTE count 20, messages 1
2022-08-01 10:16:10.909 [INFO ] [ng.zwave.internal.protocol.ZWaveNode] - NODE 6: Maximum Awake time period reached, state RETURN_ROUTES count 20, messages 1

Set of devices that are reporting this is constant (7 devices out of all 30 z-wave) and all are battery powered. All of them are working just fine.

Does anyone know what it is and should I be worried about it? Earlier such log entries were not present in my log. No changes in the openhab infrastructure were made. I am on RPi4 (raspbian) with Aeotec Z-Wave USB Z-Stick Controller.

2

I put that INFO log in with some changes to the zwave battery device sleep timer. Prior to OH3.3 there was either a 1 second awake period maximum for a fully configured node or a 5 second maximum for a not fully configured node. Not fully configured includes device initialization, after an OH restart, and likely in your case, a network heal.

In OH 3.3 the sleep timer duration is variable in 0.5 second intervals up to a user defined maximum. The default maximum is 10 seconds but can be set up to 20 seconds (On the controller UI page under advanced). The goal was to achieve battery device initialization and heals in one awake period yet save battery life by sleeping as soon as all commands are completed.

What I observed in testing is that some network heal messages can take a long time in larger networks and/or on battery nodes that are remote. However, the heal is usually completed in the next wakeup. Also (IMO) the heal is not performance affecting, it is just a re-evaluation of the routing and neighbors. If performance is good before the heal, it will likely be the same after (particularly if this is done daily). Personally, I do not run a network heal unless I have made or added devices, or something doesn’t work well. Not running also saves battery life, if that is of concern.

The idea with the INFO versus DEBUG was that the maximum could be changed, so you could try that to reduce the frequency (an occasional INFO is even less of a problem). Or you could just ignore, it is just INFO. Also a quick way to see if the heal is completed is to see the “Reinitialize Device” is among the five lines at the bottom of the device UI page.

Bob

1 Like
3

Thanks @apella12 for your reply.

I put that INFO log in with some changes to the zwave battery device sleep timer.

Does it mean that you are binding developer?

In OH 3.3 the sleep timer duration is variable in 0.5 second intervals up to a user defined maximum. The default maximum is 10 seconds but can be set up to 20 seconds (On the controller UI page under advanced). The goal was to achieve battery device initialization and heals in one awake period yet save battery life by sleeping as soon as all commands are completed.

So changing it to 20 may help to get rid of this log entries?

awake_time
awake_time746Ă—90 8.82 KB

4

Heavens No ! I just authored a PR on the battery timer for OH3.3. About 0.1% (at best) of the zwave binding.

Yes

Bob

5

:smiley:

I will play with that setting then and let know. Thanks.

6

I have checked few settings: 10, 15, 20 and it does not imapct frequency of log entries “Maximum Awake time period reached”. It shows up no matter what value is set.

For that moment I will stick with default value 10.

Tnanks Bob for your help.

7

Hello Kris.
Have you solved the problem?
I also have the LOG entries and would like to have them gone.
Christian

8

Hi @cidi
It is hard to say I have resolved it :slight_smile: because it is not an error nor warning.
It is just information. I have left it as it is.

9

I’ve reduced this down to debug level.

2 Likes