search

yenoiwesa / homebridge-connexoon

A homebridge plugin to integrate Somfy blinds with the Connexoon RTS hub
Apache License 2.0
26 stars 2 forks source link

Connexoon plugin causing sometimes Homebridge shutdown #45

Closed Kositch closed 2 years ago

Kositch commented 2 years ago

Hello,

not sure, what can cause this, but sometimes (lets say 3x/week) Connexoon plugin logs some errors (see below) which results in Homebridge shutting down (SIGTERM command). When this happens Homebridge stucks up in "Starting" state and I need to reboot whole server. It started happening since last Connexoon update to 2.1.2:

[10/03/2022, 07:07:16] [Connexoon] Get Obyvak current position success: 0
[10/03/2022, 07:07:16] [Connexoon] Get Obyvak target position success: 0
[10/03/2022, 07:07:16] [Connexoon] Get Loznice current position success: 0
[10/03/2022, 07:07:16] [Connexoon] Get Loznice target position success: 0
[10/03/2022, 07:07:16] [Connexoon] Get Pracovna current position success: 0
[10/03/2022, 07:07:16] [Connexoon] Get Pracovna target position success: 0
[10/03/2022, 07:07:16] [Connexoon] Get Pokojicek current position success: 0
[10/03/2022, 07:07:16] [Connexoon] Get Pokojicek target position success: 0
[10/03/2022, 07:07:16] [Connexoon] Get Hosti current position success: 0
[10/03/2022, 07:07:16] [Connexoon] Get Hosti target position success: 0
[10/03/2022, 07:07:34] [Connexoon] Failed to get the list of events {
  errorCode: 'RESOURCE_ACCESS_DENIED',
  error: 'invalid authentication server response'
}
[10/03/2022, 07:07:34] StatusCodeError: 401 - {"errorCode":"RESOURCE_ACCESS_DENIED","error":"invalid authentication server response"}
    at new StatusCodeError (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request-promise-core/lib/errors.js:32:15)
    at Request.plumbing.callback (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request-promise-core/lib/plumbing.js:104:33)
    at Request.RP$callback [as _callback] (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request-promise-core/lib/plumbing.js:46:31)
    at Request.self.callback (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request/request.js:185:22)
    at Request.emit (node:events:390:28)
    at Request.<anonymous> (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request/request.js:1154:10)
    at Request.emit (node:events:390:28)
    at IncomingMessage.<anonymous> (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request/request.js:1076:12)
    at Object.onceWrapper (node:events:509:28)
    at IncomingMessage.emit (node:events:402:35)
    at endReadableNT (node:internal/streams/readable:1343:12)
    at processTicksAndRejections (node:internal/process/task_queues:83:21)
[10/03/2022, 07:07:34] StatusCodeError: 401 - {"errorCode":"RESOURCE_ACCESS_DENIED","error":"invalid authentication server response"}
    at new StatusCodeError (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request-promise-core/lib/errors.js:32:15)
    at Request.plumbing.callback (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request-promise-core/lib/plumbing.js:104:33)
    at Request.RP$callback [as _callback] (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request-promise-core/lib/plumbing.js:46:31)
    at Request.self.callback (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request/request.js:185:22)
    at Request.emit (node:events:390:28)
    at Request.<anonymous> (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request/request.js:1154:10)
    at Request.emit (node:events:390:28)
    at IncomingMessage.<anonymous> (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request/request.js:1076:12)
    at Object.onceWrapper (node:events:509:28)
    at IncomingMessage.emit (node:events:402:35)
    at endReadableNT (node:internal/streams/readable:1343:12)
    at processTicksAndRejections (node:internal/process/task_queues:83:21)
[10/03/2022, 07:07:34] StatusCodeError: 401 - {"errorCode":"RESOURCE_ACCESS_DENIED","error":"invalid authentication server response"}
    at new StatusCodeError (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request-promise-core/lib/errors.js:32:15)
    at Request.plumbing.callback (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request-promise-core/lib/plumbing.js:104:33)
    at Request.RP$callback [as _callback] (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request-promise-core/lib/plumbing.js:46:31)
    at Request.self.callback (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request/request.js:185:22)
    at Request.emit (node:events:390:28)
    at Request.<anonymous> (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request/request.js:1154:10)
    at Request.emit (node:events:390:28)
    at IncomingMessage.<anonymous> (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request/request.js:1076:12)
    at Object.onceWrapper (node:events:509:28)
    at IncomingMessage.emit (node:events:402:35)
    at endReadableNT (node:internal/streams/readable:1343:12)
    at processTicksAndRejections (node:internal/process/task_queues:83:21)
[10/03/2022, 07:07:34] StatusCodeError: 401 - {"errorCode":"RESOURCE_ACCESS_DENIED","error":"invalid authentication server response"}
    at new StatusCodeError (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request-promise-core/lib/errors.js:32:15)
    at Request.plumbing.callback (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request-promise-core/lib/plumbing.js:104:33)
    at Request.RP$callback [as _callback] (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request-promise-core/lib/plumbing.js:46:31)
    at Request.self.callback (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request/request.js:185:22)
    at Request.emit (node:events:390:28)
    at Request.<anonymous> (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request/request.js:1154:10)
    at Request.emit (node:events:390:28)
    at IncomingMessage.<anonymous> (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request/request.js:1076:12)
    at Object.onceWrapper (node:events:509:28)
    at IncomingMessage.emit (node:events:402:35)
    at endReadableNT (node:internal/streams/readable:1343:12)
    at processTicksAndRejections (node:internal/process/task_queues:83:21)
[10/03/2022, 07:07:34] StatusCodeError: 401 - {"errorCode":"RESOURCE_ACCESS_DENIED","error":"invalid authentication server response"}
    at new StatusCodeError (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request-promise-core/lib/errors.js:32:15)
    at Request.plumbing.callback (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request-promise-core/lib/plumbing.js:104:33)
    at Request.RP$callback [as _callback] (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request-promise-core/lib/plumbing.js:46:31)
    at Request.self.callback (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request/request.js:185:22)
    at Request.emit (node:events:390:28)
    at Request.<anonymous> (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request/request.js:1154:10)
    at Request.emit (node:events:390:28)
    at IncomingMessage.<anonymous> (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request/request.js:1076:12)
    at Object.onceWrapper (node:events:509:28)
    at IncomingMessage.emit (node:events:402:35)
    at endReadableNT (node:internal/streams/readable:1343:12)
    at processTicksAndRejections (node:internal/process/task_queues:83:21)
[10/03/2022, 07:07:34] StatusCodeError: 401 - {"errorCode":"RESOURCE_ACCESS_DENIED","error":"invalid authentication server response"}
    at new StatusCodeError (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request-promise-core/lib/errors.js:32:15)
    at Request.plumbing.callback (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request-promise-core/lib/plumbing.js:104:33)
    at Request.RP$callback [as _callback] (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request-promise-core/lib/plumbing.js:46:31)
    at Request.self.callback (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request/request.js:185:22)
    at Request.emit (node:events:390:28)
    at Request.<anonymous> (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request/request.js:1154:10)
    at Request.emit (node:events:390:28)
    at IncomingMessage.<anonymous> (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request/request.js:1076:12)
    at Object.onceWrapper (node:events:509:28)
    at IncomingMessage.emit (node:events:402:35)
    at endReadableNT (node:internal/streams/readable:1343:12)
    at processTicksAndRejections (node:internal/process/task_queues:83:21)
[10/03/2022, 07:07:34] StatusCodeError: 401 - {"errorCode":"RESOURCE_ACCESS_DENIED","error":"invalid authentication server response"}
    at new StatusCodeError (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request-promise-core/lib/errors.js:32:15)
    at Request.plumbing.callback (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request-promise-core/lib/plumbing.js:104:33)
    at Request.RP$callback [as _callback] (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request-promise-core/lib/plumbing.js:46:31)
    at Request.self.callback (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request/request.js:185:22)
    at Request.emit (node:events:390:28)
    at Request.<anonymous> (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request/request.js:1154:10)
    at Request.emit (node:events:390:28)
    at IncomingMessage.<anonymous> (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request/request.js:1076:12)
    at Object.onceWrapper (node:events:509:28)
    at IncomingMessage.emit (node:events:402:35)
    at endReadableNT (node:internal/streams/readable:1343:12)
    at processTicksAndRejections (node:internal/process/task_queues:83:21)
[10/03/2022, 07:07:34] StatusCodeError: 401 - {"errorCode":"RESOURCE_ACCESS_DENIED","error":"invalid authentication server response"}
    at new StatusCodeError (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request-promise-core/lib/errors.js:32:15)
    at Request.plumbing.callback (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request-promise-core/lib/plumbing.js:104:33)
    at Request.RP$callback [as _callback] (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request-promise-core/lib/plumbing.js:46:31)
    at Request.self.callback (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request/request.js:185:22)
    at Request.emit (node:events:390:28)
    at Request.<anonymous> (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request/request.js:1154:10)
    at Request.emit (node:events:390:28)
    at IncomingMessage.<anonymous> (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request/request.js:1076:12)
    at Object.onceWrapper (node:events:509:28)
    at IncomingMessage.emit (node:events:402:35)
    at endReadableNT (node:internal/streams/readable:1343:12)
    at processTicksAndRejections (node:internal/process/task_queues:83:21)
[10/03/2022, 07:07:34] StatusCodeError: 401 - {"errorCode":"RESOURCE_ACCESS_DENIED","error":"invalid authentication server response"}
    at new StatusCodeError (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request-promise-core/lib/errors.js:32:15)
    at Request.plumbing.callback (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request-promise-core/lib/plumbing.js:104:33)
    at Request.RP$callback [as _callback] (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request-promise-core/lib/plumbing.js:46:31)
    at Request.self.callback (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request/request.js:185:22)
    at Request.emit (node:events:390:28)
    at Request.<anonymous> (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request/request.js:1154:10)
    at Request.emit (node:events:390:28)
    at IncomingMessage.<anonymous> (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request/request.js:1076:12)
    at Object.onceWrapper (node:events:509:28)
    at IncomingMessage.emit (node:events:402:35)
    at endReadableNT (node:internal/streams/readable:1343:12)
    at processTicksAndRejections (node:internal/process/task_queues:83:21)
[10/03/2022, 07:07:34] StatusCodeError: 401 - {"errorCode":"RESOURCE_ACCESS_DENIED","error":"invalid authentication server response"}
    at new StatusCodeError (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request-promise-core/lib/errors.js:32:15)
    at Request.plumbing.callback (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request-promise-core/lib/plumbing.js:104:33)
    at Request.RP$callback [as _callback] (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request-promise-core/lib/plumbing.js:46:31)
    at Request.self.callback (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request/request.js:185:22)
    at Request.emit (node:events:390:28)
    at Request.<anonymous> (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request/request.js:1154:10)
    at Request.emit (node:events:390:28)
    at IncomingMessage.<anonymous> (/usr/local/lib/node_modules/homebridge-connexoon/node_modules/request/request.js:1076:12)
    at Object.onceWrapper (node:events:509:28)
    at IncomingMessage.emit (node:events:402:35)
    at endReadableNT (node:internal/streams/readable:1343:12)
    at processTicksAndRejections (node:internal/process/task_queues:83:21)
[10/03/2022, 07:07:34] Got SIGTERM, shutting down Homebridge...

Any ideas what can cause this and how to prevent it from shutting down the HB server?

Kositch commented 2 years ago

I also dont know, why it is sometimes logging so often, see example:

[10/03/2022, 08:20:20] [Connexoon] Get Pokojicek current position success: 0
[10/03/2022, 08:20:20] [Connexoon] Get Pokojicek target position success: 0
[10/03/2022, 08:20:20] [Connexoon] Get Obyvak current position success: 0
[10/03/2022, 08:20:20] [Connexoon] Get Obyvak target position success: 0
[10/03/2022, 08:20:20] [Connexoon] Get Pracovna current position success: 0
[10/03/2022, 08:20:20] [Connexoon] Get Pracovna target position success: 0
[10/03/2022, 08:20:20] [Connexoon] Get Hosti current position success: 0
[10/03/2022, 08:20:20] [Connexoon] Get Hosti target position success: 0
[10/03/2022, 08:20:20] [Connexoon] Get Loznice current position success: 0
[10/03/2022, 08:20:20] [Connexoon] Get Loznice target position success: 0
[10/03/2022, 08:20:52] [Connexoon] Get Pokojicek target position success: 0
[10/03/2022, 08:20:52] [Connexoon] Get Pokojicek current position success: 0
[10/03/2022, 08:20:52] [Connexoon] Get Obyvak current position success: 0
[10/03/2022, 08:20:52] [Connexoon] Get Obyvak target position success: 0
[10/03/2022, 08:20:52] [Connexoon] Get Pracovna target position success: 0
[10/03/2022, 08:20:52] [Connexoon] Get Pracovna current position success: 0
[10/03/2022, 08:20:52] [Connexoon] Get Hosti target position success: 0
[10/03/2022, 08:20:52] [Connexoon] Get Hosti current position success: 0
[10/03/2022, 08:20:52] [Connexoon] Get Loznice target position success: 0
[10/03/2022, 08:20:52] [Connexoon] Get Loznice current position success: 0
yenoiwesa commented 2 years ago

Hi @Kositch,

~To answer your second question, these are debug level logs, any reason why you are running Homebridge in debug mode?~ I am wrong here, these are info logs. I can look at reducing the logging level for these.

Then for the error stopping the server, it's because you must be running a recent version of node JS that throws on uncaught promise. I should fix that to properly catch errors. I will have a look when time allows.

Thanks for the report!

Kositch commented 2 years ago

Thanks, it would be great to reduce logging level of those - they are not important for me and it is flooding the log of HB. For main issue - yes I am running v16.13.2 Node JS and thanks if you would be able fix that.

yenoiwesa commented 2 years ago

Done and done @Kositch, I had added proper exception handling everywhere except for the background polling updates. This has been added now and the logging level of these GET state events has been reduced to debug.

You can install version 2.1.3 of the plugin that includes these fixes.

Closing this ticket, but let me know if you are still experiencing the issue.

Kositch commented 2 years ago

Thanks a lot! Already updated, will let you know if some issues appear.

S pozdravem Ing. Michal Srna

Fotografické portfolio: michalsrna.cz

13. 3. 2022 v 5:42, Matthieu Di Berardino @.***>:

 Closed #45.

— Reply to this email directly, view it on GitHub, or unsubscribe. Triage notifications on the go with GitHub Mobile for iOS or Android. You are receiving this because you were mentioned.