search

Koenkk / zigbee2mqtt

Zigbee 🐝 to MQTT bridge 🌉, get rid of your proprietary Zigbee bridges 🔨
https://www.zigbee2mqtt.io
GNU General Public License v3.0
12.17k stars 1.68k forks source link

LGYCDD01LM always reports available updates #20238

Open cmuellner opened 11 months ago

cmuellner commented 11 months ago

What happened?

I have two Xiaomi Aqara Zigbee 3.0 LED strip T1 (LGYCDD01LM) and controlling them works fine. However, both devices have an empty firmware version and a firmware build date of 20230606 installed and report that a new update is available.

Installing the update is possible, but that does not change the installed firmware version and the fact that a new firmware update is being reported.

What did you expect to happen?

I expect firmware updates to be only reported as available if the update firmware differs from the currently installed firmware.

How to reproduce it (minimal and precise)

  1. Start Zigbee2MQTT
  2. Pair a Xiaomi Aqara Zigbee 3.0 LED strip T1
  3. Click on OTA
  4. Observe the availability of a firmware update

Then optional:

  1. Install the update
  2. Goto 3

Zigbee2MQTT version

1.34.0

Adapter firmware version

20220219

Adapter

ZBDongle-P

Debug log

The box on the right says the following during the update:

cmuellner commented 11 months ago

After going through the code, I realized that all relevant data should be available in the logs. So here we go (this is printed when pressing the Check all button` on the OTA page):

[...]
Zigbee2MQTT:info  2023-12-16 23:16:08: MQTT publish: topic 'zigbee2mqtt/foo', payload '{"audio":"OFF","audio_effect":null,"audio_sensitivity":null,"brightness":127,"color":{"x":0.3813,"y":0.3773},"color_mode":"color_temp","color_temp":251,"length":2,"linkquality":76,"max_brightness":100,"min_brightness":1,"power_on_behavior":null,"preset":null,"speed":null,"state":"OFF","update":{"installed_version":6683,"latest_version":672539,"state":"available"},"update_available":null}'
[...]
Zigbee2MQTT:info  2023-12-16 23:16:08: MQTT publish: topic 'zigbee2mqtt/bar', payload '{"audio":"OFF","audio_effect":"wave","audio_sensitivity":null,"brightness":3,"color":{"x":0.3131,"y":0.3232},"color_mode":"color_temp","color_temp":153,"length":2,"linkquality":72,"max_brightness":100,"min_brightness":1,"power_on_behavior":null,"preset":1,"speed":null,"state":"OFF","update":{"installed_version":6683,"latest_version":672539,"state":"available"},"update_available":null}'
[...]
Zigbee2MQTT:debug 2023-12-16 23:20:34: Received Zigbee message from 'Foo', type 'commandQueryNextImageRequest', cluster 'genOta', data '{"fieldControl":0,"fileVersion":6683,"imageType":141,"manufacturerCode":4447}' from endpoint 1 with groupID 0
Zigbee2MQTT:debug 2023-12-16 23:20:34: Got OTA request '{"fieldControl":0,"manufacturerCode":4447,"imageType":141,"fileVersion":6683}'
[...]
Zigbee2MQTT:debug 2023-12-16 23:20:34: Is new image available for '0x54ef4410008c50a3', current '{"fieldControl":0,"manufacturerCode":4447,"imageType":141,"fileVersion":6683}', latest meta '{"fileVersion":672539,"fileSize":942962,"url":"https://github.com/Koenkk/zigbee-OTA/raw/master/images/Xiaomi/20230610160234_lumi.light.acn132_mcu_0.0.0_2627_20230606_DA1C86.ota","sha512":"25007f79ccb030715cd9fa1a0acd447554aa1b8c0627116b0ae06e5135e6c5922e64eace80452e9a05423487d499df1fa0a23a30aead31fac2f15c51f9d82895"}'
Zigbee2MQTT:debug 2023-12-16 23:20:34: Update available for '0x54ef4410008c50a3': YES
[...]
Zigbee2MQTT:debug 2023-12-16 23:20:35: Is new image available for '0x54ef4410008c6198', current '{"fieldControl":0,"manufacturerCode":4447,"imageType":141,"fileVersion":6683}', latest meta '{"fileVersion":672539,"fileSize":942962,"url":"https://github.com/Koenkk/zigbee-OTA/raw/master/images/Xiaomi/20230610160234_lumi.light.acn132_mcu_0.0.0_2627_20230606_DA1C86.ota","sha512":"25007f79ccb030715cd9fa1a0acd447554aa1b8c0627116b0ae06e5135e6c5922e64eace80452e9a05423487d499df1fa0a23a30aead31fac2f15c51f9d82895"}'
Zigbee2MQTT:debug 2023-12-16 23:20:35: Update available for '0x54ef4410008c6198': YES
[...]

So current.fileVersion is 6683, while latest.fileVersion is 672539. I assume that current.fileVersion is reported by the device and latest.fileVersion has been defined in https://github.com/Koenkk/zigbee-OTA/pull/346.

I double-checked the PR by running scripts/add.js on my own and the fileVersion is indeed identified as 672539.

cmuellner commented 11 months ago

Since logging is already enabled, let's dig a bit deeper and have a look what happens during an update:

[...]
Zigbee2MQTT:debug 2023-12-16 23:49:27: Received MQTT message on 'zigbee2mqtt/bridge/request/device/ota_update/update' with data '{"id":"Foo","transaction":"h50az-29"}'
Zigbee2MQTT:info  2023-12-16 23:49:27: Updating 'Foo' to latest firmware
Zigbee2MQTT:debug 2023-12-16 23:49:27: Received Zigbee message from 'Foo', type 'readResponse', cluster 'genBasic', data '{"dateCode":"20230606"}' from endpoint 1 with groupID 0
Zigbee2MQTT:debug 2023-12-16 23:49:27: Updating to latest '0x54ef4410008c50a3' (lumi.light.acn132)
Zigbee2MQTT:debug 2023-12-16 23:49:27: Using endpoint '1'
Zigbee2MQTT:debug 2023-12-16 23:49:27: Received Zigbee message from 'Foo', type 'commandQueryNextImageRequest', cluster 'genOta', data '{"fieldControl":0,"fileVersion":6683,"imageType":141,"manufacturerCode":4447}' from endpoint 1 with groupID 0
Zigbee2MQTT:debug 2023-12-16 23:49:27: Got OTA request '{"fieldControl":0,"manufacturerCode":4447,"imageType":141,"fileVersion":6683}'
Zigbee2MQTT:debug 2023-12-16 23:49:27: ZigbeeOTA: downloaded main index
Zigbee2MQTT:debug 2023-12-16 23:49:27: getNewImage for '0x54ef4410008c50a3', meta {"fileVersion":672539,"fileSize":942962,"url":"https://github.com/Koenkk/zigbee-OTA/raw/master/images/Xiaomi/20230610160234_lumi.light.acn132_mcu_0.0.0_2627_20230606_DA1C86.ota","sha512":"25007f79ccb030715cd9fa1a0acd447554aa1b8c0627116b0ae06e5135e6c5922e64eace80452e9a05423487d499df1fa0a23a30aead31fac2f15c51f9d82895"}
Zigbee2MQTT:debug 2023-12-16 23:49:27: ZigbeeOTA: downloading firmware image from https://github.com/Koenkk/zigbee-OTA/raw/master/images/Xiaomi/20230610160234_lumi.light.acn132_mcu_0.0.0_2627_20230606_DA1C86.ota
Zigbee2MQTT:debug 2023-12-16 23:49:28: OTA update checksum validation succeeded for '0x54ef4410008c50a3'
Zigbee2MQTT:debug 2023-12-16 23:49:28: getNewImage for '0x54ef4410008c50a3', image header {"otaUpgradeFileIdentifier":{"type":"Buffer","data":[30,241,238,11]},"otaHeaderVersion":256,"otaHeaderLength":56,"otaHeaderFieldControl":0,"manufacturerCode":4447,"imageType":141,"fileVersion":672539,"zigbeeStackVersion":2,"otaHeaderString":"Aqara OTA Image\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000","totalImageSize":942962}
Zigbee2MQTT:debug 2023-12-16 23:49:28: Got new image for '0x54ef4410008c50a3'
Zigbee2MQTT:debug 2023-12-16 23:49:28: Starting upgrade
Zigbee2MQTT:debug 2023-12-16 23:49:28: Received Zigbee message from 'Foo', type 'commandQueryNextImageRequest', cluster 'genOta', data '{"fieldControl":0,"fileVersion":6683,"imageType":141,"manufacturerCode":4447}' from endpoint 1 with groupID 0
Zigbee2MQTT:debug 2023-12-16 23:49:28: Request offsets: fileOffset=0 pageOffset=0 dataSize=48
Zigbee2MQTT:debug 2023-12-16 23:49:28: Payload offsets: start=0 end=48 dataSize=48
Zigbee2MQTT:debug 2023-12-16 23:49:28: OTA update at 0%, remaining Infinity seconds
Zigbee2MQTT:info  2023-12-16 23:49:28: Update of 'Foo' at 0.00%
Zigbee2MQTT:info  2023-12-16 23:49:28: MQTT publish: topic 'zigbee2mqtt/Foo', payload '{"audio":"OFF","audio_effect":null,"audio_sensitivity":null,"brightness":127,"color":{"x":0.3813,"y":0.3773},"color_mode":"color_temp","color_temp":251,"length":2,"linkquality":102,"max_brightness":100,"min_brightness":1,"power_on_behavior":null,"preset":null,"speed":null,"state":"OFF","update":{"installed_version":6683,"latest_version":672539,"progress":0,"state":"updating"},"update_available":null}'
Zigbee2MQTT:debug 2023-12-16 23:49:28: Request offsets: fileOffset=48 pageOffset=0 dataSize=48
Zigbee2MQTT:debug 2023-12-16 23:49:28: Payload offsets: start=48 end=96 dataSize=48
Zigbee2MQTT:debug 2023-12-16 23:49:29: Request offsets: fileOffset=533638 pageOffset=0 dataSize=48
[...]
Zigbee2MQTT:debug 2023-12-16 23:59:00: Payload offsets: start=629170 end=629218 dataSize=48
Zigbee2MQTT:debug 2023-12-16 23:59:01: Request offsets: fileOffset=629218 pageOffset=0 dataSize=48
Zigbee2MQTT:debug 2023-12-16 23:59:01: Payload offsets: start=629218 end=629266 dataSize=48
Zigbee2MQTT:debug 2023-12-16 23:59:01: OTA update at 66.73%, remaining 285.59610444710734 seconds
Zigbee2MQTT:info  2023-12-16 23:59:01: Update of 'Foo' at 66.73%, ≈ 5 minutes remaining
Zigbee2MQTT:info  2023-12-16 23:59:01: MQTT publish: topic 'zigbee2mqtt/Foo', payload '{"audio":"OFF","audio_effect":null,"audio_sensitivity":null,"brightness":127,"color":{"x":0.3813,"y":0.3773},"color_mode":"color_temp","color_temp":251,"length":2,"linkquality":54,"max_brightness":100,"min_brightness":1,"power_on_behavior":null,"preset":null,"speed":null,"state":"OFF","update":{"installed_version":6683,"latest_version":672539,"progress":66.73,"remaining":286,"state":"updating"},"update_available":null}'
[...]
Zigbee2MQTT:debug 2023-12-17 00:29:33: Request offsets: fileOffset=942946 pageOffset=0 dataSize=48
Zigbee2MQTT:debug 2023-12-17 00:29:33: Payload offsets: start=942946 end=942962 dataSize=48
Zigbee2MQTT:debug 2023-12-17 00:29:33: Got upgrade end request for '0x54ef4410008c50a3': {"status":0,"manufacturerCode":4447,"imageType":141,"fileVersion":672539}
Zigbee2MQTT:debug 2023-12-17 00:29:33: Update succeeded, waiting for device announce
Zigbee2MQTT:info  2023-12-17 00:29:33: Update of 'Foo' at 100.00%
Zigbee2MQTT:info  2023-12-17 00:29:33: MQTT publish: topic 'zigbee2mqtt/Foo', payload '{"audio":"OFF","audio_effect":null,"audio_sensitivity":null,"brightness":127,"color":{"x":0.3813,"y":0.3773},"color_mode":"color_temp","color_temp":251,"length":2,"linkquality":138,"max_brightness":100,"min_brightness":1,"power_on_behavior":null,"preset":null,"speed":null,"state":"OFF","update":{"installed_version":6683,"latest_version":672539,"progress":100,"remaining":8,"state":"updating"},"update_available":null}'
[...]
Zigbee2MQTT:debug 2023-12-17 00:29:51: Received Zigbee message from 'Foo', type 'attributeReport', cluster 'aqaraOpple', data '{"1307":10}' from endpoint 1 with groupID 0
Zigbee2MQTT:info  2023-12-17 00:29:51: MQTT publish: topic 'zigbee2mqtt/Foo', payload '{"audio":"OFF","audio_effect":null,"audio_sensitivity":null,"brightness":127,"color":{"x":0.3813,"y":0.3773},"color_mode":"color_temp","color_temp":251,"length":2,"linkquality":134,"max_brightness":100,"min_brightness":1,"power_on_behavior":null,"preset":null,"speed":null,"state":"OFF","update":{"installed_version":6683,"latest_version":672539,"progress":100,"remaining":8,"state":"updating"},"update_available":null}'
Zigbee2MQTT:debug 2023-12-17 00:29:57: Got device announce or timed out, call resolve
Zigbee2MQTT:debug 2023-12-17 00:29:57: Device 'Foo' announced itself
Zigbee2MQTT:info  2023-12-17 00:29:57: MQTT publish: topic 'zigbee2mqtt/bridge/event', payload '{"data":{"friendly_name":"Foo","ieee_address":"0x54ef4410008c50a3"},"type":"device_announce"}'
Zigbee2MQTT:info  2023-12-17 00:29:57: Finished update of 'Foo'
Zigbee2MQTT:info  2023-12-17 00:29:57: Configuring 'Foo'
Zigbee2MQTT:info  2023-12-17 00:29:57: MQTT publish: topic 'zigbee2mqtt/Foo', payload '{"audio":"OFF","audio_effect":null,"audio_sensitivity":null,"brightness":127,"color":{"x":0.3813,"y":0.3773},"color_mode":"color_temp","color_temp":251,"length":2,"linkquality":134,"max_brightness":100,"min_brightness":1,"power_on_behavior":null,"preset":null,"speed":null,"state":"OFF","update":{"installed_version":672539,"latest_version":672539,"state":"idle"},"update_available":null}'
Zigbee2MQTT:debug 2023-12-17 00:29:57: Received Zigbee message from 'Foo', type 'attributeReport', cluster 'aqaraOpple', data '{"1307":10}' from endpoint 1 with groupID 0
Zigbee2MQTT:info  2023-12-17 00:29:57: MQTT publish: topic 'zigbee2mqtt/Foo', payload '{"audio":"OFF","audio_effect":null,"audio_sensitivity":null,"brightness":127,"color":{"x":0.3813,"y":0.3773},"color_mode":"color_temp","color_temp":251,"length":2,"linkquality":43,"max_brightness":100,"min_brightness":1,"power_on_behavior":null,"preset":null,"speed":null,"state":"OFF","update":{"installed_version":672539,"latest_version":672539,"state":"idle"},"update_available":null}'
Zigbee2MQTT:debug 2023-12-17 00:29:59: Retrieving state of 'Foo' after reconnect
[...]
Zigbee2MQTT:debug 2023-12-17 00:30:10: Received Zigbee message from 'Foo', type 'readResponse', cluster 'lightingColorCtrl', data '{"colorCapabilities":24}' from endpoint 1 with groupID 0
Zigbee2MQTT:info  2023-12-17 00:30:10: MQTT publish: topic 'zigbee2mqtt/Foo', payload '{"audio":"OFF","audio_effect":null,"audio_sensitivity":null,"brightness":127,"color":{"x":0.3813,"y":0.3773},"color_mode":"color_temp","color_temp":251,"length":2,"linkquality":18,"max_brightness":100,"min_brightness":1,"power_on_behavior":null,"preset":null,"speed":null,"state":"OFF","update":{"installed_version":672539,"latest_version":672539,"state":"idle"},"update_available":null}'
Zigbee2MQTT:debug 2023-12-17 00:30:10: Received Zigbee message from 'Foo', type 'readResponse', cluster 'genBasic', data '{"dateCode":"20230606"}' from endpoint 1 with groupID 0
Zigbee2MQTT:info  2023-12-17 00:30:10: Device 'Foo' was updated from 'null' to 'null'
Zigbee2MQTT:info  2023-12-17 00:30:10: MQTT publish: topic 'zigbee2mqtt/bridge/response/device/ota_update/update', payload '{"data":{"from":null,"id":"Foo","to":null},"status":"ok","transaction":"h50az-29"}'
Zigbee2MQTT:debug 2023-12-17 00:30:10: Received Zigbee message from 'Foo', type 'readResponse', cluster 'genOnOff', data '{"onOff":0}' from endpoint 1 with groupID 0
Zigbee2MQTT:info  2023-12-17 00:30:10: MQTT publish: topic 'zigbee2mqtt/Foo', payload '{"audio":"OFF","audio_effect":null,"audio_sensitivity":null,"brightness":127,"color":{"x":0.3813,"y":0.3773},"color_mode":"color_temp","color_temp":251,"length":2,"linkquality":18,"max_brightness":100,"min_brightness":1,"power_on_behavior":null,"preset":null,"speed":null,"state":"OFF","update":{"installed_version":672539,"latest_version":672539,"state":"idle"},"update_available":null}'
Zigbee2MQTT:debug 2023-12-17 00:30:10: Received Zigbee message from 'Foo', type 'readResponse', cluster 'lightingColorCtrl', data '{"colorTempPhysicalMax":370,"colorTempPhysicalMin":153}' from endpoint 1 with groupID 0
Zigbee2MQTT:info  2023-12-17 00:30:10: MQTT publish: topic 'zigbee2mqtt/Foo', payload '{"audio":"OFF","audio_effect":null,"audio_sensitivity":null,"brightness":127,"color":{"x":0.3813,"y":0.3773},"color_mode":"color_temp","color_temp":251,"length":2,"linkquality":14,"max_brightness":100,"min_brightness":1,"power_on_behavior":null,"preset":null,"speed":null,"state":"OFF","update":{"installed_version":672539,"latest_version":672539,"state":"idle"},"update_available":null}'
Zigbee2MQTT:info  2023-12-17 00:30:10: Successfully configured 'Foo'
Zigbee2MQTT:debug 2023-12-17 00:30:22: Received Zigbee message from 'Foo', type 'read', cluster 'genTime', data '["time","timeZone"]' from endpoint 1 with groupID 0
Zigbee2MQTT:debug 2023-12-17 00:30:23: Received Zigbee message from 'Foo', type 'attributeReport', cluster 'aqaraOpple', data '{"1301":1}' from endpoint 1 with groupID 0
Zigbee2MQTT:info  2023-12-17 00:30:23: MQTT publish: topic 'zigbee2mqtt/Foo', payload '{"audio":"OFF","audio_effect":null,"audio_sensitivity":null,"brightness":127,"color":{"x":0.3813,"y":0.3773},"color_mode":"color_temp","color_temp":251,"length":2,"linkquality":18,"max_brightness":100,"min_brightness":1,"power_on_behavior":null,"preset":null,"speed":null,"state":"OFF","update":{"installed_version":672539,"latest_version":672539,"state":"idle"},"update_available":null}'
Zigbee2MQTT:debug 2023-12-17 00:30:24: Received Zigbee message from 'Foo', type 'attributeReport', cluster 'aqaraOpple', data '{"1302":100}' from endpoint 1 with groupID 0
Zigbee2MQTT:info  2023-12-17 00:30:24: MQTT publish: topic 'zigbee2mqtt/Foo', payload '{"audio":"OFF","audio_effect":null,"audio_sensitivity":null,"brightness":127,"color":{"x":0.3813,"y":0.3773},"color_mode":"color_temp","color_temp":251,"length":2,"linkquality":18,"max_brightness":100,"min_brightness":1,"power_on_behavior":null,"preset":null,"speed":null,"state":"OFF","update":{"installed_version":672539,"latest_version":672539,"state":"idle"},"update_available":null}'
Zigbee2MQTT:debug 2023-12-17 00:30:54: Received Zigbee message from 'Foo', type 'attributeReport', cluster 'aqaraOpple', data '{"223":{"data":[0,35,193,0,0,0,1,35,13,0,0,0,2,35,7,0,0,0,3,35,13,0,0,0,4,33,1,0,5,33,0,0,6,33,1,0,7,33,1,32,8,33,18,0,9,33,16,0,10,33,1,0,11,33,1,0,19,33,0,0,20,33,0,0],"type":"Buffer"}}' from endpoint 1 with groupID 0
Zigbee2MQTT:debug 2023-12-17 00:30:54: Received Zigbee message from 'Foo', type 'attributeReport', cluster 'aqaraOpple', data '{"223":{"data":[22,33,0,0,23,33,0,0,12,33,1,0,24,33,0,0],"type":"Buffer"}}' from endpoint 1 with groupID 0
Zigbee2MQTT:debug 2023-12-17 00:31:07: Saving state to file /app/data/state.json
[...]

The highlight of this update log is of course the fact that the device reports the right version (672539) after the update:

Zigbee2MQTT:info  2023-12-17 00:30:24: MQTT publish: topic 'zigbee2mqtt/Foo', payload '{"audio":"OFF","audio_effect":null,"audio_sensitivity":null,"brightness":127,"color":{"x":0.3813,"y":0.3773},"color_mode":"color_temp","color_temp":251,"length":2,"linkquality":18,"max_brightness":100,"min_brightness":1,"power_on_behavior":null,"preset":null,"speed":null,"state":"OFF","update":{"installed_version":672539,"latest_version":672539,"state":"idle"},"update_available":null}'

All looks fine, right? So, where is the problem? Let's press the Check for new updates button and see what the device does:

[...]
Zigbee2MQTT:debug 2023-12-17 00:42:06: Received MQTT message on 'zigbee2mqtt/bridge/request/device/ota_update/check' with data '{"id":"Foo","transaction":"h50az-30"}'
Zigbee2MQTT:info  2023-12-17 00:42:06: Checking if update available for 'Foo'
Zigbee2MQTT:debug 2023-12-17 00:42:06: Check if update available for '0x54ef4410008c50a3' (lumi.light.acn132)
Zigbee2MQTT:debug 2023-12-17 00:42:06: Using endpoint '1'
Zigbee2MQTT:debug 2023-12-17 00:42:06: Received Zigbee message from 'Foo', type 'commandQueryNextImageRequest', cluster 'genOta', data '{"fieldControl":0,"fileVersion":6683,"imageType":141,"manufacturerCode":4447}' from endpoint 1 with groupID 0
Zigbee2MQTT:debug 2023-12-17 00:42:06: Got OTA request '{"fieldControl":0,"manufacturerCode":4447,"imageType":141,"fileVersion":6683}'
Zigbee2MQTT:debug 2023-12-17 00:42:06: ZigbeeOTA: downloaded main index
Zigbee2MQTT:debug 2023-12-17 00:42:06: Is new image available for '0x54ef4410008c50a3', current '{"fieldControl":0,"manufacturerCode":4447,"imageType":141,"fileVersion":6683}', latest meta '{"fileVersion":672539,"fileSize":942962,"url":"https://github.com/Koenkk/zigbee-OTA/raw/master/images/Xiaomi/20230610160234_lumi.light.acn132_mcu_0.0.0_2627_20230606_DA1C86.ota","sha512":"25007f79ccb030715cd9fa1a0acd447554aa1b8c0627116b0ae06e5135e6c5922e64eace80452e9a05423487d499df1fa0a23a30aead31fac2f15c51f9d82895"}'
Zigbee2MQTT:debug 2023-12-17 00:42:06: Update available for '0x54ef4410008c50a3': YES
Zigbee2MQTT:info  2023-12-17 00:42:06: Update available for 'Foo'

So, the device suddenly reports the old version (6683) again. And at this point, I am out of ideas.

hippytyre commented 10 months ago

I have the same issue, it's all working perfectly but the update is irritating me. I like to be up to date!

difrost commented 10 months ago

Same issue here. Seems like the firmware is indeed getting upgraded but somehow shows it runs on 6683 tho the build date was changed.

remezen commented 8 months ago

Same here, the update notification is very irritating.

Alfy1080 commented 5 months ago

Same issue for me as well....this has been going on for quite a while now. If there's anything i can help with, let me know.

remezen commented 2 months ago

Could anyone propose a solution, please?

Teeseeone commented 1 month ago

still an issue.