Homematic CCU3 wird träge? Ursache: eine Request-Flut und ein volllaufendes Log

Die CCU3 reagiert plötzlich zäh, die WebUI braucht ewig, Programme laufen verzögert. Hardware-Defekt? Zu wenig Leistung? In meinem Fall war es weder noch: Ein externer Client hat die Logik-Engine der CCU mit Anfragen geflutet, und das Webserver-Log hat dabei den Arbeitsspeicher aufgefüllt. In diesem Beitrag zeige ich die Symptome, wie ich die Ursache eingekreist habe und wie man das Problem dauerhaft behebt.

Die Symptome

• WebUI und Dashboards laden sehr langsam oder laufen in Timeouts.
• Schaltbefehle und Programme werden verzögert ausgeführt.
• Die CPU-Last ist trotzdem unauffällig (Load Average unter 1,5), der Prozessor ist überwiegend im Leerlauf.
• Der freie Arbeitsspeicher ist fast aufgebraucht, ohne dass ein einzelner Prozess auffällt.
• Im Kernel-Prozess ksoftirqd sammelt sich auffällig viel CPU-Zeit an. Das deutet auf sehr viele Netzwerkverbindungen hin.

Diagnose Schritt für Schritt

Voraussetzung ist ein SSH-Zugang zur CCU. In der WebUI unter Einstellungen → Systemsteuerung → Sicherheit aktivieren Sie SSH und vergeben ein Root-Passwort.

1. Speicher und Dateisysteme prüfen

uptime
free -m
df -h

Die Auffälligkeit bei mir: /var war zu 100 % voll. /var ist auf der CCU ein tmpfs, liegt also im RAM. Ist es voll, fehlt dem System der Arbeitsspeicher, und Prozesse, die dorthin schreiben, hängen oder scheitern.

2. Den größten Verbraucher finden

du -x -k -d 3 /var | sort -rn | head -15
ls -laS /var/log

Die Ursache war eine einzelne Datei: /var/log/lighttpd-access.log mit rund 500 MB. Eine so große Zugriffsliste entsteht nur, wenn jemand die CCU mit Requests überhäuft.

3. Wer sendet die Requests?

tail -n 20 /var/log/lighttpd-access.log
netstat -tn | awk '{print $6}' | sort | uniq -c

Im Log sah ich Hunderte POST /rega.exe-Zeilen pro Sekunde, immer von derselben IP. Die Datei rega.exe ist die Schnittstelle zur Logik-Engine (ReGa), über die Skripte, Systemvariablen und Programme angesprochen werden. netstat zeigte zusätzlich über 2.500 Verbindungen im Zustand TIME_WAIT. Das ist das typische Bild eines Clients, der in enger Schleife immer neue Verbindungen öffnet.

Bei mir stammte die IP von einem Docker-Host mit mehreren Containern. Auf dem Host lässt sich die Quelle weiter eingrenzen:

# Verbindungen pro Container zur CCU zählen
for c in $(docker ps --format '{{.Names}}'); do
  PID=$(docker inspect -f '{{.State.Pid}}' $c)
  n=$(sudo nsenter -t $PID -n ss -tn | grep -c '<CCU-IP>:')
  echo "$n $c"
done | sort -rn | head

4. Rate und Muster messen

Nachdem der Container feststand, habe ich mit tcpdump neue Verbindungen pro Sekunde gezählt. Das funktioniert auch bei verschlüsselter Verbindung (TLS), denn man braucht nur die Verbindungsaufbauten (SYN-Pakete):

sudo nsenter -t $PID -n timeout 10 \
  tcpdump -n -l -tt 'dst host <CCU-IP> and tcp dst port 48181 and tcp[tcpflags] & tcp-syn != 0'

Ergebnis: rund 27 neue Verbindungen pro Sekunde, in regelmäßigen Dreiergruppen etwa alle 110 ms. Ein so gleichmäßiger Takt deutet nicht auf Nutzerinteraktion hin, sondern auf einen automatisch getakteten Auslöser.

5. Den Auslöser finden

Die CCU-Nodes von Node-RED nutzen rega.exe, um Systemvariablen zu schreiben. Jeder ccu-sysvar-Node, der eine Nachricht erhält, löst damit eine Anfrage aus. Ich habe im Flow zurückverfolgt, welche Quellen Systemvariablen speisen. Der Schuldige war ein modbus-read-Node, der einen Batteriespeicher alle 100 ms abfragte. Das Ergebnis lief ohne Filter in eine Systemvariable. Da sich die Leistung bei jeder Messung leicht ändert, wurde bei jedem Zyklus geschrieben.

Die Behebung

Ursache beseitigen (am Client)

1. Poll-Intervall erhöhen. Für eine Systemvariable genügen meist 5–10 Sekunden statt 100 ms.
2. Filtern, bevor geschrieben wird. In Node-RED hilft ein rbe-Node (Report by Exception) im Modus Deadband, z. B. nur bei Änderungen von mehr als 50 W. Alternativ begrenzt ein delay-Node im Modus Rate Limit die Nachrichten pro Zeit.
3. Flows mit hochfrequenten Quellen grundsätzlich prüfen: Sensoren, MQTT-Topics und Modbus-Reads dürfen schnell sein, aber nicht ungefiltert in Systemvariablen oder Programme der CCU laufen.

Danach sank die Zahl der Verbindungen von etwa 27 auf etwa 1 pro Sekunde, und die CCU war wieder responsiv.

Das Log dauerhaft begrenzen (auf der CCU)

Die CCU rotiert ihre Logs per logrotate nur einmal täglich um 04:00 Uhr. Die Größenbegrenzung size 2M aus /etc/logrotate.d/lighttpd.conf greift deshalb erst zu diesem Zeitpunkt. Bei einer Flut ist der RAM-Speicher schon Stunden vorher voll. Die Lösung: Die Rotation häufiger ausführen.

Die Root-Partition der CCU ist schreibgeschützt, Änderungen in /etc gehen bei Neustarts verloren. Dauerhaft ist nur die Partition /usr/local. Skripte in /usr/local/etc/config/rc.d/ werden beim Booten automatisch gestartet (so arbeiten auch Addons). Ich habe dort ein kleines Skript angelegt:

#!/bin/sh
# /usr/local/etc/config/rc.d/logguard
# Rotiert die lighttpd-Logs minütlich nach der Regel in
# /etc/logrotate.d/lighttpd.conf (size 2M), damit /var (tmpfs)
# nicht vollläuft.
PIDFILE=/var/run/logguard.pid
case "$1" in
  ""|start)
    [ -f $PIDFILE ] && kill -0 $(cat $PIDFILE) 2>/dev/null && exit 0
    ( while true; do
        sleep 60
        /usr/sbin/logrotate /etc/logrotate.conf >/dev/null 2>&1
        # Syslog-Datei hart begrenzen (10 MB)
        [ "$(stat -c %s /var/log/messages 2>/dev/null || echo 0)" -gt 10485760 ] && : > /var/log/messages
      done ) >/dev/null 2>&1 &
    echo $! > $PIDFILE
    ;;
  stop)
    [ -f $PIDFILE ] && kill $(cat $PIDFILE) 2>/dev/null; rm -f $PIDFILE
    ;;
esac
exit 0

Installation:

chmod 755 /usr/local/etc/config/rc.d/logguard
/usr/local/etc/config/rc.d/logguard start

Damit sichert die CCU ihren Speicher selbst ab: Das Access-Log bleibt bei etwa 2 MB, ältere Daten liegen höchstens einmal komprimiert vor. Ich habe den Mechanismus getestet, indem ich das Log künstlich über 2 MB aufgefüllt habe. Innerhalb von einer Minute wurde es rotiert.

Überlebt das ein Firmware-Update?

Ja. Ein Update tauscht nur die Root-Partition, /usr/local bleibt erhalten. Das Skript lief nach dem Upgrade auf Firmware 3.89.11 sofort wieder, die Rotationsregel der Firmware war unverändert. Wichtig ist trotzdem, nach einem Update kurz zu prüfen, ob /etc/logrotate.d/lighttpd.conf noch vorhanden ist. Ändert eine künftige Firmware die Datei oder das Binary, würde das Skript wirkungslos laufen, und die Ausgaben sind auf /dev/null umgeleitet.

Checkliste für den Ernstfall

1. df -h: Ist /var voll?
2. ls -laS /var/log: Welche Datei ist am größten?
3. tail /var/log/lighttpd-access.log: Welche IP und welche URL kommen ständig vor?
4. netstat -tn: Wie viele TIME_WAIT-Verbindungen gibt es?
5. Auf dem Client: Welcher Prozess oder Flow ruft die CCU in enger Schleife auf?
6. Intervall erhöhen, Werte filtern, Log-Rotation häufiger ausführen.

Fazit

Eine träge CCU ist nicht automatisch ein Leistungs- oder Hardwareproblem. Eine ungebremste Automatisierung kann die Logik-Engine mit tausenden Anfragen pro Minute überlasten und ganz nebenbei den Arbeitsspeicher füllen. Das Problem lässt sich mit einfachen Bordmitteln diagnostizieren: df, du, netstat und ein Blick ins Access-Log. Die Behebung hat zwei Teile: die Ursache im Client abstellen und die CCU gegen volllaufende Logs absichern.