js-controller 4.0 jetzt im BETA/LATEST!

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

[apollon77]

@diginix Wirklich "inputCount"?

[Diginix]

@apollon77 Ja, system.host.iobroker.inputCount geht von normal ca 40 auf >200

Die Entprellzeit für die Erfassung war sogar 5000 ms. Habe nun mal 1000 eingestellt, falls es mal in unter 5 Sek hochschnellt, bekäme man es sonst gar nicht mit.

Nun würde mich ja mal brennend interessieren woher die inEvents kommen (können)?

[AlCalzone]

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

Nun würde mich ja mal brennend interessieren woher die inEvents kommen (können)?

Magst du vielleicht noch die inputs/outputs für die bekannterweise etwas gesprächigeren Adapter aktivieren?
d.h. Javascript, Shelly (?), Influxdb, mihome-vacuum?

mihome-vacuum hab ich zur Sicherheit mit drin, weil der es bei mir auch mal geschafft hat mit tausenden Logs meinen Pi zum Absturz zu bringen.

[apollon77]

@diginix Ja ich denke es ist nicht direkt"diese Events" weil das sind viel zu wenige. Und die Zahl sagt auch nur das bei den (recht wenigen) States die der Controller selbst als Updates bekommt es mehr wurde ... Was nebenher ggf noch in der DB pot los ist ist damit nicht sichtbar.

Aber generell ists komisch, prüfe nochmal deine skripte ob davon ggf welche "spammen" könnten ... und ja die Idee mehr Adapterprozesse (alle?) mitzuloggen ist auch gut.

Setz nur das Reporting Interval nicht zu weit runter ...

[Diginix]

@apollon77 Allein der iobroker Neustart wegen Loglevel Umstellung hat 10 Uhr auch wieder diese Anomalie:

Somit müsste es sich doch eigentlich auch bei euch mit meinen Dateien nachstellen lassen? Hat es ja aber anscheinend nicht.

[apollon77]

@diginix Naja dann müsste man es mal schaffen es komplett nachzustellen - aber auch das tat ja bei dir letztens nicht ... Weil wenn du es nachstellen könntest dann wäre ne Idee mal unterschiedliche Adapter zu deaktivieren um zu schauen ob es passiert wenn mit denen was ist und und und

[Diginix]

@apollon77 Für den Javascript Adapter hatte ich in/out Events schon mit in der history habe nun noch influx, shelly, mihome-vacuum dazu genommen.

Zumindest gibt es bei in/out beim javascript Adapter zeitliche Zusammenhänge:

Die Spitzen alle 15min muss ich noch prüfen. Da läuft mind. 1 Cron in einem Skript, aber warum da dann >3000 Events fliegen, verstehe ich gerade noch nicht. Habe den einzigen 15min Cron den ich finden konnte mal auskommentiert. Bin gespannt ob die Spitzen dann weg sind.

Ganz rechts sieht man auch noch eine "out" Spitze vom Skript Adapter mit >260 kurz nachdem alle Skripte wieder liefen nach iobroker restart.

[Moko]

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

@moko Also nein kann damit nichts zu tun haben ... und ja Backitup 2.3.3 ist noch im Latest ... wie auch der controller 4

https://repo.iobroker.live/sources-dist.json (ist in iobroker als stable hinterlegt) zeigt mir auch die 2.3.3 an, iobroker selbst meint
"Installierte Instanzen: 1
Verfügbare Version: 2.2.3
Installierte Version: 2.2.3"

[Diginix]

@moko Wo steht da 2.3.3?

[Moko]

@diginix latestVersion "2.3.3"

P.S. ich habe nicht behauptet dass die 2.3.3 als stable angezeigt wird.
Bei mir ist die letzte 2.2.3

P.S. mein Fehler: habe latest mit stable verwechselt.

[Diginix]

@moko Wenn du auf stable bist, wird dir keine latest Ver. angeboten.

[Diginix]

@AlCalzone Ich bin nun schon die ganze Zeit auf der Suche nach der Ursache für die Eventspitzen beim Javascript Adapter.
Alle Skripte zusammen haben laut Logausgabe <80 subscriptions. Wenn ich die javascript Instanz starte und somit auch alle Skripte, gibt es schon mal eine Spitze von 263 Event ausgehend. Wie wird dieser Wert ermittelt bzw. was zählt da mit rein?

Die Spitzen bei den eingehenden Events alle 15 min kann ich mir auch noch nicht erklären. Bin aber noch am Testen durch Deaktivieren von einzelnen Skripten die States von Adapter nutzen, die nur alle 15 min laufen (dwd, daswetter).

[AlCalzone]

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

Alle Skripte zusammen haben laut Logausgabe <80 subscriptions. Wenn ich die javascript Instanz starte und somit auch alle Skripte, gibt es schon mal eine Spitze von 263 Event ausgehend. Wie wird dieser Wert ermittelt bzw. was zählt da mit rein?

Jede State-Änderung jedes Wertes auf den du subscribest zählt da mit rein. By default subscribed der JS-Adapter aber alle States, selbst die die du nicht nutzt. So ermöglicht er, dass getState und setState trotz asynchroner DB synchron sind.

---

Ich hab grade nochmal versucht das nachzustellen. Testinstanz mit latest controller, die Adapter Web/WS/VIS, ein Skript welches 1000 changes/s generiert (also 15000 in- und out-events), und dabei fleißig Adapter aktualisiert. Nix... Der Controller dümpelt auf 180 MB RAM herum.

[Diginix]

@alcalzone Hm, ich werde mit meiner Analyse auch nicht schlauer.
Ich habe alle javascripte angehalten die ein "schedule" enthalten. Trotzdem habe ich weiterhin alle 15 min diese Spitzen.

Die gibt es wahrs. schon immer und machen auch keine direkten Probleme, aber nun habe ich mich durch das Erfassen der in/out Events bis dahin vorgearbeitet und wüsste gern den Ursprung.
Wenn ich den javascript Adapter anhalte kommt die ausgehende Spitze im Bild markiert. Sind aber nur 230, also ganz andere Skalierung. Meine Skripte schreiben beim Beenden keine states. Jedenfalls nicht wissentlich.