EXPERIMENTELL: JsonL Datenbank für js-controller

[simatec]

Die Umstellung auf meinem Testsystem lief problemlos durch. Werde nun das ganze testen und beobachten.

[crunchip]

@alcalzone bekomms grad nicht gebacken, wie ich die zip Datei versenden könnte, da sie immer noch 32,5mb und zu groß für Mail ist. Muss ich mal schauen oder zur Not teil ich es auf.

[apollon77]

@crunchip Dropbox? Google Drive? und Freigeben?

[AlCalzone]

Wir haben ein potentielles Performance-Problem im JS-Controller identifiziert. Das müsste so 1:1 auch die klassische File DB betreffen.

[crunchip]

@apollon77 hat sich schon geklärt

[crunchip]

@alcalzone ahja, also schon gleich was gefunden? deshalb auch die cpu des js-controllers so hoch?

[apollon77]

@crunchip Jain ... das file hat ein thema gezeigt wo viel Performance drauf geht was man optimieren kann ... aber wie @AlCalzone gesagt hat sollte das identisch die normale File DB betreffen. Also warum es "mit jsonl db plötzlich höher ist" im CPU verbrauch war nichts offensichtliches zu sehen

[crunchip]

wegen js-controller neustarts hab ich nun getestet, Problem lag dann wirklich nur an dem "node --prof" Befehl

Gesamt iobroker cpu bei über 200% kurz nach dem Neustart, pendelt sich so gerade bei 155% ein

[{"command":"iobroker.js-controller","pid":"2181","cpu":82.3,"mem":9.1,"vmem":1095432,"rss":508712,"start":"14:47","time":"6:06"},{"command":"io.javascript.0","pid":"3647","cpu":32.7,"mem":6,"vmem":1165212,"rss":339588,"start":"14:49","time":"1:52"},{"command":"io.admin.0","pid":"2378","cpu":5.1,"mem":3,"vmem":874488,"rss":172184,"start":"14:47","time":"0:22"},{"command":"io.iogo.0","pid":"3212","cpu":10.1,"mem":2.1,"vmem":1933128,"rss":119652,"start":"14:49","time":"0:36"},{"command":"io.simple-api.0","pid":"4952","cpu":2.7,"mem":1.7,"vmem":682268,"rss":96152,"start":"14:50","time":"0:08"},{"command":"io.backitup.0","pid":"2408","cpu":0.7,"mem":1.6,"vmem":663108,"rss":93352,"start":"14:48","time":"0:03"},{"command":"io.influxdb.0","pid":"2969","cpu":8,"mem":1.6,"vmem":663992,"rss":91604,"start":"14:48","time":"0:30"},{"command":"io.iot.0","pid":"3621","cpu":1.3,"mem":1.6,"vmem":794744,"rss":90332,"start":"14:49","time":"0:04"},{"command":"io.socketio.0","pid":"5007","cpu":0.8,"mem":1.5,"vmem":713808,"rss":88456,"start":"14:50","time":"0:02"},{"command":"io.influxdb.2","pid":"2999","cpu":7.5,"mem":1.5,"vmem":655672,"rss":84036,"start":"14:48","time":"0:27"},{"command":"io.influxdb.1","pid":"2984","cpu":2.3,"mem":1.3,"vmem":652268,"rss":78040,"start":"14:48","time":"0:08"},{"command":"io.shelly.0","pid":"4031","cpu":2.1,"mem":1.3,"vmem":648952,"rss":76452,"start":"14:49","time":"0:06"},{"command":"io.shuttercontrol.0","pid":"4060","cpu":1.3,"mem":1.3,"vmem":650464,"rss":74600,"start":"14:50","time":"0:03"},{"command":"io.virtualpowermeter.0","pid":"5521","cpu":3.2,"mem":1.3,"vmem":647368,"rss":73356,"start":"14:50","time":"0:08"},{"command":"io.zigbee.0","pid":"5898","cpu":2.2,"mem":1.3,"vmem":711332,"rss":73116,"start":"14:51","time":"0:04"},{"command":"io.sonoff.0","pid":"5026","cpu":6.7,"mem":1.2,"vmem":642520,"rss":70156,"start":"14:50","time":"0:19"},{"command":"io.linux-control.0","pid":"3662","cpu":4.7,"mem":1.2,"vmem":904212,"rss":69780,"start":"14:49","time":"0:16"},{"command":"io.tr-064.0","pid":"5298","cpu":1.3,"mem":1.2,"vmem":639808,"rss":69224,"start":"14:50","time":"0:03"},{"command":"io.web.0","pid":"5618","cpu":1.5,"mem":1.2,"vmem":644320,"rss":68676,"start":"14:51","time":"0:03"},{"command":"io.unifi.0","pid":"5332","cpu":4.2,"mem":1.1,"vmem":637712,"rss":66624,"start":"14:50","time":"0:10"},{"command":"io.telegram.0","pid":"5074","cpu":2.1,"mem":1.1,"vmem":773524,"rss":66572,"start":"14:50","time":"0:05"},{"command":"io.radar2.0","pid":"3951","cpu":1.3,"mem":1.1,"vmem":902612,"rss":65816,"start":"14:49","time":"0:04"},{"command":"io.telegram.1","pid":"5238","cpu":2,"mem":1.1,"vmem":837916,"rss":65676,"start":"14:50","time":"0:05"},{"command":"io.history.0","pid":"2923","cpu":2,"mem":1.1,"vmem":704220,"rss":63940,"start":"14:48","time":"0:08"},{"command":"io.smartcontrol.0","pid":"4979","cpu":1.2,"mem":1.1,"vmem":637000,"rss":63272,"start":"14:50","time":"0:03"},{"command":"io.mihome.0","pid":"3694","cpu":0.5,"mem":1.1,"vmem":612384,"rss":63212,"start":"14:49","time":"0:01"},{"command":"io.sourceanalytix.0","pid":"5041","cpu":4.3,"mem":1.1,"vmem":628040,"rss":63044,"start":"14:50","time":"0:12"},{"command":"io.fully-tablet-control.0","pid":"2729","cpu":1,"mem":1.1,"vmem":635484,"rss":62720,"start":"14:48","time":"0:04"},{"command":"io.alexa2.0","pid":"2393","cpu":1.1,"mem":1.1,"vmem":883308,"rss":62212,"start":"14:47","time":"0:04"},{"command":"io.pollenflug.0","pid":"3922","cpu":1,"mem":1.1,"vmem":702068,"rss":61896,"start":"14:49","time":"0:03"},{"command":"io.info.0","pid":"3189","cpu":0.7,"mem":1,"vmem":701368,"rss":59348,"start":"14:49","time":"0:02"},{"command":"io.wled.0","pid":"5653","cpu":3.4,"mem":1,"vmem":616556,"rss":59180,"start":"14:51","time":"0:07"},{"command":"io.tankerkoenig.0","pid":"5056","cpu":0.9,"mem":1,"vmem":699740,"rss":58624,"start":"14:50","time":"0:02"},{"command":"io.logparser.0","pid":"3678","cpu":0.9,"mem":1,"vmem":614992,"rss":58512,"start":"14:49","time":"0:03"},{"command":"io.trashschedule.0","pid":"5315","cpu":0.7,"mem":1,"vmem":632632,"rss":57456,"start":"14:50","time":"0:01"},{"command":"io.wiffi-wz.0","pid":"5635","cpu":0.8,"mem":1,"vmem":631548,"rss":57312,"start":"14:51","time":"0:01"},{"command":"io.milight-smart-light.0","pid":"3888","cpu":0.6,"mem":1,"vmem":631256,"rss":56780,"start":"14:49","time":"0:02"},{"command":"io.ble.0","pid":"2430","cpu":0.6,"mem":0.9,"vmem":612420,"rss":55780,"start":"14:48","time":"0:02"},{"command":"io.chromecast.0","pid":"2647","cpu":0.4,"mem":0.9,"vmem":1662116,"rss":55600,"start":"14:48","time":"0:01"},{"command":"io.jarvis.0","pid":"3632","cpu":0.4,"mem":0.9,"vmem":629756,"rss":54608,"start":"14:49","time":"0:01"},{"command":"io.ping.0","pid":"3903","cpu":0.9,"mem":0.9,"vmem":612412,"rss":54352,"start":"14:49","time":"0:02"},{"command":"io.sayit.0","pid":"3969","cpu":0.5,"mem":0.9,"vmem":612308,"rss":53352,"start":"14:49","time":"0:01"},{"command":"io.text2command.0","pid":"5283","cpu":0.5,"mem":0.9,"vmem":612764,"rss":53288,"start":"14:50","time":"0:01"},{"command":"io.vis-inventwo.0","pid":"5554","cpu":0.5,"mem":0.9,"vmem":610072,"rss":53124,"start":"14:51","time":"0:01"},{"command":"io.broadlink2.0","pid":"2453","cpu":0.3,"mem":0.9,"vmem":612204,"rss":53000,"start":"14:48","time":"0:01"},{"command":"io.yeelight-2.0","pid":"5827","cpu":0.7,"mem":0.9,"vmem":628392,"rss":52644,"start":"14:51","time":"0:01"},{"command":"io.seq.0","pid":"3999","cpu":0.7,"mem":0.9,"vmem":611844,"rss":52400,"start":"14:49","time":"0:02"},{"command":"io.email.0","pid":"2699","cpu":0.3,"mem":0.9,"vmem":612620,"rss":51616,"start":"14:48","time":"0:01"}]

[AlCalzone]

@crunchip wie @apollon77 schon geschrieben hat, nichts auffälliges was ich direkt mit jsonl in Verbindung bringen würde. Ich werde später auch noch mal nen test starten wo ich sehr viele Schreibzugriffe generiere, vielleicht sieht man da noch was anderes.

[Dr. Bakterius]

@alcalzone, @apollon77 Also nachdem bis jetzt die objects.jsonl nicht neu geschrieben wurde, habe ich mal den ioBroker beendet und das File vorher und nachher verglichen.

• vorher: ....... 46.209.486 Byte - 21.201 Zeilen
• nachher: .... 15.569.482 Byte - 10.744 Zeilen

Da müsste doch schon lange das File neu geschrieben worden sein, oder?

Und noch etwas ist mir aufgefallen:

user@iobroker:~$ iobroker upgrade self
No connection to databases possible ...

Besteht da ein Zusammenhang mit der neuen Datenbank?

[apollon77]

@dr-bakterius naja doppelte grösse ... 10744*2 = 21.488 ... Vllt wäre es "bald" gegangen :-))

Den Fehler kann ich bei mir nicht nachstellen ... master/slave oder single host?

[Dr. Bakterius]

@apollon77 Hieß es nicht doppelte Größe und 1.000 Zeilen? Es hat die dreifache Größe und über 10.000 Zeilen mehr!

Ich habe nur einen single Host in einem LXC unter Proxmox. Bis zur Umstellung hatte ich diesen Fehler nie...

[Dr. Bakterius]

@apollon77 sagte in EXPERIMENTELL: JsonL Datenbank für js-controller:

Den Fehler kann ich bei mir nicht nachstellen

Auch bei iobroker update kommt diese Fehlermeldung wenn der ioBroker nicht läuft. Läuft er, kann das update durchgeführt werden.

[apollon77]

@dr-bakterius Also gerade auf allen meinen 3.2.16er testsystemen (file, redis, jsonl) getestet ... tut überall. Hat der host viel zu tun? versuch mal in der iobroker.json den connectTimeout in der objects sektion hochzusetzen. müsste auf 2000 stehen.

Der Fehler kommt wenn quasi innerhalb von 2s der Server nicht startet, was aber an sich im Normalfall passieren sollte

[Dr. Bakterius]

@apollon77 Ich habe mal auf 20 Sekunden gestellt - dauert aber geht. Dann 5 Sekunden - geht auch. Und danach wieder auf 2 Sekunden. Geht jetzt plötzlich auch wieder. Dauert aber länger als gewöhnlich (wenn der Broker läuft geht es sofort). Der Host läuft auf Sparflamme und hat nicht viel zu tun. Was soll ich sagen...

Bleibt noch das Thema mit der nicht komprimierten objects.jsonl.

[apollon77]

@dr-bakterius Naja ok das es wenn iobroker nicht läuft kurz dauert (und bissl länger also bei controller 3.1.x) ist normal.

Wenn kein iobroker läuft dann ist die DB nicht da, also startet der CLI Kommando erstmal eine DB damit er dahin verbinden kann. Das sind halt die paar Sekunden. Und das muss er nicht wenns schon läuft - dann ists ja schon am laufen.

[Dr. Bakterius]

@apollon77 Okay, alles klar. Vielleicht dauert es jetzt länger weil die Datenbank größer ist? Mit zwei Sekunden hat es doch nicht geklappt (hatte zu speichern vergessen), aber mit drei Sekunden geht es jetzt.

[apollon77]

@dr-bakterius Wenn das einlesen einer jsonl DB wegen dem gewählten Ansatz länger dauert als das lesen und parten eines reinen JSOns (was gut sein kann), dann könnte da was dran sein.
@AlCalzone

[AlCalzone]

@dr-bakterius sagte in EXPERIMENTELL: JsonL Datenbank für js-controller:

Hieß es nicht doppelte Größe und 1.000 Zeilen? Es hat die dreifache Größe und über 10.000 Zeilen mehr!

Mit doppelte Größe war die Anzahl der Zeilen gemeint. @apollon77 hat das schon richtig wieder gegeben.

Komprimiert wird, wenn die Anzahl der Zeilen (d.h. Schreib- und Löschoperationen) in der Datei doppelt so hoch ist wie nötig und nur dann wenn diese Anzahl mindestens 1000 beträgt.
Es wäre also tatsächlich nach weiteren 287 Updates passiert. An den Zahlen können wir durchaus noch schrauben - das war ein erster Wurf.

Und ja, es kann sein, dass das Starten länger dauert, weil mehr geparsed wird. Ich hab ne Idee wie man das optimieren könnte. Kannst du deine (recht große) Objects DB teilen (auch gerne privat per E-Mail) oder stehen da zu viele Geheimnisse drin?

[Dr. Bakterius]

@alcalzone Okay, danke für die Erklärung. Dann habe ich dich beim ersten Mal falsch verstanden. Alles gut. Nachdem das ganze noch experimentell ist, vermutet man hinter jeder Sache gleich einen Bug.

Ich denke, mit 10.700 Objekten bin ich eher im Durchschnitt.