zachowj / node-red-contrib-home-assistant-websocket

Node-RED integration with Home Assistant
https://zachowj.github.io/node-red-contrib-home-assistant-websocket/
MIT License
506 stars 97 forks source link

Daily crash of addon #1451

Open johntdyer opened 3 months ago

johntdyer commented 3 months ago

Describe the bug

About once a day the add-on crashes and the watchdog doesn't seem to trigger a restart, seems to have started w/ Home Assistant: 2024.07.00

To Reproduce

Start it, wait and watch for crash

Expected behavior

Crashes to not happen daily

Screenshots

No response

Example Flow

No response

Environment Information

Node-Red Addon - : 18.0.4 HassOS: 2024-07-03 Supervisor: 2024.07.00

Additional context

s6-rc: info: service init-nodered: starting
s6-rc: info: service init-nginx successfully started

up to date, audited 407 packages in 3s

81 packages are looking for funding
  run `npm fund` for details

28 vulnerabilities (20 moderate, 6 high, 2 critical)

To address issues that do not require attention, run:
  npm audit fix

To address all issues possible (including breaking changes), run:
  npm audit fix --force

Some issues need review, and may require choosing
a different dependency.

Run `npm audit` for details.
npm notice
npm notice New minor version of npm available! 10.7.0 -> 10.8.2
npm notice Changelog: https://github.com/npm/cli/releases/tag/v10.8.2
npm notice To update run: npm install -g npm@10.8.2
npm notice
s6-rc: info: service init-nodered successfully started
s6-rc: info: service nodered: starting
s6-rc: info: service nodered successfully started
s6-rc: info: service nginx: starting
s6-rc: info: service nginx successfully started
s6-rc: info: service legacy-services: starting
[00:32:46] INFO: Starting Node-RED...
s6-rc: info: service legacy-services successfully started

> start
> node $NODE_OPTIONS node_modules/node-red/red.js --settings /etc/node-red/config.js

26 Jul 00:32:47 - [info] 

Welcome to Node-RED
===================

26 Jul 00:32:47 - [info] Node-RED version: v4.0.2
26 Jul 00:32:47 - [info] Node.js  version: v18.20.3
26 Jul 00:32:47 - [info] Linux 6.6.33-haos x64 LE
26 Jul 00:32:47 - [info] Loading palette nodes
26 Jul 00:32:48 - [info] Node-RED Contrib Theme Collection version: v4.0.4
26 Jul 00:32:50 - [info] Dashboard version 3.6.5 started at /endpoint/ui
26 Jul 00:32:50 - [info] Settings file  : /etc/node-red/config.js
26 Jul 00:32:50 - [info] Context store  : 'default' [module=memory]
26 Jul 00:32:50 - [info] User directory : /config/
26 Jul 00:32:50 - [warn] Projects disabled : editorTheme.projects.enabled=false
26 Jul 00:32:50 - [info] Flows file     : /config/flows.json
26 Jul 00:32:50 - [info] Server now running at http://127.0.0.1:46836/
26 Jul 00:32:50 - [info] Starting flows
26 Jul 00:32:50 - [error] [mqtt out:118db764.b6fe21] missing broker configuration
26 Jul 00:32:50 - [error] [mqtt in:6f09dcc604075a1c] missing broker configuration
[00:32:51] INFO: Starting NGinx...
26 Jul 00:32:51 - [info] Started flows
26 Jul 00:32:55 - [info] [server:Home Assistant] Connecting to http://supervisor/core
26 Jul 00:32:55 - [info] [server:Home Assistant] Connected to http://supervisor/core
26 Jul 00:34:59 - [error] [function:Update global] TypeError: Cannot read properties of undefined (reading 'find')
26 Jul 00:35:18 - [info] [server:Home Assistant] Connection closed to http://supervisor/core
26 Jul 00:35:18 - [error] [ha-api:Entities] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Jul 00:35:18 - [error] [ha-api:Entities] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Jul 00:35:18 - [error] [ha-api:Entities] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Jul 00:35:18 - [error] [ha-api:Entities] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Jul 00:35:18 - [error] [ha-api:Entities] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Jul 00:35:18 - [error] [ha-api:Entities] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Jul 00:35:18 - [error] [ha-api:Entities] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Jul 00:35:18 - [error] [ha-api:Entities] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Jul 00:35:18 - [error] [ha-api:Entities] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Jul 00:35:18 - [error] [ha-api:Entities] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Jul 00:35:18 - [error] [ha-api:Entities] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Jul 00:35:18 - [error] [ha-api:Entities] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Jul 00:35:18 - [red] Uncaught Exception:
26 Jul 00:35:18 - [error] 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 "#<Object>".
[00:35:18] INFO: Service Node-RED exited with code 1 (by signal 0)
s6-rc: info: service legacy-services: stopping
s6-rc: info: service legacy-services successfully stopped
s6-rc: info: service nginx: stopping
[00:35:18] INFO: Service NGINX exited with code 0 (by signal 0)
s6-rc: info: service nginx successfully stopped
s6-rc: info: service init-nginx: stopping
s6-rc: info: service nodered: stopping
s6-rc: info: service nodered successfully stopped
s6-rc: info: service init-nodered: stopping
s6-rc: info: service init-nginx successfully stopped
s6-rc: info: service init-nodered successfully stopped
s6-rc: info: service init-customizations: stopping
s6-rc: info: service init-customizations successfully stopped
s6-rc: info: service legacy-cont-init: stopping
s6-rc: info: service legacy-cont-init successfully stopped
s6-rc: info: service fix-attrs: stopping
s6-rc: info: service base-addon-log-level: stopping
s6-rc: info: service fix-attrs successfully stopped
s6-rc: info: service base-addon-log-level successfully stopped
s6-rc: info: service base-addon-banner: stopping
s6-rc: info: service base-addon-banner successfully stopped
s6-rc: info: service s6rc-oneshot-runner: stopping
s6-rc: info: service s6rc-oneshot-runner successfully stopped

Supervisor logs

2024-07-26 00:29:55.175 INFO (MainThread) [supervisor.docker.addon] Starting Docker add-on ccab4aaf/amd64-addon-frigate-proxy with version 1.5
2024-07-26 00:30:21.428 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API error: Cannot proxy websocket message of unsupported type: 258
2024-07-26 00:30:21.429 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API for a0d7b954_nodered closed
2024-07-26 00:30:25.111 WARNING (MainThread) [supervisor.addons.addon] Watchdog found addon Node-RED is failed, restarting...
2024-07-26 00:30:25.116 INFO (SyncWorker_12) [supervisor.docker.manager] Cleaning addon_a0d7b954_nodered application
2024-07-26 00:30:25.375 INFO (MainThread) [supervisor.docker.addon] Starting Docker add-on ghcr.io/hassio-addons/node-red/amd64 with version 18.0.4
2024-07-26 00:30:41.864 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API request initialize
2024-07-26 00:30:41.874 INFO (MainThread) [supervisor.api.proxy] WebSocket access from a0d7b954_nodered
2024-07-26 00:30:41.916 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API request running
2024-07-26 00:31:58.273 WARNING (MainThread) [supervisor.misc.tasks] Watchdog missing application response from ccab4aaf_frigate-proxy
2024-07-26 00:32:39.000 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API error: Cannot proxy websocket message of unsupported type: 258
2024-07-26 00:32:39.001 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API for a0d7b954_nodered closed
2024-07-26 00:32:42.282 WARNING (MainThread) [supervisor.addons.addon] Watchdog found addon Node-RED is failed, restarting...
2024-07-26 00:32:42.286 INFO (SyncWorker_1) [supervisor.docker.manager] Cleaning addon_a0d7b954_nodered application
2024-07-26 00:32:42.550 INFO (MainThread) [supervisor.docker.addon] Starting Docker add-on ghcr.io/hassio-addons/node-red/amd64 with version 18.0.4
2024-07-26 00:32:55.917 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API request initialize
2024-07-26 00:32:55.927 INFO (MainThread) [supervisor.api.proxy] WebSocket access from a0d7b954_nodered
2024-07-26 00:32:55.931 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API request running
2024-07-26 00:34:01.345 WARNING (MainThread) [supervisor.misc.tasks] Watchdog found a problem with ccab4aaf_frigate-proxy application!
2024-07-26 00:34:01.352 INFO (SyncWorker_12) [supervisor.docker.manager] Stopping addon_ccab4aaf_frigate-proxy application
2024-07-26 00:34:01.769 INFO (SyncWorker_12) [supervisor.docker.manager] Cleaning addon_ccab4aaf_frigate-proxy application
2024-07-26 00:34:02.165 INFO (MainThread) [supervisor.docker.addon] Starting Docker add-on ccab4aaf/amd64-addon-frigate-proxy with version 1.5
2024-07-26 00:34:42.525 WARNING (MainThread) [supervisor.addons.options] Unknown option 'desc' for Network UPS Tools (a0d7b954_nut)
2024-07-26 00:34:42.525 WARNING (MainThread) [supervisor.addons.options] Unknown option 'snmp_version' for Network UPS Tools (a0d7b954_nut)
2024-07-26 00:34:42.525 WARNING (MainThread) [supervisor.addons.options] Unknown option 'mibs' for Network UPS Tools (a0d7b954_nut)
2024-07-26 00:34:42.525 WARNING (MainThread) [supervisor.addons.options] Unknown option 'pollinterval' for Network UPS Tools (a0d7b954_nut)
2024-07-26 00:34:42.525 WARNING (MainThread) [supervisor.addons.options] Unknown option 'upsmon_deadtime' for Network UPS Tools (a0d7b954_nut)
2024-07-26 00:35:18.029 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API error: Cannot proxy websocket message of unsupported type: 258
2024-07-26 00:35:18.029 INFO (MainThread) [supervisor.api.proxy] Home Assistant WebSocket API for a0d7b954_nodered closed
2024-07-26 00:35:21.488 ERROR (MainThread) [asyncio] Task exception was never retrieved
future: <Task finished name='Task-95945' coro=<Addon.watchdog_container() done, defined at /usr/src/supervisor/supervisor/addons/addon.py:1429> exception=AddonsJobError('Rate limit exceeded, more than 10 calls in 0:30:00')>
Traceback (most recent call last):
  File "/usr/src/supervisor/supervisor/addons/addon.py", line 1443, in watchdog_container
    await self._restart_after_problem(event.state)
  File "/usr/src/supervisor/supervisor/jobs/decorator.py", line 290, in wrapper
    raise on_condition(
supervisor.exceptions.AddonsJobError: Rate limit exceeded, more than 10 calls in 0:30:00
2024-07-26 00:36:05.249 WARNING (MainThread) [supervisor.misc.tasks] Watchdog missing application response from ccab4aaf_frigate-proxy
2024-07-26 00:38:08.321 WARNING (MainThread) [supervisor.misc.tasks] Watchdog found a problem with ccab4aaf_frigate-proxy application!
2024-07-26 00:38:08.330 INFO (SyncWorker_8) [supervisor.docker.manager] Stopping addon_ccab4aaf_frigate-proxy application
2024-07-26 00:38:08.800 INFO (SyncWorker_8) [supervisor.docker.manager] Cleaning addon_ccab4aaf_frigate-proxy application
2024-07-26 00:38:09.266 INFO (MainThread) [supervisor.docker.addon] Starting Docker add-on ccab4aaf/amd64-addon-frigate-proxy with version 1.5

Forked from https://github.com/hassio-addons/addon-node-red/issues/1917

zachowj commented 3 months ago

To narrow down the UnhandledPromiseRejection can you add the following code to your settings.js file to help capture a better description of the error? This can removed once the error happens.

process.on('unhandledRejection', (reason, p) => {
  console.log('Unhandled Rejection: ', p, 'reason:', reason);
});

Secondly, you can connect directly to Node-RED and not through the Home Assistant proxy. https://zachowj.github.io/node-red-contrib-home-assistant-websocket/guide/#configuration

johntdyer commented 3 months ago

Thank you for getting back to me... QQ though re: your request... how do I make this change to node-red given its running as a container as an add-on? Wont any change be lost as soon as I restart the process?

-John

On Jul 27, 2024, at 9:04 PM, Jason @.***> wrote:

To narrow down the UnhandledPromiseRejection can you add the following code to your settings.js file to help capture a better description of the error? This can removed once the error happens.

process.on('unhandledRejection', (reason, p) => { console.log('Unhandled Rejection: ', p, 'reason:', reason); }); Secondly, you can connect directly to Node-RED and not through the Home Assistant proxy. https://zachowj.github.io/node-red-contrib-home-assistant-websocket/guide/#configuration

— Reply to this email directly, view it on GitHub https://github.com/zachowj/node-red-contrib-home-assistant-websocket/issues/1451#issuecomment-2254300285, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAAOG6QDOXKONK6TE35RVDLZOQ7QVAVCNFSM6AAAAABLSEZHAGVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDENJUGMYDAMRYGU. You are receiving this because you authored the thread.

johntdyer commented 3 months ago

Actually I think I found it in ~/addon_configs/a0d7b954_nodered

here is the file after editing, I assume this is at the right scope within this module ?


process.on('unhandledRejection', (reason, p) => {
  console.log('Unhandled Rejection: ', p, 'reason:', reason);
});

module.exports = {
  mqttReconnectTime: 15000,
  serialReconnectTime: 15000,

  functionGlobalContext: {
    // os:require('os'),
    // jfive:require("johnny-five"),
    // j5board:require("johnny-five").Board({repl:false})
  },

  paletteCategories: [
    "home_assistant",
    "subflows",
    "common",
    "function",
    "network",
    "sequence",
    "parser",
    "storage",
  ],

  logging: {
    console: {
      metrics: false,
      audit: false,
    },
  },

  editorTheme: {
    projects: {
      enabled: false,
    },
  },
};
zachowj commented 3 months ago

here is the file after editing, I assume this is at the right scope within this module ?

correct

Opisek commented 3 months ago

Have you narrowed it down? I am experiencing the same connection lost error everyday at the same time.

Opisek commented 3 months ago

I managed to fix it, not sure if the core problem is the same for everyone. I used to access Home Assistant only through my public domain and public IP address. That IP address was internally routed back to my server without leaving the local network. Still, the IP changed every night.

It seems that node-red doesn't get notifiied or doesn't act upon losing connection with Home Assistant that way. Only once an automation later on actiively tries to reach Home Assistant (for me my wake-up automation), does node-red get an error communicating with Home Assistant. On the next request, node-red will connect to the correct IP again.

I solved it by setting up a local PKI with self-signed root certificate and connecting node-red to Home Assistant via a local domain and IP address instead. Hope this helps.

frenck commented 1 month ago

This issue is currently blocking further updates and releases of the add-on version of Node-RED.

This is in the logs (default settings, use add-on environment to connect to the server)

30 Sep 20:17:32 - [info] [server:Home Assistant] Connecting to http://supervisor/core
30 Sep 20:17:32 - [info] [server:Home Assistant] Connected to http://supervisor/core
30 Sep 20:17:32 - [red] Uncaught Exception:
30 Sep 20:17:32 - [error] 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 "#<Object>".

Adding the debug code you gave above, it comes out with:

30 Sep 20:23:02 - [info] [server:Home Assistant] Connecting to http://supervisor/core
30 Sep 20:23:02 - [info] [server:Home Assistant] Connected to http://supervisor/core
Unhandled Rejection:  Promise {
  <rejected> { code: 'unknown_command', message: 'Unknown command.' }
} reason: { code: 'unknown_command', message: 'Unknown command.' }
Unhandled Rejection:  Promise {
  <rejected> { code: 'unknown_command', message: 'Unknown command.' }
} reason: { code: 'unknown_command', message: 'Unknown command.' }

Please note, I test against an older HA to ensure compatibility there as well: 2024.1.0.dev20231213

Will migrate that test instance to see if it makes a difference.

Edit: Nevermind, issue unrelated to this one... 🤦 Ignore me.