Zu früh gefreut … die 1. hat etwas gebraucht, ist dann aber mit 10 Transport Errors auch wieder abgesprungen :mad:
Zwar nicht paresy aber ich hab den Fehler nicht im Log 
Das ist interessant … taucht auf beiden CCU2s in „/var/log/messages“ auf und zwar genau zu dem Zeitpunkt wenn sich IPS „registriert“!? 
Im Betrieb kommt die FM jedenfalls nicht in dieser Art.
Ich hatte das bisher ignoriert und kann mich ehrlich gesagt nicht mehr exakt erinnern wann ich die FM das erste Mal gesehen habe. Mindestens aber zurück bis #3209!
Oohhh, ist das peinlich … die Meldung kommt doch. Hab da irgendwas Falsches gesehen. :o
Beim Start und nach „meinem“ ApplyChanges taucht das auf. Vor dem ApplyChanges habe ich einige „normale“ transport error (8-10), jedesmal in Verbindung mit den neuen Geräten (Thermostat, Messstecker, Doppel-Temp.-fühler), dann wirkt mein Skript. Normale transport error auch beim Beenden vom IPS-Dienst.
Die komplette Zeile taucht auch noch in einem anderen Zusammenhang auf, wo ich keine Tätigkeit im IPS feststellen kann.
2014-01-07 09:38:01 user.info rfd: IPS support system.listMethods
2014-01-07 09:38:01 user.info rfd: IPS support system.multicall
2014-01-07 09:38:01 user.info rfd: IPS support event
2014-01-07 09:38:01 user.error rfd: XmlRpc transport error calling listDevices({"IPS"}) on http://xxx.xxx.xxx.xxx:5545/RPC2:
2014-01-07 09:38:01 user.debug rfd: GetAvailableFirmware for HM-RCV-50
2014-01-07 09:38:01 user.debug rfd: GetAvailableFirmware for HM-RC-Key3-B
2014-01-07 09:38:01 user.debug rfd: GetAvailableFirmware for HM-Sec-Key-O
usw. Firmware-Abfrage der Geräte
Mal vorab zur Info
Hier noch was
Meldung IPS
06.01.2014 02:03:27.428 | 23213 | WARNING | HomeMatic Socket | Unsupported methodName newDevices
Meldung CCU2
2014-01-06 02:03:26 user.debug rfd: JEQ008xxxx's type is HM-SCI-3-FM
2014-01-06 02:03:26 user.debug rfd: (KEQ0113xxx) Response status: OK, Data.
2014-01-06 02:03:26 user.debug rfd: (KEQ0113xxx) Response status: OK, Data.
2014-01-06 02:03:26 user.debug rfd: (KEQ0113xxx) Response status: OK, Data.
2014-01-06 02:03:26 user.debug rfd: (KEQ0113xxx) Response status: OK, Data.
2014-01-06 02:03:26 user.debug rfd: (KEQ0113xxx) Response status: OK, Data.
2014-01-06 02:03:26 user.debug rfd: (KEQ0113xxx) Response status: OK, Data.
2014-01-06 02:03:26 user.debug rfd: (KEQ0113xxx) Response status: OK, Data.
2014-01-06 02:03:26 user.debug rfd: (KEQ0113xxx) Response status: OK, Data.
2014-01-06 02:03:26 user.debug rfd: (KEQ0113xxx) Response status: OK.
2014-01-06 02:03:26 user.debug rfd: Device firmware version is 1.0
2014-01-06 02:03:26 user.debug rfd: TX: @1695770044 0x2120C5 -> 0x19F3CB CONFIG_START [KEQ0113xxx]:
CNT=1,RPTEN=1,RPTED=0,BIDI=1,BURST=0,WAKEUP=0,WAKEMEUP=0,BCAST=0,TYPE=0x01
CONFIG_CHANNEL = 0
CONFIG_PEER_ADDRESS = 0x000000
CONFIG_PEER_CHANNEL = 0
CONFIG
2014-01-06 02:03:26 user.debug rfd: (KEQ0113xxx) Response status: Telegram sent, received ACK.
2014-01-06 02:03:26 user.debug rfd: Response accepted: @1695770201 RSSI=-71dB 0x19F3CB -> 0x2120C5 ACK [KEQ0113xxx]:
CNT=1,RPTEN=1,RPTED=0,BIDI=0,BURST=0,WAKEUP=0,WAKEMEUP=0,BCAST=0,TYPE=0x02
2014-01-06 02:03:26 user.debug rfd: TX: @1695770202 0x2120C5 -> 0x19F3CB CONFIG_WRITE_INDEX [KEQ0113xxx]:
CNT=10,RPTEN=1,RPTED=0,BIDI=1,BURST=0,WAKEUP=0,WAKEMEUP=0,BCAST=0,TYPE=0x01
CONFIG_CHANNEL = 0
DATA = 02 01 0A 21 0B 20 0C C5
2014-01-06 02:03:27 user.debug rfd: (KEQ0113xxx) Response status: Telegram sent, received ACK.
2014-01-06 02:03:27 user.debug rfd: Response accepted: @1695770463 RSSI=-72dB 0x19F3CB -> 0x2120C5 ACK [KEQ0113xxx]:
CNT=10,RPTEN=1,RPTED=0,BIDI=0,BURST=0,WAKEUP=0,WAKEMEUP=0,BCAST=0,TYPE=0x02
2014-01-06 02:03:27 user.debug rfd: TX: @1695770465 0x2120C5 -> 0x19F3CB CONFIG_END [KEQ0113xxx]:
CNT=19,RPTEN=1,RPTED=0,BIDI=1,BURST=0,WAKEUP=0,WAKEMEUP=0,BCAST=0,TYPE=0x01
CONFIG_CHANNEL = 0
2014-01-06 02:03:27 user.debug rfd: (KEQ0113xxx) Response status: Telegram sent, received ACK.
2014-01-06 02:03:27 user.debug rfd: Response accepted: @1695770728 RSSI=-72dB 0x19F3CB -> 0x2120C5 ACK [KEQ0113xxx]:
CNT=19,RPTEN=1,RPTED=0,BIDI=0,BURST=0,WAKEUP=0,WAKEMEUP=0,BCAST=0,TYPE=0x02
2014-01-06 02:03:27 user.debug rfd: GetAvailableFirmware for HM-SCI-3-FM
2014-01-06 02:03:27 user.debug rfd: Enforce CYCLIC_INFO_MSG=true
2014-01-06 02:03:27 user.debug rfd: TX: @1695770754 0x2120C5 -> 0x19F3CB CONFIG_PARAM_REQ [KEQ0113xxx]:
CNT=28,RPTEN=1,RPTED=0,BIDI=1,BURST=0,WAKEUP=0,WAKEMEUP=0,BCAST=0,TYPE=0x01
CONFIG_CHANNEL = 0
CONFIG_PEER_ADDRESS = 0x000000
CONFIG_PEER_CHANNEL = 0
C
2014-01-06 02:03:27 user.error rfd: XmlRpcClient error calling newDevices({"IPS",{[ADDRESS:"JEQ008xxxx",CHILDREN:{"JEQ008xxxx:0","JEQ008xxxx:1","JEQ008xxxx:2","JEQ008xxxx:3"},FIRMWARE:"1.0",FLAGS:1,INTERFACE:"KEQ0113xxx",PARAMSETS:{"MASTER"},PARENT:"",RF_ADDRESS:170
2014-01-06 02:03:27 user.error rfd: XmlRpc transport error
2014-01-06 02:03:27 local0.info ReGaHss: Info: XmlRpcMethodNewDevices::execute: New devices={"1007",{[ADDRESS:"JEQ008xxxx",CHILDREN:{"JEQ008xxxx:0","JEQ008xxxx:1","JEQ008xxxx:2","JEQ008xxxx:3"},FIRMWARE:"1.0",FLAGS:1,INTERFACE:"KEQ0113xxx",PARAMSETS:{"MASTER"},PAREN
2014-01-06 02:03:27 local0.info ReGaHss: Info: XmlRpcMethodNewDevices::execute: New devices for interface id="1007" [../Platform/DOM/iseXmlRpc.cpp (894)]
2014-01-06 02:03:27 local0.info ReGaHss: Info: IseXmlRpc::CreateDevices: Device list = {[ADDRESS:"JEQ008xxxx",CHILDREN:{"JEQ008xxxx:0","JEQ008xxxx:1","JEQ008xxxx:2","JEQ008xxxx:3"},FIRMWARE:"1.0",FLAGS:1,INTERFACE:"KEQ0113xxx",PARAMSETS:{"MASTER"},PARENT:"",RF_ADDRE
2014-01-06 02:03:27 local0.info ReGaHss: Info: IseXmlRpc::CreateDevices: address = JEQ008xxxx[../Platform/DOM/iseXmlRpc.cpp (2651)]
2014-01-06 02:03:27 local0.info ReGaHss: Info: IseXmlRpc::FillDeviceData: DeviceDescription = [ADDRESS:"JEQ008xxxx",CHILDREN:{"JEQ008xxxx:0","JEQ008xxxx:1","JEQ008xxxx:2","JEQ008xxxx:3"},FIRMWARE:"1.0",FLAGS:1,INTERFACE:"KEQ0113xxx",PARAMSETS:{"MASTER"},PARENT:"",RF
2014-01-06 02:03:27 local0.info ReGaHss: Info: IseXmlRpc::GetInterfaceByID: interface name= BidCos-RF for ID=1007 [../Platform/DOM/iseXmlRpc.cpp (2571)]
2014-01-06 02:03:27 local0.info ReGaHss: Info: IseXmlRpc::GetInterfaceByID: interface name= BidCos-RF for ID=1007 [../Platform/DOM/iseXmlRpc.cpp (2571)]
Bin darüber gestolpert: Grundlagen: XML-RPC Server
Das erklärt zumindest mal die Funktionsweise von „listDevices“.
Sofern die unter dem Link beschriebene Mechanik zutrifft (wovon ich ausgehe) folgere ich rein logisch, dass IPS die falsche/keine Antwort auf das „listDevices“ der CCU schickt.
Ich glaube ich muss den NPF nochmal anwerfen …
Hast Du Meldungen mit „VM_Update“ im IPS-Log zum Zeitpunkt des transport error? Irgendwas läuft da bei mir auf und erzeugt dann die Fehler.
Nope! Nichts dergleichen.
Habe gerade den Start von IPS nochmals mitgeschnüffelt. Irgend etwas kommt mir da spanisch vor.
Ich poste es gleich mal…
Wie angekündigt…
Die erste Kontaktaufnahme sieht so aus:
[b]IPS sagt:[/b] Bin....8....init............http://192.168.xxx.xxx:5545........IPS
[b]CCU antwortet:[/b] Bin.............
Nach der Registrierung durch IPS auf der CCU kommt erst ein „system.listMethods“:
[b]CCU sagt:[/b] POST /RPC2 HTTP/1.1
User-Agent: XMLRPC++ 0.7
Host: 192.168.xxx.xxx:5545
Content-Type: text/xml
Content-length: 145
<?xml version="1.0"?>
<methodCall><methodName>system.listMethods</methodName><params><param><value>IPS</value></param></params></methodCall>
[b]IPS antwortet:[/b] HTTP/1.1 200 OK
Connection: keep-alive
Content-Type: text/xml
Content-Length: 243
Date: Wed, 08 Jan 2014 21:16:41 GMT
<methodResponse><params><param><value><array><data><value><string>system.listMethods</string></value><value><string>system.multicall</string></value><value><string>event</string></value></data></array></value></param></params></methodResponse>
Danach versucht die CCU ein „listDevices“ …
[b]CCU sagt:[/b] POST /RPC2 HTTP/1.1User-Agent: XMLRPC++ 0.7
Host: 192.168.xxx.xxx:5545
Content-Type: text/xml
Content-length: 138
<?xml version="1.0"?>
<methodCall><methodName>listDevices</methodName><params><param><value>IPS</value></param></params></methodCall>
[b]IPS antwortet:[/b] HTTP/1.1 200 OK
Connection: keep-alive
Content-Type: text/xml
Content-Length: 0
Date: Wed, 08 Jan 2014 21:16:41 GMT
<HTML><BODY><B>200 OK</B></BODY></HTML>
… und bekommt ein „200 OK“ zurück (ich glaube hier geht´s in die Hose). Sollte da nicht sowas wie …
<methodResponse> irgendwas ... irgendwas ... irgendwas </methodResponse>
… kommen?
Ich hätte eigentlich erwartet, dass die Kommunikation so überhaupt nicht richtig zustande kommt, es geht danach aber direkt mit Daten von der CCU weiter … verwirrend …
Schon der Verbindungsaufbau ist komisch.
Warum antwortet IPS mit einem Multicall? Die CCU sendet doch gar keinen ?
Und sollte der Content nicht auch mit <?xml beginnen?
Michael
Ich gehöre hier eigentlich nicht her, arbeite aber grad selbst am gleichen Problem für HCS deswegen mal meine 2-cent:
Jep das stimmt so, da sollte sowas wie das hier stehen:
HTTP/1.1 200 OK
Content-Length: 125
Content-Type: text/xml
Vary: Accept-Charset
Server: Microsoft-IIS/7.5
X-Powered-By: PHP/5.4.3
X-Powered-By: ASP.NET
Date: Thu, 09 Jan 2014 13:27:44 GMT
Connection: close
<?xml version="1.0"?>
<methodResponse>
<params>
<param>
<value><string></string></value>
</param>
</params>
Das keine Devices zurück gegeben werden ist nicht weiter schlimm. Wie schon erwähnt schickt die CCU danach selbst alle Devices, man kann das dann aber auch einfach ignorieren.
Was teilweise auch zu fehler führt:
homematic-ccu2 user.err rfd: XmlRpc fault calling system.listMethods({"3"}) on ...
Diese Fehler kommt zustande, weil system.listMethods eigentlich keinen parameter akzeptiert, die CCU schickt aber die Init-ID mit - warum auch immer.
Warum es zwischen drin bei normalen events dann zu XmlRpc transport error kommt, kann ich auch noch nicht sagen, leider.
Grüße
Daniel
Lasst Euch in Euren Forschungen nicht durch diesen eher banalen Beitrag stören.
Nach gut 3 Tagen Erfahrungen mit dem Auto-Reboot-Script aus #292 zeigt sich, dass man damit erst mal leben kann.
1-2 Hänger der CCU2 am Tag werden zeitnah erkannt und durch CCU2-Reboot alles neu gestartet.
Wer also eine „wartungsfreie“ Zwischenlösung sucht könnte sich mit diesem Script behelfen.
vg Alexander
Mir war doch so als hätte ich da heute morgen schon was gelesen 
http://homematic-forum.de/forum/viewtopic.php?f=26&t=16352
Momentan sieht es bei mir so aus, dass die „transport error“ (TE) im Normalbetrieb nur während des Backups (vielleicht hohe Last, …) kommen. Habe den Prozess mal entzerrt und hatte dadurch nur sieben TE und kein ApplyChanges. Es muss aber irgendwelche Unterschiede in den TE geben, da das System bei mir mal bei 8, mal bei 9, mal bei 10 neu verbindet. Ein anderes Mal haben 11 TE nicht zum Neuverbinden geführt. Ist schon merkwürdig das Ganze.
Danke für die Infos, Daniel! Deine 2 Cent sind herzlich willkommen! 
Verhält es sich mit HCS ähnlich, dass eine offene WebUI die Verbindung stabilisiert?
Die zentrale Instanz, die WebUI und die Daten aus dem rfd durchlaufen, ist ja primär der Lighty auf der CCU (siehe: LINK). Ich habe da auch schon einiges an unterschiedlichen Setups getestet, aber nichts half wirklich oder erzeugte einen ähnlichen Effekt wie die offene WebUI. Man müsste mal herausfinden wo genau da der Zusammenhang ist … aktuell fehlen mir allerdings Ideen für neue Ansätze
Cheers
/Jens
Weiss jetzt woher die „Wunderheilung“ meines System kommt :mad:
Habe einen Syslog-Server angegeben damit die Fehler protokolliert werden. Leider treten dann die TE nicht mehr (bzw. nur noch bei vermuteter Überlastung des IPS-PC) auf. Wenn nicht dauernd gesyslogt (Adress-Zeile in CCU gelöscht) wird kommen die TE wieder.
Heute Nacht kamen dann auch die restlichen drei TE und die Schnittstelle wurde wieder geweckt. :rolleyes:
Gruß
Bruno
Seit der letzten Beta hat mein System auch eine Wunderheilung erfahren. Keine Verzögerungen und kein Verbindungsverlust mehr. Was hat der Paresy denn da feines gemacht.
sorry zman0801 meinte ich
Meine (Sys-)loggen seit Stunde „0“. Welchen Log-Level hast Du denn eingestellt?
Ich habe die 2.5.4 hatte aber die geschilderten Probleme.