VZM31-SN firmware updates aborting and hanging via Z2M

Greetings. First a quick background. I’m only a couple of weeks into Home Assistant, and a day or so into Mosquitto and Zigbee2MQTT. I have just moved two Blue 2-in-1 VZM31-SN over from SmartThings to my HA (docker) + Mosquitto (docker) + Z2M (docker) + SLZB-06M Zigbee coordinator connected via PoE.

According to Z2M, I am running 2.08 on the two Blue switches I have paired up. Each time I try to do the “Update device firmware” in the OTA menu, it ends abruptly (very early on, mind you) with something like this (from the Z2M log file):

debug 2024-02-04 23:14:35: OTA: Payload offsets: start=16200 end=16250 dataSize=50
debug 2024-02-04 23:14:35: OTA: Request offsets: fileOffset=16250 pageOffset=0 dataSize=63
debug 2024-02-04 23:14:35: OTA: Payload offsets: start=16250 end=16300 dataSize=50
debug 2024-02-04 23:14:35: OTA: Request offsets: fileOffset=16300 pageOffset=0 dataSize=63
debug 2024-02-04 23:14:35: OTA: Payload offsets: start=16300 end=16350 dataSize=50
debug 2024-02-04 23:14:35: OTA: Request offsets: fileOffset=16350 pageOffset=0 dataSize=63
debug 2024-02-04 23:14:35: OTA: Payload offsets: start=16350 end=16400 dataSize=50
debug 2024-02-04 23:14:36: OTA: Request offsets: fileOffset=16400 pageOffset=0 dataSize=63
debug 2024-02-04 23:14:36: OTA: Payload offsets: start=16400 end=16450 dataSize=50
debug 2024-02-04 23:14:36: OTA: Request offsets: fileOffset=16450 pageOffset=0 dataSize=63
debug 2024-02-04 23:14:36: OTA: Payload offsets: start=16450 end=16500 dataSize=50
debug 2024-02-04 23:14:36: Received MQTT message on 'zigbee2mqtt/bridge/request/options' with data '{"options":{"advanced":{"log_level":"error"}},"transaction":"ol1qx-2"}'
error 2024-02-04 23:15:15: Adapter disconnected, stopping
error 2024-02-04 23:15:15: Failed to stop Zigbee2MQTT

Then Z2M restarts itself. I’m happy to collect more debugs log; but I may need a little guidance on how to best go about that. While I’m green on some of the new things; I’m plenty proficient w/ Linux and Networking.

I would also like to add that I was doing an mtr/ping to the SLZB-06M Zigbee ethernet coordinator’s IP address (which btw, I set to STATIC based on reading some other woes w/ DHCP+reservation), and did not lose a single packet other than when I asked it to reboot itself.

I also think it’s worth noting that I have successfully updated the firmware on 6x Sengled E11-N1EA bulbs via this same setup without any hiccups worth noting. A couple times it failed to start; but then I started toggling the ON/OFF state shortly after requesting a firmware update and that seemed to help kick it into gear.

Oh, and after Z2M restarts itself after the failure case, it tends to get caught in a state where it thinks it is still updating that device; but really it is not. I’ve found that if I leave it be for some undetermined amount of time, it eventually times out and figures out that a firmware update is pending. Rinse and repeat.

What else may be of use to know? How can I help you help me :wink:

Oh, I DO have a Hubitat C-8. I have never paired the Inovelli switches to it. I was originally going to move to that Hub; but then I got a taste of Home Assistant and decided I was up for the challenge. I guess I COULD try pairing a switch to the Hubitat and try to do the firmware update via it… but ultimately, I need to make sure my new HA environment can perform this activity eventually.

My SLZB-06M selected Zigbee channel 11… according to its scan, it was one of two channels w/ the least amount of noise on it.

Thanks everyone. Also, should I open a support ticket on this? Or do those same people monitor this forum?

-Josh

What are the first four numbers of the ieee number of the switch? How big is your zigbee network? How close is the switch to another router? Has an update worked previously? SInce the coordinator is ethernet can you temporarily move it closer to the switch and try again?

What are the first four numbers of the ieee number of the switch?

IEEE starts with 0x94de… I had all of my “bad ones” replaced… 10 out of 10.

How close is the switch to another router? Has an update worked previously?

My ethernet coordinator is about 8 ft away from the two switches w/ a big antenna on it. There is two layers of drywall in between, though.

Has an update worked previously?

I’ve only ever had these paired to SmartThings (which is located in the same area, btw) and last I heard SmartThings can’t do firmware updates on these switches, I have therefore never tried a firmware update on the Blue switches previously. However, the same setup seems to send firmware updates to my Sengled E11-N1EA’s which are a bit (2-4 meters) FURTHER from the zigbee ethernet coordinator.

SInce the coordinator is ethernet can you temporarily move it closer to the switch and try again?

I COULD, in theory; but I feel like ~8ft should be close enough, ya know?

I just tried the firmware update from HomeAssistant instead of clicking the button in Z2M. I felt like it made it further that time; but then it still aborted slightly after 34.54%. I put more logs in from this one below in case there are hints in there.

I looked at my zigbee ethernet coordinator dashboard, and it showed the coordinator stayed “up”, but the Z2M integration recycled when the firmware stopped. Which makes sense, since Z2M restarted.

debug 2024-02-05 12:07:18: OTA: Update at 34.54%, remaining 1087.571149863143 seconds
info  2024-02-05 12:07:18: Update of 'Media Room Middle Switch' at 34.54%, ≈ 18 minutes remaining
info  2024-02-05 12:07:18: MQTT publish: topic 'zigbee2mqtt/Media Room Middle Switch', payload '{"action":null,"activeEnergyReports":null,"activePowerReports":null,"autoTimerOff":null,"auxSwitchUniqueScenes":null,"bindingOffToOnSyncLevel":null,"brightness":254,"brightnessLevelForDoubleTapDown":null,"brightnessLevelForDoubleTapUp":null,"buttonDelay":null,"defaultLed1ColorWhenOff":null,"defaultLed1ColorWhenOn":null,"defaultLed1IntensityWhenOff":null,"defaultLed1IntensityWhenOn":null,"defaultLed2ColorWhenOff":null,"defaultLed2ColorWhenOn":null,"defaultLed2IntensityWhenOff":null,"defaultLed2IntensityWhenOn":null,"defaultLed3ColorWhenOff":null,"defaultLed3ColorWhenOn":null,"defaultLed3IntensityWhenOff":null,"defaultLed3IntensityWhenOn":null,"defaultLed4ColorWhenOff":null,"defaultLed4ColorWhenOn":null,"defaultLed4IntensityWhenOff":null,"defaultLed4IntensityWhenOn":null,"defaultLed5ColorWhenOff":null,"defaultLed5ColorWhenOn":null,"defaultLed5IntensityWhenOff":null,"defaultLed5IntensityWhenOn":null,"defaultLed6ColorWhenOff":null,"defaultLed6ColorWhenOn":null,"defaultLed6IntensityWhenOff":null,"defaultLed6IntensityWhenOn":null,"defaultLed7ColorWhenOff":null,"defaultLed7ColorWhenOn":null,"defaultLed7IntensityWhenOff":null,"defaultLed7IntensityWhenOn":null,"defaultLevelLocal":null,"defaultLevelRemote":null,"deviceBindNumber":null,"dimmingSpeedDownLocal":null,"dimmingSpeedDownRemote":null,"dimmingSpeedUpLocal":null,"dimmingSpeedUpRemote":null,"doubleTapClearNotifications":null,"doubleTapDownToParam56":null,"doubleTapUpToParam55":null,"energy":43.47,"firmwareUpdateInProgressIndicator":null,"higherOutputInNonNeutral":null,"individual_led_effect":null,"internalTemperature":null,"invertSwitch":null,"ledBarScaling":null,"ledColorWhenOff":null,"ledColorWhenOn":null,"ledIntensityWhenOff":null,"ledIntensityWhenOn":null,"led_effect":null,"linkquality":164,"loadLevelIndicatorTimeout":null,"localProtection":null,"maximumLevel":null,"minimumLevel":null,"onOffLedMode":null,"outputMode":null,"overheat":null,"periodicPowerAndEnergyReports":null,"power":20.2,"powerType":null,"rampRateOffToOnLocal":null,"rampRateOffToOnRemote":127,"rampRateOnToOffLocal":null,"rampRateOnToOffRemote":127,"relayClick":null,"remoteProtection":null,"smartBulbMode":null,"state":"ON","stateAfterPowerRestored":null,"switchType":null,"update":{"installed_version":16908808,"latest_version":16908815,"progress":34.54,"remaining":1088,"state":"updating"},"update_available":null}'
debug 2024-02-05 12:07:18: OTA: Request offsets: fileOffset=106000 pageOffset=0 dataSize=63
debug 2024-02-05 12:07:18: OTA: Payload offsets: start=106000 end=106050 dataSize=50
debug 2024-02-05 12:07:18: OTA: Request offsets: fileOffset=106050 pageOffset=0 dataSize=63
debug 2024-02-05 12:07:18: OTA: Payload offsets: start=106050 end=106100 dataSize=50
debug 2024-02-05 12:07:19: OTA: Request offsets: fileOffset=106100 pageOffset=0 dataSize=63
debug 2024-02-05 12:07:19: OTA: Payload offsets: start=106100 end=106150 dataSize=50
debug 2024-02-05 12:07:19: OTA: Request offsets: fileOffset=106150 pageOffset=0 dataSize=63
debug 2024-02-05 12:07:19: OTA: Payload offsets: start=106150 end=106200 dataSize=50
debug 2024-02-05 12:07:19: OTA: Request offsets: fileOffset=106200 pageOffset=0 dataSize=63
debug 2024-02-05 12:07:19: OTA: Payload offsets: start=106200 end=106250 dataSize=50
debug 2024-02-05 12:07:19: OTA: Request offsets: fileOffset=106250 pageOffset=0 dataSize=63
debug 2024-02-05 12:07:19: OTA: Payload offsets: start=106250 end=106300 dataSize=50
debug 2024-02-05 12:07:19: Received Zigbee message from 'Media Room Middle Switch', type 'attributeReport', cluster 'seMetering', data '{"currentSummDelivered":[0,4348]}' from endpoint 1 with groupID 0
info  2024-02-05 12:07:19: MQTT publish: topic 'zigbee2mqtt/Media Room Middle Switch', payload '{"action":null,"activeEnergyReports":null,"activePowerReports":null,"autoTimerOff":null,"auxSwitchUniqueScenes":null,"bindingOffToOnSyncLevel":null,"brightness":254,"brightnessLevelForDoubleTapDown":null,"brightnessLevelForDoubleTapUp":null,"buttonDelay":null,"defaultLed1ColorWhenOff":null,"defaultLed1ColorWhenOn":null,"defaultLed1IntensityWhenOff":null,"defaultLed1IntensityWhenOn":null,"defaultLed2ColorWhenOff":null,"defaultLed2ColorWhenOn":null,"defaultLed2IntensityWhenOff":null,"defaultLed2IntensityWhenOn":null,"defaultLed3ColorWhenOff":null,"defaultLed3ColorWhenOn":null,"defaultLed3IntensityWhenOff":null,"defaultLed3IntensityWhenOn":null,"defaultLed4ColorWhenOff":null,"defaultLed4ColorWhenOn":null,"defaultLed4IntensityWhenOff":null,"defaultLed4IntensityWhenOn":null,"defaultLed5ColorWhenOff":null,"defaultLed5ColorWhenOn":null,"defaultLed5IntensityWhenOff":null,"defaultLed5IntensityWhenOn":null,"defaultLed6ColorWhenOff":null,"defaultLed6ColorWhenOn":null,"defaultLed6IntensityWhenOff":null,"defaultLed6IntensityWhenOn":null,"defaultLed7ColorWhenOff":null,"defaultLed7ColorWhenOn":null,"defaultLed7IntensityWhenOff":null,"defaultLed7IntensityWhenOn":null,"defaultLevelLocal":null,"defaultLevelRemote":null,"deviceBindNumber":null,"dimmingSpeedDownLocal":null,"dimmingSpeedDownRemote":null,"dimmingSpeedUpLocal":null,"dimmingSpeedUpRemote":null,"doubleTapClearNotifications":null,"doubleTapDownToParam56":null,"doubleTapUpToParam55":null,"energy":43.48,"firmwareUpdateInProgressIndicator":null,"higherOutputInNonNeutral":null,"individual_led_effect":null,"internalTemperature":null,"invertSwitch":null,"ledBarScaling":null,"ledColorWhenOff":null,"ledColorWhenOn":null,"ledIntensityWhenOff":null,"ledIntensityWhenOn":null,"led_effect":null,"linkquality":148,"loadLevelIndicatorTimeout":null,"localProtection":null,"maximumLevel":null,"minimumLevel":null,"onOffLedMode":null,"outputMode":null,"overheat":null,"periodicPowerAndEnergyReports":null,"power":20.2,"powerType":null,"rampRateOffToOnLocal":null,"rampRateOffToOnRemote":127,"rampRateOnToOffLocal":null,"rampRateOnToOffRemote":127,"relayClick":null,"remoteProtection":null,"smartBulbMode":null,"state":"ON","stateAfterPowerRestored":null,"switchType":null,"update":{"installed_version":16908808,"latest_version":16908815,"progress":34.54,"remaining":1088,"state":"updating"},"update_available":null}'
debug 2024-02-05 12:07:19: Received Zigbee message from 'Media Room Middle Switch', type 'attributeReport', cluster 'seMetering', data '{"currentSummDelivered":[0,4348]}' from endpoint 1 with groupID 1
debug 2024-02-05 12:07:19: Received Zigbee message from 'Media Room Middle Switch', type 'attributeReport', cluster 'haElectricalMeasurement', data '{"activePower":201}' from endpoint 1 with groupID 0
info  2024-02-05 12:07:19: MQTT publish: topic 'zigbee2mqtt/Media Room Middle Switch', payload '{"action":null,"activeEnergyReports":null,"activePowerReports":null,"autoTimerOff":null,"auxSwitchUniqueScenes":null,"bindingOffToOnSyncLevel":null,"brightness":254,"brightnessLevelForDoubleTapDown":null,"brightnessLevelForDoubleTapUp":null,"buttonDelay":null,"defaultLed1ColorWhenOff":null,"defaultLed1ColorWhenOn":null,"defaultLed1IntensityWhenOff":null,"defaultLed1IntensityWhenOn":null,"defaultLed2ColorWhenOff":null,"defaultLed2ColorWhenOn":null,"defaultLed2IntensityWhenOff":null,"defaultLed2IntensityWhenOn":null,"defaultLed3ColorWhenOff":null,"defaultLed3ColorWhenOn":null,"defaultLed3IntensityWhenOff":null,"defaultLed3IntensityWhenOn":null,"defaultLed4ColorWhenOff":null,"defaultLed4ColorWhenOn":null,"defaultLed4IntensityWhenOff":null,"defaultLed4IntensityWhenOn":null,"defaultLed5ColorWhenOff":null,"defaultLed5ColorWhenOn":null,"defaultLed5IntensityWhenOff":null,"defaultLed5IntensityWhenOn":null,"defaultLed6ColorWhenOff":null,"defaultLed6ColorWhenOn":null,"defaultLed6IntensityWhenOff":null,"defaultLed6IntensityWhenOn":null,"defaultLed7ColorWhenOff":null,"defaultLed7ColorWhenOn":null,"defaultLed7IntensityWhenOff":null,"defaultLed7IntensityWhenOn":null,"defaultLevelLocal":null,"defaultLevelRemote":null,"deviceBindNumber":null,"dimmingSpeedDownLocal":null,"dimmingSpeedDownRemote":null,"dimmingSpeedUpLocal":null,"dimmingSpeedUpRemote":null,"doubleTapClearNotifications":null,"doubleTapDownToParam56":null,"doubleTapUpToParam55":null,"energy":43.48,"firmwareUpdateInProgressIndicator":null,"higherOutputInNonNeutral":null,"individual_led_effect":null,"internalTemperature":null,"invertSwitch":null,"ledBarScaling":null,"ledColorWhenOff":null,"ledColorWhenOn":null,"ledIntensityWhenOff":null,"ledIntensityWhenOn":null,"led_effect":null,"linkquality":148,"loadLevelIndicatorTimeout":null,"localProtection":null,"maximumLevel":null,"minimumLevel":null,"onOffLedMode":null,"outputMode":null,"overheat":null,"periodicPowerAndEnergyReports":null,"power":20.1,"powerType":null,"rampRateOffToOnLocal":null,"rampRateOffToOnRemote":127,"rampRateOnToOffLocal":null,"rampRateOnToOffRemote":127,"relayClick":null,"remoteProtection":null,"smartBulbMode":null,"state":"ON","stateAfterPowerRestored":null,"switchType":null,"update":{"installed_version":16908808,"latest_version":16908815,"progress":34.54,"remaining":1088,"state":"updating"},"update_available":null}'
debug 2024-02-05 12:07:19: Received Zigbee message from 'Media Room Middle Switch', type 'attributeReport', cluster 'haElectricalMeasurement', data '{"activePower":201}' from endpoint 1 with groupID 1
debug 2024-02-05 12:07:20: OTA: Request offsets: fileOffset=106300 pageOffset=0 dataSize=63
debug 2024-02-05 12:07:20: OTA: Payload offsets: start=106300 end=106350 dataSize=50
debug 2024-02-05 12:07:20: OTA: Request offsets: fileOffset=106350 pageOffset=0 dataSize=63
debug 2024-02-05 12:07:20: OTA: Payload offsets: start=106350 end=106400 dataSize=50
debug 2024-02-05 12:07:20: OTA: Request offsets: fileOffset=106400 pageOffset=0 dataSize=63
debug 2024-02-05 12:07:20: OTA: Payload offsets: start=106400 end=106450 dataSize=50
debug 2024-02-05 12:07:20: OTA: Request offsets: fileOffset=106450 pageOffset=0 dataSize=63
debug 2024-02-05 12:07:20: OTA: Payload offsets: start=106450 end=106500 dataSize=50
debug 2024-02-05 12:07:21: OTA: Request offsets: fileOffset=106500 pageOffset=0 dataSize=63
debug 2024-02-05 12:07:21: OTA: Payload offsets: start=106500 end=106550 dataSize=50
debug 2024-02-05 12:07:21: OTA: Request offsets: fileOffset=106550 pageOffset=0 dataSize=63
debug 2024-02-05 12:07:21: OTA: Payload offsets: start=106550 end=106600 dataSize=50
debug 2024-02-05 12:07:21: OTA: Request offsets: fileOffset=106600 pageOffset=0 dataSize=63
debug 2024-02-05 12:07:21: OTA: Payload offsets: start=106600 end=106650 dataSize=50
debug 2024-02-05 12:07:22: OTA: Request offsets: fileOffset=106650 pageOffset=0 dataSize=63
debug 2024-02-05 12:07:22: OTA: Payload offsets: start=106650 end=106700 dataSize=50
debug 2024-02-05 12:07:22: OTA: Request offsets: fileOffset=106700 pageOffset=0 dataSize=63
debug 2024-02-05 12:07:22: OTA: Payload offsets: start=106700 end=106750 dataSize=50
debug 2024-02-05 12:07:22: OTA: Request offsets: fileOffset=106750 pageOffset=0 dataSize=63
debug 2024-02-05 12:07:22: OTA: Payload offsets: start=106750 end=106800 dataSize=50
debug 2024-02-05 12:07:22: OTA: Request offsets: fileOffset=106800 pageOffset=0 dataSize=63
debug 2024-02-05 12:07:22: OTA: Payload offsets: start=106800 end=106850 dataSize=50
debug 2024-02-05 12:07:23: Received Zigbee message from 'Media Room Mid-Front-Right Bulb', type 'commandQueryNextImageRequest', cluster 'genOta', data '{"fieldControl":0,"fileVersion":71,"imageType":1004,"manufacturerCode":4448}' from endpoint 1 with groupID 0
debug 2024-02-05 12:07:23: Device 'Media Room Mid-Front-Right Bulb' requested OTA
debug 2024-02-05 12:07:24: Received Zigbee message from 'Media Room Rear-Right Bulb', type 'attributeReport', cluster 'seMetering', data '{"currentSummDelivered":[0,2599]}' from endpoint 1 with groupID 0
info  2024-02-05 12:07:24: MQTT publish: topic 'zigbee2mqtt/Media Room Rear-Right Bulb', payload '{"brightness":254,"color":{"x":0.3137,"y":0.3238},"color_mode":"color_temp","color_temp":154,"energy":0.26,"linkquality":152,"power":6.5,"state":"ON","update":{"installed_version":71,"latest_version":71,"state":"idle"},"update_available":null}'
debug 2024-02-05 12:07:25: Received Zigbee message from 'Media Room Mid-Front-Right Bulb', type 'commandQueryNextImageRequest', cluster 'genOta', data '{"fieldControl":0,"fileVersion":71,"imageType":1004,"manufacturerCode":4448}' from endpoint 1 with groupID 0
debug 2024-02-05 12:07:25: Device 'Media Room Mid-Front-Right Bulb' requested OTA
debug 2024-02-05 12:07:26: Received Zigbee message from 'Media Room Mid-Back-Left Bulb', type 'attributeReport', cluster 'seMetering', data '{"currentSummDelivered":[0,647067]}' from endpoint 1 with groupID 0
info  2024-02-05 12:07:26: MQTT publish: topic 'zigbee2mqtt/Media Room Mid-Back-Left Bulb', payload '{"brightness":254,"color":{"x":0.3137,"y":0.3238},"color_mode":"color_temp","color_temp":154,"energy":64.71,"linkquality":156,"power":6.5,"state":"ON","update":{"installed_version":71,"latest_version":71,"state":"idle"},"update_available":null}'
debug 2024-02-05 12:07:27: OTA: Image block response failed (CommandResponse 0x70ac08fffe7346d3/1 genOta.imageBlockResponse({"status":0,"manufacturerCode":4655,"imageType":257,"fileVersion":16908815,"fileOffset":106800,"dataSize":50,"data":{"type":"Buffer","data":[254,186,182,201,22,176,243,83,183,27,200,120,4,249,28,36,61,71,48,170,64,162,110,141,244,145,114,248,82,193,102,98,141,183,236,135,6,124,18,16,5,160,34,178,60,76,175,184,19,0]}}, {"timeout":10000,"disableResponse":false,"disableRecovery":false,"disableDefaultResponse":true,"direction":1,"srcEndpoint":null,"reservedBits":0,"manufacturerCode":null,"transactionSequenceNumber":null,"writeUndiv":false}) failed (sendZclFrameToEndpointInternal error))
error 2024-02-05 12:07:27: Adapter disconnected, stopping
debug 2024-02-05 12:07:27: Saving state to file /app/data/state.json
info  2024-02-05 12:07:27: MQTT publish: topic 'zigbee2mqtt/bridge/state', payload '{"state":"offline"}'
info  2024-02-05 12:07:27: Disconnecting from MQTT server
info  2024-02-05 12:07:27: Stopping zigbee-herdsman...
error 2024-02-05 12:07:27: Failed to stop Zigbee2MQTT

I missed this one. Currently, this zigbee network consists of the ethernet coordinator, and 6 Sengled bulbs (which are end point devices), and these two Inovelli blue switches… all of that is in the same room, which is across the hall from the coordinator.

I do have Smartthings zigbee and zwave networks with quite a few other devices and other Inovelli blue switches, etc. I’m not sure what channel those are on, nor how to tell in the SmartThings world. Would those be relevant to this issue?

Great. Just making sure before we dive too deep.

That should be close enough.

Agreed.

Overall it looks like it should work. It might be worth dusting off the C8 to see if it makes a difference. I know I had one switch the refused to OTA with Z2M and I had to manually flash a new bootloader.

I tried another update via HA…

It failed in under a minute after 3.63% message.

But what I wanted to add here is that the lights on that switch flicker fast at the start of the update and about a minute or so after it fails.

What does the last line mean in the log? It sure doesn’t seem like it failed to stop Z2M, as the log file restarted, etc.

error 2024-02-05 13:37:22: Adapter disconnected, stopping
debug 2024-02-05 13:37:22: Saving state to file /app/data/state.json
info  2024-02-05 13:37:22: MQTT publish: topic 'zigbee2mqtt/bridge/state', payload '{"state":"offline"}'
info  2024-02-05 13:37:23: Disconnecting from MQTT server
info  2024-02-05 13:37:23: Stopping zigbee-herdsman...
error 2024-02-05 13:37:23: Failed to stop Zigbee2MQTT

Strange. I haven’t seen that error before. A google shows you’re not the only one.

Quick progress update… I found this issue that someone else posted and downgraded my Z2M version and presto, the blue switch updated without issue.

So, it looks to be a Z2M issue. Yay!

1 Like