Possibly a problem with OTA upgrades

[einalex]

Describe the bug On running an OTA upgrade,

openhab> zigbee otaupgrade start 33352/1 minil2_100E.ota
OTA File "minil2_100E.ota" set for node 8248/1
OTA File: ZigBeeOtaFile [headerVersion=256, headerLength=56, manufacturerCode=4742, imageType=0004, fileVersion=0000100E, stackVersion=ZIGBEE_PRO, headerString=ota-file-test, imageSize=259018]

the following error occurs.

15:53:04.851 [WARN ] [.zsmartsystems.zigbee.ZigBeeExecutors] - Uncaught exception in thread NotificationService-thread-2555
java.lang.NullPointerException: Cannot invoke "com.zsmartsystems.zigbee.app.otaserver.ZclOtaUpgradeServer.cancelUpgrade()" because "this.otaServer" is null
    at org.openhab.binding.zigbee.handler.ZigBeeThingHandler.otaStatusUpdate(ZigBeeThingHandler.java:1032) ~[?:?]
    at com.zsmartsystems.zigbee.app.otaserver.ZclOtaUpgradeServer$2.run(ZclOtaUpgradeServer.java:583) ~[?:?]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
    at java.lang.Thread.run(Thread.java:833) ~[?:?]

To Reproduce Steps to reproduce the behavior:

1. prepare for firmware upgrade (file in right location with correct permissions, know your parameters)
2. run command

Expected behavior OTA firmware upgrade succeeds.

Additional context

openhab 4.0.1 on debian bookworm arm64, raspi4b

zigbee hub: POPP ZB-Stick 2023/07/31 17:05:04 Elelabs_EzspFwUtility: Elelabs Zigbee adapter detected: 2023/07/31 17:05:04 Elelabs_EzspFwUtility: Adapter: ELR023 2023/07/31 17:05:04 Elelabs_EzspFwUtility: Firmware: 6.10.3-41 2023/07/31 17:05:04 Elelabs_EzspFwUtility: EZSP v8

Device in question is a SONOFF Mini-L2 Updating another one of these worked fine a couple of months ago on an x86 system running openhab 3.4.3 - I think.

It does have an upgrade cluster.

Output Clusters   : (Client)
   0019 Ota Upgrade
     - APS Security disabled
        S       0 r-- IEEE_ADDRESS              Upgrade Server ID                         
        S       1 r-- UNSIGNED_32_BIT_INTEGER   File Offset                               
        S       2 r-- UNSIGNED_32_BIT_INTEGER   Current File Version                     Sun May 28 11:17:16 UTC 2023 4106
        S       3 r-- UNSIGNED_16_BIT_INTEGER   Current ZigBee Stack Version              
        S       4 r-- UNSIGNED_32_BIT_INTEGER   Downloaded File Version                   
        S       5 r-- UNSIGNED_16_BIT_INTEGER   Downloaded ZigBee Stack Version           
        S       6 r-- ENUMERATION_8_BIT         Image Upgrade Status                     Sun May 28 11:54:15 UTC 2023 0
        S       7 r-- UNSIGNED_16_BIT_INTEGER   Manufacturer ID                           
        S       8 r-- UNSIGNED_16_BIT_INTEGER   Image Type ID                             
        S       9 r-- UNSIGNED_16_BIT_INTEGER   Minimum Block Request Period              
        S      10 r-- UNSIGNED_32_BIT_INTEGER   Image Stamp                               
        S   65533 r-- UNSIGNED_16_BIT_INTEGER   Cluster Revision                          
        S   65534 r-- ENUMERATION_16_BIT        Attribute Reporting Status    

[cdjackson]

The OTA upgrade system does work, so there must be something specific to your OTA file, or device. Please provide in the first instance a debug log showing all the log entries leading up to this - just seeing the exception without debug logging to provide the context is not very useful

[einalex]

tried another file on another device:

openhab> zigbee otaupgrade start 32378/1 tapdial.ota
tapdial.ota" set for node 7E7A/1
OTA File: ZigBeeOtaFile [headerVersion=256, headerLength=56, manufacturerCode=4107, imageType=0121, fileVersion=02003B19, stackVersion=ZIGBEE_PRO, headerString=, imageSize=185770]

2023-07-31 22:41:38.878 [DEBUG] [ee.app.otaserver.ZclOtaUpgradeServer] - 7E7A/1: OTA Server file set: ZigBeeOtaFile [headerVersion=256, headerLength=56, manufacturerCode=4107, imageType=0121, fileVersion=02003B19, stackVersion=ZIGBEE_PRO, headerString=, imageSize=185770]
2023-07-31 22:41:38.880 [DEBUG] [ee.app.otaserver.ZclOtaUpgradeServer] - 7E7A/1 OTA status updated to OTA_WAITING.
2023-07-31 22:41:38.885 [WARN ] [zsmartsystems.zigbee.ZigBeeExecutors] - Uncaught exception in thread NotificationService-thread-328
java.lang.NullPointerException: Cannot invoke "com.zsmartsystems.zigbee.app.otaserver.ZclOtaUpgradeServer.cancelUpgrade()" because "this.otaServer" is null
    at org.openhab.binding.zigbee.handler.ZigBeeThingHandler.otaStatusUpdate(ZigBeeThingHandler.java:1032) ~[?:?]
    at com.zsmartsystems.zigbee.app.otaserver.ZclOtaUpgradeServer$2.run(ZclOtaUpgradeServer.java:583) ~[?:?]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?]
    at java.lang.Thread.run(Thread.java:833) ~[?:?]
2023-07-31 22:43:15.923 [DEBUG] [ee.app.otaserver.ZclOtaUpgradeServer] - 5CF0/232 OTA Server: No file set in QueryNextImageCommand.
2023-07-31 22:43:15.925 [DEBUG] [ee.app.otaserver.ZclOtaUpgradeServer] - 5CF0/232 OTA Server: No file returned from listeners.
2023-07-31 22:45:13.331 [DEBUG] [ee.app.otaserver.ZclOtaUpgradeServer] - 22DC/11 OTA Server: No file set in QueryNextImageCommand.
2023-07-31 22:45:13.332 [DEBUG] [ee.app.otaserver.ZclOtaUpgradeServer] - 22DC/11 OTA Server: No file returned from listeners.

[cdjackson]

Again - this is working for other clients. I can't help you if you don't provide the requested log file.

[cdjackson]

Looking at the exception, this is likely not a problem with the library. I see that you are using openHAB and I suspect that the issue is in OH.

[einalex]

Please specify which additional logging channels you need at debug level.

[cdjackson]

As per my. last comment, I don't think the issue is in this repository so we probably should close the issue here. I would suggest trying the standalone console in this repository.