Exception configuring Sonoff TRVZB thermostatic valves: value is not a number (using ember driver on ZBDongle-E)

[Ricc68]

What happened?

During the configuration of the Sonoff TRVZB a number of exceptions appeared in the log about value not a number.

What did you expect to happen?

I expect to not have these errors.

How to reproduce it (minimal and precise)

Join a Sonoff TRVZB Thermostatic valve and the issue appears: confirmed on two valves.

Zigbee2MQTT version

1.37.0

Adapter firmware version

7.4.2 [GA]

Adapter

Sonoff ZBDongle-E

Setup

Add-on on Home Assistant OS, host is a VM on x86-64, dongle uses ember driver

Debug log

[2024-05-04 17:10:36] info: zh:controller: Interview for '0x38398ffffe03aa79' started
[2024-05-04 17:10:36] info: z2m: Device '0x38398ffffe03aa79' joined
[2024-05-04 17:10:36] info: z2m: Starting interview of '0x38398ffffe03aa79'
[2024-05-04 17:10:39] warning: zh:ember: [ZDO] Node descriptor for "3870" reports device is only compliant to revision "22" of the ZigBee specification (current revision: 23).
[2024-05-04 17:11:14] info: zh:controller: Succesfully interviewed '0x38398ffffe03aa79'
[2024-05-04 17:11:14] info: z2m: Successfully interviewed '0x38398ffffe03aa79', device has successfully been paired
[2024-05-04 17:11:14] info: z2m: Device '0x38398ffffe03aa79' is supported, identified as: SONOFF Zigbee thermostatic radiator valve (TRVZB)
[2024-05-04 17:11:14] info: z2m: Configuring '0x38398ffffe03aa79'
[2024-05-04 17:11:14] info: z2m: Update available for '0x38398ffffe03aa79'
[2024-05-04 17:12:48] error: z2m: Exception while calling fromZigbee converter: Value is not a number, got undefined (undefined)}
[2024-05-04 17:13:07] error: z2m: Exception while calling fromZigbee converter: Value is not a number, got undefined (undefined)}
[2024-05-04 17:13:08] error: z2m: Exception while calling fromZigbee converter: Value is not a number, got undefined (undefined)}
[2024-05-04 17:13:08] info: z2m: Successfully configured '0x38398ffffe03aa79'

[Ricc68]

I have recharged the batteries of one of the devices (now it is at 97%) and I have found the same "value is not a number" exception when reconfiguring the device after powerup and reconnect (it was already joined so it's not the join but seems to be when fetching information from the device.

[Nerivec]

@photomoose I saw you helped debug this device a while back, do you mind checking this behavior?

[Koenkk]

@Ricc68 could you provide the debug log of this?

See this on how to enable debug logging.

[Ricc68]

I have enabled the debug log and surely enough no error happened. I have tried on both the TRVZB and both of them joined and configured without emitting any "value is not a number" error.
Looks like enabling debug fixed somehow the issue?
It was 100% reproducible without debug and now is 100% non reproducible with debug.

The following is the TRVZB further from the coordinator. I think it timed out the first configuration try but then configured properly:

[2024-05-05 21:43:31] info: zh:controller: Interview for '0x38398ffffe03aa79' started
[2024-05-05 21:43:31] info: z2m: Device '0x38398ffffe03aa79' joined
[2024-05-05 21:43:31] info: z2m: Starting interview of '0x38398ffffe03aa79'
[2024-05-05 21:43:32] warning: zh:ember: [ZDO] Node descriptor for "27448" reports device is only compliant to revision "22" of the ZigBee specification (current revision: 23).
[2024-05-05 21:43:47] info: zh:controller: Succesfully interviewed '0x38398ffffe03aa79'
[2024-05-05 21:43:47] info: z2m: Successfully interviewed '0x38398ffffe03aa79', device has successfully been paired
[2024-05-05 21:43:47] info: z2m: Device '0x38398ffffe03aa79' is supported, identified as: SONOFF Zigbee thermostatic radiator valve (TRVZB)
[2024-05-05 21:43:47] info: z2m: Configuring '0x38398ffffe03aa79'
[2024-05-05 21:43:52] error: z2m: Failed to configure '0x38398ffffe03aa79', attempt 1 (Error: Bind 0x38398ffffe03aa79/1 hvacThermostat from '0xe8e07efffec0c2a0/1' failed (Delivery failed for {"profileId":0,"clusterId":33,"sourceEndpoint":0,"destinationEndpoint":0,"options":4416,"groupId":0,"sequence":243})
at EmberOneWaitress.deliveryFailedFor (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/oneWaitress.ts:96:31)
at EmberAdapter.onMessageSentDeliveryFailed (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:558:30)
at Ezsp.emit (node:events:517:28)
at Ezsp.ezspMessageSentHandler (/app/node_modules/zigbee-herdsman/src/adapter/ember/ezsp/ezsp.ts:3957:18)
at Ezsp.callbackDispatch (/app/node_modules/zigbee-herdsman/src/adapter/ember/ezsp/ezsp.ts:794:18)
at Ezsp.tick (/app/node_modules/zigbee-herdsman/src/adapter/ember/ezsp/ezsp.ts:448:22)
at listOnTimeout (node:internal/timers:569:17)
at processTimers (node:internal/timers:512:7))
[2024-05-05 21:43:59] info: z2m: Configuring '0x38398ffffe03aa79'
[2024-05-05 21:45:17] info: z2m: Successfully configured '0x38398ffffe03aa79'

[Ricc68]

Huh I was going to disable the debug but I did not find the debug clause anymore in the configuration.yaml
Is the debug clause valid only for the first z2m run and then is removed from the configuration?
If that's the case then tomorrow I will repeat the test.
But anyway fact is that this evening I could not reproduce the issue.

[fir3drag0n]

Usually you can find logs in the subfolder

[Ricc68]

I was trying to reproduce the issue with debug disabled but I had a timeout fail during configuration, I don't know if it is related but still it is an issue during configuration. The TRVZB is joined in fact it shows the ZigBee icon but now if I try to click on Reconfigure to manually fetch the configuration it does nothing.
I'll remove the device, enable debug and rejoin it.

Here the log:

[2024-05-07 18:56:08] info: z2m: Device '0x0cae5ffffeb0aa7b' joined
[2024-05-07 18:56:08] info: z2m: Starting interview of '0x0cae5ffffeb0aa7b'
[2024-05-07 18:56:25] error: zh:ember: Delivery of BROADCAST failed for "65532" [apsFrame={"profileId":0,"clusterId":54,"sourceEndpoint":0,"destinationEndpoint":0,"options":0,"groupId":0,"sequence":183} messageTag=255]
[2024-05-07 18:56:32] info: zh:controller: Succesfully interviewed '0x0cae5ffffeb0aa7b'
[2024-05-07 18:56:32] info: z2m: Successfully interviewed '0x0cae5ffffeb0aa7b', device has successfully been paired
[2024-05-07 18:56:32] info: z2m: Device '0x0cae5ffffeb0aa7b' is supported, identified as: SONOFF Zigbee thermostatic radiator valve (TRVZB)
[2024-05-07 18:56:32] info: z2m: Configuring '0x0cae5ffffeb0aa7b'
[2024-05-07 18:56:48] error: z2m: Failed to configure '0x0cae5ffffeb0aa7b', attempt 1 (Error: Bind 0x0cae5ffffeb0aa7b/1 hvacThermostat from '0xe8e07efffec0c2a0/1' failed ({"target":50212,"apsFrame":{"profileId":0,"clusterId":33,"sourceEndpoint":0,"destinationEndpoint":0,"options":4416,"groupId":0,"sequence":237},"responseClusterId":32801} timed out after 15000ms)
at Object.start (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/oneWaitress.ts:194:23)
at EmberOneWaitress.startWaitingFor (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/oneWaitress.ts:218:50)
at Object.func (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/emberAdapter.ts:3397:48)
at runNextTicks (node:internal/process/task_queues:60:5)
at processImmediate (node:internal/timers:447:9)
at EmberRequestQueue.dispatch (/app/node_modules/zigbee-herdsman/src/adapter/ember/adapter/requestQueue.ts:117:46))
[2024-05-07 18:57:28] info: z2m: Configuring '0x0cae5ffffeb0aa7b'
[2024-05-07 18:59:10] error: zh:ember: Delivery of BROADCAST failed for "65533" [apsFrame={"profileId":41440,"clusterId":33,"sourceEndpoint":242,"destinationEndpoint":242,"options":256,"groupId":0,"sequence":246} messageTag=0]
[2024-05-07 19:00:21] error: zh:ember: Delivery of BROADCAST failed for "65533" [apsFrame={"profileId":0,"clusterId":19,"sourceEndpoint":0,"destinationEndpoint":0,"options":1024,"groupId":0,"sequence":137} messageTag=255]
[2024-05-07 19:02:30] error: zh:ember: Delivery of BROADCAST failed for "65532" [apsFrame={"profileId":0,"clusterId":54,"sourceEndpoint":0,"destinationEndpoint":0,"options":256,"groupId":0,"sequence":0} messageTag=12]

[Ricc68]

@Koenkk I've got a full debug log of a join+configuration of the TRVZB device id 0x0cae5ffffeb0aa7b (if I read correctly the logs).
log.log

[Ricc68]

@Koenkk I don't see this error anymore in the z2m logs. Should this ticket be closed?

[Koenkk]

@Ricc68 if it is fixed yes

[Ricc68]

@Koenkk Cannot reproduce anymore on 1.40.1, closing this issue as fixed.