From 6e346073e75685eed52da0d2e229ef68e073c76d Mon Sep 17 00:00:00 2001 From: Nerivec <62446222+Nerivec@users.noreply.github.com> Date: Sun, 13 Apr 2025 21:49:12 +0200 Subject: [PATCH] feat: Allow scheduling OTA on device request (#26823) Co-authored-by: Koen Kanters --- lib/extension/otaUpdate.ts | 330 +++++++++++++++++++------- lib/types/api.ts | 24 +- test/extensions/otaUpdate.test.ts | 380 ++++++++++++++++++++++++++---- 3 files changed, 604 insertions(+), 130 deletions(-) diff --git a/lib/extension/otaUpdate.ts b/lib/extension/otaUpdate.ts index eb22b0b15..12478d7ea 100644 --- a/lib/extension/otaUpdate.ts +++ b/lib/extension/otaUpdate.ts @@ -18,7 +18,7 @@ import * as settings from '../util/settings'; import utils from '../util/utils'; import Extension from './extension'; -type UpdateState = 'updating' | 'idle' | 'available'; +type UpdateState = 'updating' | 'idle' | 'available' | 'scheduled'; interface UpdatePayload { update: { progress?: number; @@ -29,12 +29,18 @@ interface UpdatePayload { }; } -const topicRegex = new RegExp(`^${settings.get().mqtt.base_topic}/bridge/request/device/ota_update/(update|check)/?(downgrade)?`, 'i'); +const topicRegex = new RegExp( + `^${settings.get().mqtt.base_topic}/bridge/request/device/ota_update/(update|check|schedule|unschedule)/?(downgrade)?`, + 'i', +); export default class OTAUpdate extends Extension { - private inProgress = new Set(); - private lastChecked: {[s: string]: number} = {}; + private inProgress = new Set(); + private lastChecked = new Map(); + private scheduledUpgrades = new Set(); + private scheduledDowngrades = new Set(); + // biome-ignore lint/suspicious/useAwait: API override async start(): Promise { this.eventBus.onMQTTMessage(this, this.onMQTTMessage); this.eventBus.onDeviceMessage(this, this.onZigbeeEvent); @@ -78,37 +84,122 @@ export default class OTAUpdate extends Extension { } @bind private async onZigbeeEvent(data: eventdata.DeviceMessage): Promise { - if (data.type !== 'commandQueryNextImageRequest' || !data.device.definition || this.inProgress.has(data.device.ieeeAddr)) return; + if (data.type !== 'commandQueryNextImageRequest' || !data.device.definition || this.inProgress.has(data.device.ieeeAddr)) { + return; + } + + // `commandQueryNextImageRequest` check above should ensures this is valid but... + assert( + data.meta.zclTransactionSequenceNumber !== undefined, + "Missing 'queryNextImageRequest' transaction sequence number (cannot match reply)", + ); + logger.debug(`Device '${data.device.name}' requested OTA`); - const automaticOTACheckDisabled = settings.get().ota.disable_automatic_update_check; + if (data.device.definition.ota) { + if (this.scheduledUpgrades.has(data.device.ieeeAddr) || this.scheduledDowngrades.has(data.device.ieeeAddr)) { + this.inProgress.add(data.device.ieeeAddr); - if (data.device.definition.ota && !automaticOTACheckDisabled) { - // When a device does a next image request, it will usually do it a few times after each other - // with only 10 - 60 seconds inbetween. It doesn't make sense to check for a new update - // each time, so this interval can be set by the user. The default is 1,440 minutes (one day). - const updateCheckInterval = settings.get().ota.update_check_interval * 1000 * 60; - const check = - this.lastChecked[data.device.ieeeAddr] !== undefined - ? Date.now() - this.lastChecked[data.device.ieeeAddr] > updateCheckInterval - : true; - if (!check) return; + logger.info(`Updating '${data.device.name}' to latest firmware`); - this.lastChecked[data.device.ieeeAddr] = Date.now(); - let availableResult: Ota.UpdateAvailableResult | undefined; + try { + const fileVersion = await ota.update( + data.device.zh, + data.device.otaExtraMetas, + this.scheduledDowngrades.has(data.device.ieeeAddr), + async (progress, remaining) => { + let msg = `Update of '${data.device.name}' at ${progress.toFixed(2)}%`; - try { - // never use 'previous' when responding to device request - availableResult = await ota.isUpdateAvailable(data.device.zh, data.device.otaExtraMetas, data.data as Ota.ImageInfo, false); - } catch (error) { - logger.debug(`Failed to check if update available for '${data.device.name}' (${error})`); + if (remaining) { + msg += `, ≈ ${Math.round(remaining / 60)} minutes remaining`; + } + + logger.info(msg); + + await this.publishEntityState( + data.device, + this.getEntityPublishPayload(data.device, 'updating', progress, remaining ?? undefined), + ); + }, + data.data as Ota.ImageInfo, + data.meta.zclTransactionSequenceNumber, + ); + + // remove right away on update success or no image in case any of the below calls fail + this.scheduledUpgrades.delete(data.device.ieeeAddr); + this.scheduledDowngrades.delete(data.device.ieeeAddr); + + if (fileVersion === undefined) { + logger.info(`No image currently available for '${data.device.name}'. Unscheduling.`); + + // XXX: superfluous? + this.removeProgressAndRemainingFromState(data.device); + await this.publishEntityState(data.device, this.getEntityPublishPayload(data.device, 'idle')); + this.inProgress.delete(data.device.ieeeAddr); + + return; + } + + logger.info(`Finished update of '${data.device.name}'`); + + this.removeProgressAndRemainingFromState(data.device); + await this.publishEntityState( + data.device, + this.getEntityPublishPayload(data.device, {available: false, currentFileVersion: fileVersion, otaFileVersion: fileVersion}), + ); + + const firmwareTo = await this.readSoftwareBuildIDAndDateCode(data.device); + + logger.info(() => `Device '${data.device.name}' was updated to '${stringify(firmwareTo)}'`); + + /** + * Re-configure after reading software build ID and date code, some devices use a + * custom attribute for this (e.g. Develco SMSZB-120) + */ + this.eventBus.emitReconfigure({device: data.device}); + this.eventBus.emitDevicesChanged(); + } catch (e) { + logger.debug(`Update of '${data.device.name}' failed (${e}). Retry scheduled for next request.`); + + this.removeProgressAndRemainingFromState(data.device); + await this.publishEntityState(data.device, this.getEntityPublishPayload(data.device, 'scheduled')); + } + + this.inProgress.delete(data.device.ieeeAddr); + + return; // we're done } - await this.publishEntityState(data.device, this.getEntityPublishPayload(data.device, availableResult ?? 'idle')); + if (!settings.get().ota.disable_automatic_update_check) { + // When a device does a next image request, it will usually do it a few times after each other + // with only 10 - 60 seconds inbetween. It doesn't make sense to check for a new update + // each time, so this interval can be set by the user. The default is 1,440 minutes (one day). + const updateCheckInterval = settings.get().ota.update_check_interval * 1000 * 60; + const check = this.lastChecked.has(data.device.ieeeAddr) + ? Date.now() - this.lastChecked.get(data.device.ieeeAddr)! > updateCheckInterval + : true; - if (availableResult?.available) { - const message = `Update available for '${data.device.name}'`; - logger.info(message); + if (!check) { + return; + } + + this.inProgress.add(data.device.ieeeAddr); + this.lastChecked.set(data.device.ieeeAddr, Date.now()); + let availableResult: Ota.UpdateAvailableResult | undefined; + + try { + // never use 'previous' when responding to device request + availableResult = await ota.isUpdateAvailable(data.device.zh, data.device.otaExtraMetas, data.data as Ota.ImageInfo, false); + } catch (error) { + logger.debug(`Failed to check if update available for '${data.device.name}' (${error})`); + } + + await this.publishEntityState(data.device, this.getEntityPublishPayload(data.device, availableResult ?? 'idle')); + + if (availableResult?.available) { + const message = `Update available for '${data.device.name}'`; + logger.info(message); + } } } @@ -122,6 +213,7 @@ export default class OTAUpdate extends Extension { data.meta.zclTransactionSequenceNumber, ); logger.debug(`Responded to OTA request of '${data.device.name}' with 'NO_IMAGE_AVAILABLE'`); + this.inProgress.delete(data.device.ieeeAddr); } private async readSoftwareBuildIDAndDateCode( @@ -175,11 +267,14 @@ export default class OTAUpdate extends Extension { | Zigbee2MQTTAPI['bridge/request/device/ota_update/check'] | Zigbee2MQTTAPI['bridge/request/device/ota_update/check/downgrade'] | Zigbee2MQTTAPI['bridge/request/device/ota_update/update'] - | Zigbee2MQTTAPI['bridge/request/device/ota_update/update/downgrade']; + | Zigbee2MQTTAPI['bridge/request/device/ota_update/update/downgrade'] + | Zigbee2MQTTAPI['bridge/request/device/ota_update/schedule'] + | Zigbee2MQTTAPI['bridge/request/device/ota_update/schedule/downgrade'] + | Zigbee2MQTTAPI['bridge/request/device/ota_update/unschedule']; const ID = (typeof message === 'object' && message.id !== undefined ? message.id : message) as string; const device = this.zigbee.resolveEntity(ID); - const type = topicMatch[1]; - const downgrade = Boolean(topicMatch[2]); + const type = topicMatch[1] as 'check' | 'update' | 'schedule' | 'unschedule'; + const downgrade = topicMatch[2] === 'downgrade'; let error: string | undefined; let errorStack: string | undefined; @@ -188,83 +283,148 @@ export default class OTAUpdate extends Extension { } else if (!device.definition || !device.definition.ota) { error = `Device '${device.name}' does not support OTA updates`; } else if (this.inProgress.has(device.ieeeAddr)) { + // also guards against scheduling while check/update op in progress that could result in undesired OTA state error = `Update or check for update already in progress for '${device.name}'`; } else { - this.inProgress.add(device.ieeeAddr); + switch (type) { + case 'check': { + this.inProgress.add(device.ieeeAddr); - if (type === 'check') { - const msg = `Checking if update available for '${device.name}'`; - logger.info(msg); + logger.info(`Checking if update available for '${device.name}'`); - try { - const availableResult = await ota.isUpdateAvailable(device.zh, device.otaExtraMetas, undefined, downgrade); - const msg = `${availableResult.available ? 'Update' : 'No update'} available for '${device.name}'`; - logger.info(msg); + try { + const availableResult = await ota.isUpdateAvailable(device.zh, device.otaExtraMetas, undefined, downgrade); - await this.publishEntityState(device, this.getEntityPublishPayload(device, availableResult)); + logger.info(`${availableResult.available ? 'Update' : 'No update'} available for '${device.name}'`); - this.lastChecked[device.ieeeAddr] = Date.now(); - const response = utils.getResponse<'bridge/response/device/ota_update/check'>(message, { - id: ID, - update_available: availableResult.available, - }); + await this.publishEntityState(device, this.getEntityPublishPayload(device, availableResult)); + this.lastChecked.set(device.ieeeAddr, Date.now()); - await this.mqtt.publish('bridge/response/device/ota_update/check', stringify(response)); - } catch (e) { - error = `Failed to check if update available for '${device.name}' (${(e as Error).message})`; - errorStack = (e as Error).stack; + const response = utils.getResponse<'bridge/response/device/ota_update/check'>(message, { + id: ID, + update_available: availableResult.available, + }); + + await this.mqtt.publish('bridge/response/device/ota_update/check', stringify(response)); + } catch (e) { + error = `Failed to check if update available for '${device.name}' (${(e as Error).message})`; + errorStack = (e as Error).stack; + } + + break; } - } else { - // type === 'update' - const msg = `Updating '${device.name}' to ${downgrade ? 'previous' : 'latest'} firmware`; - logger.info(msg); - try { - const firmwareFrom = await this.readSoftwareBuildIDAndDateCode(device, 'immediate'); - const fileVersion = await ota.update(device.zh, device.otaExtraMetas, downgrade, async (progress, remaining) => { - let msg = `Update of '${device.name}' at ${progress.toFixed(2)}%`; + case 'update': { + this.inProgress.add(device.ieeeAddr); - if (remaining) { - msg += `, ≈ ${Math.round(remaining / 60)} minutes remaining`; + if (this.scheduledUpgrades.delete(device.ieeeAddr)) { + logger.info(`Previously scheduled '${device.name}' upgrade was cancelled by manual update`); + } else if (this.scheduledDowngrades.delete(device.ieeeAddr)) { + logger.info(`Previously scheduled '${device.name}' downgrade was cancelled by manual update`); + } + + logger.info(`Updating '${device.name}' to ${downgrade ? 'previous' : 'latest'} firmware`); + + try { + const firmwareFrom = await this.readSoftwareBuildIDAndDateCode(device, 'immediate'); + const fileVersion = await ota.update(device.zh, device.otaExtraMetas, downgrade, async (progress, remaining) => { + let msg = `Update of '${device.name}' at ${progress.toFixed(2)}%`; + + if (remaining) { + msg += `, ≈ ${Math.round(remaining / 60)} minutes remaining`; + } + + logger.info(msg); + + await this.publishEntityState(device, this.getEntityPublishPayload(device, 'updating', progress, remaining ?? undefined)); + }); + + if (fileVersion === undefined) { + throw new Error('No image currently available'); } - logger.info(msg); + logger.info(`Finished update of '${device.name}'`); + this.removeProgressAndRemainingFromState(device); + await this.publishEntityState( + device, + this.getEntityPublishPayload(device, {available: false, currentFileVersion: fileVersion, otaFileVersion: fileVersion}), + ); - await this.publishEntityState(device, this.getEntityPublishPayload(device, 'updating', progress, remaining ?? undefined)); - }); + const firmwareTo = await this.readSoftwareBuildIDAndDateCode(device); - logger.info(`Finished update of '${device.name}'`); - this.removeProgressAndRemainingFromState(device); - await this.publishEntityState( - device, - this.getEntityPublishPayload(device, {available: false, currentFileVersion: fileVersion, otaFileVersion: fileVersion}), - ); + logger.info(() => `Device '${device.name}' was updated from '${stringify(firmwareFrom)}' to '${stringify(firmwareTo)}'`); - const firmwareTo = await this.readSoftwareBuildIDAndDateCode(device); + /** + * Re-configure after reading software build ID and date code, some devices use a + * custom attribute for this (e.g. Develco SMSZB-120) + */ + this.eventBus.emitReconfigure({device}); + this.eventBus.emitDevicesChanged(); - logger.info(() => `Device '${device.name}' was updated from '${stringify(firmwareFrom)}' to '${stringify(firmwareTo)}'`); + const response = utils.getResponse<'bridge/response/device/ota_update/update'>(message, { + id: ID, + from: firmwareFrom ? {software_build_id: firmwareFrom.softwareBuildID, date_code: firmwareFrom.dateCode} : undefined, + to: firmwareTo ? {software_build_id: firmwareTo.softwareBuildID, date_code: firmwareTo.dateCode} : undefined, + }); - /** - * Re-configure after reading software build ID and date code, some devices use a - * custom attribute for this (e.g. Develco SMSZB-120) - */ - this.eventBus.emitReconfigure({device}); - this.eventBus.emitDevicesChanged(); + await this.mqtt.publish('bridge/response/device/ota_update/update', stringify(response)); + } catch (e) { + logger.debug(`Update of '${device.name}' failed (${e})`); + error = `Update of '${device.name}' failed (${(e as Error).message})`; + errorStack = (e as Error).stack; - const response = utils.getResponse<'bridge/response/device/ota_update/update'>(message, { + this.removeProgressAndRemainingFromState(device); + await this.publishEntityState(device, this.getEntityPublishPayload(device, 'available')); + } + + break; + } + + case 'schedule': { + // ensure only one type scheduled by deleting from the other if necessary + if (downgrade) { + if (this.scheduledUpgrades.delete(device.ieeeAddr)) { + logger.info(`Previously scheduled '${device.name}' upgrade was cancelled in favor of new downgrade request`); + } + + this.scheduledDowngrades.add(device.ieeeAddr); + } else { + if (this.scheduledDowngrades.delete(device.ieeeAddr)) { + logger.info(`Previously scheduled '${device.name}' downgrade was cancelled in favor of new upgrade request`); + } + + this.scheduledUpgrades.add(device.ieeeAddr); + } + + logger.info(`Scheduled '${device.name}' to ${downgrade ? 'downgrade' : 'upgrade'} firmware on next request from device`); + + await this.publishEntityState(device, this.getEntityPublishPayload(device, 'scheduled', undefined, undefined)); + + const response = utils.getResponse<'bridge/response/device/ota_update/schedule'>(message, { id: ID, - from: firmwareFrom ? {software_build_id: firmwareFrom.softwareBuildID, date_code: firmwareFrom.dateCode} : undefined, - to: firmwareTo ? {software_build_id: firmwareTo.softwareBuildID, date_code: firmwareTo.dateCode} : undefined, }); - await this.mqtt.publish('bridge/response/device/ota_update/update', stringify(response)); - } catch (e) { - logger.debug(`Update of '${device.name}' failed (${e})`); - error = `Update of '${device.name}' failed (${(e as Error).message})`; - errorStack = (e as Error).stack; + await this.mqtt.publish('bridge/response/device/ota_update/schedule', stringify(response)); - this.removeProgressAndRemainingFromState(device); - await this.publishEntityState(device, this.getEntityPublishPayload(device, 'available')); + break; + } + + case 'unschedule': { + if (this.scheduledUpgrades.delete(device.ieeeAddr)) { + logger.info(`Previously scheduled '${device.name}' upgrade was cancelled`); + } else if (this.scheduledDowngrades.delete(device.ieeeAddr)) { + logger.info(`Previously scheduled '${device.name}' downgrade was cancelled`); + } + + await this.publishEntityState(device, this.getEntityPublishPayload(device, 'idle', undefined, undefined)); + + const response = utils.getResponse<'bridge/response/device/ota_update/unschedule'>(message, { + id: ID, + }); + + await this.mqtt.publish('bridge/response/device/ota_update/unschedule', stringify(response)); + + break; } } diff --git a/lib/types/api.ts b/lib/types/api.ts index 2eaad7a00..085e1b38d 100644 --- a/lib/types/api.ts +++ b/lib/types/api.ts @@ -387,6 +387,26 @@ export interface Zigbee2MQTTAPI { | undefined; }; + 'bridge/request/device/ota_update/schedule': { + id: string; + }; + + 'bridge/request/device/ota_update/schedule/downgrade': { + id: string; + }; + + 'bridge/response/device/ota_update/schedule': { + id: string; + }; + + 'bridge/request/device/ota_update/unschedule': { + id: string; + }; + + 'bridge/response/device/ota_update/unschedule': { + id: string; + }; + 'bridge/request/device/interview': { id: string | number; }; @@ -648,9 +668,9 @@ export type Zigbee2MQTTResponseEndpoints = | 'bridge/response/device/configure' | 'bridge/response/device/remove' | 'bridge/response/device/ota_update/check' - | 'bridge/response/device/ota_update/check' - | 'bridge/response/device/ota_update/update' | 'bridge/response/device/ota_update/update' + | 'bridge/response/device/ota_update/schedule' + | 'bridge/response/device/ota_update/unschedule' | 'bridge/response/device/interview' | 'bridge/response/device/generate_external_definition' | 'bridge/response/device/options' diff --git a/test/extensions/otaUpdate.test.ts b/test/extensions/otaUpdate.test.ts index a6a1084d5..55eca0537 100644 --- a/test/extensions/otaUpdate.test.ts +++ b/test/extensions/otaUpdate.test.ts @@ -38,7 +38,6 @@ describe('Extension: OTAUpdate', () => { mockSleep.mock(); data.writeDefaultConfiguration(); settings.reRead(); - settings.reRead(); controller = new Controller(vi.fn(), vi.fn()); await controller.start(); await flushPromises(); @@ -51,14 +50,22 @@ describe('Extension: OTAUpdate', () => { vi.useRealTimers(); }); - beforeEach(async () => { + beforeEach(() => { zhc.ota.setConfiguration(DEFAULT_CONFIG); const extension = controller.getExtension('OTAUpdate')! as OTAUpdate; // @ts-expect-error private - extension.lastChecked = {}; + extension.lastChecked = new Map(); // @ts-expect-error private extension.inProgress = new Set(); - mocksClear.forEach((m) => m.mockClear()); + // @ts-expect-error private + extension.scheduledUpgrades = new Set(); + // @ts-expect-error private + extension.scheduledDowngrades = new Set(); + + for (const mock of mocksClear) { + mock.mockClear(); + } + devices.bulb.mockClear(); updateSpy.mockClear(); isUpdateAvailableSpy.mockClear(); @@ -66,11 +73,11 @@ describe('Extension: OTAUpdate', () => { controller.state.state = {}; }); - afterEach(async () => { + afterEach(() => { settings.set(['ota', 'disable_automatic_update_check'], false); }); - it.each(['update', 'update/downgrade'])('Should OTA update a device with topic %s', async (type) => { + it.each(['update', 'update/downgrade'])('updates a device with topic %s', async (type) => { const downgrade = type === 'update/downgrade'; let count = 10; devices.bulb.endpoints[0].read.mockImplementation(() => { @@ -87,7 +94,7 @@ describe('Extension: OTAUpdate', () => { onProgress(0, undefined); onProgress(10, 3600.2123); - return 90; + return await Promise.resolve(90); }); mockMQTTEvents.message(`zigbee2mqtt/bridge/request/device/ota_update/${type}`, 'bulb'); @@ -141,7 +148,7 @@ describe('Extension: OTAUpdate', () => { expect(mockMQTTPublishAsync).toHaveBeenCalledWith('zigbee2mqtt/bridge/devices', expect.any(String), {retain: true, qos: 0}); }); - it('Should handle when OTA update fails', async () => { + it('handles when OTA update fails', async () => { devices.bulb.endpoints[0].read.mockImplementation(() => { return {swBuildId: 1, dateCode: '2019010'}; }); @@ -158,7 +165,24 @@ describe('Extension: OTAUpdate', () => { ); }); - it('Should be able to check if OTA update is available', async () => { + it('handles when OTA update returns no image available', async () => { + devices.bulb.endpoints[0].read.mockImplementation(() => { + return {swBuildId: 1, dateCode: '2019010'}; + }); + devices.bulb.save.mockClear(); + updateSpy.mockResolvedValueOnce(undefined); + + mockMQTTEvents.message('zigbee2mqtt/bridge/request/device/ota_update/update', stringify({id: 'bulb'})); + await flushPromises(); + expect(mockMQTTPublishAsync).toHaveBeenCalledWith('zigbee2mqtt/bulb', stringify({update: {state: 'available'}}), {retain: true, qos: 0}); + expect(mockMQTTPublishAsync).toHaveBeenCalledWith( + 'zigbee2mqtt/bridge/response/device/ota_update/update', + stringify({data: {}, status: 'error', error: "Update of 'bulb' failed (No image currently available)"}), + {retain: false, qos: 0}, + ); + }); + + it('is able to check if OTA update is available', async () => { isUpdateAvailableSpy.mockResolvedValueOnce({available: false, currentFileVersion: 10, otaFileVersion: 10}); mockMQTTEvents.message('zigbee2mqtt/bridge/request/device/ota_update/check', 'bulb'); await flushPromises(); @@ -216,7 +240,7 @@ describe('Extension: OTAUpdate', () => { device.definition = originalDefinition; }); - it('Should handle if OTA update check fails', async () => { + it('handles if OTA update check fails', async () => { isUpdateAvailableSpy.mockRejectedValueOnce(new Error('RF signals disturbed because of dogs barking')); mockMQTTEvents.message('zigbee2mqtt/bridge/request/device/ota_update/check', 'bulb'); @@ -234,7 +258,7 @@ describe('Extension: OTAUpdate', () => { ); }); - it('Should fail when device does not exist', async () => { + it('fails when device does not exist', async () => { mockMQTTEvents.message('zigbee2mqtt/bridge/request/device/ota_update/check', 'not_existing_deviceooo'); await flushPromises(); expect(mockMQTTPublishAsync).toHaveBeenCalledWith( @@ -244,7 +268,7 @@ describe('Extension: OTAUpdate', () => { ); }); - it('Should not check for OTA when device does not support it', async () => { + it('does not check for OTA when device does not support it', async () => { mockMQTTEvents.message('zigbee2mqtt/bridge/request/device/ota_update/check', 'dimmer_wall_switch'); await flushPromises(); expect(mockMQTTPublishAsync).toHaveBeenCalledWith( @@ -254,32 +278,54 @@ describe('Extension: OTAUpdate', () => { ); }); - it('Should refuse to check/update when already in progress', async () => { - isUpdateAvailableSpy.mockImplementationOnce( - // @ts-expect-error mocked as needed - async () => { - await new Promise((resolve) => { - setTimeout(() => resolve(), 99999); + it.each(['check', 'check/downgrade', 'update', 'update/downgrade', 'schedule', 'schedule/downgrade', 'unschedule'])( + 'refuses to %s when already in progress', + async (type) => { + if (type.includes('schedule') || type.includes('check')) { + isUpdateAvailableSpy.mockImplementationOnce(async () => { + return await new Promise((resolve) => { + setTimeout( + () => + resolve({ + available: false, + currentFileVersion: 1, + otaFileVersion: 1, + }), + 99999, + ); + }); }); - }, - ); - mockMQTTEvents.message('zigbee2mqtt/bridge/request/device/ota_update/check', 'bulb'); - await flushPromises(); - mockMQTTEvents.message('zigbee2mqtt/bridge/request/device/ota_update/check', 'bulb'); - await flushPromises(); - expect(isUpdateAvailableSpy).toHaveBeenCalledTimes(1); - vi.runOnlyPendingTimers(); - await flushPromises(); - expect(mockMQTTPublishAsync).toHaveBeenCalledWith( - 'zigbee2mqtt/bridge/response/device/ota_update/check', - stringify({data: {}, status: 'error', error: `Update or check for update already in progress for 'bulb'`}), - {retain: false, qos: 0}, - ); - }); + } else { + updateSpy.mockImplementationOnce(async () => { + return await new Promise((resolve) => { + setTimeout(() => resolve(1), 99999); + }); + }); + } - it('Shouldnt crash when read modelID before/after OTA update fails', async () => { + mockMQTTEvents.message(`zigbee2mqtt/bridge/request/device/ota_update/${type.includes('schedule') ? 'check' : type}`, 'bulb'); + await flushPromises(); + mockMQTTEvents.message(`zigbee2mqtt/bridge/request/device/ota_update/${type}`, 'bulb'); + await flushPromises(); + + if (type.includes('schedule') || type.includes('check')) { + expect(isUpdateAvailableSpy).toHaveBeenCalledTimes(1); + } else { + expect(updateSpy).toHaveBeenCalledTimes(1); + } + + await vi.runOnlyPendingTimersAsync(); + expect(mockMQTTPublishAsync).toHaveBeenCalledWith( + `zigbee2mqtt/bridge/response/device/ota_update/${type.replace('/downgrade', '')}`, + stringify({data: {}, status: 'error', error: `Update or check for update already in progress for 'bulb'`}), + {retain: false, qos: 0}, + ); + }, + ); + + it('does not crash when read modelID before/after OTA update fails', async () => { devices.bulb.endpoints[0].read.mockRejectedValueOnce('Failed from').mockRejectedValueOnce('Failed to'); - updateSpy.mockImplementationOnce(vi.fn()); + updateSpy.mockResolvedValueOnce(1); mockMQTTEvents.message('zigbee2mqtt/bridge/request/device/ota_update/update', 'bulb'); await flushPromises(); @@ -290,7 +336,29 @@ describe('Extension: OTAUpdate', () => { ); }); - it('Should check for update when device requests it', async () => { + it('cancels scheduled when direct update requested', async () => { + updateSpy.mockResolvedValueOnce(1); + + mockMQTTEvents.message('zigbee2mqtt/bridge/request/device/ota_update/schedule', 'bulb'); + await flushPromises(); + + mockMQTTEvents.message('zigbee2mqtt/bridge/request/device/ota_update/update', 'bulb'); + await flushPromises(); + + expect(mockLogger.info).toHaveBeenCalledWith("Previously scheduled 'bulb' upgrade was cancelled by manual update"); + + updateSpy.mockResolvedValueOnce(1); + + mockMQTTEvents.message('zigbee2mqtt/bridge/request/device/ota_update/schedule/downgrade', 'bulb'); + await flushPromises(); + + mockMQTTEvents.message('zigbee2mqtt/bridge/request/device/ota_update/update', 'bulb'); + await flushPromises(); + + expect(mockLogger.info).toHaveBeenCalledWith("Previously scheduled 'bulb' downgrade was cancelled by manual update"); + }); + + it('checks for update when device requests it', async () => { const data = {imageType: 12382}; isUpdateAvailableSpy.mockResolvedValueOnce({available: true, currentFileVersion: 10, otaFileVersion: 12}); const payload = { @@ -327,7 +395,7 @@ describe('Extension: OTAUpdate', () => { ); }); - it('Should respond with NO_IMAGE_AVAILABLE when update available request fails', async () => { + it('responds with NO_IMAGE_AVAILABLE when update available request fails', async () => { const data = {imageType: 12382}; isUpdateAvailableSpy.mockRejectedValueOnce('Nothing to find here'); const payload = { @@ -348,7 +416,7 @@ describe('Extension: OTAUpdate', () => { expect(mockMQTTPublishAsync).toHaveBeenCalledWith('zigbee2mqtt/bulb', stringify({update: {state: 'idle'}}), {retain: true, qos: 0}); }); - it('Should check for update when device requests it and it is not available', async () => { + it('checks for update when device requests it and it is not available', async () => { const data = {imageType: 12382}; isUpdateAvailableSpy.mockResolvedValueOnce({available: false, currentFileVersion: 13, otaFileVersion: 13}); const payload = { @@ -373,7 +441,7 @@ describe('Extension: OTAUpdate', () => { ); }); - it('Should not check for update when device requests it and disable_automatic_update_check is set to true', async () => { + it('does not check for update when device requests it and disable_automatic_update_check is set to true', async () => { settings.set(['ota', 'disable_automatic_update_check'], true); const data = {imageType: 12382}; isUpdateAvailableSpy.mockResolvedValueOnce({available: true, currentFileVersion: 10, otaFileVersion: 13}); @@ -391,7 +459,233 @@ describe('Extension: OTAUpdate', () => { expect(isUpdateAvailableSpy).toHaveBeenCalledTimes(0); }); - it('Should respond with NO_IMAGE_AVAILABLE when not supporting OTA', async () => { + it.each(['schedule', 'schedule/downgrade'])('schedules and performs an update with topic %s', async (type) => { + const downgrade = type === 'schedule/downgrade'; + + if (downgrade) { + settings.set(['ota', 'disable_automatic_update_check'], true); // coverage, scheduling not affected by this + } + + updateSpy.mockImplementationOnce(async (device, extraMetas, previous, onProgress) => { + expect(previous).toStrictEqual(downgrade); + + onProgress(0, undefined); + onProgress(10, 3600.2123); + return await Promise.resolve(2); + }); + + mockMQTTEvents.message(`zigbee2mqtt/bridge/request/device/ota_update/${type}`, 'bulb'); + await flushPromises(); + + expect(mockMQTTPublishAsync).toHaveBeenNthCalledWith(1, 'zigbee2mqtt/bulb', stringify({update: {state: 'scheduled'}}), { + retain: true, + qos: 0, + }); + expect(mockMQTTPublishAsync).toHaveBeenNthCalledWith( + 2, + 'zigbee2mqtt/bridge/response/device/ota_update/schedule', + stringify({data: {id: 'bulb'}, status: 'ok'}), + {retain: false, qos: 0}, + ); + + const data = {imageType: 12382}; + const payload = { + data, + cluster: 'genOta', + device: devices.bulb, + endpoint: devices.bulb.getEndpoint(1)!, + type: 'commandQueryNextImageRequest', + linkquality: 10, + meta: {zclTransactionSequenceNumber: 10}, + }; + + await mockZHEvents.message(payload); + await flushPromises(); + + expect(updateSpy).toHaveBeenCalledTimes(1); + expect(mockMQTTPublishAsync).toHaveBeenNthCalledWith(3, 'zigbee2mqtt/bulb', stringify({update: {state: 'updating', progress: 0}}), { + retain: true, + qos: 0, + }); + expect(mockMQTTPublishAsync).toHaveBeenNthCalledWith( + 4, + 'zigbee2mqtt/bulb', + stringify({update: {state: 'updating', progress: 10, remaining: 3600}}), + {retain: true, qos: 0}, + ); + expect(mockMQTTPublishAsync).toHaveBeenNthCalledWith( + 5, + 'zigbee2mqtt/bulb', + stringify({update: {state: 'idle', installed_version: 2, latest_version: 2}}), + {retain: true, qos: 0}, + ); + expect(mockMQTTPublishAsync).toHaveBeenNthCalledWith(6, 'zigbee2mqtt/bridge/devices', expect.any(String), {retain: true, qos: 0}); + }); + + it('schedules and cancels an update when no image available', async () => { + updateSpy.mockResolvedValueOnce(undefined); + + mockMQTTEvents.message('zigbee2mqtt/bridge/request/device/ota_update/schedule', 'bulb'); + await flushPromises(); + + expect(mockMQTTPublishAsync).toHaveBeenNthCalledWith(1, 'zigbee2mqtt/bulb', stringify({update: {state: 'scheduled'}}), { + retain: true, + qos: 0, + }); + expect(mockMQTTPublishAsync).toHaveBeenNthCalledWith( + 2, + 'zigbee2mqtt/bridge/response/device/ota_update/schedule', + stringify({data: {id: 'bulb'}, status: 'ok'}), + {retain: false, qos: 0}, + ); + + const data = {imageType: 12382}; + const payload = { + data, + cluster: 'genOta', + device: devices.bulb, + endpoint: devices.bulb.getEndpoint(1)!, + type: 'commandQueryNextImageRequest', + linkquality: 10, + meta: {zclTransactionSequenceNumber: 10}, + }; + + await mockZHEvents.message(payload); + await flushPromises(); + + expect(updateSpy).toHaveBeenCalledTimes(1); + expect(mockMQTTPublishAsync).toHaveBeenNthCalledWith(3, 'zigbee2mqtt/bulb', stringify({update: {state: 'idle'}}), {retain: true, qos: 0}); + }); + + it('schedules and re-schedules an update when failed', async () => { + updateSpy.mockRejectedValueOnce('Update failed').mockImplementationOnce(async (device, extraMetas, previous, onProgress) => { + onProgress(0, undefined); + onProgress(10, 3600.2123); + return await Promise.resolve(2); + }); + + mockMQTTEvents.message('zigbee2mqtt/bridge/request/device/ota_update/schedule', 'bulb'); + await flushPromises(); + + expect(mockMQTTPublishAsync).toHaveBeenNthCalledWith(1, 'zigbee2mqtt/bulb', stringify({update: {state: 'scheduled'}}), { + retain: true, + qos: 0, + }); + expect(mockMQTTPublishAsync).toHaveBeenNthCalledWith( + 2, + 'zigbee2mqtt/bridge/response/device/ota_update/schedule', + stringify({data: {id: 'bulb'}, status: 'ok'}), + {retain: false, qos: 0}, + ); + + const data = {imageType: 12382}; + const payload = { + data, + cluster: 'genOta', + device: devices.bulb, + endpoint: devices.bulb.getEndpoint(1)!, + type: 'commandQueryNextImageRequest', + linkquality: 10, + meta: {zclTransactionSequenceNumber: 10}, + }; + + await mockZHEvents.message(payload); + await flushPromises(); + + expect(updateSpy).toHaveBeenCalledTimes(1); + expect(mockMQTTPublishAsync).toHaveBeenNthCalledWith(3, 'zigbee2mqtt/bulb', stringify({update: {state: 'scheduled'}}), { + retain: true, + qos: 0, + }); + + await mockZHEvents.message(payload); + await flushPromises(); + console.log(mockMQTTPublishAsync.mock.calls.map((c) => c[0])); + + expect(updateSpy).toHaveBeenCalledTimes(2); + expect(mockMQTTPublishAsync).toHaveBeenNthCalledWith(4, 'zigbee2mqtt/bulb', stringify({update: {state: 'updating', progress: 0}}), { + retain: true, + qos: 0, + }); + expect(mockMQTTPublishAsync).toHaveBeenNthCalledWith( + 5, + 'zigbee2mqtt/bulb', + stringify({update: {state: 'updating', progress: 10, remaining: 3600}}), + {retain: true, qos: 0}, + ); + expect(mockMQTTPublishAsync).toHaveBeenNthCalledWith( + 6, + 'zigbee2mqtt/bulb', + stringify({update: {state: 'idle', installed_version: 2, latest_version: 2}}), + {retain: true, qos: 0}, + ); + expect(mockMQTTPublishAsync).toHaveBeenNthCalledWith(7, 'zigbee2mqtt/bridge/devices', expect.any(String), {retain: true, qos: 0}); + }); + + it('overwrites current schedule on re-schedule', async () => { + for (const [type, overwriteType] of [ + ['schedule', 'schedule/downgrade'], + ['schedule/downgrade', 'schedule'], + ]) { + mockMQTTEvents.message(`zigbee2mqtt/bridge/request/device/ota_update/${type}`, 'bulb'); + await flushPromises(); + + expect(mockMQTTPublishAsync).toHaveBeenNthCalledWith(1, 'zigbee2mqtt/bulb', stringify({update: {state: 'scheduled'}}), { + retain: true, + qos: 0, + }); + expect(mockMQTTPublishAsync).toHaveBeenNthCalledWith( + 2, + 'zigbee2mqtt/bridge/response/device/ota_update/schedule', + stringify({data: {id: 'bulb'}, status: 'ok'}), + {retain: false, qos: 0}, + ); + + mockMQTTEvents.message(`zigbee2mqtt/bridge/request/device/ota_update/${overwriteType}`, 'bulb'); + await flushPromises(); + + expect(mockMQTTPublishAsync).toHaveBeenNthCalledWith(3, 'zigbee2mqtt/bulb', stringify({update: {state: 'scheduled'}}), { + retain: true, + qos: 0, + }); + expect(mockMQTTPublishAsync).toHaveBeenNthCalledWith( + 4, + 'zigbee2mqtt/bridge/response/device/ota_update/schedule', + stringify({data: {id: 'bulb'}, status: 'ok'}), + {retain: false, qos: 0}, + ); + } + }); + + it.each(['schedule', 'schedule/downgrade'])('unschedules', async (type) => { + mockMQTTEvents.message(`zigbee2mqtt/bridge/request/device/ota_update/${type}`, 'bulb'); + await flushPromises(); + + expect(mockMQTTPublishAsync).toHaveBeenNthCalledWith(1, 'zigbee2mqtt/bulb', stringify({update: {state: 'scheduled'}}), { + retain: true, + qos: 0, + }); + expect(mockMQTTPublishAsync).toHaveBeenNthCalledWith( + 2, + 'zigbee2mqtt/bridge/response/device/ota_update/schedule', + stringify({data: {id: 'bulb'}, status: 'ok'}), + {retain: false, qos: 0}, + ); + + mockMQTTEvents.message('zigbee2mqtt/bridge/request/device/ota_update/unschedule', 'bulb'); + await flushPromises(); + + expect(mockMQTTPublishAsync).toHaveBeenNthCalledWith(3, 'zigbee2mqtt/bulb', stringify({update: {state: 'idle'}}), {retain: true, qos: 0}); + + expect(mockMQTTPublishAsync).toHaveBeenNthCalledWith( + 4, + 'zigbee2mqtt/bridge/response/device/ota_update/unschedule', + stringify({data: {id: 'bulb'}, status: 'ok'}), + {retain: false, qos: 0}, + ); + }); + + it('responds with NO_IMAGE_AVAILABLE when not supporting OTA', async () => { const device = devices.HGZB04D; const data = {imageType: 12382}; const payload = { @@ -409,7 +703,7 @@ describe('Extension: OTAUpdate', () => { expect(device.endpoints[0].commandResponse).toHaveBeenCalledWith('genOta', 'queryNextImageResponse', {status: 152}, undefined, 10); }); - it('Should respond with NO_IMAGE_AVAILABLE when not supporting OTA and device has no OTA endpoint to standard endpoint', async () => { + it('responds with NO_IMAGE_AVAILABLE when not supporting OTA and device has no OTA endpoint to standard endpoint', async () => { const device = devices.SV01; const data = {imageType: 12382}; const payload = { @@ -427,7 +721,7 @@ describe('Extension: OTAUpdate', () => { expect(device.endpoints[0].commandResponse).toHaveBeenCalledWith('genOta', 'queryNextImageResponse', {status: 152}, undefined, 10); }); - it('Sets given configuration', async () => { + it('sets given configuration', async () => { const setConfiguration = vi.spyOn(zhc.ota, 'setConfiguration'); settings.set(['ota', 'zigbee_ota_override_index_location'], 'local.index.json'); settings.set(['ota', 'image_block_response_delay'], 10000); @@ -454,7 +748,7 @@ describe('Extension: OTAUpdate', () => { setConfiguration.mockClear(); }); - it('Clear update state on startup', async () => { + it('clear update state on startup', async () => { // @ts-expect-error private const device = controller.zigbee.resolveEntity(devices.bulb_color.ieeeAddr); // @ts-expect-error private