wichtiges UPDATE für controller 7.2.2 im stable

[tp1de]

Startet jetzt. So sieht der Startlog aus:

! node-red.0 2018-02-16 11:06:51.192 debug 16 Feb 11:06:51 - [info] [inject:Jede Minute] repeat = 60000
! node-red.0 2018-02-16 11:06:23.395 debug 16 Feb 11:06:23 - [info] [inject:Jede 15 Sekunden] repeat = 15000
! node-red.0 2018-02-16 11:06:19.887 debug 16 Feb 11:06:19 - [info] [inject:Jede 15 Sekunden] repeat = 15000
! node-red.0 2018-02-16 11:06:10.718 debug 16 Feb 11:06:10 - [info] [inject:Jede 15 Sekunden] repeat = 15000
! node-red.0 2018-02-16 11:06:07.141 debug 29 queued state values set in ioBroker
! node-red.0 2018-02-16 11:06:06.997 warn 2018-02-16 11:06:06.990 - [34mdebug[39m: node-red.0 statesDB connected
! node-red.0 2018-02-16 11:06:06.913 warn 16 Feb 11:06:06 - [warn] Communication send error: Error: not opened
! node-red.0 2018-02-16 11:06:06.634 debug Message for "HC.01.Relais.6" queued because ioBroker connection not initialized Message for "HC.01.Sensoren.1wire.Fussbodenvorlauf" queued because ioBroker connection not initialized Message for "HC.0
! node-red.0 2018-02-16 11:06:06.634 debug Message for "HC.01.Sensoren.1wire.Heizungsrücklauf" queued because ioBroker connection not initialized Message for "HC.01.Vorrang_Wasser" queued because ioBroker connection not initialized
! node-red.0 2018-02-16 11:06:06.633 debug Message for "HC.01.Relais.7" queued because ioBroker connection not initialized
! node-red.0 2018-02-16 11:06:06.567 warn 2018-02-16 11:06:06.565 - [34mdebug[39m: node-red.0 objectDB connected
! node-red.0 2018-02-16 11:06:05.550 debug Message for "HC.01.Relais.0" queued because ioBroker connection not initialized Message for "HC.01.Relais.1" queued because ioBroker connection not initialized Message for "HC.01.Relais.2" queued beca
! node-red.0 2018-02-16 11:06:05.545 debug Message for "HC.01.Vorrang_Wasser" queued because ioBroker connection not initialized
! node-red.0 2018-02-16 11:06:05.521 debug 16 Feb 11:06:05 - [info] [inject:Jede 15 Sekunden] repeat = 15000
! node-red.0 2018-02-16 11:06:05.427 debug 16 Feb 11:06:05 - [info] [inject:8708f6be.fced8] repeat = 300000
! node-red.0 2018-02-16 11:06:05.423 debug Message for "HC.01.Sensoren.DHT22.Keller.Luftfeuchte" queued because ioBroker connection not initialized
! node-red.0 2018-02-16 11:06:05.422 debug Message for "HC.01.Sensoren.DHT22.Keller.Temperatur" queued because ioBroker connection not initialized
! node-red.0 2018-02-16 11:06:04.897 debug Message for "HC.01.Brennerauslastung" queued because ioBroker connection not initialized 16 Feb 11:06:04 - [info] [inject:Jede 10 Sekunden] repeat = 10000
! node-red.0 2018-02-16 11:06:04.893 debug Message for "HC.01.Brennerlaufzeit_Std" queued because ioBroker connection not initialized
! node-red.0 2018-02-16 11:06:04.890 debug Message for "HC.01.Brenner" queued because ioBroker connection not initialized
! node-red.0 2018-02-16 11:06:04.875 debug Message for "hm-rpc.0.info.connection" queued because ioBroker connection not initialized 16 Feb 11:06:04 - [info] [inject:Jede Minute] repeat = 60000
! node-red.0 2018-02-16 11:06:04.869 debug Message for "HC.01.Status" queued because ioBroker connection not initialized
! node-red.0 2018-02-16 11:06:04.866 debug Message for "HC.01.Brennerlaufzeit_Std" queued because ioBroker connection not initialized Message for "HC.01.Brennerlaufzeit_Tag" queued because ioBroker connection not initialized Message for "HC.01
! node-red.0 2018-02-16 11:06:04.865 debug Message for "HC.01.Brennerlaufzeit" queued because ioBroker connection not initialized
! node-red.0 2018-02-16 11:06:04.842 warn 2018-02-16 11:06:04.839 - [31merror[39m: node-red.0 no connection to objects DB
! node-red.0 2018-02-16 11:06:04.818 debug 16 Feb 11:06:04 - [info] Started flows
! node-red.0 2018-02-16 11:06:01.162 debug 16 Feb 11:06:01 - [info] [inject:1 hour] repeat = 3600000
! node-red.0 2018-02-16 11:05:59.788 debug 16 Feb 11:05:59 - [info] [inject:Reset 00:00 Uhr] crontab = 00 00 * * *
! node-red.0 2018-02-16 11:05:36.621 debug 16 Feb 11:05:36 - [info] Starting flows
! node-red.0 2018-02-16 11:05:35.736 debug 16 Feb 11:05:35 - [info] Server now running at http://127.0.0.1:1880/
! node-red.0 2018-02-16 11:05:35.704 debug 16 Feb 11:05:35 - [37-rpi-piface.js] Error: "gpio load spi" command failed. Check device tree is disabled.
! node-red.0 2018-02-16 11:05:35.670 debug 16 Feb 11:05:35 - [info] Flows file : /opt/iobroker/iobroker-data/node-red/flows.json
! node-red.0 2018-02-16 11:05:35.664 warn 16 Feb 11:05:35 - [warn] Projects disabled : set editorTheme.projects.enabled=true to enable
! node-red.0 2018-02-16 11:05:35.661 debug 16 Feb 11:05:35 - [info] User directory : /opt/iobroker/iobroker-data/node-red/
! node-red.0 2018-02-16 11:05:35.655 debug 16 Feb 11:05:35 - [info] Settings file : /opt/iobroker/iobroker-data/node-red/settings.js
! node-red.0 2018-02-16 11:05:35.502 debug 16 Feb 11:05:35 - [info] Dashboard version 2.8.1 started at /ui
! node-red.0 2018-02-16 11:05:34.845 debug 16 Feb 11:05:34 - [info] Polymer started at /polymer
! node-red.0 2018-02-16 11:05:29.375 debug 16 Feb 11:05:29 - [info] Loading palette nodes
! node-red.0 2018-02-16 11:05:28.134 debug 16 Feb 11:05:28 - [info] Linux 4.9.35-v7+ arm LE
! node-red.0 2018-02-16 11:05:28.134 debug 16 Feb 11:05:28 - [info] Node.js version: v4.8.7
! node-red.0 2018-02-16 11:05:28.131 debug 16 Feb 11:05:28 - [info] Node-RED version: v0.18.3
! node-red.0 2018-02-16 11:05:28.112 debug 16 Feb 11:05:28 - [info] Welcome to Node-RED ===================
! node-red.0 2018-02-16 11:05:24.700 info Starting node-red: –max-old-space-size=128 /opt/iobroker/node_modules/iobroker.node-red/node_modules/node-red/red.js -v --settings /opt/iobroker/iobroker-data/node-red/settings.js
! node-red.0 2018-02-16 11:05:24.182 info starting. Version 1.5.1 in /opt/iobroker/node_modules/iobroker.node-red, node: v4.8.7
! node-red.0 2018-02-16 11:05:24.125 debug statesDB connected
! node-red.0 2018-02-16 11:05:24.027 debug objectDB connected
! host.rasp1 2018-02-16 11:05:22.306 info instance system.adapter.node-red.0 started with pid 21238

[apollon77]

Sieht gut aus, oder ?!

Die eine Zeile:

> node-red.0 2018-02-16 11:06:06.913 warn 16 Feb 11:06:06 - [warn] Communication send error: Error: not opened

kommt von irgendwelcher anderen Kommunikation, oder ?!

[tp1de]

Werde jetzt mal laufen lassen und Dir dann ein weiteres Feedback geben. Habe jetzt den Start der Flows um mindestens 10 Sekunden verzögert, das geht ja in der aktuellen Node-Red Version.

Habe noch keine Ahnung woher der communication error kommt. Mir ist nur aufgefallen, dass ich nach Neustart von node-red nicht auf die Web-Oberfläche (Port 1880) komme. Musste nochmal starten, dann ging es …..

[apollon77]

Dann baue ich heute Abend das zusätzliche Logging mal aus und release die 1.5.1. Klappt ja :-)

[tp1de]

Ingo,

ich habe jetzt noch einmal intensiv getestet. Das Puffern scheint zu funktionieren es spricht aus meiner Sicht nichts dagegen, diese Version produktiv zu setzten. Ich würde aber die Debug-Messages erst einmal drin lassen um zu sehen, wie häufig das Zwischenpuffern notwendig ist. Bleibt noch die Frage warum?

Auffällig ist, das beim Start von node-red die States DB connected wird, ca. 4 Sekunden später startet der erste Flow und 5 mSek später kommt der Connection Timeout zur States DB.

Dann dauert es ca. 2.5 Sekunden bis diese wieder verbunden ist. Dazwischen werden die die Messages gepuffert und nach Reconnect ca. 200 mSek später geschrieben. Beim letzten Start waren das 24 Werte !

Irgendwas muss doch die States DB Abbrüche verursachen …

Aber erst einmal vielen Dank und Grüße

Thomas

[apollon77]

@tom57:

Ich würde aber die Debug-Messages erst einmal drin lassen um zu sehen, wie häufig das Zwischenpuffern notwendig ist. Bleibt noch die Frage warum? `
Eigentlich unnötig weil es nur beim Starten puffert. Man bekommt aktuell potentielle "reconnectes" der State-DB nicht mit. Müsste man mal schauen was dann passiert.

@tom57:

Auffällig ist, das beim Start von node-red die States DB connected wird, ca. 4 Sekunden später startet der erste Flow und 5 mSek später kommt der Connection Timeout zur States DB.

Dann dauert es ca. 2.5 Sekunden bis diese wieder verbunden ist. Dazwischen werden die die Messages gepuffert und nach Reconnect ca. 200 mSek später geschrieben. Beim letzten Start waren das 24 Werte !

Irgendwas muss doch die States DB Abbrüche verursachen … `

In deinem letzten Log gab es aber keine reconnects … oder spielst Du daraf an das er doppet verbindet? DAS ist Absicht in dem node-red Fall.

Zuerst startet der Adapter selbst, er connected die State-DB, dann startet er node-red.

Node-red initialisiert dann die ganzen Nodes unter anderem die "ioBroker-Nodes". Diese bauen eine (gemeinsame) eigene Verbindung zur States-DB auf.

Das sieht man in deinem Log an sich schön. Da ist auch keinerlei Reconnect oder sonst was drin.