Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Unhandled promise rejection: Cannot read properties of undefined (reading '_setAuthenticating') #369

Open
raintonr opened this issue Dec 8, 2022 · 6 comments
Assignees
Labels
dependencies Pull requests that update a dependency file

Comments

@raintonr
Copy link
Collaborator

raintonr commented Dec 8, 2022

I recently had some nasty stuff going on with our Miniserver which caused the ioBroker Loxone adapter to crash and get stuck in a restart loop. As a result of this restart loop, IOB disabled the adapter and when the Miniserver was fixed our system as a whole still didn't fully recover due to the Loxone adapter being disabled.

Looking at the log, the crash & restart looks like this:

2022-12-08 09:36:11.981  - ^[[32minfo^[[39m: loxone.0 (15697) Trying to connect
2022-12-08 09:36:15.156  - ^[[31merror^[[39m: loxone.0 (15697) Couldn't open socket
2022-12-08 09:36:20.157  - ^[[32minfo^[[39m: loxone.0 (15697) Trying to connect
2022-12-08 09:36:20.315  - ^[[31merror^[[39m: loxone.0 (15697) Couldn't open socket
2022-12-08 09:36:25.317  - ^[[32minfo^[[39m: loxone.0 (15697) Trying to connect
2022-12-08 09:36:25.471  - ^[[31merror^[[39m: loxone.0 (15697) Couldn't open socket
2022-12-08 09:36:30.473  - ^[[32minfo^[[39m: loxone.0 (15697) Trying to connect
2022-12-08 09:36:30.605  - ^[[31merror^[[39m: loxone.0 (15697) Couldn't open socket
2022-12-08 09:36:35.606  - ^[[32minfo^[[39m: loxone.0 (15697) Trying to connect
2022-12-08 09:36:35.610  - ^[[31merror^[[39m: loxone.0 (15697) Couldn't open socket
2022-12-08 09:36:40.612  - ^[[32minfo^[[39m: loxone.0 (15697) Trying to connect
2022-12-08 09:36:40.786  - ^[[31merror^[[39m: loxone.0 (15697) Unhandled promise rejection. 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().
2022-12-08 09:36:40.787  - ^[[31merror^[[39m: loxone.0 (15697) unhandled promise rejection: Cannot read properties of undefined (reading '_setAuthenticating')
2022-12-08 09:36:40.788  - ^[[31merror^[[39m: loxone.0 (15697) TypeError: Cannot read properties of undefined (reading '_setAuthenticating')
    at _handleBadAuthResponse (/opt/iobroker/node_modules/lxcommunicator/modules/WebSocket.js:336:14)
    at _rejected (/opt/iobroker/node_modules/q/q.js:864:24)
    at /opt/iobroker/node_modules/q/q.js:890:30
    at Promise.when (/opt/iobroker/node_modules/q/q.js:1142:31)
    at Promise.promise.promiseDispatch (/opt/iobroker/node_modules/q/q.js:808:41)
    at /opt/iobroker/node_modules/q/q.js:624:44
    at runSingle (/opt/iobroker/node_modules/q/q.js:137:13)
    at flush (/opt/iobroker/node_modules/q/q.js:125:13)
    at processTicksAndRejections (node:internal/process/task_queues:78:11)
2022-12-08 09:36:40.788  - ^[[31merror^[[39m: loxone.0 (15697) Cannot read properties of undefined (reading '_setAuthenticating')
2022-12-08 09:36:40.829  - ^[[32minfo^[[39m: loxone.0 (15697) terminating
2022-12-08 09:36:40.830  - ^[[33mwarn^[[39m: loxone.0 (15697) Terminated (UNCAUGHT_EXCEPTION): Without reason
2022-12-08 09:36:40.832  - ^[[31merror^[[39m: loxone.0 (15697) Couldn't open socket
2022-12-08 09:36:40.832  - ^[[33mwarn^[[39m: loxone.0 (15697) setTimeout called, but adapter is shutting down
2022-12-08 09:36:41.325  - ^[[31merror^[[39m: loxone.0 (15697) Couldn't upload structure file attachment to sentry: Error: Request failed with status code 403
2022-12-08 09:36:41.594  - ^[[31merror^[[39m: host.pl.mh Caught by controller[1]: Could not acquire a token! {"user":"api","code":412,"value":{"lastEdit":"2009-01-01 01:00:00","unix":1230768000}}
2022-12-08 09:36:41.594  - ^[[31merror^[[39m: host.pl.mh Caught by controller[2]: 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:
2022-12-08 09:36:41.595  - ^[[31merror^[[39m: host.pl.mh Caught by controller[3]: TypeError: Cannot read properties of undefined (reading '_setAuthenticating')
2022-12-08 09:36:41.595  - ^[[31merror^[[39m: host.pl.mh Caught by controller[3]:     at _handleBadAuthResponse (/opt/iobroker/node_modules/lxcommunicator/modules/WebSocket.js:336:14)
2022-12-08 09:36:41.595  - ^[[31merror^[[39m: host.pl.mh Caught by controller[3]:     at _rejected (/opt/iobroker/node_modules/q/q.js:864:24)
2022-12-08 09:36:41.595  - ^[[31merror^[[39m: host.pl.mh Caught by controller[3]:     at /opt/iobroker/node_modules/q/q.js:890:30
2022-12-08 09:36:41.596  - ^[[31merror^[[39m: host.pl.mh Caught by controller[3]:     at Promise.when (/opt/iobroker/node_modules/q/q.js:1142:31)
2022-12-08 09:36:41.596  - ^[[31merror^[[39m: host.pl.mh Caught by controller[3]:     at Promise.promise.promiseDispatch (/opt/iobroker/node_modules/q/q.js:808:41)
2022-12-08 09:36:41.596  - ^[[31merror^[[39m: host.pl.mh Caught by controller[3]:     at /opt/iobroker/node_modules/q/q.js:624:44
2022-12-08 09:36:41.596  - ^[[31merror^[[39m: host.pl.mh Caught by controller[3]:     at runSingle (/opt/iobroker/node_modules/q/q.js:137:13)
2022-12-08 09:36:41.596  - ^[[31merror^[[39m: host.pl.mh Caught by controller[3]:     at flush (/opt/iobroker/node_modules/q/q.js:125:13)
2022-12-08 09:36:41.596  - ^[[31merror^[[39m: host.pl.mh Caught by controller[3]:     at processTicksAndRejections (node:internal/process/task_queues:78:11)
2022-12-08 09:36:41.597  - ^[[31merror^[[39m: host.pl.mh Caught by controller[4]: WebSocket:  socket failed! WS Close Code: -unknown-
2022-12-08 09:36:41.597  - ^[[31merror^[[39m: host.pl.mh instance system.adapter.loxone.0 terminated with code 6 (UNCAUGHT_EXCEPTION)
2022-12-08 09:36:41.598  - ^[[32minfo^[[39m: host.pl.mh Restart adapter system.adapter.loxone.0 because enabled
2022-12-08 09:37:11.783  - ^[[32minfo^[[39m: host.pl.mh instance system.adapter.loxone.0 started with pid 7612

This exception needs catching and the connection attempt retried rather than letting the Loxone adapter die.

@raintonr
Copy link
Collaborator Author

raintonr commented Dec 8, 2022

Can't see anything immediately obvious but noticed something probably unrelated: In the catch below there should be a this.socket.close(); before this.reconnect();. It's like this in the other catch blocks after the socket is successfully opened and probably forgotten here:

        let file: StructureFile;
        try {
            const fileString = await this.socket.send('data/LoxAPP3.json');
            file = JSON.parse(fileString);
        } catch (error) {
            // do not stringify error, it can contain circular references
            this.log.error(`Couldn't get structure file`);
            this.reconnect();
            return false;
        }

@DreDaPro
Copy link

DreDaPro commented Feb 1, 2023

looking for help!

host.IoBroker 2023-01-31 23:34:38.430 info "system.adapter.loxone.0" disabled
host.IoBroker 2023-01-31 23:34:38.307 info Restart adapter system.adapter.loxone.0 because enabled
host.IoBroker 2023-01-31 23:34:38.306 error instance system.adapter.loxone.0 terminated with code 6 (UNCAUGHT_EXCEPTION)
host.IoBroker 2023-01-31 23:34:38.306 error Caught by controller[2]: at processTicksAndRejections (node:internal/process/task_queues:78:11)
host.IoBroker 2023-01-31 23:34:38.306 error Caught by controller[2]: at flush (/opt/iobroker/node_modules/q/q.js:125:13)
host.IoBroker 2023-01-31 23:34:38.306 error Caught by controller[2]: at runSingle (/opt/iobroker/node_modules/q/q.js:137:13)
host.IoBroker 2023-01-31 23:34:38.306 error Caught by controller[2]: at /opt/iobroker/node_modules/q/q.js:624:44
host.IoBroker 2023-01-31 23:34:38.306 error Caught by controller[2]: at Promise.promise.promiseDispatch (/opt/iobroker/node_modules/q/q.js:808:41)
host.IoBroker 2023-01-31 23:34:38.306 error Caught by controller[2]: at Promise.when (/opt/iobroker/node_modules/q/q.js:1142:31)
host.IoBroker 2023-01-31 23:34:38.306 error Caught by controller[2]: at /opt/iobroker/node_modules/q/q.js:890:30
host.IoBroker 2023-01-31 23:34:38.306 error Caught by controller[2]: at _rejected (/opt/iobroker/node_modules/q/q.js:864:24)
host.IoBroker 2023-01-31 23:34:38.306 error Caught by controller[2]: at _handleBadAuthResponse (/opt/iobroker/node_modules/lxcommunicator/modules/WebSocket.js:336:14)
host.IoBroker 2023-01-31 23:34:38.306 error Caught by controller[2]: TypeError: Cannot read properties of undefined (reading '_setAuthenticating')
host.IoBroker 2023-01-31 23:34:38.305 error Caught by controller[1]: 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:
host.IoBroker 2023-01-31 23:34:38.305 error Caught by controller[0]: WebSocket: socket failed! WS Close Code: 1006
loxone.0 2023-01-31 23:34:37.761 warn Terminated (UNCAUGHT_EXCEPTION): Without reason
loxone.0 2023-01-31 23:34:37.759 info terminating
loxone.0 2023-01-31 23:34:37.744 error Cannot read properties of undefined (reading '_setAuthenticating')
loxone.0 2023-01-31 23:34:37.744 error TypeError: Cannot read properties of undefined (reading '_setAuthenticating') at _handleBadAuthResponse (/opt/iobroker/node_modules/lxcommunicator/modules/WebSocket.js:336:14) at _rejected (/opt/iobroker/node_modules/q/q.js:864:24) at /opt/iobroker/node_modules/q/q.js:890:30 at Promise.when (/opt/iobroker/node_modules/q/q.js:1142:31) at Promise.promise.promiseDispatch (/opt/iobroker/node_modules/q/q.js:808:41) at /opt/iobroker/node_modules/q/q.js:624:44 at runSingle (/opt/iobroker/node_modules/q/q.js:137:13) at flush (/opt/iobroker/node_modules/q/q.js:125:13) at processTicksAndRejections (node:internal/process/task_queues:78:11)
loxone.0 2023-01-31 23:34:37.743 error unhandled promise rejection: Cannot read properties of undefined (reading '_setAuthenticating')
loxone.0 2023-01-31 23:34:37.743 error Unhandled promise rejection. 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().
loxone.0 2023-01-31 23:34:37.738 error Couldn't open socket
loxone.0 2023-01-31 23:34:37.618 info Trying to connect
loxone.0 2023-01-31 23:34:37.541 info starting. Version 3.0.0 in /opt/iobroker/node_modules/iobroker.loxone, node: v16.19.0, js-controller: 4.0.24

@raintonr raintonr self-assigned this Mar 12, 2023
@raintonr
Copy link
Collaborator Author

I suspect this will be solved with changed being made for #298.

@raintonr
Copy link
Collaborator Author

I suspect this will be solved with changed being made for #298.

Sadly not. I was able to reproduce this even after #298 seems fixed by physically pulling the LAN cable during a reconnect. Hmmmmm...

@raintonr
Copy link
Collaborator Author

See Loxone/lxcommunicator#21

@raintonr
Copy link
Collaborator Author

Awaiting merge in upstream Loxone/lxcommunicator#22

@raintonr raintonr added the dependencies Pull requests that update a dependency file label Mar 16, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
dependencies Pull requests that update a dependency file
Projects
None yet
Development

No branches or pull requests

2 participants