CCU auf Raspberry hat jede Nacht Verbindungsverlust

[Heuser]

Hallo Community,
ich betreibe seit ein paar Wochen als Ersatz für die CCU2 als Raspberrymatic 2.29.23.20171118 einen Raspberry Pi3, der mit einer IP-Symcon 4.3 (ebenfalls auf Raspberry Pi) zusammen meine Haussteuerung bildet. Nun stelle ich fest, dass die beiden Einheiten untereinander häufig ihre Verbindung verlieren und danach meistens der erneute Verbindungsaufbau abgelehnt wird. Dieser Socket Fehler tritt völlig unvermittelt auf, meistens nachts, und sorgt für eine „kalte Bude“. Nach einem Neustart der Raspberrymatic ist der Spuk dann meistens erstmal wieder für eine Weile vorbei. Mit der "normalen" CCU2 besteht dieses Problem nicht. Ich habe mir als Workarround ein kleines Script erstellt, welches die Verbindung IP-Symcon -> RaspCCU nach Verlust wieder herstellen soll. Leider blockt die RaspCCU in den meisten Fällen den neuen Verbindungsversuch.

Die Logs (verkürzt) zeigen nach dem Auftreten des Verbindungsabruchs folgendes:

Code: Alles auswählen

Dec  8 03:05:53 homematic-raspi local0.err ReGaHss: Error: Postback: max buffer data size reached or data without content-length: -1 postbackSize: 1047041 [httpServer.cpp:1384]
Dec  8 03:05:53 homematic-raspi local0.err ReGaHss: Error: Content-Length or Postback Param size incorrect! contLen=-1 postLen=588 PostParam=&<?xml version="1.0"?>^M <SOAP-ENV:Envelope xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/" SOAP-ENV:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><SOAP-ENV:Body><m:AddPortMapping xmlns:m=""><NewRemoteHost></NewRemoteHost><NewExternalPort>8889</NewExternalPort><NewProtocol>TCP</NewProtocol><NewInternalPort>8889</NewInternalPort><NewInternalClient>192.168.51.5</NewInternalClient><NewEnabled>1</NewEnabled><NewPortMappingDescription>IP-Camera</NewPortMappingDescription><NewLeaseDuration>0</NewLeaseDuration></m:AddPortMapping></SOAP-ENV:Body></SOAP-ENV:Envelope>^M  [httpServer.cpp:1402]
Dec  8 03:26:36 homematic-raspi local0.err ReGaHss: Error: Postback: max buffer data size reached or data without content-length: -1 postbackSize: 1047041 [httpServer.cpp:1384]
Dec  8 03:26:36 homematic-raspi local0.err ReGaHss: Error: Content-Length or Postback Param size incorrect! contLen=-1 postLen=588 PostParam=&<?xml version="1.0"?>^M <SOAP-ENV:Envelope xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/" SOAP-ENV:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><SOAP-ENV:Body><m:AddPortMapping xmlns:m=""><NewRemoteHost></NewRemoteHost><NewExternalPort>8889</NewExternalPort><NewProtocol>TCP</NewProtocol><NewInternalPort>8889</NewInternalPort><NewInternalClient>192.168.51.5</NewInternalClient><NewEnabled>1</NewEnabled><NewPortMappingDescription>IP-Camera</NewPortMappingDescription><NewLeaseDuration>0</NewLeaseDuration></m:AddPortMapping></SOAP-ENV:Body></SOAP-ENV:Envelope>^M  [httpServer.cpp:1402]
Dec  8 03:30:00 homematic-raspi cron.info crond[207]: USER root pid 1706 cmd /bin/SetInterfaceClock 127.0.0.1:2001
Dec  8 03:47:03 homematic-raspi local0.err ReGaHss: Error: Postback: max buffer data size reached or data without content-length: -1 postbackSize: 1047041 [httpServer.cpp:1384]
Dec  8 03:47:03 homematic-raspi local0.err ReGaHss: Error: Content-Length or Postback Param size incorrect! contLen=-1 postLen=588 PostParam=&<?xml version="1.0"?>^M <SOAP-ENV:Envelope xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/" SOAP-ENV:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><SOAP-ENV:Body><m:AddPortMapping xmlns:m=""><NewRemoteHost></NewRemoteHost><NewExternalPort>8889</NewExternalPort><NewProtocol>TCP</NewProtocol><NewInternalPort>8889</NewInternalPort><NewInternalClient>192.168.51.5</NewInternalClient><NewEnabled>1</NewEnabled><NewPortMappingDescription>IP-Camera</NewPortMappingDescription><NewLeaseDuration>0</NewLeaseDuration></m:AddPortMapping></SOAP-ENV:Body></SOAP-ENV:Envelope>^M  [httpServer.cpp:1402]
Dec  8 04:00:00 homematic-raspi cron.info crond[207]: USER root pid 1719 cmd /bin/SetInterfaceClock 127.0.0.1:2001
Dec  8 04:00:00 homematic-raspi cron.info crond[207]: USER root pid 1720 cmd /bin/setHWClock.sh
Dec  8 04:00:00 homematic-raspi cron.info crond[207]: USER root pid 1721 cmd /usr/sbin/logrotate -f /etc/logrotate.conf || logger -p error -t "logrotate" "logrotate aborted with error $?"
Dec  8 04:30:00 homematic-raspi cron.info crond[207]: USER root pid 1749 cmd /bin/SetInterfaceClock 127.0.0.1:2001
Dec  8 04:38:02 homematic-raspi local0.err ReGaHss: Error: Postback: max buffer data size reached or data without content-length: -1 postbackSize: 1047041 [httpServer.cpp:1384]
Dec  8 04:38:02 homematic-raspi local0.err ReGaHss: Error: Content-Length or Postback Param size incorrect! contLen=-1 postLen=588 PostParam=&<?xml version="1.0"?>^M <SOAP-ENV:Envelope xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/" SOAP-ENV:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><SOAP-ENV:Body><m:AddPortMapping xmlns:m=""><NewRemoteHost></NewRemoteHost><NewExternalPort>8889</NewExternalPort><NewProtocol>TCP</NewProtocol><NewInternalPort>8889</NewInternalPort><NewInternalClient>192.168.51.5</NewInternalClient><NewEnabled>1</NewEnabled><NewPortMappingDescription>IP-Camera</NewPortMappingDescription><NewLeaseDuration>0</NewLeaseDuration></m:AddPortMapping></SOAP-ENV:Body></SOAP-ENV:Envelope>^M  [httpServer.cpp:1402]
Dec  8 04:39:11 homematic-raspi local0.err ReGaHss: Error: Postback: max buffer data size reached or data without content-length: -1 postbackSize: 1047041 [httpServer.cpp:1384]
Dec  8 04:39:11 homematic-raspi local0.err ReGaHss: Error: Content-Length or Postback Param size incorrect! contLen=-1 postLen=589 PostParam=&<?xml version="1.0"?>^M <SOAP-ENV:Envelope xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/" SOAP-ENV:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><SOAP-ENV:Body><m:AddPortMapping xmlns:m=""><NewRemoteHost></NewRemoteHost><NewExternalPort>8903</NewExternalPort><NewProtocol>TCP</NewProtocol><NewInternalPort>8903</NewInternalPort><NewInternalClient>192.168.51.20</NewInternalClient><NewEnabled>1</NewEnabled><NewPortMappingDescription>IP-Camera</NewPortMappingDescription><NewLeaseDuration>0</NewLeaseDuration></m:AddPortMapping></SOAP-ENV:Body></SOAP-ENV:Envelope>^M  [httpServer.cpp:1402]
Dec  8 05:00:00 homematic-raspi cron.info crond[207]: USER root pid 1767 cmd /bin/SetInterfaceClock 127.0.0.1:2001
Dec  8 05:00:00 homematic-raspi cron.info crond[207]: USER root pid 1768 cmd /bin/setHWClock.sh
Dec  8 05:30:00 homematic-raspi cron.info crond[207]: USER root pid 1793 cmd /bin/SetInterfaceClock 127.0.0.1:2001
Dec  8 05:39:13 homematic-raspi local0.err ReGaHss: Error: Postback: max buffer data size reached or data without content-length: -1 postbackSize: 1047041 [httpServer.cpp:1384]
Dec  8 05:39:13 homematic-raspi local0.err ReGaHss: Error: Content-Length or Postback Param size incorrect! contLen=-1 postLen=588 PostParam=&<?xml version="1.0"?>^M <SOAP-ENV:Envelope xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/" SOAP-ENV:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><SOAP-ENV:Body><m:AddPortMapping xmlns:m=""><NewRemoteHost></NewRemoteHost><NewExternalPort>8889</NewExternalPort><NewProtocol>TCP</NewProtocol><NewInternalPort>8889</NewInternalPort><NewInternalClient>192.168.51.5</NewInternalClient><NewEnabled>1</NewEnabled><NewPortMappingDescription>IP-Camera</NewPortMappingDescription><NewLeaseDuration>0</NewLeaseDuration></m:AddPortMapping></SOAP-ENV:Body></SOAP-ENV:Envelope>^M  [httpServer.cpp:1402]
Dec  8 05:40:25 homematic-raspi local0.err ReGaHss: Error: Postback: max buffer data size reached or data without content-length: -1 postbackSize: 1047041 [httpServer.cpp:1384]
Dec  8 05:40:25 homematic-raspi local0.err ReGaHss: Error: Content-Length or Postback Param size incorrect! contLen=-1 postLen=589 PostParam=&<?xml version="1.0"?>^M <SOAP-ENV:Envelope xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/" SOAP-ENV:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><SOAP-ENV:Body><m:AddPortMapping xmlns:m=""><NewRemoteHost></NewRemoteHost><NewExternalPort>8903</NewExternalPort><NewProtocol>TCP</NewProtocol><NewInternalPort>8903</NewInternalPort><NewInternalClient>192.168.51.20</NewInternalClient><NewEnabled>1</NewEnabled><NewPortMappingDescription>IP-Camera</NewPortMappingDescription><NewLeaseDuration>0</NewLeaseDuration></m:AddPortMapping></SOAP-ENV:Body></SOAP-ENV:Envelope>^M  [httpServer.cpp:1402]
Dec  8 05:42:11 homematic-raspi local0.err ReGaHss: Error: XmlRpc: Error in XmlRpcClient::writeRequest: write error (error 111). [iseXmlRpc.h:281]
Dec  8 05:42:11 homematic-raspi local0.err ReGaHss: Error: IseXmlRpc::CallXmlrpcMethod: execute failed; method =getDeviceDescription Params = {"JEQ0683126"} result= nil [iseXmlRpc.cpp:2599]
Dec  8 05:42:11 homematic-raspi local0.err ReGaHss: Error: IseXmlRpc::CallGetDeviceDescription: CallXmlrpcMethod failed [iseXmlRpc.cpp:2189]
Dec  8 05:42:11 homematic-raspi local0.err ReGaHss: Error: XmlRpc: Error in XmlRpcClient::writeRequest: write error (error 111). [iseXmlRpc.h:281]
Dec  8 05:42:11 homematic-raspi local0.err ReGaHss: Error: IseXmlRpc::CallXmlrpcMethod: execute failed; method =getDeviceDescription Params = {"KEQ0433627"} result= nil [iseXmlRpc.cpp:2599]
Dec  8 05:42:11 homematic-raspi local0.err ReGaHss: Error: IseXmlRpc::CallGetDeviceDescription: CallXmlrpcMethod failed [iseXmlRpc.cpp:2189]
Dec  8 05:42:11 homematic-raspi local0.err ReGaHss: Error: XmlRpc: Error in XmlRpcClient::writeRequest: write error (error 111). [iseXmlRpc.h:281]
Dec  8 05:42:11 homematic-raspi local0.err ReGaHss: Error: IseXmlRpc::CallXmlrpcMethod: execute failed; method =getDeviceDescription Params = {"EEQ0046215"} result= nil [iseXmlRpc.cpp:2599]
Dec  8 05:42:11 homematic-raspi local0.err ReGaHss: Error: IseXmlRpc::CallGetDeviceDescription: CallXmlrpcMethod failed [iseXmlRpc.cpp:2189]
Dec  8 05:42:11 homematic-raspi local0.err ReGaHss: Error: XmlRpc: Error in XmlRpcClient::writeRequest: write error (error 111). [iseXmlRpc.h:281]
Dec  8 05:42:11 homematic-raspi local0.err ReGaHss: Error: IseXmlRpc::CallXmlrpcMethod: execute failed; method =getDeviceDescription Params = {"NEQ1802540"} result= nil [iseXmlRpc.cpp:2599]
Dec  8 05:42:11 homematic-raspi local0.err ReGaHss: Error: IseXmlRpc::CallGetDeviceDescription: CallXmlrpcMethod failed [iseXmlRpc.cpp:2189]
Dec  8 05:42:11 homematic-raspi local0.err ReGaHss: Error: XmlRpc: Error in XmlRpcClient::writeRequest: write error (error 111). [iseXmlRpc.h:281]
Dec  8 05:42:11 homematic-raspi local0.err ReGaHss: Error: IseXmlRpc::CallXmlrpcMethod: execute failed; method =getDeviceDescription Params = {"JEQ0712010"} result= nil [iseXmlRpc.cpp:2599]
Dec  8 05:42:11 homematic-raspi local0.err ReGaHss: Error: IseXmlRpc::CallGetDeviceDescription: CallXmlrpcMethod failed [iseXmlRpc.cpp:2189]
Dec  8 05:42:11 homematic-raspi local0.err ReGaHss: Error: XmlRpc: Error in XmlRpcClient::writeRequest: write error (error 111). [iseXmlRpc.h:281]
Dec  8 05:42:11 homematic-raspi local0.err ReGaHss: Error: IseXmlRpc::CallXmlrpcMethod: execute failed; method =getDeviceDescription Params = {"JEQ0098982"} result= nil [iseXmlRpc.cpp:2599]
Dec  8 05:42:11 homematic-raspi local0.err ReGaHss: Error: IseXmlRpc::CallGetDeviceDescription: CallXmlrpcMethod failed [iseXmlRpc.cpp:2189]

Hat jemand ähnliche Erfahrungen oder hat einen Lösungsvorschlag?

[anli]

Hallo und herzlich willkommen!

Es sieht so aus, als wird an die RPiMatic ein Request gesendet, den sie nicht versteht und für ungültig hält:

Code: Alles auswählen

Dec 8 03:05:53 homematic-raspi local0.err ReGaHss: Error: Postback: max buffer data size reached or data without content-length: -1 postbackSize: 1047041 [httpServer.cpp:1384]
Dec 8 03:05:53 homematic-raspi local0.err ReGaHss: Error: Content-Length or Postback Param size incorrect! contLen=-1 postLen=588 PostParam=&<?xml version="1.0"?>^M <SOAP-ENV:Envelope xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/" SOAP-ENV:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><SOAP-ENV:Body><m:AddPortMapping xmlns:m=""><NewRemoteHost></NewRemoteHost><NewExternalPort>8889</NewExternalPort><NewProtocol>TCP</NewProtocol><NewInternalPort>8889</NewInternalPort><NewInternalClient>192.168.51.5</NewInternalClient><NewEnabled>1</NewEnabled><NewPortMappingDescription>IP-Camera</NewPortMappingDescription><NewLeaseDuration>0</NewLeaseDuration></m:AddPortMapping></SOAP-ENV:Body></SOAP-ENV:Envelope>^M [httpServer.cpp:1402]

Du musst herausfinden, warum der Request an die RPiMatic gesendet wird und das korrigieren (vermutlich ist die IP-Adresse der RPiMatic an einer falschen Stelle eingetragen). Eine Schnittstelle in der RPiMatic, die diesen UPnP-Request verarbeiten könnte kenne ich nicht.

[jmaus]

Eine Schnittstelle in der RPiMatic, die diesen UPnP-Request verarbeiten könnte kenne ich nicht.

Das sollte bei einer CCU2 nicht anders sein. Auch dort gibt es keine Schnittstelle die diese Art von UPnP-Requests verarbeiten kann. D.h. dort sollte zumindest der gleiche Fehler im Logfile auftreten. Die Frage wäre allerdings natürlich warum das anscheinend zu einem Verbindungsabbruch zu IP-Symcon führt. Aus den Logfiles ist ja nur heraus zu lesen, dass anscheinend an die Rege-Schnittstelle (Port 8181) ein Request gesendet wird der auf der einen Seite kein "Content-Length" header hat und wohl ein UPnP Request ist den die ReGa nicht verarbeiten kann. Warum das dann allerdings zu einem Verbindungsabbruch zu IP-Symcon führen sollte ist mir noch nicht so recht klar. Ich kann mir nur erklären das dieser UPnP Request direkt von IP-Symcon kommt und dadurch das dieser nicht beantwortet wird bricht IP-Symcon dann selbstständig die Verbindung ab.

[Heuser]

Erst einmal danke ich euch. Die Frage ist, warum die "CCU" die Verbindung ablehnt? Der Abbruch ist nicht so schlimm. Dafür habe ich ein Script erstellt. Das die RaspCCU dicht macht, das ist ein Problem.

[jmaus]

Das die RaspCCU dicht macht, das ist ein Problem.

Ich kann mir schwer vorstellen das die RaspCCU wirklich "dicht" macht. Das ganze sollte sich genauso verhalten wie bei einer CCU2. D.h. sie sollte den Request ablehnen/ignorieren und normal weiter machen...

[Heuser]

Das stimmt wohl, das Webfrontend ist erreichbar und auch die Devices werden angesprochen. Lediglich der Zugriff der IP-Symcon wird abgelehnt und erst durch den Neustart der CCU wieder freigegeben.

[jmaus]

Dann hört sich das für mich eher nach einem Problem im IP-Symcon an...

[Gluehwurm]

Wird irgendeine Einstellung falsch sein oder ein Netzwerkfehler, bei mir läuft das problemlos.

Gruß
Bruno

[Heuser]

Ein Netzwerkfehler ist ausgeschlossen. (alles bis ins Detail geprüft)
Die beiden Devices, die sich im Log auffällig verhielten wurden angepasst. (Upnp abgeschaltet)
Ausfälle nach wie vor jede Nacht aus unerklärlichen Gründen.
Jeden Morgen ein Neustart der RaspCCU und erst dann funktioniert die Schnittstelle zur IP Symcon wieder.
Kann ich in der RaspberryMatic einen Befehl zum automatischen Neustart um, sagen wir mal 3 Uhr, einrichten?

[jmaus]

Jeden Morgen ein Neustart der RaspCCU und erst dann funktioniert die Schnittstelle zur IP Symcon wieder.
Kann ich in der RaspberryMatic einen Befehl zum automatischen Neustart um, sagen wir mal 3 Uhr, einrichten?

Hast du denn mal probiert IP Symcon stattdessen neu zu starten um zu sehen ob dann die Probleme auch beseitigt sind? Und klar kannst du einen Befehl eintimen das dein RaspberryMatic jede nacht neu gestartet wird. Du solltest jedoch besser die Ursache finden warum das so ist.

Beschreib doch bitte noch einmal die genaue symptomatik die dann auftritt. Klar, IP Symcon kann RaspberryMatic nicht mehr ansteuern. Aber was geht noch abseits von IP Symcon? Kannst du dich per WebUI noch einloggen, kannst du da manuell schalten? Man müsste wirklich mal rausbekommen was genau denn da bitte hängt da ggf. ja doch irgendwo im HomeMatic system ein problem ist das ich jetzt nicht überblicke...