search

Koenkk / zigbee2mqtt

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

OTA process fails - timeout, device did not request any image blocks #22819

Closed 1mfaasj closed 4 weeks ago

1mfaasj commented 3 months ago

What happened?

I'm trying to update my HUE lamp to a newer version but it fails: ERROR OTA: timeout, device did not request any image blocks

More information about the device: Zigbee model: LTA001 Zigbee fabrikant: Signify Netherlands B.V Description: HUE white ambiance E27 with bluetooth

What did you expect to happen?

that the update starts and finishes successfully.

How to reproduce it (minimal and precise)

Open zigbee2mqtt, OTA and see that there is an available update. When I click on Update it fails after a few minutes.

Zigbee2MQTT version

1.37.1

Adapter firmware version

20221226

Adapter

zStack3x0

Setup

Home Assistant running in Docker

Debug log

No response

Nerivec commented 3 months ago

OTA got refactored in dev branch. Any chance you can try it? Otherwise, it will be in July release, you can try then. Lots of Hue devices got tested on it already.

1mfaasj commented 2 months ago

Hi @Nerivec I switched to image: koenkk/zigbee2mqtt:latest-dev but it looks like the error stays:

Info 2024-06-19 11:51:49z2m: Updating 'VoorraadhokLamp' to latest firmware
Info 2024-06-19 11:51:50z2m: Update of 'VoorraadhokLamp' at 0.00%
Info 2024-06-19 11:51:50z2m:mqtt: MQTT publish: topic 'zigbee2mqtt/VoorraadhokLamp', payload '{"brightness":254,"linkquality":80,"power_on_behavior":null,"state":"ON","update":{"installed_version":16785162,"latest_version":16786434,"progress":0,"state":"updating"},"update_available":null}'
Info 2024-06-19 11:54:20z2m:mqtt: MQTT publish: topic 'zigbee2mqtt/VoorraadhokLamp', payload '{"brightness":254,"linkquality":76,"power_on_behavior":null,"state":"ON","update":{"installed_version":16785162,"latest_version":16786434,"state":"available"},"update_available":null}'
Info 2024-06-19 11:54:20z2m:mqtt: MQTT publish: topic 'zigbee2mqtt/bridge/response/device/ota_update/update', payload '{"data":{"id":"VoorraadhokLamp"},"error":"Update of 'VoorraadhokLamp' failed (Timeout. Device did not start/finish firmware download after being notified. (Error: Timeout - 8102 - 11 - null - 25 - 3 after 150000ms))","status":"error","transaction":"nhfjc-2"}'
Error 2024-06-19 11:54:20z2m: Update of 'VoorraadhokLamp' failed (Timeout. Device did not start/finish firmware download after being notified. (Error: Timeout - 8102 - 11 - null - 25 - 3 after 150000ms))
1mfaasj commented 2 months ago

Any progress?

Nerivec commented 2 months ago

We'd need to see what is going on with that particular device (since other Hue have no problem). Any chance you can sniff the process of starting an OTA and waiting for it to fail? https://www.zigbee2mqtt.io/advanced/zigbee/04_sniff_zigbee_traffic.html

1mfaasj commented 2 months ago

I've gathered some more debug data, something you can use for finding the rootcause? I've got the same issue with all my HUE lamps. I also tried the latest 5 zigbee2mqtt versions without luck unfortunately.

It looks like its receiving an update but doesn't actually update the new image to the device?

Debug 2024-07-12 14:38:20Received MQTT message on 'zigbee2mqtt/bridge/request/device/ota_update/update' with data '{"id":"ZolderLamp","transaction":"7mstz-2"}'
Info 2024-07-12 14:38:20Updating 'ZolderLamp' to latest firmware
Debug 2024-07-12 14:38:20Received Zigbee message from 'ZolderLamp', type 'readResponse', cluster 'genBasic', data '{"dateCode":"20230403","swBuildId":"1.104.2"}' from endpoint 11 with groupID 0
Debug 2024-07-12 14:38:20OTA: Updating to latest '0x001788010b87ea55' (LWA004)
Debug 2024-07-12 14:38:20OTA: Using endpoint '11'
Debug 2024-07-12 14:38:20Received Zigbee message from 'ZolderLamp', type 'commandQueryNextImageRequest', cluster 'genOta', data '{"fieldControl":0,"fileVersion":16786696,"imageType":274,"manufacturerCode":4107}' from endpoint 11 with groupID 0
Debug 2024-07-12 14:38:20OTA: Got request '{"fieldControl":0,"manufacturerCode":4107,"imageType":274,"fileVersion":16786696}'
Debug 2024-07-12 14:38:20ZigbeeOTA: Getting image metadata for 'LWA004'
Debug 2024-07-12 14:38:20ZigbeeOTA: Downloaded main index
Debug 2024-07-12 14:38:20OTA: Getting new image for '0x001788010b87ea55' (LWA004), latest meta {"fileVersion":16787456,"fileSize":467774,"url":"https://otau.meethue.com/storage/ZGB_100B_0112/4d726d6f-7a87-4c6a-962f-f9c76ce125ef/100B-0112-01002800-ConfLightBLE-Lamps-EFR32MG13.zigbee","sha512":"75308c541c19a71cbf1a2f30b413c630e1852bed2e94be312a2fa5429e2caf058a55e759f180e4b9cf9e676ed2692285b6c51b5748c3f031e06f7f52b46f6060"}
Debug 2024-07-12 14:38:20OTA: Downloading firmware image from 'https://otau.meethue.com/storage/ZGB_100B_0112/4d726d6f-7a87-4c6a-962f-f9c76ce125ef/100B-0112-01002800-ConfLightBLE-Lamps-EFR32MG13.zigbee' using the zigbeeOTA custom CA certificates
Debug 2024-07-12 14:38:21OTA: Update checksum validation succeeded for '0x001788010b87ea55' (LWA004)
Debug 2024-07-12 14:38:21OTA: Get new image for '0x001788010b87ea55' (LWA004), image header {"otaUpgradeFileIdentifier":{"type":"Buffer","data":[30,241,238,11]},"otaHeaderVersion":256,"otaHeaderLength":56,"otaHeaderFieldControl":0,"manufacturerCode":4107,"imageType":274,"fileVersion":16787456,"zigbeeStackVersion":2,"otaHeaderString":"\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000","totalImageSize":467774}
Debug 2024-07-12 14:38:21OTA: Got new image for '0x001788010b87ea55' (LWA004)
Debug 2024-07-12 14:38:21OTA: Starting upgrade
Debug 2024-07-12 14:38:21Received Zigbee message from 'ZolderLamp', type 'commandQueryNextImageRequest', cluster 'genOta', data '{"fieldControl":0,"fileVersion":16786696,"imageType":274,"manufacturerCode":4107}' from endpoint 11 with groupID 0
Debug 2024-07-12 14:38:22OTA: Request offsets: fileOffset=0 pageOffset=0 dataSize=64
Debug 2024-07-12 14:38:22OTA: Payload offsets: start=0 end=50 dataSize=50
Debug 2024-07-12 14:38:22OTA: Update at 0%, remaining Infinity seconds
Info 2024-07-12 14:38:22Update of 'ZolderLamp' at 0.00%
Info 2024-07-12 14:38:22MQTT publish: topic 'zigbee2mqtt/ZolderLamp', payload '{"brightness":254,"level_config":{"current_level_startup":254},"linkquality":69,"power_on_behavior":"on","state":"ON","update":{"installed_version":16786696,"latest_version":16787456,"progress":0,"state":"updating"},"update_available":null}'
Debug 2024-07-12 14:38:22OTA: Request offsets: fileOffset=0 pageOffset=0 dataSize=64
Debug 2024-07-12 14:38:22OTA: Payload offsets: start=0 end=50 dataSize=50
Debug 2024-07-12 14:40:37Successfully pinged 'ZolderLamp' (attempt 1/2)
Debug 2024-07-12 14:40:52Update of 'ZolderLamp' failed (Error: OTA: Timeout, device did not request any image blocks)
Info 2024-07-12 14:40:52MQTT publish: topic 'zigbee2mqtt/ZolderLamp', payload '{"brightness":254,"level_config":{"current_level_startup":254},"linkquality":69,"power_on_behavior":"on","state":"ON","update":{"installed_version":16786696,"latest_version":16787456,"state":"available"},"update_available":null}'
Info 2024-07-12 14:40:52MQTT publish: topic 'zigbee2mqtt/bridge/response/device/ota_update/update', payload '{"data":{"id":"ZolderLamp"},"error":"Update of 'ZolderLamp' failed (OTA: Timeout, device did not request any image blocks)","status":"error","transaction":"7mstz-2"}'
Error 2024-07-12 14:40:52Update of 'ZolderLamp' failed (OTA: Timeout, device did not request any image blocks)
Debug 2024-07-12 14:40:52Error: OTA: Timeout, device did not request any image blocks at /app/node_modules/zigbee-herdsman-converters/src/lib/ota/common.ts:532:28 at runNextTicks (node:internal/process/task_queues:60:5) at listOnTimeout (node:internal/timers:538:9) at processTimers (node:internal/timers:512:7)

on the status page at the device (in zigbee2mqtt interface):

{
    "brightness": 254,
    "level_config": {
        "current_level_startup": 254
    },
    "linkquality": 69,
    "power_on_behavior": "on",
    "state": "ON",
    "update": {
        "installed_version": 16786696,
        "latest_version": 16787456,
        "state": "available"
    },
    "update_available": null
}

at the About page

Zigbee model: LWA004
Zigbee Fabrikant: Signify Netherlands B.V.
Description: Hue Filament Standard A60/E27 bluetooth
IEEE adres: 0x001788010b87ea55
Netwerkadres: 0x77C4
Firmware build date: 20230403
Firmwareversion: 1.104.2
Fabrikant:  [Philips](https://www.zigbee2mqtt.io/supported-devices/#v=Philips)
Model: [8718699688820](https://www.zigbee2mqtt.io/devices/8718699688820.html#philips-8718699688820)
Koenkk commented 2 months ago

Could you try to move the device very close to the coordinator, re-pair it there and try to update again?

1mfaasj commented 1 month ago

hm after some more investigation; seems like I had also ZHA active in my HA, could be conflicting with the z2m integratie right? and the LQI of the most devices have a very low number, so I need to improve that first I think. the zigbee network is not stable atm so I will come back and try again when those issues are addressed.

1mfaasj commented 4 weeks ago

Issue solved by improving the network