S2 Qubino Mini dimmers randomly go to "Is Failed"
Posted: 12 Jun 2020 09:57
I've a number of Qubino Mini Dimmers, support S2 security, in my new home setup.
I've been running this setup since November 2019, and have had intermittent random failure of some of these Qubino S2 devices.
Now I didn't have the perfect reception setup antenna wise yet, so I figured it would improve when I would have a better setup.
Now that 3.06 z-way has stabilised my system, and the antenna reception is also greatly improved by adding a u.fl and external antenna, I still have the random failure of some of the Mini Dimmers.
It's hard for me to pin down when this occurs exactly, it can be fixed by cutting power to the Qubino Module. However I'd like to understand what causes this "Is Failed" state.
Is it the razberry or the qubino device having an issue, and how should I go about debugging this?
Thing worth noting:
I don't have any other S2 devices except the Qubino Mini Dimmers.
It's not the same module failing all the time, It seems random a bit
Although it seems like the modules that tend to be furthest away from the controller suffer this issue the most.
Also, but I don't have enough empirical data, it's just a hunch, this tends to happen when my raspberrypi is busy / having a high CPU load.
By analysing the logs, it looks like the razberry is waiting for a reply on the "S2 Nonce Get" command, but never gets it when the module is on "Is Failed" state.
When I trigger an interview when the module is in failed state, and explicitly ask SecurityS2 interview, you'll see the request command being scheduled again:
[2020-06-12 08:45:08.510] [D] [zway] SETDATA devices.26.instances.0.commandClasses.159.data.grantedKeys.S0 = False
[2020-06-12 08:45:08.511] [D] [zway] SETDATA devices.26.instances.0.commandClasses.159.data.grantedKeys.S2Unauthenticated = False
[2020-06-12 08:45:08.513] [D] [zway] SETDATA devices.26.instances.0.commandClasses.159.data.grantedKeys.S2Authenticated = True
[2020-06-12 08:45:08.515] [D] [zway] SETDATA devices.26.instances.0.commandClasses.159.data.grantedKeys.S2Access = False
[2020-06-12 08:45:08.516] [D] [zway] SETDATA devices.26.instances.0.commandClasses.159.data.security = True
[2020-06-12 08:45:08.518] [D] [zway] SETDATA devices.26.instances.0.commandClasses.159.data.secureNodeInfoFrames.S2Authenticated = byte[0]
[2020-06-12 08:45:08.520] [D] [zway] ( zero-length buffer )
[2020-06-12 08:45:08.521] [zway] Node 26:0 CC SecurityS2: requesting secure NIF for security class S2 Authenticated
[2020-06-12 08:45:08.523] [zway] Using security scheme S2 Authenticated
[2020-06-12 08:45:08.524] [zway] Adding job: Secure S2 NIF Get
[2020-06-12 08:45:08.526] [zway] Job 0x13 (Security S2 Nonce Get): Cancelling job: Security S2 Nonce Get
[2020-06-12 08:45:08.527] [zway] Removing job: Security S2 Nonce Get
[2020-06-12 08:45:08.527] [zway] Adding job: Security S2 Nonce Get
[2020-06-12 08:45:08.527] [D] [zway] Security S2 send timer set to 100.000000
[2020-06-12 08:45:13.758] [D] [zway] Job 0x3b: deleted from queue
followed by
[2020-06-12 08:46:56.057] [D] [zway] Security S2 send timeout event
[2020-06-12 08:46:56.059] [zway] Job 0x13 (Secure S2 NIF Get): Security S2 failed to prepare S2 packet
[2020-06-12 08:46:56.071] [zway] Job 0x13 (Security S2 Nonce Get): Cancelling job: Security S2 Nonce Get
[2020-06-12 08:46:56.072] [zway] Removing job: Security S2 Nonce Get
[2020-06-12 08:46:56.074] [zway] Adding job: Security S2 Nonce Get
[2020-06-12 08:46:56.076] [D] [zway] Security S2 send timer set to 100.000000
Controller info:
Firmware
Library Type: Static Controller
SDK Version: 6.81.01
Serial API Version: 05.37
Software Information
Version number: v3.0.6
Compile-ID: 82a4fd59993dc610c06507351714f95f21475262
Compile-Date: 2020-04-28 13:52:20 +0300
UI
UI version 1.5.1
Built date 03-04-2020 13:45:40
I've been running this setup since November 2019, and have had intermittent random failure of some of these Qubino S2 devices.
Now I didn't have the perfect reception setup antenna wise yet, so I figured it would improve when I would have a better setup.
Now that 3.06 z-way has stabilised my system, and the antenna reception is also greatly improved by adding a u.fl and external antenna, I still have the random failure of some of the Mini Dimmers.
It's hard for me to pin down when this occurs exactly, it can be fixed by cutting power to the Qubino Module. However I'd like to understand what causes this "Is Failed" state.
Is it the razberry or the qubino device having an issue, and how should I go about debugging this?
Thing worth noting:
I don't have any other S2 devices except the Qubino Mini Dimmers.
It's not the same module failing all the time, It seems random a bit
Although it seems like the modules that tend to be furthest away from the controller suffer this issue the most.
Also, but I don't have enough empirical data, it's just a hunch, this tends to happen when my raspberrypi is busy / having a high CPU load.
By analysing the logs, it looks like the razberry is waiting for a reply on the "S2 Nonce Get" command, but never gets it when the module is on "Is Failed" state.
When I trigger an interview when the module is in failed state, and explicitly ask SecurityS2 interview, you'll see the request command being scheduled again:
[2020-06-12 08:45:08.510] [D] [zway] SETDATA devices.26.instances.0.commandClasses.159.data.grantedKeys.S0 = False
[2020-06-12 08:45:08.511] [D] [zway] SETDATA devices.26.instances.0.commandClasses.159.data.grantedKeys.S2Unauthenticated = False
[2020-06-12 08:45:08.513] [D] [zway] SETDATA devices.26.instances.0.commandClasses.159.data.grantedKeys.S2Authenticated = True
[2020-06-12 08:45:08.515] [D] [zway] SETDATA devices.26.instances.0.commandClasses.159.data.grantedKeys.S2Access = False
[2020-06-12 08:45:08.516] [D] [zway] SETDATA devices.26.instances.0.commandClasses.159.data.security = True
[2020-06-12 08:45:08.518] [D] [zway] SETDATA devices.26.instances.0.commandClasses.159.data.secureNodeInfoFrames.S2Authenticated = byte[0]
[2020-06-12 08:45:08.520] [D] [zway] ( zero-length buffer )
[2020-06-12 08:45:08.521] [zway] Node 26:0 CC SecurityS2: requesting secure NIF for security class S2 Authenticated
[2020-06-12 08:45:08.523] [zway] Using security scheme S2 Authenticated
[2020-06-12 08:45:08.524] [zway] Adding job: Secure S2 NIF Get
[2020-06-12 08:45:08.526] [zway] Job 0x13 (Security S2 Nonce Get): Cancelling job: Security S2 Nonce Get
[2020-06-12 08:45:08.527] [zway] Removing job: Security S2 Nonce Get
[2020-06-12 08:45:08.527] [zway] Adding job: Security S2 Nonce Get
[2020-06-12 08:45:08.527] [D] [zway] Security S2 send timer set to 100.000000
[2020-06-12 08:45:13.758] [D] [zway] Job 0x3b: deleted from queue
followed by
[2020-06-12 08:46:56.057] [D] [zway] Security S2 send timeout event
[2020-06-12 08:46:56.059] [zway] Job 0x13 (Secure S2 NIF Get): Security S2 failed to prepare S2 packet
[2020-06-12 08:46:56.071] [zway] Job 0x13 (Security S2 Nonce Get): Cancelling job: Security S2 Nonce Get
[2020-06-12 08:46:56.072] [zway] Removing job: Security S2 Nonce Get
[2020-06-12 08:46:56.074] [zway] Adding job: Security S2 Nonce Get
[2020-06-12 08:46:56.076] [D] [zway] Security S2 send timer set to 100.000000
Controller info:
Firmware
Library Type: Static Controller
SDK Version: 6.81.01
Serial API Version: 05.37
Software Information
Version number: v3.0.6
Compile-ID: 82a4fd59993dc610c06507351714f95f21475262
Compile-Date: 2020-04-28 13:52:20 +0300
UI
UI version 1.5.1
Built date 03-04-2020 13:45:40