js-controller 4.0 jetzt im BETA/LATEST!

e-i-k-e

Aktualisiere gerade ein Slave von 4.0.10 auf 4.0.15.
Habe es nun bereits mit sudo -H -u iobroker npm install iobroker.js-controller versucht.

Bei den anderen Geräten hatte ich dieses Problem nicht.
Was kann ich tun?

pi@raspberrypi-display2:/opt/iobroker $ sudo -H -u iobroker npm install iobroker.js-controller

> iobroker.js-controller@4.0.10 preinstall /opt/iobroker/node_modules/iobroker.js-controller
> node lib/preinstallCheck.js

NPM version: 6.14.16

> iobroker.js-controller@4.0.10 install /opt/iobroker/node_modules/iobroker.js-controller
> node iobroker.js setup first

No connection to objects 192.168.3.100:6379[redis]
/opt/iobroker/node_modules/standard-as-callback/built/index.js:6
        throw e;
        ^

Error: Connection is closed.
    at close (/opt/iobroker/node_modules/ioredis/built/redis/event_handler.js:184:25)
    at Socket.<anonymous> (/opt/iobroker/node_modules/ioredis/built/redis/event_handler.js:151:20)
    at Object.onceWrapper (events.js:520:26)
    at Socket.emit (events.js:400:28)
    at TCP.<anonymous> (net.js:686:12)
Emitted 'error' event on ScanStream instance at:
    at /opt/iobroker/node_modules/ioredis/built/ScanStream.js:38:22
    at tryCatcher (/opt/iobroker/node_modules/standard-as-callback/built/utils.js:12:23)
    at /opt/iobroker/node_modules/standard-as-callback/built/index.js:33:51
    at processTicksAndRejections (internal/process/task_queues.js:95:5)
npm WARN optional SKIPPING OPTIONAL DEPENDENCY: fsevents@~2.3.2 (node_modules/chokidar/node_modules/fsevents):
npm WARN notsup SKIPPING OPTIONAL DEPENDENCY: Unsupported platform for fsevents@2.3.2: wanted {"os":"darwin","arch":"any"} (current: {"os":"linux","arch":"arm"})

npm ERR! code ELIFECYCLE
npm ERR! errno 1
npm ERR! iobroker.js-controller@4.0.10 install: `node iobroker.js setup first`
npm ERR! Exit status 1
npm ERR!
npm ERR! Failed at the iobroker.js-controller@4.0.10 install script.
npm ERR! This is probably not a problem with npm. There is likely additional logging output above.

npm ERR! A complete log of this run can be found in:
npm ERR!     /home/iobroker/.npm/_logs/2022-02-21T20_58_28_730Z-debug.l

Keine Ahnung was jetzt los ist..

pi@raspberrypi-display2:~ $ iobroker stop
pi@raspberrypi-display2:~ $ iobroker fix
library: loaded
Library version=2022-02-10
ioBroker is not installed in /opt/iobroker! Cannot fix anything...

apollon77

@e-i-k-e Wie geht es dem Redis? Steht ggf etwas im Redis log? Ich hab das gefühl das sich der beendet mittendrin.

e-i-k-e

@apollon77

Hast du zufällig den Pfad parat?

Ich habe den kompletten Container inkl. Reids mal neu gestartet. Keine Änderung.

Thomas Braun

@e-i-k-e

less -R /var/log/redis/redis-server.log

und

systemctl status redis

anschauen.

Diginix

@AlCalzone @apollon77
Hab eben per CLI admin, web und ws aktualisiert und dann ist der js-controller mal wieder RAM technisch eskaliert mit über 2 GB. Hat sich dann aber ohne mein Zutun wieder stabilisiert. Wahrs. reichten die 6 GB RAM der VM gerade so aus.

              total        used        free      shared  buff/cache   available
Mem:           5941        4407         131           1        1402        1242
Swap:             0           0           0

e-i-k-e

@thomas-braun

Danke.

Im Log steht immer das gleiche, nichts auffälliges.

11670:C 20 Feb 2022 22:13:49.210 * DB saved on disk
11670:C 20 Feb 2022 22:13:49.228 * RDB: 7 MB of memory used by copy-on-write
139:M 20 Feb 2022 22:13:49.345 * Background saving terminated with success
139:M 20 Feb 2022 22:15:49.680 * 10000 changes in 60 seconds. Saving...
139:M 20 Feb 2022 22:15:49.698 * Background saving started by pid 11703
11703:C 20 Feb 2022 22:16:04.583 * DB saved on disk
11703:C 20 Feb 2022 22:16:04.601 * RDB: 14 MB of memory used by copy-on-write
139:M 20 Feb 2022 22:16:04.688 * Background saving terminated with success
139:M 20 Feb 2022 22:18:21.814 * 10000 changes in 60 seconds. Saving...

pi@ioBroker-Rock:~$ systemctl status redis
* redis-server.service - Advanced key-value store
     Loaded: loaded (/lib/systemd/system/redis-server.service; enabled; vendor preset: enabled)
     Active: active (running) since Mon 2022-02-21 22:27:17 CET; 46min ago
       Docs: http://redis.io/documentation,
             man:redis-server(1)
    Process: 114 ExecStart=/usr/bin/redis-server /etc/redis/redis.conf (code=exited, status=0/SUCCESS)
   Main PID: 135 (redis-server)
      Tasks: 4 (limit: 18952)
     Memory: 1.7G
        CPU: 6min 39.212s
     CGroup: /system.slice/redis-server.service
             `-135 /usr/bin/redis-server 0.0.0.0:6379

Fünf weitere Slave laufen aber auch problemlos mit dem Master und der Redis DB.

Marty56

Ich beobachte einen seltsamen Effekt, den ich nicht verstehe.

Ich habe iob mit dem Update auf von js-controller 4 von Objects type: jsonl
States type: redis auf Objects type: jsonl States type: jsonl umgestellt, was auch ohne Probleme geklappt hat und einige Stunden stabil lief.

Dann hatte ich mir gedacht, dass ich redis ausschalte, um ein bisschen Speicher zu sparen. Diese Änderung führte zu einer dramatischen Instabilität. Iob konnte kein Web Interface mehr anzeigen, die über SSH gestartet Console hat mich nach einigen Sekunden wieder rausgeschmissen und Debmatic ist auch nicht mehr gestartet. Ansonsten habe ich noch NextPVR installiert. Debmatic und NextPVR haben keine Abhängigkeiten von redis.
Es wirkt so, als ob es dennoch Prozesse gibt, die immer noch redis Verfügbarkeit benötigen und wenn sie die nicht bekommen, das System extrem belasten.

Gottseidank konnte ich in der kurzen Zeitspanne, in der die Console funktioniert hat, den redis Server wieder via SSH einschalten und jetzt läuft es wieder stabil.

Hat jemand eine Idee? Kann man irgendwie herausbekommen, wer den Redis Server benutzt?

Marty56

gelöscht

Fortune95

@apollon77

Node.js: v14.19.0
js-controller: 4.0.15

Habe gerade folgendes nach einem Neustart des Shelly Adapters im Log gefunden:

2022-02-22 06:12:00.875 - error: shelly.0 (15030) uncaught exception: This socket has been ended by the other party
2022-02-22 06:12:00.876 - error: shelly.0 (15030) Error: This socket has been ended by the other party
at Socket.writeAfterFIN [as write] (net.js:468:14)
at connack (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:300:10)
at generate (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:32:14)
at Writable.write [as _write] (/opt/iobroker/node_modules/mqtt-connection/lib/writeToStream.js:13:9)
at writeOrBuffer (internal/streams/writable.js:358:12)
at Writable.write (internal/streams/writable.js:303:10)
at Connection.Duplexify._write (/opt/iobroker/node_modules/duplexify/index.js:208:22)
at doWrite (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:428:64)
at writeOrBuffer (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:417:5)
at Connection.Writable.write (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:334:11)
2022-02-22 06:12:00.877 - error: shelly.0 (15030) Exception-Code: EPIPE: This socket has been ended by the other party
2022-02-22 06:12:00.880 - error: shelly.0 (15030) uncaught exception: This socket has been ended by the other party
2022-02-22 06:12:00.880 - error: shelly.0 (15030) Error: This socket has been ended by the other party
at Socket.writeAfterFIN [as write] (net.js:468:14)
at writeVarByteInt (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:804:17)
at connack (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:302:3)
at generate (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:32:14)
at Writable.write [as _write] (/opt/iobroker/node_modules/mqtt-connection/lib/writeToStream.js:13:9)
at writeOrBuffer (internal/streams/writable.js:358:12)
at Writable.write (internal/streams/writable.js:303:10)
at Connection.Duplexify._write (/opt/iobroker/node_modules/duplexify/index.js:208:22)
at doWrite (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:428:64)
at writeOrBuffer (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:417:5)
2022-02-22 06:12:00.880 - error: shelly.0 (15030) Exception-Code: EPIPE: This socket has been ended by the other party
2022-02-22 06:12:00.881 - error: shelly.0 (15030) uncaught exception: This socket has been ended by the other party
2022-02-22 06:12:00.881 - error: shelly.0 (15030) Error: This socket has been ended by the other party
at Socket.writeAfterFIN [as write] (net.js:468:14)
at connack (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:303:10)
at generate (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:32:14)
at Writable.write [as _write] (/opt/iobroker/node_modules/mqtt-connection/lib/writeToStream.js:13:9)
at writeOrBuffer (internal/streams/writable.js:358:12)
at Writable.write (internal/streams/writable.js:303:10)
at Connection.Duplexify._write (/opt/iobroker/node_modules/duplexify/index.js:208:22)
at doWrite (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:428:64)
at writeOrBuffer (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:417:5)
at Connection.Writable.write (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:334:11)
2022-02-22 06:12:00.881 - error: shelly.0 (15030) Exception-Code: EPIPE: This socket has been ended by the other party
2022-02-22 06:12:00.882 - error: shelly.0 (15030) uncaught exception: This socket has been ended by the other party
2022-02-22 06:12:00.882 - error: shelly.0 (15030) Error: This socket has been ended by the other party
at Socket.writeAfterFIN [as write] (net.js:468:14)
at connack (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:305:10)
at generate (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:32:14)
at Writable.write [as _write] (/opt/iobroker/node_modules/mqtt-connection/lib/writeToStream.js:13:9)
at writeOrBuffer (internal/streams/writable.js:358:12)
at Writable.write (internal/streams/writable.js:303:10)
at Connection.Duplexify._write (/opt/iobroker/node_modules/duplexify/index.js:208:22)
at doWrite (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:428:64)
at writeOrBuffer (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:417:5)
at Connection.Writable.write (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:334:11)
2022-02-22 06:12:00.882 - error: shelly.0 (15030) Exception-Code: EPIPE: This socket has been ended by the other party
2022-02-22 06:12:00.883 - warn: shelly.0 (15030) Terminated (UNCAUGHT_EXCEPTION): Without reason
2022-02-22 06:12:00.950 - error: host.iobroker Caught by controller[1]: Error: This socket has been ended by the other party
2022-02-22 06:12:00.955 - error: host.iobroker Caught by controller[1]: at Socket.writeAfterFIN [as write] (net.js:468:14)
2022-02-22 06:12:00.955 - error: host.iobroker Caught by controller[1]: at connack (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:300:10)
2022-02-22 06:12:00.955 - error: host.iobroker Caught by controller[1]: at generate (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:32:14)
2022-02-22 06:12:00.955 - error: host.iobroker Caught by controller[1]: at Writable.write [as _write] (/opt/iobroker/node_modules/mqtt-connection/lib/writeToStream.js:13:9)
2022-02-22 06:12:00.955 - error: host.iobroker Caught by controller[1]: at writeOrBuffer (internal/streams/writable.js:358:12)
2022-02-22 06:12:00.956 - error: host.iobroker Caught by controller[1]: at Writable.write (internal/streams/writable.js:303:10)
2022-02-22 06:12:00.956 - error: host.iobroker Caught by controller[1]: at Connection.Duplexify._write (/opt/iobroker/node_modules/duplexify/index.js:208:22)
2022-02-22 06:12:00.956 - error: host.iobroker Caught by controller[1]: at doWrite (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:428:64)
2022-02-22 06:12:00.956 - error: host.iobroker Caught by controller[1]: at writeOrBuffer (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:417:5)
2022-02-22 06:12:00.956 - error: host.iobroker Caught by controller[1]: at Connection.Writable.write (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:334:11)
2022-02-22 06:12:00.956 - error: host.iobroker Caught by controller[2]: Error: This socket has been ended by the other party
2022-02-22 06:12:00.956 - error: host.iobroker Caught by controller[2]: at Socket.writeAfterFIN [as write] (net.js:468:14)
2022-02-22 06:12:00.956 - error: host.iobroker Caught by controller[2]: at writeVarByteInt (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:804:17)
2022-02-22 06:12:00.956 - error: host.iobroker Caught by controller[2]: at connack (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:302:3)
2022-02-22 06:12:00.957 - error: host.iobroker Caught by controller[2]: at generate (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:32:14)
2022-02-22 06:12:00.957 - error: host.iobroker Caught by controller[2]: at Writable.write [as _write] (/opt/iobroker/node_modules/mqtt-connection/lib/writeToStream.js:13:9)
2022-02-22 06:12:00.957 - error: host.iobroker Caught by controller[2]: at writeOrBuffer (internal/streams/writable.js:358:12)
2022-02-22 06:12:00.957 - error: host.iobroker Caught by controller[2]: at Writable.write (internal/streams/writable.js:303:10)
2022-02-22 06:12:00.957 - error: host.iobroker Caught by controller[2]: at Connection.Duplexify._write (/opt/iobroker/node_modules/duplexify/index.js:208:22)
2022-02-22 06:12:00.957 - error: host.iobroker Caught by controller[2]: at doWrite (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:428:64)
2022-02-22 06:12:00.957 - error: host.iobroker Caught by controller[2]: at writeOrBuffer (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:417:5)
2022-02-22 06:12:00.957 - error: host.iobroker Caught by controller[2]: Error: This socket has been ended by the other party
2022-02-22 06:12:00.957 - error: host.iobroker Caught by controller[2]: at Socket.writeAfterFIN [as write] (net.js:468:14)
2022-02-22 06:12:00.957 - error: host.iobroker Caught by controller[2]: at connack (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:303:10)
2022-02-22 06:12:00.958 - error: host.iobroker Caught by controller[2]: at generate (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:32:14)
2022-02-22 06:12:00.958 - error: host.iobroker Caught by controller[2]: at Writable.write [as _write] (/opt/iobroker/node_modules/mqtt-connection/lib/writeToStream.js:13:9)
2022-02-22 06:12:00.958 - error: host.iobroker Caught by controller[2]: at writeOrBuffer (internal/streams/writable.js:358:12)
2022-02-22 06:12:00.958 - error: host.iobroker Caught by controller[2]: at Writable.write (internal/streams/writable.js:303:10)
2022-02-22 06:12:00.958 - error: host.iobroker Caught by controller[2]: at Connection.Duplexify._write (/opt/iobroker/node_modules/duplexify/index.js:208:22)
2022-02-22 06:12:00.958 - error: host.iobroker Caught by controller[2]: at doWrite (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:428:64)
2022-02-22 06:12:00.958 - error: host.iobroker Caught by controller[2]: at writeOrBuffer (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:417:5)
2022-02-22 06:12:00.958 - error: host.iobroker Caught by controller[2]: at Connection.Writable.write (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:334:11)
2022-02-22 06:12:00.958 - error: host.iobroker Caught by controller[3]: Error: This socket has been ended by the other party
2022-02-22 06:12:00.958 - error: host.iobroker Caught by controller[3]: at Socket.writeAfterFIN [as write] (net.js:468:14)
2022-02-22 06:12:00.959 - error: host.iobroker Caught by controller[3]: at connack (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:305:10)
2022-02-22 06:12:00.959 - error: host.iobroker Caught by controller[3]: at generate (/opt/iobroker/node_modules/mqtt-connection/node_modules/mqtt-packet/writeToStream.js:32:14)
2022-02-22 06:12:00.959 - error: host.iobroker Caught by controller[3]: at Writable.write [as _write] (/opt/iobroker/node_modules/mqtt-connection/lib/writeToStream.js:13:9)
2022-02-22 06:12:00.959 - error: host.iobroker Caught by controller[3]: at writeOrBuffer (internal/streams/writable.js:358:12)
2022-02-22 06:12:00.959 - error: host.iobroker Caught by controller[3]: at Writable.write (internal/streams/writable.js:303:10)
2022-02-22 06:12:00.959 - error: host.iobroker Caught by controller[3]: at Connection.Duplexify._write (/opt/iobroker/node_modules/duplexify/index.js:208:22)
2022-02-22 06:12:00.961 - error: host.iobroker Caught by controller[3]: at doWrite (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:428:64)
2022-02-22 06:12:00.961 - error: host.iobroker Caught by controller[3]: at writeOrBuffer (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:417:5)
2022-02-22 06:12:00.962 - error: host.iobroker Caught by controller[3]: at Connection.Writable.write (/opt/iobroker/node_modules/duplexify/node_modules/readable-stream/lib/_stream_writable.js:334:11)
2022-02-22 06:12:00.962 - error: host.iobroker instance system.adapter.shelly.0 terminated with code 1 (JS_CONTROLLER_STOPPED)

apollon77

@diginix welche nodejs Version nutzt du?

apollon77

@diginix hast du bitte mal das log dieser Updates und paar mins davor und danach bitte? Auch: wie genau wurden die Updates ausgeführt? Einzeln? Uplgrade all?

apollon77

@e-i-k-e und das log ist vom Update Zeitraum? Ja komisch. Dann Versuchs nochmal bitte

arteck

@marty56 zeigmal

iob setup custom

wenn alle hosts bei dir auf jsonl laufen dann ist redis überflüssig.. da läuft nix mehr im hintergrund

apollon77

@e-i-k-e bitte auch mal die Ausgabe von iob Upgrade Self zeigen.

apollon77

@marty56 also wenn iobroker es nicht mehr nutzt dann wäre super wenn wir das in einem eigenen thread klären könnten. Wenn es so eine Auswirkung auf dein System hat dann sollte Top (falls Prozesse Amok laufen) Bzw /var/log/syslog Einblicke geben

apollon77

@fortune95 ja. Issue bei shelly Bitte. Scheinbar verkraftet der es nicht so gut wenn eine MQTT Verbindung abbricht. Hat nichts mit dem Controller zu tun

apollon77

@arteck …oder eine der anderen von ihm genannten Softwares nutzen auf redis. Müsste er aber wissen ;-)) aber bitte in einem extra thread.

MCU

@apollon77 Hab gerade mal ein upgrade gemacht von 3.3.22 -> 4.0.15
Sind die Fehler normal?
Frische Installation , iot gestoppt, da Test-System

pi@raspberrypi:~ $ iob upgrade self
Update js-controller from @3.3.22 to @4.0.15
NPM version: 6.14.16
npm install iobroker.js-controller@4.0.15 --loglevel error --unsafe-perm --prefix "/opt/iobroker" (System call)
Server Objects 127.0.0.1:54854 Error from InMemDB: Error: GET-UNSUPPORTED for namespace cfg.: Data=["meta.objects.features.useSets"]
Server States 127.0.0.1:51330 Error from InMemDB: Error: GET-UNSUPPORTED for namespace meta.: Data=["meta.states.protocolVersion"]
Server Objects 127.0.0.1:54854 Error from InMemDB: Error: GET-UNSUPPORTED for namespace cfg.: Data=["meta.objects.protocolVersion"]
Server States 127.0.0.1:51332 Error from InMemDB: Error: PSUBSCRIBE-UNSUPPORTED for namespace meta.: Data=["meta.*"]
Server Objects 127.0.0.1:54854 Error from InMemDB: Error: Unknown LUA script load
Server Objects 127.0.0.1:54854 Error from InMemDB: Error: Unknown LUA script load
Server Objects 127.0.0.1:54854 Error from InMemDB: Error: Unknown LUA script load
Server Objects 127.0.0.1:54854 Error from InMemDB: Error: SET-UNSUPPORTED for namespace cfg.: Data=["meta.objects.features.useSets",{"type":"Buffer","data":[49]}]
Could not migrate objects to corresponding sets: Error SET-UNSUPPORTED for namespace cfg.: Data=["meta.objects.features.useSets",{"type":"Buffer","data":[49]}]

apollon77

@mcu wie du im zweiten post in diesem thread klar lesen kannst. Ja sind leider normal.

apollon77

@diginix Also ichhabe gerade mal mein jsonl testsystem mit upgrades maltretiert ... Mein Controller hat dort 150MB und ist meistens maximal auf 170MB hoch, einmal kurz auf 190MB, aber nur um spätestens 30s später wieder auf 150MB zu sinken ... Zeig mal bitte auch deine iobroker.json Konfig

NEWS

js-controller 4.0 jetzt im BETA/LATEST!

Support us

999
Online

30.4k
Users

76.7k
Topics

1.2m
Posts

NEWS

js-controller 4.0 jetzt im BETA/LATEST!

Support us

999Online

30.4kUsers

76.7kTopics

1.2mPosts

999
Online

30.4k
Users

76.7k
Topics

1.2m
Posts