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.

Sign up for GitHub

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

Jump to bottom

Random restarts of Node-RED caused by Shelly plugin #157

Open
MrMysakovich opened this issue Jun 9, 2024 · 72 comments
Open

Random restarts of Node-RED caused by Shelly plugin #157

MrMysakovich opened this issue Jun 9, 2024 · 72 comments

Comments

@MrMysakovich
Copy link

MrMysakovich commented Jun 9, 2024 •
edited
Loading

Hi,

I need some help with an issue I'm encountering.

I'm getting these error messages whenever there's a random restart of NR:

9 Jun 12:38:03 - [red] Uncaught Exception:
9 Jun 12:38:03 - [error] AxiosError: timeout of 5000ms exceeded
    at RedirectableRequest.handleRequestTimeout (/home/pi/.node-red/node_modules/axios/lib/adapters/http.js:647:16)
    at RedirectableRequest.emit (node:events:519:28)
    at Timeout.<anonymous> (/home/pi/.node-red/node_modules/follow-redirects/index.js:210:12)
    at listOnTimeout (node:internal/timers:573:17)
    at processTimers (node:internal/timers:514:7)
    at Axios.request (/home/pi/.node-red/node_modules/axios/lib/core/Axios.js:45:41)
    at runNextTicks (node:internal/process/task_queues:60:5)
    at listOnTimeout (node:internal/timers:540:9)
    at processTimers (node:internal/timers:514:7)
nodered.service: Main process exited, code=exited, status=1/FAILURE
nodered.service: Failed with result 'exit-code'.
nodered.service: Consumed 7min 24.362s CPU time.
nodered.service: Scheduled restart job, restart counter is at 20.
Stopped nodered.service - Node-RED graphical event wiring tool.
nodered.service: Consumed 7min 24.362s CPU time.
Started nodered.service - Node-RED graphical event wiring tool.
9 Jun 12:38:25 - [info]
Welcome to Node-RED
===================
9 Jun 12:38:25 - [info] Node-RED version: v3.1.9
9 Jun 12:38:25 - [info] Node.js  version: v20.14.0
9 Jun 12:38:25 - [info] Linux 6.6.31+rpt-rpi-v8 arm64 LE
9 Jun 12:38:25 - [info] Loading palette nodes
9 Jun 12:38:28 - [info] Dashboard version 3.6.5 started at /ui
9 Jun 12:38:28 - [info] Settings file  : /home/pi/.node-red/settings.js
9 Jun 12:38:28 - [info] Context store  : 'default' [module=memory]
9 Jun 12:38:28 - [info] User directory : /home/pi/.node-red
9 Jun 12:38:28 - [warn] Projects disabled : editorTheme.projects.enabled=false
9 Jun 12:38:28 - [info] Flows file     : /home/pi/.node-red/flows.json
9 Jun 12:38:28 - [info] Server now running at http://127.0.0.1:1880/
9 Jun 12:38:28 - [info] Starting flows
9 Jun 12:38:29 - [info] Started flows
Shelly gen1 server is listening on port 20001
Shelly gen2 server is listening on port 10001

My setup:

[
    {
        "id": "1cb729744d7be53d",
        "type": "shelly-gen2",
        "z": "04ae3d56e09f0645",
        "g": "6913adfeb31ec056",
        "hostname": "10.0.10.37",
        "description": "Water Heater - Basement",
        "mode": "polling",
        "server": "",
        "outputmode": "event",
        "uploadretryinterval": 5000,
        "pollinginterval": "5000",
        "pollstatus": false,
        "getstatusoncommand": true,
        "devicetype": "Relay",
        "devicetypemustmatchexactly": false,
        "outputs": 1,
        "x": 750,
        "y": 1200,
        "wires": [
            []
        ]
    },
    {
        "id": "5f72fa3adf200141",
        "type": "shelly-gen2",
        "z": "04ae3d56e09f0645",
        "g": "6913adfeb31ec056",
        "hostname": "10.0.10.39",
        "description": "Water Heater - Work",
        "mode": "polling",
        "server": "",
        "outputmode": "event",
        "uploadretryinterval": 5000,
        "pollinginterval": "5000",
        "pollstatus": false,
        "getstatusoncommand": true,
        "devicetype": "Relay",
        "devicetypemustmatchexactly": false,
        "outputs": 1,
        "x": 740,
        "y": 1260,
        "wires": [
            []
        ]
    },
    {
        "id": "02f241a770528413",
        "type": "shelly-gen2",
        "z": "04ae3d56e09f0645",
        "g": "6913adfeb31ec056",
        "hostname": "10.0.10.37",
        "description": "Water Heater - Basement",
        "mode": "polling",
        "server": "04263f2d054cc2a1",
        "uploadretryinterval": "5000",
        "pollinginterval": "5000",
        "pollstatus": false,
        "getstatusoncommand": false,
        "devicetype": "Relay",
        "devicetypemustmatchexactly": false,
        "outputs": 1,
        "x": 390,
        "y": 1340,
        "wires": [
            [
                "4e572747190b24b3"
            ]
        ]
    },
    {
        "id": "b81ad76ecee44bcb",
        "type": "shelly-gen2",
        "z": "04ae3d56e09f0645",
        "g": "6913adfeb31ec056",
        "hostname": "10.0.10.39",
        "description": "Water Heater - Work",
        "mode": "polling",
        "server": "04263f2d054cc2a1",
        "uploadretryinterval": "5000",
        "pollinginterval": "5000",
        "pollstatus": false,
        "getstatusoncommand": false,
        "devicetype": "Relay",
        "devicetypemustmatchexactly": false,
        "outputs": 1,
        "x": 380,
        "y": 1400,
        "wires": [
            [
                "57eb76c1b3c06e5b"
            ]
        ]
    },
    {
        "id": "b67c0231bc6cb96f",
        "type": "shelly-gen1",
        "z": "04ae3d56e09f0645",
        "g": "4471973aed0d711c",
        "hostname": "10.0.10.24",
        "description": "Shelly Plug S - Solax Cooling",
        "mode": "polling",
        "server": "033a6e9acf499057",
        "uploadretryinterval": "5000",
        "pollinginterval": "5000",
        "pollstatus": false,
        "getstatusoncommand": false,
        "devicetype": "Relay",
        "devicetypemustmatchexactly": false,
        "outputs": 1,
        "x": 1240,
        "y": 1280,
        "wires": [
            [
                "4641e7b609b2a776"
            ]
        ]
    },
    {
        "id": "753157d6fb24b30a",
        "type": "shelly-gen1",
        "z": "04ae3d56e09f0645",
        "g": "4471973aed0d711c",
        "hostname": "10.0.10.24",
        "description": "Shelly Plug S - Solax Cooling",
        "mode": "polling",
        "server": "",
        "outputmode": "event",
        "uploadretryinterval": 5000,
        "pollinginterval": "5000",
        "pollstatus": false,
        "getstatusoncommand": true,
        "devicetype": "Relay",
        "devicetypemustmatchexactly": false,
        "outputs": 1,
        "x": 1480,
        "y": 1200,
        "wires": [
            []
        ]
    },
    {
        "id": "04263f2d054cc2a1",
        "type": "shelly-gen2-server",
        "port": "10001",
        "hostname": "unimatrix"
    },
    {
        "id": "033a6e9acf499057",
        "type": "shelly-gen1-server",
        "port": "20001",
        "hostname": ""
    }
]

Can anyone help me figure out what I'm doing wrong?
@windkh
Copy link
Owner

windkh commented Jun 9, 2024

Thanks for reporting. I wonder why you have two nodes with the same IP?

@MrMysakovich
Copy link
Author

One just to get status every 1s and one for switching ON / OFF every 15 minutes - water heaters while feed in energy (solar)

@windkh
Copy link
Owner

windkh commented Jun 10, 2024

@MrMysakovich I can only see a portion of your flow.... you are using the same IP address in different nodes
image

All of your nodes poll the shelly every 5 seconds which means that it can happen that you poll the same shelly at almost the same time from two nodes.

  1. Even if two nodes call the shelly at the same time node-red must not crash --> I will try to reproduce that and find a solution
  2. Can you change the mode of the nodes from "polling" to "callback" or to "none" to crosscheck that the problem comes from my theory.
  3. Can you send me the full flow?

@MrMysakovich
Copy link
Author

Yes, because I use the first node for inject every 1s (status) and the second one every 15 minutes for switching ON / OFF.

  1. Maybe I can add one information more that I use same Shellys in Homebridge too.
  2. I will try to set it to none.
[
    {
        "id": "856b984c5428f3bf",
        "type": "inject",
        "z": "04ae3d56e09f0645",
        "g": "6913adfeb31ec056",
        "name": "inject 1x za 1s",
        "props": [
            {
                "p": "payload"
            },
            {
                "p": "topic",
                "vt": "str"
            }
        ],
        "repeat": "1",
        "crontab": "",
        "once": true,
        "onceDelay": "10",
        "topic": "",
        "payload": "",
        "payloadType": "date",
        "x": 160,
        "y": 1340,
        "wires": [
            [
                "02f241a770528413",
                "b81ad76ecee44bcb"
            ]
        ]
    },
    {
        "id": "02f241a770528413",
        "type": "shelly-gen2",
        "z": "04ae3d56e09f0645",
        "g": "6913adfeb31ec056",
        "hostname": "10.0.10.37",
        "description": "Water Heater - Basement",
        "mode": "polling",
        "server": "04263f2d054cc2a1",
        "uploadretryinterval": "5000",
        "pollinginterval": "5000",
        "pollstatus": false,
        "getstatusoncommand": false,
        "devicetype": "Relay",
        "devicetypemustmatchexactly": false,
        "outputs": 1,
        "x": 390,
        "y": 1340,
        "wires": [
            [
                "4e572747190b24b3"
            ]
        ]
    },
    {
        "id": "b81ad76ecee44bcb",
        "type": "shelly-gen2",
        "z": "04ae3d56e09f0645",
        "g": "6913adfeb31ec056",
        "hostname": "10.0.10.39",
        "description": "Water Heater - Work",
        "mode": "polling",
        "server": "04263f2d054cc2a1",
        "uploadretryinterval": "5000",
        "pollinginterval": "5000",
        "pollstatus": false,
        "getstatusoncommand": false,
        "devicetype": "Relay",
        "devicetypemustmatchexactly": false,
        "outputs": 1,
        "x": 380,
        "y": 1400,
        "wires": [
            [
                "57eb76c1b3c06e5b"
            ]
        ]
    },
    {
        "id": "4e572747190b24b3",
        "type": "function",
        "z": "04ae3d56e09f0645",
        "g": "6913adfeb31ec056",
        "name": "Hlavní bojler",
        "func": "if (msg.payload.switch0.output === true) {\n    msg.payload.switch0.output = \"Zapnuto\";\n} else {\n    msg.payload.switch0.output = \"Vypnuto\";\n}\nreturn { payload: msg.payload.switch0.output };",
        "outputs": 1,
        "timeout": 0,
        "noerr": 0,
        "initialize": "",
        "finalize": "",
        "libs": [],
        "x": 590,
        "y": 1340,
        "wires": [
            [
                "10d01ad10ee60225"
            ]
        ]
    },
    {
        "id": "57eb76c1b3c06e5b",
        "type": "function",
        "z": "04ae3d56e09f0645",
        "g": "6913adfeb31ec056",
        "name": "Vedlejší bojler",
        "func": "if (msg.payload.switch0.output === true) {\n    msg.payload.switch0.output = \"Zapnuto\";\n} else {\n    msg.payload.switch0.output = \"Vypnuto\";\n}\nreturn { payload: msg.payload.switch0.output };",
        "outputs": 1,
        "timeout": 0,
        "noerr": 0,
        "initialize": "",
        "finalize": "",
        "libs": [],
        "x": 600,
        "y": 1400,
        "wires": [
            [
                "c93a18a601770f58"
            ]
        ]
    },
    {
        "id": "10d01ad10ee60225",
        "type": "ui_text",
        "z": "04ae3d56e09f0645",
        "g": "6913adfeb31ec056",
        "group": "7ab912b224a2e5e9",
        "order": 1,
        "width": "0",
        "height": "0",
        "name": "",
        "label": "Hlavní bojler",
        "format": "{{msg.payload}}",
        "layout": "row-spread",
        "className": "",
        "style": false,
        "font": "",
        "fontSize": "",
        "color": "#000000",
        "x": 770,
        "y": 1340,
        "wires": []
    },
    {
        "id": "c93a18a601770f58",
        "type": "ui_text",
        "z": "04ae3d56e09f0645",
        "g": "6913adfeb31ec056",
        "group": "7ab912b224a2e5e9",
        "order": 2,
        "width": "0",
        "height": "0",
        "name": "",
        "label": "Vedlejší bojler",
        "format": "{{msg.payload}}",
        "layout": "row-spread",
        "className": "",
        "style": false,
        "font": "",
        "fontSize": "",
        "color": "#000000",
        "x": 780,
        "y": 1400,
        "wires": []
    },
    {
        "id": "c22d652471825384",
        "type": "inject",
        "z": "04ae3d56e09f0645",
        "g": "6913adfeb31ec056",
        "name": "inject 1x za 15 minut",
        "props": [
            {
                "p": "payload"
            },
            {
                "p": "topic",
                "vt": "str"
            }
        ],
        "repeat": "900",
        "crontab": "",
        "once": true,
        "onceDelay": "60",
        "topic": "",
        "payload": "",
        "payloadType": "date",
        "x": 180,
        "y": 1200,
        "wires": [
            [
                "ae5a5b2ad4937485",
                "44a9fac79d02c5ad"
            ]
        ]
    },
    {
        "id": "ae5a5b2ad4937485",
        "type": "function",
        "z": "04ae3d56e09f0645",
        "g": "6913adfeb31ec056",
        "name": "Spínání hlavního bojleru",
        "func": "var feedin_power = flow.get (\"feedin_power\")\nvar shelly = flow.get(\"shelly\");\n\nvar relayState = {\n    relay: 0,\n    on: false\n};\n\nif (feedin_power > 1000) {\n    relayState.on = true;\n}\n\nif (relayState.on) {\n    msg.payload = {\n        method: \"Switch.Set\",\n        parameters: {\n            id: 0,\n            on: true\n        }\n    };\n} else {\n    msg.payload = {\n        method: \"Switch.Set\",\n        parameters: {\n            id: 0,\n            on: false\n        }\n    };\n}\n\nreturn msg;\n",
        "outputs": 1,
        "timeout": 0,
        "noerr": 0,
        "initialize": "",
        "finalize": "",
        "libs": [],
        "x": 430,
        "y": 1200,
        "wires": [
            [
                "1cb729744d7be53d"
            ]
        ]
    },
    {
        "id": "1cb729744d7be53d",
        "type": "shelly-gen2",
        "z": "04ae3d56e09f0645",
        "g": "6913adfeb31ec056",
        "hostname": "10.0.10.37",
        "description": "Water Heater - Basement",
        "mode": "polling",
        "server": "",
        "outputmode": "event",
        "uploadretryinterval": 5000,
        "pollinginterval": "5000",
        "pollstatus": false,
        "getstatusoncommand": true,
        "devicetype": "Relay",
        "devicetypemustmatchexactly": false,
        "outputs": 1,
        "x": 750,
        "y": 1200,
        "wires": [
            []
        ]
    },
    {
        "id": "5f72fa3adf200141",
        "type": "shelly-gen2",
        "z": "04ae3d56e09f0645",
        "g": "6913adfeb31ec056",
        "hostname": "10.0.10.39",
        "description": "Water Heater - Work",
        "mode": "polling",
        "server": "",
        "outputmode": "event",
        "uploadretryinterval": 5000,
        "pollinginterval": "5000",
        "pollstatus": false,
        "getstatusoncommand": true,
        "devicetype": "Relay",
        "devicetypemustmatchexactly": false,
        "outputs": 1,
        "x": 740,
        "y": 1260,
        "wires": [
            []
        ]
    },
    {
        "id": "44a9fac79d02c5ad",
        "type": "function",
        "z": "04ae3d56e09f0645",
        "g": "6913adfeb31ec056",
        "name": "Spínání vedlejšího bojleru + HDO",
        "func": "var feedin_power = flow.get(\"feedin_power\");\nvar vysledekHDO = global.get(\"vysledekHDO\");\nvar shelly = flow.get(\"shelly\");\n\nif (vysledekHDO === \"NT\") {\n    msg.payload = {\n        method: \"Switch.Set\",\n        parameters: {\n            id: 0,\n            on: true,\n        }\n    };\n} else if (feedin_power > 1000) {\n    msg.payload = {\n        method: \"Switch.Set\",\n        parameters: {\n            id: 0,\n            on: true,\n        }\n    };\n} else {\n    msg.payload = {\n        method: \"Switch.Set\",\n        parameters: {\n            id: 0,\n            on: false,\n        }\n    };\n}\n\nreturn msg;",
        "outputs": 1,
        "timeout": 0,
        "noerr": 0,
        "initialize": "",
        "finalize": "",
        "libs": [],
        "x": 460,
        "y": 1260,
        "wires": [
            [
                "5f72fa3adf200141"
            ]
        ]
    },
    {
        "id": "80037bb69b86efc0",
        "type": "inject",
        "z": "04ae3d56e09f0645",
        "g": "4471973aed0d711c",
        "name": "inject 1x za 5s",
        "props": [
            {
                "p": "payload"
            },
            {
                "p": "topic",
                "vt": "str"
            }
        ],
        "repeat": "5",
        "crontab": "",
        "once": true,
        "onceDelay": "10",
        "topic": "",
        "payload": "",
        "payloadType": "date",
        "x": 1020,
        "y": 1200,
        "wires": [
            [
                "75faecb7513cc6be"
            ]
        ]
    },
    {
        "id": "75faecb7513cc6be",
        "type": "function",
        "z": "04ae3d56e09f0645",
        "g": "4471973aed0d711c",
        "name": "Spínání chlazení střídače",
        "func": "var InvTemperature = flow.get(\"InvTemperature\")\nvar shelly = flow.get(\"shelly\");\n\nvar relayState = {\n    relay: 0,\n    on: false\n};\n\nif (InvTemperature > 46) {\n    relayState.on = true;\n}\n\nif (relayState.on) {\n    msg.payload = {\n        relay: 0,\n        on: true\n    };\n} else {\n    msg.payload = {\n        relay: 0,\n        on: false\n    };\n}\n\nreturn msg;\n",
        "outputs": 1,
        "timeout": 0,
        "noerr": 0,
        "initialize": "",
        "finalize": "",
        "libs": [],
        "x": 1230,
        "y": 1200,
        "wires": [
            [
                "753157d6fb24b30a"
            ]
        ]
    },
    {
        "id": "753157d6fb24b30a",
        "type": "shelly-gen1",
        "z": "04ae3d56e09f0645",
        "g": "4471973aed0d711c",
        "hostname": "10.0.10.24",
        "description": "Shelly Plug S - Solax Cooling",
        "mode": "polling",
        "server": "",
        "outputmode": "event",
        "uploadretryinterval": 5000,
        "pollinginterval": "5000",
        "pollstatus": false,
        "getstatusoncommand": true,
        "devicetype": "Relay",
        "devicetypemustmatchexactly": false,
        "outputs": 1,
        "x": 1480,
        "y": 1200,
        "wires": [
            []
        ]
    },
    {
        "id": "59d2db7e33eb38b6",
        "type": "inject",
        "z": "04ae3d56e09f0645",
        "g": "4471973aed0d711c",
        "name": "inject 1x za 1s",
        "props": [
            {
                "p": "payload"
            },
            {
                "p": "topic",
                "vt": "str"
            }
        ],
        "repeat": "1",
        "crontab": "",
        "once": true,
        "onceDelay": "10",
        "topic": "",
        "payload": "",
        "payloadType": "date",
        "x": 1020,
        "y": 1280,
        "wires": [
            [
                "b67c0231bc6cb96f"
            ]
        ]
    },
    {
        "id": "b67c0231bc6cb96f",
        "type": "shelly-gen1",
        "z": "04ae3d56e09f0645",
        "g": "4471973aed0d711c",
        "hostname": "10.0.10.24",
        "description": "Shelly Plug S - Solax Cooling",
        "mode": "polling",
        "server": "033a6e9acf499057",
        "uploadretryinterval": "5000",
        "pollinginterval": "5000",
        "pollstatus": false,
        "getstatusoncommand": false,
        "devicetype": "Relay",
        "devicetypemustmatchexactly": false,
        "outputs": 1,
        "x": 1240,
        "y": 1280,
        "wires": [
            [
                "4641e7b609b2a776"
            ]
        ]
    },
    {
        "id": "4641e7b609b2a776",
        "type": "function",
        "z": "04ae3d56e09f0645",
        "g": "4471973aed0d711c",
        "name": "Chlazení střídače",
        "func": "if (msg.payload.relays[0].ison === true) {\n    msg.payload.relays[0].ison = \"Zapnuto\";\n} else {\n    msg.payload.relays[0].ison = \"Vypnuto\";\n}\nreturn { payload: msg.payload.relays[0].ison };",
        "outputs": 1,
        "timeout": "",
        "noerr": 0,
        "initialize": "",
        "finalize": "",
        "libs": [],
        "x": 1470,
        "y": 1280,
        "wires": [
            [
                "27d7bf6139036df6"
            ]
        ]
    },
    {
        "id": "27d7bf6139036df6",
        "type": "ui_text",
        "z": "04ae3d56e09f0645",
        "g": "4471973aed0d711c",
        "group": "b95997595a206299",
        "order": 3,
        "width": "0",
        "height": "0",
        "name": "",
        "label": "Chlazení střídače",
        "format": "{{msg.payload}}",
        "layout": "row-spread",
        "className": "",
        "style": false,
        "font": "",
        "fontSize": "",
        "color": "#000000",
        "x": 1670,
        "y": 1280,
        "wires": []
    },
    {
        "id": "04263f2d054cc2a1",
        "type": "shelly-gen2-server",
        "port": "10001",
        "hostname": "unimatrix"
    },
    {
        "id": "7ab912b224a2e5e9",
        "type": "ui_group",
        "name": "Vyhřívání bojlerů",
        "tab": "c28c1c92b7ceb034",
        "order": 4,
        "disp": true,
        "width": "9",
        "collapse": false,
        "className": ""
    },
    {
        "id": "033a6e9acf499057",
        "type": "shelly-gen1-server",
        "port": "20001",
        "hostname": ""
    },
    {
        "id": "b95997595a206299",
        "type": "ui_group",
        "name": "Střídač",
        "tab": "c28c1c92b7ceb034",
        "order": 7,
        "disp": true,
        "width": "9",
        "collapse": false,
        "className": ""
    },
    {
        "id": "c28c1c92b7ceb034",
        "type": "ui_tab",
        "name": "FVE",
        "icon": "dashboard",
        "order": 1,
        "disabled": false,
        "hidden": false
    }
]

@windkh
Copy link
Owner

windkh commented Jun 14, 2024

@MrMysakovich I am running your flow here and it seems to work fine... after what time did you get the restarts?

@windkh
Copy link
Owner

windkh commented Jun 14, 2024

@MrMysakovich I see that you trigger your node with an inject node. And at the same time you poll the device every 5000ms. This does not really make sense to do it twice. Either you use mode none and the inject node or you remove the inject node and let the shelly node poll for you. In addition to that: if you only want to be noticed when the some switch is triggered then you better use callback mode. Until now your flow works here without problems. Do you use additional flows that may cause additional CPU load or do you run the flow on a low performance hardware like a raspberry?

@MrMysakovich
Copy link
Author

@windkh I already have it set to "none" and it still restarts Node-RED with the same log output (even Shelly node sometimes says 5000 ms time exceeded even when I have set polling to "none") I have in the same flow also modbus-getter to Solax Hybrid G4 and I read live data from it. Running Node-RED on Raspberry Pi 4B 8GB ram - Homebridge image.

@windkh
Copy link
Owner

windkh commented Jun 15, 2024

Ok then it means that sending the command request to the shelly timed out. I assume that you are running the raspi via wifi?

@MrMysakovich
Copy link
Author

No, wired and I never had problem with Shelly through Homebridge. Really don’t know why it happens :/
Btw Shelly connection is stable.

@windkh
Copy link
Owner

windkh commented Jun 15, 2024

@MrMysakovich
I just tried to reproduce the problem: if I just remove the shelly from the network I get exactly the same output. However node-red does not restart here.

@windkh
Copy link
Owner

windkh commented Jun 15, 2024

@windkh please install V10.25.1
I change a few timeout. If it happens again please send me the node-red log

@MrMysakovich
Copy link
Author

@windkh I updated it. Thank you. Lets see it in few days. Maybe it could be caused that Homebridge image doesn't work well together with Node-RED?

@windkh
Copy link
Owner

windkh commented Jun 15, 2024

@MrMysakovich well the call stack is the same as mine here but my node-red does not restart. I wrap all requests to the shelly with a try catch to avoid that node-red will crash. In you callstack it seems that there was no catch somewhere. In my code I could not find the problem as there are many requests that could cause that. So I added unique timeouts to every request
5001, 5002, ... so we will probably see more in the next stack trace...

@MrMysakovich
Copy link
Author

@windkh So it crashed again, but unfortunately I do not have logs, because somehow logging stopped working. Could you help me please to setup settings.js to log everything?

@windkh
Copy link
Owner

windkh commented Jun 18, 2024

@MrMysakovich can you not just copy the output of the console?

@MrMysakovich
Copy link
Author

MrMysakovich commented Jun 18, 2024 •
edited
Loading

I got this in NR:
image

The main problem is that I get the NR log as a service from the Homebridge terminal, and the logging is active until I exit the window.

18 Jun 13:11:54 - [warn] [shelly-gen1:b67c0231bc6cb96f] timeout of 5012ms exceeded
18 Jun 13:13:48 - [warn] [shelly-gen2:b81ad76ecee44bcb] AxiosError: timeout of 5022ms exceeded
18 Jun 13:48:54 - [warn] [shelly-gen1:b67c0231bc6cb96f] timeout of 5012ms exceeded
18 Jun 13:59:06 - [warn] [shelly-gen1:b67c0231bc6cb96f] timeout of 5012ms exceeded
18 Jun 14:58:06 - [warn] [shelly-gen2:02f241a770528413] AxiosError: timeout of 5022ms exceeded

This time there was no restart of NR.

@MrMysakovich
Copy link
Author

UPDATE: So far, Node-RED hasn't rebooted yet. Let’s see in few more days.

@floppes
Copy link

floppes commented Jun 23, 2024

I had a look at my node-red logs for another reason but found the same crashes as @MrMysakovich.

My setup:
node-red 3.1.8 with node-red-contrib-shelly 10.25.1 running on a Raspberry Pi 4 which is connected via cable to my LAN.
Two Shellies (Plus 2PM and Plus1) where one of them is outside in the garage with a low Wifi signal.

In the logs I have about one to two exceptions with a restart of node-red. Here are the latest four:

Jun 21 12:44:14 raspi-red Node-RED[7797]: 21 Jun 12:44:14 - [red] Uncaught Exception:
Jun 21 12:44:14 raspi-red Node-RED[7797]: 21 Jun 12:44:14 - [error] AxiosError: timeout of 5022ms exceeded
Jun 21 12:44:14 raspi-red Node-RED[7797]:     at RedirectableRequest.handleRequestTimeout (/home/flo/.node-red/node_modules/axios/dist/node/axios.cjs:3123:1>
Jun 21 12:44:14 raspi-red Node-RED[7797]:     at RedirectableRequest.emit (node:events:517:28)
Jun 21 12:44:14 raspi-red Node-RED[7797]:     at Timeout.<anonymous> (/home/flo/.node-red/node_modules/follow-redirects/index.js:210:12)
Jun 21 12:44:14 raspi-red Node-RED[7797]:     at listOnTimeout (node:internal/timers:569:17)
Jun 21 12:44:14 raspi-red Node-RED[7797]:     at process.processTimers (node:internal/timers:512:7)
Jun 21 12:44:14 raspi-red Node-RED[7797]:     at Axios.request (/home/flo/.node-red/node_modules/axios/dist/node/axios.cjs:3876:41)
Jun 21 12:44:14 raspi-red Node-RED[7797]:     at runNextTicks (node:internal/process/task_queues:60:5)
Jun 21 12:44:14 raspi-red Node-RED[7797]:     at listOnTimeout (node:internal/timers:538:9)
Jun 21 12:44:14 raspi-red Node-RED[7797]:     at process.processTimers (node:internal/timers:512:7)

Jun 22 18:10:22 raspi-red Node-RED[8998]: 22 Jun 18:10:22 - [red] Uncaught Exception:
Jun 22 18:10:22 raspi-red Node-RED[8998]: 22 Jun 18:10:22 - [error] AxiosError: timeout of 5022ms exceeded
Jun 22 18:10:22 raspi-red Node-RED[8998]:     at RedirectableRequest.handleRequestTimeout (/home/flo/.node-red/node_modules/axios/dist/node/axios.cjs:3123:1>
Jun 22 18:10:22 raspi-red Node-RED[8998]:     at RedirectableRequest.emit (node:events:517:28)
Jun 22 18:10:22 raspi-red Node-RED[8998]:     at Timeout.<anonymous> (/home/flo/.node-red/node_modules/follow-redirects/index.js:210:12)
Jun 22 18:10:22 raspi-red Node-RED[8998]:     at listOnTimeout (node:internal/timers:569:17)
Jun 22 18:10:22 raspi-red Node-RED[8998]:     at process.processTimers (node:internal/timers:512:7)
Jun 22 18:10:22 raspi-red Node-RED[8998]:     at Axios.request (/home/flo/.node-red/node_modules/axios/dist/node/axios.cjs:3876:41)
Jun 22 18:10:22 raspi-red Node-RED[8998]:     at runNextTicks (node:internal/process/task_queues:60:5)
Jun 22 18:10:22 raspi-red Node-RED[8998]:     at listOnTimeout (node:internal/timers:538:9)
Jun 22 18:10:22 raspi-red Node-RED[8998]:     at process.processTimers (node:internal/timers:512:7)

Jun 22 19:18:24 raspi-red Node-RED[11241]: 22 Jun 19:18:24 - [red] Uncaught Exception:
Jun 22 19:18:24 raspi-red Node-RED[11241]: 22 Jun 19:18:24 - [error] AxiosError: timeout of 5022ms exceeded
Jun 22 19:18:24 raspi-red Node-RED[11241]:     at RedirectableRequest.handleRequestTimeout (/home/flo/.node-red/node_modules/axios/dist/node/axios.cjs:3123:>
Jun 22 19:18:24 raspi-red Node-RED[11241]:     at RedirectableRequest.emit (node:events:517:28)
Jun 22 19:18:24 raspi-red Node-RED[11241]:     at Timeout.<anonymous> (/home/flo/.node-red/node_modules/follow-redirects/index.js:210:12)
Jun 22 19:18:24 raspi-red Node-RED[11241]:     at listOnTimeout (node:internal/timers:569:17)
Jun 22 19:18:24 raspi-red Node-RED[11241]:     at process.processTimers (node:internal/timers:512:7)
Jun 22 19:18:24 raspi-red Node-RED[11241]:     at Axios.request (/home/flo/.node-red/node_modules/axios/dist/node/axios.cjs:3876:41)
Jun 22 19:18:24 raspi-red Node-RED[11241]:     at runNextTicks (node:internal/process/task_queues:60:5)
Jun 22 19:18:24 raspi-red Node-RED[11241]:     at listOnTimeout (node:internal/timers:538:9)
Jun 22 19:18:24 raspi-red Node-RED[11241]:     at process.processTimers (node:internal/timers:512:7)

Jun 23 01:07:22 raspi-red Node-RED[11356]: 23 Jun 01:07:22 - [red] Uncaught Exception:
Jun 23 01:07:22 raspi-red Node-RED[11356]: 23 Jun 01:07:22 - [error] AxiosError: timeout of 5022ms exceeded
Jun 23 01:07:22 raspi-red Node-RED[11356]:     at RedirectableRequest.handleRequestTimeout (/home/flo/.node-red/node_modules/axios/dist/node/axios.cjs:3123:>
Jun 23 01:07:22 raspi-red Node-RED[11356]:     at RedirectableRequest.emit (node:events:517:28)
Jun 23 01:07:22 raspi-red Node-RED[11356]:     at Timeout.<anonymous> (/home/flo/.node-red/node_modules/follow-redirects/index.js:210:12)
Jun 23 01:07:22 raspi-red Node-RED[11356]:     at listOnTimeout (node:internal/timers:569:17)
Jun 23 01:07:22 raspi-red Node-RED[11356]:     at process.processTimers (node:internal/timers:512:7)
Jun 23 01:07:22 raspi-red Node-RED[11356]:     at Axios.request (/home/flo/.node-red/node_modules/axios/dist/node/axios.cjs:3876:41)
Jun 23 01:07:22 raspi-red Node-RED[11356]:     at runNextTicks (node:internal/process/task_queues:60:5)
Jun 23 01:07:22 raspi-red Node-RED[11356]:     at listOnTimeout (node:internal/timers:538:9)
Jun 23 01:07:22 raspi-red Node-RED[11356]:     at process.processTimers (node:internal/timers:512:7)

It's always 5022 ms timeout. I hope this helps you find the problem.

@MrMysakovich
Copy link
Author

New update: Although writing logs doesn't work in my setup now, Node-RED keeps restarting.

@windkh
Copy link
Owner

windkh commented Jun 24, 2024

@MrMysakovich I released 10.25.2 a few minutes ago. I refactored some internal things, please give it a try... maybe it works now. Please let me know ....

@MrMysakovich
Copy link
Author

@windkh Thank you really much, we will see in a few days...

@MrMysakovich
Copy link
Author

MrMysakovich commented Jun 25, 2024 •
edited
Loading

So NR has rebooted randomly again today. Somehow I didn't catch the log (logging in NR still doesn’t work)

@floppes
Copy link

floppes commented Jun 25, 2024

With version 10.25.2 I had a reboot today as well:

Jun 25 16:26:14 raspi-red Node-RED[26941]: 25 Jun 16:26:14 - [red] Uncaught Exception:
Jun 25 16:26:14 raspi-red Node-RED[26941]: 25 Jun 16:26:14 - [error] AxiosError: timeout of 5022ms exceeded
Jun 25 16:26:14 raspi-red Node-RED[26941]:     at RedirectableRequest.handleRequestTimeout (/home/flo/.node-red/node_modules/axios/dist/node/axios.cjs:3123:>
Jun 25 16:26:14 raspi-red Node-RED[26941]:     at RedirectableRequest.emit (node:events:517:28)
Jun 25 16:26:14 raspi-red Node-RED[26941]:     at Timeout.<anonymous> (/home/flo/.node-red/node_modules/follow-redirects/index.js:210:12)
Jun 25 16:26:14 raspi-red Node-RED[26941]:     at listOnTimeout (node:internal/timers:569:17)
Jun 25 16:26:14 raspi-red Node-RED[26941]:     at process.processTimers (node:internal/timers:512:7)
Jun 25 16:26:14 raspi-red Node-RED[26941]:     at Axios.request (/home/flo/.node-red/node_modules/axios/dist/node/axios.cjs:3876:41)
Jun 25 16:26:14 raspi-red Node-RED[26941]:     at runNextTicks (node:internal/process/task_queues:60:5)
Jun 25 16:26:14 raspi-red Node-RED[26941]:     at listOnTimeout (node:internal/timers:538:9)
Jun 25 16:26:14 raspi-red Node-RED[26941]:     at process.processTimers (node:internal/timers:512:7)
Jun 25 16:26:14 raspi-red systemd[1]: nodered.service: Main process exited, code=exited, status=1/FAILURE
Jun 25 16:26:14 raspi-red systemd[1]: nodered.service: Failed with result 'exit-code'.
Jun 25 16:26:14 raspi-red systemd[1]: nodered.service: Consumed 16min 28.310s CPU time.
Jun 25 16:26:34 raspi-red systemd[1]: nodered.service: Scheduled restart job, restart counter is at 1.
Jun 25 16:26:34 raspi-red systemd[1]: Stopped nodered.service - Node-RED graphical event wiring tool.
Jun 25 16:26:34 raspi-red systemd[1]: nodered.service: Consumed 16min 28.310s CPU time.
Jun 25 16:26:34 raspi-red systemd[1]: Started nodered.service - Node-RED graphical event wiring tool.
Jun 25 16:26:35 raspi-red Node-RED[29068]: 25 Jun 16:26:35 - [info]
Jun 25 16:26:35 raspi-red Node-RED[29068]: Welcome to Node-RED
Jun 25 16:26:35 raspi-red Node-RED[29068]: ===================
Jun 25 16:26:35 raspi-red Node-RED[29068]: 25 Jun 16:26:35 - [info] Node-RED version: v3.1.8
Jun 25 16:26:35 raspi-red Node-RED[29068]: 25 Jun 16:26:35 - [info] Node.js  version: v18.20.3
Jun 25 16:26:35 raspi-red Node-RED[29068]: 25 Jun 16:26:35 - [info] Linux 6.6.28+rpt-rpi-v8 arm64 LE
Jun 25 16:26:35 raspi-red Node-RED[29068]: 25 Jun 16:26:35 - [info] Loading palette nodes
Jun 25 16:26:38 raspi-red Node-RED[29068]: 25 Jun 16:26:38 - [info] Settings file  : /home/flo/.node-red/settings.js

@windkh
Copy link
Owner

windkh commented Jun 26, 2024

thanks for the log... I need to think about how to solve it...

@windkh
Copy link
Owner

windkh commented Jun 26, 2024

@MrMysakovich
I tried to reproduce it but failed. I can force a timeout using a shelly simulation and I get the callstack below which looks similar to your one. But it does not crash node-red.

Interestingly the line numbers are different. E.g. http.js:647:16 in my callstack, in your one axios.cjs:3123 see below.
So I ask myself what axios version is in your folder
/home/flo/.node-red/node_modules/axios/package.json

Mine is "1.6.8" (the latest one available is 1.7.2=

26 Jun 21:53:24 - [warn] [shelly-gen2:e8443a89795c5ba5] AxiosError: timeout of 5022ms exceeded
at RedirectableRequest.handleRequestTimeout (C:\Users\wind.node-red\node_modules\node-red-contrib-shelly\node_modules\axios\lib\adapters\http.js:647:16)
at RedirectableRequest.emit (node:events:517:28)
at Timeout. (C:\Users\wind.node-red\node_modules\follow-redirects\index.js:210:12)
at listOnTimeout (node:internal/timers:569:17)
at processTimers (node:internal/timers:512:7)
at Axios.request (C:\Users\wind.node-red\node_modules\node-red-contrib-shelly\node_modules\axios\lib\core\Axios.js:45:41)
at runNextTicks (node:internal/process/task_queues:60:5)
at listOnTimeout (node:internal/timers:538:9)
at processTimers (node:internal/timers:512:7)

@floppes
Copy link

floppes commented Jun 26, 2024

I have axios version 1.6.8 as well.

@floppes
Copy link

floppes commented Jun 27, 2024

I'd really like to help fix this error, I'm curious about the cause. I'm a software developer myself, but I mainly work with .NET and C, only little JavaScript.

I don't know about JavaScript's promises and how a try-catch around an async call behaves, but your code looks like it should catch the timeout exception.

The differences in the stack traces probably result from the type of Node-RED installation. I guess that the code in axios/lib/adapters is transpiled into the single file axios/dist/node/axios.cjs. If you compare axios/lib/adapters/http.js at line 640 with axios/dist/node/axios.cjs at line 3160, it's the same code:

      req.setTimeout(timeout, function handleRequestTimeout() {
        if (isDone) return;
        let timeoutErrorMessage = config.timeout ? 'timeout of ' + config.timeout + 'ms exceeded' : 'timeout exceeded';
        const transitional = config.transitional || transitionalDefaults;
        if (config.timeoutErrorMessage) {
          timeoutErrorMessage = config.timeoutErrorMessage;
        }
        reject(new AxiosError(
          timeoutErrorMessage,
          transitional.clarifyTimeoutError ? AxiosError.ETIMEDOUT : AxiosError.ECONNABORTED,
          config,
          req
        ));
        abort();
      });

I am relatively new to Node-RED. I installed it just 3 months ago. Therefore I still have the whole log :)

So here's a little timeline I reconstructed from the log:

Right from the start I installed node-red-contrib-shelly 10.18.0 and node-red-dashboard 3.6.5 on April 2nd.

The first uncaught exception occured on June 5th in the morning. I didn't notice it, only just a few days ago when I commented here.

I upgraded node-red-contrib-shelly to 10.25.0 on the same day of the exception (June 5th) in the evening (after the exception).

Upgraded node-red-contrib-shelly to 10.25.1 on June 17th.

Upgraded node-red-contrib-shelly to 10.25.2 on June 24th.

The last package I installed was node-red-node-email 2.2.1 on May 29th.

Since then my Node-RED ran without manual restarts/reboots until the first exception on June 5th.

Overall I have 46 uncaught exceptions in my log which restarted Node-RED.

Interestingly, there are 2 axios timeouts just as warnings without stack traces and no restart of Node-RED:

Jun 26 17:23:11 raspi-red Node-RED[30131]: 26 Jun 17:23:11 - [warn] [shelly-gen2:11f2d076facb62a1] Error: AxiosError: timeout of 5000ms exceeded
...
Jun 27 06:59:35 raspi-red Node-RED[32011]: 27 Jun 06:59:35 - [warn] [shelly-gen2:11f2d076facb62a1] Error: AxiosError: timeout of 5000ms exceeded

I hope this helps. If you want, I can send you the whole logfile by mail.

@MrMysakovich
Copy link
Author

My Node-RED is installed through this script:
bash <(curl -sL https://raw.githubusercontent.com/node-red/linux-installers/master/deb/update-nodejs-and-nodered) --node20

on Homebridge Image

@windkh
Copy link
Owner

windkh commented Jun 27, 2024

I'd really like to help fix this error, I'm curious about the cause. I'm a software developer myself, but I mainly work with .NET and C, only little JavaScript.

I don't know about JavaScript's promises and how a try-catch around an async call behaves, but your code looks like it should catch the timeout exception.

The differences in the stack traces probably result from the type of Node-RED installation. I guess that the code in axios/lib/adapters is transpiled into the single file axios/dist/node/axios.cjs. If you compare axios/lib/adapters/http.js at line 640 with axios/dist/node/axios.cjs at line 3160, it's the same code:

      req.setTimeout(timeout, function handleRequestTimeout() {
        if (isDone) return;
        let timeoutErrorMessage = config.timeout ? 'timeout of ' + config.timeout + 'ms exceeded' : 'timeout exceeded';
        const transitional = config.transitional || transitionalDefaults;
        if (config.timeoutErrorMessage) {
          timeoutErrorMessage = config.timeoutErrorMessage;
        }
        reject(new AxiosError(
          timeoutErrorMessage,
          transitional.clarifyTimeoutError ? AxiosError.ETIMEDOUT : AxiosError.ECONNABORTED,
          config,
          req
        ));
        abort();
      });

I am relatively new to Node-RED. I installed it just 3 months ago. Therefore I still have the whole log :)

So here's a little timeline I reconstructed from the log:

Right from the start I installed node-red-contrib-shelly 10.18.0 and node-red-dashboard 3.6.5 on April 2nd.

The first uncaught exception occured on June 5th in the morning. I didn't notice it, only just a few days ago when I commented here.

I upgraded node-red-contrib-shelly to 10.25.0 on the same day of the exception (June 5th) in the evening (after the exception).

Upgraded node-red-contrib-shelly to 10.25.1 on June 17th.

Upgraded node-red-contrib-shelly to 10.25.2 on June 24th.

The last package I installed was node-red-node-email 2.2.1 on May 29th.

Since then my Node-RED ran without manual restarts/reboots until the first exception on June 5th.

Overall I have 46 uncaught exceptions in my log which restarted Node-RED.

Interestingly, there are 2 axios timeouts just as warnings without stack traces and no restart of Node-RED:

Jun 26 17:23:11 raspi-red Node-RED[30131]: 26 Jun 17:23:11 - [warn] [shelly-gen2:11f2d076facb62a1] Error: AxiosError: timeout of 5000ms exceeded
...
Jun 27 06:59:35 raspi-red Node-RED[32011]: 27 Jun 06:59:35 - [warn] [shelly-gen2:11f2d076facb62a1] Error: AxiosError: timeout of 5000ms exceeded

I hope this helps. If you want, I can send you the whole logfile by mail.

@floppes
ok then let's try to do a teams meeting where we can talk about options. Right now I am not happy with the web requests implementation in the nodes. In the beginning I used to use "request" which then was deprecated. I turned to axios which supported async await. So probably I will rewrite the code in the function shellyRequestAsync completely... however before I can not explain where the error comes from it does not make sense to refactor it. We need to find a way to force that bug to appear more frequently. I guess chances are high to eliminate it then.

@floppes
Copy link

floppes commented Jun 28, 2024

Ok, we can try a Teams meeting. From your name I guess you are German like me? You can e-mail me your preferred time for a meeting: floppes [at] gmx [dot] de

Another thing that came to my mind: I enabled authentication in my Shelly devices a few weeks ago. It must have been June 4th because that's when I have the first entry of this kind:

[warn] [shelly-gen2:2a27b195c3b1b31c] Error: Unauthorized /rpc/Shelly.GetStatus

That was the night before the first uncaught exception!

I am still getting this error from time to time (58 times in total) even though the credentials are stored in the nodes.

I will disable authentication now. Maybe this is the cause for the exceptions...

@MrMysakovich
Copy link
Author

@windkh I don’t have any

@windkh
Copy link
Owner

windkh commented Jul 7, 2024

Sorry my mistake... I mean shelly nodes ofcourse

@MrMysakovich
Copy link
Author

The latest one so 10.26.0

@windkh
Copy link
Owner

windkh commented Jul 7, 2024

@MrMysakovich please retry with 10.27.0

@MrMysakovich
Copy link
Author

@windkh you mean 10.26.2? I updated it. Let’s see, thanks

@windkh
Copy link
Owner

windkh commented Jul 7, 2024

No 10.27.0

@MrMysakovich
Copy link
Author

I don’t see update to 10.27.0

IMG_8190

@windkh
Copy link
Owner

windkh commented Jul 7, 2024

I just released it a few minutes ago... maybe the nr server needs some time to outroll it

@MrMysakovich
Copy link
Author

Updated.

@MrMysakovich
Copy link
Author

MrMysakovich commented Jul 8, 2024 •
edited
Loading

Now this, one random restart of NR happened.

8 Jul 15:53:40 - [warn] [shelly-gen1:b67c0231bc6cb96f] getaddrinfo ENOTFOUND undefined
8 Jul 15:53:41 - [warn] [shelly-gen1:b67c0231bc6cb96f] getaddrinfo ENOTFOUND undefined
8 Jul 15:53:42 - [warn] [shelly-gen1:b67c0231bc6cb96f] getaddrinfo ENOTFOUND undefined
8 Jul 15:53:43 - [warn] [shelly-gen1:b67c0231bc6cb96f] getaddrinfo ENOTFOUND undefined
8 Jul 15:53:44 - [warn] [shelly-gen1:b67c0231bc6cb96f] getaddrinfo ENOTFOUND undefined
8 Jul 15:53:45 - [warn] [shelly-gen1:b67c0231bc6cb96f] getaddrinfo ENOTFOUND undefined
8 Jul 15:53:46 - [warn] [shelly-gen1:b67c0231bc6cb96f] getaddrinfo ENOTFOUND undefined
8 Jul 15:53:47 - [warn] [shelly-gen1:b67c0231bc6cb96f] getaddrinfo ENOTFOUND undefined
8 Jul 15:53:48 - [warn] [shelly-gen1:b67c0231bc6cb96f] getaddrinfo ENOTFOUND undefined
8 Jul 15:53:49 - [warn] [shelly-gen1:b67c0231bc6cb96f] getaddrinfo ENOTFOUND undefined
8 Jul 15:54:30 - [warn] [shelly-gen2:5f72fa3adf200141] Error: read ECONNRESET
8 Jul 15:54:30 - [warn] [shelly-gen2:1cb729744d7be53d] Error: read ECONNRESET

@MrMysakovich
Copy link
Author 

8 Jul 16:01:13 - [red] Uncaught Exception:
8 Jul 16:01:13 - [error] AxiosError: timeout of 5022ms exceeded
    at RedirectableRequest.handleRequestTimeout (/home/pi/.node-red/node_modules/axios/lib/adapters/http.js:647:16)
    at RedirectableRequest.emit (node:events:519:28)
    at Timeout.<anonymous> (/home/pi/.node-red/node_modules/follow-redirects/index.js:210:12)
    at listOnTimeout (node:internal/timers:573:17)
    at processTimers (node:internal/timers:514:7)
    at Axios.request (/home/pi/.node-red/node_modules/axios/lib/core/Axios.js:45:41)
nodered.service: Main process exited, code=exited, status=1/FAILURE
nodered.service: Failed with result 'exit-code'.
nodered.service: Consumed 39.608s CPU time.
nodered.service: Scheduled restart job, restart counter is at 1.
Stopped nodered.service - Node-RED graphical event wiring tool.
nodered.service: Consumed 39.608s CPU time.
Started nodered.service - Node-RED graphical event wiring tool.

@floppes
Copy link

floppes commented Jul 9, 2024

It has been running fine for me for the last days, but this morning I got two undhandled exceptions again:

Jul 09 10:36:45 raspi-red Node-RED[60217]: 9 Jul 10:36:45 - [red] Uncaught Exception:
Jul 09 10:36:45 raspi-red Node-RED[60217]: 9 Jul 10:36:45 - [error] AxiosError: timeout of 5022ms exceeded
Jul 09 10:36:45 raspi-red Node-RED[60217]:     at RedirectableRequest.handleRequestTimeout (/home/flo/.node-red/node_modules/axios/dist/node/axios.cjs:3123:>
Jul 09 10:36:45 raspi-red Node-RED[60217]:     at RedirectableRequest.emit (node:events:517:28)
Jul 09 10:36:45 raspi-red Node-RED[60217]:     at Timeout.<anonymous> (/home/flo/.node-red/node_modules/follow-redirects/index.js:210:12)
Jul 09 10:36:45 raspi-red Node-RED[60217]:     at listOnTimeout (node:internal/timers:569:17)
Jul 09 10:36:45 raspi-red Node-RED[60217]:     at process.processTimers (node:internal/timers:512:7)
Jul 09 10:36:45 raspi-red Node-RED[60217]:     at Axios.request (/home/flo/.node-red/node_modules/axios/dist/node/axios.cjs:3876:41)
Jul 09 10:36:45 raspi-red Node-RED[60217]:     at runNextTicks (node:internal/process/task_queues:60:5)
Jul 09 10:36:45 raspi-red Node-RED[60217]:     at listOnTimeout (node:internal/timers:538:9)
Jul 09 10:36:45 raspi-red Node-RED[60217]:     at process.processTimers (node:internal/timers:512:7)

...

Jul 09 10:37:21 raspi-red Node-RED[80029]: 9 Jul 10:37:21 - [red] Uncaught Exception:
Jul 09 10:37:21 raspi-red Node-RED[80029]: 9 Jul 10:37:21 - [error] AxiosError: timeout of 5022ms exceeded
Jul 09 10:37:21 raspi-red Node-RED[80029]:     at RedirectableRequest.handleRequestTimeout (/home/flo/.node-red/node_modules/axios/dist/node/axios.cjs:3123:>
Jul 09 10:37:21 raspi-red Node-RED[80029]:     at RedirectableRequest.emit (node:events:517:28)
Jul 09 10:37:21 raspi-red Node-RED[80029]:     at Timeout.<anonymous> (/home/flo/.node-red/node_modules/follow-redirects/index.js:210:12)
Jul 09 10:37:21 raspi-red Node-RED[80029]:     at listOnTimeout (node:internal/timers:569:17)
Jul 09 10:37:21 raspi-red Node-RED[80029]:     at process.processTimers (node:internal/timers:512:7)
Jul 09 10:37:21 raspi-red Node-RED[80029]:     at Axios.request (/home/flo/.node-red/node_modules/axios/dist/node/axios.cjs:3876:41)
Jul 09 10:37:21 raspi-red Node-RED[80029]:     at runNextTicks (node:internal/process/task_queues:60:5)
Jul 09 10:37:21 raspi-red Node-RED[80029]:     at listOnTimeout (node:internal/timers:538:9)
Jul 09 10:37:21 raspi-red Node-RED[80029]:     at process.processTimers (node:internal/timers:512:7)

I was still on 10.26.0 und will update to 10.27.3 now.

@Baloo52
Copy link

Baloo52 commented Jul 16, 2024 •
edited
Loading

Hi,
any news about this issues? I update to 10.28.1
Some devices says sometime read ECONNRESET and NR restart 10-20 times a day.

Regards

@reini12345
Copy link

reini12345 commented Aug 6, 2024 •
edited
Loading

same for me:

`=================
6 Aug 20:36:46 - [red] Uncaught Exception:
6 Aug 20:36:46 - [error] AxiosError: timeout of 5022ms exceeded
at RedirectableRequest.handleRequestTimeout (/data/node_modules/node-red-contrib-shelly/node_modules/axios/lib/adapters/http.js:647:16)
at RedirectableRequest.emit (node:events:519:28)
at Timeout. (/data/node_modules/follow-redirects/index.js:210:12)
at listOnTimeout (node:internal/timers:573:17)
at processTimers (node:internal/timers:514:7)
at Axios.request (/data/node_modules/node-red-contrib-shelly/node_modules/axios/lib/core/Axios.js:45:41)
6 Aug 20:36:48 - [info]
Welcome to Node-RED

6 Aug 20:36:48 - [info] Node-RED version: v4.0.2
6 Aug 20:36:48 - [info] Node.js version: v20.15.1
6 Aug 20:36:48 - [info] Linux 6.2.16-4-pve x64 LE
6 Aug 20:36:48 - [info] Loading palette nodes
6 Aug 20:36:49 - [info] node-red-contrib-ccu version: 3.4.2
6 Aug 20:36:50 - [info] Dashboard version 3.4.0 started at /ui
6 Aug 20:36:50 - [warn] ------------------------------------------------------
6 Aug 20:36:50 - [warn] [node-red-node-rbe/rbe] 'rbe' already registered by module node-red
6 Aug 20:36:50 - [warn] ------------------------------------------------------
6 Aug 20:36:50 - [info] Settings file : /data/settings.js
6 Aug 20:36:50 - [info] Context store : 'default' [module=localfilesystem]
6 Aug 20:36:50 - [info] User directory : /data
6 Aug 20:36:50 - [warn] Projects disabled : editorTheme.projects.enabled=false
6 Aug 20:36:50 - [info] Flows file : /data/flows.json
6 Aug 20:36:50 - [info] Server now running at http://127.0.0.1:1880/
6 Aug 20:36:50 - [warn] `

@windkh
Copy link
Owner

windkh commented Sep 8, 2024

Sorry for delay: I am back from vacation... any news here? I will fix this if I am able to reproduce it. Any ideas?

@MrMysakovich
Copy link
Author

@windkh Hi, I hope you enjoyed your vacation!

Look at this screenshot:
IMG_9871

@windkh
Copy link
Owner

windkh commented Sep 8, 2024

@MrMysakovich please send me your flow. And the output of the console with node-red nodejs version. Shelly nodes version.
On what machine do you run that nodes? raspi? Docker?

@MrMysakovich
Copy link
Author

MrMysakovich commented Sep 8, 2024 •
edited
Loading

@windkh Look up, it's still the same flow. I am creator of this thread.

@windkh
Copy link
Owner

windkh commented Sep 8, 2024

@MrMysakovich what version of the nodes do you use?

@MrMysakovich
Copy link
Author

@windkh 10.28.2 so the latest one. NR rebooted 127 times in the last 5 hours
IMG_9883

@windkh
Copy link
Owner

windkh commented Sep 16, 2024

@MrMysakovich can you please upgrade to 11.0.1. Let me know if something changed. Thanks in advance.

@MrMysakovich
Copy link
Author

@windkh I updated it. I will let you know in one week. Thank you

@floppes
Copy link

floppes commented Sep 24, 2024

@windkh I updated to 11.0.1 a week ago and had one restart since then:

Sep 18 13:24:37 raspi-red Node-RED[228928]: 18 Sep 13:24:37 - [red] Uncaught Exception:
Sep 18 13:24:37 raspi-red Node-RED[228928]: 18 Sep 13:24:37 - [error] AxiosError: timeout of 5022ms exceeded
Sep 18 13:24:37 raspi-red Node-RED[228928]:     at RedirectableRequest.handleRequestTimeout (/home/flo/.node-red/node_modules/axios/dist/node/axios.cjs:3193:16)
Sep 18 13:24:37 raspi-red Node-RED[228928]:     at RedirectableRequest.emit (node:events:517:28)
Sep 18 13:24:37 raspi-red Node-RED[228928]:     at Timeout.<anonymous> (/home/flo/.node-red/node_modules/follow-redirects/index.js:210:12)
Sep 18 13:24:37 raspi-red Node-RED[228928]:     at listOnTimeout (node:internal/timers:569:17)
Sep 18 13:24:37 raspi-red Node-RED[228928]:     at process.processTimers (node:internal/timers:512:7)
Sep 18 13:24:37 raspi-red Node-RED[228928]:     at Axios.request (/home/flo/.node-red/node_modules/axios/dist/node/axios.cjs:4287:41)
Sep 18 13:24:37 raspi-red systemd[1]: nodered.service: Main process exited, code=exited, status=1/FAILURE
Sep 18 13:24:37 raspi-red systemd[1]: nodered.service: Failed with result 'exit-code'.
Sep 18 13:24:37 raspi-red systemd[1]: nodered.service: Consumed 15min 45.455s CPU time.
Sep 18 13:24:57 raspi-red systemd[1]: nodered.service: Scheduled restart job, restart counter is at 1.
Sep 18 13:24:57 raspi-red systemd[1]: Stopped nodered.service - Node-RED graphical event wiring tool.
Sep 18 13:24:57 raspi-red systemd[1]: nodered.service: Consumed 15min 45.455s CPU time.
Sep 18 13:24:57 raspi-red systemd[1]: Started nodered.service - Node-RED graphical event wiring tool.
Sep 18 13:24:58 raspi-red Node-RED[250345]: 18 Sep 13:24:58 - [info]
Sep 18 13:24:58 raspi-red Node-RED[250345]: Welcome to Node-RED
Sep 18 13:24:58 raspi-red Node-RED[250345]: ===================

Did you try to reproduce the error with authentication enabled in the Shelly device?
I have no restarts when I disable authentication. But I'd like to keep authentication enabled for more security.

@windkh
Copy link
Owner

windkh commented Sep 24, 2024

@floppes
thanks for the hint: I will active authentication then

@MrMysakovich
Copy link
Author

MrMysakovich commented Sep 24, 2024 •
edited
Loading

I have authentication ON as well. As you see, after update of plugin, NR had to reboot 139 times.

24 Sep 14:08:21 - [error] AxiosError: timeout of 5022ms exceeded
    at RedirectableRequest.handleRequestTimeout (/home/pi/.node-red/node_modules/axios/lib/adapters/http.js:657:16)
    at RedirectableRequest.emit (node:events:519:28)
    at Timeout.<anonymous> (/home/pi/.node-red/node_modules/follow-redirects/index.js:210:12)
    at listOnTimeout (node:internal/timers:581:17)
    at processTimers (node:internal/timers:519:7)
    at Axios.request (/home/pi/.node-red/node_modules/axios/lib/core/Axios.js:45:41)
    at runNextTicks (node:internal/process/task_queues:60:5)
    at listOnTimeout (node:internal/timers:545:9)
    at processTimers (node:internal/timers:519:7)
nodered.service: Main process exited, code=exited, status=1/FAILURE
nodered.service: Failed with result 'exit-code'.
nodered.service: Consumed 2min 41.844s CPU time.
nodered.service: Scheduled restart job, restart counter is at 139.
Stopped nodered.service - Node-RED graphical event wiring tool.
nodered.service: Consumed 2min 41.844s CPU time.```

@reini12345
Copy link

Hello, I also have authentication on. After the last updates on the Shellys themselves I got this error in NodeRed
chrome_jBWXmqhOui

@windkh
Copy link
Owner

windkh commented Sep 27, 2024

Hello, I also have authentication on. After the last updates on the Shellys themselves I got this error in NodeRed chrome_jBWXmqhOui

Was that a shelly gen1 that caused the problem?

@reini12345
Copy link

reini12345 commented Sep 27, 2024 •
edited
Loading

@windkh yes

For most Gen2 devices, I have disabled the polling option and use mqtt instead.

@windkh
Copy link
Owner

windkh commented Oct 20, 2024

I need someone who can show me this in a teams meeting. Anyone here who is willing to show me what is going on?

@Baloo52
Copy link

Baloo52 commented Oct 20, 2024 via email

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
5 participants
@windkh @floppes @MrMysakovich @Baloo52 @reini12345