Test js-controller v2.0.x (GitHub)

darkiop

Testfall 2:

iobroker-master um 10:30:05 beendet und nach 20s wieder gestartet, log auf slave:

--> Kein Log das die Verbindung wieder besteht. 10:32:37 wurde der iobroker-master wieder gestartet und war ein paar Sekunden später auch wieder Verbunden (--> ersichtlich im Admin).

2019-10-15 10:30:01.626  - info: host.iobroker-hwr iobroker Starting node restart.js
2019-10-15 10:30:03.055  - info: host.iobroker-hwr iobroker.js-controller version 2.0.30 js-controller starting
2019-10-15 10:30:03.063  - info: host.iobroker-hwr Copyright (c) 2014-2019 bluefox, 2014 hobbyquaker
2019-10-15 10:30:03.064  - info: host.iobroker-hwr hostname: iobroker-hwr, node: v10.16.3
2019-10-15 10:30:03.065  - info: host.iobroker-hwr ip addresses: 10.3.1.22 fe80::561e:8619:1900:f27
2019-10-15 10:30:20.413  - info: host.iobroker-hwr connected to Objects and States
2019-10-15 10:30:20.684  - info: host.iobroker-hwr 87 instances found
2019-10-15 10:30:20.709  - info: host.iobroker-hwr starting 2 instances
2019-10-15 10:30:20.727  - info: host.iobroker-hwr instance system.adapter.smartmeter.0 started with pid 928
2019-10-15 10:30:24.719  - info: host.iobroker-hwr instance system.adapter.smartmeter.1 started with pid 943
2019-10-15 10:32:28.828  - error: host.iobroker-hwr connect ETIMEDOUT
2019-10-15 10:32:28.833  - error: smartmeter.0 (928) connect ETIMEDOUT
2019-10-15 10:32:28.838  - error: smartmeter.1 (943) connect ETIMEDOUT
2019-10-15 10:32:40.833  - error: host.iobroker-hwr connect ETIMEDOUT
2019-10-15 10:32:40.841  - error: smartmeter.0 (928) connect ETIMEDOUT
2019-10-15 10:32:40.864  - error: smartmeter.1 (943) connect ETIMEDOUT
2019-10-15 10:32:42.839  - error: host.iobroker-hwr connect ECONNREFUSED 192.168.1.82:9001
2019-10-15 10:32:42.847  - error: smartmeter.0 (928) connect ECONNREFUSED 192.168.1.82:9001
2019-10-15 10:32:42.867  - error: smartmeter.1 (943) connect ECONNREFUSED 192.168.1.82:9001
2019-10-15 10:32:44.844  - error: host.iobroker-hwr connect ECONNREFUSED 192.168.1.82:9001
2019-10-15 10:32:44.850  - error: smartmeter.0 (928) connect ECONNREFUSED 192.168.1.82:9001
2019-10-15 10:32:44.870  - error: smartmeter.1 (943) connect ECONNREFUSED 192.168.1.82:9001
2019-10-15 10:32:46.846  - error: host.iobroker-hwr connect ECONNREFUSED 192.168.1.82:9001
2019-10-15 10:32:46.851  - error: smartmeter.0 (928) connect ECONNREFUSED 192.168.1.82:9001
2019-10-15 10:32:46.873  - error: smartmeter.1 (943) connect ECONNREFUSED 192.168.1.82:9001
2019-10-15 10:32:48.850  - error: host.iobroker-hwr connect ECONNREFUSED 192.168.1.82:9001
2019-10-15 10:32:48.854  - error: smartmeter.0 (928) connect ECONNREFUSED 192.168.1.82:9001
2019-10-15 10:32:48.876  - error: smartmeter.1 (943) connect ECONNREFUSED 192.168.1.82:9001
2019-10-15 10:32:50.852  - error: host.iobroker-hwr connect ECONNREFUSED 192.168.1.82:9001
2019-10-15 10:32:50.857  - error: smartmeter.0 (928) connect ECONNREFUSED 192.168.1.82:9001
2019-10-15 10:32:50.878  - error: smartmeter.1 (943) connect ECONNREFUSED 192.168.1.82:9001
2019-10-15 10:32:52.855  - error: host.iobroker-hwr connect ECONNREFUSED 192.168.1.82:9001
2019-10-15 10:32:52.859  - error: smartmeter.0 (928) connect ECONNREFUSED 192.168.1.82:9001
2019-10-15 10:32:52.881  - error: smartmeter.1 (943) connect ECONNREFUSED 192.168.1.82:9001

darkiop

Testfall 3

iobroker-redis um 10:45:13 Uhr beendet. Log Master.
Einige Minuten später iobroker-redis wieder gestartet - der iobroker-master schafft es nicht wieder auf die Beine. Nach einem restart des Containers für den Master ist wieder alles verbunden.

log_tf3.txt

darkiop

Testfall 4

┬─[darkiop@odin:~]─[11:00:32]
╰─>$ docker stop iobroker-redis

┬─[darkiop@odin:~]─[11:02:15]
╰─>$ docker start iobroker-redis

smartmeter.1 hat einen Wert von 2019-10-15 11:01:34.726 über sql.0 in die DB geschrieben!

apollon77

@darkiop Alles unix dgram complier warnungen Aber ja ist egal, tut alles

apollon77

Danke für die Tests!!

Testfall1 : So soll es sein
Testfall 2: Auch hier soll es so sein. Wenn Du auf "debug" oder "silly" log hättest würdest du die reconnects als Log sehen.
Testfall 3 Bitte mit der neuen 2.0.31 auf Github nochmal testen
Testfall 4; Cooool

darkiop

@apollon77 sagte in [Aufruf] js-controller 2.0 Beta Test:

Danke für die Tests!!

Gern!

Testfall 3 Bitte mit der neuen 2.0.31 auf Github nochmal testen

Da stimmt was nicht:

┬─[darkiop@odin:~]─[13:35:02]
╰─>$ docker stop iobroker-redis
iobroker-redis
┬─[darkiop@odin:~]─[13:41:53]
╰─>$ docker start iobroker-redis
iobroker-redis

Log Master:

2019-10-15 13:41:48.364  - error: scenes.0 (1492) connect ETIMEDOUT
2019-10-15 13:41:48.366  - error: pi-hole.0 (1228) connect ETIMEDOUT
2019-10-15 13:41:48.368  - error: harmony.0 (388) connect ETIMEDOUT
2019-10-15 13:41:48.368  - error: simple-api.0 (1695) connect ETIMEDOUT
2019-10-15 13:41:48.372  - error: javascript.1 (1068) connect ETIMEDOUT
2019-10-15 13:41:48.372  - error: sql.0 (1819) connect ETIMEDOUT
2019-10-15 13:41:48.372  - error: telegram.0 (2364) connect ETIMEDOUT
2019-10-15 13:41:48.375  - error: host.iobroker-master connect ETIMEDOUT
2019-10-15 13:41:48.379  - error: hm-rega.0 (403) connect ETIMEDOUT
2019-10-15 13:41:48.379  - error: hs100.0 (480) connect ETIMEDOUT
2019-10-15 13:41:48.379  - error: tr-064-community.0 (2710) connect ETIMEDOUT
2019-10-15 13:41:48.385  - error: stiebel-isg.0 (2029) connect ETIMEDOUT
2019-10-15 13:41:48.385  - error: moma.0 (1162) connect ETIMEDOUT
2019-10-15 13:41:48.390  - error: ping.0 (1378) connect ETIMEDOUT
2019-10-15 13:41:48.391  - error: hm-rpc.1 (426) connect ETIMEDOUT
2019-10-15 13:41:48.392  - error: backitup.0 (457) connect ETIMEDOUT
2019-10-15 13:41:48.393  - error: hm-rpc.2 (450) connect ETIMEDOUT
2019-10-15 13:41:48.393  - error: javascript.0 (808) connect ETIMEDOUT
2019-10-15 13:41:48.399  - error: mercedesme.0 (1108) connect ETIMEDOUT
2019-10-15 13:41:48.407  - error: info.0 (789) connect ETIMEDOUT
2019-10-15 13:42:00.004  - warn: host.iobroker-master instance system.adapter.daswetter.0 already running with pid 11372
2019-10-15 13:42:03.215  - info: host.iobroker-master instance system.adapter.daswetter.0 terminated with code 0 (NO_ERROR)
2019-10-15 13:42:04.501  - debug: harmony.0 (388) system.adapter.admin.0: logging true
2019-10-15 13:42:04.532  - debug: harmony.0 (388) States connected to redis: 192.168.1.86:6379
2019-10-15 13:42:20.048  - error: admin.0 (419) uncaught exception: Maximum call stack size exceeded
2019-10-15 13:42:20.052  - error: admin.0 (419) RangeError: Maximum call stack size exceeded
    at Sender.frameAndSend (/opt/iobroker/node_modules/ws/lib/Sender.js:166:14)
    at /opt/iobroker/node_modules/ws/lib/Sender.js:126:12
    at Sender.applyExtensions (/opt/iobroker/node_modules/ws/lib/Sender.js:287:5)
    at /opt/iobroker/node_modules/ws/lib/Sender.js:120:10
    at Sender.flush (/opt/iobroker/node_modules/ws/lib/Sender.js:268:3)
    at /opt/iobroker/node_modules/ws/lib/Sender.js:270:10
    at /opt/iobroker/node_modules/ws/lib/Sender.js:127:7
    at Sender.applyExtensions (/opt/iobroker/node_modules/ws/lib/Sender.js:287:5)
    at /opt/iobroker/node_modules/ws/lib/Sender.js:120:10
    at Sender.flush (/opt/iobroker/node_modules/ws/lib/Sender.js:268:3)
2019-10-15 13:42:20.318  - error: host.iobroker-master Caught by controller[0]: RangeError: Maximum call stack size exceeded
2019-10-15 13:42:20.320  - error: host.iobroker-master Caught by controller[0]:     at Sender.frameAndSend (/opt/iobroker/node_modules/ws/lib/Sender.js:166:14)
2019-10-15 13:42:20.321  - error: host.iobroker-master Caught by controller[0]:     at /opt/iobroker/node_modules/ws/lib/Sender.js:126:12
2019-10-15 13:42:20.323  - error: host.iobroker-master Caught by controller[0]:     at Sender.applyExtensions (/opt/iobroker/node_modules/ws/lib/Sender.js:287:5)
2019-10-15 13:42:20.324  - error: host.iobroker-master Caught by controller[0]:     at /opt/iobroker/node_modules/ws/lib/Sender.js:120:10
2019-10-15 13:42:20.325  - error: host.iobroker-master Caught by controller[0]:     at Sender.flush (/opt/iobroker/node_modules/ws/lib/Sender.js:268:3)
2019-10-15 13:42:20.326  - error: host.iobroker-master Caught by controller[0]:     at /opt/iobroker/node_modules/ws/lib/Sender.js:270:10
2019-10-15 13:42:20.327  - error: host.iobroker-master Caught by controller[0]:     at /opt/iobroker/node_modules/ws/lib/Sender.js:127:7
2019-10-15 13:42:20.328  - error: host.iobroker-master Caught by controller[0]:     at Sender.applyExtensions (/opt/iobroker/node_modules/ws/lib/Sender.js:287:5)
2019-10-15 13:42:20.328  - error: host.iobroker-master Caught by controller[0]:     at /opt/iobroker/node_modules/ws/lib/Sender.js:120:10
2019-10-15 13:42:20.329  - error: host.iobroker-master Caught by controller[0]:     at Sender.flush (/opt/iobroker/node_modules/ws/lib/Sender.js:268:3)
2019-10-15 13:42:20.331  - info: host.iobroker-master instance system.adapter.admin.0 terminated with code 0 (NO_ERROR)
2019-10-15 13:42:20.333  - info: host.iobroker-master Restart adapter system.adapter.admin.0 because enabled
2019-10-15 13:42:20.340  - debug: harmony.0 (388) system.adapter.admin.0: logging false
2019-10-15 13:42:49.810  - info: tankerkoenig.0 (2155) Reading data from tankerkoenig ...
2019-10-15 13:42:50.388  - info: host.iobroker-master instance system.adapter.admin.0 started with pid 27743
2019-10-15 13:43:00.021  - info: host.iobroker-master instance system.adapter.daswetter.0 started with pid 28216
2019-10-15 13:43:09.649  - info: host.iobroker-master instance system.adapter.daswetter.0 terminated with code 0 (NO_ERROR)

Keine neue States da:

apollon77

@darkiop in dem Fall ist Admin gestorben weil sich irgendwie Dinge aufgestaut haben und Admin restartet. Ggf fehlen dadurch Daten? Lad im browser mal neu. Jetzt fehlende States da?

Ansonsten hat sich der iobroker aber wieder gefangen mit der Version oder?!

apollon77

@darkiop Aahhh noch eine Frage: du hast nur States im redis, korrekt?

darkiop

Ok, zweiter Test - jetzt ohne den admin.0 crash ....

der Master ist wieder auf den Beinen, der Slave hat es aber nicht geschaft. stop/start aufm Slave und er ist wieder verbunden.

Puffert der controller auch Logs? Die 3 hier sind eigentlich entstanden während redis weg war, geschrieben wurden sie nach dem redis wieder da war:

2019-10-15 14:00:00.786  - info: javascript.0 (618) script.js.PRODUKTIV.Beleuchtung.01_Bewegungsmelder_Flur: +++ Bewegung im Flur. Helligkeitsschwelle bei < 10 | Aktuelle Helligkeit: 31.8 | Licht wird nicht geschaltet. +++
2019-10-15 14:00:01.180  - info: javascript.0 (618) script.js.PRODUKTIV.Beleuchtung.01_Bewegungsmelder_Flur: +++ Bewegung im Flur. Helligkeitsschwelle bei < 10 | Aktuelle Helligkeit: 32.6 | Licht wird nicht geschaltet. +++
2019-10-15 14:00:01.523  - info: javascript.0 (618) script.js.PRODUKTIV.Beleuchtung.01_Bewegungsmelder_Flur: +++ Bewegung im Flur. Helligkeitsschwelle bei < 10 | Aktuelle Helligkeit: 32.6 | Licht wird nicht geschaltet. +++

Edit:

So lange war redis weg:

darkiop

@apollon77 sagte in [Aufruf] js-controller 2.0 Beta Test:

Aahhh noch eine Frage: du hast nur States im redis, korrekt?

Ja.

smartboart

@apollon77 said in [Aufruf] js-controller 2.0 Beta Test:

@smartboart mehr log bitte

gerne

2019-10-14 19:36:28.810 - info: host.ioBroker-Rock Update repository "latest" under "http://download.iobroker.net/sources-dist-latest.json"
2019-10-14 19:37:21.257 - info: host.ioBroker-Rock iobroker upgrade statistics
2019-10-14 19:37:23.968 - info: host.ioBroker-Rock iobroker Update statistics from @0.2.0 to @0.2.2
2019-10-14 19:37:25.117 - info: host.ioBroker-Rock iobroker NPM version: 6.9.0npm install iobroker.statistics@0.2.2 --loglevel error --production --save --prefix "/opt/iobroker" (System call)
2019-10-14 19:39:04.319 - info: host.ioBroker-Rock iobroker In file included from ../node_modules/nan/nan.h:82:0, from ../src/bufferutil.cc:16:../node_modules/nan/nan_new.h: In function ‘v8::Local NanIntern::To(v8::Handle) [with T = v8::Integer; v8::Handle = v8::Local]’:../node_modules/nan/nan_new.h:29:66: warning: ‘v8::Local v8::Value::ToInteger() const’ is deprecated: Use maybe version [-Wdeprecated-declarations] To(v8::Handle i) { return i->ToInteger(); } ^
2019-10-14 19:39:04.321 - info: host.ioBroker-Rock iobroker In file included from ../src/bufferutil.cc:7:0:/home/iobroker/.node-gyp/10.16.3/include/node/v8.h:10052:16: note: declared here Local Value::ToInteger() const { ^In file included from ../node_modules/nan/nan.h:82:0, from ../src/bufferutil.cc:16:../node_modules/nan/nan_new.h: In function ‘v8::Local NanIntern::To(v8::Handle) [with T = v8::Int32; v8::Handle = v8::Local]’:../node_modules/nan/nan_new.h:34:64: error: no matching function for call to ‘v8::Integer::ToInt32()’ To(v8::Handle i) { return i->ToInt32(); } ^In file included from ../src/bufferutil.cc:7:0:/home/iobroker/.node-gyp/10.16.3/include/node/v8.h:2437:43: note: candidate: v8::MaybeLocal v8::Value::ToInt32(v8::Local) const V8_WARN_UNUSED_RESULT MaybeLocal ToInt32(Local context) const; ^/home/iobroker/.node-gyp/10.16.3/include/node/v8.h:2437:43: note: candidate expects 1 argument, 0 providedIn file included from /home/iobroker/.node-gyp/10.16.3/include/node/v8.h:26:0, from ../src/bufferutil.cc:7:/home/iobroker/.node-gyp/10.16.3/include/node/v8.h:2450:30: note: candidate: v8::Local v8::Value::ToInt32(v8::Isolate*) const Local ToInt32(Isolate* isolate) const); ^/home/iobroker/.node-gyp/10.16.3/include/node/v8config.h:324:3: note: in definition of macro ‘V8_DEPRECATED’ declarator attribute((deprecated(message))) ^~~~~~~~
2019-10-14 19:39:04.324 - info: host.ioBroker-Rock iobroker /home/iobroker/.node-gyp/10.16.3/include/node/v8.h:2450:30: note: candidate expects 1 argument, 0 provided Local ToInt32(Isolate* isolate) const); ^/home/iobroker/.node-gyp/10.16.3/include/node/v8config.h:324:3: note: in definition of macro ‘V8_DEPRECATED’ declarator attribute((deprecated(message))) ^~~~~~~~~~
2019-10-14 19:39:04.327 - info: host.ioBroker-Rock iobroker In file included from ../node_modules/nan/nan.h:82:0, from ../src/bufferutil.cc:16:../node_modules/nan/nan_new.h: In function ‘v8::Local NanIntern::To(v8::Handle) [with T = v8::Uint32; v8::Handle = v8::Local]’:../node_modules/nan/nan_new.h:39:65: error: no matching function for call to ‘v8::Integer::ToUint32()’ To(v8::Handle i) { return i->ToUint32(); } ^In file included from ../src/bufferutil.cc:7:0:/home/iobroker/.node-gyp/10.16.3/include/node/v8.h:2435:44: note: candidate: v8::MaybeLocal v8::Value::ToUint32(v8::Local) const V8_WARN_UNUSED_RESULT MaybeLocal ToUint32( ^~/home/iobroker/.node-gyp/10.16.3/include/node/v8.h:2435:44: note: candidate expects 1 argument, 0 provided
2019-10-14 19:39:04.349 - info: host.ioBroker-Rock iobroker In file included from ../node_modules/nan/nan_new.h:189:0, from ../node_modules/nan/nan.h:82, from ../src/bufferutil.cc:16:../node_modules/nan/nan_implementation_12_inl.h: In static member function ‘static NanIntern::FactoryBase::return_t NanIntern::Factory::New(bool)’:../node_modules/nan/nan_implementation_12_inl.h:49:38: error: no matching function for call to ‘v8::BooleanObject::New(bool&)’ return v8::BooleanObject::New(value).As(); ^
2019-10-14 19:39:04.352 - info: host.ioBroker-Rock iobroker In file included from ../src/bufferutil.cc:7:0:/home/iobroker/.node-gyp/10.16.3/include/node/v8.h:5035:23: note: candidate: static v8::Local v8::BooleanObject::New(v8::Isolate*, bool) static Local New(Isolate* isolate, bool value); ^/home/iobroker/.node-gyp/10.16.3/include/node/v8.h:5035:23: note: candidate expects 2 arguments, 1 providedIn file included from ../node_modules/nan/nan_new.h:189:0, from ../node_modules/nan/nan.h:82, from ../src/bufferutil.cc:16:../node_modules/nan/nan_implementation_12_inl.h:49:60: error: expected primary-expression before ‘>’ token return v8::BooleanObject::New(value).As(); ^../node_modules/nan/nan_implementation_12_inl.h:49:62: error: expected primary-expression before ‘)’ token return v8::BooleanObject::New(value).As(); ^
2019-10-14 19:39:04.371 - info: host.ioBroker-Rock iobroker ../node_modules/nan/nan_implementation_12_inl.h: In static member function ‘static NanIntern::FactoryBase::return_t NanIntern::Factory::New(v8::Handle, v8::RegExp::Flags)’:../node_modules/nan/nan_implementation_12_inl.h:158:40: warning: ‘static v8::Local v8::RegExp::New(v8::Local, v8::RegExp::Flags)’ is deprecated: Use maybe version [-Wdeprecated-declarations] return v8::RegExp::New(pattern, flags); ^
2019-10-14 19:39:04.373 - info: host.ioBroker-Rock iobroker In file included from /home/iobroker/.node-gyp/10.16.3/include/node/v8.h:26:0, from ../src/bufferutil.cc:7:/home/iobroker/.node-gyp/10.16.3/include/node/v8.h:5110:38: note: declared here Local New(Local pattern, Flags flags)); ^/home/iobroker/.node-gyp/10.16.3/include/node/v8config.h:324:3: note: in definition of macro ‘V8_DEPRECATED’ declarator attribute((deprecated(message))) ^~~~~~
2019-10-14 19:39:04.378 - info: host.ioBroker-Rock iobroker In file included from ../node_modules/nan/nan_new.h:189:0, from ../node_modules/nan/nan.h:82, from ../src/bufferutil.cc:16:../node_modules/nan/nan_implementation_12_inl.h: In static member function ‘static NanIntern::FactoryBase::return_t NanIntern::Factory::New(v8::Local)’:../node_modules/nan/nan_implementation_12_inl.h:166:69: error: no matching function for call to ‘v8::ScriptCompiler::Compile(v8::Isolate*, v8::ScriptCompiler::Source*)’ return v8::ScriptCompiler::Compile(v8::Isolate::GetCurrent(), &src); ^In file included from ../src/bufferutil.cc:7:0:/home/iobroker/.node-gyp/10.16.3/include/node/v8.h:1510:51: note: candidate: static v8::MaybeLocal v8::ScriptCompiler::Compile(v8::Local, v8::ScriptCompiler::Source*, v8::ScriptCompiler::CompileOptions, v8::ScriptCompiler::NoCacheReason) static V8_WARN_UNUSED_RESULT MaybeLocal

smartboart

Mir ist noch was aufgefallen. Hab für den fullybrowser nen Chron Job im Admin angelegt.
Alle 4 Stunden neustarten.... Der Log sieht dann so aus. Ist der einzige adapter mit nem Chron job bei mir..

apollon77

@smartboart denke alles nur Warnungen.

apollon77

@smartboart sicher das es 4 stündlich ist? Das siehe eher nach minütlich aus.

apollon77

@darkiop hast du hier bitte das Slave log komplett von dem Zeitraum?

smartboart

@apollon77 said in [Aufruf] js-controller 2.0 Beta Test:

@smartboart sicher das es 4 stündlich ist? Das siehe eher nach minütlich aus.
ja sehr sicher...

Das ist jadas verwunderliche...noch dazu der Fehler.
instance system.adapter.fullybrowser.0 terminated with code 156 (156)

Jan1

@smartboart
das ist alle 4 Stunden jede Minute

smartboart

@Jan1 oh ok..ich glaube ich sollte mich nochmal mit den Chron Zeiten auseinanderstzen..Danke!!!

smartboart

@apollon77 said in [Aufruf] js-controller 2.0 Beta Test:

@smartboart denke alles nur Warnungen.

ok danke..hab ich mir gedacht, macht auch keine Probleme. Wenn du oder sonst wer dennoch ne Idee hat wie man diese gyp und nan Warnungen abstellt, gerne her damit.....

darkiop

@apollon77

Das ist alles von heute aufm Slave ab dem Zeitpunkt des Redis-Tests:

log_slave.txt

NEWS

Test js-controller v2.0.x (GitHub)

Support us

1.5k
Online

30.9k
Users

77.6k
Topics

1.2m
Posts

NEWS

Test js-controller v2.0.x (GitHub)

Support us

1.5kOnline

30.9kUsers

77.6kTopics

1.2mPosts

1.5k
Online

30.9k
Users

77.6k
Topics

1.2m
Posts