Recurring error forces restart of child bridge

[Sujovian]

Hi,

I moved this plugin to a child bridge because it was slowing down Hombridge service. Every two hours the plugin throws the following error, which forces the child bridge to restart:

/usr/local/lib/node_modules/homebridge-ecobee-away/node_modules/axios/lib/core/createError.js:16
var error = new Error(message);
^
Error: Request failed with status code 500
at createError (/usr/local/lib/node_modules/homebridge-ecobee-away/node_modules/axios/lib/core/createError.js:16:15)
at settle (/usr/local/lib/node_modules/homebridge-ecobee-away/node_modules/axios/lib/core/settle.js:17:12)
at IncomingMessage.handleStreamEnd (/usr/local/lib/node_modules/homebridge-ecobee-away/node_modules/axios/lib/adapters/http.js:260:11)
at IncomingMessage.emit (node:events:402:35)
at endReadableNT (node:internal/streams/readable:1343:12)
at processTicksAndRejections (node:internal/process/task_queues:83:21)
[2/1/2022, 9:22:10 AM] [Ecobee Away] Child bridge process ended
[2/1/2022, 9:22:10 AM] [Ecobee Away] Process Ended. Code: 1, Signal: null
[2/1/2022, 9:22:17 AM] [Ecobee Away] Restarting Process...
[2/1/2022, 9:22:18 AM] [Ecobee Away] Launched child bridge with PID 26297
[2/1/2022, 9:22:18 AM] Registering platform 'homebridge-ecobee-away.EcobeeAway'
[2/1/2022, 9:22:18 AM] [Ecobee Away] Loaded homebridge-ecobee-away v1.0.2 child bridge successfully
[2/1/2022, 9:22:18 AM] Loaded 1 cached accessories from cachedAccessories.0EE6DDEA3D5B.
[2/1/2022, 9:22:18 AM] [Ecobee Away] Loading accessory from cache: Ecobee Away
[2/1/2022, 9:22:18 AM] [Ecobee Away] Renewing auth token
[2/1/2022, 9:22:18 AM] Homebridge v1.4.0 (HAP v0.10.0) (Ecobee Away) is running on port 58070.
[2/1/2022, 9:22:19 AM] [Ecobee Away] Restoring existing accessory from cache: Ecobee Away
[2/1/2022, 10:22:19 AM] [Ecobee Away] Renewing auth token

[powellcj12]

Not unique to child bridges, I've been hitting this occasionally:

[25/06/2022, 14:28:03] Error: Request failed with status code 500
    at createError (/usr/local/lib/node_modules/homebridge-ecobee-away/node_modules/axios/lib/core/createError.js:16:15)
    at settle (/usr/local/lib/node_modules/homebridge-ecobee-away/node_modules/axios/lib/core/settle.js:17:12)
    at IncomingMessage.handleStreamEnd (/usr/local/lib/node_modules/homebridge-ecobee-away/node_modules/axios/lib/adapters/http.js:269:11)
    at IncomingMessage.emit (node:events:538:35)
    at endReadableNT (node:internal/streams/readable:1345:12)
    at processTicksAndRejections (node:internal/process/task_queues:83:21)
[25/06/2022, 14:28:03] Got SIGTERM, shutting down Homebridge...
[25/06/2022, 14:28:08] [HB Supervisor] Homebridge Process Ended. Code: 143, Signal: null
[25/06/2022, 14:28:13] [HB Supervisor] Restarting Homebridge...

axios/axios@7f12366 updating things almost a year ago, I wonder if we should consider updating? I might try it locally to see how things go.

[powellcj12]

Okay I managed to get things working with some minimal changes (see powellcj12/homebridge-ecobee-away@0f679e5) - I've got this running locally seems fine, I'll let kick the tires a bit more over the next few weeks before submitting a PR since I feel like this would be a fairly large change...

[powellcj12]

Updating to v0.72 doesn't seem to fix things, I now get this:

[26/06/2022, 09:28:05] UnhandledPromiseRejection: This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). The promise rejected with the reason "AxiosError: Request failed with status code 500".
[26/06/2022, 09:28:05] Got SIGTERM, shutting down Homebridge...
[26/06/2022, 09:28:10] [HB Supervisor] Homebridge Process Ended. Code: 143, Signal: null

I found axios/axios#4802 complaining about a similar sounding thing where there's a comment claiming this is fixed in the v1 alpha release, guess I can give this a try... de6f5f2

[powellcj12]

So running the v1 alpha itself didn't fix anything, but after poking around the code for a bit I realized some of it my stem from NodeJS itself - I was originally running 16.14.X and decided I'd try updating to the latest available 16.15.1 and since doing so haven't encountered this. It did used to be every couple hours I would see this, but after updating Node earlier this morning I haven't seen it once. So I think this might be an external issue that can be addressed with updating Node, I've downgraded axios back to the current version in package.json to try and confirm.

[gpfountz]

FYI, my homebridge is running node.js v16.15.1 and it is failing and causing a restart every 2 hours. Exactly 1 hour after homebridge starts, I see a log entry saying 'Renewing auth token'. Then exactly 1 hour later, 'Request failed with status code 500.' Thanks for all your time and effort fixing this!!

[powellcj12]

@gpfountz interesting, thanks for sharing - I did also start seeing the errors again after downgrading back to v0.21 of axios, so I've put myself back on the v1 alpha release to see if maybe it's a combination of these is needed to fix. I don't suppose you're interesting in giving it a try as well just to get more data?

[gpfountz]

sure, glad to help in anyway I can.

[powellcj12]

Well it seems like even with the alpha after updating Node I'm still seeing it again, so I'm running out of ideas...

[twennywonn]

I just wanted to chime in because I am having the same issues and a love the functionality this plugin provides. I hope someone smarter than me can figure it out.

[gmcluhan]

+1 on would really like a fix for this. Happy to test anything if needed.