Sporadische Programmverzögerung unerklärbar

[Baxxy]

die debugging Vorschläge

Hier mal ein Muster wie das dann aussehen könnte...

A = Aktion (Tastendruck)
B = Bearbeitung (WebUI-Programm)
C = Reaktion (Aktorstatus)

Interessant bei mir... hier gibt es auch eine minimale Verzögerung zwischen Aktion und Bearbeitung. Die soll hier aber nicht Thema sein.

Grüße
Baxxy

[schonwiederich]

@ MichaelN
@ Braxxy
@ Alle

Ich habe nun einige Eurer debugging Ansätze eingebaut:

Hier sieht man nun das alles zeitnah und reibungslos läuft, so wie eigentlich schon immer.

Auch das Programm passt vom Zeitstemepel genau in den Ablauf der Punkte des Systemprotokolls.

Ebenso habe ich nun auch das Programm zur Protokollierung der Häufigkeit von Programtriggern eingebaut.

Die Screenshots zeigen nun erstmal den Zustand wenn alles in Ordnung ist.
Wie sich dies verhält wenn das nächste Mal die Verzögerung eintritt, werde ich dann wieder berichten.
Ob das Triggerhäufigkeitsprogramm hier auffälligkeiten Zeigt werden wir dann sehen.
Für solche Fälle wäre vermutlich ein Programm hilfreich welches nicht (oder neben) der Häufigkeit die Durchlaufzeit darstellt.
Also vom Trigger bis zum Ausführungsende. Damit könnte man ggf auch Problemkandidaten auf die Schliche kommen, aber das liegt jenseitz meiner Kompetenzen.
Danke erstmal bis hierhin an alle.
Ich melde mich auf jeden Fall wenn der Nächste Verzögerungszustand bemerkbar war,

[schonwiederich]

Es ist passiert , zwar nur mit 4 Sekunden Verzug aber passiert.
Systemprotokoll: Was ich erkennen konte habe ich orange gefärbt und kommentiert.

Was sich daraus ableiten lässt.
Anscheinend bekommt das Programm zum selben Moment den Zeitstempel zu dem der Taster gedrückt wird.
Aber Schaltaktion und Protokollvariable werden 4 Sekunden später erst ausgeführt.
Es scheint also als wird das Programm korrekt getriggert, aber die Umsetzung geschieht dann erst verzögert.


Hier das Logfile, ich finde zwar manche dinge wieder aber ich find emich darin nicht zurecht und könnte es auch nicht "bewerten".

homematic-ccu3-2021-09-16.log

(827.07 KiB) 20-mal heruntergeladen

Historian zeigt nichts Anderes.

Könnt ihr in Summe auf etwas schließen, oder gibt jemandem der das Log File "lesen" kann, dieses etwas mehr Aufschluss?

Danke !

[MichaelN]

Irgendwas, was die CCU kurzfristig beschäftigt?

Ich zitiere mich mal selbst...

Was ist das da um 22:06:10?

[Baxxy]

Was ist das da um 22:06:10?

OpenWeather - Datenabruf? Gut möglich das die ReGa da mit parsen beschäftigt war.

[shartelt]

ähnliches Verhalten hatte erst kürzlich einer, der Programme mit Scripten laufen lies, die dann die komplette REGA blockiert haben und dadurch in einem ganz anderen Programm zu Verzögerungen führte.

ich liebe es, wenn ein Plan funktioniert.

[schonwiederich]

Hallo ihr 3,
Da ihr mir so fleißig helft, traue ich mich kaum zu wiedersprechen.
Ja, da läuft eine owm Abfrage, aber die kann es nicht sein.
1 läuft die Seite Jahren
2 laufen mehrere
Jede Stunde
Alle drei Stunden
Etc.
3 wäre es die owm Abfrage, wäre der schaltbefehl dennoch schon vor :10 ausgeführt worden.
4 jetzt waren es 4 Sekunden. Es waren auch schon mal 10 Minuten. Wenn owm andauernd die ccu mit parsen blockiert würde ich auch andere Verzögerungen feststellen.
5 würde owm ins Leere laufen würden die Variablen sich nicht aktualisieren.
6 die owm Programme haben schon auf der ccu 2 sauber funktioniert, auf dem raspberry 3b bisher auch immer.

Ich vermute also eher nicht die owm Programme.
Sollte aus dem Log niemand was anderes herauslesen werde ich bald dennoch die owms mal deaktiviert und dann abwarten.

Ich kann nicht erkennen was die ccu blockiert was nicht schon seit Jahren läuft
Im log laufen eine Menge Dinge zwischen klick und schaltbefehl aber die kann ich leider nicht "lesen"


Danke euch.

[shartelt]

was ist denn, wenn die openweather api nun wesentlich langsamer ist oder sonstiges?

mach’s doch einfach mal aus und teste

[Xel66]

... Ja, da läuft eine owm Abfrage, aber die kann es nicht sein.
1 läuft die Seite Jahren

Wie ich weiter vorn im Thread schon hingewiesen habe, war es bei einem ähnlich gelagerten Problem auch eine externe Abfrage, die zu Verzögerungen geführt hat. Auch wenn Du meinst, dass es nicht sein kann. Die Firmware der CCU ist nicht für die externe Kommunikation geeignet, auch wenn viele behaupten, dass es ja bei ihnen funktioniert. Sie bekommen es nur nicht mit.

Es gibt nur eine einzige Scriptengine. Ist diese durch ein laufendes Script blockiert, dann geht nichts mehr. Auch keine Programme. Du bis nicht der Erste, der genau auf solche Probleme stößt. Du fragst einen externen Dienst ab. Wie schnell und er Dir überhaupt antwortet, unterliegt nicht Deinem Einfluss. Und ob sich etwas beim Diensteanbieter geändert hat, unterliegt ebenfalls nicht Deiner Kontrolle. Da das Script mit den Antworten des Servers arbeiten (parsen) muss, wartet es auch logischerweise die Anworten ab. Und das bringt Deine Verzögerungen. Wenn Du shartelts Vorschlag folgst und das abschaltest, wirst Du ja merken, ob das die Ursache ist.

Gruß Xel66

[schonwiederich]

Hallo zusammen,

ich war eine Zeit lang ausgefallen. Jetzt bin ich wieder fit.
Gestern Abend habe ich dann den Vorschlag durchgeführt die OWM Programme (die die Wetterdaten von OWM regelmäßig holen) zu deaktivieren.
Ich will nicht zu voreilig sein, aber es scheint wie ich es vermutet hatte, diese waren und sind es nicht, denn heute früh um 06:555 habe ich das Problem wieder festgestellt.

Ich habe beim deaktivieren der OWM Programme auch die Variabel nochmal resettet welche die ausgeführten Programme mitschreibt.
Diese sind seit gestern neu mitgeschrieben worden:

Taster gedrückt:

tastendrt.JPG (13.05 KiB) 347 mal betrachtet

Programm ausgeführt:

Wieder ein schnönes Beispiel das die CCU Minutenlang "geblockt" war bevor das Programm zur Ausführung gekommen ist.
Hier noch das Log File

homematic-ccu3-2021-10-07.log

(7.83 MiB) 21-mal heruntergeladen

Historian zeigt auch nichts auffälliges:

Kennt jemand zufällig ein Programm mit dem man die Skript Engine Auslastung mitschreiben kann, bzw welche Programme sich aktuell in Bearbeitung / Warteschleife befinden?

Auch wenn ich leider nun mit den OWM Programmen kein Glück hatte bin ich dankbar für jeden weiteren Hinweis, oder jemanden der im Log File vielleicht was auffälliges findet was vor 06:57 Uhr angefangen hat und die CCU blockiert.
Denn ehrlich gesagt möchte ich dem Vorschlag IOBROKER bzw. den Homematic Adapter auf IOBROKER abzuschalten als aller letztes folgen.
Denn so lange ich dann teste, funktioniert alles was mit IOB in Verbindung zur CCU läuft dann nicht mehr.
Vor allem die Frage an Euch alle: Würde sich herausstellen, dass IOB dieses Blockieren verursacht, was wäre der Lösungsweg? Es kann ja nicht die Lösung sein, den Adapter dauerhaft zu deaktivieren. Das Problem hätte ich dann nicht als einziger. Hat jemand eine Idee wie ich herausfinden kann ob IOB die Ursache ist, auch ohne den Adapter zu deaktivieren?


Vielen Dank vorab!!!!!!!