Z-Wave timeouts

robjkamp · December 6, 2023, 4:39pm

When reinitializing a device it also takes a long time to go past “VERSION”.

robjkamp · December 6, 2023, 4:42pm

Sometimes sending a command to the light also helps in it starting to listen again.

robjkamp · December 6, 2023, 4:49pm

This is the amount of NAK’s (116 per minute) are registered in the Log file. All going to Node 255. Can this count for the insanely growing number of thread on my system as well?

2023-12-06 17:46:40.544 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:46:40.544 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:46:41.614 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:46:41.614 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:46:42.683 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:46:42.683 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:46:43.752 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:46:43.752 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:46:44.822 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:46:44.823 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:46:45.893 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:46:45.893 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:46:46.964 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:46:46.964 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:46:48.034 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:46:48.034 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:46:49.105 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:46:49.105 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:46:50.175 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:46:50.175 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:46:51.244 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:46:51.244 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:46:52.314 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:46:52.314 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:46:53.383 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:46:53.383 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:46:54.453 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:46:54.453 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:46:55.523 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:46:55.524 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:46:56.593 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:46:56.593 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:46:57.662 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:46:57.662 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:46:58.731 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:46:58.731 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:46:59.800 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:46:59.801 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:00.870 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:00.870 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:01.940 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:01.941 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:03.010 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:03.010 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:04.079 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:04.079 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:05.148 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:05.148 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:06.218 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:06.218 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:07.287 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:07.287 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:08.358 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:08.358 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:09.428 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:09.428 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:10.498 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:10.498 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:11.567 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:11.567 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:12.637 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:12.637 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:13.706 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:13.706 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:14.775 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:14.775 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:15.845 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:15.845 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:16.916 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:16.916 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:17.986 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:17.986 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:19.057 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:19.057 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:20.127 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:20.127 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:21.197 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:21.198 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:22.267 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:22.267 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:23.338 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:23.338 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:24.408 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:24.408 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:25.479 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:25.479 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:26.550 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:26.550 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:27.620 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:27.621 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:28.691 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:28.691 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:29.761 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:29.761 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:30.832 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:30.832 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:31.901 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:31.901 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:32.970 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:32.971 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:34.040 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:34.040 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:35.109 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:35.110 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:36.180 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:36.180 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:37.250 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:37.250 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:38.319 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:38.319 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:39.389 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:39.390 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:40.459 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:40.459 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:41.528 [DEBUG] [nal.protocol.ZWaveTransactionManager] - processReceiveMessage input 0<>128 : Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=
2023-12-06 17:47:41.528 [DEBUG] [nal.protocol.ZWaveTransactionManager] - Received msg (0): Message: class=null[0], type=NAK[3], dest=255, callback=0, payload=

apella12 · December 6, 2023, 8:01pm

Sorry to drop off there, I was upgrading to M4 and had problems.

I don’t know if he has time, but @chris need to look at this. It is beyond my experience and knowledge.
FWIW, my thoughts;

The only messages that seem to get through are from Node 29 and they use CRC_16_ENCAP. There are also numerous messages about mismatched CRC
WaveCRC16EncapsulationCommandClass] - NODE 31: CRC check failed message contains EE BE but should be AA 3D From the above NAK also is related to failed checks. Were these nodes included securely and did anything happen to 16 byte code on the controller UI page? Node 255 is the controller, so the binding and controller are not speaking the same language. Is there a loose wire and/or is the hat securely fastened?
I’m a little concerned about the “7 Pro” using the 700 chip, but none of the messages in the log are the issues I’ve seen with a 700 controller. For example the messages that get through use ApplicationCommandHandler (0x04) which is the same as a 500 chip uses. How long have you had that controller? Also if you get a chance, run a debug from an OH startup and look for something like these;
Got MessageGetVersion response. Version=Z-Wave 6.07, Library Type=1 Got MessageGetVersion response. Version=Z-Wave 7.19, Library Type=7
I’m curious about what SDK this device is using.
As to nvm backup, I’ve never used these devices, but it sounds like the Zway application is handling that ok and from your report that is not helping.

EDIT: I did think of something last night. After a network restore a soft reset is often required especially on 7 series controllers. For a Zstick this means unplug and replug after a nvm operation. From the Debug the binding seems to be trying to do a soft reset, but the controller is not responding. For your controller you might need to shutdown the Pi and then restart. I’m thinking a reboot might happen too fast (capacitors could still have a charge). Might be worth a try

robjkamp · December 9, 2023, 8:05pm

The reset was all my doing. Sometimes after a restart it helps to perform a Synchronize Network on the brdige then save the bridge. The wait for it to come back and then perform a Soft Reset Controller and save again.

apella12 · December 9, 2023, 8:52pm

FYI- unless you have more than one controller that command doesn’t do anything. IIRC it tells the primary controller to send node information to the other controllers.

robjkamp · December 11, 2023, 8:42am

Good to know.

robjkamp · January 13, 2024, 11:59am

Another question on this topic. In the z-way-server community a scheduled soft-reset of the controller stick is very helpful. Can this be achieved in OpenHAB?

apella12 · January 13, 2024, 2:44pm

Yes. From the UI page for the controller near the bottom. Two comments;

I don’t have real any experience with this.
From the debug log viewer extract in Post 7 doesn’t seem to work (assuming this was from OH)

kristofejro · January 13, 2024, 3:37pm

What does such soft-reset execatly do?

robjkamp · January 13, 2024, 6:56pm

It performs a unplug and plugin action.

robjkamp · January 13, 2024, 6:57pm

I know it can be done from the UI. I would like to perform this from the cron if possible.

kristofejro · January 13, 2024, 7:00pm

Thanks for that information.
Do you use it when z-wave is getting timeouts?

robjkamp · January 13, 2024, 7:43pm

Indeed

apella12 · January 13, 2024, 8:29pm

Sorry do not know.

Separately, I have some yellow flags about the RazBerry 7 Pro. There was also a person with a problem on the zwave github site. One thing that seems odd for a 700 chip controller is that it uses ApplicationCommandHandler (0x04) for unsolicited messages (like the 500 chip), rather than BridgeApplicationCommand (0xa8) like the USB based 700 controllers. This makes me think that the SDK was modified so the device could work with bindings that had not yet implemented (0xa8) but raises a flag as to what else was modified. I also wonder since the stable OH4.1 release can handle (0xa8) that maybe the firmware in the Razberry might transition over? Are you on OH4.1.x?

Also, I have seen earlier versions of the SDK than 7.17.2 in some Razberry 7 debugs and there is a note on the Zwave JS site about recommended 700 SDK’s. I do not know what you have, but maybe use a OTW upgrade to 7.18.x, if you are not there already. I used 7.18.3 with all my 700 controller testing.

Lastly, (and I do not think this is the real problem) but it was recently found that orphan links can cause excess command polling of all channels. Might want to see if you have some (See post here.)

Again sorry I could not help with the reset via rule/cron, but the timeouts should not be happening unless something else is wrong.

edit: I did think of something similar (to the soft reset) that might be accessible by rule (but I don’t know how myself), that is to Stop and Start the Zwave binding within the karaf console. Also the API has install/uninstall binding option. Both should clear the zwave queues and reinitialize the RazBerry.

rtdog · January 13, 2024, 9:08pm

robjkamp,

I have discovered that the menu item “Reinitialize the device” is missing on a zwave device in the case that initialization did not yet complete. To confirm this is the case for your devices you can turn on DEBUG for zwave and hit “Heal the device”. I would expect to see “Can not start heal as initialisation is not complete” in the log file for that node. That log message will tell you the initialization state as well.

In my experience, in the case that the zwave device did not initialize after a startup or network heal after some short time ~3 minutes, then it will never initialize. I’m working on some coping mechanisms on how to detect this and reinitialize, etc.

I’m skeptical that this issue is directly related to your lightbulb problem, but could be tangentially related through the general problem of a zwave network performance issue.

robjkamp · January 15, 2024, 10:37am

I’m on OH4.1.1.

I get about 30000 [WARN ] [ve.internal.protocol.ZWaveController] - TODO: Implement processing of Request Message = -- (0xa) per day.

apella12 · January 15, 2024, 9:09pm

The problem is the controller_softreset. On the UI code tab is that set to false? After that change, stop and start the ZWave binding (hopefully to clear) and never use softreset again. Then we can see what the underlying issue is.

tl;dr
From the ZW spec;

This command is used to request the Z-Wave Module to perform a soft reset. The Soft Reset Command Identifier is 0x08.
The frame flow for this command is an Acknowledged frame.
I can’t quite see why the OH Zwave command is sent more than once per the JAVA doc. Maybe that is because your Razberry is sending NAK, not ACK, so the Soft Reset Command keeps repeating?

 /**
     * Sends a request to perform a soft reset on the controller. This will just
     * reset the controller - probably similar to a power cycle. It doesn't
     * reinitialise the network, or change the network configuration.
     * <p>
     * <b>NOTE</b>: On some (most!) sticks, this doesn't return a response. Therefore, the number of retries is set to
     * 1. <br>
     * <b>NOTE</b>: On some (most!) ZWave-Plus sticks, this can cause the stick to hang.
     *
     */

Back to the Zwave spec (note that SHOULD does not need MUST)
Note: A Z-Wave Module SHOULD issue a Z-Wave API Started Command when it has completed the reset operation. The Z-Wave API Started Command Command Identifier is 0x0A
Your Razberry is sending this (Z-Wave API Started Command). The OpenHAB Zwave binding is not set up for this.

You could also open an issue on the zwave github to find why the command is still repeating, but I don’t think this is a helpful command.

robjkamp · January 16, 2024, 7:35am

This is part the code tab.

UID: zwave:serial_zstick:99c0ff6689
label: Z-Wave Serial Controller
thingTypeUID: zwave:serial_zstick
configuration:
  controller_softreset: false
  security_networkkey: A KEY
  security_inclusionmode: 0
  controller_sisnode: 1
  controller_maxawakeperiod: 20
  controller_sync: false
  controller_master: true
  inclusion_mode: 1
  port: /dev/ttyAMA0
  controller_wakeupperiod: 3600
  controller_exclude: false
  heal_time: 2
  controller_inclusiontimeout: 30
  controller_hardreset: false
...

apella12 · January 16, 2024, 3:26pm

That should be fine.

Did a soft reset on my test system with Aeotec Zstick and it worked. At this point all roads lead to the Razberry (IMO). Comparison to your debug (tried to line up the messages).
zwave-timeouts-reset controller.txt (3.4 KB)

As noted above I would stop using the Soft Reset and upgrade the Razberry firmware to see if that helps (or see what new adventures await). If you don’t want to do that you could save your network and factory reset the Razberry, then reload network. Once that is done a ZW Debug level startup might provide a clue to the root cause (if it is not fixed). Buying a USB backup stick could be a good idea too.

Good luck