search

Koenkk / zigbee-herdsman-converters

Collection of device converters to be used with zigbee-herdsman
MIT License
886 stars 2.96k forks source link

'MAC transaction expired' (240) with Eurotronic Spirit SPZB0001 thermostat #715

Closed vansoest closed 3 years ago

vansoest commented 4 years ago

Sporadic my Eurotronic Spirit SPZB0001 thermostat will not react on commands and throw an exception 'MAC transaction expired' like: zigbee2mqtt:error 2019-10-25T10:07:50: Publish 'set' 'current_heating_setpoint' to 'thermostat/living_room' failed: 'Error: Data request failed with error: 'MAC transaction expired' (240)' zigbee2mqtt:info 2019-10-25T10:07:50: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"zigbee_publish_error","message":"Publish 'set' 'current_heating_setpoint' to 'thermostat/living_room' failed: 'Error: Data request failed with error: 'MAC transaction expired' (240)'","meta":{"friendly_name":"thermostat/living_room"}}'

But If I change the temperature manually on the device itself, the transaction error will be fixed and reacting normal on set current_heating_setpoint: zigbee2mqtt:info 2019-10-25T10:19:56: MQTT publish: topic 'zigbee2mqtt/thermostat/living_room', payload '{"eurotronic_error_status":0,"current_heating_setpoint":19,"local_temperature":19.28,"occupied_heating_setpoint":20,"unoccupied_heating_setpoint":16,"eurotronic_system_mode":1,"pi_heating_demand":0,"battery":100,"linkquality":73,"system_mode":"heat"}'

using hassio with zigbee2mqtt-edge docker image, but can not get the current git commit: https://github.com/danielwelch/hassio-zigbee2mqtt/issues/242 my latest version I assume is a few days old but already patched with the thermostat_system_mode feature! https://github.com/Koenkk/zigbee-herdsman-converters/pull/682 Coordinator: CC2531 zStack12 20190619

How to avoid this problem? The thermostat device is in the same room with the coordinator. The networkmap shows me a value from the coordinator to the device around 80-120.

Koenkk commented 4 years ago

This topic suggest to decrease the poll rate: https://e2e.ti.com/support/wireless-connectivity/zigbee-and-thread/f/158/t/674420?CC2531-How-to-wake-up-sleeping-MAC-layer-

I've compiled a firmware with a polling rate of 200 ms (instead of 1000 ms), does it keep working now? Link to firmware: https://drive.google.com/open?id=1-M6Q7Nx3f5cMba91tqbf5Rmf7Qck_r_B

vansoest commented 4 years ago

Flashed with the raspberry pi on the header and I got now 'No network route' (205)' for my thermostats. 

zigbee2mqtt:info  2019-10-30T13:48:22: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"zigbee_publish_error","message":"Publish 'set' 'system_mode' to 'thermostat/bathroom' failed: 'Error: Data request failed with error: 'No network route' (205)'","meta":{"friendly_name":"thermostat/bathroom"}}'

zigbee2mqtt:error 2019-10-30T13:53:48: Publish 'set' 'system_mode' to 'thermostat/living_room' failed: 'Error: Data request failed with error: 'No network route' (205)'
zigbee2mqtt:info  2019-10-30T13:53:48: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"zigbee_publish_error","message":"Publish 'set' 'system_mode' to 'thermostat/living_room' failed: 'Error: Data request failed with error: 'No network route' (205)'","meta":{"friendly_name":"thermostat/living_room"}}'

Ok I think the values are now corrupted. I reflashed now with sbl_tool.bin and cc_flash the version before: of the Z-Stack_Home_1.2 CC2531_SOURCE_ROUTING_20190619 archive.

But now all seems broken. No device is communicating with the coordinator. Is there a way to fix it?

Koenkk commented 4 years ago

try to re-power the thermostat so that the coordinator can find a new route to the device. If that doesn't help try re-pairing them.

vansoest commented 4 years ago

all devices are now not working with the old 20190619 and your firmware. I have flashed another CC2531 now. It does also not work.

so you say I have to repair all 20 devices without a reason? no messages, the networkmap is also dead

edit: pairing a fresh new device works. so maybe an id on the CC2531 has been changed and I can patch it?

Koenkk commented 4 years ago

If you didn't change the panid, channel or network_key in configuration.yaml you shouldn't have to do that. What errors do you get when controlling other devices?

vansoest commented 4 years ago

I’ve got no data the most devices are sensors. Aquara PIR and Magnet sensors. The new magnet fresh paired device work normal. All other devices are dead. So I tried to re-pair the livingroom thermostat, firmware reset on the device itself. Then repair with the isolator and the device appears in the log, but now it will also throw the same exception.

zigbee2mqtt:info  2019-10-30T15:23:26: MQTT publish: topic 'zigbee2mqtt/bridge/config', payload '{"version":"1.6.0","commit":"78824b48c090470d178c00da80c0d57c58eeccf2","coordinator":{"type":"zStack12","meta":{"transportrev":2,"product":0,"majorrel":2,"minorrel":6,"maintrel":3,"revision":20191028}},"log_level":"info","permit_join":true}'
zigbee2mqtt:info  2019-10-30T15:23:58: Accepting joining non-banned device '0x00158d000192309a'
zigbee2mqtt:error 2019-10-30T15:27:42: Publish 'set' 'system_mode' to 'thermostat/living_room' failed: 'Error: Data request failed with error: 'No network route' (205)'
zigbee2mqtt:info  2019-10-30T15:27:42: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"zigbee_publish_error","message":"Publish 'set' 'system_mode' to 'thermostat/living_room' failed: 'Error: Data request failed with error: 'No network route' (205)'","meta":{"friendly_name":"thermostat/living_room"}}'

I think I can purge the database.db and then It will work. I used jq and compared the new device with the old, it differs a bit, see screenshot.

Selection_543 0x00158d00032b747d is the »fresh« magnet sensor.

panid, channel or network_key are the same.

edit: the ikea router has published their linkquality: zigbee2mqtt:info 2019-10-30T15:30:15: MQTT publish: topic 'zigbee2mqtt/router/hall_ikea', payload '{"linkquality":52}' still no output from other devices.

shall I upload the database.db without to getting a risk to publish secret informations about my keys?

vansoest commented 4 years ago

@Koenkk I will now re-pair all devices. (done this 3 weeks ago). When I reflash the coordinator a repairing is always required? edit: wow nice pairing works now by the first attempt without problems.

Koenkk commented 4 years ago

No repairing shouldnt be necessary when reflashing. Does your thermostat work now?

vansoest commented 4 years ago

yes, but we have to wait for the next 1-2 days. I will check the logs for sporadic MAC transaction expired errors.

vansoest commented 4 years ago

I think the problem is solved I found no new errors inside the container log.

sti0 commented 4 years ago

@Koenkk I've got the same issue from time to time. But I'm using a CC26X2R1 coordinator. Is it possible to decrease the poll rate for this coordinator, too?

Koenkk commented 4 years ago

@sti0 can you try replacing /opt/zigbee2mqtt/node_modules/zigbee-herdsman/dist/adapter/z-stack/adapter/startZnp.js with https://gist.github.com/Koenkk/ca4b55f33bb1727af6bda204b95feafe . This should set the poll rate to 200.

vansoest commented 4 years ago

I got again the MAC transaction error but only for 1-2 thermostats. Other thermostats working well. But sometimes after a long time, it will break things. Rebooting the zigbee2mqtt service helped yesterday. Today the same error. Changing the temperature on the thermostat itself fixed the issue (again).

➜ ~ docker logs addon_7ad98f9c_zigbee2mqtt_edge | grep -i 'MAC transaction expired'

zigbee2mqtt:error 2019-12-29T12:21:23: Publish 'set' 'current_heating_setpoint' to 'thermostat/living_room' failed: 'Error: Data request failed with error: 'MAC transaction expired' (240)'
zigbee2mqtt:info  2019-12-29T12:21:23: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"zigbee_publish_error","message":"Publish 'set' 'current_heating_setpoint' to 'thermostat/living_room' failed: 'Error: Data request failed with error: 'MAC transaction expired' (240)'","meta":{"friendly_name":"thermostat/living_room"}}'
zigbee2mqtt:error 2019-12-29T12:22:01: Publish 'set' 'current_heating_setpoint' to 'thermostat/living_room' failed: 'Error: Data request failed with error: 'MAC transaction expired' (240)'
zigbee2mqtt:info  2019-12-29T12:22:01: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"zigbee_publish_error","message":"Publish 'set' 'current_heating_setpoint' to 'thermostat/living_room' failed: 'Error: Data request failed with error: 'MAC transaction expired' (240)'","meta":{"friendly_name":"thermostat/living_room"}}'
zigbee2mqtt:error 2019-12-29T12:23:47: Publish 'set' 'current_heating_setpoint' to 'thermostat/living_room' failed: 'Error: Data request failed with error: 'MAC transaction expired' (240)'
zigbee2mqtt:info  2019-12-29T12:23:47: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"zigbee_publish_error","message":"Publish 'set' 'current_heating_setpoint' to 'thermostat/living_room' failed: 'Error: Data request failed with error: 'MAC transaction expired' (240)'","meta":{"friendly_name":"thermostat/living_room"}}'
zigbee2mqtt:error 2019-12-29T12:25:04: Publish 'set' 'current_heating_setpoint' to 'thermostat/living_room' failed: 'Error: Data request failed with error: 'MAC transaction expired' (240)'
zigbee2mqtt:info  2019-12-29T12:25:04: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"zigbee_publish_error","message":"Publish 'set' 'current_heating_setpoint' to 'thermostat/living_room' failed: 'Error: Data request failed with error: 'MAC transaction expired' (240)'","meta":{"friendly_name":"thermostat/living_room"}}'

Which kind of data do you need to find out what is the issue now?

earion commented 4 years ago

Same issue for me - I have 2 thermostats - one is working, second is presenting Mac transaction expired


gru 29 19:47:08 raspberrypi bash[6336]: zigbee2mqtt:debug 2019-12-29T18:47:08: Received MQTT message on 'zigbee2mqtt/termostat_gabinet/set' with data '{"current_heating_setpoint": 18.0}'
gru 29 19:47:08 raspberrypi bash[6336]: zigbee2mqtt:debug 2019-12-29T18:47:08: Publishing 'set' 'current_heating_setpoint' to 'termostat_gabinet'

What boders me is that this device is still anouncing itself. Any idea? Also what is strange for me that I don't have any readings about temperature from both devices

gru 29 19:47:37 raspberrypi bash[6336]: zigbee2mqtt:debug 2019-12-29T18:47:37: Publishing 'set' 'current_heating_setpoint' to 'termostat_sypialnia'
gru 29 19:47:44 raspberrypi bash[6336]: zigbee2mqtt:error 2019-12-29T18:47:44: Publish 'set' 'current_heating_setpoint' to 'termostat_sypialnia' failed: 'Error: Data request failed with error: 'MAC transaction expired' (240)'
gru 29 19:47:44 raspberrypi bash[6336]: zigbee2mqtt:info  2019-12-29T18:47:44: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"zigbee_publish_error","message":"Publish 'set' 'current_heating_setpoint' to 'termostat_sypialnia' failed: 'Error: Data request failed with error: 'MAC transaction expired' (240)'","meta":{"friendly_name":"termostat_sypialnia"}}'
gru 29 19:48:02 raspberrypi bash[6336]: zigbee2mqtt:debug 2019-12-29T18:48:02: Device 'termostat_sypialnia' announced itself

My database.db here : https://pastebin.com/725ip5m5

after upgrade to zigbee2mqqt 1.8:

gru 29 20:26:41 raspberrypi bash[8767]: zigbee2mqtt:debug 2019-12-29 20:26:41: Received MQTT message on 'zigbee2mqtt/termostat_sypialnia/set' with data '{"current_heating_setpoint": 20.0}'
gru 29 20:26:41 raspberrypi bash[8767]: zigbee2mqtt:debug 2019-12-29 20:26:41: Publishing 'set' 'current_heating_setpoint' to 'termostat_sypialnia'
gru 29 20:26:41 raspberrypi bash[8767]: zigbee2mqtt:error 2019-12-29 20:26:41: Publish 'set' 'current_heating_setpoint' to 'termostat_sypialnia' failed: 'Error: Data request failed with error: 'MAC transaction expired' (240)'
gru 29 20:26:41 raspberrypi bash[8767]: zigbee2mqtt:debug 2019-12-29 20:26:41: Error: Data request failed with error: 'MAC transaction expired' (240)
gru 29 20:26:41 raspberrypi bash[8767]:     at ZStackAdapter. (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/dist/adapter/z-stack/adapter/zStackAdapter.js:578:27)
gru 29 20:26:41 raspberrypi bash[8767]:     at Generator.next ()
gru 29 20:26:41 raspberrypi bash[8767]:     at fulfilled (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/dist/adapter/z-stack/adapter/zStackAdapter.js:5:58)
gru 29 20:26:41 raspberrypi bash[8767]: zigbee2mqtt:info  2019-12-29 20:26:41: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"zigbee_publish_error","message":"Publish 'set' 'current_heating_setpoint' to 'termostat_sypialnia' failed: 'Error: Data request failed with error: 'MAC transaction expired' (240)'","meta":{"friendly_name":"termostat_sypialnia"}}'
gru 29 20:26:41 raspberrypi bash[8767]: zigbee2mqtt:debug 2019-12-29 20:26:41: Device 'termostat_sypialnia' announced itself
sti0 commented 4 years ago

@sti0 can you try replacing /opt/zigbee2mqtt/node_modules/zigbee-herdsman/dist/adapter/z-stack/adapter/startZnp.js with https://gist.github.com/Koenkk/ca4b55f33bb1727af6bda204b95feafe . This should set the poll rate to 200.

@Koenkk did this and there are no MAC-messages for a few days. Today I received one again. :-(

sti0 commented 4 years ago

Today I've got another issue zigbee2mqtt responses with the MAC error. After pressing the hardware buttons the new temperature setpoint is delivered to zigbee2mqtt and visible in HA. But if I then try to set the temperature with zigbee2mqtt the MAC error responses again.

earion commented 4 years ago

For me fix with changing

@sti0 can you try replacing /opt/zigbee2mqtt/node_modules/zigbee-herdsman/dist/adapter/z-stack/adapter/startZnp.js with https://gist.github.com/Koenkk/ca4b55f33bb1727af6bda204b95feafe . This should set the poll rate to 200.

@Koenkk did this and there are no MAC-messages for a few days. Today I received one again. :-(

For me this fix doesn't change anything. Is it possible that i have broken Spirit device ? Even if i pair device i still get message that device announced itself, and also have this strange Mac error. Second SPZB0001 works well.


sty 06 19:24:44 raspberrypi bash[6681]: zigbee2mqtt:info  2020-01-06 19:24:44: Starting interview of 'termostat_sypialnia'
sty 06 19:24:44 raspberrypi bash[6681]: zigbee2mqtt:info  2020-01-06 19:24:44: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"pairing","message":"interview_started","meta":{"friendly_name":"termostat_sypialnia"}}'
sty 06 19:24:46 raspberrypi bash[6681]: zigbee2mqtt:debug 2020-01-06 19:24:46: Received Zigbee message from 'termostat_sypialnia', type 'readResponse', cluster 'genBasic', data '{"modelId":"SPZB0001","manufacturerName":"Eurotronic","powerSource":3}' from endpoint 1 with groupID 0
sty 06 19:24:46 raspberrypi bash[6681]: zigbee2mqtt:debug 2020-01-06 19:24:46: No converter available for 'SPZB0001' with cluster 'genBasic' and type 'readResponse' and data '{"modelId":"SPZB0001","manufacturerName":"Eurotronic","powerSource":3}'
sty 06 19:24:46 raspberrypi bash[6681]: zigbee2mqtt:debug 2020-01-06 19:24:46: Received Zigbee message from 'termostat_sypialnia', type 'readResponse', cluster 'genBasic', data '{"zclVersion":2,"appVersion":22,"stackVersion":5}' from endpoint 1 with groupID 0
sty 06 19:24:46 raspberrypi bash[6681]: zigbee2mqtt:debug 2020-01-06 19:24:46: No converter available for 'SPZB0001' with cluster 'genBasic' and type 'readResponse' and data '{"zclVersion":2,"appVersion":22,"stackVersion":5}'
sty 06 19:24:46 raspberrypi bash[6681]: zigbee2mqtt:debug 2020-01-06 19:24:46: Received Zigbee message from 'termostat_sypialnia', type 'readResponse', cluster 'genBasic', data '{"hwVersion":35,"dateCode":"20191014","swBuildId":"00000000"}' from endpoint 1 with groupID 0
sty 06 19:24:46 raspberrypi bash[6681]: zigbee2mqtt:debug 2020-01-06 19:24:46: No converter available for 'SPZB0001' with cluster 'genBasic' and type 'readResponse' and data '{"hwVersion":35,"dateCode":"20191014","swBuildId":"00000000"}'
sty 06 19:24:46 raspberrypi bash[6681]: zigbee2mqtt:info  2020-01-06 19:24:46: Successfully interviewed 'termostat_sypialnia', device has successfully been paired
sty 06 19:24:46 raspberrypi bash[6681]: zigbee2mqtt:info  2020-01-06 19:24:46: Device 'termostat_sypialnia' is supported, identified as: Eurotronic Spirit Zigbee wireless heater thermostat (SPZB0001)
sty 06 19:24:46 raspberrypi bash[6681]: zigbee2mqtt:info  2020-01-06 19:24:46: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"pairing","message":"interview_successful","meta":{"friendly_name":"termostat_sypialnia","model":"SPZB0001","vendor":"Eurotronic","description":"Spirit Zigbee wireless heater thermostat","supported":true}}'
sty 06 19:24:46 raspberrypi bash[6681]: zigbee2mqtt:info  2020-01-06 19:24:46: Configuring 'termostat_sypialnia'
sty 06 19:24:48 raspberrypi bash[6681]: zigbee2mqtt:info  2020-01-06 19:24:48: Succesfully configured 'termostat_sypialnia'
sty 06 19:25:18 raspberrypi bash[6681]: zigbee2mqtt:debug 2020-01-06 19:25:18: Device 'termostat_sypialnia' announced itself
sty 06 19:26:04 raspberrypi bash[6681]: zigbee2mqtt:debug 2020-01-06 19:26:04: Device 'termostat_sypialnia' announced itself
sty 06 19:26:09 raspberrypi bash[6681]: zigbee2mqtt:debug 2020-01-06 19:26:09: Device 'termostat_sypialnia' announced itself

sty 06 19:33:16 raspberrypi bash[6681]: zigbee2mqtt:debug 2020-01-06 19:33:16: Device 'termostat_sypialnia' announced itself
sty 06 19:33:23 raspberrypi bash[6681]: zigbee2mqtt:debug 2020-01-06 19:33:23: Received MQTT message on 'zigbee2mqtt/termostat_sypialnia/set' with data '{"current_heating_setpoint": 21.0}'
sty 06 19:33:23 raspberrypi bash[6681]: zigbee2mqtt:debug 2020-01-06 19:33:23: Publishing 'set' 'current_heating_setpoint' to 'termostat_sypialnia'
sty 06 19:33:29 raspberrypi bash[6681]: zigbee2mqtt:error 2020-01-06 19:33:29: Publish 'set' 'current_heating_setpoint' to 'termostat_sypialnia' failed: 'Error: Data request failed with error: 'MAC transaction expired' (240)'
sty 06 19:33:29 raspberrypi bash[6681]: zigbee2mqtt:debug 2020-01-06 19:33:29: Error: Data request failed with error: 'MAC transaction expired' (240)
sty 06 19:33:29 raspberrypi bash[6681]:     at ZStackAdapter. (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/dist/adapter/z-stack/adapter/zStackAdapter.js:578:27)
sty 06 19:33:29 raspberrypi bash[6681]:     at Generator.next ()
sty 06 19:33:29 raspberrypi bash[6681]:     at fulfilled (/opt/zigbee2mqtt/node_modules/zigbee-herdsman/dist/adapter/z-stack/adapter/zStackAdapter.js:5:58)
sty 06 19:33:29 raspberrypi bash[6681]: zigbee2mqtt:info  2020-01-06 19:33:29: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"zigbee_publish_error","message":"Publish 'set' 'current_heating_setpoint' to 'termostat_sypialnia' failed: 'Error: Data request failed with error: 'MAC transaction expired' (240)'","meta":{"friendly_name":"termostat_sypialnia"}}'
sty 06 19:33:35 raspberrypi bash[6681]: zigbee2mqtt:debug 2020-01-06 19:33:35: Saving state to file /opt/zigbee2mqtt/data/state.json
sty 06 19:33:48 raspberrypi bash[6681]: zigbee2mqtt:debug 2020-01-06 19:33:48: Device 'termostat_sypialnia' announced itself
PrivatHomeServer commented 4 years ago

I'm looking for a solution too. We currently use three of these thermostats. We use a coordinator as CC2531 + router with external antenna. I'm not sure if I'm just getting it since the 1.8 update. But I installed two new devices yesterday. One is definitely not working...

zigbee2mqtt:info 2020-01-07 22:33:27: MQTT publish: topic 'zigbee2mqtt/Buero_HZ', payload '{"eurotronic_system_mode":1,"system_mode":"heat","linkquality":44,"local_temperature":20,"occupied_heating_setpoint":10,"unoccupied_heating_setpoint":16,"pi_heating_demand":0,"current_heating_setpoint":10,"eurotronic_error_status":0,"battery":100}' zigbee2mqtt:error 2020-01-07 22:33:48: Publish 'set' 'current_heating_setpoint' to 'Buero_HZ' failed: 'Error: Data request failed with error: 'MAC transaction expired' (240)' zigbee2mqtt:info 2020-01-07 22:33:48: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"zigbee_publish_error","message":"Publish 'set' 'current_heating_setpoint' to 'Buero_HZ' failed: 'Error: Data request failed with error: 'MAC transaction expired' (240)'","meta":{"friendly_name":"Buero_HZ"}}'

earion commented 4 years ago

@PrivatHomeServer can You show log with debug on ? Add in configuration

advanced:
  log_level: debug

I'm pretty sure that You will receive same issue as mine.

Koenkk commented 4 years ago

for cc2531 coordinator users: can you try with the firmware from https://github.com/Koenkk/zigbee-herdsman-converters/issues/715#issuecomment-547073703

sti0 commented 4 years ago

@Koenkk I'm still using your suggested change (https://github.com/Koenkk/zigbee-herdsman-converters/issues/715#issuecomment-565814660) and it's not perfect but I noticed less MAC errors than without it. Would it be possible to set the poll rate by a parameter or would it be necessary to copy the changed startZnp.js file to my docker container after every restart?

Koenkk commented 4 years ago

@sti0 first i want to make sure this fixes the problem, can you change https://gist.github.com/Koenkk/ca4b55f33bb1727af6bda204b95feafe#file-startznp-js-poll-rate-200-L214 200 to 100 here and see if things improve?

sti0 commented 4 years ago

@sti0 first i want to make sure this fixes the problem, can you change https://gist.github.com/Koenkk/ca4b55f33bb1727af6bda204b95feafe#file-startznp-js-poll-rate-200-L214 200 to 100 here and see if things improve?

Thanks. Changed it. Will come back to you in a few days.

PrivatHomeServer commented 4 years ago

I had to replace a thermostat (new) due to a hardware defect. Theoretically everything should work again. However, the thermostats cannot always be activated. It could be that my Zigbee network (linkquality) is not yet optimal. Maybe the thermostats do not always react.

If there is a version to flash again I can test this. So far it runs under:

Version of Zigbee2Mqtt: 1.9.0 Coordinator version: 20190608

earion commented 4 years ago

@sti0 first i want to make sure this fixes the problem, can you change https://gist.github.com/Koenkk/ca4b55f33bb1727af6bda204b95feafe#file-startznp-js-poll-rate-200-L214 200 to 100 here and see if things improve?

For me that did't fix the issue

sti0 commented 4 years ago

@sti0 first i want to make sure this fixes the problem, can you change https://gist.github.com/Koenkk/ca4b55f33bb1727af6bda204b95feafe#file-startznp-js-poll-rate-200-L214 200 to 100 here and see if things improve?

I had this running for over a week on the stable z2m 1.9 version and the errors appear only sometimes (around 20 errors / week). I set the local_temperature_calibration all day so this is quite a good result.

I got the following errors:

zigbee_publish_error: Publish 'set' 'local_temperature_calibration' to 'climate_schlafzimmer' failed: 'Error: Data request failed with error: 'MAC transaction expired' (240)' zigbee_publish_error: Publish 'set' 'local_temperature_calibration' to 'climate_schlafzimmer' failed: 'Error: Data request failed with error: 'MAC no ack' (233)'

THe errors appear on every of my three devices. Even there is an error, it "heals itself" and in the most cases not throw another error after.

This is not the perfect solution but way better than with a higher polling rate.

Koenkk commented 4 years ago

@sti0 you mean setting it twice right after each other fixes the issue?

sjorge commented 4 years ago

I'm not running the modified pulling thing, but I have also noticed sometimes the TRV is slow to respond, poking it again immediately after the failure will work.

Maybe we give up to quickly? Or maybe it is in a deep sleep and needs a good kick or something.

Koenkk commented 4 years ago

@sjorge @sti0 if that indeed works, solving this issue would be as easy as just adding 240 here https://github.com/Koenkk/zigbee-herdsman/blob/master/src/adapter/z-stack/adapter/zStackAdapter.ts#L647

sti0 commented 4 years ago

@sti0 you mean setting it twice right after each other fixes the issue?

No, that's not the case. Sometimes if you set a value twice the error appears two times. But it's often the case that the second setting sets the value on the device (but the second setting could be a hour later). What I did ist to decrease the polling rate as you advised me (https://github.com/Koenkk/zigbee-herdsman-converters/issues/715#issuecomment-572426985).

@sjorge @sti0 if that indeed works, solving this issue would be as easy as just adding 240 here https://github.com/Koenkk/zigbee-herdsman/blob/master/src/adapter/z-stack/adapter/zStackAdapter.ts#L647

If I understand the code, if we add 240, the command is resend after a MAC error. This could possibly work. I will test this. But should I increase the polling rate back to standard? Could we log the success somehow?

As mentioned in my previous post (https://github.com/Koenkk/zigbee-herdsman-converters/issues/715#issuecomment-578602851) there is also a 233 error sometimes:

zigbee_publish_error: Publish 'set' 'local_temperature_calibration' to 'climate_schlafzimmer' failed: 'Error: Data request failed with error: 'MAC no ack' (233)'

Koenkk commented 4 years ago

@sti0

sti0 commented 4 years ago

@Koenkk ok, will do this at the weekend because I like to monitor the behavior.

sti0 commented 4 years ago

@Koenkk I added if ([225,233,240].includes(dataConfirm.payload.status) && attempt === 0) {

at https://github.com/Koenkk/zigbee-herdsman/blob/master/src/adapter/z-stack/adapter/zStackAdapter.ts#L647 and https://github.com/Koenkk/zigbee-herdsman/blob/81ce0ec78c5203085257cdd02dddd360e4cce5a2/src/adapter/z-stack/adapter/zStackAdapter.ts#L698

but received to errors in the morning (both 240). The device responses successful some minutes later after I set the temperature calibration again. Yesterday no errors appeared.

Koenkk commented 4 years ago

@sti0 maybe we should add a small delay before retrying, right before https://github.com/Koenkk/zigbee-herdsman/blob/master/src/adapter/z-stack/adapter/zStackAdapter.ts#L653 and https://github.com/Koenkk/zigbee-herdsman/blob/81ce0ec78c5203085257cdd02dddd360e4cce5a2/src/adapter/z-stack/adapter/zStackAdapter.ts#L704 add: await Wait(2000); = 2 seconds.

sti0 commented 4 years ago

@Koenkk added your suggestion and it seems to work fine but I received an 240 error last night (the 1st one since the wait adjustment). Do you have any other ideas?

Koenkk commented 4 years ago

I suggest to try up to 3 times (now 2), can you adapt the code (just duplicate the if statement for now).

sti0 commented 4 years ago

Changed it into 

const dataConfirm = await response.promise;
if (dataConfirm.payload.status !== 0) {
    if ([225, 233, 240].includes(dataConfirm.payload.status) && attempt === 0) {
        /**
         * When many commands at once are executed we can end up in a MAC channel access failure
         * error (225). This is because there is too much traffic on the network.
         * Retry this command once after a cooling down period.
         */
        await Wait(2000);
        return this.dataRequest(
            destinationAddress, destinationEndpoint, sourceEndpoint, clusterID, radius, data, timeout, 1
        );
    } else {
        if ([225, 233, 240].includes(dataConfirm.payload.status) && attempt === 1) {
            /**
             * When many commands at once are executed we can end up in a MAC channel access failure
             * error (225). This is because there is too much traffic on the network.
             * Retry this command once after a cooling down period.
             */
            await Wait(2000);
            return this.dataRequest(
                destinationAddress, destinationEndpoint, sourceEndpoint, clusterID, radius, data, timeout, 2
            );
        } else {
            throw new DataConfirmError(dataConfirm.payload.status);
        }
    }
}

Is this what you meant?

Koenkk commented 4 years ago

I've made the changes in: https://gist.github.com/Koenkk/c4bdd09dec17f69e4702bff87b24399b

sti0 commented 4 years ago

Thanks, I test it and will report.

sti0 commented 4 years ago

@Koenkk another 240 error appeared with the changed version. I changed the wait time then to 2000ms but another error appeared.

sjorge commented 4 years ago

Just wondering, is the stick you are using one that support the updateRoute thing? If not, Maybe the old route doesn’t work at that point and until the trv sends and update no new route is established.

~ sjorge

On 5 Feb 2020, at 23:20, Timo S. notifications@github.com wrote:

 @Koenkk another 240 error appeared with the changed version. I changed the wait time then to 2000ms but another error appeared.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub, or unsubscribe.

sti0 commented 4 years ago

I'm using a CC26X1 (https://www.zigbee2mqtt.io/information/supported_adapters.html#texas-instruments-cc26x2r1) with the 20191106 firmware.

sjorge commented 4 years ago

Nice, IIRC that does the new route discovery stuff... so I don’t think that could be an extra issue here, hmmmm

~ sjorge

On 5 Feb 2020, at 23:49, Timo S. notifications@github.com wrote:

 I'm using a CC26X1 (https://www.zigbee2mqtt.io/information/supported_adapters.html#texas-instruments-cc26x2r1) with the 20191106 firmware.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub, or unsubscribe.

CodeFinder2 commented 4 years ago

I am having the same problem with only one of my devices (out of 5 total thermostats).

zigbee2mqtt:error 2020-02-08 12:07:13: Publish 'set' 'current_heating_setpoint' to 'office/thermostat' failed: 'Error: Write 0x00158d0001ffc5c5/1 hvacThermostat({"16387":{"value":800,"type":41}}, {"timeout":10000,"defaultResponseTimeout":15000,"manufacturerCode":4151,"disableDefaultResponse":true}) failed (Error: Data request failed with error: 'MAC transaction expired' (240))'
zigbee2mqtt:info  2020-02-08 12:07:13: MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"type":"zigbee_publish_error","message":"Publish 'set' 'current_heating_setpoint' to 'office/thermostat' failed: 'Error: Write 0x00158d0001ffc5c5/1 hvacThermostat({\"16387\":{\"value\":800,\"type\":41}}, {\"timeout\":10000,\"defaultResponseTimeout\":15000,\"manufacturerCode\":4151,\"disableDefaultResponse\":true}) failed (Error: Data request failed with error: 'MAC transaction expired' (240))'","meta":{"friendly_name":"office/thermostat"}}'

Interestingly, the problematic device is very close (<1,5m clear line of sight) to my CC1352P-2 coordinator but I don't know if that really matters :thinking:

Edit: also already tried repairing but the problem occurred again next day... I am virtually unable to control my device from HA/Z2M as it doesn't react to any of the commands sent. It only works directly from the device. 🙄 Rebooted, deleted and re-paired again, and it seems to work now. Having this rtscts flag set to true now (can anyone explain to me what is does in this context?).

sti0 commented 4 years ago

Interestingly, the problematic device is very close (<1,5m clear line of sight) to my CC1352P-2 coordinator but I don't know if that really matters

My most affected device is only ~0.5m away from the coordinator. Even clear sight.

CodeFinder2 commented 4 years ago

Okay, the error already appeared again (less than 24h). I cannot control my thermostat through Z2M ... very annoying... :disappointed:

Any ideas for a potential fix for this? Anything I can test?

sti0 commented 4 years ago

Okay, the error already appeared again (less than 24h). I cannot control my thermostat through Z2M ... very annoying...

Any ideas for a potential fix for this? Anything I can test?

Could you please provide the firmware of the devices (https://github.com/Koenkk/zigbee2mqtt/issues/2500#issuecomment-583890805)

@Koenkk should we close the other issue (#2500) as it is duplicated?

CodeFinder2 commented 4 years ago

@sti0 Sure, here they are:

{"model":"SPZB0001","friendly_name":"office/thermostat","manufacturerID":4151,"manufacturerName":"Eurotronic","powerSource":"Battery","modelID":"SPZB0001","hardwareVersion":35,"softwareBuildID":"22190930","dateCode":"20191014","lastSeen":1581282174965}

{"model":"SPZB0001","friendly_name":"living_room/thermostat","manufacturerID":4151,"manufacturerName":"Eurotronic","powerSource":"Battery","modelID":"SPZB0001","hardwareVersion":35,"softwareBuildID":"22190930","dateCode":"20191014","lastSeen":1581282409805}
{"model":"SPZB0001","friendly_name":"bedroom/thermostat","manufacturerID":4151,"manufacturerName":"Eurotronic","powerSource":"Battery","modelID":"SPZB0001","hardwareVersion":35,"softwareBuildID":"22190930","dateCode":"20191014","lastSeen":1581268977482}
{"model":"SPZB0001","friendly_name":"kitchen/thermostat","manufacturerID":4151,"manufacturerName":"Eurotronic","powerSource":"Battery","modelID":"SPZB0001","hardwareVersion":35,"softwareBuildID":"22190930","dateCode":"20191014","lastSeen":1581268979268}
{"model":"SPZB0001","friendly_name":"bathroom/thermostat","manufacturerID":4151,"manufacturerName":"Eurotronic","powerSource":"Battery","modelID":"SPZB0001","hardwareVersion":35,"softwareBuildID":"22190930","dateCode":"20191014","lastSeen":1581282313434}

As you can see, all have the same hw/sw version :thinking: The first one is the one having this issue (hope the others won't be "infected" in the future :frowning: )

PS: I think closing the other issue is a good idea!

sti0 commented 4 years ago

I've made the changes in: https://gist.github.com/Koenkk/c4bdd09dec17f69e4702bff87b24399b

@Koenkk running this for a week now and I've got <10 MAC errors so I think this implementation is way better than the actual state. I publish local_temperature_calibration all day long and change the temperature several times a day. So I think that's a pretty good value (nothing is perfect ;-)).

I modified your gist and increased the attempts to 4 and wait time to 2000 sec. Maybe we could increase to 5 attempts and get rid of the other errors.

const dataConfirm = await response.promise;
        if (dataConfirm.payload.status !== 0) {
            if ([225, 233, 240].includes(dataConfirm.payload.status) && attempt <= 4) {
                /**
                 * When many commands at once are executed we can end up in a MAC channel access failure
                 * error (225). This is because there is too much traffic on the network.
                 * Retry this command once after a cooling down period.
                 */
                await Wait(2000);
                return this.dataRequest(
                    destinationAddress, destinationEndpoint, sourceEndpoint, clusterID, radius, data, timeout,
                    attempt + 1
                );
            } else {
                throw new DataConfirmError(dataConfirm.payload.status);
            }
        }
CodeFinder2 commented 4 years ago

Surprisingly, mine started working again (no such errors yet/anymore) for no obvious reason! (Note that previously I was not even able to change the temperature via HA regardless of how often I tried...very mysterious 😅