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

[raintonr]

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]

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]

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]

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

[raintonr]

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]

See https://github.com/Loxone/lxcommunicator/issues/21

[raintonr]

Awaiting merge in upstream https://github.com/Loxone/lxcommunicator/pull/22