UPDATE 31.10.: Amazon Alexa - ioBroker Skill läuft aus ?

[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

[Diginix]

@apollon77 nodejs 14.19.0
Da es nur Adapterupdates waren, habe ich bei laufendem iobroker und offenem admin Tab in der CLI:

iobroker update && iobroker upgrade all -y

Der Admin war dann auch direkt nach Browser Refresh auf 5.3.1 und im iobroker Log sieht man außer dieser einen Zeile absolut nichts anderes:

2022-02-21 22:58:05.440  - info: admin.0 (610598) starting. Version 5.3.1 in /opt/iobroker/node_modules/iobroker.admin, node: v14.19.0, js-controller: 4.0.15

Davor und danach sind mit zeitlichem Abstand nur Ausgaben von meinen Skripten.
Mein js-controller läuft auf Loglevel warn, daher ist der nicht sehr mitteilungsbedürftig.

iobroker.json:

Spoiler

{
  "system": {
    "memoryLimitMB": 0,
    "hostname": ""
  },
  "multihostService": {
    "enabled": false,
    "secure": true
  },
  "network": {
    "IPv4": true,
    "IPv6": true,
    "bindAddress": null,
    "useSystemNpm": true
  },
  "objects": {
    "type": "jsonl",
    "typeComment": "Possible values: 'file' - [port 9001], redis - [port 6379], couch - [port 5984].",
    "host": "127.0.0.1",
    "port": 9001,
    "user": "",
    "pass": "",
    "noFileCache": false,
    "connectTimeout": 2000,
    "writeFileInterval": 3600000,
    "options": {
      "auth_pass": null,
      "retry_max_delay": 5000
    }
  },
  "states": {
    "type": "jsonl",
    "typeComment": "Possible values: 'file' - [port 9000], 'redis' - [port 6379].",
    "host": "127.0.0.1",
    "port": 9000,
    "maxQueue": 1000,
    "writeFileInterval": 60000,
    "options": {
      "auth_pass": null,
      "retry_max_delay": 5000
    }
  },
  "log": {
    "level": "warn",
    "maxDays": 14,
    "noStdout": true,
    "transport": {
      "file1": {
        "zippedArchive": false,
        "type": "file",
        "enabled": true,
        "filename": "log/iobroker",
        "fileext": ".log",
        "maxsize": null,
        "maxFiles": null
      },
      "syslog1": {
        "type": "syslog",
        "enabled": false,
        "host": "localhost",
        "host_comment": "The host running syslogd, defaults to localhost.",
        "port_comment": "The port on the host that syslog is running on, defaults to syslogd's default port(514/UDP).",
        "protocol": "udp4",
        "protocol_comment": "The network protocol to log over (e.g. tcp4, udp4, unix, unix-connect, etc).",
        "path_comment": "The path to the syslog dgram socket (i.e. /dev/log or /var/run/syslog for OS X).",
        "facility_comment": "Syslog facility to use (Default: local0).",
        "localhost": "iobroker",
        "localhost_comment": "Host to indicate that log messages are coming from (Default: localhost).",
        "sysLogType_comment": "The type of the syslog protocol to use (Default: BSD).",
        "app_name_comment": "The name of the application (Default: process.title).",
        "eol_comment": "The end of line character to be added to the end of the message (Default: Message without modifications)."
      }
    }
  },
  "dataDirComment": "Always relative to iobroker.js-controller/",
  "dataDir": "../../iobroker-data/"
}

Die hatte @AlCalzone ja auch schon.

Mich stören die Auffälligkeiten nicht und ich kann damit leben, aber wollte es eben gemeldet haben. Wenn der als stable auf breite Masse losgelassen wird, gibt es vllt noch andere Betroffene. Und falls nicht, dann bleibe ich eben für immer der einzige mit js-c RAM Amokläufen.

[AlCalzone]

@diginix sagte in js-controller 4.0 jetzt im BETA/LATEST!:

Mich stören die Auffälligkeiten nicht und ich kann damit leben, aber wollte es eben gemeldet haben.

Wir würden es schon gerne finden, aber dazu müssen wir es entweder verstehen oder nachstellen können. Ich versuch mich nachher auch nochmal dran.
Ist sonst noch irgendwas auffälliges während dem Update? z.B. hohe input/output counts in der Instanzübersicht während dem Update?

[Diginix]

@alcalzone Keine Auffälligkeiten bei in/out beim Controller. 15min nach dem Ausreißer gestern war in mal bei 73 statt <50 wie normal. Aber das ist ja sicher weit unter dem Radar.

Im Diagramm sehe ich gerade, dass sich der js-controller heute 7:41 Uhr vollkommen unbemerkt zeitweise auch wieder >2 GB gegönnt hat. Zu der Zeit war der iobroker einfach nur im Leerlauf. Kein Backup Cron, kein gar nichts.

[Diginix]

@AlCalzone HA!

Ändert man die Diagrammdarstellung und zoomt rein, sieht man doch etwas:

Immer wenn der RAM hochschnellt bekommt der js-controller ein Vielfaches an in states (>200 bei sonst <50).

[apollon77]

@diginix Interessant. Sind das controller eingehend oder ausgehend changes? Ansonsten: War das während dem Update auch so so?

Könntest DU während wir das versuchen zu analysieren den controler bitte auf info loglevel stellen ?

[Diginix]

@apollon77 Nur die eingehenden Events schnellen hoch. Das obere Diagramm mit >200 in Events war bei dem Update
Das untere Diagramm ist von heute morgen wo eigentlich keine Aktivitäten waren.
Loglevel ist auf info umgestellt.