{Homey,Device,Driver}.onUninit not guaranteed to be called at all

[robertklep]

In what I assume is the current version of SDKv3, when an app gets a SIGTERM, the following code is run:

homey.destroy();
process.nextTick(() => process.exit());

homey.destroy(), in turn, will run this code:

Promise.resolve().then(() => HomeyApp.onUninit()).catch(this.error);
for (const driver of Object.values(ManagerDrivers.getDrivers())) {
  Promise.resolve().then(() => driver.onUninit()).catch(this.error);
  for (const device of driver.getDevices()) {
    Promise.resolve().then(() => device.onUninit()).catch(this.error);
  }
}

Because the next tick queue will run before the microtask/promise queue, the process is exited before it even gets a chance to run any of the onUninit methods.

[AdyRock]

That explains the crash reports I get when my apps updated and try to clean up.

[frodeheg]

I would really like to get this issue fixed as it makes it impossible to do a safe shutdown of the app when sending out updates. The alternative I have is to run this.homey.settings.set(...) every minute (or more often) to avoid losing the state, which is a very bad alternative compared to only having to run this.homey.settings.set(...) during onUninit().

[frodeheg]

Can we please add the label 'bug' to this issue? (I can't figure out how)

[robertklep]

@frodeheg looks like only the owner of the repository can add labels to issues.

[WeeJeWel]

I would really like to get this issue fixed as it makes it impossible to do a safe shutdown of the app when sending out updates. The alternative I have is to run this.homey.settings.set(...) every minute (or more often) to avoid losing the state, which is a very bad alternative compared to only having to run this.homey.settings.set(...) during onUninit().

Can you elaborate on your usecase/problem? There are various events where Homey Pro can stop running apps at any time (e.g. power loss). It has never been a real issue before, so I'm wondering why this is required for your app.

[frodeheg]

so I'm wondering why this is required for your app.

In Norway a new model for charging for electricity usage was introduced on the 1st of July 2022. With this model, for every month we have to pay a grid fee based on the maximum hourly consumption of the previous month (a bit simplified). The goal of this new fee is to reduce the maximum load on the power grid and as such reduce the need to upgrade the infrastructure.

Thus I made an app that limits the maximum power you can draw for any given hour to just below the step where increased grid cost is introduced. For this to be completely reliable it is absolutely essential that the app manages to keep the energy usage below this threshold every single hour of the entire month. Ideally this means that the app should be running 100%, but this is not possible due to external factors. Thus, I feel it is critical that my app remember the state it was in whenever the app is restarted in any single hour, such that it can take measures to prevent using too much power for the rest of the hour just after a restart. If onUninit had been working I could have made sure of this for at least two cases: When the app is updated with a new version and when the user has initiated a soft reboot process (which as it turns out some users do once every night)

So without onUninit I have to save this critical state regularly instead and every minute lost constitutes an error of the estimate of about 1.7%, so there is some wiggle room but at 5 minutes the error is up to 8.3% which is starting to become significant. If the power usage for one hour is too high for any single hour the cost for the entire month increases significantly, thus I would very much like the onUninit function to be operational to reduce this wiggle room as much as possible.

The app I am talking about is https://homey.app/a/no.sparegris and it is now one of the most popular apps in Norway according to your app store.

[robertklep]

Besides that, none of the onUninit() methods actually get called when an app gets restarted/killed, in spite of what the documentation suggests.

[AdyRock]

I have implemented code in the onUninit() functions to clean up and log out of APIs, etc. I can tell they are not working as I get crash reports every time someone updates or restart the apps because code is still running that would of been stopped.

[frodeheg]

@AdyRock , you can try this workaround, it works well for me:

async onInit() {
  this.homey.on('unload', () => this.onUninit());
  ....
}

(you might want to have a guard in the onUnit function that prevents it from being called twice though, in case Athom ever decides they want to fix this issue)

[RonnyWinkler]

I get similar crash reports - and concole logs in local debugging. The app crashes most times it gets restarted (in the mobile app) or if it gets updated (e.g. debug version is running and store version gets installed).

There is no timer or timeout running. Only a websocket client which could trigger during app exit. The trigger could cause a capability change with setCapabilityValue(), but exceptions are catched.

/opt/homey-client/system/manager/ManagerApps/AppProcess/node_modules/homey-apps-sdk-v3/lib/Homey.js:1
"use strict";const path=require("path"),SimpleClass=require("./SimpleClass.js"),Manager=require("./Manager.js");class Homey extends SimpleClass{constructor(e,t,s,i){super(),this.dir=e,this.tmpdir=path.join(e,"tmp"),this.version=s,this.platform=i,this.env={},this.manifest=t,this.app={},this.__readyPromise=new Promise(e=>{this.__readyResolve=e}),this._timers=new Set,this._destroyed=!1,this.apps={},this.arp={},this.audio={},this.ble={},this.cloud={},this.clock={},this.drivers={},this.discovery={},this.flow={},this.geolocation={},this.i18n={},this.images={},this.insights={},this.ledring={},this.nfc={},this.notifications={},this.rf={},this.settings={},this.speechInput={},this.speechOutput={},this.zigbee={},this.zwave={},this.api={}}ready(){return this.__readyPromise}markReady(){this.__readyResolve()}hasPermission(e){return!1!==Array.isArray(this.manifest.permissions)&&this.manifest.permissions.includes(e)}__(e,t){}setTimeout(e,t,...s){if(this._destroyed)return null;const i=setTimeout(()=>{this._timers.delete(i),e(...s)},t);return this._timers.add(i),i}clearTimeout(e){clearTimeout(e),this._timers.delete(e)}setInterval(e,t,...s){if(this._destroyed)return null;const i=setInterval(e,t,...s);return this._timers.add(i),i}clearInterval(e){clearInterval(e),this._timers.delete(e)}destroy(){this.__debug("Homey Destroyed"),this.emit("unload"),this._destroyed=!0;for(const e of this._timers.values())clearTimeout(e);const e={emit:async e=>{throw this.__debug(`Emit after destroy ${e}`),new Error(`Cannot send "${e}" because the app instance has been destroyed.\n`+"This may indicate that your app is not cleaning up all resources in `onUninit()`.")}},t=this.app,s=this.drivers;for(const t of Object.keys(this)){const s=this[t];s instanceof Manager&&(this[t]=void 0,s.homey=void 0,s.__client=e,s.removeAllListeners(),Object.defineProperty(this,t,{get(){throw new Error(`Cannot access \`this.homey.${t}\` because the app instance has been destroyed.\n`+"This may indicate that your app is not cleaning up all resources in `onUninit()`.")}}))}this.app=void 0,Object.defineProperty(this,"app",{get(){throw new Error("Cannot access `this.homey.app` because the app instance has been destroyed.\nThis may indicate that your app is not cleaning up all resources in `onUninit()`.")}}),this.removeAllListeners(),Promise.resolve().then(()=>t.onUninit()).catch(this.error);for(const e of Object.values(s.getDrivers())){Promise.resolve().then(()=>e.onUninit()).catch(this.error);for(const t of e.getDevices())Promise.resolve().then(()=>t.onUninit()).catch(this.error)}}}module.exports=Homey;

TypeError: e.getDevices is not a function or its return value is not iterable
    at Homey.destroy (/opt/homey-client/system/manager/ManagerApps/AppProcess/node_modules/homey-apps-sdk-v3/lib/Homey.js:1:2490)
    at process.unload (/opt/homey-client/system/manager/ManagerApps/AppProcess/node_modules/homey-apps-sdk-v3/lib/SDK.js:143:13)
    at process.emit (node:events:526:28)

--- INFO: io.home-assistant.community has been killed ---

[RonnyWinkler]

async onInit() { this.homey.on('unload', () => this.onUninit()); .... }

That makes no difference for me. The onUninit gets called and it seems the websocket connection is closed, but still the app crashes. Then it restarts and works, but in MobileApp there is still the infoamation like "stopped unexpectedly".

The console output is:

App onUninit() - close connection
Waiting for the debugger to disconnect...
/opt/homey-client/system/manager/ManagerApps/AppProcess/node_modules/homey-apps-sdk-v3/lib/Homey.js:1
"use strict";const path=require("path"),SimpleClass=require("./SimpleClass.js"),Manager=require("./Manager.js");class Homey extends SimpleClass{constructor(e,t,s,i){super(),this.dir=e,this.tmpdir=path.join(e,"tmp"),this.version=s,this.platform=i,this.env={},this.manifest=t,this.app={},this.__readyPromise=new Promise(e=>{this.__readyResolve=e}),this._timers=new Set,this._destroyed=!1,this.apps={},this.arp={},this.audio={},this.ble={},this.cloud={},this.clock={},this.drivers={},this.discovery={},this.flow={},this.geolocation={},this.i18n={},this.images={},this.insights={},this.ledring={},this.nfc={},this.notifications={},this.rf={},this.settings={},this.speechInput={},this.speechOutput={},this.zigbee={},this.zwave={},this.api={}}ready(){return this.__readyPromise}markReady(){this.__readyResolve()}hasPermission(e){return!1!==Array.isArray(this.manifest.permissions)&&this.manifest.permissions.includes(e)}__(e,t){}setTimeout(e,t,...s){if(this._destroyed)return null;const i=setTimeout(()=>{this._timers.delete(i),e(...s)},t);return this._timers.add(i),i}clearTimeout(e){clearTimeout(e),this._timers.delete(e)}setInterval(e,t,...s){if(this._destroyed)return null;const i=setInterval(e,t,...s);return this._timers.add(i),i}clearInterval(e){clearInterval(e),this._timers.delete(e)}destroy(){this.__debug("Homey Destroyed"),this.emit("unload"),this._destroyed=!0;for(const e of this._timers.values())clearTimeout(e);const e={emit:async e=>{throw this.__debug(`Emit after destroy ${e}`),new Error(`Cannot send "${e}" because the app instance has been destroyed.\n`+"This may indicate that your app is not cleaning up all resources in `onUninit()`.")}},t=this.app,s=this.drivers;for(const t of Object.keys(this)){const s=this[t];s instanceof Manager&&(this[t]=void 0,s.homey=void 0,s.__client=e,s.removeAllListeners(),Object.defineProperty(this,t,{get(){throw new Error(`Cannot access \`this.homey.${t}\` because the app instance has been destroyed.\n`+"This may indicate that your app is not cleaning up all resources in `onUninit()`.")}}))}this.app=void 0,Object.defineProperty(this,"app",{get(){throw new Error("Cannot access `this.homey.app` because the app instance has been destroyed.\nThis may indicate that your app is not cleaning up all resources in `onUninit()`.")}}),this.removeAllListeners(),Promise.resolve().then(()=>t.onUninit()).catch(this.error);for(const e of Object.values(s.getDrivers())){Promise.resolve().then(()=>e.onUninit()).catch(this.error);for(const t of e.getDevices())Promise.resolve().then(()=>t.onUninit()).catch(this.error)}}}module.exports=Homey;

TypeError: e.getDevices is not a function or its return value is not iterable
    at Homey.destroy (/opt/homey-client/system/manager/ManagerApps/AppProcess/node_modules/homey-apps-sdk-v3/lib/Homey.js:1:2490)
    at process.unload (/opt/homey-client/system/manager/ManagerApps/AppProcess/node_modules/homey-apps-sdk-v3/lib/SDK.js:143:13)
    at process.emit (node:events:526:28)

--- INFO: io.home-assistant.community has been killed ---
Debugger listening on ws://0.0.0.0:9225/a16af451-d1df-4923-8646-703bb43df97f
For help, see: https://nodejs.org/en/docs/inspector
Debugger attached.
(node:31344) [INSPECTOR_ASYNC_STACK_TRACES_NOT_AVAILABLE] Warning: Warning: Async stack traces in debugger are not available on 32bit platforms. The feature is disabled.
(Use `node --trace-warnings ...` to show where the warning was created)
[log] 2022-11-01 13:04:33 [App] Home-Assistant is running...
[log] 2022-11-01 13:04:33 [App] connecting to home-assistant

[robertklep]

TypeError: e.getDevices is not a function or its return value is not iterable

@RonnyWinkler since you're overloading getDevices in your drivers, are you sure the issue isn't caused by that?

The SDK runs this code from Homey.destroy():

    Promise.resolve().then(() => HomeyApp.onUninit()).catch(this.error);
    for (const driver of Object.values(ManagerDrivers.getDrivers())) {
      Promise.resolve().then(() => driver.onUninit()).catch(this.error);
      for (const device of driver.getDevices()) {
        Promise.resolve().then(() => device.onUninit()).catch(this.error);
      }
    }

And the error you're getting is thrown in the last for loop (for (const device of driver.getDevices())).

[RonnyWinkler]

Oh, many thanks for the hint. I used this name by mistake and wasn't aware I overloaded this function. I will change this and check if it's running without errors then.

Edit: Great, much better now :-)

App onUninit() - close connection
Waiting for the debugger to disconnect...

--- INFO: io.home-assistant.community has been killed ---
Debugger listening on ws://0.0.0.0:9225/4dec56bc-8000-4b6b-b03d-14aab0adcbaf
For help, see: https://nodejs.org/en/docs/inspector
Debugger attached.
(node:5491) [INSPECTOR_ASYNC_STACK_TRACES_NOT_AVAILABLE] Warning: Warning: Async stack traces in debugger are not available on 32bit platforms. The feature is disabled.
(Use `node --trace-warnings ...` to show where the warning was created)
[log] 2022-11-01 13:41:38 [App] Home-Assistant is running...

[oh2th]

Looks like the same is going on with com.sensibo for the past month. However only from Homeys running 10.0.5

Stack trace
/opt/homey-client/system/manager/ManagerApps/AppProcess/node_modules/@athombv/homey-apps-sdk-v3/lib/Homey.js:1
"use strict";const path=require("path"),SimpleClass=require("./SimpleClass.js"),Manager=require("./Manager.js");class Homey extends SimpleClass{constructor(e,t,s,i,r){super(),this.dir=e,this.tmpdir=path.join(e,"tmp"),this.version=s,this.platform=i,this.platformVersion=r,this.env={},this.manifest=t,this.app={},this.__readyPromise=new Promise(e=>{this.__readyResolve=e}),this._timers=new Set,this._destroyed=!1,this.apps={},this.arp={},this.audio={},this.ble={},this.cloud={},this.clock={},this.drivers={},this.discovery={},this.flow={},this.geolocation={},this.i18n={},this.images={},this.insights={},this.ledring={},this.nfc={},this.notifications={},this.rf={},this.settings={},this.speechInput={},this.speechOutput={},this.zigbee={},this.zwave={},this.api={}}ready(){return this.__readyPromise}markReady(){this.__readyResolve()}hasPermission(e){return!1!==Array.isArray(this.manifest.permissions)&&this.manifest.permissions.includes(e)}__(e,t){}setTimeout(e,t,...s){if(this._destroyed)return null;const i=setTimeout(()=>{this._timers.delete(i),e(...s)},t);return this._timers.add(i),i}clearTimeout(e){clearTimeout(e),this._timers.delete(e)}setInterval(e,t,...s){if(this._destroyed)return null;const i=setInterval(e,t,...s);return this._timers.add(i),i}clearInterval(e){clearInterval(e),this._timers.delete(e)}destroy(){this.__debug("Homey Destroyed"),this.emit("unload"),this._destroyed=!0;for(const e of this._timers.values())clearTimeout(e);const e={emit:async e=>{throw this.__debug(`Emit after destroy ${e}`),new Error(`Cannot send "${e}" because the app instance has been destroyed.\n`+"This may indicate that your app is not cleaning up all resources in `onUninit()`.")}},t=this.app,s=this.drivers;for(const t of Object.keys(this)){const s=this[t];s instanceof Manager&&(this[t]=void 0,s.homey=void 0,s.__client=e,s.removeAllListeners(),Object.defineProperty(this,t,{get(){throw new Error(`Cannot access \`this.homey.${t}\` because the app instance has been destroyed.\n`+"This may indicate that your app is not cleaning up all resources in `onUninit()`.")}}))}this.app=void 0,Object.defineProperty(this,"app",{get(){throw new Error("Cannot access `this.homey.app` because the app instance has been destroyed.\nThis may indicate that your app is not cleaning up all resources in `onUninit()`.")}}),this.removeAllListeners(),Promise.resolve().then(()=>t.onUninit()).catch(this.error);for(const e of Object.values(s.getDrivers())){Promise.resolve().then(()=>e.onUninit()).catch(this.error);for(const t of e.getDevices())Promise.resolve().then(()=>t.onUninit()).catch(this.error)}}}module.exports=Homey;

TypeError: s.getDrivers is not a function
    at Homey.destroy (/opt/homey-client/system/manager/ManagerApps/AppProcess/node_modules/@athombv/homey-apps-sdk-v3/lib/Homey.js:1:2424)
    at process.unload (/opt/homey-client/system/manager/ManagerApps/AppProcess/node_modules/@athombv/homey-apps-sdk-v3/lib/SDK.js:144:13)
    at process.emit (node:events:526:28)

[alistairg]

A +1 to fix this from me, also. When using the debugger (homey app run) the CTRL-C method documented simply blows the app away - there is no smooth shutdown.

The driver I'm currently writing connects to a fussy device that demands a smooth disconnect or it blocks further connections. While this MAY be livable as an edge case, it's absolutely not during debugging and update cycles.