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

apollon77

@sven12 Un dläuft auf dem Slave vllt noch ein Prozess?

apollon77

@coyote Das bitte im iqontrol Thread besprechen. Userfiles wurden bei dem Adapter generell in einen andern Pfad verschoben. Und am Ende sind wir wieder bei "komische Wege an den unterstützten Standards vorbei ;-))

Das Skript sollte das mit "writeFile" korrekt im ioBroker-Storage ablegen und nicht an allem vorbei Aber wie gesagt: Thema am besten im iqontrol Thread besprechen

sven12

@apollon77
Nein auf beiden läuft kein Prozess mehr...

coyote

@apollon77 ok, dann werde ich das dort mal anschneiden.

Was ist mit den Warnings im Log? Ist da was zu erkennen warum die beim Start kamen? Oder einfach mal so lassen und sich freuen, dass jetzt alles läuft

apollon77

@coyote Wieviele Objekte/States hast Du? Siehst Du in ioBroker unter Tab "Objekte"

coyote

@apollon77 sind ein paar

Objekte: 44287, Zustände: 40604

apollon77

@coyote Ok, I need to think about it ... I have a solution, but don't know if I want this ... https://github.com/ioBroker/ioBroker.js-controller/issues/487

Apollon77 created this issue in ioBroker/ioBroker.js-controller

closed Redis-LUA scripts need too long ... #487

apollon77

@sven12 Sehr strange ... wenn Meldungen wie bei deinem manuellen Log kommen bzw "addrinuse" dann nutzt irgendwas den Port. Magst Du mal einen Reboot versuchen?

coyote

@apollon77 alles klar, dann weiß ich Bescheid, sagen wir einfach ich habe zu viele States

sven12

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

addrinuse

Also das "addrinuse" kam ja nur weil die alte Instanz noch nicht sauber beendet war als ich die Instanz neu gestartet habe.
Ich glaube das kann ich mittlerweile ausschließen. Habe einfach zu schnell den Adapter neu gestartet
Die letzten Logs haben das ja auch nicht mehr angezeigt.... Ich glaube das ist nicht das Problem..
Reboot geht heute nicht mehr.. Morgen evtl.

sigi234

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

sagen wir einfach ich habe zu viele States

Sind nicht wenige. Ich habe 18500

apollon77

@coyote neee passt schon. Das ist Realität Das könnte aktuell bei einem neustart oder neustart des sourceanalytics passieren bei dir, aber ich kläre es und wir finden eine Lösung.

coyote

@apollon77 OK. Ist halt über die Jahre bisschen was zusammen gekommen, aber genau dieses Zusammenspiel der verschiedenen Komponenten macht ioBroker ja so interessant

Stuebi

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

Ich habe eben das update auf den js-controller 2.0 Beta auf meinem Entwicklerrechner (macbook, nodejs 10) durchgeführt. Seit dem wird im Visual Studio Code (VSC) kein Logging im Debug Modus angezeigt. Jemand eine Idee was ich dort ändern muss.
....

VG
Stübi

Ich habe jetzt eine Lösung gefunden damit das Logfile im Debugging Modus im Visual Studio Code (VSC) bei dem js-controller >= 2 wieder angezeigt wird. In der launch.json im .vscode Verzeichnis ist der Eintrag "outputCapture": "std" hinzuzufügen. Damit wird über STDOUT im Terminal des VSC angezeigt. Die Args sind

Beispiel:

{
    "configurations": [
        {
            "type": "node",
            "request": "launch",
            "name": "Programm starten",
            "program": "${workspaceFolder}/shelly.js",
            "cwd": "${workspaceRoot}",
            "args": [
                "--debug", "--force", "--logs", "--trace-warnings"
            ],
            "outputCapture": "std"
        }
    ]
}

Debugging Output:

VG
Stübi

apollon77

Hey an alle Tester,

hier mal die Zusammenfassung der Themen die ich gerade so auf dem Radar habe. Bitte schaut mal ob das passt oder was fehlt!

Performance 2.0 bei file/file (Thema "daswetter") @SBorg hast du mal ne Laufzeit des adapters von der 1.5 ... würde gern mal was vergleichen?)
kein IPv4 verfügbar bei start/boot und controller bleibt trotz restarts dabei das IPv4 noch nicht geht (EHOSTUNREACH). Mit nem Delay nach dem Start tuts. 1 Bericht mit RPi 4
Mit "redis/redis" und vielen States (ca >25.000) laufen ggf LUA Skripte zu lange und blockieren den Redis
VSCode und Adapter-Debugging - Console Ausgaben werden nicht sauber durchgeschliffen, Workaround verfügbar
vis-justgage Beschriftung im Browser "null" anstelle Text, Liegt daran das jetzt ggf null anstelle "undefined" zurückkommt. Müssen klären ob Widgets oder vis das fixen sollte. Könnte andere Widgets auch betreffen
auto restart des controller-prozesses tut nicht (1 Bericht)
(kein Problem) shelly Adapter funktioniert nicht mehr, 1 Bericht -- Reboot hats behoben

Ist das vollständig?

Ansonsten habe ich eine Bitte an Euch, die Ihr ja jetzt viel getestet habt. Lest mit Eurem heutigen Wissen bitte nochmal die Anleitung/FAQ oben durch und überlegt was fehlt bzw was euch geholfen hätte bzw was falsch/unvollständig ist. Ich würde auch gern parallel anfangen das oben für den latest Release vorzubereiten.

darkiop

Hi Ingo,
sorry hatte gestern leider keine Zeit. Bei mir noch folgende Dinge:

IPv4 beim Start des Slaves, keine Verbindung zum Master
Wenn ioBroker Master beendet wird schafft es der Slave nicht mehr sich zu verbinden
Skript Download package.zip - javascript-Adapter
Jede Nacht um 3:58 verliert der Slave die Verbindung zum Master und schafft es nicht mehr sich zu verbinden. Siehe Log am Ende. Im Log des Masters gibt es um 03:58 leider nichts.

Vermutlich haben 1,2 und 3 die selbe Ursache (außer das was um 3:58 passiert, das habe ich nocht nicht gefunden - Skript-Trigger und Instanz Restarts habe ich berreits durch).

Aktuell laufen beide auf 2.0.22.

Bin nun allerdings bis heut Abend unterwegs.

Danke + Grüße

cat iobroker.2019-10-03.log
2019-10-03 03:57:31.992  - warn: host.iobroker-hwr Slave controller detected disconnection. Stop all instances.
2019-10-03 03:57:32.000  - info: host.iobroker-hwr stopInstance system.adapter.smartmeter.0
2019-10-03 03:57:32.001  - info: host.iobroker-hwr stopInstance forced system.adapter.smartmeter.0 killing pid 1272
2019-10-03 03:57:32.002  - info: host.iobroker-hwr stopInstance system.adapter.smartmeter.1
2019-10-03 03:57:32.003  - info: host.iobroker-hwr stopInstance forced system.adapter.smartmeter.1 killing pid 1288
2019-10-03 03:57:32.005  - warn: smartmeter.0 (1272) ERROR CLOSING SERIALPORT
2019-10-03 03:57:32.007  - warn: smartmeter.1 (1288) ERROR CLOSING SERIALPORT
2019-10-03 03:57:33.493  - warn: smartmeter.1 (1288) Cannot connect/reconnect to objects DB. Terminating
2019-10-03 03:57:33.494  - warn: smartmeter.0 (1272) Cannot connect/reconnect to objects DB. Terminating
2019-10-03 03:57:43.997  - warn: host.iobroker-hwr Slave controller detected disconnection. Stop all instances.
2019-10-03 03:57:44.002  - info: host.iobroker-hwr stopInstance system.adapter.smartmeter.0
2019-10-03 03:57:44.002  - info: host.iobroker-hwr stopInstance system.adapter.smartmeter.1
2019-10-03 03:57:54.494  - error: host.iobroker-hwr connect ETIMEDOUT
2019-10-03 03:57:54.496  - error: host.iobroker-hwr Error: connect ETIMEDOUT
    at Socket.<anonymous> (/opt/iobroker/node_modules/ioredis/built/redis/index.js:282:31)
    at Object.onceWrapper (events.js:286:20)
    at Socket.emit (events.js:198:13)
    at Socket._onTimeout (net.js:442:8)
    at ontimeout (timers.js:436:11)
    at tryOnTimeout (timers.js:300:5)
    at listOnTimeout (timers.js:263:5)
    at Timer.processTimers (timers.js:223:10)
2019-10-03 03:58:02.006  - info: host.iobroker-hwr iobroker _restart
2019-10-03 03:58:02.514  - info: host.iobroker-hwr iobroker Starting node restart.js



cat iobroker.2019-10-04.log
2019-10-04 03:58:16.868  - warn: host.iobroker-hwr Slave controller detected disconnection. Stop all instances.
2019-10-04 03:58:16.874  - info: host.iobroker-hwr stopInstance system.adapter.smartmeter.0
2019-10-04 03:58:16.875  - info: host.iobroker-hwr stopInstance forced system.adapter.smartmeter.0 killing pid 985
2019-10-04 03:58:16.876  - info: host.iobroker-hwr stopInstance system.adapter.smartmeter.1
2019-10-04 03:58:16.877  - info: host.iobroker-hwr stopInstance forced system.adapter.smartmeter.1 killing pid 1005
2019-10-04 03:58:16.880  - warn: smartmeter.0 (985) ERROR CLOSING SERIALPORT
2019-10-04 03:58:16.881  - warn: smartmeter.1 (1005) ERROR CLOSING SERIALPORT
2019-10-04 03:58:18.369  - warn: smartmeter.1 (1005) Cannot connect/reconnect to objects DB. Terminating
2019-10-04 03:58:18.376  - warn: smartmeter.0 (985) Cannot connect/reconnect to objects DB. Terminating
2019-10-04 03:58:24.983  - warn: host.iobroker-hwr Slave controller detected disconnection. Stop all instances.
2019-10-04 03:58:24.984  - info: host.iobroker-hwr stopInstance system.adapter.smartmeter.0
2019-10-04 03:58:24.984  - info: host.iobroker-hwr stopInstance system.adapter.smartmeter.1
2019-10-04 03:58:27.980  - warn: host.iobroker-hwr Slave controller detected disconnection. Stop all instances.
2019-10-04 03:58:27.981  - info: host.iobroker-hwr stopInstance system.adapter.smartmeter.0
2019-10-04 03:58:27.981  - info: host.iobroker-hwr stopInstance system.adapter.smartmeter.1
2019-10-04 03:58:30.481  - error: host.iobroker-hwr connect EHOSTUNREACH 192.168.1.82:9000
2019-10-04 03:58:30.482  - error: host.iobroker-hwr Error: connect EHOSTUNREACH 192.168.1.82:9000
    at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1106:14)
2019-10-04 03:58:32.980  - warn: host.iobroker-hwr Slave controller detected disconnection. Stop all instances.
2019-10-04 03:58:32.981  - info: host.iobroker-hwr stopInstance system.adapter.smartmeter.0
2019-10-04 03:58:32.981  - info: host.iobroker-hwr stopInstance system.adapter.smartmeter.1
2019-10-04 03:58:45.487  - error: host.iobroker-hwr connect ECONNREFUSED 192.168.1.82:9000
2019-10-04 03:58:45.487  - error: host.iobroker-hwr Error: connect ECONNREFUSED 192.168.1.82:9000
    at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1106:14)
2019-10-04 03:58:46.879  - info: host.iobroker-hwr iobroker _restart
2019-10-04 03:58:47.391  - info: host.iobroker-hwr iobroker Starting node restart.js
2019-10-04 05:43:08.886  - info: host.iobroker-hwr iobroker.js-controller version 2.0.19 js-controller starting
2019-10-04 05:43:08.893  - info: host.iobroker-hwr Copyright (c) 2014-2019 bluefox, 2014 hobbyquaker
2019-10-04 05:43:08.894  - info: host.iobroker-hwr hostname: iobroker-hwr, node: v10.16.3
2019-10-04 05:43:08.896  - info: host.iobroker-hwr ip addresses: 10.3.1.22 fe80::dea6:32ff:fe17:78f5
2019-10-04 05:43:09.113  - info: host.iobroker-hwr connected to Objects and States
2019-10-04 05:43:09.153  - warn: host.iobroker-hwr Multihost discovery server: service started on 0.0.0.0:50005
2019-10-04 05:43:10.178  - info: host.iobroker-hwr 85 instances found
2019-10-04 05:43:10.195  - info: host.iobroker-hwr starting 2 instances
2019-10-04 05:43:10.213  - info: host.iobroker-hwr instance system.adapter.smartmeter.0 started with pid 2855
2019-10-04 05:43:14.213  - info: host.iobroker-hwr instance system.adapter.smartmeter.1 started with pid 2870
2019-10-04 06:14:38.153  - info: host.iobroker-hwr received SIGTERM
2019-10-04 06:14:38.157  - info: host.iobroker-hwr stopInstance system.adapter.smartmeter.0
2019-10-04 06:14:38.157  - info: host.iobroker-hwr stopInstance system.adapter.smartmeter.1
2019-10-04 06:14:38.179  - warn: smartmeter.0 (2855) ERROR CLOSING SERIALPORT
2019-10-04 06:14:38.182  - warn: smartmeter.1 (2870) ERROR CLOSING SERIALPORT
2019-10-04 06:14:38.217  - info: host.iobroker-hwr stopInstance system.adapter.smartmeter.0 send kill signal
2019-10-04 06:14:38.218  - info: host.iobroker-hwr stopInstance system.adapter.smartmeter.1 send kill signal
2019-10-04 06:14:38.993  - info: host.iobroker-hwr instance system.adapter.smartmeter.1 terminated with code 156 (156)
2019-10-04 06:14:39.096  - info: host.iobroker-hwr instance system.adapter.smartmeter.0 terminated with code 156 (156)
2019-10-04 06:14:39.096  - info: host.iobroker-hwr All instances are stopped.
2019-10-04 06:14:39.357  - info: host.iobroker-hwr terminated
2019-10-04 06:26:49.496  - info: host.iobroker-hwr iobroker.js-controller version 2.0.22 js-controller starting
2019-10-04 06:26:49.508  - info: host.iobroker-hwr Copyright (c) 2014-2019 bluefox, 2014 hobbyquaker
2019-10-04 06:26:49.509  - info: host.iobroker-hwr hostname: iobroker-hwr, node: v10.16.3
2019-10-04 06:26:49.512  - info: host.iobroker-hwr ip addresses: 10.3.1.22 fe80::dea6:32ff:fe17:78f5
2019-10-04 06:26:50.124  - info: host.iobroker-hwr connected to Objects and States
2019-10-04 06:26:50.169  - warn: host.iobroker-hwr Multihost discovery server: service started on 0.0.0.0:50005
2019-10-04 06:26:51.006  - info: host.iobroker-hwr Delete state "system.host.iobroker-hwr.compactModeEnabled"
2019-10-04 06:26:51.206  - info: host.iobroker-hwr 85 instances found
2019-10-04 06:26:51.227  - info: host.iobroker-hwr starting 2 instances
2019-10-04 06:26:51.252  - info: host.iobroker-hwr instance system.adapter.smartmeter.0 started with pid 982
2019-10-04 06:26:51.276  - info: host.iobroker-hwr Some obsolete host states deleted.
2019-10-04 06:26:55.235  - info: host.iobroker-hwr instance system.adapter.smartmeter.1 started with pid 1001
2019-10-04 06:48:37.054  - info: host.iobroker-hwr Update repository "latest" under "http://download.iobroker.net/sources-dist-latest.json"
 
 

cat iobroker.2019-10-05.log
2019-10-05 03:58:12.569  - warn: host.iobroker-hwr Slave controller detected disconnection. Stop all instances.
2019-10-05 03:58:12.575  - info: host.iobroker-hwr stopInstance system.adapter.smartmeter.0
2019-10-05 03:58:12.576  - info: host.iobroker-hwr stopInstance forced system.adapter.smartmeter.0 killing pid 982
2019-10-05 03:58:12.577  - info: host.iobroker-hwr stopInstance system.adapter.smartmeter.1
2019-10-05 03:58:12.578  - info: host.iobroker-hwr stopInstance forced system.adapter.smartmeter.1 killing pid 1001
2019-10-05 03:58:12.583  - warn: smartmeter.1 (1001) ERROR CLOSING SERIALPORT
2019-10-05 03:58:14.074  - warn: smartmeter.1 (1001) Cannot connect/reconnect to objects DB. Terminating
2019-10-05 03:58:24.575  - warn: host.iobroker-hwr Slave controller detected disconnection. Stop all instances.
2019-10-05 03:58:24.576  - info: host.iobroker-hwr stopInstance system.adapter.smartmeter.0
2019-10-05 03:58:24.577  - info: host.iobroker-hwr stopInstance system.adapter.smartmeter.1
2019-10-05 03:58:25.394  - error: host.iobroker-hwr connect EHOSTUNREACH 192.168.1.82:9000
2019-10-05 03:58:25.395  - error: host.iobroker-hwr Error: connect EHOSTUNREACH 192.168.1.82:9000
    at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1106:14)
2019-10-05 03:58:29.897  - warn: host.iobroker-hwr Slave controller detected disconnection. Stop all instances.
2019-10-05 03:58:29.898  - info: host.iobroker-hwr stopInstance system.adapter.smartmeter.0
2019-10-05 03:58:29.899  - info: host.iobroker-hwr stopInstance system.adapter.smartmeter.1
2019-10-05 03:58:40.399  - error: host.iobroker-hwr connect ECONNREFUSED 192.168.1.82:9000
2019-10-05 03:58:40.399  - error: host.iobroker-hwr Error: connect ECONNREFUSED 192.168.1.82:9000
    at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1106:14)
2019-10-05 03:58:42.581  - info: host.iobroker-hwr iobroker _restart
2019-10-05 03:58:42.777  - error: host.iobroker-hwr iobroker path.js:1077        path = process.cwd();                       ^Error: ENOENT: no such file or directory, uv_cwd    at Object.resolve (path.js:1077:24)    at Function.Module._resolveLookupPaths (internal/modules/cjs/loader.js:534:17)    at Function.Module._resolveFilename (internal/modules/cjs/loader.js:629:20)    at Function.Module._load (internal/modules/cjs/loader.js:562:25)    at Module.require (internal/modules/cjs/loader.js:692:17)    at require (internal/modules/cjs/helpers.js:25:18)    at Object.<anonymous> (/opt/iobroker/node_modules/iobroker.js-controller/iobroker.js:1:1)    at Module._compile (internal/modules/cjs/loader.js:778:30)    at Object.Module._extensions..js (internal/modules/cjs/loader.js:789:10)    at Module.load (internal/modules/cjs/loader.js:653:32)
2019-10-05 03:58:42.780  - info: host.iobroker-hwr iobroker exit 1
2019-10-05 07:10:31.915  - info: host.iobroker-hwr iobroker.js-controller version 2.0.22 js-controller starting
2019-10-05 07:10:31.922  - info: host.iobroker-hwr Copyright (c) 2014-2019 bluefox, 2014 hobbyquaker
2019-10-05 07:10:31.923  - info: host.iobroker-hwr hostname: iobroker-hwr, node: v10.16.3
2019-10-05 07:10:31.925  - info: host.iobroker-hwr ip addresses: 10.3.1.22 fe80::dea6:32ff:fe17:78f5
2019-10-05 07:10:32.147  - info: host.iobroker-hwr connected to Objects and States
2019-10-05 07:10:32.187  - warn: host.iobroker-hwr Multihost discovery server: service started on 0.0.0.0:50005
2019-10-05 07:10:33.291  - info: host.iobroker-hwr 85 instances found
2019-10-05 07:10:33.315  - info: host.iobroker-hwr starting 2 instances
2019-10-05 07:10:33.336  - info: host.iobroker-hwr instance system.adapter.smartmeter.0 started with pid 12375
2019-10-05 07:10:37.326  - info: host.iobroker-hwr instance system.adapter.smartmeter.1 started with pid 12418

SBorg

Performance bei der 1.5.14 bei Aktivierung der ersten drei APIs liegt so zwischen 25-30 Sekunden.
Mit der 2.0.22 ~180 Sekunden, gelegentlich auch über meinem derzeitigen Timeout von 300 Sekunden. Dann stockt auch die Verarbeitung weiterer Javascripts die da ev. laufen möchten.

...und woran auch immer es liegt: Node-RED Dashboard will einfach nicht

apollon77

@SBorg Ok, Dashboard wie gesagt tut bei mir und anderen ... ich weiss nicht hilfreich für dich, aber ürde ich gerade nicht dem controller anlasten

apollon77

@darkiop Ooohk,

dein 1. ist in meiner Liste
dein 2. jetzt auch (bei dir tut der restart nicht ... können wir gern tief rein "diggen"
1. sollte seit 2.0.22 gefixt sein
  Dann zu 4. ... liefert /var/log/syslog irgendwas? Einerseits spielt da der nicht funktio0nierende restart rein, aber auch hier ist jetzt die neue Fehlermeldung interessant:

2019-10-05 03:58:42.777 - error: host.iobroker-hwr iobroker path.js:1077 path = process.cwd(); ^Error: ENOENT: no such file or directory, uv_cwd at Object.resolve (path.js:1077:24) at Function.Module._resolveLookupPaths (internal/modules/cjs/loader.js:534:17) at Function.Module._resolveFilename (internal/modules/cjs/loader.js:629:20) at Function.Module._load (internal/modules/cjs/loader.js:562:25) at Module.require (internal/modules/cjs/loader.js:692:17) at require (internal/modules/cjs/helpers.js:25:18) at Object.<anonymous> (/opt/iobroker/node_modules/iobroker.js-controller/iobroker.js:1:1) at Module._compile (internal/modules/cjs/loader.js:778:30) at Object.Module._extensions..js (internal/modules/cjs/loader.js:789:10) at Module.load (internal/modules/cjs/loader.js:653:32)

Wie geht es denn der SD Karte so? Dieser Fehler heisst an sich das das Verzeichnis weg ist ... und damit wird merkwürdig. Deshalb schau mal zu der Zeit bitte in /var/log/syslog
Ansonsten wäre ist bei: Filesystem check, Netzteil checken/tauschen? ...

apollon77

@darkiop So, dann wollen wir mal.
An sich ist die Logik so (du hast ja jetzt sytemd und nicht mehr init.d) das systemd selbst den restart macht wenn der controller mit einem Exitcode != 0 sich beendet.

Also man nehme ein System wo iobroker per systemd gestartet ist. Wenn du jetzt den js-controller-Prozess killst (ps auxww|grep js-controller -... dann kill prozessid) merkt systemd das und startet Ihn neu.

Bei mir im /var/log/syslog sieht das dann so aus:

Oct  5 12:42:34 io-test systemd[1]: iobroker.service: Main process exited, code=exited, status=1/FAILURE
Oct  5 12:42:44 io-test systemd[1]: iobroker.service: Failed with result 'exit-code'.
Oct  5 12:42:45 io-test systemd[1]: iobroker.service: Service hold-off time over, scheduling restart.
Oct  5 12:42:45 io-test systemd[1]: iobroker.service: Scheduled restart job, restart counter is at 1.
Oct  5 12:42:45 io-test systemd[1]: Stopped ioBroker Server.
Oct  5 12:42:45 io-test systemd[1]: Started ioBroker Server.
... startet wieder ...

Fangen wir mal damit an ob das bei dir korrekt tut.

NEWS

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

closed Redis-LUA scripts need too long ... #487

Support us

1.0k
Online

31.7k
Users

79.7k
Topics

1.3m
Posts

NEWS

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

closed Redis-LUA scripts need too long ... #487

Support us

1.0kOnline

31.7kUsers

79.7kTopics

1.3mPosts

1.0k
Online

31.7k
Users

79.7k
Topics

1.3m
Posts