Weiterhin regelmäßige Abstürze

blackbasket commented 3 years ago

Please describe your problem Mein Problem, dass die RM alle 7 Tage die Segel streicht, haben wir ja schon mehrfach aus unterschiedlichen Richtungen beleuchtet. Inzwischen habe ich alles neu aufgesetzt und neu angelernt. Das Problem besteht weiterhin. Die Hardware wurde schon kreuzgetauscht. Auf allen vier anderen RMs/CCUs (incl. meiner alten Hardware) kann ich das Problem nicht reproduzieren.

Leider ist der einzige Unterschied, dass auf meiner RM zu Hause HAP läuft und auf den Firmengeräten nicht. Ich hoffe weiterhin, dass HAP "unschuldig" ist, aber ich hänge mal das Log von gestern an. Um 15:18 ist der CPU load von 2% auf 26% angestiegen. Vielleicht kann mir jemand die Zeilen interpretieren. Dann wäre ich schon dankbar ;)

hmserver.txt

What happends Absturz nach ca. 7 Tagen. CPU load auf 26%.

What should be happend weiterlaufen ;)

Steps to reproduce this issue diverses, auch schon alle Programme deaktiviert und mehrere (nicht alle) Geräte abgelernt

thkl commented 3 years ago

hmm im hmserver tauchen ein paar Fehler auf das http Requests auf den RPC Port von HAP nicht möglich sind. Diese gehen aber nicht auf localhost:9875 sondern die eth0 IP der CCU ... ich habe vom Netzwerkrouting auf Linux wenig Ahnung und weiss jetzt nicht ob der Request dann aufwändig durch das ganze Netzwerkinterface geschoben wird oder doch nur die Abkürzung auf local nimmt.

Ich schau mal , das ich die RPC Schnittstellenevents der CCU auf localhost abonniere ..

blackbasket commented 3 years ago

Top :) danke :)

blackbasket commented 3 years ago

Hallo Thomas,

kann ich eigentlich schon was testen? Ich habe gerade gesehen, dass du ein File bearbeitet hast. Diese Nacht war wieder Ende :/

LG

thkl commented 3 years ago

Ich bau nachher mal eine neue Release Version zusammen.

blackbasket commented 3 years ago

Hallo Thomas,

Update ist gestern Nachmittag erfolgt. Zur Info noch ein Zitat aus RM-Issue 1249:

"AFAIR this addon was already responsible for several different things in respect of bringing down a whole CCU. In addition, the your top-lsof logfile you can see that when the issue happend the number of socket file descriptor increases for the HmIPServer as well as for HAP HomeMatic. Thus, disable/uninstall it completely and see if this solves your problems."

Ich werde weiter beobachten ;)

LG, Marcel

thkl commented 3 years ago

👍

thkl commented 3 years ago

Btw ichvhab auf dem Produktivsystem (RM auf einem Pi4) als auch auf dem Test (RM Pi3) keine solchen Probleme.

Naja 0.61 connected auf 127.0.0.1 zu den jeweiligen Interfaces.

blackbasket commented 3 years ago

Hallo Thomas,

wenn ich die veränderte CPU usage richtig deute, wird es in den nächsten Stunden wieder crashen. Soll/kann ich dann das gesamte Syslog von heute ca. 1400 bis zum Crash posten? Oder stehen da private Daten drin, die ich bisher übersehen habe?

LG, Marcel

thkl commented 3 years ago

Das kann ich nicht so genau beurteilen. Seriennummern werden drin sein. Passwörter eher nicht.

blackbasket commented 3 years ago

Also, die RM hat heute um ca 1040 wieder die Segel gestrichen. Ich habe leider die Logs nicht von der RM kopiert. In den Syslogs sehe ich nur, dass in dem Moment, wo der CPU-Kern in Volllast läuft, wieder XmlRpc-Fehler.

Das Syslog kann ich später nachliefern.

Wird eigentlich dein Homebridge-Addon noch supported? Dann würde ich ggf. mal testweise umsteigen. Nach einem halben Jahr nervt es langsam etwas ;) (Bitte nicht falsch verstehen, kein Vorwurf!)

thkl commented 3 years ago

Das Addon selber kommuniziert nicht via XMLRPC mit den Geräten sondern holt die Daten von Rega ab. Die einzige XMLRPC Kommunikation ist, das die Events der Schnittstellen abonniert werden. Es gibt einen Watchdog, der die Schnittstellen, wenn einige Zeit keine Events eintreffen, neu verbindet. Das kann natürlich im Laufe der hohen CPU Last der Fall sein.

Was Du noch mal versuchen könntest ist per cron einfach Nachts den Daemon Restarten. Der Restart Befehl wäre

/etc/config/rc.d/hap-homematic restart

Das sollte auf jeden Fall evtl. Memory Issues beseitigen.

Das Homebridge Plugin habe ich etwas vernachlässigt in letzter Zeit. Es ist aber auf die aktuelle Homebridge Version angepasst.

blackbasket commented 3 years ago

Hallo Thomas,

ich hab den cronjob (hoffentlich) eingerichtet.

Ich habe die /usr/local/crontabs/root bearbeitet und nach einem Neustart sehe ich die Zeile auch, wenn ich crontab -e ausführe.

LG, Marcel

thkl commented 3 years ago

Na schauen wir mal .. Ich bin immer noch nicht überzeugt davon, das hap Schuld ist (es gibt halt nur dieses eine Ticket hier zu diesem Problem). Ich schließe es aber auch nicht grundsätzlich aus.

blackbasket commented 3 years ago

ich verstehe, was du meinst... das wundert mich auch schon die ganze Zeit... klingt auch ähnlich absurd wie seinerzeit #111 ... deshalb auch die Frage bzgl. des homebridge Plugins... Wenn's nächsten Mittwochabend/Donnerstagmorgen wieder kaputt ist, werde ich wohl mal wechseln... dann wissen wir zumindest, ob es vom HAP kommt...

edit: ich habe gerade nochmal in das alte Ticket geschaut... da war der Fehler "Jun 14 08:21:25 org.apache.http.impl.client.DefaultHttpClient INFO [HmIP-RF_java_WorkerPool-1] I/O exception (java.net.SocketException) caught when processing request to {}->http://127.0.0.1:39292: Broken pipe (Write failed)" zumindest auch drin...

kautz0 commented 3 years ago

Hallo zusammen,

ich bin mir nicht sicher, aber ich vermute ich habe das gleiche Problem. Bei mir war das heute Morgen so, dass ich zwar auf die CCU komme aber diese die ganze Zeit hängt bis irgendwann garnichts mehr geht, dann lädt die Weboberfläche halb und passiert lange nichts und nach ca. 5 Minuten ist diese dann geladen jedoch ist alles sehr zäh (ich habe leider kein Übersicht der CPU Auslastung etc.) sobald ich auf F5 drücke muss ich wieder ewig warten bis ich etwas machen kann. Auf die hap-homematic Weboberfläche komme ich komischerweise drauf und dort kann ich normal rumklicken aber nichts neues erstellen z.B. Programm oder Besondere Variable etc..

Ich habe bis jetzt die CCU neu gestartet, dann ging wieder alles.

Ich habe kein RM sondert die "normale" CCU3 im Einsatz.

nach ca. 5 min:

Logs: hap-homematic-log_27_05_21.txt

hmserver.log.txt hmserver.log.1.txt

blackbasket commented 3 years ago

Hallo @xz-wq ,

kann es sein, dass sich die WebUI in dem Moment verabschiedet hat, als du auf "Geräte" geklickt hast? Das ist mir zumindest gestern Mittag aufgefallen. Ich vermute, dass das Verhalten bei "Räumen" etc. vergleichbar sein müsste. In jedem Fall werden dann ja Gerätedaten geladen.

LG, Marcel

kautz0 commented 3 years ago

Hallo @xz-wq ,

kann es sein, dass sich die WebUI in dem Moment verabschiedet hat, als du auf "Geräte" geklickt hast? Das ist mir zumindest gestern Mittag aufgefallen. Ich vermute, dass das Verhalten bei "Räumen" etc. vergleichbar sein müsste. In jedem Fall werden dann ja Gerätedaten geladen.

LG,

Marcel

Hi Marcel,

das Bild mit "Regiert nicht mehr" kam nachdem ich auf Diagramme geklickt habe aber wie du sagst, denke ich das etwas geladen wird.

LG

thkl commented 3 years ago

Die Webseite erneuert beim Öffnen das Gerätecache, das ist richtig. Das ist eine recht große Aufgabe für Rega.

Aber solange die Seite nicht angezeigt wird, wird da nichts gemacht.

Wenn das WebGui der CCU so zäh ist, ist meistens Rega ausgelastet.

blackbasket commented 3 years ago

Die Webseite erneuert beim Öffnen das Gerätecache, das ist richtig. Das ist eine recht große Aufgabe für Rega.

Aber solange die Seite nicht angezeigt wird, wird da nichts gemacht.

Wenn das WebGui der CCU so zäh ist, ist meistens Rega ausgelastet.

ist mir gestern auch das erste Mal - mehr oder weniger bewusst - aufgefallen... ich hatte im PRTG gesehen, dass die CPU seit 2h bei >25% total war... dann habe ich die WebUI geöffnet, weil ich die Büchse neu starten wollte... da ging noch alles... dann wollte ich (dummerweise) doch mal sehen, ob ich noch irgendwas steuern kann... als ich dann auf "Geräte" geklickt habe, musste ich das Ding doch per SSH neu starten... ich war aber auch im Stress und konnte der UI keine Minuten zugucken ;) deshalb hab ich ja auch den log-download vergessen -.-

thkl commented 3 years ago

Ich könnte man testweise die Rega Calls und Antworten vom Debug Log ins Info schieben. Dann wird jeder Request ins normale Log geschrieben. Das wird dann zwar auch voll aber nicht so wie das debug log.

blackbasket commented 3 years ago

Klingt gut für mich... Es gibt nicht zu viele Logs ;) man denke an ProxyLogon :D

thkl commented 3 years ago

Zum Test :

https://raw.githubusercontent.com/thkl/hap-homematic/RegaLog/lib/HomeMaticRegaRequest.js

in /usr/local/addons/hap-homematic/node_modules/hap-homematic/lib tauschen .. dann sollten alle Rega Calls mit Script und Ergebnis ins Log wandern

thkl commented 3 years ago

Beim Start werden eine Menge Requests ausgeführt da noch keine Daten vorhanden sind, da nicht wundern. Ggf könnte ich das zusammenfassen 🤔

blackbasket commented 3 years ago

Hallo Thomas,

ist ausgetauscht und neu gestartet. Danach war die CPU kurz bei >60%, ist dann aber auch wieder auf die gewohnten 2-3% gefallen.

LG, Marcel

thkl commented 3 years ago

Naja die Version loggt ja nur alle Rega Calls. Die Sache mit dem initialen Zusammenfassen teste ich gerade.

blackbasket commented 3 years ago

Mal ein kurzes Update: Die offenen Prozesse/Files mittels lsof nehmen trotz der täglichen Restarts zu.

Nach ca 1200 Zeilen die ersten 1-2 Tage, sind es heute schon wieder ca 2100...

thkl commented 3 years ago

Welche files sind denn offen bzw welche Prozesse hängen ?

Ich schreibe eigentlich nur in die History Files für Eve. Und da sollten bei einem Prozess Ende auch spätestens alle Filehandles geschlossen werden. Wobei hier auch nicht permanent geschrieben wird sondern nur wenn sich eine gewisse Menge an Daten angesammelt hat.

blackbasket commented 3 years ago

Halo Thomas,

anbei mal verschiedene Log-Auszüge. Da fehlt mir leider das Verständnis zu. Dafür bin ich zu sehr Techniker und zu wenig Entwickler ;)

LG, Marcel vor-letztem-crash.txt heute.txt nach-letztem-crash.txt sa-vormittag.txt

thkl commented 3 years ago

Ach Herrjeh.....

Ich habe einen Watchdog, der die Verbindungen zu den Schnittstellen (HmIp BidCos) neu aufbaut, wenn eine gewisse Zeit keine Events kommen. Das könnte ich mal abschaltbar machen.

Aber selbst das sollte nach einem ProzessEnde erledigt sein. Aber wer weiß wie der HMServer drauf reagiert.

thkl commented 3 years ago

ich hab mal den Reconnect Watchdog hier https://github.com/thkl/hap-homematic/blob/RegaLog/lib/HomeMaticRPC.js rausgeschmissen

blackbasket commented 3 years ago

Thx :) ausgetauscht und neu gestartet...

blackbasket commented 3 years ago

Hallo Thomas,

ich möchte den Tag jetzt nicht vor dem Abend bzw. besser 10. Tag loben ;) Aber bisher sieht es seit dem Austausch der RPC.js gut aus.

LG, Marcel

thkl commented 3 years ago

Ok, also was ich bisher gemacht habe: Es gibt einen Watchdog pro Schnittstelle, der regelmässig getriggert wird, wenn ein Event auf der Schnittstelle rein kommt. Wenn in der bisherigen Version 300 Sekunden lang kein Event kommt (im Normalfall ist ein lautes Geschrei aller Geräte auf der Schnittstelle) dann wird die Verbindung zur Schnittstelle beendet (ich melde HAP als Eventempfänger an der Schnittstelle ab) und wieder neu aufgebaut. Das sind diese Einträge aus Deinem Log:

May 11 15:16:44 de.eq3.ccu.virtualdevice.service.internal.rega.VirtualDeviceHandlerRega INFO  [vert.x-eventloop-thread-1] (un)registerCallback on VirtualDeviceHandlerRega called from url: http://192.168.179.25:9875 
May 11 15:16:44 de.eq3.ccu.virtualdevice.service.internal.rega.VirtualDeviceHandlerRega INFO  [vert.x-eventloop-thread-1] Removed InterfaceId: null 
May 11 15:16:45 de.eq3.ccu.virtualdevice.service.internal.rega.VirtualDeviceHandlerRega INFO  [vert.x-eventloop-thread-1] (un)registerCallback on VirtualDeviceHandlerRega called from url: http://192.168.179.25:9875 
May 11 15:16:45 de.eq3.ccu.virtualdevice.service.internal.rega.VirtualDeviceHandlerRega INFO  [vert.x-eventloop-thread-1] Added InterfaceId: HAP_VirtualDevices.

Damit möchte ich sicherstellen, das nicht durch irgend etwas auf Dauer die Verbindung zur Schnittstelle verloren geht. Wenn zb der CCU Watchdog aus irgend einem Grund die Schnittstelle neu startet würde HAP das nicht mitbekommen und damit würde keine Events mehr von Geräten zu HomeKit Änderungen führen.

Dieser Watchdog ist jetzt aus ...

Ich werde mal die Zeit variabel in die Config stellen. So das man vielleicht aller Stunden mal schaut ... oder so ...

blackbasket commented 3 years ago

Die RM läuft das erste Mal seit Dezember 2020 8 volle Tage :)

thkl commented 3 years ago

Erschreckend ist doch aber das eine Nutzung eines offiziellen API Calls den HM Server so aus dem Tritt bringt, das das gesamte System crasht.

Ich baue dann mal eine Option für den Watchdog ein. Zb 0-60 min oder so.

blackbasket commented 3 years ago

Definitiv :/

ich hab grad nur ein Mobile zur Hand... da ist das Code Browsing doof... es wäre ja mal interessant, ob du an dem Watchdog zwischen 09/2020 und 12/2020 geschraubt hast...

thkl commented 3 years ago

Den WD gibt es schon länger. Ich glaube im Dezember habe ich am Reconnect was gemacht. Seit dem ignoriere ich Fehler beim Abmelden. Diese werden aber ins Hap Log geschrieben wenn sie auftreten.

Ggf ist das Problem ja hier. Obwohl in deinem HMServer Log ja keinerlei Errors bei den Calls aufschlagen.

blackbasket commented 3 years ago

Ich kann mich auch nur erinnern, dass die Probleme seit einem Update (HAP & damals CCU) kurz vor Weihnachten bestanden... ich hatte zuvor aber auch mehrere HAP-Updates ausgelassen... das macht es nicht einfacher :/

thkl commented 3 years ago

Die Änderung ist am 28.12. ins Git gegangen. Aber der Release war sicher später.

Davor war wenig was ich auf dieses Problem verorten würde.

Der WD reconnected auch nur wenn 300 sek nix kommt. Ich habe im Produktivsystem hier wenig HmIp aber den Wert hatte ich immer locker gerissen. Irgend ein Ird ändert immer den Helligkeitswert oder irgendwer schickt eine Maintenance Message.

Im HM Netz ist es hier noch lauter, da die Thermostate permanent quatschen.

blackbasket commented 3 years ago

Ok, das ist definitiv zu spät...

thkl commented 3 years ago

Diese beiden Commits machen den Watchdog flexibel und abschaltbar : https://github.com/thkl/hap-homematic/commit/d1d5db11fecd478935ad3506533dab928fec7080 / https://github.com/thkl/hap-homematic/commit/9931037f356a511d66a77c3dcec406f04017bb0c

blackbasket commented 3 years ago

Alles klar :) ich werde erst mal bis 10d warten ;) dann installiere ich das aktuelle RM und tausche die Files aus...

blackbasket commented 3 years ago

So, die Files sind endlich getauscht ;) Ich habe den Watchdog jetzt erst mal deaktiviert...

blackbasket commented 3 years ago

Hallo Thomas,

ich würde vorschlagen, dass du die Watchdog-Option noch unter die Beschreibung zur HomeKit-Kompatibilität verschiebst. Ich hätte dir gerne einen PR erstellt, aber ich bin zu blöd, die korrekte Stelle im Code zu finden.

LG, Marcel

thkl commented 3 years ago

Oh ja natürlich ....

blackbasket commented 3 years ago

Hallo Thomas,

14 Tage sind um und alles läuft stabil :)

Vielen lieben Dank :)

Das Ticket können wir dann wohl schließen...

kautz0 commented 3 years ago

Kommt da dann eine neue Version inkl. der Einstellung per Update?

Von: blackbasket @.> Gesendet: Wednesday, June 9, 2021 9:08:10 PM An: thkl/hap-homematic @.> Cc: Emanuel Kautz @.>; Mention @.> Betreff: Re: [thkl/hap-homematic] Weiterhin regelmäßige Abstürze (#437)

Hallo Thomas,

14 Tage sind um und alles läuft stabil :)

Vielen lieben Dank :)

Das Ticket können wir dann wohl schließen...

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHubhttps://github.com/thkl/hap-homematic/issues/437#issuecomment-858015001, or unsubscribehttps://github.com/notifications/unsubscribe-auth/AOM33PZT4Y53N6MOVIDAYQTTR63ZVANCNFSM44Y4HZNA.

gerd2005 commented 3 years ago

Kommt da dann eine neue Version inkl. der Einstellung per Update? …

Hallo, ja, das würde mich auch interessieren. Ich habe die v0.61 auch erst einmal ausgelassen.

thkl commented 3 years ago

Was denn ? Crasht es wieder ?

blackbasket commented 3 years ago

Sorry, damit hatte ich nicht gerechnet ;)

@xz-wq Ja, beim nächsten Release werden die Files mit drin sein. @gerd2005 Falls du mit der .60 das Problem nicht hast, glaube ich auch nicht, dass du es mit .61 bekommst

Bei mir bestand das Problem seit Dezember... Sollte das Problem bei euch auftreten, könnt ihr einfach die Files aus den Commits austauschen und den Dienst einmal neu starten...

thkl / hap-homematic

Weiterhin regelmäßige Abstürze #437