Zigbee OTA Firmware Provider

NilsOF · May 26, 2020, 8:18am

Looking closer at the Ikea firmwares:
As far as I can tell there is a complete “standard” zigbee ota inside each of the downloads. Splitting out the relevant part should be trivial.
(I wrote a crude python script just for a peek inside the downloaded firmware files )

However:
“modelId” from the rest api (visible in Paperui) do not match with any names I can find in the firmwarefiles or the json.
One must take a guess.

Is it possible to expose this firmware ID thru the rest API (or in xml)?
This firmware-id is found both in the firmware OTA files (in the OTA header) and in the Ikea jsonfile.
A firmware downloader for Ikea devices would then be much easier to write.

Not quite a wildcard, but I believe other vendors do use the same firmware in several products as well (which differs only in socket or LED configuration)

chris · May 26, 2020, 8:35am

No - this isn’t available in the device. The device will make a request with the firmware ID - it may request multiple firmwares if it likes and as far as I know there’s no way to ask a device what firmware ID(s) it will ask for.

This is clearly manufacturer specific - others I know (eg Osram) clearly have different firmware for every device.

izzy84075 · June 4, 2020, 3:40am

Two months later… Sorry, life got crazy and I just got back to poking at this.

I’m not quite sure which logs you’re wanting, but I spent a while turning various things on and off and wasn’t able to get anything more insightful than what was in that other snippet.

I have a log that had the com.zsmartsystems.zigbee debug log on for the end of the upgrade, and it has the raw messages for that bit, but having that turned on for the entire thing seems to make something crash or lock up. The error itself is the only WARN in the file, so easy to find that part.

If there’s something more specific you’d like logs of, I’m afraid I’ll need a bit more guidance.

NilsOF · June 7, 2020, 8:44pm

I think I see the same as @izzy84075
In my case trying to upgrade a Ikea “control outlet” (wall plug) from 2.0.022 to 2.0.024.

2020-06-07 22:09:44.097 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - <-- RX ASH frame: AshFrameData [frmNum=7, ackNum=1, reTx=false, data=58 90 45 00 04 01 19 00 01 01 40 00 00 00 30 FF C3 24 B0 FF FF 0C 01 23 06 00 7C 11 01 11 23 46 02 20 02]
2020-06-07 22:09:44.097 [DEBUG] [zigbee.dongle.ember.ZigBeeDongleEzsp] - RX EZSP: EzspIncomingMessageHandler [networkId=0, type=EMBER_INCOMING_UNICAST, apsFrame=EmberApsFrame [profileId=0104, clusterId=0019, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_RETRY], groupId=0, sequence=30], lastHo$
2020-06-07 22:09:44.098 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX APS: ZigBeeApsFrame [sourceAddress=B024/1, destinationAddress=0000/1, profile=0104, cluster=0019, addressMode=DEVICE, radius=0, apsSecurity=false, ackRequest=false, apsCounter=30, rssi=-61, lqi=FF, payload=01 23 06 00 7C 11 01 11 23 46 02$
2020-06-07 22:09:44.098 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX ZCL: ZclHeader [frameType=CLUSTER_SPECIFIC_COMMAND, manufacturerSpecific=false, direction=CLIENT_TO_SERVER, disableDefaultResponse=false, manufacturerCode=0, sequenceNumber=35, commandId=6]
2020-06-07 22:09:44.098 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - RX CMD: UpgradeEndCommand [Ota Upgrade: B024/1 -> 0000/1, cluster=0019, TID=23, status=SUCCESS, manufacturerCode=4476, imageType=4353, fileVersion=537019939]
2020-06-07 22:09:44.098 [DEBUG] [transaction.ZigBeeTransactionManager] - notifyTransactionCommand: UpgradeEndCommand [Ota Upgrade: B024/1 -> 0000/1, cluster=0019, TID=23, status=SUCCESS, manufacturerCode=4476, imageType=4353, fileVersion=537019939]
2020-06-07 22:09:44.098 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - --> TX ASH frame: AshFrameAck [ackNum=0, notRdy=false]
2020-06-07 22:09:44.098 [DEBUG] [ee.app.otaserver.ZclOtaUpgradeServer] - B024/1 OTA Error: Invalid server state OTA_WAITING when handling UpgradeEndCommand.
2020-06-07 22:09:44.099 [DEBUG] [e.transaction.ZigBeeTransactionQueue] - 086BD7FFFE1AFDDC: Added transaction to queue, len=1, transaction=ZigBeeTransaction [ieeeAddress=086BD7FFFE1AFDDC queueTime=0, state=WAITING, sendCnt=0, command=DefaultResponse [Ota Upgrade: 0000/0 -> B024/1, cluster=0019, TID=23, commandIden$
2020-06-07 22:09:44.099 [DEBUG] [transaction.ZigBeeTransactionManager] - B024/1: Sending ZigBeeTransaction [ieeeAddress=086BD7FFFE1AFDDC queueTime=0, state=WAITING, sendCnt=0, command=DefaultResponse [Ota Upgrade: 0000/0 -> B024/1, cluster=0019, TID=23, commandIdentifier=6, statusCode=UNKNOWN]]
2020-06-07 22:09:44.099 [DEBUG] [transaction.ZigBeeTransactionManager] - transactionListenerAdded: 1 outstanding
2020-06-07 22:09:44.099 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX CMD: DefaultResponse [Ota Upgrade: 0000/0 -> B024/1, cluster=0019, TID=23, commandIdentifier=6, statusCode=UNKNOWN]
2020-06-07 22:09:44.100 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX ZCL: ZclHeader [frameType=ENTIRE_PROFILE_COMMAND, manufacturerSpecific=false, direction=SERVER_TO_CLIENT, disableDefaultResponse=true, manufacturerCode=0, sequenceNumber=35, commandId=11]
2020-06-07 22:09:44.100 [DEBUG] [tsystems.zigbee.ZigBeeNetworkManager] - TX APS: ZigBeeApsFrame [sourceAddress=0000/1, destinationAddress=B024/1, profile=0104, cluster=0019, addressMode=DEVICE, radius=31, apsSecurity=false, ackRequest=true, apsCounter=4A, rssi=--, lqi=--, payload=18 23 0B 06 FF]
2020-06-07 22:09:44.100 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - TX EZSP: EzspSendUnicastRequest [networkId=0, type=EMBER_OUTGOING_DIRECT, indexOrDestination=B024, apsFrame=EmberApsFrame [profileId=0104, clusterId=0019, sourceEndpoint=1, destinationEndpoint=1, options=[EMBER_APS_OPTION_RETRY, EMBER_APS_OP$
2020-06-07 22:09:44.100 [DEBUG] [e.ember.internal.ash.AshFrameHandler] - ASH: TX EZSP queue size: 1

The new firmware never “activate” so the wall plug stay at firmware version 2.0.022

shorty707 · June 19, 2020, 10:35pm

I get the following when I try to update the firmware.

00:33:27.188 [DEBUG] [bee.app.otaserver.ZclOtaUpgradeServer] - 4801/3 OTA status updated to OTA_WAITING.
00:33:27.189 [WARN ] [.zsmartsystems.zigbee.ZigBeeExecutors] - Uncaught exception in thread NotificationService-thread-1219
java.lang.IllegalStateException: Update is finished.
	at org.eclipse.smarthome.core.thing.internal.firmware.ProgressCallbackImpl.next(ProgressCallbackImpl.java:101) ~[?:?]
	at org.openhab.binding.zigbee.handler.ZigBeeThingHandler$4.otaStatusUpdate(ZigBeeThingHandler.java:958) ~[?:?]
	at com.zsmartsystems.zigbee.app.otaserver.ZclOtaUpgradeServer$2.run(ZclOtaUpgradeServer.java:517) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:1.8.0_191]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:1.8.0_191]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_191]
00:33:27.190 [WARN ] [.zsmartsystems.zigbee.ZigBeeExecutors] - Uncaught exception in thread NotificationService-thread-1221
java.lang.IllegalStateException: Update is finished.
	at org.eclipse.smarthome.core.thing.internal.firmware.ProgressCallbackImpl.next(ProgressCallbackImpl.java:101) ~[?:?]
	at org.openhab.binding.zigbee.handler.ZigBeeThingHandler$4.otaStatusUpdate(ZigBeeThingHandler.java:958) ~[?:?]
	at com.zsmartsystems.zigbee.app.otaserver.ZclOtaUpgradeServer$2.run(ZclOtaUpgradeServer.java:517) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:1.8.0_191]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:1.8.0_191]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_191]
00:33:27.190 [INFO ] [event.FirmwareUpdateProgressInfoEvent] - The firmware update progress for thing zigbee:device:c890ebfb:7cb03eaa00acf5af changed. Step: TRANSFERRING Progress: null.
00:33:27.198 [INFO ] [event.FirmwareUpdateProgressInfoEvent] - The firmware update progress for thing zigbee:device:c890ebfb:7cb03eaa00acf5af changed. Step: REBOOTING Progress: 0.
00:33:27.189 [WARN ] [.zsmartsystems.zigbee.ZigBeeExecutors] - Uncaught exception in thread NotificationService-thread-1222
java.lang.IllegalStateException: Update is finished.
	at org.eclipse.smarthome.core.thing.internal.firmware.ProgressCallbackImpl.next(ProgressCallbackImpl.java:101) ~[?:?]
	at org.openhab.binding.zigbee.handler.ZigBeeThingHandler$4.otaStatusUpdate(ZigBeeThingHandler.java:958) ~[?:?]
	at com.zsmartsystems.zigbee.app.otaserver.ZclOtaUpgradeServer$2.run(ZclOtaUpgradeServer.java:517) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:1.8.0_191]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:1.8.0_191]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_191]
00:33:27.196 [WARN ] [.zsmartsystems.zigbee.ZigBeeExecutors] - Uncaught exception in thread NotificationService-thread-1224
java.lang.IllegalStateException: Update is finished.
	at org.eclipse.smarthome.core.thing.internal.firmware.ProgressCallbackImpl.next(ProgressCallbackImpl.java:101) ~[?:?]
	at org.openhab.binding.zigbee.handler.ZigBeeThingHandler$4.otaStatusUpdate(ZigBeeThingHandler.java:958) ~[?:?]
	at com.zsmartsystems.zigbee.app.otaserver.ZclOtaUpgradeServer$2.run(ZclOtaUpgradeServer.java:517) ~[?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:1.8.0_191]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:1.8.0_191]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_191]

shorty707 · June 20, 2020, 3:46pm

I started over and resetted the stick. Just added the 1 plug I wanted to firmware update.
Now getting this:

17:42:08.968 [ERROR] [rnal.common.AbstractInvocationHandler] - An error occurred while calling method 'FirmwareUpdateHandler.updateFirmware()' on 'org.openhab.binding.zigbee.handler.ZigBeeThingHandler@58a630be': null
java.lang.NullPointerException: null
	at org.openhab.binding.zigbee.handler.ZigBeeThingHandler.updateFirmware(ZigBeeThingHandler.java:906) ~[?:?]
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_191]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:1.8.0_191]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_191]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_191]
	at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:152) [bundleFile:?]
	at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:52) [bundleFile:?]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_191]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_191]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_191]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_191]
17:42:08.972 [ERROR] [al.firmware.FirmwareUpdateServiceImpl] - Unexpected exception occurred for firmware update of thing with UID zigbee:device:c890ebfb:7cb03eaa00acf5af and firmware FirmwareImpl [thingTypeUID=zigbee:device, vendor=OSRAM, model=Plug 01, modelRestricted=false, description=null, version=0x01020509, prerequisiteVersion=null, changelog=null, onlineChangelog=null, md5Hash=null, properties={}].

chris · June 20, 2020, 4:16pm

@shorty707 if you are expecting anyone to offer suggestions on what might be wrong, I would suggest to post more information - it’s pretty much impossible to know what is wrong with next to nothing to go on.

shorty707 · June 20, 2020, 4:28pm

well there is not much more that I would be aware of.

My Binding version is 2.5.5 Release Build, the firmwareproviderjar is the 1.0.2 from above in this thread, coordinator a xbee zstick 2 ZB. The device is a Osram Plug 01.
As per your documentation in this thread I created the xml and and together with the ota file from the ledvance page for the plug 01 I zipped it and put it in the firmware folder.

It is shown also on the UI like in your example above… however Instantly after I click Install I get an “Update failed” on the UI and the above exception in the log.

In the UI it shows:

Anything I could log more to help shed light on it?

best

chris · June 20, 2020, 4:39pm

What about log files for starters? That might help - the error itself is not very useful without knowing what is happening to give it some context

Bruce_Osborne · June 20, 2020, 5:02pm

Become aware of the binding documentation. Hint: How about the section when things do not go as expected?

shorty707 · June 20, 2020, 5:25pm

I did actually post a debug above. The documentation does not even mention the bindings capability of device firmware updates.

I put everything I am aware of now into debug again.

log:set debug org.openhab.binding.zigbee
log:set debug com.zsmartsystems.zigbee
log:set info com.zsmartsystems.zigbee.dongle.xbee.internal.ash
log:set debug com.zsmartsystems.zigbee.app.otaserver.ZclOtaUpgradeServer

this is the full output when I click “Install”:

19:21:17.944 [DEBUG] [ing.zigbee.handler.ZigBeeThingHandler] - null: Update firmware with 0x01020509
19:21:17.946 [ERROR] [rnal.common.AbstractInvocationHandler] - An error occurred while calling method 'FirmwareUpdateHandler.updateFirmware()' on 'org.openhab.binding.zigbee.handler.ZigBeeThingHandler@58a630be': null
java.lang.NullPointerException: null
	at org.openhab.binding.zigbee.handler.ZigBeeThingHandler.updateFirmware(ZigBeeThingHandler.java:906) ~[?:?]
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_191]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:1.8.0_191]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_191]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_191]
	at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:152) [bundleFile:?]
	at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:52) [bundleFile:?]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_191]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_191]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_191]
	at java.lang.Thread.run(Thread.java:748) [?:1.8.0_191]
19:21:17.949 [ERROR] [al.firmware.FirmwareUpdateServiceImpl] - Unexpected exception occurred for firmware update of thing with UID zigbee:device:c890ebfb:7cb03eaa00acf5af and firmware FirmwareImpl [thingTypeUID=zigbee:device, vendor=OSRAM, model=Plug 01, modelRestricted=false, description=null, version=0x01020509, prerequisiteVersion=null, changelog=null, onlineChangelog=null, md5Hash=null, properties={}].

chris · June 20, 2020, 5:30pm

Sorry for missing this - it was only 1 line long and I would have expected a lot more than 1 line.

I think Bruce is talking about the documentation section about debug logs.

I’m very surprised that there is only two lines printed. Unfortunately I can’t really comment further.

chris · June 20, 2020, 5:31pm

@shorty what file are you trying to load? Are you sure you have created it correctly?

shorty707 · June 20, 2020, 5:54pm

its this from the ledvance/osram webpage for the PLUG 01:

zipped with the xml

thats my xml

addtionally. this is the properties from the device I want to update:

chris · June 20, 2020, 7:07pm

Without a larger debug log I really can’t work out what is going on. It looks like some sort of configuration problem, but there’s simply too little information to go on.

Bruce_Osborne · June 20, 2020, 7:16pm

Perhaps the documentation should be nodified to say UNFILTERED debug logs are useful for troubleshooting.

shorty707 · June 23, 2020, 9:42am

I switched now to a Ember Controller (Bitron).
Now the update does work. So it was related to the xbee controller.

I will rebuild now my network and see if also the other issues are gone I had.

chris · July 18, 2020, 12:25pm

Please try with the latest binding as there was a fix made recently that may help with this OTA issue.

Bruce_Osborne · July 18, 2020, 12:45pm

@shorty707 It is usually easiest to use the install script.

Zigbee and Z-Wave manual install script - Tutorials & Examples - openHAB Community

Peter_Zachau · December 2, 2021, 2:06pm

Will there be support for OpenHab 3?
Firmwareprovider was added after building it from git. And Log seems to be ok:

2021-12-02 14:43:36.342 [INFO ] [penhab.event.FirmwareStatusInfoEvent] - Firmware status of thing zigbee:device:01382AC2:7cb03eaa00b09e1c changed to UPDATE_EXECUTABLE.The new updatable firmware version is 0x01020509.

But, if i look at the Think i have not the shown line. No Info about currend Version and no update Button.