Connection between HA and Node Red keep Resetting

Describe the bug

from time to time, the connection between HA and Nodered just keep resetting: from within node red, the HA(ex. Event State node) status just going from "connnecting, connected, running... connecting, connnected, running... )

To Reproduce

It's quite difficult to reproduce it. it just happens quite randomly. the frequency is in the last several month, it happens quite offen. the frequency also varies: sometime, it happen very often, such as , for the whole night, I guess), it keep resetting; some time it LOOKS stable. But generally speaking, with my set up, it happens for every 2 or three days.

I have a feeling that the error was triggered by a wrong "call service" action. but when I purposely trigger a wrong "call service" action, it does not necessary trigger this error.

Please take a look at the logs I attached here.

I have a quite complicated node red flows: about 20 flows, and 4000 nodes.

nodered.log

Expected behavior

The connection between HA and Node red should maintained.

Screenshots

this issue simply happends on every flow which as a node from Homeassistant.

Example Flow

[
    {
        "id": "ac7f510db8bb03d7",
        "type": "subflow",
        "name": "log",
        "info": "",
        "category": "",
        "in": [
            {
                "x": 140,
                "y": 180,
                "wires": [
                    {
                        "id": "ec6d8e0ab1345d42"
                    }
                ]
            }
        ],
        "out": [
            {
                "x": 760,
                "y": 180,
                "wires": [
                    {
                        "id": "ec6d8e0ab1345d42",
                        "port": 0
                    }
                ]
            }
        ],
        "env": [
            {
                "name": "log_attribute",
                "type": "str",
                "value": ""
            }
        ],
        "meta": {},
        "color": "#DDAA99",
        "status": {
            "x": 760,
            "y": 320,
            "wires": [
                {
                    "id": "a005a35b4ea9adf8",
                    "port": 0
                }
            ]
        }
    },
    {
        "id": "a005a35b4ea9adf8",
        "type": "change",
        "z": "ac7f510db8bb03d7",
        "name": "",
        "rules": [
            {
                "t": "set",
                "p": "payload",
                "pt": "msg",
                "to": "log_display",
                "tot": "msg"
            }
        ],
        "action": "",
        "property": "",
        "from": "",
        "to": "",
        "reg": false,
        "x": 600,
        "y": 300,
        "wires": [
            []
        ]
    },
    {
        "id": "ec6d8e0ab1345d42",
        "type": "function",
        "z": "ac7f510db8bb03d7",
        "name": "",
        "func": "var attributeName = env.get(\"log_attribute\");\nvar timestamp = new Date().toLocaleString('en-GB');\n\nif (attributeName && attributeName.trim() !== \"\") {\n    var attributeValue = msg[attributeName];\n    msg.log_display = `${timestamp}: ${attributeValue}`;\n} else {\n    msg.log_display = timestamp;\n}\n\nreturn msg;\n\n\n\n\n\n\n\n\n// var attributeName = env.get(\"log_attribute\");\n\n// var attributeValue ;\n\n// var timestamp = (new Date()).toLocaleDateString() + \" \" + (new Date()).toLocaleTimeString('en-GB');\n\n\n// if (attributeName !== undefined && attributeName.trim() !== \"\") {\n\n\n//     attributeValue = msg[attributeName];\n//     msg.log_display = timestamp + \": \" + attributeValue\n\n// }  else {\n//     msg.log_display = timestamp \n// }\n\n\n\n\n// return msg;\n\n",
        "outputs": 1,
        "noerr": 0,
        "initialize": "",
        "finalize": "",
        "libs": [],
        "x": 340,
        "y": 180,
        "wires": [
            [
                "a005a35b4ea9adf8"
            ]
        ]
    },
    {
        "id": "34dc5a14e791abf6",
        "type": "link in",
        "z": "0266edf078264249",
        "name": "in: refreshing",
        "links": [
            "5a02b52f1957efea",
            "66ed5db38f9e2acf",
            "690f2a19c27af2d8"
        ],
        "x": 415,
        "y": 1020,
        "wires": [
            [
                "88af364cf06e07f7"
            ]
        ]
    },
    {
        "id": "2a58a7a5e14b3035",
        "type": "subflow:ac7f510db8bb03d7",
        "z": "0266edf078264249",
        "name": "sync statemachine with current_time slot",
        "x": 840,
        "y": 980,
        "wires": [
            [
                "25563b0f59368225"
            ]
        ]
    },
    {
        "id": "b5719cd394eef0ed",
        "type": "switch",
        "z": "0266edf078264249",
        "name": "from_normal_trigger",
        "property": "from_normal_trigger",
        "propertyType": "flow",
        "rules": [
            {
                "t": "true"
            },
            {
                "t": "else"
            }
        ],
        "checkall": "false",
        "repair": false,
        "outputs": 2,
        "x": 720,
        "y": 840,
        "wires": [
            [
                "514eb5393137b402"
            ],
            [
                "4add15f3bc3397dd"
            ]
        ]
    },
    {
        "id": "514eb5393137b402",
        "type": "subflow:ac7f510db8bb03d7",
        "z": "0266edf078264249",
        "name": "",
        "x": 750,
        "y": 760,
        "wires": [
            []
        ]
    },
    {
        "id": "76fae01a5df262f5",
        "type": "server-state-changed",
        "z": "0266edf078264249",
        "name": "current_time_slot -- no-delete",
        "server": "538475ac.a2270c",
        "version": 5,
        "outputs": 1,
        "exposeAsEntityConfig": "",
        "entityId": "input_select.current_time_slot",
        "entityIdType": "exact",
        "outputInitially": false,
        "stateType": "str",
        "ifState": "",
        "ifStateType": "str",
        "ifStateOperator": "is",
        "outputOnlyOnStateChange": true,
        "for": "",
        "forType": "num",
        "forUnits": "seconds",
        "ignorePrevStateNull": false,
        "ignorePrevStateUnknown": false,
        "ignorePrevStateUnavailable": false,
        "ignoreCurrentStateUnknown": false,
        "ignoreCurrentStateUnavailable": false,
        "outputProperties": [
            {
                "property": "initial_time_slot",
                "propertyType": "msg",
                "value": "",
                "valueType": "entityState"
            }
        ],
        "x": 460,
        "y": 840,
        "wires": [
            [
                "b5719cd394eef0ed"
            ]
        ]
    },
    {
        "id": "4add15f3bc3397dd",
        "type": "subflow:ac7f510db8bb03d7",
        "z": "0266edf078264249",
        "name": "",
        "x": 910,
        "y": 840,
        "wires": [
            [
                "25563b0f59368225"
            ]
        ]
    },
    {
        "id": "88af364cf06e07f7",
        "type": "switch",
        "z": "0266edf078264249",
        "name": "running?",
        "property": "ha_status",
        "propertyType": "global",
        "rules": [
            {
                "t": "eq",
                "v": "running",
                "vt": "str"
            },
            {
                "t": "else"
            }
        ],
        "checkall": "true",
        "repair": false,
        "outputs": 2,
        "x": 520,
        "y": 1020,
        "wires": [
            [
                "2a58a7a5e14b3035"
            ],
            [
                "877343a80b8c00e1"
            ]
        ]
    },
    {
        "id": "671e455f6ebb0f5a",
        "type": "subflow:ac7f510db8bb03d7",
        "z": "0266edf078264249",
        "name": "",
        "env": [
            {
                "name": "log_attribute",
                "value": "ha_status",
                "type": "str"
            }
        ],
        "x": 870,
        "y": 1060,
        "wires": [
            []
        ]
    },
    {
        "id": "877343a80b8c00e1",
        "type": "change",
        "z": "0266edf078264249",
        "name": "ha_status",
        "rules": [
            {
                "t": "set",
                "p": "ha_status",
                "pt": "msg",
                "to": "ha_status",
                "tot": "global"
            }
        ],
        "action": "",
        "property": "",
        "from": "",
        "to": "",
        "reg": false,
        "x": 740,
        "y": 1060,
        "wires": [
            [
                "671e455f6ebb0f5a"
            ]
        ]
    },
    {
        "id": "25563b0f59368225",
        "type": "switch",
        "z": "0266edf078264249",
        "name": "running?",
        "property": "ha_status",
        "propertyType": "global",
        "rules": [
            {
                "t": "eq",
                "v": "running",
                "vt": "str"
            },
            {
                "t": "else"
            }
        ],
        "checkall": "true",
        "repair": false,
        "outputs": 2,
        "x": 1080,
        "y": 840,
        "wires": [
            [
                "ba6ac0826c84c1d0"
            ],
            [
                "01fd36080f85fccb"
            ]
        ]
    },
    {
        "id": "538475ac.a2270c",
        "type": "server",
        "name": "Home Assistant",
        "version": 5,
        "addon": false,
        "rejectUnauthorizedCerts": true,
        "ha_boolean": "y|yes|true|on|home|open",
        "connectionDelay": false,
        "cacheJson": true,
        "heartbeat": true,
        "heartbeatInterval": "30",
        "areaSelector": "friendlyName",
        "deviceSelector": "friendlyName",
        "entitySelector": "id",
        "statusSeparator": "at: ",
        "statusYear": "hidden",
        "statusMonth": "hidden",
        "statusDay": "2-digit",
        "statusHourCycle": "h23",
        "statusTimeFormat": "h:m",
        "enableGlobalContextStore": true
    }
]

Environment Information

Version:

Home Assistant version: 2024.3.1 (I'm using Kubernetes/Docker) Companion version: v3.1.3

Node-RED version: V3.1.7 (also in Docker i mage: nodered/node-red:3.1.7) Docker: Yes (Kubernetes) Add-on: N.A

Node.js version: N.A (Node.js in Docker?) OS: Ubuntu 23.10

Additional context

No response

What do the Home Assistant logs show anything at the time of the disconnects?

Just now, I reproduced this issue, it seems that there is NO obvisous error repoting on home asssistant side when nodered reporting errors:

here is the logs from nodered:

25 Mar 09:49:29 - [info] [server:Home Assistant] Connection closed to http://ha-service:8123
25 Mar 09:49:29 - [error] [api-call-service:motion_smooth_living_dining on] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
25 Mar 09:49:29 - [error] [api-call-service:vibration_smooth_kitchen on] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
25 Mar 09:49:29 - [error] [api-call-service:motion_smooth_dining_kitchen on] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
25 Mar 09:49:29 - [error] [api-call-service:motion_smooth_livingroom on] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
25 Mar 09:49:29 - [error] [api-call-service:today_cleaning_mode] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
25 Mar 09:49:29 - [error] [api-call-service:motion_smooth_updiele off] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
25 Mar 09:49:29 - [error] [api-call-service:off: light_time_focus] NoConnectionError
25 Mar 09:49:29 - [info] [server:Home Assistant] Connecting to http://ha-service:8123
25 Mar 09:49:29 - [error] [api-call-service:off: light_time_upfloor] NoConnectionError
25 Mar 09:49:30 - [info] [server:Home Assistant] Connected to http://ha-service:8123

and below are the logs from home assistant at the same time( according to timestamp), which is just a warning and has nothing to do with nodred:

2024-03-25 09:46:49.282 WARNING (MainThread) [zigpy.application] Unknown device AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x9F15)
2024-03-25 09:46:49.288 WARNING (MainThread) [zigpy.application] Unknown device AddrModeAddress(addr_mode=<AddrMode.NWK: 2>, address=0x9F15)
2024-03-25 09:48:26.419 WARNING (MainThread) [homeassistant.helpers.entity] Entity var.no_change_trigger_list (<class 'custom_components.var.Variable'>) is using self.async_update_ha_state(), without enabling force_update. Instead it should use self.async_write_ha_state(), please report it to the author of the 'var' custom integration

my gut feeling is: this issue come out when I use this:

but that's just my gut feeling

I have 20 switches configured and they are becoming unavailable every 2-4 minutes.

Actually, before the crash, I cal also see a warning: Possible EventEmitter memory leak detected. 11 flows:started listeners added to [EventEmitter]. Use emitter.setMaxListeners() to increase limit

25 Mar 21:01:19 - [info] Starting flows
25 Mar 21:01:38 - [info] Started flows
(node:7) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 flows:started listeners added to [EventEmitter]. Use emitter.setMaxListeners() to increase limit
25 Mar 21:01:38 - [info] [server:Home Assistant] Connecting to http://ha-service:8123
25 Mar 21:01:38 - [info] [server:Home Assistant] Connected to http://ha-service:8123
25 Mar 21:24:52 - [info] Stopping flows
25 Mar 21:24:53 - [info] [server:Home Assistant] Closing connection to http://ha-service:8123
25 Mar 21:24:54 - [info] Stopped flows
25 Mar 21:24:54 - [info] Updated flows
25 Mar 21:24:54 - [info] Starting flows
25 Mar 21:25:18 - [info] Started flows
(node:7) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 flows:started listeners added to [EventEmitter]. Use emitter.setMaxListeners() to increase limit
25 Mar 21:25:18 - [info] [server:Home Assistant] Connecting to http://ha-service:8123
25 Mar 21:25:18 - [info] [server:Home Assistant] Connected to http://ha-service:8123
26 Mar 00:22:56 - [info] [server:Home Assistant] Connection closed to http://ha-service:8123
26 Mar 00:22:56 - [error] [api-call-service:light_automation] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 00:22:56 - [error] [api-call-service:motion_off_wait_time] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 00:22:56 - [error] [api-call-service:controller_aft_on_reset] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 00:22:56 - [error] [api-call-service:light_automation] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 00:22:56 - [error] [api-call-service:today_cleaning_mode] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 00:22:56 - [error] [api-call-service:keep-alive] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 00:22:56 - [info] [server:Home Assistant] Connecting to http://ha-service:8123
26 Mar 00:22:57 - [info] [server:Home Assistant] Connected to http://ha-service:8123
26 Mar 06:07:57 - [info] [server:Home Assistant] Connection closed to http://ha-service:8123
26 Mar 06:07:57 - [error] [api-call-service:light_automation] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 06:07:57 - [error] [api-call-service:motion_off_wait_time] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 06:07:57 - [error] [api-call-service:controller_aft_on_reset] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 06:07:57 - [error] [api-call-service:light_automation] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 06:07:57 - [error] [api-call-service:motion_off_wait_time] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 06:07:57 - [error] [api-call-service:controller_aft_on_reset] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 06:07:57 - [error] [api-call-service:light_automation] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 06:07:57 - [error] [api-call-service:motion_off_wait_time] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 06:07:57 - [error] [api-call-service:controller_aft_on_reset] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 06:07:57 - [error] [api-call-service:light_automation] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 06:07:57 - [error] [api-call-service:motion_off_wait_time] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 06:07:57 - [error] [api-call-service:controller_aft_on_reset] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 06:07:57 - [error] [api-call-service:light_automation] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 06:07:57 - [error] [api-call-service:motion_off_music_wait_time] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 06:07:57 - [error] [api-call-service:automation] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 06:07:57 - [error] [api-call-service:motion_off_music_wait_time] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 06:07:57 - [error] [api-call-service:automation] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 06:07:57 - [error] [api-call-service:motion_off_music_wait_time] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 06:07:57 - [error] [api-call-service:automation] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 06:07:57 - [error] [api-call-service:motion_off_music_wait_time] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 06:07:57 - [error] [api-call-service:automation] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 06:07:57 - [error] [api-call-service:motion_off_music_wait_time] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 06:07:57 - [error] [api-call-service:automation] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 06:07:57 - [error] [api-call-service:motion_off_music_wait_time] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 06:07:57 - [error] [api-call-service:automation] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 06:07:57 - [error] [api-call-service:motion_off_music_wait_time] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 06:07:57 - [error] [api-call-service:automation] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 06:07:57 - [error] [api-call-service:motion_off_music_wait_time] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 06:07:57 - [error] [api-call-service:automation] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 06:07:57 - [error] [api-call-service:motion_off_music_wait_time] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 06:07:57 - [error] [api-call-service:automation] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 06:07:57 - [error] [api-call-service:motion_off_music_wait_time] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 06:07:57 - [error] [api-call-service:automation] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 06:07:57 - [error] [api-call-service:motion_off_music_wait_time] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 06:07:57 - [error] [api-call-service:automation] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 06:07:57 - [error] [api-call-service:motion_off_music_wait_time] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 06:07:57 - [error] [api-call-service:automation] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 06:07:57 - [error] [api-call-service:motion_smooth_bathroom off] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 06:07:57 - [error] [api-call-service:today_cleaning_mode] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 06:07:57 - [error] [api-call-service:keep-alive] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 06:07:57 - [error] [api-call-service:controller wait time] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 06:07:57 - [error] [api-call-service:controller wait time] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
26 Mar 06:07:57 - [error] [api-call-service:motion off wait time] NoConnectionError

Actually, before the connection between nodered and HA crashes, I can see that it takes several seconds to send a message from nodered to HA.

I made a screen shot from node red: you can see that the "call service" node could be staying "sending" status for so long time that I have enough time to make a screenshot. Shortly after that, the connection crashes.

This problem happens so often, and it's not difficult for to reproduce it. I can support the debug activities if necessary.

I am seeing a similar issue #1327 . At some point of time NR logs that the connection is closed. Due to that the sensor entity nodes that expect to send data to HA fail and throw an error. In HA no error is logged at the same time.

I am seeing a noticable period after executing a Call Service when the node shows its status as "disconnected", before the connection is automatically reconnected. Nothing in most of the logs ... but I did find
and in the HA Node-RED add-on's log

9 Mar 15:09:23 - [info] [server:Home Assistant] Connecting to http://supervisor/core
29 Mar 15:09:23 - [info] [server:Home Assistant] Connected to http://supervisor/core
29 Mar 16:17:27 - [info] Stopping flows
29 Mar 16:17:27 - [info] [server:Home Assistant] Closing connection to http://supervisor/core
29 Mar 16:17:27 - [info] [mqtt-broker:HA MQTT broker add-on] Disconnected from broker: mqtt://192.168.1.98:1883
29 Mar 16:17:27 - [info] Stopped flows
29 Mar 16:17:27 - [info] Updated flows
29 Mar 16:17:27 - [info] Starting flows
29 Mar 16:17:27 - [info] Started flows
29 Mar 16:17:27 - [info] [mqtt-broker:HA MQTT broker add-on] Connected to broker: mqtt://192.168.1.98:1883
29 Mar 16:17:27 - [info] [sun events:66322be3ba106617] calculating sunevents for lat -34.4281594207054 and lng 150.884547793503
29 Mar 16:17:32 - [info] [server:Home Assistant] Connecting to http://supervisor/core
29 Mar 16:17:32 - [info] [server:Home Assistant] Connected to http://supervisor/core
29 Mar 16:24:44 - [info] Stopping flows
29 Mar 16:24:44 - [info] [server:Home Assistant] Closing connection to http://supervisor/core
29 Mar 16:24:44 - [info] [mqtt-broker:HA MQTT broker add-on] Disconnected from broker: mqtt://192.168.1.98:1883
29 Mar 16:24:44 - [info] Stopped flows
29 Mar 16:24:44 - [info] Updated flows
29 Mar 16:24:44 - [info] Starting flows
29 Mar 16:24:44 - [info] Started flows
29 Mar 16:24:44 - [info] [mqtt-broker:HA MQTT broker add-on] Connected to broker: mqtt://192.168.1.98:1883
29 Mar 16:24:44 - [info] [sun events:66322be3ba106617] calculating sunevents for lat -34.4281594207054 and lng 150.884547793503
29 Mar 16:24:49 - [info] [server:Home Assistant] Connecting to http://supervisor/core
29 Mar 16:24:49 - [info] [server:Home Assistant] Connected to http://supervisor/core
29 Mar 16:27:59 - [info] Stopping flows
29 Mar 16:27:59 - [info] [server:Home Assistant] Closing connection to http://supervisor/core
29 Mar 16:27:59 - [info] [mqtt-broker:HA MQTT broker add-on] Disconnected from broker: mqtt://192.168.1.98:1883
29 Mar 16:27:59 - [info] Stopped flows
29 Mar 16:27:59 - [info] Updated flows
29 Mar 16:27:59 - [info] Starting flows
29 Mar 16:27:59 - [info] Started flows
29 Mar 16:27:59 - [info] [mqtt-broker:HA MQTT broker add-on] Connected to broker: mqtt://192.168.1.98:1883
29 Mar 16:27:59 - [info] [sun events:66322be3ba106617] calculating sunevents for lat -34.4281594207054 and lng 150.884547793503
29 Mar 16:28:03 - [error] [api-call-service:process sentence] NoConnectionError
29 Mar 16:28:04 - [info] [server:Home Assistant] Connecting to http://supervisor/core
29 Mar 16:28:04 - [info] [server:Home Assistant] Connected to http://supervisor/core
29 Mar 17:22:13 - [warn] [function:determine event] zha_event: exiting  event_type=double_click, entity_id=lumi_button
29 Mar 17:22:43 - [error] [link call:c95bb3a74082da5d] timeout

9 Mar 15:09:23 - [info] [server:Home Assistant] Connecting to http://supervisor/core
29 Mar 15:09:23 - [info] [server:Home Assistant] Connected to http://supervisor/core
29 Mar 16:17:27 - [info] Stopping flows
29 Mar 16:17:27 - [info] [server:Home Assistant] Closing connection to http://supervisor/core
29 Mar 16:17:27 - [info] [mqtt-broker:HA MQTT broker add-on] Disconnected from broker: mqtt://192.168.1.98:1883
29 Mar 16:17:27 - [info] Stopped flows
29 Mar 16:17:27 - [info] Updated flows
29 Mar 16:17:27 - [info] Starting flows
29 Mar 16:17:27 - [info] Started flows
29 Mar 16:17:27 - [info] [mqtt-broker:HA MQTT broker add-on] Connected to broker: mqtt://192.168.1.98:1883
29 Mar 16:17:27 - [info] [sun events:66322be3ba106617] calculating sunevents for lat -34.4281594207054 and lng 150.884547793503
29 Mar 16:17:32 - [info] [server:Home Assistant] Connecting to http://supervisor/core
29 Mar 16:17:32 - [info] [server:Home Assistant] Connected to http://supervisor/core
29 Mar 16:24:44 - [info] Stopping flows
29 Mar 16:24:44 - [info] [server:Home Assistant] Closing connection to http://supervisor/core
29 Mar 16:24:44 - [info] [mqtt-broker:HA MQTT broker add-on] Disconnected from broker: mqtt://192.168.1.98:1883
29 Mar 16:24:44 - [info] Stopped flows
29 Mar 16:24:44 - [info] Updated flows
29 Mar 16:24:44 - [info] Starting flows
29 Mar 16:24:44 - [info] Started flows
29 Mar 16:24:44 - [info] [mqtt-broker:HA MQTT broker add-on] Connected to broker: mqtt://192.168.1.98:1883
29 Mar 16:24:44 - [info] [sun events:66322be3ba106617] calculating sunevents for lat -34.4281594207054 and lng 150.884547793503
29 Mar 16:24:49 - [info] [server:Home Assistant] Connecting to http://supervisor/core
29 Mar 16:24:49 - [info] [server:Home Assistant] Connected to http://supervisor/core
29 Mar 16:27:59 - [info] Stopping flows
29 Mar 16:27:59 - [info] [server:Home Assistant] Closing connection to http://supervisor/core
29 Mar 16:27:59 - [info] [mqtt-broker:HA MQTT broker add-on] Disconnected from broker: mqtt://192.168.1.98:1883
29 Mar 16:27:59 - [info] Stopped flows
29 Mar 16:27:59 - [info] Updated flows
29 Mar 16:27:59 - [info] Starting flows
29 Mar 16:27:59 - [info] Started flows
29 Mar 16:27:59 - [info] [mqtt-broker:HA MQTT broker add-on] Connected to broker: mqtt://192.168.1.98:1883
29 Mar 16:27:59 - [info] [sun events:66322be3ba106617] calculating sunevents for lat -34.4281594207054 and lng 150.884547793503
29 Mar 16:28:03 - [error] [api-call-service:process sentence] NoConnectionError
29 Mar 16:28:04 - [info] [server:Home Assistant] Connecting to http://supervisor/core
29 Mar 16:28:04 - [info] [server:Home Assistant] Connected to http://supervisor/core
29 Mar 17:22:13 - [warn] [function:determine event] zha_event: exiting  event_type=double_click, entity_id=lumi_button
29 Mar 17:22:43 - [error] [link call:c95bb3a74082da5d] timeout

Hi @donburch888 ,

Are you running node red in a standalong docker (from homeassistant) container or you're using HASS OS?

I'm wondering whether I should go back HASS OS setup ...

This issue is really annoying, it's happening all of the time, and make node red almost useless for home assistant...

I am now running HAOS under proxmox, so I could run things as separate VMs ... but no, I have just taken the easy way of running everything as HAOS add-ons.

If you connect directly to Home Assistant and do not use the Supervisor proxy does that change anything?

Uncheck use the add-on and create a long-lived access token.

For anyone else wanting to follow zachowj's suggestion...

In Home Assistant I created a long-lived access token and copied it to the clipboard.
In Node-RED I opened a node which links to Home Assistant Server (in this case a Call Service node), then clicked on the pencil icon next to Server field.
I unchecked "Using the Home Assistant Add-on", added the URL of my Home Assistant server (yes, i prefer to use IP address), and pasted the long-lived access token (from step 1) into the "Access token" field.
[Update], [Done] and [Deploy].
I then restarted Home Assistant, using the "Reboot system" option to make sure that all add-ons are restarted as well.

My test flow is working ... quickly pressing the inject node to say "this is a test" is no longer requiring a pause to let the server reconnect ... and back in HA, the Node-RED Log is no longer disconnecting and reconnecting. :-)

[18:02:17] INFO: Starting NGinx... 28 Apr 18:13:20 - [info] Stopping flows 28 Apr 18:13:20 - [info] [mqtt-broker:HA MQTT broker add-on] Disconnected from broker: mqtt://192.168.1.98:1883 28 Apr 18:13:20 - [info] Stopped flows 28 Apr 18:13:20 - [info] Updated flows 28 Apr 18:13:20 - [info] Starting flows 28 Apr 18:13:20 - [info] Started flows 28 Apr 18:13:20 - [info] [server:Home Assistant] Connecting to http://192.168.1.98:8123 28 Apr 18:13:20 - [info] [mqtt-broker:HA MQTT broker add-on] Connected to broker: mqtt://192.168.1.98:1883 28 Apr 18:13:20 - [info] [server:Home Assistant] Connected to http://192.168.1.98:8123 28 Apr 18:13:20 - [info] [sun events:66322be3ba106617] calculating sunevents for lat -34.4281594207054 and lng 150.884547793503

Looking good for me.

If you connect directly to Home Assistant and do not use the Supervisor proxy does that change anything?

Uncheck use the add-on and create a long-lived access token.

I was using long-lived access token, and the checkbox of "using home assistant addon" was always unchecked.

Hi, @zachowj,

as this issue is quite easy to reproduce on my setup, do you think it makes sense that you create a debug version (docker), which could provided more logs hopefully, and I run it on my machine, and send you back those log file? and I could assist you closely to find the root cause of this issue. currently, I'm using nodered on my k8s cluster.

@taoyx Do you use render template nodes?

Hi @zachowj,

Thank you. I guess you are talk about this node:

the attached block are the only one in my application: I just did a try, but didn't really use it. Now let me delete it, and see whether it makes a difference.

Also, I have a gut feeling: the problems come offen when the resource(cpu, memory) pressure comes. But that's just a feeling, because, when I assign the home assistant container and node red on to a 2-core/4G memory kubernetes node, the problem is still happending.

Also, I found nodered did eat quite a lot memory on my k8s cluster:

Maybe I'm too verbose... hope it could help a little bit.

Thank you very much.

[ { "id": "f231967.0251a68", "type": "inject", "z": "f843e870b264bca3", "name": "YAML String", "props": [ { "p": "payload" }, { "p": "topic", "vt": "str" } ], "repeat": "", "crontab": "", "once": false, "onceDelay": 0.1, "topic": "", "payload": "{\"a\":1}", "payloadType": "str", "x": 630, "y": 1220, "wires": [ [ "a0110756.ecfa48" ] ] }, { "id": "8f8f31b7.1f916", "type": "debug", "z": "f843e870b264bca3", "name": "", "active": true, "tosidebar": true, "console": false, "tostatus": false, "complete": "payload", "targetType": "msg", "statusVal": "", "statusType": "auto", "x": 1110, "y": 1220, "wires": [] }, { "id": "5138ba3.c972444", "type": "inject", "z": "f843e870b264bca3", "name": "Object", "repeat": "", "crontab": "", "once": false, "onceDelay": 0.1, "topic": "", "payload": "{\"a\":1, \"b\":[1,2,3]}", "payloadType": "json", "x": 610, "y": 1260, "wires": [ [ "2fa653cc.60d3dc" ] ] }, { "id": "50f2f4c.4a6e60c", "type": "debug", "z": "f843e870b264bca3", "name": "", "active": true, "tosidebar": true, "console": false, "tostatus": false, "complete": "false", "x": 950, "y": 1260, "wires": [] }, { "id": "a0110756.ecfa48", "type": "template", "z": "f843e870b264bca3", "name": "", "field": "payload", "fieldType": "msg", "format": "yaml", "syntax": "plain", "template": "a: 1\nb:\n - 1\n - 2\n - 3", "output": "str", "x": 800, "y": 1220, "wires": [ [ "104b80e2.51068f" ] ] }, { "id": "2fa653cc.60d3dc", "type": "yaml", "z": "f843e870b264bca3", "property": "payload", "name": "", "x": 770, "y": 1260, "wires": [ [ "50f2f4c.4a6e60c" ] ] }, { "id": "104b80e2.51068f", "type": "yaml", "z": "f843e870b264bca3", "property": "payload", "name": "", "x": 950, "y": 1220, "wires": [ [ "8f8f31b7.1f916" ] ] } ]

Hi @zachowj,

Hi After I removed those template node from nodered, I didn't see anychange: the connection between HA and Nodered is still resetting.

I keep seeing this warning of memory leakage, do you know how to debug it? what is (node:6) below?

(node:6) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 flows:started listeners added to [EventEmitter]. Use emitter.setMaxListeners() to increase limit

thank you, Richard

7 May 10:38:03 - [error] [api-call-service:controller_aft_on_reset] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}} 7 May 10:38:03 - [error] [api-call-service:light_automation] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}} 7 May 10:38:03 - [error] [api-call-service:motion_off_wait_time] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}} 7 May 10:38:03 - [error] [api-call-service:controller_aft_on_reset] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}} 7 May 10:38:03 - [error] [api-call-service:light_automation] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}} 7 May 10:38:03 - [error] [api-call-service:motion_off_wait_time] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}} 7 May 10:38:03 - [error] [api-call-service:controller_aft_on_reset] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}} 7 May 10:38:03 - [error] [api-call-service:light_automation] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}} 7 May 10:38:03 - [info] [server:Home Assistant] Connecting to http://ha-service:8123 7 May 10:38:04 - [info] [server:Home Assistant] Connected to http://ha-service:8123 7 May 10:38:06 - [info] [server:Home Assistant] Connection closed to http://ha-service:8123 7 May 10:38:06 - [info] [server:Home Assistant] Connecting to http://ha-service:8123 7 May 10:38:06 - [info] [server:Home Assistant] Connected to http://ha-service:8123 7 May 10:38:08 - [info] [server:Home Assistant] Connection closed to http://ha-service:8123 7 May 10:38:08 - [info] [server:Home Assistant] Connecting to http://ha-service:8123 7 May 10:38:08 - [info] [server:Home Assistant] Connected to http://ha-service:8123 7 May 10:42:31 - [info] Stopping flows 7 May 10:42:32 - [info] [server:Home Assistant] Closing connection to http://ha-service:8123 7 May 10:42:32 - [info] Stopped flows 7 May 10:42:33 - [info] Updated flows 7 May 10:42:33 - [info] Starting flows 7 May 10:42:51 - [info] Started flows (node:6) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 flows:started listeners added to [EventEmitter]. Use emitter.setMaxListeners() to increase limit 7 May 10:42:51 - [info] [server:Home Assistant] Connecting to http://ha-service:8123 7 May 10:42:51 - [info] [server:Home Assistant] Connected to http://ha-service:8123

when I go through the remaining issue, there are several duplicate one. From my point, this issue is the most painfule one for this project: It happens several times a day, and make the automation very unreliable.

Shall we looking for alternative solution?

I really suspect this issure is related with memory leak: that's reason there are no much use logs either on HA side or NR side. Normally, before the issue happens, we can always see such warning message:

(node:7) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 flows:started listeners added to [EventEmitter]. Use emitter.setMaxListeners() to increase limit

the similiar issue happens in another project, and they seems found the issue, refer here:

quoto here:

In fixResponseChunkedTransferBadEnding() two signals are added to the socket in every request, but they are never removed.

In https://github.com/node-fetch/node-fetch/pull/1474 I fix that problem by removing both signals on the socket's close() event.

Hope it helps. @zachowj

PS. also attach my latest logs:

(node:7) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 flows:started listeners added to [EventEmitter]. Use emitter.setMaxListeners() to increase limit
17 May 21:48:31 - [info] [server:Home Assistant] Connecting to http://ha-service:8123
17 May 21:48:31 - [info] [server:Home Assistant] Connected to http://ha-service:8123
17 May 21:51:07 - [info] Stopping flows
17 May 21:51:11 - [info] [server:Home Assistant] Closing connection to http://ha-service:8123
17 May 21:51:11 - [info] Stopped flows
17 May 21:51:11 - [info] Updated flows
17 May 21:51:12 - [info] Starting flows
17 May 21:51:27 - [info] Started flows
(node:7) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 flows:started listeners added to [EventEmitter]. Use emitter.setMaxListeners() to increase limit
17 May 21:51:27 - [info] [server:Home Assistant] Connecting to http://ha-service:8123
17 May 21:51:27 - [info] [server:Home Assistant] Connected to http://ha-service:8123
17 May 21:55:48 - [info] Stopping flows
17 May 21:55:48 - [info] [server:Home Assistant] Closing connection to http://ha-service:8123
17 May 21:55:49 - [info] Stopped flows
17 May 21:55:49 - [info] Updated flows
17 May 21:55:50 - [info] Starting flows
17 May 21:56:15 - [info] Started flows
(node:7) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 flows:started listeners added to [EventEmitter]. Use emitter.setMaxListeners() to increase limit
17 May 21:56:15 - [info] [server:Home Assistant] Connecting to http://ha-service:8123
17 May 21:56:15 - [info] [server:Home Assistant] Connected to http://ha-service:8123
18 May 14:37:27 - [info] Stopping flows
18 May 14:37:28 - [info] [server:Home Assistant] Closing connection to http://ha-service:8123
18 May 14:37:29 - [info] Stopped flows
18 May 14:37:29 - [info] Updated flows
18 May 14:37:29 - [info] Starting flows
18 May 14:37:50 - [info] Started flows
(node:7) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 flows:started listeners added to [EventEmitter]. Use emitter.setMaxListeners() to increase limit
18 May 14:37:50 - [info] [server:Home Assistant] Connecting to http://ha-service:8123
18 May 14:37:50 - [info] [server:Home Assistant] Connected to http://ha-service:8123
18 May 14:38:03 - [info] Stopping flows
18 May 14:38:04 - [info] [server:Home Assistant] Closing connection to http://ha-service:8123
18 May 14:38:04 - [info] Stopped flows
18 May 14:38:04 - [info] Updated flows
18 May 14:38:05 - [info] Starting flows
18 May 14:38:26 - [info] Started flows
(node:7) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 flows:started listeners added to [EventEmitter]. Use emitter.setMaxListeners() to increase limit
18 May 14:38:26 - [info] [server:Home Assistant] Connecting to http://ha-service:8123
18 May 14:38:26 - [info] [server:Home Assistant] Connected to http://ha-service:8123
18 May 14:39:37 - [info] Stopping flows
18 May 14:39:37 - [info] [server:Home Assistant] Closing connection to http://ha-service:8123
18 May 14:39:38 - [info] Stopped flows
18 May 14:39:38 - [info] Updated flows
18 May 14:39:38 - [info] Starting flows
18 May 14:39:59 - [info] Started flows
(node:7) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 flows:started listeners added to [EventEmitter]. Use emitter.setMaxListeners() to increase limit
18 May 14:39:59 - [info] [server:Home Assistant] Connecting to http://ha-service:8123
18 May 14:39:59 - [info] [server:Home Assistant] Connected to http://ha-service:8123
18 May 15:59:35 - [info] [server:Home Assistant] Connection closed to http://ha-service:8123
18 May 15:59:35 - [error] [api-call-service:motion_off_wait_time] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
18 May 15:59:35 - [error] [api-call-service:controller_aft_on_reset] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
18 May 15:59:35 - [error] [api-call-service:light_automation] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
18 May 15:59:35 - [error] [api-call-service:motion_off_wait_time] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
18 May 15:59:35 - [error] [api-call-service:controller_aft_on_reset] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
18 May 15:59:35 - [error] [api-call-service:light_automation] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
18 May 15:59:35 - [error] [api-call-service:motion_off_wait_time] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
18 May 15:59:35 - [error] [api-call-service:controller_aft_on_reset] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
18 May 15:59:35 - [error] [api-call-service:light_automation] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}
18 May 15:59:35 - [error] [api-call-service:motion_off_wait_time] Error: Unrecognized error: {"type":"result","success":false,"error":{"code":3,"message":"Connection lost"}}

I'm suspecting a memory leak as well. I woke up a couple days ago to find the machine I run node-red on (alongside other services) completely locked up, and had to reboot it. I track memory usage for the machine running these services in home assistant, and it was at 100% prior to freezing. While node-red is not always pegging the system at 100% when the connection/disconnection issue occurs, I do see slowly rising memory usage until node-red is rebooted, at which point usage returns to normal.

For me, the disconnection from HA seems to happen about once an hour. It's during this period that memory usage begins to rise. No logs on HA's side, though the Node-RED container logs just repeat as such until I restart the container:

10 Jun 09:40:29 - [info] [server:Home Assistant] Connection closed to http://localhost:8123
10 Jun 09:40:29 - [info] [server:Home Assistant] Connecting to http://localhost:8123
10 Jun 09:40:29 - [info] [server:Home Assistant] Connected to http://localhost:8123
10 Jun 09:40:29 - [info] [server:Home Assistant] Connection closed to http://localhost:8123
10 Jun 09:40:29 - [info] [server:Home Assistant] Connecting to http://localhost:8123
10 Jun 09:40:29 - [info] [server:Home Assistant] Connected to http://localhost:8123
10 Jun 09:40:29 - [info] [server:Home Assistant] Connection closed to http://localhost:8123
10 Jun 09:40:29 - [info] [server:Home Assistant] Connecting to http://localhost:8123
10 Jun 09:40:29 - [info] [server:Home Assistant] Connected to http://localhost:8123
10 Jun 09:40:29 - [info] [server:Home Assistant] Connection closed to http://localhost:8123
10 Jun 09:40:29 - [info] [server:Home Assistant] Connecting to http://localhost:8123
10 Jun 09:40:29 - [info] [server:Home Assistant] Connected to http://localhost:8123
10 Jun 09:40:29 - [info] [server:Home Assistant] Connection closed to http://localhost:8123
10 Jun 09:40:29 - [info] [server:Home Assistant] Connecting to http://localhost:8123
10 Jun 09:40:29 - [info] [server:Home Assistant] Connected to http://localhost:8123
10 Jun 09:40:29 - [info] [server:Home Assistant] Connection closed to http://localhost:8123
10 Jun 09:40:29 - [info] [server:Home Assistant] Connecting to http://localhost:8123
10 Jun 09:40:29 - [info] [server:Home Assistant] Connected to http://localhost:8123
10 Jun 09:40:29 - [info] [server:Home Assistant] Connection closed to http://localhost:8123
10 Jun 09:40:29 - [info] [server:Home Assistant] Connecting to http://localhost:8123
10 Jun 09:40:29 - [info] [server:Home Assistant] Connected to http://localhost:8123

Seems related (if not the same) to this issue as well: https://github.com/zachowj/node-red-contrib-home-assistant-websocket/issues/1225

I should note that I've tried downgrading the version of Node-RED & node-red-contrib-home-assistant-websocket, but the problem persisted. In addition, this problem seems to have began prior to the June release of home assistant, but has persisted since updating.

Hello, zachowj,

Do you think this post could be relavent to this issue? they seems to find a walk around solution for the issue which is quite similiar to the issue here:

https://community.home-assistant.io/t/node-red-losing-websocket-connection/159372/42

thanks,

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