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

[sven12]

@apollon77
Wenn ich den Adapter im Admin gestoppt habe, kommt auf der Konsole das hier:

iobroker@iobroker-host:/opt/iobroker$ node node_modules/iobroker.shelly/shelly.js --force --logs
2019-10-04 20:45:07.776  - error: shelly.0 (20885) adapter disabled
2019-10-04 20:45:07.779  - info: shelly.0 (20885) starting. Version 3.1.0 in /opt/iobroker/node_modules/iobroker.shelly, node: v8.16.1
2019-10-04 20:45:07.841  - info: shelly.0 (20885) Stating Shelly adapter in CoAP modus.
Exception: Error: addMembership EADDRINUSE/Error: addMembership EADDRINUSE
2019-10-04 20:45:07.960  - error: shelly.0 (20885) Exception: Error: addMembership EADDRINUSE
2019-10-04 20:45:07.961  - info: shelly.0 (20885) Closing Adapter

[apollon77]

@sven12 Kann es sein das da irgendwie noch eine Instanz läuft? Schau al mit "ps auxww|grep shelly"

[sven12]

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

ps auxww|grep shelly

iobroker@iobroker-host:/opt/iobroker$ ps auxww|grep shelly
iobroker 26889  0.0  0.0  12780   928 pts/3    S+   20:48   0:00 grep shelly
iobroker@iobroker-host:/opt/iobroker$ node node_modules/iobroker.shelly/shelly.js --force --logs
2019-10-04 20:48:48.376  - error: shelly.0 (27548) shelly.0 invalid process id scenario 25918 vs. 27548. Stopping

[coyote]

@apollon77 sorry, klar macht vllt mehr Sinn...

Hier mal ab Start von iobroker bis Anfang der Warnings:

Log.txt

Übrigens habe ich noch ein kleines Problem, es gibt ein Unifi Script von liv-in-the-sky, dass schreibt ein html file nach /opt/iobroker/iobroker-data/files/iqontrol/htmlclients.html
Die Datei ist auch definitiv dort vorhanden und wird auch stetig geändert, nur wird sie mir jetzt nach der Umstellung in iQontrol nicht mehr angezeigt und iQontrol sagt, nicht vorhanden.

Muss in iQontrol der Pfad jetzt geändert werden oder woran kann das liegen?

[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:

1. IPv4 beim Start des Slaves, keine Verbindung zum Master
2. Wenn ioBroker Master beendet wird schafft es der Slave nicht mehr sich zu verbinden
3. Skript Download package.zip - javascript-Adapter
4. 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