Razberry Z-Way 3.0.0--CRC16 and Security classes showing up

Discussions about Z-Way software and Z-Wave technology in general
cdogg76
Posts: 39
Joined: 28 Sep 2014 23:13

Re: Razberry Z-Way 3.0.0--CRC16 and Security classes showing up

Post by cdogg76 » 22 Oct 2019 20:25

Ok, here are logs with one device that stopped responding properly (in that it wouldn't turn on/off, but it was receiving the messages). Any idea what is causing all this apparent corruption?

Code: Select all

---------------
[2019-10-21 18:10:15.334] [D] [zway] RECEIVED: ( 01 09 00 04 10 21 03 26 03 00 E5 )
[2019-10-21 18:10:15.334] [D] [zway] SENT ACK
[2019-10-21 18:10:15.335] [D] [zway] SETDATA devices.33.data.lastReceived = 0 (0x00000000)
[2019-10-21 18:10:15.335] [D] [zway] SETDATA devices.33.instances.0.commandClasses.38.data.level = 0 (0x00000000)
[2019-10-21 18:10:15.356] [D] [zway] RECEIVED: ( 01 09 00 04 10 21 03 22 03 00 E1 )
[2019-10-21 18:10:15.356] [D] [zway] SENT ACK
[2019-10-21 18:10:15.356] [E] [zway] Unknown type for command 3
[2019-10-21 18:10:15.357] [W] [zway] Got command class 0x22, command 0x03 frame from device 33 to controller, but policy do not allow it - ignoring
[2019-10-21 18:10:15.357] [D] [zway] SETDATA devices.33.data.lastReceived = 0 (0x00000000)
[2019-10-21 18:10:15.419] [D] [zway] RECEIVED: ( 01 09 00 04 10 1B 03 26 03 00 DF )
[2019-10-21 18:10:15.419] [D] [zway] SENT ACK
[2019-10-21 18:10:15.420] [D] [zway] SETDATA devices.27.data.lastReceived = 0 (0x00000000)
[2019-10-21 18:10:15.420] [D] [zway] SETDATA devices.27.instances.0.commandClasses.38.data.level = 0 (0x00000000)
[2019-10-21 18:10:15.570] [D] [zway] RECEIVED: ( 01 09 00 04 00 21 03 26 03 00 F5 )
[2019-10-21 18:10:15.570] [D] [zway] SENT ACK

------------

[2019-10-21 19:12:02.052] [D] [zway] SETDATA devices.33.data.lastReceived = 0 (0x00000000)
[2019-10-21 19:12:02.052] [D] [zway] Received reply on job (SwitchMultilevel Get)
[2019-10-21 19:12:02.052] [D] [zway] SETDATA devices.33.instances.0.commandClasses.38.data.level = 0 (0x00000000)
[2019-10-21 19:12:02.145] [D] [zway] RECEIVED: ( 01 09 00 04 10 21 03 26 03 00 E5 )
[2019-10-21 19:12:02.145] [D] [zway] SENT ACK
[2019-10-21 19:12:02.146] [D] [zway] SETDATA devices.33.data.lastReceived = 0 (0x00000000)
[2019-10-21 19:12:02.146] [D] [zway] SETDATA devices.33.instances.0.commandClasses.38.data.level = 0 (0x00000000)
[2019-10-21 19:12:02.260] [D] [zway] RECEIVED: ( 01 09 00 04 10 21 03 24 03 02 E5 )
[2019-10-21 19:12:02.260] [D] [zway] SENT ACK
[2019-10-21 19:12:02.261] [W] [zway] Got frame from device 33 to controller, but command class 0x24 is not implemented
[2019-10-21 19:12:02.261] [D] [zway] SETDATA devices.33.data.lastReceived = 0 (0x00000000)
[2019-10-21 19:12:02.280] [D] [zway] RECEIVED: ( 01 09 00 04 10 21 03 26 03 00 E5 )
[2019-10-21 19:12:02.281] [D] [zway] SENT ACK
[2019-10-21 19:12:02.281] [D] [zway] SETDATA devices.33.data.lastReceived = 0 (0x00000000)
[2019-10-21 19:12:02.281] [D] [zway] SETDATA devices.33.instances.0.commandClasses.38.data.level = 0 (0x00000000)
[2019-10-21 19:12:02.345] [D] [zway] RECEIVED: ( 01 09 00 04 00 21 03 26 03 00 F5 )
[2019-10-21 19:12:02.345] [D] [zway] SENT ACK
------------

[2019-10-21 19:36:18.950] [D] [zway] SETDATA devices.27.data.lastReceived = 0 (0x00000000)
[2019-10-21 19:36:18.951] [D] [zway] SETDATA devices.27.instances.0.commandClasses.38.data.level = 0 (0x00000000)
[2019-10-21 19:36:19.034] [D] [zway] RECEIVED: ( 01 09 00 04 10 21 03 26 03 00 E5 )
[2019-10-21 19:36:19.034] [D] [zway] SENT ACK
[2019-10-21 19:36:19.034] [D] [zway] SETDATA devices.33.data.lastReceived = 0 (0x00000000)
[2019-10-21 19:36:19.035] [D] [zway] SETDATA devices.33.instances.0.commandClasses.38.data.level = 0 (0x00000000)
[2019-10-21 19:36:19.054] [D] [zway] Job 0x13: deleted from queue
[2019-10-21 19:36:19.086] [D] [zway] RECEIVED: ( 01 09 00 04 10 21 03 26 03 00 E5 )
[2019-10-21 19:36:19.087] [D] [zway] SENT ACK
[2019-10-21 19:36:19.087] [D] [zway] SETDATA devices.33.data.lastReceived = 0 (0x00000000)
[2019-10-21 19:36:19.087] [D] [zway] SETDATA devices.33.instances.0.commandClasses.38.data.level = 0 (0x00000000)
[2019-10-21 19:36:19.137] [D] [zway] RECEIVED: ( 01 09 00 04 10 21 03 26 03 00 E5 )
[2019-10-21 19:36:19.137] [D] [zway] SENT ACK
[2019-10-21 19:36:19.137] [D] [zway] SETDATA devices.33.data.lastReceived = 0 (0x00000000)
[2019-10-21 19:36:19.137] [D] [zway] SETDATA devices.33.instances.0.commandClasses.38.data.level = 0 (0x00000000)
[2019-10-21 19:36:19.295] [D] [zway] RECEIVED: ( 01 09 00 04 10 21 03 26 03 00 E5 )
[2019-10-21 19:36:19.295] [D] [zway] SENT ACK
[2019-10-21 19:36:19.296] [D] [zway] SETDATA devices.33.data.lastReceived = 0 (0x00000000)
[2019-10-21 19:36:19.296] [D] [zway] SETDATA devices.33.instances.0.commandClasses.38.data.level = 0 (0x00000000)
[2019-10-21 19:36:19.692] [D] [zway] RECEIVED: ( 01 09 00 04 10 21 03 26 03 00 E5 )
[2019-10-21 19:36:19.692] [D] [zway] SENT ACK
[2019-10-21 19:36:19.693] [D] [zway] SETDATA devices.33.data.lastReceived = 0 (0x00000000)
[2019-10-21 19:36:19.693] [D] [zway] SETDATA devices.33.instances.0.commandClasses.38.data.level = 0 (0x00000000)
[2019-10-21 19:36:19.744] [D] [zway] RECEIVED: ( 01 09 00 04 10 21 03 26 03 00 E5 )
[2019-10-21 19:36:19.745] [D] [zway] SENT ACK
[2019-10-21 19:36:19.745] [D] [zway] SETDATA devices.33.data.lastReceived = 0 (0x00000000)
[2019-10-21 19:36:19.745] [D] [zway] SETDATA devices.33.instances.0.commandClasses.38.data.level = 0 (0x00000000)
[2019-10-21 19:36:19.869] [D] [zway] RECEIVED: ( 01 09 00 04 10 21 03 24 03 00 E7 )
[2019-10-21 19:36:19.869] [D] [zway] SENT ACK
[2019-10-21 19:36:19.870] [W] [zway] Got frame from device 33 to controller, but command class 0x24 is not implemented
[2019-10-21 19:36:19.870] [D] [zway] SETDATA devices.33.data.lastReceived = 0 (0x00000000)
[2019-10-21 19:36:19.922] [D] [zway] RECEIVED: ( 01 09 00 04 10 21 03 26 03 00 E5 )
[2019-10-21 19:36:19.922] [D] [zway] SENT ACK
[2019-10-21 19:36:19.922] [D] [zway] SETDATA devices.33.data.lastReceived = 0 (0x00000000)
[2019-10-21 19:36:19.922] [D] [zway] SETDATA devices.33.instances.0.commandClasses.38.data.level = 0 (0x00000000)
[2019-10-21 19:36:19.951] [D] [zway] RECEIVED: ( 01 09 00 04 10 21 03 26 03 00 E5 )
[2019-10-21 19:36:19.952] [D] [zway] SENT ACK
[2019-10-21 19:36:19.952] [D] [zway] SETDATA devices.33.data.lastReceived = 0 (0x00000000)
[2019-10-21 19:36:19.952] [D] [zway] SETDATA devices.33.instances.0.commandClasses.38.data.level = 0 (0x00000000)
[2019-10-21 19:36:20.004] [D] [zway] RECEIVED: ( 01 09 00 04 10 21 03 26 03 00 E5 )
[2019-10-21 19:36:20.004] [D] [zway] SENT ACK
[2019-10-21 19:36:20.005] [D] [zway] SETDATA devices.33.data.lastReceived = 0 (0x00000000)
[2019-10-21 19:36:20.005] [D] [zway] SETDATA devices.33.instances.0.commandClasses.38.data.level = 0 (0x00000000)
[2019-10-21 19:36:20.066] [D] [zway] RECEIVED: ( 01 09 00 04 10 21 03 26 03 00 E5 )
[2019-10-21 19:36:20.067] [D] [zway] SENT ACK
[2019-10-21 19:36:20.067] [D] [zway] SETDATA devices.33.data.lastReceived = 0 (0x00000000)
[2019-10-21 19:36:20.068] [D] [zway] SETDATA devices.33.instances.0.commandClasses.38.data.level = 0 (0x00000000)
[2019-10-21 19:36:20.086] [D] [zway] RECEIVED: ( 01 09 00 04 10 21 03 26 03 00 E5 )
[2019-10-21 19:36:20.086] [D] [zway] SENT ACK
[2019-10-21 19:36:20.087] [D] [zway] SETDATA devices.33.data.lastReceived = 0 (0x00000000)
[2019-10-21 19:36:20.087] [D] [zway] SETDATA devices.33.instances.0.commandClasses.38.data.level = 0 (0x00000000)
[2019-10-21 19:36:20.243] [D] [zway] RECEIVED: ( 01 09 00 04 10 21 03 26 03 00 E5 )
[2019-10-21 19:36:20.243] [D] [zway] SENT ACK
[2019-10-21 19:36:20.243] [D] [zway] SETDATA devices.33.data.lastReceived = 0 (0x00000000)
[2019-10-21 19:36:20.243] [D] [zway] SETDATA devices.33.instances.0.commandClasses.38.data.level = 0 (0x00000000)
[2019-10-21 19:36:20.275] [D] [zway] RECEIVED: ( 01 09 00 04 10 21 03 26 03 00 E5 )
[2019-10-21 19:36:20.275] [D] [zway] SENT ACK
[2019-10-21 19:36:20.276] [D] [zway] SETDATA devices.33.data.lastReceived = 0 (0x00000000)
[2019-10-21 19:36:20.276] [D] [zway] SETDATA devices.33.instances.0.commandClasses.38.data.level = 0 (0x00000000)
[2019-10-21 19:36:20.360] [D] [zway] RECEIVED: ( 01 09 00 04 10 21 03 26 03 00 E5 )
[2019-10-21 19:36:20.360] [D] [zway] SENT ACK
[2019-10-21 19:36:20.360] [D] [zway] SETDATA devices.33.data.lastReceived = 0 (0x00000000)
[2019-10-21 19:36:20.360] [D] [zway] SETDATA devices.33.instances.0.commandClasses.38.data.level = 0 (0x00000000)
[2019-10-21 19:36:20.401] [D] [zway] RECEIVED: ( 01 09 00 04 10 21 03 26 03 00 E5 )
[2019-10-21 19:36:20.401] [D] [zway] SENT ACK
[2019-10-21 19:36:20.402] [D] [zway] SETDATA devices.33.data.lastReceived = 0 (0x00000000)
[2019-10-21 19:36:20.402] [D] [zway] SETDATA devices.33.instances.0.commandClasses.38.data.level = 0 (0x00000000)
[2019-10-21 19:36:20.443] [D] [zway] RECEIVED: ( 01 09 00 04 10 21 03 26 03 00 E5 )
[2019-10-21 19:36:20.443] [D] [zway] SENT ACK
[2019-10-21 19:36:20.444] [D] [zway] SETDATA devices.33.data.lastReceived = 0 (0x00000000)
[2019-10-21 19:36:20.444] [D] [zway] SETDATA devices.33.instances.0.commandClasses.38.data.level = 0 (0x00000000)
[2019-10-21 19:36:20.506] [D] [zway] RECEIVED: ( 01 09 00 04 10 21 03 26 03 00 E5 )
[2019-10-21 19:36:20.506] [D] [zway] SENT ACK
[2019-10-21 19:36:20.507] [D] [zway] SETDATA devices.33.data.lastReceived = 0 (0x00000000)
------------

[2019-10-21 19:54:17.352] [D] [zway] SENT ACK
[2019-10-21 19:54:17.352] [D] [zway] SETDATA devices.33.data.lastReceived = 0 (0x00000000)
[2019-10-21 19:54:17.352] [D] [zway] SETDATA devices.33.instances.0.commandClasses.38.data.level = 0 (0x00000000)
[2019-10-21 19:54:17.413] [D] [zway] RECEIVED: ( 01 09 00 04 10 21 03 22 03 00 E1 )
[2019-10-21 19:54:17.413] [D] [zway] SENT ACK
[2019-10-21 19:54:17.414] [E] [zway] Unknown type for command 3
[2019-10-21 19:54:17.414] [W] [zway] Got command class 0x22, command 0x03 frame from device 33 to controller, but policy do not allow it - ignoring
[2019-10-21 19:54:17.414] [D] [zway] SETDATA devices.33.data.lastReceived = 0 (0x00000000)
[2019-10-21 19:54:17.507] [D] [zway] RECEIVED: ( 01 09 00 04 10 21 03 26 03 00 E5 )
[2019-10-21 19:54:17.507] [D] [zway] SENT ACK
-----------

[2019-10-21 20:07:35.676] [D] [zway] RECEIVED: ( 01 09 00 04 10 21 03 26 03 00 E5 )
[2019-10-21 20:07:35.676] [D] [zway] SENT ACK
[2019-10-21 20:07:35.676] [D] [zway] SETDATA devices.33.data.lastReceived = 0 (0x00000000)
[2019-10-21 20:07:35.677] [D] [zway] SETDATA devices.33.instances.0.commandClasses.38.data.level = 0 (0x00000000)
[2019-10-21 20:07:35.749] [D] [zway] RECEIVED: ( 01 09 00 04 10 21 03 66 03 00 A5 )
[2019-10-21 20:07:35.750] [D] [zway] SENT ACK
[2019-10-21 20:07:35.750] [W] [zway] Got command class 0x66, command 0x03 frame from device 33 to controller, but policy do not allow it - ignoring
[2019-10-21 20:07:35.750] [D] [zway] SETDATA devices.33.data.lastReceived = 0 (0x00000000)
[2019-10-21 20:07:35.780] [D] [zway] RECEIVED: ( 01 09 00 04 10 21 03 26 03 00 E5 )
[2019-10-21 20:07:35.780] [D] [zway] SENT ACK
[2019-10-21 20:07:35.781] [D] [zway] SETDATA devices.33.data.lastReceived = 0 (0x00000000)
[2019-10-21 20:07:35.781] [D] [zway] SETDATA devices.33.instances.0.commandClasses.38.data.level = 0 (0x00000000)
[2019-10-21 20:07:35.790] [D] [zway] RECEIVED: ( 01 09 00 04 10 21 03 26 03 00 E5 )
[2019-10-21 20:07:35.791] [D] [zway] SENT ACK
------------

[2019-10-21 20:53:56.010] [D] [zway] RECEIVED: ( 01 09 00 04 10 21 03 26 03 00 E5 )
[2019-10-21 20:53:56.010] [D] [zway] SENT ACK
[2019-10-21 20:53:56.011] [D] [zway] SETDATA devices.33.data.lastReceived = 0 (0x00000000)
[2019-10-21 20:53:56.011] [D] [zway] SETDATA devices.33.instances.0.commandClasses.38.data.level = 0 (0x00000000)
[2019-10-21 20:53:56.051] [D] [zway] Job 0x13: deleted from queue
[2019-10-21 20:53:56.104] [D] [zway] RECEIVED: ( 01 09 00 04 10 21 03 36 03 00 F5 )
[2019-10-21 20:53:56.104] [D] [zway] SENT ACK
[2019-10-21 20:53:56.104] [W] [zway] Got frame from device 33 to controller, but command class 0x36 is not implemented
[2019-10-21 20:53:56.105] [D] [zway] SETDATA devices.33.data.lastReceived = 0 (0x00000000)
[2019-10-21 20:53:56.352] [D] [zway] Job 0x13: deleted from queue
[2019-10-21 20:53:56.366] [I] [zway] Adding job: SwitchMultilevel Get
[2019-10-21 20:53:56.376] [D] [zway] SENDING (cb 0x33): ( 01 09 00 13 31 02 26 02 25 33 E4 )
[2019-10-21 20:53:56.377] [D] [zway] RECEIVED ACK
[2019-10-21 20:53:56.381] [D] [zway] RECEIVED: ( 01 04 01 13 01 E8 )
[2019-10-21 20:53:56.381] [D] [zway] SENT ACK

------------
[2019-10-21 21:14:38.408] [D] [zway] RECEIVED: ( 01 0D 00 04 10 25 07 56 01 25 03 00 67 A8 7A )
[2019-10-21 21:14:38.408] [D] [zway] SENT ACK
[2019-10-21 21:14:38.409] [D] [zway] SETDATA devices.37.data.lastReceived = 0 (0x00000000)
[2019-10-21 21:14:38.409] [D] [zway] SETDATA devices.37.instances.0.commandClasses.37.data.level = False
[2019-10-21 21:14:38.418] [D] [zway] RECEIVED: ( 01 0D 00 04 00 33 07 56 01 25 03 FF 79 58 6D )
[2019-10-21 21:14:38.418] [D] [zway] SENT ACK
[2019-10-21 21:14:38.419] [D] [zway] SETDATA devices.51.data.lastReceived = 0 (0x00000000)
[2019-10-21 21:14:38.419] [D] [zway] SETDATA devices.51.instances.0.commandClasses.37.data.level = True
[2019-10-21 21:14:38.449] [D] [zway] RECEIVED: ( 01 0D 00 04 00 33 07 56 01 25 03 FF 79 58 6D )
[2019-10-21 21:14:38.449] [D] [zway] SENT ACK
[2019-10-21 21:14:38.450] [D] [zway] SETDATA devices.51.data.lastReceived = 0 (0x00000000)
[2019-10-21 21:14:38.450] [D] [zway] SETDATA devices.51.instances.0.commandClasses.37.data.level = True
[2019-10-21 21:14:38.655] [D] [zway] RECEIVED: ( 01 0D 00 04 10 25 07 56 01 25 03 00 67 A8 7A )
[2019-10-21 21:14:38.655] [D] [zway] SENT ACK
[2019-10-21 21:14:38.655] [D] [zway] SETDATA devices.37.data.lastReceived = 0 (0x00000000)
[2019-10-21 21:14:38.656] [D] [zway] SETDATA devices.37.instances.0.commandClasses.37.data.level = False
[2019-10-21 21:14:38.668] [D] [zway] RECEIVED: ( 01 0D 00 04 10 21 07 56 01 21 03 00 67 A8 7A )
[2019-10-21 21:14:38.668] [D] [zway] SENT ACK
[2019-10-21 21:14:38.669] [I] [zway] Got frame from device 33 to controller, but command class 0x56 for device is not registered - instantiating it as not supported
[2019-10-21 21:14:38.669] [D] [zway] SETDATA devices.33.instances.0.commandClasses.86.data = Empty
[2019-10-21 21:14:38.669] [D] [zway] SETDATA devices.33.instances.0.commandClasses.86.data.supported = Empty
[2019-10-21 21:14:38.669] [D] [zway] SETDATA devices.33.instances.0.commandClasses.86.data.supported = True
[2019-10-21 21:14:38.669] [D] [zway] SETDATA devices.33.instances.0.commandClasses.86.data.version = Empty
[2019-10-21 21:14:38.669] [D] [zway] SETDATA devices.33.instances.0.commandClasses.86.data.version = 1 (0x00000001)
[2019-10-21 21:14:38.669] [D] [zway] SETDATA devices.33.instances.0.commandClasses.86.data.security = Empty
[2019-10-21 21:14:38.669] [D] [zway] SETDATA devices.33.instances.0.commandClasses.86.data.security = False
[2019-10-21 21:14:38.669] [D] [zway] SETDATA devices.33.instances.0.commandClasses.86.data.interviewDone = Empty
[2019-10-21 21:14:38.669] [D] [zway] SETDATA devices.33.instances.0.commandClasses.86.data.interviewCounter = Empty
[2019-10-21 21:14:38.670] [D] [zway] SETDATA devices.33.instances.0.commandClasses.86.data.interviewDone = False
[2019-10-21 21:14:38.670] [D] [zway] SETDATA devices.33.instances.0.commandClasses.86.data.interviewCounter = 10 (0x0000000a)
[2019-10-21 21:14:38.670] [D] [zway] SETDATA devices.33.instances.0.commandClasses.86.data.crc16Requested = Empty
[2019-10-21 21:14:38.670] [D] [zway] SETDATA devices.33.data.lastReceived = 0 (0x00000000)
[2019-10-21 21:14:38.670] [E] [zway] Node 33:0 CC CRC16: Packet CRC error (expected 0xbb68, got 0x67a8)
[2019-10-21 21:14:38.670] [E] [zway] Error returned from _zway_cc_call_handler(zway, command, controller->id, 0, data[4], &data[5]): Wrong packet from Z-Wave network or Discovery got bad data (stick communication failed) (-9)
[2019-10-21 21:14:38.729] [W] [zway] Reply not received before timeout for job (SwitchBinary Get)
[2019-10-21 21:14:38.794] [D] [zway] RECEIVED: ( 01 0D 00 04 10 25 07 56 01 25 03 00 67 A8 7A )
[2019-10-21 21:14:38.794] [D] [zway] SENT ACK
[2019-10-21 21:14:38.795] [D] [zway] SETDATA devices.37.data.lastReceived = 0 (0x00000000)
[2019-10-21 21:14:38.795] [D] [zway] SETDATA devices.37.instances.0.commandClasses.37.data.level = False
[2019-10-21 21:14:38.892] [D] [zway] RECEIVED: ( 01 0D 00 04 10 21 07 56 01 21 03 00 67 A8 7A )
[2019-10-21 21:14:38.893] [D] [zway] SENT ACK
[2019-10-21 21:14:38.893] [D] [zway] SETDATA devices.33.data.lastReceived = 0 (0x00000000)
[2019-10-21 21:14:38.893] [E] [zway] Node 33:0 CC CRC16: Packet CRC error (expected 0xbb68, got 0x67a8)
[2019-10-21 21:14:38.894] [E] [zway] Error returned from _zway_cc_call_handler(zway, command, controller->id, 0, data[4], &data[5]): Wrong packet from Z-Wave network or Discovery got bad data (stick communication failed) (-9)
[2019-10-21 21:14:38.926] [D] [zway] RECEIVED: ( 01 0D 00 04 10 21 07 56 01 21 03 00 67 A8 7A )
[2019-10-21 21:14:38.926] [D] [zway] SENT ACK
[2019-10-21 21:14:38.926] [D] [zway] SETDATA devices.33.data.lastReceived = 0 (0x00000000)
[2019-10-21 21:14:38.926] [E] [zway] Node 33:0 CC CRC16: Packet CRC error (expected 0xbb68, got 0x67a8)
[2019-10-21 21:14:38.926] [E] [zway] Error returned from _zway_cc_call_handler(zway, command, controller->id, 0, data[4], &data[5]): Wrong packet from Z-Wave network or Discovery got bad data (stick communication failed) (-9)
[2019-10-21 21:14:39.052] [D] [zway] RECEIVED: ( 01 0D 00 04 10 21 07 56 01 21 03 00 67 A8 7A )
[2019-10-21 21:14:39.052] [D] [zway] SENT ACK
[2019-10-21 21:14:39.053] [D] [zway] SETDATA devices.33.data.lastReceived = 0 (0x00000000)
[2019-10-21 21:14:39.053] [E] [zway] Node 33:0 CC CRC16: Packet CRC error (expected 0xbb68, got 0x67a8)
[2019-10-21 21:14:39.053] [E] [zway] Error returned from _zway_cc_call_handler(zway, command, controller->id, 0, data[4], &data[5]): Wrong packet from Z-Wave network or Discovery got bad data (stick communication failed) (-9)

-------
Thanks for your help!

User avatar
PoltoS
Posts: 5056
Joined: 26 Jan 2011 19:36

Re: Razberry Z-Way 3.0.0--CRC16 and Security classes showing up

Post by PoltoS » 22 Oct 2019 22:45

So far Z-Way complains on "not implemented" or "policy do not allow" and hence blocks the creation of wrong CCs. But notice the 01 09 00 04 10 <-- the 10 means Z-Wave Explore Frame - means the device was not able to reach the controller and used last cry "help me to find it".

Take a look on our analytics to get more info about your network and improve it

cdogg76
Posts: 39
Joined: 28 Sep 2014 23:13

Re: Razberry Z-Way 3.0.0--CRC16 and Security classes showing up

Post by cdogg76 » 23 Oct 2019 00:55

My network has been tricky. At times, everything runs smoothly. Other times, all hell breaks loose and a bunch of devices lose all of their neighbors. Somehow, re-including a device causes something to happen where it 'fixes' all the connections.

In any case, the timings on my network are pretty healthy. Many are in the single-digits, others in the two-digits, and only my FLIR Schlage door lock is in the hundreds up to low thousands. I do have one outlet switch in the attic that has times typically 100-200, with the occasional lost packet.

Can I send you directly a zip of a larger log to skim through that has many more error? I don't know which I should be picking and handing to you and it'd probably be faster for you to diagnose any issues directly. Although I had the issue of the network going wacky until I re-included a device (usually associated with a reboot of the Razberry, for whatever reason), I haven't had this issue with so many of my devices picking up new CCs and ignoring commands until I upgraded to 3.0.0.

If we can't fix this, then can I use a 3.0.0 backup on a 2.3.8 installation? Also, is there any way to force an ID on an inclusion? If so, I could consider excluding all devices and then re-including every one to see if that might help.

Thanks!

cdogg76
Posts: 39
Joined: 28 Sep 2014 23:13

Re: Razberry Z-Way 3.0.0--CRC16 and Security classes showing up

Post by cdogg76 » 31 Oct 2019 02:45

Hello,

Here's the packet errors I'm getting on a device that is regularly falling into this bad state:

Code: Select all

[2019-10-28 08:03:34.912] [W] [zway] Got command class 0x25, command 0x03 frame from device 25 to controller, but policy do not allow it - ignoring
[2019-10-28 08:03:35.184] [W] [zway] Got command class 0x25, command 0x03 frame from device 25 to controller, but policy do not allow it - ignoring
[2019-10-28 08:03:35.703] [W] [zway] Got command class 0x25, command 0x03 frame from device 25 to controller, but policy do not allow it - ignoring
[2019-10-28 08:03:35.755] [W] [zway] Got command class 0x25, command 0x03 frame from device 25 to controller, but policy do not allow it - ignoring
[2019-10-28 08:06:01.905] [W] [zway] Got command class 0x25, command 0x03 frame from device 58 to controller, but policy do not allow it - ignoring
[2019-10-28 08:06:01.928] [W] [zway] Got command class 0x25, command 0x03 frame from device 58 to controller, but policy do not allow it - ignoring
[2019-10-28 08:06:01.965] [W] [zway] Got command class 0x25, command 0x03 frame from device 58 to controller, but policy do not allow it - ignoring
[2019-10-28 08:06:02.363] [W] [zway] Got command class 0x25, command 0x03 frame from device 58 to controller, but policy do not allow it - ignoring
[2019-10-28 08:06:02.501] [W] [zway] Got command class 0x25, command 0x03 frame from device 58 to controller, but policy do not allow it - ignoring
[2019-10-28 08:06:03.127] [W] [zway] Got command class 0x25, command 0x03 frame from device 58 to controller, but policy do not allow it - ignoring
[2019-10-28 11:57:08.361] [W] [zway] Got command class 0x25, command 0x03 frame from device 33 to controller, but policy do not allow it - ignoring
[2019-10-28 11:57:08.852] [W] [zway] Got command class 0x25, command 0x03 frame from device 33 to controller, but policy do not allow it - ignoring
[2019-10-28 13:38:28.173] [W] [zway] Got command class 0x25, command 0x03 frame from device 25 to controller, but policy do not allow it - ignoring
[2019-10-28 17:35:12.099] [W] [zway] Got command class 0x25, command 0x03 frame from device 25 to controller, but policy do not allow it - ignoring
[2019-10-28 17:35:12.269] [W] [zway] Got command class 0x25, command 0x03 frame from device 25 to controller, but policy do not allow it - ignoring
[2019-10-28 17:35:12.279] [W] [zway] Got command class 0x25, command 0x03 frame from device 25 to controller, but policy do not allow it - ignoring
[2019-10-28 17:35:12.290] [W] [zway] Got command class 0x25, command 0x03 frame from device 25 to controller, but policy do not allow it - ignoring
[2019-10-28 17:35:12.518] [W] [zway] Got command class 0x25, command 0x03 frame from device 25 to controller, but policy do not allow it - ignoring
[2019-10-28 22:10:11.308] [W] [zway] Got frame from device 25 to controller, but command class 0x24 is not implemented
[2019-10-28 22:14:23.496] [W] [zway] Got frame from device 25 to controller, but command class 0x24 is not implemented
[2019-10-28 22:14:23.881] [W] [zway] Got frame from device 25 to controller, but command class 0x24 is not implemented
[2019-10-28 22:36:05.484] [W] [zway] Got frame from device 25 to controller, but command class 0xa6 is not implemented
[2019-10-28 23:13:21.298] [W] [zway] Got command class 0x22, command 0x07 frame from device 25 to controller, but policy do not allow it - ignoring
[2019-10-29 00:32:29.808] [W] [zway] Got command class 0x22, command 0x03 frame from device 25 to controller, but policy do not allow it - ignoring
[2019-10-29 00:32:30.109] [W] [zway] Got command class 0x22, command 0x03 frame from device 25 to controller, but policy do not allow it - ignoring
[2019-10-29 00:32:30.170] [W] [zway] Got command class 0x22, command 0x01 frame from device 25 to controller, but policy do not allow it - ignoring
[2019-10-29 00:32:30.233] [W] [zway] Got command class 0x22, command 0x03 frame from device 25 to controller, but policy do not allow it - ignoring
[2019-10-29 00:32:30.953] [W] [zway] Got command class 0x22, command 0x03 frame from device 25 to controller, but policy do not allow it - ignoring
[2019-10-29 00:32:31.506] [W] [zway] Got command class 0x22, command 0x03 frame from device 25 to controller, but policy do not allow it - ignoring
[2019-10-29 00:32:31.570] [W] [zway] Got command class 0x22, command 0x03 frame from device 25 to controller, but policy do not allow it - ignoring
[2019-10-29 01:16:26.484] [I] [zway] Got frame from device 25 to controller, but command class 0x56 for device is not registered - instantiating it as not supported
[2019-10-29 01:16:26.486] [W] [zway] Got command class 0x25, command 0x03 frame from device 25 to controller, but policy do not allow it - ignoring
[2019-10-29 06:15:56.494] [W] [zway] Got command class 0x25, command 0x03 frame from device 25 to controller, but policy do not allow it - ignoring
Are any of these of interest to what you're looking for? I can get you the logs around specific ones.

Thanks!

piet66
Posts: 84
Joined: 04 Feb 2017 17:00

Re: Razberry Z-Way 3.0.0--CRC16 and Security classes showing up

Post by piet66 » 31 Oct 2019 20:07

I had the same issue: a device, which was running since nearly 1 year without any problem suddenly didn't accept any command by ZWay. It took me a whole day to find the reason: in interview results there was the additional command class CRC16, which the device doesn't support. After new interview it now works well again.

What I don't understand: In my opinion it's impossible for the interview results to be changed afterwards after it was completed. Why does ZWay accept and process such information?
Isn't it possible to fix the interview results for such unsolicited changes without requirement by the user?
Raspberry Pi 3 Model B Rev 1.2
Raspbian GNU/Linux 9 (stretch)
ZMEERAZ 2016, SDK Version: 6.51.03, Serial API Version: 05.00
Z-Way version v3.0.0 from 2019-07-18 02:13:01 +0300 (build 146fa9b44605907737b17032131987cab573da1f)

cdogg76
Posts: 39
Joined: 28 Sep 2014 23:13

Re: Razberry Z-Way 3.0.0--CRC16 and Security classes showing up

Post by cdogg76 » 04 Nov 2019 04:06

Hi, Piet66,

Can you check your logs for any lines that contain the word "Got" and the device ID for your device that had the problem? Is Z-way receiving some unexpected (or maybe misinterpreted?) packets from that device?

Thanks!

piet66
Posts: 84
Joined: 04 Feb 2017 17:00

Re: Razberry Z-Way 3.0.0--CRC16 and Security classes showing up

Post by piet66 » 04 Nov 2019 12:40

I don't know, when this problem occured. Tried to find it in log files. Debug is switched off,

First log: A restart was made. All seems correct. No crc16 interview.

Code: Select all

[2019-10-21 17:34:18.318] [I] [core] Executing script: /*** Z-Way Home Automation Engine main executable ***************************** ...
[2019-10-21 17:34:21.753] [I] [zway] Node 65:0 CC Basic Interview done
[2019-10-21 17:34:21.753] [I] [zway] Interview for Node #65 finished.
[2019-10-21 17:34:21.754] [I] [zway] Node 65:0 CC SwitchBinary Interview done
[2019-10-21 17:34:21.754] [I] [zway] Interview for Node #65 finished.
[2019-10-21 17:34:21.754] [I] [zway] Node 65:0 CC SwitchMultilevel Interview done
[2019-10-21 17:34:21.754] [I] [zway] Interview for Node #65 finished.
[2019-10-21 17:34:21.754] [I] [zway] Node 65:0 CC SwitchAll Interview done
[2019-10-21 17:34:21.754] [I] [zway] Interview for Node #65 finished.
[2019-10-21 17:34:21.754] [I] [zway] Node 65:0 CC AssociationGroupInformation Interview done
[2019-10-21 17:34:21.754] [I] [zway] Interview for Node #65 finished.
[2019-10-21 17:34:21.755] [I] [zway] Node 65:0 CC DeviceResetLocally Interview done
[2019-10-21 17:34:21.755] [I] [zway] Interview for Node #65 finished.
[2019-10-21 17:34:21.755] [I] [zway] Node 65:0 CC ZWavePlusInfo Interview done
[2019-10-21 17:34:21.755] [I] [zway] Interview for Node #65 finished.
[2019-10-21 17:34:21.755] [I] [zway] Node 65:0 CC Configuration Interview done
[2019-10-21 17:34:21.755] [I] [zway] Interview for Node #65 finished.
[2019-10-21 17:34:21.755] [I] [zway] Node 65:0 CC Alarm Interview done
[2019-10-21 17:34:21.755] [I] [zway] Interview for Node #65 finished.
[2019-10-21 17:34:21.756] [I] [zway] Node 65:0 CC ManufacturerSpecific Interview done
[2019-10-21 17:34:21.756] [I] [zway] Interview for Node #65 finished.
[2019-10-21 17:34:21.756] [I] [zway] Node 65:0 CC PowerLevel Interview done
[2019-10-21 17:34:21.756] [I] [zway] Interview for Node #65 finished.
[2019-10-21 17:34:21.756] [I] [zway] Node 65:0 CC NodeNaming Interview done
[2019-10-21 17:34:21.756] [I] [zway] Interview for Node #65 finished.
[2019-10-21 17:34:21.756] [I] [zway] Node 65:0 CC Association Interview done
[2019-10-21 17:34:21.757] [I] [zway] Interview for Node #65 finished.
[2019-10-21 17:34:21.757] [I] [zway] Node 65:0 CC Version Interview done
[2019-10-21 17:34:21.757] [I] [zway] Interview for Node #65 finished.
[2019-10-21 17:34:22.231] [I] [zway] Job 0x62 (Check if node is failed): Node 65 is operating
[2019-10-21 17:34:23.173] [I] [zway] Job 0x80 (Get routing table line): List of neighbours for node 65: [ 17 21 36 3f 40 46 47 48 49 4f 50 ]
[2019-10-21 17:35:01.203] [I] [core] Creating device switchBinary ZWayVDev_zway_65-0-37
[2019-10-21 17:35:01.313] [I] [core] Creating device switchMultilevel ZWayVDev_zway_65-0-38
[2019-10-21 17:35:01.481] [I] [core] Creating device sensorBinary ZWayVDev_zway_65-0-113-8-5-A
[2019-10-21 17:35:01.540] [I] [core] Creating device sensorBinary ZWayVDev_zway_65-0-113-8-8-A
Second.log:First mentioning of crc16. No other interviews for this device. No other error messages. No messages with Got.

Code: Select all

[2019-10-22 07:29:02.361] [I] [core] ---  ZWayVDev_zway_65-0-38 performCommand processing: {"0":"on"}
[2019-10-22 07:29:22.814] [I] [core] ---  ZWayVDev_zway_65-0-38 performCommand processing: {"0":"on"}
[2019-10-22 18:32:01.982] [I] [core] ---  ZWayVDev_zway_65-0-38 performCommand processing: {"0":"off"}
[2019-10-22 18:32:13.072] [E] [zway] Packet FC::ApplicationCommandHandlerCallback is too short: required at least 7 bytes, got 5
[2019-10-22 18:32:13.073] [E] [zway] Error returned from (fc->callbackFunc)(zway, cjob, size, buffer): Wrong packet from Z-Wave network or Discovery got bad data (stick communication failed) (-9)
[2019-10-22 18:32:22.411] [I] [core] ---  ZWayVDev_zway_65-0-38 performCommand processing: {"0":"off"}
[2019-10-22 18:33:12.097] [E] [zway] SendData callback Id is invalid: 0x6d! Probably too late
[2019-10-22 18:33:12.098] [E] [zway] SendData callback Id is invalid: 0x6d! Probably too late
[2019-10-22 18:33:12.107] [E] [zway] SendData callback Id is invalid: 0x6d! Probably too late
[2019-10-22 18:33:19.278] [I] [zway] Node 65:0 CC CRC16 Interview done
[2019-10-22 18:33:20.586] [I] [zway] Interview for Node #65 finished.
[2019-10-22 18:33:49.956] [I] [zway] Node 65 controls CC Basic
[2019-10-22 19:00:46.488] [I] [zway] Node 65 controls CC Basic
[2019-10-22 21:26:35.911] [E] [zway] Packet FC::ApplicationCommandHandlerCallback is too short: required at least 7 bytes, got 6
[2019-10-22 21:26:35.911] [E] [zway] Error returned from (fc->callbackFunc)(zway, cjob, size, buffer): Wrong packet from Z-Wave network or Discovery got bad data (stick communication failed) (-9)
[2019-10-22 21:26:35.921] [E] [zway] Packet FC::ApplicationCommandHandlerCallback is too short: required at least 7 bytes, got 6
[2019-10-22 21:26:35.921] [E] [zway] Error returned from (fc->callbackFunc)(zway, cjob, size, buffer): Wrong packet from Z-Wave network or Discovery got bad data (stick communication failed) (-9)
[2019-10-22 21:26:35.931] [E] [zway] Packet FC::ApplicationCommandHandlerCallback is too short: required at least 7 bytes, got 6
[2019-10-22 21:26:35.931] [E] [zway] Error returned from (fc->callbackFunc)(zway, cjob, size, buffer): Wrong packet from Z-Wave network or Discovery got bad data (stick communication failed) (-9)
[2019-10-22 21:26:35.941] [E] [zway] Packet FC::ApplicationCommandHandlerCallback is too short: required at least 7 bytes, got 6
[2019-10-22 21:26:35.941] [E] [zway] Error returned from (fc->callbackFunc)(zway, cjob, size, buffer): Wrong packet from Z-Wave network or Discovery got bad data (stick communication failed) (-9)
[2019-10-23 07:31:01.477] [I] [core] ---  ZWayVDev_zway_65-0-38 performCommand processing: {"0":"on"}
[2019-10-23 07:31:21.563] [I] [core] ---  ZWayVDev_zway_65-0-38 performCommand processing: {"0":"on"}
[2019-10-23 08:13:18.480] [I] [zway] Job 0x48 (Request node neighbours update): Neighbour update started for node 65
[2019-10-23 08:13:23.227] [I] [zway] Job 0x48 (Request node neighbours update): Neighbour update failed for node 65
[2019-10-23 08:13:59.959] [I] [zway] Job 0x48 (Request node neighbours update): Neighbour update started for node 65
[2019-10-23 08:14:00.693] [I] [zway] Job 0x48 (Request node neighbours update): Neighbour update started for node 65
[2019-10-23 08:14:03.314] [I] [zway] Job 0x48 (Request node neighbours update): Neighbour update started for node 65
[2019-10-23 08:14:09.400] [I] [zway] Job 0x48 (Request node neighbours update): Neighbour update done for node 65
[2019-10-23 08:14:09.472] [I] [zway] Job 0x80 (Get routing table line): List of neighbours for node 65: [ 02 17 1b 21 2f 36 3f 40 46 47 48 49 4f 50 ]
[2019-10-23 18:30:01.230] [I] [core] ---  ZWayVDev_zway_65-0-38 performCommand processing: {"0":"off"}
[2019-10-23 18:30:22.773] [I] [core] ---  ZWayVDev_zway_65-0-38 performCommand processing: {"0":"off"}
Third log: New restart. crc16 mentioned.

Code: Select all

[2019-10-26 07:35:21.660] [I] [core] ---  ZWayVDev_zway_65-0-38 performCommand processing: {"0":"on"}
[2019-10-26 10:34:17.113] [I] [core] Executing script: /*** Z-Way Home Automation Engine main executable ***************************** ...
[2019-10-26 10:34:20.781] [I] [zway] Node 65:0 CC Basic Interview done
[2019-10-26 10:34:20.781] [I] [zway] Interview for Node #65 finished.
[2019-10-26 10:34:20.781] [I] [zway] Node 65:0 CC SwitchBinary Interview done
[2019-10-26 10:34:20.781] [I] [zway] Interview for Node #65 finished.
[2019-10-26 10:34:20.781] [I] [zway] Node 65:0 CC SwitchMultilevel Interview done
[2019-10-26 10:34:20.781] [I] [zway] Interview for Node #65 finished.
[2019-10-26 10:34:20.782] [I] [zway] Node 65:0 CC SwitchAll Interview done
[2019-10-26 10:34:20.782] [I] [zway] Interview for Node #65 finished.
[2019-10-26 10:34:20.782] [I] [zway] Node 65:0 CC AssociationGroupInformation Interview done
[2019-10-26 10:34:20.782] [I] [zway] Interview for Node #65 finished.
[2019-10-26 10:34:20.782] [I] [zway] Node 65:0 CC DeviceResetLocally Interview done
[2019-10-26 10:34:20.782] [I] [zway] Interview for Node #65 finished.
[2019-10-26 10:34:20.783] [I] [zway] Node 65:0 CC ZWavePlusInfo Interview done
[2019-10-26 10:34:20.783] [I] [zway] Interview for Node #65 finished.
[2019-10-26 10:34:20.783] [I] [zway] Node 65:0 CC Configuration Interview done
[2019-10-26 10:34:20.783] [I] [zway] Interview for Node #65 finished.
[2019-10-26 10:34:20.783] [I] [zway] Node 65:0 CC Alarm Interview done
[2019-10-26 10:34:20.783] [I] [zway] Interview for Node #65 finished.
[2019-10-26 10:34:20.784] [I] [zway] Node 65:0 CC ManufacturerSpecific Interview done
[2019-10-26 10:34:20.784] [I] [zway] Interview for Node #65 finished.
[2019-10-26 10:34:20.784] [I] [zway] Node 65:0 CC PowerLevel Interview done
[2019-10-26 10:34:20.784] [I] [zway] Interview for Node #65 finished.
[2019-10-26 10:34:20.784] [I] [zway] Node 65:0 CC NodeNaming Interview done
[2019-10-26 10:34:20.784] [I] [zway] Interview for Node #65 finished.
[2019-10-26 10:34:20.784] [I] [zway] Node 65:0 CC Association Interview done
[2019-10-26 10:34:20.784] [I] [zway] Interview for Node #65 finished.
[2019-10-26 10:34:20.785] [I] [zway] Node 65:0 CC Version Interview done
[2019-10-26 10:34:20.785] [I] [zway] Interview for Node #65 finished.
[2019-10-26 10:34:20.785] [I] [zway] Node 65:0 CC CRC16 Interview done
[2019-10-26 10:34:20.785] [I] [zway] Interview for Node #65 finished.
[2019-10-26 10:34:21.305] [I] [zway] Job 0x62 (Check if node is failed): Node 65 is operating
[2019-10-26 10:34:22.180] [I] [zway] Job 0x80 (Get routing table line): List of neighbours for node 65: [ 03 1b 27 36 3f 40 46 47 48 4f 50 ]
[2019-10-26 10:35:00.424] [I] [core] Creating device switchBinary ZWayVDev_zway_65-0-37
[2019-10-26 10:35:00.552] [I] [core] Creating device switchMultilevel ZWayVDev_zway_65-0-38
[2019-10-26 10:35:00.674] [I] [core] Creating device sensorBinary ZWayVDev_zway_65-0-113-8-5-A
[2019-10-26 10:35:00.736] [I] [core] Creating device sensorBinary ZWayVDev_zway_65-0-113-8-8-A
[2019-10-26 18:25:01.358] [I] [core] ---  ZWayVDev_zway_65-0-38 performCommand processing: {"0":"off"}
Raspberry Pi 3 Model B Rev 1.2
Raspbian GNU/Linux 9 (stretch)
ZMEERAZ 2016, SDK Version: 6.51.03, Serial API Version: 05.00
Z-Way version v3.0.0 from 2019-07-18 02:13:01 +0300 (build 146fa9b44605907737b17032131987cab573da1f)

User avatar
PoltoS
Posts: 5056
Joined: 26 Jan 2011 19:36

Re: Razberry Z-Way 3.0.0--CRC16 and Security classes showing up

Post by PoltoS » 07 Nov 2019 03:05

Please set Debug log level, not Info (log-level field in config.xml)

Post Reply