HMIPServer exceptions und automatisierte watchdog Neustarts?

[udochrist]

Hi,

Obwohl meine raspmatic seit ewiger zeit immer nur bei upgrades neugestartet wird muss ich in den letzten 4 allerdings 3 mal per shell neu starten aufgrund verschiedener Probleme. vielleicht lässt sich der restart ja automatisieren.
Solange man zu Hause ist und merkt dass Programme oder Automatismen nicht mehr funktionieren ist das weniger das problem. bei Abwesenheit kann das aber schon schlecht sein.

HMIPServer OutOfMemory
Hier wäre eventuell sinnvoll wenn ein watchdog den Prozess / das system neu starten würde. dem systemverhalten nach konnte die raspmatic sich davon nicht erholen. Und ich habe absolut keine Idee was das Thema getriggered hat.

2023-02-09 06:13:36,631 io.vertx.core.impl.ContextImpl ERROR [nr_D24DjW_HmIP-RF_WorkerPool-0] Unhandled exception
java.lang.OutOfMemoryError: Java heap space
        at com.sun.org.apache.xerces.internal.util.XMLStringBuffer.<init>(XMLStringBuffer.java:69) ~[?:1.8.0_345]
        at com.sun.xml.internal.stream.writers.XMLWriter.<init>(XMLWriter.java:55) ~[?:1.8.0_345]
        at com.sun.xml.internal.stream.writers.XMLWriter.<init>(XMLWriter.java:63) ~[?:1.8.0_345]
        at com.sun.xml.internal.stream.writers.XMLStreamWriterImpl.setOutputUsingStream(XMLStreamWriterImpl.java:340) ~[?:1.8.0_345]
        at com.sun.xml.internal.stream.writers.XMLStreamWriterImpl.setOutput(XMLStreamWriterImpl.java:299) ~[?:1.8.0_345]
        at com.sun.xml.internal.stream.writers.XMLStreamWriterImpl.<init>(XMLStreamWriterImpl.java:222) ~[?:1.8.0_345]
        at com.sun.xml.internal.stream.XMLOutputFactoryImpl.createXMLStreamWriter(XMLOutputFactoryImpl.java:187) ~[?:1.8.0_345]
        at com.sun.xml.internal.stream.XMLOutputFactoryImpl.createXMLStreamWriter(XMLOutputFactoryImpl.java:123) ~[?:1.8.0_345]
        at de.eq3.cbcs.legacy.communication.rpc.internal.format.xml.XmlRpcSerializer.<init>(XmlRpcSerializer.java:42) ~[HMIPServer.jar:?]
        at de.eq3.cbcs.legacy.communication.rpc.internal.format.xml.XmlRequestResponseProcessor.serializeRequest(XmlRequestResponseProcessor.java:104) ~[HMIPServer.jar:?]
        at de.eq3.cbcs.legacy.communication.rpc.internal.transport.http.HttpTransport.sendRequest(HttpTransport.java:103) ~[HMIPServer.jar:?]
        at de.eq3.cbcs.legacy.communication.rpc.internal.rpc.RpcClient.sendRequest(RpcClient.java:94) ~[HMIPServer.jar:?]
        at de.eq3.cbcs.legacy.communication.rpc.internal.rpc.RpcClient.invoke(RpcClient.java:82) ~[HMIPServer.jar:?]
        at com.sun.proxy.$Proxy41.multicall(Unknown Source) ~[?:?]
        at de.eq3.cbcs.legacy.bidcos.rpc.internal.LegacyBackendClient.multicall(LegacyBackendClient.java:234) ~[HMIPServer.jar:?]
        at de.eq3.cbcs.legacy.bidcos.rpc.internal.LegacyBackendNotificationHandler.handleReceivedStatusData(LegacyBackendNotificationHandler.java:275) ~[HMIPServer.jar:?]
        at de.eq3.cbcs.legacy.bidcos.rpc.internal.LegacyBackendNotificationHandler.handleBackendNotification(LegacyBackendNotificationHandler.java:162) ~[HMIPServer.jar:?]
        at de.eq3.cbcs.legacy.bidcos.rpc.internal.LegacyBackendNotificationHandler.handle(LegacyBackendNotificationHandler.java:106) ~[HMIPServer.jar:?]
        at de.eq3.cbcs.legacy.bidcos.rpc.internal.LegacyBackendNotificationHandler.handle(LegacyBackendNotificationHandler.java:39) ~[HMIPServer.jar:?]
        at io.vertx.core.impl.AbstractContext.dispatch(AbstractContext.java:100) ~[HMIPServer.jar:?]
        at io.vertx.core.impl.WorkerContext.lambda$emit$0(WorkerContext.java:59) ~[HMIPServer.jar:?]
        at io.vertx.core.impl.WorkerContext$$Lambda$96/1079412410.handle(Unknown Source) ~[?:?]
        at io.vertx.core.impl.WorkerContext.lambda$execute$2(WorkerContext.java:104) ~[HMIPServer.jar:?]
        at io.vertx.core.impl.WorkerContext$$Lambda$97/1375592102.run(Unknown Source) ~[?:?]
        at io.vertx.core.impl.TaskQueue.run(TaskQueue.java:76) ~[HMIPServer.jar:?]
        at io.vertx.core.impl.TaskQueue$$Lambda$36/1132559452.run(Unknown Source) ~[?:?]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) ~[?:1.8.0_345]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) ~[?:1.8.0_345]
        at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[HMIPServer.jar:?]
        at java.lang.Thread.run(Thread.java:750) ~[?:1.8.0_345]
2023-02-09 06:14:01,732 io.vertx.core.impl.ContextImpl ERROR [10790_WorkerPool-1] Unhandled exception
java.lang.OutOfMemoryError: Java heap space

HMIPServer NoSuchPortException
Auch das Thema habe ich bisher noch nicht gesehen. ich vermute aber auch hier wird sich der Prozess nicht automatisch reparieren und ein Neustart wäre vielleicht die beste Wahl.

2023-02-10 05:48:35,911 de.eq3.cbcs.server.local.base.internal.LocalServerAdapterInitialization ERROR [vert.x-eventloop-thread-1] Error 'LOCAL_ADAPTER_NO_SUCH_PORT' while trying to open port '/dev/mmd_hmip':
de.eq3.cbcs.lib.commdevice.CommDeviceException: Exception while trying to open serial port. Check configured port '/dev/mmd_hmip'
        at de.eq3.cbcs.lib.nrjavaserialdevice.SerialCommDevice.open(SerialCommDevice.java:103) ~[HMIPServer.jar:?]
        at de.eq3.cbcs.lib.hmiptrxcommadapter.HomeMaticIPTRXCommAdapter.open(HomeMaticIPTRXCommAdapter.java:894) ~[HMIPServer.jar:?]
        at de.eq3.cbcs.lib.hmiptrxcommadapter.HomeMaticIPTRXCommAdapter.<init>(HomeMaticIPTRXCommAdapter.java:103) ~[HMIPServer.jar:?]
        at de.eq3.cbcs.server.local.base.internal.ShareableHomeMaticIPTRXCommAdapter.<init>(ShareableHomeMaticIPTRXCommAdapter.java:34) ~[HMIPServer.jar:?]
        at de.eq3.cbcs.server.local.base.internal.LocalServerAdapterInitialization.start(LocalServerAdapterInitialization.java:109) ~[HMIPServer.jar:?]
        at io.vertx.core.AbstractVerticle.start(AbstractVerticle.java:106) ~[HMIPServer.jar:?]
        at io.vertx.core.impl.DeploymentManager.lambda$doDeploy$5(DeploymentManager.java:196) ~[HMIPServer.jar:?]
        at io.vertx.core.impl.AbstractContext.dispatch(AbstractContext.java:100) ~[HMIPServer.jar:?]
        at io.vertx.core.impl.AbstractContext.dispatch(AbstractContext.java:63) ~[HMIPServer.jar:?]
        at io.vertx.core.impl.EventLoopContext.lambda$runOnContext$0(EventLoopContext.java:38) ~[HMIPServer.jar:?]
        at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:164) ~[HMIPServer.jar:?]
        at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:469) ~[HMIPServer.jar:?]
        at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:500) ~[HMIPServer.jar:?]
        at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:986) ~[HMIPServer.jar:?]
        at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) ~[HMIPServer.jar:?]
        at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) ~[HMIPServer.jar:?]
        at java.lang.Thread.run(Thread.java:750) ~[?:1.8.0_345]
Caused by: gnu.io.NoSuchPortException
        at gnu.io.CommPortIdentifier.getPortIdentifier(CommPortIdentifier.java:274) ~[HMIPServer.jar:?]
        at de.eq3.cbcs.lib.nrjavaserialdevice.SerialCommDevice.open(SerialCommDevice.java:95) ~[HMIPServer.jar:?]
        ... 16 more

In allen Linux bezogenen Logfiles sind keine hinweise auf irgendwelche Fehler (dmesg, message log). Die beiden Probleme scheine n eher mit der CCU-software als dem Host zusammen zu hängen.

Grüße

EDT: Formatierung

[MichaelN0815]

Das hat eher was damit zu tun, was du mit der CCU anstellst. Skripte, Middleware, Addons?

[udochrist]

Das Ram der Maschine ist ja ok. nur der HMIPServer kommt mit dem der JavaVM zugewiesenen memory nicht aus. Wenn der Watchdog nicht aufs log sieht merkt er das nicht würde ich sagen.

[MichaelN0815]

Bei üblicher Nutzung passiert sowas nicht und ich würde eher versuchen solche Probleme gar nicht erst entstehen zu lassen, als Aufwand in eine Placebo Lösung zu packen. Zeig den Mechanismus, der das Problem verursacht und Jens wird es (wenn möglich) abstellen.

[jens-maus]

Was zeigt denn monit status hmipserver wenn das Problem auftritt? Ist ja nicht so, das es keinen WatchDog gibt der den HMIPServer überwacht. Aber wenn dieser die Probleme in die der HMIPServer dienst wohl reingerannt ist von außen nicht erkennen kann, dann gibt es keine Möglichkeit der Benachrichtung über solche Probleme. Es finden ja schon eine ganze Reihe von Überwachungen der Laufzeit des HMIPServer und den anderen Homematic-kritischen Diensten statt. Aber man kann einfach erfahrungsgemäß nicht 100% der möglichen Probleme abdecken. Und wenn der HMIPServer zwar prinzipiell weiterläuft, vom OS betrachtet aber kein problem hat, aber intern ein OOM meldet sehe ich keine Möglichkeit wie z.B. monit das mitbekommen sollte. Schau dir also im Fall der Fälle mal die Werte mit monit status hmipserver an und wenn es da auffälligkeiten gibt kann man da irgendwelche Schwellen natürlich noch anpassen oder so.

Es bleibt auch trotzdem dabei: Dies ist wohl ein sehr sehr seltenes Problem (du bist der erste seit fast 10 Jahren der mit OOM Meldungen im HMIPServer um die Ecke kommt) und insofern gebe ich @Baxxy13 recht das es besser wäre das Problem am Schopfe zu packen. D.h. den HMIPServer z.B. in den DEBUG modus zu versetzen und wenn das Problem auftaucht rauszubekommen woher das kommt (vmtl. von zu vielen XMLRPC Anfragen/Bombardements) und dann auf der einen seite die Ursache abzustellen und ggf. aber auch das Problem an eQ3 zu melden damit die dort ggf. die OOM Meldung abfangen könne. Wir können hier IMHO recht wenig bis gar nichts machen daran, denn HMIPServer ist closed source....

[jens-maus]

Wenn der Watchdog nicht aufs log sieht merkt er das nicht würde ich sagen.

Genau so ist es. Und der WatchDog kann nicht "aufs Log" schauen, das ist einfach ilosorisch so etwas für einen Fall der 1x in 10 Jahren auftaucht umzusetzen. Schau dir nächstes mal die Daten via monit status hmipserver and und wenn es da ansatzpunkte gibt kann man gerne eine Benachrichtung anhand dieser Daten vornehmen. Ich vermute aber mal das wird auch keinen wirklichen Erfolg bringen und es bleibt dabei das die Ursache beseitigt werden muss/sollte.

[udochrist]

Hallo ,

wenn das problem wieder auftritt sammle ich gerne per Befehl mal Zusatzinformationen. Dumm ist es aber, wenn das Problem dann auftritt wenn man gerade gar keine Zeit hat es zu analysieren und aus dem haus muss, aber die CCU im haus laufen muss oder es nicht mitkriegt weil man nicht zu Hause ist.

Zudem will ich nicht sagen dass meine beiden Problem oft auftreten. Das kann ich nicht beurteilen:
In dem Fall war es so dass die CCU keine WebGUI mehr gezeigt hat nach dem login screen. ggfls machen sich dann viele nicht mehr die Mühe überhaupt per ssh und Logfiles auf der Maschine zu prüfen und booten einfach weil "tot". Ob Leute überhaupt sollte OOMs finden und melden kann ich ebenfalls nicht beurteilen. Eventuell normiert das die Anzahl solcher Fehlermeldungen etwas.

Ich habe ehrlich gesagt keine Ahnung warum direkt so hart über eine einfache Frage/Vorschlag diskutiert wird.

Die beiden genannten Punkte entsprechen eigentlich nichts anderem als dem automatischen Neustart wenn RAM oder CPU überlastet sind.

Zum "Geht nicht mit monit" würde ich sagen:
Ein script mit passendem grep auf die Logfiles das ggfls noch Logfiles , Prozesslisten,... auf einen usb stick sichert ist vermutlich kein Hexenwerk und stellt sicher in solchen Fällen dass die Daten die zur analyse gebraucht werden zur verfügung stehen.
Ich glaube Monit kann per script überwachen und damit getriggered werden...

In dem Sinne:

• wenn der Vorschlag nicht sinnvoll ist habe ich kein Problem damit.

[Baxxy13]

Die beiden Probleme scheine n eher mit der CCU-software als dem Host zusammen zu hängen.

Ja dann sag doch mal was der Host ist.
Raspi / VM / Docker / HA-AddOn?

Ein Neustart des HmIP-Servers im laufenden Betrieb ist eh eine schlechte Idee. Mann muss mindestens danach noch die ReGa neu starten.
Besser ist es die ganze Zentrale neu zu starten und noch besser deinen Problemverursacher zu finden und auszumerzen.

[udochrist]

Die Raspberrymatic läuft auf einem ganz normalen Pi3B. Und zwar seit ca 4 Jahren in derselben Konfiguration was addons oder Zusatzsoftware angeht.
Installiert ist cuxd, mail, hm-tools und redmatic. Redmatic nur um die gerate einfach an HomeKit zu kriegen ohne weitere plugins oder Integrationen oder Logik.

Ich vermute aber dass die Hardware/umgebung für den Post egal ist.
Solche Fehler können vermutlich überall auftreten und mir geht es mehr um "Nutzerfreundlichkeit" als um Fehleranalyse mit dem Post.

Wenn in dem Fall ein Neustart des system das sinnvollste ist und sowieso alle user das tun, dann kann das system das auch selbst tun und den user informieren darüber.
Ich hatte jetzt 3 Tage das Problem und am 4ten nicht mehr. Absolut keine Ahnung was das ausgelöst haben soll und vor allem wie man das rauskriegen kann (aber das ist ein anderes Thema wie gesagt)

[Baxxy13]

Also die Idee, das Monit dem HmIP-Server etwas genauer "auf die Finger schaut" und ggf. bei abnormalem Verhalten Alarm schlägt ist ja erstmal nicht verkehrt.

Das nützt dem User aber nur was wenn er regelmäßig auf die WebUI schaut oder sich per Push / Email informieren lässt.
Einen automatisierten Reboot kann ich aber nicht gutheißen, da man zum einen damit jegliche Möglichkeit der Problemanalyse verliert und das im schlimmsten Fall zu einer Reboot-Schleife führen kann.

Oberstes Ziel bleibt für mich damit weiterhin den Problemverursacher zu finden und zu terminieren.

Und anhand deines Logs (OOM) fällt der Verdacht stark auf RedMatic, denn:
nr_D24DjW_HmIP-RF ist ein Init von NodeRed (RedMatic) am HmIP-Server.

[jens-maus]

Und anhand deines Logs (OOM) fällt der Verdacht stark auf RedMatic, denn:

nr_D24DjW_HmIP-RF ist ein Init von NodeRed (RedMatic) am HmIP-Server.

Den Verdacht hatte ich auch schon.. RedMatic ist auch ein ganz schöner RAM-Esser und kann mitunter auch ziemlichen Load auf den XMLRPC Schnittstellen verursachen. Und leider steigt auch zunehmend meine Sorge das es bald ganz mit RedMatic zu Ende ist weil es einfach schon zu lange unmaintained ist, die Welt (bzw. RaspberryMatic) sich aber weiterentwickelt...

[udochrist]

Also die Idee, das Monit dem HmIP-Server etwas genauer "auf die Finger schaut" und ggf. bei abnormalem Verhalten Alarm schlägt ist ja erstmal nicht verkehrt.
Das nützt dem User aber nur was wenn er regelmäßig auf die WebUI schaut oder sich per Push / Email informieren lässt.

Würde ich nicht 100% so sehen. Hier kommt es auf den Modus an: wie gesagt sollte man sich als Entwickler überlegen welche infos man braucht und diese infos per script automatisch sammeln und auf ein nicht-volatiles Laufwerk (usb oder rw Bereich des filesystems) legen. Es ist allemal besser es wegzukopieren als nach einer Fehlermeldung vom user zu erfahren dass die Dateien/infos weg sind.

Dazu kann man dann sogar einen Menüpunkt in der GUI machen die Dateien zu versenden oder beim Wiederanlauf das Zeugs per mail automatisiert versenden. Es lässt sich sogar ein Ticket in GitHub mit attachment dazu per Programm erstellen wenn man das denn implementieren möchte.

Einen automatisierten Reboot kann ich aber nicht gutheißen, da man zum einen damit jegliche Möglichkeit der Problemanalyse verliert und das im schlimmsten Fall zu einer Reboot-Schleife führen kann.

Ob eine Reboot schleife im sinne des end-user-nutzens besser/schlechter ist als eine nicht funktionierende/rumdümpelnde Maschine ist für mich fraglich.
Ich hatte aber gesagt: ein reboot counter der ebenfalls persistent ist und nicht mehr als 3 automatische reboots zulässt und beim manuellen reboot gelöscht wird kann bei sowas helfen.
Wegen Problemanalyse siehe vorher. Ob alle user während das Problem existiert überhaupt in der lage sind die analyse durchzuführen (know-how, zeit, willen, Internetzugriff für suchen/fragen und warten auf antworten...) ist aus meiner Sicht sowieso die frage...

Oberstes Ziel bleibt für mich damit weiterhin den Problemverursacher zu finden und zu terminieren.

Gerne, aber sorry: Der Verursacher ist im Kontext dieses Postings absolut zweitrangig. es geht mir hier ausschliesslich darum möglichst automatisiert Fehlerursachen abzufangen und zu behandeln. Betrachte das Posting hier bitte nicht als "Fehlermeldung" sonder als Feature-Request.

Wie schon mehrfach gesagt: worst-case ist, dass dieses Problem entsteht, während man nicht zu Hause ist. Aktuell erfolgt nicht mal eine info dazu obwohl die gesamte smart-steuerung den geist aufgibt.

Grüße