zigbee2mqtt icon indicating copy to clipboard operation
zigbee2mqtt copied to clipboard

Ubisys C4: "Invalid image" on firmware update

Open ahemwe opened this issue 3 years ago • 2 comments

What happened?

I've added an Ubisys C4 device and tried to update the firmware.

Current firmware: 20160122-DE-FB0

What did you expect to happen?

successful firmware update

How to reproduce it (minimal and precise)

In frontend: Request firmware update of device

Update starts and then fails after some seconds.

Zigbee2MQTT version

1.28.0

Adapter firmware version

0x26780700

Adapter

ConBee2/RaspBee2

Debug log

2022-11-26 13:37:21MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"message":"Updating '0x001fee0000000ee8' to latest firmware","meta":{"device":"0x001fee0000000ee8","status":"update_in_progress"},"type":"ota_update"}' Debug 2022-11-26 13:37:21Received Zigbee message from '0x001fee0000000ee8', type 'readResponse', cluster 'genBasic', data '{"dateCode":"20160122-DE-FB0"}' from endpoint 1 with groupID null Info 2022-11-26 13:37:21MQTT publish: topic 'zigbee2mqtt/0x001fee0000000ee8', payload '{"last_seen":"2022-11-26T13:37:37+01:00","linkquality":255,"update":{"state":"available"},"update_available":true}' Debug 2022-11-26 13:37:21Updating to latest '0x001fee0000000ee8' (C4 (5504)) Debug 2022-11-26 13:37:21Using endpoint '232' Debug 2022-11-26 13:37:30Received Zigbee message from '0x001fee0000000ee8', type 'commandQueryNextImageRequest', cluster 'genOta', data '{"fieldControl":1,"fileVersion":17039684,"imageType":31497,"manufacturerCode":4338}' from endpoint 232 with groupID null Info 2022-11-26 13:37:30MQTT publish: topic 'zigbee2mqtt/0x001fee0000000ee8', payload '{"last_seen":"2022-11-26T13:37:47+01:00","linkquality":255,"update":{"state":"available"},"update_available":true}' Debug 2022-11-26 13:37:30Got OTA request '{"fieldControl":1,"manufacturerCode":4338,"imageType":31497,"fileVersion":17039684}' Debug 2022-11-26 13:37:30OTA ubisys: got firmware page, status: 200, data.length: 12017 Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B01-0000-0006-01110206-spo-fmd.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B01-0000-0006-0192020D-spo-fmd.ota1.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B02-0000-0001-010F0206-spo-fms.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B02-0000-0001-0192020D-spo-fms.ota1.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B02-0002-0007-010F0206-spo-fms.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B02-0002-0007-0192020D-spo-fms.ota1.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B03-0000-0006-010E0206-spo-fms2.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B03-0000-0006-0191020D-spo-fms2.ota1.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B04-0000-0007-01160206-spo-fmsh.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B04-0000-0007-0191020D-spo-fmsh.ota1.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B05-0000-0004-010F0206-spo-rms.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B05-0000-0004-0191020D-spo-rms.ota1.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B06-0000-0004-010E0206-spo-rms2.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B06-0000-0004-0191020D-spo-rms2.ota1.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B07-0000-0004-01160206-spo-rmsh.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B07-0000-0004-0191020D-spo-rmsh.ota1.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B08-0000-0004-01110206-spo-rmd.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B08-0000-0004-0192020D-spo-rmd.ota1.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B09-0000-0004-01090206-spo-fmi4.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B09-0000-0004-0192020D-spo-fmi4.ota1.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B0A-0000-0005-010A0206-m7b-r0.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B0A-0000-0005-0193020D-m7b-r0.ota1.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B0B-0000-0001-01000206-m7b-h10.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B0B-0000-0001-01900210-m7b-h10.ota1.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B0C-0000-0000-01000206-m7b-wd1.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B0D-0000-0001-01140240-m7b-h1.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B0D-0000-0001-011C0300-m7b-h1.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B11-0000-0001-00920210-m7b-ld6.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B11-0000-0001-00940240-m7b-q95.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B21-0000-0006-0193020E-spo-fmd.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B21-0000-0006-0194020E-spo-fmd.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B22-0000-0001-0193020D-spo-fms-rev0-1.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B22-0002-0007-0193020D-spo-fms.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B23-0000-0006-0192020D-spo-fms2.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B24-0000-0007-0192020D-spo-fmsh.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B25-0000-0004-0192020D-spo-rms.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B26-0000-0004-0192020D-spo-rms2.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B27-0000-0004-0192020D-spo-rmsh.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B28-0000-0004-0194020E-spo-rmd.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B28-0000-0004-0195020E-spo-rmd.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B29-0000-0004-01930221-spo-fmi4.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B29-0000-0004-01940221-spo-fmi4.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B2A-0000-0005-02000230-m7b-r0.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B2A-0000-0005-02010230-m7b-r0.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B2B-0000-0001-01920210-m7b-h10.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B2C-0000-0001-01010300-ld6.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B31-0000-0006-02010300-spo-fmd.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B32-0000-0001-02000300-spo-fms-rev0-1.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B32-0002-0007-02000300-spo-fms.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B33-0000-0006-02000300-spo-fms2.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B34-0000-0007-02000300-spo-fmsh.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B35-0000-0004-02000300-spo-rms.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B36-0000-0004-02000300-spo-rms2.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B37-0000-0004-02000300-spo-rmsh.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B38-0000-0004-02010300-spo-rmd.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B39-0000-0004-02000300-spo-fmi4.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B3A-0000-0005-02020300-m7b-r0.ota.zigbee Debug 2022-11-26 13:37:30OTA ubisys: image found: 10F2-7B3B-0000-0001-02000300-m7b-h10.ota.zigbee Debug 2022-11-26 13:37:30getNewImage for '0x001fee0000000ee8', meta {"hardwareVersionMin":0,"hardwareVersionMax":4,"fileVersion":26345997,"url":"http://fwu.ubisys.de/smarthome/OTA/release/10F2-7B09-0000-0004-0192020D-spo-fmi4.ota1.zigbee"} Debug 2022-11-26 13:37:31getNewImage for '0x001fee0000000ee8', image header {"otaUpgradeFileIdentifier":{"type":"Buffer","data":[30,241,238,11]},"otaHeaderVersion":256,"otaHeaderLength":60,"otaHeaderFieldControl":4,"manufacturerCode":4338,"imageType":31497,"fileVersion":26345997,"zigbeeStackVersion":2,"otaHeaderString":"ubisys C4\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000\u0000","totalImageSize":208802,"minimumHardwareVersion":0,"maximumHardwareVersion":4} Debug 2022-11-26 13:37:31Got new image for '0x001fee0000000ee8' Debug 2022-11-26 13:37:31Starting upgrade Debug 2022-11-26 13:37:35Received Zigbee message from '0x001fee0000000ee8', type 'commandQueryNextImageRequest', cluster 'genOta', data '{"fieldControl":1,"fileVersion":17039684,"imageType":31497,"manufacturerCode":4338}' from endpoint 232 with groupID null Info 2022-11-26 13:37:35MQTT publish: topic 'zigbee2mqtt/0x001fee0000000ee8', payload '{"last_seen":"2022-11-26T13:37:52+01:00","linkquality":255,"update":{"state":"available"},"update_available":true}' Info 2022-11-26 13:37:35MQTT publish: topic 'zigbee2mqtt/0x001fee0000000ee8', payload '{"last_seen":"2022-11-26T13:37:52+01:00","linkquality":255,"update":{"state":"available"},"update_available":true}' Debug 2022-11-26 13:37:35OTA update at 0%, remaining Infinity seconds Info 2022-11-26 13:37:35Update of '0x001fee0000000ee8' at 0.00% Info 2022-11-26 13:37:35MQTT publish: topic 'zigbee2mqtt/0x001fee0000000ee8', payload '{"last_seen":"2022-11-26T13:37:52+01:00","linkquality":255,"update":{"progress":0,"state":"updating"},"update_available":false}' Info 2022-11-26 13:37:35MQTT publish: topic 'zigbee2mqtt/bridge/log', payload '{"message":"Update of '0x001fee0000000ee8' at 0.00%","meta":{"device":"0x001fee0000000ee8","progress":0,"status":"update_progress"},"type":"ota_update"}' Info 2022-11-26 13:37:35MQTT publish: topic 'zigbee2mqtt/0x001fee0000000ee8', payload '{"last_seen":"2022-11-26T13:37:52+01:00","linkquality":255,"update":{"progress":0,"state":"updating"},"update_available":false}' Info 2022-11-26 13:37:35MQTT publish: topic 'zigbee2mqtt/0x001fee0000000ee8', payload '{"last_seen":"2022-11-26T13:37:52+01:00","linkquality":255,"update":{"progress":0,"state":"updating"},"update_available":false}' Info 2022-11-26 13:37:36MQTT publish: topic 'zigbee2mqtt/0x001fee0000000ee8', payload '{"last_seen":"2022-11-26T13:37:52+01:00","linkquality":255,"update":{"progress":0,"state":"updating"},"update_available":false}' Info 2022-11-26 13:37:36MQTT publish: topic 'zigbee2mqtt/0x001fee0000000ee8', payload '{"last_seen":"2022-11-26T13:37:53+01:00","linkquality":255,"update":{"progress":0,"state":"updating"},"update_available":false}' Info 2022-11-26 13:37:49MQTT publish: topic 'zigbee2mqtt/0x001fee0000000ee8', payload '{"last_seen":"2022-11-26T13:38:05+01:00","linkquality":255,"update":{"progress":0,"state":"updating"},"update_available":false}' Info 2022-11-26 13:37:49MQTT publish: topic 'zigbee2mqtt/0x001fee0000000ee8', payload '{"last_seen":"2022-11-26T13:38:05+01:00","linkquality":255,"update":{"progress":0,"state":"updating"},"update_available":false}' Debug 2022-11-26 13:37:49Got upgrade end request for '0x001fee0000000ee8': {"status":150,"manufacturerCode":4338,"imageType":31497,"fileVersion":26345997} Debug 2022-11-26 13:37:49Update failed with reason: 'invalid image' Debug 2022-11-26 13:37:49Update of '0x001fee0000000ee8' failed (Error: Update failed with reason: 'invalid image')

ahemwe avatar Nov 26 '22 12:11 ahemwe

I've checked the web page of the vendor and found the latest firmware of this device mentioned 10F2-7B39-0000-0004-02000300-spo-fmi4.ota.zigbee.

This file is also listed in in the log above, but it's not downloaded. Instead, 10F2-7B09-0000-0004-0192020D-spo-fmi4.ota1.zigbee is downloaded from zigbee2mqtt, which is not listed for any device on the webpage.

I see the decision for that image is made here in zigbee-herdsman-converters but I've no clue where imageType is defined for this device.

Could it be, that the naming scheme for ubisys firmware changed and z2h has to be adapted?

ahemwe avatar Nov 26 '22 17:11 ahemwe

One more observation: Ubisys mentions in their changelog that firmware update has to be done sequentially from one release to the next. This would mean, current firmware has always to be taken into account when updating. Is this considered in z2h?

ahemwe avatar Nov 26 '22 17:11 ahemwe

@felixstorm Thanks a lot for providing OTA for ubisys some years ago. May I ask you kindly for your advice on this topic? Why does z2h try to download a different file than the one mentioned on the webpage?

ahemwe avatar Dec 04 '22 10:12 ahemwe

@ahemwe Thanks for notifying me. The general idea is to select the oldest image that fits the hardware (i.e. that has the same imageType as the device reports for itself) and that still has a higher version than the current one to comply with the sequentially rule.
Also, ubisys changed the image file format at one point and also switched the image type of all devices that already have a newer firmware version and were therefore able to accept updates in the new format. This might very well also be the primary reason behind the sequentially rule.

I will try to look into this more in detail to find out why it’s not working and how to fix it, but it might take a few days to find some spare time. I think that I ran into the same issue myself once with a C4 but then just kept it on the old firmware due to lack of time, so I might even be able to reproduce it here…

felixstorm avatar Dec 04 '22 11:12 felixstorm

Ok, I think I have an idea now: The firmware download code has been reworked to use an official repository as the firmware source, but in https://github.com/Koenkk/zigbee-herdsman-converters/pull/4491 the logic seems to have been forced to always take the latest firmware instead of the oldest one but higher than current.

And I suppose the firmware on your (and my) C4 is so old that the latest one just matching the image type does not work but an intermediate step is required. I will try out a changed logic when at my computer then report here…

felixstorm avatar Dec 04 '22 11:12 felixstorm

Thanks a lot for your feedback and all activities. If I can somehow support by testing something on my end, please let me know. My current firmware is 20160122-DE-FB0. BTW: My motivation for updating the firmware is, that I only see endpoint-agnostic action data when pushing any button. Meaning, when configuring the input actions to toggle I only see action toggle for all inputs and not e.g. 1_toggle when using input 1, and 2_toggelwhen using input 2 as mentioned in documentation.

ahemwe avatar Dec 04 '22 12:12 ahemwe

I’m not deep into the details of how actions get reported ATM, but TBH I am not sure if a firmware update will change anything here since AFAIK the Zigbee side of the ubisys device will most likely not change that much with the update. It might very well be that there is another issue with your configuration. Unfortunately I use the C4 only to directly control other directly bound Zigbee devices, so I cannot give much advice here.

About the your firmware version: This gets reported in Z2M as firmware build date, but at least with regards to ubisys devices it seems more like a hardware version to me since it does not change with firmware updates. The firmware version should appear in the next column, but only the later ubisys firmware versions seem to actually do that…

felixstorm avatar Dec 04 '22 13:12 felixstorm

@ahemwe I have tried around with this quite a bit now, but unfortunately to no avail. I tried both the older as well as the later firmware version that fit the device (by adjusting the code to select it), but both get refused for me. I will try to get in contact with ubisys support now and check if they have an idea what could be going wrong...

felixstorm avatar Dec 08 '22 16:12 felixstorm

Did ubisys provide any feedback on your request? Is there anything a non-js programmer could contribute to this issue? @felixstorm

ahemwe avatar Jan 06 '23 12:01 ahemwe

@ahemwe I have been on vacation until yesterday but will try to follow up with ubisys at the beginning of this week. They already told me that there is no other firmware version in between that would be able to solve this, so I sent them a log dump containing the Zigbee messages.

But TBH I am not sure if it is something that is solvable by software at all - I might just have to send in the C4 for them to update it (and potentially fix it internally). I will post here as soon as I have any further information...

felixstorm avatar Jan 09 '23 08:01 felixstorm

Short update: I was in contact with ubisys again today and after checking the logs again, they asked me to send in the device for an exchange and hoping that they can diagnose the issue a bit further in their own lab.

But TBH it seems to me more and more that there is probably not much that can be done on the side on zigbee2mqtt to fix this.

felixstorm avatar Jan 16 '23 17:01 felixstorm

This issue is stale because it has been open 30 days with no activity. Remove stale label or comment or this will be closed in 7 days

github-actions[bot] avatar Feb 16 '23 00:02 github-actions[bot]