und noch ein regelm. "Absturz" einer CCU2

[Pietro]

Hallo Leute,

ich leide seit einigen Wochen ebenfalls an einer Instabilität meiner CCU2.

Zur Vorgeschichte:
Bin an sich schon ein "alter Hase" was homematic betrifft (komme noch aus den fhz-Zeiten) und hatte eigentlich nie massive Stabilitätsprobleme.
Würde meine Installation als "sehr groß" bezeichnen und habe auch jede Menge wired Komponenten und ein Funk-Gateway (eckig) im Einsatz.
Seit ein paar Wochen kommt es "plötzlich" (ok, irgendetwas wird immer geändert ) zu regelm. Neustarts von homeputer cl, die ccu selbst läuft stabil durch.
Nun hatte ich natürlich sofort homeputer in Verdacht und habe mich dort auf die Fehlersuche gemacht - das einzige was hier in den (homeputer-)Logs auftaucht ist lediglich ein Restart der Exec-Engine.

Also habe ich mir einmal die CCU-Seite angesehen und habe entdeckt, dass es immer ca. 30 Sekunden vor dem homeputer-Restart entsprechende Auffälligkeiten im CCU-Log gab, die ich so im Forum noch nicht finden konnte.
Die Restarts finden alle 2-3 Tage statt, ich verwende die aktuellste CCU-Firmenware (2.19), aktuelles CuxD und auch die aktuelle homeputer-Version.
Bin schon mit allen Versionen mehrere Releases zurück gestiegen, leider ohne Erfolg.

Hier der Auszug aus dem CCU-Log kurz bevor es zum Restart von homeputer kommt:

Code: Alles auswählen

Jul 18 11:21:03 homematic-ccu2 user.warn multimac: Bad cast: std::bad_cast
Jul 18 11:24:33 homematic-ccu2 user.warn multimac: Bad cast: std::bad_cast
Jul 18 11:26:02 homematic-ccu2 user.warn multimac: Bad cast: std::bad_cast
Jul 18 12:23:03 homematic-ccu2 user.warn multimac: Coprocessor is busy. Max response retry attempts reached.
Jul 18 13:23:32 homematic-ccu2 user.warn hs485d: XmlRpc transport failed (first try), retrying...
Jul 18 13:23:32 homematic-ccu2 user.err hs485d: XmlRpcClient error calling event({[methodName:"event",params:{"70","JEQ0122797:15","FREQUENCY",1117.000000}]}) on http://127.0.0.1:2110/RPC2:
Jul 18 13:23:32 homematic-ccu2 user.err hs485d: XmlRpc transport error
Jul 18 13:23:32 homematic-ccu2 user.warn hs485d: XmlRpc transport failed (first try), retrying...
Jul 18 13:23:32 homematic-ccu2 user.err hs485d: XmlRpcClient error calling event({[methodName:"event",params:{"70","JEQ0122797:21","VALUE",665.000000}]}) on http://127.0.0.1:2110/RPC2:
Jul 18 13:23:32 homematic-ccu2 user.err hs485d: XmlRpc transport error
Jul 18 13:23:32 homematic-ccu2 user.warn rfd: XmlRpc transport failed (first try), retrying...
Jul 18 13:23:32 homematic-ccu2 user.err rfd: XmlRpcClient error calling event({[methodName:"event",params:{"71","KEQ0971141:2","BOOT",true}],[methodName:"event",params:{"71","KEQ0971141:2","ENERGY_COUNTER",410568.600000}],[methodName:"event",params:{"71","KEQ0971141:2","POWE
Jul 18 13:23:32 homematic-ccu2 user.err rfd: XmlRpc transport error
Jul 18 13:23:33 homematic-ccu2 user.warn hs485d: XmlRpc transport failed (first try), retrying...
Jul 18 13:23:33 homematic-ccu2 user.err hs485d: XmlRpcClient error calling event({[methodName:"event",params:{"70","JEQ0122797:21","VALUE",685.000000}]}) on http://127.0.0.1:2110/RPC2:
Jul 18 13:23:33 homematic-ccu2 user.err hs485d: XmlRpc transport error

So ca. um 13:23:50 kam es dann zu einem Restart von homeputer - das Muster ist immer dasselbe, die Komponenten wo es einen XmlRpc transport error gibt aber immer unterschiedlich.
Meist ist das erste Gerät wo es einen derartigen Fehler gibt wired, manchmal aber auch eine Funkkomponente.

Auf der CCU läuft bis auf CuxD und homeputer nichts, es gibt auf der CCU genau ein Script welches minütlich ausgeführt wird.
Die Restarts sind scheinbar unabhängig von etwaigen Userinteraktionen (Pocketcontrol, etc.) und treten auch dann auf, wenn niemand das System bedient.


Kann irgendjemand etwas mit den obigen Logs etwas anfangen ?

Vielen Dank !

lg Pietro

[Familienvater]

Hi,

ja, die Fehler haben mit HPCL zu tun, habe gerade noch mal nachgeschaut, der Event-Abonnent "70" ist bei mir die ExecEngine beim hs485d (wired) und "71" ist die Exec-Engine beim rfd (HM-Funk).

Ich habe bei meinen unregelmäßigen Abstürzen der EE noch nicht direkt im Syslog der CCU weiter geschaut, aber wenn der Kommunikationsprozess der EE selbst abstürzt oder nicht mit anderen Komponenten der EE komunizieren kann, ist es nach meiner Auffassung verständlich, das die entsprechenden Schnittstellen-Prozesse auf der CCU ihrerseits Fehler verursachen (IIRC verdaut jeder Schnittstellenprozess der CCU bis zu 10 aufeinanderfolgende Fehler eines Abonnenten, dann wird der Abonnent rausgeschmissen und bekommt keine Events mehr).

Warum die EE konkret Probleme bekommt, ist für mich nach wie vor nicht nachvollziehbar, auch wenn es doof klingt, ich mache es an Sonnenwind und gekippten Bits und Bytes fest (auch ich habe mehr oder weniger täglich mit Softwareproblemen zu tun, und das ist die allgemeine Ausrede, wenn ich den Fehler nicht finde bzw. dieser sich mangels Komplexität nicht genau eingrenzen läßt). Grundsätzlich scheint das ganze zu funktionieren, warum/wieso/weshalb da irgendwelche potentiellen Speicherlecks irgendwann zu effektvollen Nebeneffekten führen... Mangels Quellcode der EE werden wir es nie finden, Contronics/RK tut sein bestes, damit die EE stabil ist.

Der Familienvater

[Pietro]

Danke Familienvater !

Du gehst also davon aus, dass die Fehlerlogs in der CCU eine Folge der EE sind und nicht dass die EE aufgrund der CCU abschmiert ?

Hmmm...ich habe nun einmal die Häufigkeit der setccusysvar-Befehle drastisch reduziert, mal sehen ob das etwas bringt...
Auch wenn wir Sonnenwinde und Ähnliches für diese Effekte verantwortlich machen, so finde ich es doch seltsam, dass die EE nun über Jahre rel. stabil lief und nun plötzlich alle 2-3 Tage herumzickt...(ohne dass ich jetzt DIE große Änderung gemacht hätte).


Kannst Du eigentlich etwas mit diesen Meldung anfangen ?

Code: Alles auswählen

Jul 18 11:26:02 homematic-ccu2 user.warn multimac: Bad cast: std::bad_cast
Jul 18 12:23:03 homematic-ccu2 user.warn multimac: Coprocessor is busy. Max response retry attempts reached

Hab ich da einfach nur ein Duty_Cycle-Problem ? (hab dazu nichts im Forum gefunden)

lg Pietro

P.S.: Mal sehen ob das Thema im richtigen Subforum aufgehoben bleibt...

[Familienvater]

Hi,

setccusysvar, und das regelmäßig... Das ist mit 70% die Ursache. Wo die Grenze zu ziehen ist, zwischen geht noch gut, und Oh-Gott, das ist aber zuviel, kann ich nicht sagen. Wann immer ich versucht habe, etwas mit intensiver Nutzung von setccusysvar zu machen, ist mir die EE regelmäßig abgeschmiert (gleiches gilt auch für getsite). Zur Not kann man das Setzen von Systemvariablen per startprogramm in einer Shell per wget/curl machen (unschön, aber gefühlt stabiler).

Es bleibt nur immer die Frage, warum will ich überhaupt aus HPCL eine SV regelmäßig setzen.
Ich lese genau zwei SVs regelmäßig (einmal pro Tag), das sind die boolschen Feiertagsvariablen für heute und morgen, um z.B. die Rolladensteuerung in HPCL damit zu steuern.

Das intensive setzen von SVs habe nur gemacht, um z.B. per HomeStatus-Display von Homeputer Inhalte auf einem Tablet anzuzeigen (und wegen stabilitätsproblemen landet das regelmäßig wieder in der digitalen Versenkung).

Der Familienvater

[Tobias78]

Hallo Familienvater,
Homestatus lässt sich komplett ohne setccusysvar steuern. Die Variablen müssen nur angelegt und leer sein, dann kann per http Befehl direkt gesteuert werden. Dieser Weg bring die Latenz auf ~1s und macht wesentlich mehr Spaß bzw ist selbst mit 3x6(x4) Matrix dauerhaft stabil.
Gruß,
Tobias.

[Familienvater]

Hi,

inzwischen ist das möglich ja. Als ich damals angefangen hatte, damit zu testen, war es noch nicht möglich. Und mein "Framework" dafür beruht noch auf der Nutzung von Systemvariablen.
Aber trotzdem danke für den Hinweis, vielleicht probiere ich das direkte Setzen auf dem Tablet mal als 5. Variante.

Der Familienvater

[Pietro]

setccusysvar, und das regelmäßig... Das ist mit 70% die Ursache.
Der Familienvater

Da bin ich mir noch nicht sicher.
Nachdem ich gestern massiv setccuvar-Befehler ausgebaut habe und einiges an Logik nun zusätzlich in CCU-Scripte verlagert habe (was ich immer vermeiden wollte), stützt nun EE noch häufiger ab (in der Nacht zwei mal).
Es sieht fast so aus, dass das ganze um so instabiler wird, je mehr auf der CCU-Schicht läuft - hatte auch ähnliche Erfahrungen wie ich einmal testweise die Duty-Cylce-Scripts laufen ließ.
Sehr seltsam....

Zur Not kann man das Setzen von Systemvariablen per startprogramm in einer Shell per wget/curl machen (unschön, aber gefühlt stabiler).
Der Familienvater

Das Theater habe ich schon in ähnlicher Form hinter mir, nachdem ich alle getccuvar-Befehler ausgebaut habe..naja, ziemlich umständlich...

Es bleibt nur immer die Frage, warum will ich überhaupt aus HPCL eine SV regelmäßig setzen.
Ich lese genau zwei SVs regelmäßig (einmal pro Tag), das sind die boolschen Feiertagsvariablen für heute und morgen, um z.B. die Rolladensteuerung in HPCL damit zu steuern.
Der Familienvater

Das ist leicht erklärt - ich errechne mir etliche Variablen in HPCL (Stromverbrauch mit S0-Zähler, Helligkeitssensor, etc.) die ich aber auch in z.B. PocketControl oder Graphite (für alle meine Auswertungen) zur Verfügung haben möchte.
Seit gestern läuft dies doppelt gemoppelt, indem ich die Berechungen auch parallel in einem Script der CCU ausführe um eben auf setvarccu verzichten zu können.
Wie gesagt, dieses Konstrukt hat über Jahr stabil funktioniert und plötzlich das....

Bin schön langsam verzweifelt...

lg Pietro

[Pietro]

Neuer Status:
Mittlerweile bin ich sicher, dass die EE-Restarts eine Folge von Problemen auf dem CCU-Layer sind und nicht umgekehrt.
Nach dem ich einige CCU-Scripts temporär disabled habe, läuft sie bis dato (ca. 2 Tage) durch - zwar noch kein Grund zur Entwarnung, aber ein Konnex lässt sich schon mal ableiten.

Wie oben erwähnt, hat sich die Restart-Frequenz der EE drastisch erhöht nachdem ich gewisse EE-Funktionen (setccusysvar) in hpcl ausgebaut und nativ in Scripts auf der CCU realisiert habe.

Was mir nun auffällt, dass der freie Speicher der CCU stetig schwindet - klar, ein Teil wird gecached, dennoch beunruhigend und ich befürchte, dass dies möglicherweise die indirekte Ursache für die Restarts ist.
Alleine der Java-Prozess krallt sich 200M ! Ist das normal ? (habe keinerlei Diagramme auf der CCU):

Wie sieht das bei Euch aus ?

[Familienvater]

Hi,

ja

Code: Alles auswählen

CPU:  28% usr  14% sys   0% nic  57% idle   0% io   0% irq   0% sirq
Load average: 0.08 0.32 0.52 2/198 1446
  PID  PPID USER     STAT   VSZ %VSZ %CPU COMMAND
 1446  1441 root     R     2380   1%  32% top
  373     1 root     S     203m  81%   5% java -Xmx64m -Dlog4j.configuration=fil
19472 19468 root     S    57804  23%   5% {ExecEngine}
26733     1 root     S    62404  24%   0% /usr/local/homeputer/FHZ2000IF
  368     1 root     S    28464  11%   0% /bin/rfd -f /etc/config/rfd.conf -l 1
  551     1 root     S    28436  11%   0% /bin/ReGaHss -f /etc/rega.conf -l 2
  335   332 root     S    23872   9%   0% /bin/hs485d -l 1 -g -i 0
   94     1 root     S    15568   6%   0% /usr/sbin/crond
19468 19465 root     S    11936   5%   0% /usr/local/homeputer/ctlexen
 1437   286 root     S     6908   3%   0% {sshd} sshd: root@pts/0
  280     1 root     S     5676   2%   0% /usr/sbin/lighttpd -f /etc/lighttpd/li
  353     1 root     S     5412   2%   0% /bin/multimacd -f /etc/config/multimac
  286     1 root     S     4288   2%   0% /usr/sbin/sshd
  554     1 root     S     3968   2%   0% /bin/hss_led
  332     1 root     S     3776   1%   0% /bin/hs485dLoader -l 1 -dw /etc/config
  262     1 root     S     3736   1%   0% /bin/eq3configd
  264     1 root     S     3712   1%   0% /bin/ssdpd
  274     1 root     S     3640   1%   0% ntpclient -h 192.168.1.2 -l
  589     1 root     S     3240   1%   0% /usr/local/addons/cuxd/cuxd
  103     1 root     S     2776   1%   0% /lib/udev/udevd -d

Falls Du eine/mehrere FHZ2000 hast (habe keinen IF-Treiber im Sreenshot gesehen), lohnt es sich nach meiner Erfahrung, den FHZ2000IF öfters mal neu zu starten (habe ich automatisiert alle 8h, alle 24h dürfte auch noch reichen, aber 7 Tage traue ich dem Ding in meiner Umgebung mit 2x FHZ2000 nicht zu).

Die EE wächst mit jedem Tag bei mir, das ist unschön, aber für mich inzwischen normal.

Der Familienvater

[Pietro]

Danke für den Tipp und die Info !

Nein, FHZ-Komponenten hab ich damals beim Umstieg auf homematic alle rausgehaut

Na schauen wir mal weiter, derzeit ist noch ein Script disabled und die EE läuft nun schon sagenhafte 36 Stunden ohne Restart durch

lg Pietro