Restart of JS-Adapter when error in Promise function #1022

GreatSUN · 2022-05-04T18:56:10Z

When there is an error in a function in a promise (see code below) then the adapter cannot identify where the error comes from and restarts the adapter. I hope that I have created a reasonable example code, because I have changed my implementation meanwhile to node-fetch and fixed all potential errors. It at least did what I described when I tried it here.

function callFunction(testVar) { console.log(testMeVar); } var request = require('then-request'); request('GET', 'http://example.com').done(function (res) { callFunction('test'); })

Expected behavior
The code should raise an error, but the instance should not be restarted.

Screenshots & Logfiles
20:53:18.081 | error | javascript.0 (527) script.js.Test.TestScript: ReferenceError: testMeVar is not defined
20:53:18.081 | error | javascript.0 (527) at callFunction (script.js.Test.TestScript:2:17)
20:53:18.082 | error | javascript.0 (527) at script.js.Test.TestScript:6:5
20:53:18.205 | error | host.iobroker Caught by controller[0]: at callFunction (script.js.Test.TestScript:364:17)
20:53:18.205 | error | host.iobroker Caught by controller[0]: at script.js.Test.TestScript:368:5

Versions:

Adapter version: v5.6.0
JS-Controller version: 4.0.23
Node version: v16.15.0
Operating system: Slackware Host + Debian 11.3 in container managed by podman

The text was updated successfully, but these errors were encountered:

Apollon77 · 2022-05-04T20:25:04Z

Is the instance really restarted? Please post more log

GreatSUN · 2022-05-05T18:25:21Z

Here the output of the main log (sorry for the crazy icons):

2022-05-04 20:53:18.081  - �[31merror�[39m: javascript.0 (527) script.js.Test.TestScript: ReferenceError: testMeVar is not defined
2022-05-04 20:53:18.081  - �[31merror�[39m: javascript.0 (527)     at callFunction (script.js.Test.TestScript:2:17)
2022-05-04 20:53:18.082  - �[31merror�[39m: javascript.0 (527)     at script.js.Test.TestScript:6:5
2022-05-04 20:53:18.082  - �[31merror�[39m: javascript.0 (527)     at tryCallOne (/opt/iobroker/node_modules/promise/lib/core.js:37:12)
2022-05-04 20:53:18.082  - �[31merror�[39m: javascript.0 (527)     at /opt/iobroker/node_modules/promise/lib/core.js:123:15
2022-05-04 20:53:18.082  - �[31merror�[39m: javascript.0 (527)     at flush (/opt/iobroker/node_modules/asap/raw.js:50:29)
2022-05-04 20:53:18.083  - �[31merror�[39m: javascript.0 (527)     at processTicksAndRejections (node:internal/process/task_queues:78:11)
2022-05-04 20:53:18.205  - �[31merror�[39m: host.iobroker Caught by controller[0]: ReferenceError: testMeVar is not defined
2022-05-04 20:53:18.205  - �[31merror�[39m: host.iobroker Caught by controller[0]:     at callFunction (script.js.Test.TestScript:364:17)
2022-05-04 20:53:18.205  - �[31merror�[39m: host.iobroker Caught by controller[0]:     at script.js.Test.TestScript:368:5
2022-05-04 20:53:18.205  - �[31merror�[39m: host.iobroker Caught by controller[0]:     at tryCallOne (/opt/iobroker/node_modules/promise/lib/core.js:37:12)
2022-05-04 20:53:18.205  - �[31merror�[39m: host.iobroker Caught by controller[0]:     at /opt/iobroker/node_modules/promise/lib/core.js:123:15
2022-05-04 20:53:18.206  - �[31merror�[39m: host.iobroker Caught by controller[0]:     at flush (/opt/iobroker/node_modules/asap/raw.js:50:29)
2022-05-04 20:53:18.206  - �[31merror�[39m: host.iobroker Caught by controller[0]:     at processTicksAndRejections (node:internal/process/task_queues:78:11)
2022-05-04 20:53:18.206  - �[31merror�[39m: host.iobroker instance system.adapter.javascript.0 terminated with code 1 (JS_CONTROLLER_STOPPED)
2022-05-04 20:53:18.206  - �[32minfo�[39m: host.iobroker Restart adapter system.adapter.javascript.0 because enabled
2022-05-04 20:53:48.280  - �[32minfo�[39m: host.iobroker instance system.adapter.javascript.0 started with pid 591

Apollon77 · 2022-05-06T13:47:48Z

I checked it and yes it seems that since node.js 16 "Unhandled rejections" like in your case can be grabbed with a listener (and we do this), but the node process will exit in any case once this happens :-(

stale · 2023-05-09T02:42:46Z

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs within the next 7 days. Please check if the issue is still relevant in the most current version of the adapter and tell us. Also check that all relevant details, logs and reproduction steps are included and update them if needed. Thank you for your contributions.
Dieses Problem wurde automatisch als veraltet markiert, da es in letzter Zeit keine Aktivitäten gab. Es wird geschlossen, wenn nicht innerhalb der nächsten 7 Tage weitere Aktivitäten stattfinden. Bitte überprüft, ob das Problem auch in der aktuellsten Version des Adapters noch relevant ist, und teilt uns dies mit. Überprüft auch, ob alle relevanten Details, Logs und Reproduktionsschritte enthalten sind bzw. aktualisiert diese. Vielen Dank für Eure Unterstützung.

ticaki · 2023-11-10T15:48:14Z

nodejs: v18.18.2

io-package.json:
"compact": false,
"nodeProcessParams": ["--unhandled-rejections=warn"],

Testscript:

async function test() {
    return await messageToAsync('test','test', {timeout: 1000})
}
async function test2 () {
    return await test()
}
test2()

Log:



2023-11-10 16:46:10.565 - info: javascript.0 (50870) Start javascript script.js.Test.Skript_1
2023-11-10 16:46:10.576 - info: javascript.0 (50870) script.js.Test.Skript_1: registered 0 subscriptions, 0 schedules, 0 messages, 0 logs and 0 file subscriptions
2023-11-10 16:46:11.577 - error: javascript.0 (50870) Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch().
2023-11-10 16:46:11.578 - error: javascript.0 (50870) unhandled promise rejection: undefined
2023-11-10 16:46:11.578 - error: javascript.0 (50870) undefined

...


2023-11-10 16:46:11.634 - info: javascript.0 (50870) terminating
2023-11-10 16:46:11.635 - warn: javascript.0 (50870) Terminated (UNCAUGHT_EXCEPTION): Without reason
2023-11-10 16:46:12.112 - info: javascript.0 (50870) terminating
2023-11-10 16:46:12.215 - error: host.iobroker Caught by controller[0]: This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). The promise rejected with the reason:
2023-11-10 16:46:12.216 - error: host.iobroker Caught by controller[1]: timeout
2023-11-10 16:46:12.216 - error: host.iobroker Caught by controller[2]: (node:50870) UnhandledPromiseRejectionWarning: timeout
2023-11-10 16:46:12.216 - error: host.iobroker Caught by controller[2]: (Use `node --trace-warnings ...` to show where the warning was created)
2023-11-10 16:46:12.216 - error: host.iobroker Caught by controller[3]: (node:50870) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 4)
2023-11-10 16:46:12.216 - error: host.iobroker instance system.adapter.javascript.0 terminated with code 6 (UNCAUGHT_EXCEPTION)
2023-11-10 16:46:12.216 - info: host.iobroker Restart adapter system.adapter.javascript.0 because enabled
2023-11-10 16:46:20.573 - info: admin.0 (576) <== Disconnect system.user.admin from ::ffff:192.168.178.133 javascript
2023-11-10 16:46:42.260 - info: host.iobroker instance system.adapter.javascript.0 started with pid 57320

klein0r · 2023-11-11T08:16:23Z

@ticaki Yes, because it is also an unhandled exception.
You can shorten your test script like

throw new Error('test');

ticaki · 2023-11-11T08:22:52Z

Test and report requested by Apollon77. :)

to test this: ioBroker/ioBroker.js-controller#844 (comment)

klein0r · 2023-11-14T08:02:52Z

Looks like the "new" common.nodeProcessParams: ["--unhandled-rejections=warn"] is available since js-controller 5

ioBroker/ioBroker.js-controller#2123

Using this feature will disable the possibility to start the adapter in compact mode

Mhhh - if specified, the adapter won't start in compact mode anymore? Are there any statistics, how many users are running their system in compact mode and have the JavaScript adapter installed @Apollon77 ?

Apollon77 · 2023-11-14T20:19:17Z

Start not anymore? this was never reported and yes there should be a log when using compact but there should be no error or such.

ticaki · 2023-11-14T21:24:26Z

If compact is allowed, "common.nodeProcessParams" is not activated, regardless of whether it is used.

2023-11-10 15:01:38.436 - warn: host.iobroker Adapter javascript has "compact=true" as well as "nodeProcessParams" specified, this is not supported, please report to developer

klein0r · 2023-11-15T07:10:52Z

Of course - but the warning will be raised when common.compact is set to true - which means: on every adapter start.

https://github.com/ioBroker/ioBroker.js-controller/blob/bb422a02d9a94a000eae16cf0c342485b028e224/packages/controller/src/main.ts#L4117-L4122

So compact mode support must be disabled completely:

ioBroker.javascript/io-package.json

Line 142 in 939b0b0

"compact": true,

Otherwise the warning will be raised on every start. Even if the instance is not running in compact mode. That will lead to many issues (because it should be reported to the developers).

Apollon77 · 2023-11-15T12:00:45Z

I would more fevor then a js-controller issue to only log this message if compact is szpported and also active foir this instance ... to then log on start :-)

In fact till now - to be honest additionally - this setting do not seem to have a noticeable solving effect for issues with uhancled rejections :-)

Apollon77 mentioned this issue Jun 9, 2022

Allow to add custom start parameters to instances ioBroker/ioBroker.js-controller#844

Closed

stale bot added the wontfix label May 9, 2023

stale bot removed the wontfix label Nov 11, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Restart of JS-Adapter when error in Promise function #1022

Restart of JS-Adapter when error in Promise function #1022

GreatSUN commented May 4, 2022

Apollon77 commented May 4, 2022

GreatSUN commented May 5, 2022 •

edited by Apollon77

Apollon77 commented May 6, 2022 •

edited

stale bot commented May 9, 2023

ticaki commented Nov 10, 2023 •

edited

klein0r commented Nov 11, 2023

ticaki commented Nov 11, 2023 •

edited

klein0r commented Nov 14, 2023 •

edited

Apollon77 commented Nov 14, 2023

ticaki commented Nov 14, 2023

klein0r commented Nov 15, 2023

Apollon77 commented Nov 15, 2023

Restart of JS-Adapter when error in Promise function #1022

Restart of JS-Adapter when error in Promise function #1022

Comments

GreatSUN commented May 4, 2022

Apollon77 commented May 4, 2022

GreatSUN commented May 5, 2022 • edited by Apollon77

Apollon77 commented May 6, 2022 • edited

stale bot commented May 9, 2023

ticaki commented Nov 10, 2023 • edited

klein0r commented Nov 11, 2023

ticaki commented Nov 11, 2023 • edited

klein0r commented Nov 14, 2023 • edited

Apollon77 commented Nov 14, 2023

ticaki commented Nov 14, 2023

klein0r commented Nov 15, 2023

Apollon77 commented Nov 15, 2023

GreatSUN commented May 5, 2022 •

edited by Apollon77

Apollon77 commented May 6, 2022 •

edited

ticaki commented Nov 10, 2023 •

edited

ticaki commented Nov 11, 2023 •

edited

klein0r commented Nov 14, 2023 •

edited