[Bug]: Schedule command seems to be ignored during boot up (each fresh IOBroker start)

[Helmut1965]

I'm sure that

• This issue is still present in the current beta version of this adapter
• There is no other (open) issue with the same topic (use the search!)
• This issue is not described in the adapter documentation / FAQ (read the docs!)

Script type

Javascript

The problem

I create the following script for testing:
function Test1() { log('In Function','error'); setState('0_userdata.0.Allgemein.TestBoot', 'test', false); }; log('Script Test1 gestartet:','error'); schedule("*/10 * * * * *", Test1 );

Expected behavior: After boot up, the scipt logs a message 'Script Test1 gestartet". Creates a cron schedule which logs a message each 10s with In Function

This works during normal operation. In case the system is booted the script doesn't work like expected. During boot, the log entry "Script Test1 gestartet:" isnn't shown and the schedule statement seems to be ignored. The script is firing the text "In function" more than 1000 times a minute until it's automatically stopped.
To solve the problem I have to enter: iobroker restart javascript.0 and all works well.

iobroker.current.log (in debug mode!)

Shutdown at 13:55:35 -> Boot at 13:59:24
2024-04-17 13:55:35.534 - ^[[32minfo^[[39m: javascript.0 (2626) terminating
2024-04-17 13:59:24.355 - ^[[31merror^[[39m: javascript.0 (953) script.js.Technik.Heizung.BootTestScript: In Function
2024-04-17 13:59:24.410 - ^[[31merror^[[39m: javascript.0 (953) script.js.Technik.Heizung.BootTestScript: In Function
2024-04-17 13:59:24.441 - ^[[31merror^[[39m: javascript.0 (953) script.js.Technik.Heizung.BootTestScript: In Function
2024-04-17 13:59:24.475 - ^[[31merror^[[39m: javascript.0 (953) script.js.Technik.Heizung.BootTestScript: In Function
2024-04-17 13:59:24.492 - ^[[31merror^[[39m: javascript.0 (953) script.js.Technik.Heizung.BootTestScript: In Function
2024-04-17 13:59:24.851 - ^[[31merror^[[39m: javascript.0 (953) script.js.Technik.Heizung.BootTestScript: In Function
2024-04-17 13:59:24.870 - ^[[31merror^[[39m: javascript.0 (953) script.js.Technik.Heizung.BootTestScript: In Function
2024-04-17 13:59:24.884 - ^[[31merror^[[39m: javascript.0 (953) script.js.Technik.Heizung.BootTestScript: In Function
2024-04-17 13:59:24.912 - ^[[31merror^[[39m: javascript.0 (953) script.js.Technik.Heizung.BootTestScript: In Function
2024-04-17 13:59:24.956 - ^[[31merror^[[39m: javascript.0 (953) script.js.Technik.Heizung.BootTestScript: In Function
fireing same entry more than 1000 times
...
2024-04-17 14:01:16.146 - ^[[31merror^[[39m: javascript.0 (953) script.js.Technik.Heizung.BootTestScript: In Function
2024-04-17 14:01:16.156 - ^[[31merror^[[39m: javascript.0 (953) script.js.Technik.Heizung.BootTestScript: In Function
2024-04-17 14:01:16.168 - ^[[31merror^[[39m: javascript.0 (953) Script script.js.Technik.Heizung.BootTestScript is calling setState more than 1000 times per minute! Stopping Script now! Please check your script!
2024-04-17 14:01:16.169 - ^[[32minfo^[[39m: javascript.0 (953) Stop script script.js.Technik.Heizung.BootTestScript

Just for information: In case I do a adapter restart the log looks completly different it looks like
2024-04-17 14:02:01.560 - ^[[34mdebug^[[39m: javascript.0 (1188) Redis Objects: Use Redis connection: 127.0.0.1:9001
2024-04-17 14:02:01.600 - ^[[34mdebug^[[39m: javascript.0 (1188) Objects client ready ... initialize now
2024-04-17 14:02:01.602 - ^[[34mdebug^[[39m: javascript.0 (1188) Objects create System PubSub Client
2024-04-17 14:02:01.604 - ^[[34mdebug^[[39m: javascript.0 (1188) Objects create User PubSub Client
2024-04-17 14:02:01.649 - ^[[34mdebug^[[39m: javascript.0 (1188) Objects client initialize lua scripts
2024-04-17 14:02:01.658 - ^[[34mdebug^[[39m: javascript.0 (1188) Objects connected to redis: 127.0.0.1:9001
2024-04-17 14:02:01.696 - ^[[34mdebug^[[39m: javascript.0 (1188) Redis States: Use Redis connection: 127.0.0.1:9000
2024-04-17 14:02:01.711 - ^[[34mdebug^[[39m: javascript.0 (1188) States create System PubSub Client
2024-04-17 14:02:01.713 - ^[[34mdebug^[[39m: javascript.0 (1188) States create User PubSub Client
2024-04-17 14:02:01.780 - ^[[34mdebug^[[39m: javascript.0 (1188) States connected to redis: 127.0.0.1:9000
2024-04-17 14:02:01.834 - ^[[34mdebug^[[39m: javascript.0 (1188) Plugin sentry Initialize Plugin (enabled=true)
2024-04-17 14:02:01.837 - ^[[32minfo^[[39m: javascript.0 (1188) Plugin sentry Sentry Plugin disabled for this process because data reporting is disabled on instance
2024-04-17 14:02:02.032 - ^[[32minfo^[[39m: javascript.0 (1188) starting. Version 7.8.0 in /opt/iobroker/node_modules/iobroker.javascript, node: v18.20.2, js-controller: 5.0.19
2024-04-17 14:02:02.103 - ^[[34mdebug^[[39m: javascript.0 (1188) Loaded TypeScript definitions for node: ["node_modules/@types/node/package.json","node_modules/@types/node/index.d.ts","node_modules/@types/node/assert.d.ts","node_modules/@types/node/assert/strict.d.ts","node_modules/@types/node/globals.d.ts","node_modules/@types/node/async_hooks.d.ts","node_modules/@types/node/buffer.d.ts","node_modules/@types/node/child_process.d.ts","node_modules/@types/node/cluster.d.ts","node_modules/@types/node/console.d.ts","node_modules/@types/node/constants.d.ts","node_modules/@types/node/crypto.d.ts","node_modules/@types/node/dgram.d.ts","node_modules/@types/node/diagnostics_channel.d.ts","node_modules/@types/node/dns.d.ts","node_modules/@types/node/dns/promises.d.ts","node_modules/@types/node/domain.d.ts","node_modules/@types/node/dom-events.d.ts","node_modules/@types/node/events.d.ts","node_modules/@types/node/fs.d.ts","node_modules/@types/node/fs/promises.d.ts","node_modules/@types/node/http.d.ts","node_modules/@types/node/http2.d.ts","node_modules/@types/node/https.d.ts","node_modules/@types/node/inspector.d.ts","node_modules/@types/node/module.d.ts","node_modules/@types/node/net.d.ts","node_modules/@types/node/os.d.ts","node_modules/@types/node/path.d.ts","node_modules/@types/node/perf_hooks.d.ts","node_modules/@types/node/process.d.ts","node_modules/@types/node/punycode.d.ts","node_modules/@types/node/querystring.d.ts","node_modules/@types/node/readline.d.ts","node_modules/@types/node/readline/promises.d.ts","node_modules/@types/node/repl.d.ts","node_modules/@types/node/sea.d.ts","node_modules/@types/node/stream.d.ts","node_modules/@types/node/stream/promises.d.ts","node_modules/@types/node/stream/consumers.d.ts","node_modules/@types/node/stream/web.d.ts","node_modules/@types/node/string_decoder.d.ts","node_modules/@types/node/test.d.ts","node_modules/@types/node/timers.d.ts","node_modules/@types/node/timers/promises.d.ts","node_modules/@types/node/tls.d.ts","node_modules/@types/node/trace_events.d.ts","node_modules/@types/node/tty.d.ts","node_modules/@types/node/url.d.ts","node_modules/@types/node/util.d.ts","node_modules/@types/node/v8.d.ts","node_modules/@types/node/vm.d.ts","node_modules/@types/node/wasi.d.ts","node_modules/@types/node/worker_threads.d.ts","node_modules/@types/node/zlib.d.ts","node_modules/@types/node/globals.global.d.ts"]
2024-04-17 14:02:02.126 - ^[[34mdebug^[[39m: javascript.0 (1188) Loaded TypeScript definitions for request: ["node_modules/@types/request/package.json","node_modules/@types/request/index.d.ts"]
2024-04-17 14:02:02.622 - ^[[32minfo^[[39m: javascript.0 (1188) requesting all states
2024-04-17 14:02:02.625 - ^[[32minfo^[[39m: javascript.0 (1188) requesting all objects

Version of nodejs

5.0.19

Version of ioBroker js-controller

v18.20.2

Version of adapter

v7.8.0

[Helmut1965]

Some colleagues try to reproduce this on there system, they was not able to do so, so I close this here for now and some more investigation of the configuration to find out what cause the problem