[GELÖST] RpcIOException: java.net.ConnectException: Connection timed out (Connection timed out)

[Karamike]

Nachdem mein Setup jahrelang klaglos funktioniert hat, tritt seit etwa Ende des letzten Jahres im Zusammenhang mit RPC ein Timeout auf, der meine Zentralen zeitweise lahmlegt.

In meinem Setup ist eine Homematic-Zentrale über RPC mit einer FHEM-Installation verbunden. Die FHEM-Webseiten haben teilweise über eine Minute gebraucht, um sich aufzubauen.

Ein Blick in das FHEM-Log zeigte alle 20 Minuten den folgenden Fehler:

Code: Alles auswählen

2023.01.28 18:24:42 2: HMCCURPCPROC [d_rpc000080BidCos_RF] RPC request error RPC::XML::Client::simple_request: RPC::XML::Client::send_request: HTTP server error: read timeout
2023.01.28 18:42:45 2: HMCCURPCPROC [d_rpc000080BidCos_RF] RPC request error RPC::XML::Client::simple_request: RPC::XML::Client::send_request: HTTP server error: read timeout
2023.01.28 19:01:28 2: HMCCURPCPROC [d_rpc000080BidCos_RF] RPC request error RPC::XML::Client::simple_request: RPC::XML::Client::send_request: HTTP server error: read timeout
2023.01.28 19:20:10 2: HMCCURPCPROC [d_rpc000080BidCos_RF] RPC request error RPC::XML::Client::simple_request: RPC::XML::Client::send_request: HTTP server error: read timeout

FHEM durchsucht in regelmäßigen Abständen die Homematic-Zentrale per RPC nach neuen Geräten.
Augenscheinlich "hängt" FHEM während dieser Timeout auftritt.

Zu etwa der gleichen Zeit fielen mit ähnliche "Hänger" in der WebUI der Homematic-Zentrale selbst auf.

Auf der Suche nach der Ursache sind am auffälligsten die Fehlermeldungen in /var/log/hmserver.log.

Dort treten in etwa dem gleichen Rhythmus die folgenden Fehlermeldungen auf:

Code: Alles auswählen

2023-01-28 17:10:00,551 de.eq3.cbcs.util.EQ3LoggerOutputStream ERROR [vert.x-worker-thread-2] de.eq3.cbcs.legacy.communication.rpc.RpcIOException: java.net.ConnectException: Connection timed out (Connection timed out) 
2023-01-28 17:10:00,564 de.eq3.cbcs.util.EQ3LoggerOutputStream ERROR [vert.x-worker-thread-2] 	at de.eq3.cbcs.legacy.communication.rpc.internal.transport.http.HttpTransport.sendRequest(HttpTransport.java:110) 
...
2023-01-28 17:10:00,570 de.eq3.cbcs.util.EQ3LoggerOutputStream ERROR [vert.x-worker-thread-2] Caused by: java.net.ConnectException: Connection timed out (Connection timed out) 
2023-01-28 17:10:00,570 de.eq3.cbcs.util.EQ3LoggerOutputStream ERROR [vert.x-worker-thread-2] 	at java.net.PlainSocketImpl.socketConnect(Native Method) 
...
2023-01-28 17:10:00,574 de.eq3.cbcs.legacy.bidcos.rpc.internal.InterfaceInitializer ERROR [vert.x-worker-thread-2] IO Exception: Could not add interface: HmIP-RF 
de.eq3.cbcs.legacy.communication.rpc.RpcIOException: java.net.ConnectException: Connection timed out (Connection timed out)
	at de.eq3.cbcs.legacy.communication.rpc.internal.transport.http.HttpTransport.sendRequest(HttpTransport.java:110) ~[HMIPServer.jar:?]
...	

(vollständiges Log im Anhang)

Auch hier ein Timeout. Völlig unerklärlich finde ich die Meldung "Could not add interface: HmIP-RF"

An der Zentrale (Raspberry 3b) hängen über einen HmIP-RFUSB-Stick nur HomematicIP-Funk-Sensoren und Aktoren.
Diese lassen sich - wenn das System gerade nicht hängt - sowohl von der Homematic-Zentrale als auch über FHEM per RPC steuern und auslesen.

Ich habe Folgendes versucht, aber der Fehler bleibt:

• Aus- und Wiedereinschalten

• Firmware auf neue SD-Karte

• Downgrade der RaspberryMatic-Firmware auf eine Version von vor einem Jahr

• Umzug von Raspberry 3b auf Raspberry 4 (mit Systembackup)

Als weitere Software läuft auf der Zentrale nur CUxD.
Die RaspberryMatic-Firmware und CUxD sind auf dem aktuellen Stand.

Hat jemand eine Idee zur Ursache oder wie man den Fehler eingrenzen kann?

[Karamike]

Nachdem mein System jetzt einige Wochen ohne Probleme läuft und ich mir einigermaßen sicher sein kann, den Schuldigen gefunden zu haben, hier die Auflösung für Alle, die sich auch am Kopf gekratzt haben oder künftige Google-Reisende, die die Suchmaschine hierhin verschlagen hat.

Der Schuldige kommt aus einer unerwarteten Richtung und ich muss mir vorwerfen, einen Workaround nicht resetfest gemacht zu haben.

Das Problem war CCU-Historian, der auf einem anderen Gerät lief, und den Raspberry abfragte. Die Problematik hatte ich auch bereits hier im Forum beschrieben.

Hier ein kurze Wiederholung:

Mein CCU-Historian fragt zwei Raspberrymatic-Installationen ab. Eine im normalen LAN, die andere über eine Wireguard-VPN-Verbindung.

Damit hat der (separate) Rechner, auf dem der CCU-Historian läuft, 2 IP-Adressen: die aus dem lokalen Netzwerk und die aus dem VPN-Netzwerk.

Das Problem ist, dass (bis jetzt) in der Konfiguration des CCU-Historian nur eine IP-Adresse angegeben werden kann und diese eine Adresse für ALLE Abfragen verwendet wird.

Diese Abfrage kommt - wegen entsprechend gesetzten Routen - auch an beiden CCUs an.

Die CCU verwendet dann die vom CCU-Historian übermittelte (eine feste) Adresse für ihre Rückantwort.

Für eine der CCUs ist das eine Adresse im lokalen Netzwerk und die Antwort geht prompt zurück.

Die andere CCU kennt diese Rückadresse nicht, da sie in einem völlig anderen Subnetz liegt, und wartet und wartet und wartet... bis dann irgendwann der erlösende Timeout auftritt.

Während des Wartens reagiert die Web-UI nicht und es kommt zu ewigen Verzögerungen bei der Bedienung.

Während dieser Zeit reagiert die CCU aber auch auf andere RPC-Anfragen nicht, z.B. von der im letzten Posting erwähnten FHEM-Installation, sodass auch die FHEM-Installation festhing und ebenfalls auf einen Timeout gewartet hat.

Der Workaround ist ein route-Befehl in der Zentrale, die nicht weiß, wie sie ihre Antwort zurückschicken soll, den ich über die Kommandozeile eingegeben hatte. Nachdem das System lief, hatte ich vergessen, diesen in /usr/local/etc/rc.local zu schreiben.

Und so lief das System monatelang einwandfrei - bis zum nächsten Reset.