Neues Modul HMCCU für Homematic CCU

Begonnen von zap, 19 August 2015, 19:45:30

Vorheriges Thema - Nächstes Thema

AHA1805

Hallo zap,

Danke für die schnelle Antwort.

Gruß Hannes

Gesendet von meinem SM-T715 mit Tapatalk

AHA 1805 RIP 29.08.2016 --> RUHE IN FRIEDEN
In Gedanken Bei dir HANNES
Dein Bruder Gerd (Inputsammler) Vermisst dich Hannes (AHA1805)

zap

#91
Zitat von: mifh am 13 Dezember 2015, 20:52:37
Aber wie kriege ich ein event mit, wenn der Taster ausgelöst wird?

Habe leider keinen Taster, kann es daher nicht testen. RPC Server dürfte beim Schalten einen Event liefern. Die Frage ist, ob es einen Datenpunkt gibt, in dem die CCU den letzten Schaltvorgang speichert. Dann könnte man auch AT nutzen. Die Datenpunkte bekommst Du mit get d_ccu deviceinfo Device-Name/Device-Address

Zitat
Also RPC-Server? Den kriege ich nicht so recht ans Laufen. Wenn ich den anschalte, startet er brav und schreibt ein langweiliges Logfile ohne aufregende Einträge (...) Außerdem scheint er FHEM lahmzulegen. Wenn der RPC-Server läuft, bringt ein

get d_ccu devicelist

den gesamten FHEM-Prozess ohne relevante Einträge im fhem.log ins Nirwana (web-Oberfläche ist tot, kein CPU-Verbrauch). Das File in /tmp enthält nur 1 Byte.

Die Einträge in ccurpcd.log sollten so aussehen, wenn der RPC-Server erfolgreich gestartet wurde:


13.12.2015 19:42:49 Creating file queue
13.12.2015 19:42:49 Initializing RPC server
13.12.2015 19:42:49 callback server created
13.12.2015 19:42:49 Adding callback for events
13.12.2015 19:42:49 Adding callback for new devices
13.12.2015 19:42:49 Adding callback for deleted devices
13.12.2015 19:42:49 Adding callback for modified devices
13.12.2015 19:42:49 Registering callback
13.12.2015 19:45:50 RPC callback with URL http://192.168.1.12:7401/fh initialized
13.12.2015 19:45:50 Entering server loop. Use kill -SIGINT 18261 to terminate program
13.12.2015 19:45:50 ListDevices
13.12.2015 19:45:52 NewDevice: received 176 device specifications
13.12.2015 19:53:29 Received 250 events from CCU since last check


Bitte beachten: zwischen "Registering callback" und "RPC callback with ..." vergehen immer exakt 3 Minuten. Während dieser 3 Minuten sollte man die Finger von der CCU Oberfläche lassen und auch keinen HMCCU Befehl von FHEM aus absetzen. Das geht meistens in die Hose ;-). (die RPC Schnittstelle ist ein "zartes Pflänzchen", das sehr sensibel reagiert). Die letzte Meldung "Received 250 ..." kommt alle 250 events von der CCU um anzuzeigen, dass der RPC-Server noch lebt.

Probiere mal folgendes: Stoppe FHEM. Stoppe den RPC-Server, wenn er noch läuft mit kill -SIGINT Prozess-Id. Warte bis er nicht mehr läuft (kann einige Sekunden dauern). Starte nun FHEM mit rpcserver = off bzw. auskommentiertem Attribut. Starte nun den RPC-Server aus FHEM heraus mit attr d_ccu rpcserver on. Warte 3-4 Minuten. Deine Client-Devices sollten nun aktualisiert werden. Falls nicht, prüfe mal ccurpcd.log, ob alles wie oben gelistet aussieht.

Zitat
Ach ja, alle 10 Minuten beschwert fhem sich über die leere Parameterfile hmvalues.txt

Ich nehme an, Du hast einen AT definiert mit dem Befehl "get d_ccu parfile". Mit einer solchen Parameterdatei kannst Du Batch mäßig eine ganze Liste von Kanälen/Datenpunkten auf einmal abfragen. Der Aufbau der Datei ist im Readme beschrieben. Sieht im Prinzip so aus:

{Channel-Name|Channel-Address}[.Datapoint_Expression] [Substitute_Rule]

Also z.B.

# Hole alle Datenpunkte die TEMP enthalten
LEQ1234567:1.TEMP
# Hole alle Datenpunkte, die mit RSSI beginnen
LEQ1212121:0.^RSSI.*
# Hole den Datenpunkt STATE und ersetze die Werte
LEQ3234355:1.^STATE$ true:on,false:off
# Hole alle Datenpunkte
LEQ3434545:2
usw.

Zitat
Noch eine kleine Beobachtung: ich mache gerne ein tail -f auf eine log-Datei. Mache ich das für ccurpcd.log, merkt fhem wohl, dass da jemand einen Finder auf der Datei hat und meckert:

2015.12.13 19:40:17 1: HMCCU: Externally launched RPC server detected. Kill process manually with command kill -SIGINT 32656


Das interpretierst Du falsch. So eine innovative Prozess-Erkennung per Filehandle würde ich mir zwar zutrauen, aber ganz so fies bin ich dann doch nicht ;-)

Die Fehlermeldung besagt nur, dass Du versucht hast, per attr rpcserver on den RPC-Server zu starten, obwohl noch ein Prozess aktiv ist, dessen PID HMCCU nicht kennt. Gründe dafür können sein, dass zwischenzeitlich FHEM abgeschmiert war und neu gestartet wurde, oder dass HMCCU neu geladen wurde, oder dass der RPC-Server manuell von Linux aus gestartet wurde. Kann auch sein, dass der RPC-Server nicht beendet wird, wenn man FHEM anhält. In diesem Fall sorry, muss ich mal testen.

Noch ein paar allgemeine Anmerkungen:

- get devicelist ist nur erforderlich, wenn das Modul HMCCU per reload neu geladen wird oder sich ein Gerät in der CCU geändert hat. Beim define eines HMCCU Device wird get devicelist automatisch ausgeführt. Die erfolgreiche Ausführung ist am Internal "devcount" im HMCCU Device zu erkennen (>0).

- Das Attribut substitute arbeitet im Zusammenhang mit dem RPC-Server leider nicht korrekt bzw. wird ignoriert. Fix dafür inklusive einer deutlichen funktionalen Erweiterung der Ersetzung von Werten heute oder morgen per Update.
2xCCU3 mit ca. 100 Aktoren, Sensoren
Entwicklung: FHEM auf Proxmox Debian VM
Produktiv inzwischen auf Home Assistant gewechselt.
Maintainer: HMCCU, (Fully, AndroidDB)

mifh

Hallo Zap

Das war ja eine fixe Antwort, danke sehr. Das stellt die meisten Profisupporter doch in den Schatten :)

Die Idee mit dem Datenpunkt probiere ich mal aus. Wäre ja schon etwas unelegant, sich die Werte per AT herzupollen und dann auf Änderung zu vergleichen. Aber wenn es ginge...

Vielen Dank für den Hinweis mit dem parfile. Jetzt habe auch ich verstanden, wozu das da ist :)

Leider kriege ich den RPCserver immer noch nicht ans Laufen. Ich habe das so gemacht, wie von Dir beschrieben: FHEM stoppen, Neustart ohne RPC Server, RPC Server manuell starten, Finger weg von FHEM und CCU.
Ich habe das mal mitprotokolliert:


pi@pi3 /opt/fhem $ ps aux | grep perl
fhem      2454  1.2  5.3  25472 23748 ?        S    19:49   0:11 perl /opt/fhem/fhem.pl /opt/fhem/fhem.cfg
pi        3039  0.0  0.4   4144  1868 pts/0    S+   20:04   0:00 grep --color=auto perl
pi@pi3 /opt/fhem $ ps aux | grep perl
pi        3041  0.0  0.4   4144  1832 pts/0    S+   20:04   0:00 grep --color=auto perl
pi@pi3 /opt/fhem $ /etc/init.d/fhem start
Starting fhem...
Can't open ./log/fhem-2015-12.log: Keine Berechtigung at fhem.pl line 2174.
pi@pi3 /opt/fhem $ !ps
ps aux | grep perl
pi        3048  0.0  0.4   4144  1888 pts/0    S+   20:05   0:00 grep --color=auto perl
pi@pi3 /opt/fhem $ sudo /etc/init.d/fhem start
Starting fhem...
pi@pi3 /opt/fhem $ ps aux | grep perl         
fhem      3052  106  2.4  14520 10864 pts/0    R    20:05   0:03 perl fhem.pl fhem.cfg
pi        3054  0.0  0.3   4144  1772 pts/0    S+   20:05   0:00 grep --color=auto perl
pi@pi3 /opt/fhem $ ps aux | grep perl
fhem      3052 39.1  5.2  27044 23160 pts/0    S    20:05   0:10 perl fhem.pl fhem.cfg
fhem      3059 87.0  3.8  20300 17020 pts/0    R    20:05   0:07 /usr/bin/perl ./FHEM/ccurpcd.pl hm-ccu2 2001 /tmp/ccuqueue ./log/ccurpcd.log
pi        3065  0.0  0.4   4144  1864 pts/0    S+   20:05   0:00 grep --color=auto perl
pi@pi3 /opt/fhem $ date
Mo 14. Dez 20:06:06 CET 2015
pi@pi3 /opt/fhem $ cd log
pi@pi3 /opt/fhem/log $ ls -l
insgesamt 1780
-rw-r--r-- 1 fhem dialout   2085 Dez 14 20:05 ccurpcd.log
-rw-r--r-- 1 fhem dialout   6508 Dez 14 20:04 eventTypes.txt
-rw-r--r-- 1 fhem dialout 183926 Okt 31  2014 fhem-2014-10.log
-rw-r--r-- 1 fhem dialout  68297 Nov 30  2014 fhem-2014-11.log
-rw-r--r-- 1 fhem dialout 464297 Dez 31  2014 fhem-2014-12.log
-rw-r--r-- 1 fhem dialout  46116 Jan 31  2015 fhem-2015-01.log
-rw-r--r-- 1 fhem dialout  28078 Feb 28  2015 fhem-2015-02.log
-rw-r--r-- 1 fhem dialout  78534 Mär 31  2015 fhem-2015-03.log
-rw-r--r-- 1 fhem dialout  69695 Apr 30  2015 fhem-2015-04.log
-rw-r--r-- 1 fhem dialout  28717 Mai 31  2015 fhem-2015-05.log
-rw-r--r-- 1 fhem dialout  50367 Jun 30 22:43 fhem-2015-06.log
-rw-r--r-- 1 fhem dialout  43131 Jul 31 22:43 fhem-2015-07.log
-rw-r--r-- 1 fhem dialout  58450 Aug 31 19:24 fhem-2015-08.log
-rw-r--r-- 1 fhem dialout  39423 Sep 30 22:55 fhem-2015-09.log
-rw-r--r-- 1 fhem dialout   5134 Okt 31 22:43 fhem-2015-10.log
-rw-r--r-- 1 fhem dialout  84598 Nov 30 22:43 fhem-2015-11.log
-rw-r--r-- 1 fhem dialout 462448 Dez 14 20:05 fhem-2015-12.log
-rw-r--r-- 1 fhem dialout   3550 Dez 14 20:04 fhem.save
-rw-r--r-- 1 fhem root       847 Sep  3 05:54 report_snd_jl2.log
pi@pi3 /opt/fhem/log $ cat ccurpcd.log
13.12.2015 16:25:35 Creating file queue
13.12.2015 16:25:35 Initializing RPC server
13.12.2015 16:25:36 callback server created
13.12.2015 16:25:36 Adding callback for events
13.12.2015 16:25:36 Adding callback for new devices
13.12.2015 16:25:36 Adding callback for deleted devices
13.12.2015 16:25:36 Adding callback for modified devices
13.12.2015 16:25:36 Registering callback
13.12.2015 19:41:56 Creating file queue
13.12.2015 19:41:56 Initializing RPC server
13.12.2015 19:41:58 callback server created
13.12.2015 19:41:58 Adding callback for events
13.12.2015 19:41:58 Adding callback for new devices
13.12.2015 19:41:58 Adding callback for deleted devices
13.12.2015 19:41:58 Adding callback for modified devices
13.12.2015 19:41:58 Registering callback
13.12.2015 19:49:39 Creating file queue
13.12.2015 19:49:39 Initializing RPC server
13.12.2015 19:49:40 callback server created
13.12.2015 19:49:40 Adding callback for events
13.12.2015 19:49:40 Adding callback for new devices
13.12.2015 19:49:40 Adding callback for deleted devices
13.12.2015 19:49:40 Adding callback for modified devices
13.12.2015 19:49:40 Registering callback
13.12.2015 20:08:07 Creating file queue
13.12.2015 20:08:07 Initializing RPC server
13.12.2015 20:08:08 callback server created
13.12.2015 20:08:08 Adding callback for events
13.12.2015 20:08:08 Adding callback for new devices
13.12.2015 20:08:08 Adding callback for deleted devices
13.12.2015 20:08:08 Adding callback for modified devices
13.12.2015 20:08:08 Registering callback
14.12.2015 19:32:43 Creating file queue
14.12.2015 19:32:43 Initializing RPC server
14.12.2015 19:32:43 Can't connect to CCU
14.12.2015 19:32:43 Error: Can't initialize RPC server
14.12.2015 20:05:43 Creating file queue
14.12.2015 20:05:43 Initializing RPC server
14.12.2015 20:05:45 callback server created
14.12.2015 20:05:45 Adding callback for events
14.12.2015 20:05:45 Adding callback for new devices
14.12.2015 20:05:45 Adding callback for deleted devices
14.12.2015 20:05:45 Adding callback for modified devices
14.12.2015 20:05:45 Registering callback



Wie Du siehst, kommt der nicht über das hinaus: Kein RPC callback with URL http://192.168.1.12:7401/fh initialized zu sehen.

14.12.2015 20:05:43 Creating file queue
14.12.2015 20:05:43 Initializing RPC server
14.12.2015 20:05:45 callback server created
14.12.2015 20:05:45 Adding callback for events
14.12.2015 20:05:45 Adding callback for new devices
14.12.2015 20:05:45 Adding callback for deleted devices
14.12.2015 20:05:45 Adding callback for modified devices
14.12.2015 20:05:45 Registering callback


Sieht ja so aus, als würde die CCU an dieer Stelle nicht antworten:
$client->send_request ("init",$callbackurl,"CB1");



An der CCU sollte der RPC Dienst laufen. Kann man das irgendwo prüfen? In der Anleitung schlägst Du das vor:

http://hm-ccu2/config/xmlapi/devicelist.cgi?show_internal=1

Das beantwortet die CCU mit einem 404.

Hast Du irgend eine Idee dazu?


Gruß
Michael

zap

Ja, der RPC Server wird tatsächlich nicht richtig initialisiert. Muss ich mir mal anschauen ... wird aber heute nix mehr.

Könnte natürlich sein, dass der RPC Prozess auf der CCU abgeschmiert ist. Werde in der kommenden Version einen Check einbauen.

Die Test-URL hat nichts mit dem RPC Server zu tun. Das ist ein XML-API Aufruf zum Auflisten aller CCU Geräte. Damit das geht, muss das XML-API Addon auf der CCU installiert sein. Das und andere Software gibt es z.B. unter homematic-inside.de

BTW: Beim Runterfahren von fhem wird ein laufender RPC-Server tatsächlich nicht gestoppt. Fixe ich noch, hat aber nichts mit Deinem Problem zu tun.
2xCCU3 mit ca. 100 Aktoren, Sensoren
Entwicklung: FHEM auf Proxmox Debian VM
Produktiv inzwischen auf Home Assistant gewechselt.
Maintainer: HMCCU, (Fully, AndroidDB)

mifh

Kleiner Nachtrag:
Ich habe eben mal die CCU auf Werkseinstellungen zurückgesetzt und jetzt scheitn sich was zu tun:
14.12.2015 20:48:20 Creating file queue
14.12.2015 20:48:20 Initializing RPC server
14.12.2015 20:48:22 callback server created
14.12.2015 20:48:22 Adding callback for events
14.12.2015 20:48:22 Adding callback for new devices
14.12.2015 20:48:22 Adding callback for deleted devices
14.12.2015 20:48:22 Adding callback for modified devices
14.12.2015 20:48:22 Registering callback http://192.168.1.25:7401/fh
14.12.2015 21:13:38 RPC callback with URL http://192.168.1.25:7401/fh initialized
14.12.2015 21:13:38 Entering server loop. Use kill -SIGINT 5167 to terminate program


Ich lerne mal den Taster wieder an und schaue weiter.

Gruß Michael

zap

Du kannst auf der CCU prüfen, ob der RPC Prozess läuft:

ps -ef | grep rfd

Außerdem sollte folgender Befehl die Prozess-ID des RPC Prozesses liefern:

fuser 2001/tcp

Wenn hier keine Zahl ausgegeben wird, läuft kein RPC Prozess. Dann einfach die CCU mal neu starten.

Wie man per SSH auf die CCU Command Line kommt, steht hier:

http://www.homematic-inside.de/tecbase/homematic/generell/item/zugriff-auf-das-dateisystem-der-ccu-2
2xCCU3 mit ca. 100 Aktoren, Sensoren
Entwicklung: FHEM auf Proxmox Debian VM
Produktiv inzwischen auf Home Assistant gewechselt.
Maintainer: HMCCU, (Fully, AndroidDB)

zap

#96
Ich habe gerade eine neue Version der Module sowie des RPC-Servers eingecheckt.

Bugfixes:


  • Beim Update von Readings in Client-Devices durch den RPC-Server wurde das Attribut substitute ignoriert
  • Beim Stoppen von FHEM wurde der RPC-Server nicht beendet

Erweiterungen:

Der RPC-Server prüft nun beim Starten, ob die RPC-Schnittstelle der CCU erreichbar ist. Falls nicht, wird der Start abgebrochen.

Attribut ccureadingfilter: Legt einen regulären Ausdruck für Datenpunkte fest. Nur wenn ein Datenpunkt zu diesem Ausdruck passt, wird er als Reading gespeichert. Dies reduziert die Anzahl der Readings deutlich.

Beispiel: attr my_dev ccureadingfilter (^STATE$|TEMPERATURE)

Attribut stripnumber: Legt fest, in welchem Format Fließkommazahlen als Reading gespeichert werden. 0=Wie von CCU geliefert, 1=Mit maximal einer Null nach dem Komma, 2=Ohne Null nach dem Komma.

Attribut substitute: Hier gibt es die größten Änderungen. Die bisherige Variante hatte den Nachteil, dass die Ersetzungsregeln immer auf alle gelesenen Datenpunkte angewendet wurden. Nun kann man für bestimmte Datenpunkte eigene Regeln angeben. Das Format ist:

subst_rule[;...]
substrule := [datapoint!]regexp1:substtext1[,...]

Beispiel: Für STATE alle logischen Werte durch on/off ersetzen, für LOWBAT alle durch yes/no ersetzen, für alle anderen durch open/closed ersetzen.

attr mydev substitute STATE!(0|false):off,(1|true):on;LOWBAT!(0|false):no,(1|true):yes;(0|false):closed,(1|true):open

Die Angabe von 0/1 neben true/false ist erforderlich, da die get Befehle für logische Werte true/false liefern während der RPC-Server 0/1 liefert.

2xCCU3 mit ca. 100 Aktoren, Sensoren
Entwicklung: FHEM auf Proxmox Debian VM
Produktiv inzwischen auf Home Assistant gewechselt.
Maintainer: HMCCU, (Fully, AndroidDB)

mifh

Hallo Zap,

ich bin mal wieder am probieren.
Kannst Du Dir evtl. die Sache mit der Startprüfung des ccurpcd.pl noch mal anschauen?
Wenn ich ein tail-f auf dem logfile laufen lassen, kann ich den Prozess reproduzierbar nicht anstarten:

015.12.16 21:04:24 1: HMCCU: Stopping RPC server
2015.12.16 21:04:42 1: HMCCU: Externally launched RPC server detected. Kill process manually with command kill -SIGINT 18647
2015.12.16 21:05:00 1: HMCCU: d_ccu Channel name or address invalid
2015.12.16 21:05:00 3: at_ccu: HMCCU: d_ccu Channel name or address invalid
2015.12.16 21:05:33 1: HMCCU: Externally launched RPC server detected. Kill process manually with command kill -SIGINT 18647
^C
pi@pi3 /opt/fhem/log $ ps aux | grep 18647
pi       18647  0.0  0.3   3936  1472 pts/2    S+   21:00   0:00 tail -f ccurpcd.log
pi       18906  0.0  0.4   4144  1856 pts/3    S+   21:06   0:00 grep --color=auto 18647
pi@pi3 /opt/fhem/log $


Die angemeckerte PID ist dabei kein ccurpcd.pl, sondern eben das tail -f.

Gruß
Michael

zap

Mist. An sowas habe ich nicht gedacht. Mein Fehler. Liegt an der Art und Weise, wie ich auf einen laufenden Prozess prüfe.
Wird korrigiert.
2xCCU3 mit ca. 100 Aktoren, Sensoren
Entwicklung: FHEM auf Proxmox Debian VM
Produktiv inzwischen auf Home Assistant gewechselt.
Maintainer: HMCCU, (Fully, AndroidDB)

zap

#99
Neue Versionen von 88_HMCCU.pm, 88_HMCCUDEV.pm, 88_HMCCUCHN.pm und ccurpcd.pl eingecheckt.

Fixes:

  • Fehler bei der Prüfung auf laufenden ccurpcd Prozess behoben

Neue Funktionen:

Erweiterte Formatierung des Internals STATE analog zum Standardattribut 'stateFormat'. Leider unterstützt stateFormat keine Readings mit Doppelpunkt im Namen. Daher gibt es nun für HMCCUDEV und HMCCUCHN das Attribut 'ccustate'. Die Syntax ist identisch zu 'stateFormat', es können jedoch keine Perl-Ausdrücke angegeben werden. Zusätzlich zu 'ccustate' muss noch das Attribut 'stateFormat' auf "{HMCCU_State()}" gesetzt werden. Die Funktion HMCCU_State() wertet 'ccustate' aus und ersetzt Readings durch Werte. Außerdem wird geprüft, ob das Reading 'state' auf 'Error' steht. In diesem Fall wird STATE ebenfalls auf 'Error' gesetzt.

Beispiel:


attr my_dev ccustate T: KLIMA_WOHN:1.TEMPERATURE° H: KLIMA_WOHN:1.HUMIDITY%
attr my_dev stateFormat {HMCCU_State($name)}


Update: Da gerade an anderer Stelle die Diskussion hinsichtlich Sonderzeichen in Readingnames hochkocht, werde ich in der nächsten Version den Doppelpunkt in Readingnames durch ein anderes Zeichen ersetzen.
2xCCU3 mit ca. 100 Aktoren, Sensoren
Entwicklung: FHEM auf Proxmox Debian VM
Produktiv inzwischen auf Home Assistant gewechselt.
Maintainer: HMCCU, (Fully, AndroidDB)

mifh

#100
Diese Kommunkation scheint ja ein ziemlich sensibles Kerlchen zu sein.

der ccurpcd schafft es bei mir immer noch nicht aus der Initialisierung raus. So sieht das Logfile aus:

19.12.2015 16:52:29 Creating file queue
19.12.2015 16:52:29 Initializing RPC server
19.12.2015 16:52:31 callback server created
19.12.2015 16:52:31 Adding callback for events
19.12.2015 16:52:31 Adding callback for new devices
19.12.2015 16:52:31 Adding callback for deleted devices
19.12.2015 16:52:31 Adding callback for modified devices
19.12.2015 16:52:31 Registering callback

Dabei bleibt es dann, bis ich den Prozess mit attr attr d_ccu rpcserver off beende.
Dann (und erst dann) fängt der rfd auf der CCU  in /var/log/messages an zu meckern:

ec 19 16:57:58 homematic-ccu2 user.err rfd: XmlRpc transport error calling system.listMethods({"CB1"}) on http://192.168.1.25:7401/fh:
Dec 19 16:57:58 homematic-ccu2 user.err rfd: XmlRpc transport error calling listDevices({"CB1"}) on http://192.168.1.25:7401/fh:

Da der Logeintrag "RPC callback with URL ..." nicht kommt, scheint der ccurpcd ja in dem $client->send_request ("init",$callbackurl,"CB1"); zu hängen.
Ach ja, die drei Minuten warte ich brav ab und das XML-API Addon habe ich auch installiert.

Bediene ich den Taster, ist die Fehlermeldung im message.log auf der CCU entsprechend länger (wieder erst nach dem Beenden!):

Dec 19 17:17:33 homematic-ccu2 user.err rfd: XmlRpcClient error calling event({[methodName:"event",params:{"CB1","MEQ0399400:1","PRESS_SHORT",true}]}) on http://192.168.1.25:7401/fh:
Dec 19 17:17:33 homematic-ccu2 user.err rfd: XmlRpc transport error
Dec 19 17:17:33 homematic-ccu2 user.err rfd: XmlRpcClient error calling event({[methodName:"event",params:{"CB1","MEQ0399400:1","INSTALL_TEST",true}]}) on http://192.168.1.25:7401/fh:
Dec 19 17:17:33 homematic-ccu2 user.err rfd: XmlRpc transport error




Kleiner Nachtrag: Weil ich langsam das Problem im Umfeld Raspberry/Perl-Libs vermute, habe ich den ccurpcd mal auf meinem ubuntu-Rechner ausgeführt. Außer der xml-rpc lib braucht der Prozess ja nix. Das hat geklappt, nach 3 Minuten ging er in die Bearbeitungsschleife.
Ich habe dann mal auf dem Rapsberry ein apt-get remove librpc-xml-perl; apt-get automrevmoce; apt-get install librpc-xml-perl gemacht und den ccurpcd ebenfalls direkt gestartet. Hat leider nichts geholfen.

zap

#101
Du hast jetzt aber auf dem Raspi nicht noch das Modul HMRPC aktiv, oder? Was liefert der Befehl

netstat -an | grep 7401

Der rfd auf der CCU erreicht den ccurpcd anscheinend nicht, obwohl zu diesem Zeitpunkt der Listener schon auf Port 7401 lauschen sollte und auch der Handler für listdevices regisitriert ist.

Seltsam, dass es auf Ubuntu läuft und auf dem Raspi nicht.

Der Server ist jedenfalls korrekt bei der CCU registriert, sonst würde die nicht versuchen, Events zu schicken. In einem vorherigen Post hatte das doch schon mal funktioniert. Hast Du was geändert?
2xCCU3 mit ca. 100 Aktoren, Sensoren
Entwicklung: FHEM auf Proxmox Debian VM
Produktiv inzwischen auf Home Assistant gewechselt.
Maintainer: HMCCU, (Fully, AndroidDB)

mifh

Danke für den Tipp.

Ich habe keine Ahnung, warum es lt. logfile nach dem Neuaufsetzen der CCU zweimal geklappt hat und nun nicht.
Auf dem Port 7401 lauscht sonst niemand. Meiner Meinung nach müsste dann auch das Anlegen des callbackservers fehlschlagen.
Die CCU hängt durchaus am callbackserver, so interpretiere ich das zumindest (ich habe den ccurpcd.pl in c.pl umbenannt, Deine Prüfung, ob der Prozess schon läuft schlägt z.B. auch zu, wenn man den Prozess mit sudo startet  :D):

pi@pi3 /opt/fhem/tmp/fhem-code/fhem/contrib/HMCCU $ ps aux | grep perl
pi       11017  0.0  0.4   4144  1884 pts/3    S+   11:34   0:00 grep --color=auto perl
pi@pi3 /opt/fhem/tmp/fhem-code/fhem/contrib/HMCCU $
pi@pi3 /opt/fhem/tmp/fhem-code/fhem/contrib/HMCCU $
pi@pi3 /opt/fhem/tmp/fhem-code/fhem/contrib/HMCCU $ !netstat
netstat -an | grep 7401
pi@pi3 /opt/fhem/tmp/fhem-code/fhem/contrib/HMCCU $ sudo perl c.pl hm-ccu2 2001 /tmp/ccuqueue ccurpcd.log &
[1] 11023
pi@pi3 /opt/fhem/tmp/fhem-code/fhem/contrib/HMCCU $
pi@pi3 /opt/fhem/tmp/fhem-code/fhem/contrib/HMCCU $
pi@pi3 /opt/fhem/tmp/fhem-code/fhem/contrib/HMCCU $ netstat -an | grep 7401                               
pi@pi3 /opt/fhem/tmp/fhem-code/fhem/contrib/HMCCU $ netstat -an | grep 7401
pi@pi3 /opt/fhem/tmp/fhem-code/fhem/contrib/HMCCU $ netstat -an | grep 7401
tcp        0      0 0.0.0.0:7401            0.0.0.0:*               LISTEN     
tcp      262      0 192.168.1.25:7401       192.168.1.30:53035      VERBUNDEN 
pi@pi3 /opt/fhem/tmp/fhem-code/fhem/contrib/HMCCU $ ps aux | grep perl                                     
root     11023  0.0  0.5   5140  2620 pts/3    S    11:35   0:00 sudo perl c.pl hm-ccu2 2001 /tmp/ccuqueue ccurpcd.log
root     11024 18.4  3.9  20684 17520 pts/3    S    11:35   0:08 perl c.pl hm-ccu2 2001 /tmp/ccuqueue ccurpcd.log
pi       11044  0.0  0.4   4144  1868 pts/3    S+   11:36   0:00 grep --color=auto perl
pi@pi3 /opt/fhem/tmp/fhem-code/fhem/contrib/HMCCU $ netstat -an | grep 7401
tcp        0      0 0.0.0.0:7401            0.0.0.0:*               LISTEN     
tcp      262      0 192.168.1.25:7401       192.168.1.30:53035      VERBUNDEN 
pi@pi3 /opt/fhem/tmp/fhem-code/fhem/contrib/HMCCU $ netstat -an | grep 7401
tcp        0      0 0.0.0.0:7401            0.0.0.0:*               LISTEN     
tcp      262      0 192.168.1.25:7401       192.168.1.30:53035      VERBUNDEN 
pi@pi3 /opt/fhem/tmp/fhem-code/fhem/contrib/HMCCU $ netstat -an | grep 7401
tcp        0      0 0.0.0.0:7401            0.0.0.0:*               LISTEN     
tcp      262      0 192.168.1.25:7401       192.168.1.30:53035      VERBUNDEN 
pi@pi3 /opt/fhem/tmp/fhem-code/fhem/contrib/HMCCU $ netstat -an | grep 7401
tcp        0      0 0.0.0.0:7401            0.0.0.0:*               LISTEN     
tcp      262      0 192.168.1.25:7401       192.168.1.30:53035      VERBUNDEN 
pi@pi3 /opt/fhem/tmp/fhem-code/fhem/contrib/HMCCU $ cat ccurpcd.log
pi@pi3 /opt/fhem/tmp/fhem-code/fhem/contrib/HMCCU $ ps aux | grep perl
pi       11017  0.0  0.4   4144  1884 pts/3    S+   11:34   0:00 grep --color=auto perl
pi@pi3 /opt/fhem/tmp/fhem-code/fhem/contrib/HMCCU $
pi@pi3 /opt/fhem/tmp/fhem-code/fhem/contrib/HMCCU $
pi@pi3 /opt/fhem/tmp/fhem-code/fhem/contrib/HMCCU $ !netstat
netstat -an | grep 7401
pi@pi3 /opt/fhem/tmp/fhem-code/fhem/contrib/HMCCU $ sudo perl c.pl hm-ccu2 2001 /tmp/ccuqueue ccurpcd.log &
[1] 11023
pi@pi3 /opt/fhem/tmp/fhem-code/fhem/contrib/HMCCU $
pi@pi3 /opt/fhem/tmp/fhem-code/fhem/contrib/HMCCU $
pi@pi3 /opt/fhem/tmp/fhem-code/fhem/contrib/HMCCU $ netstat -an | grep 7401                               
pi@pi3 /opt/fhem/tmp/fhem-code/fhem/contrib/HMCCU $ netstat -an | grep 7401
pi@pi3 /opt/fhem/tmp/fhem-code/fhem/contrib/HMCCU $ netstat -an | grep 7401
tcp        0      0 0.0.0.0:7401            0.0.0.0:*               LISTEN     
tcp      262      0 192.168.1.25:7401       192.168.1.30:53035      VERBUNDEN 
pi@pi3 /opt/fhem/tmp/fhem-code/fhem/contrib/HMCCU $ ps aux | grep perl                                     
root     11023  0.0  0.5   5140  2620 pts/3    S    11:35   0:00 sudo perl c.pl hm-ccu2 2001 /tmp/ccuqueue ccurpcd.log
root     11024 18.4  3.9  20684 17520 pts/3    S    11:35   0:08 perl c.pl hm-ccu2 2001 /tmp/ccuqueue ccurpcd.log
pi       11044  0.0  0.4   4144  1868 pts/3    S+   11:36   0:00 grep --color=auto perl
pi@pi3 /opt/fhem/tmp/fhem-code/fhem/contrib/HMCCU $ netstat -an | grep 7401
tcp        0      0 0.0.0.0:7401            0.0.0.0:*               LISTEN     
tcp      262      0 192.168.1.25:7401       192.168.1.30:53035      VERBUNDEN 
pi@pi3 /opt/fhem/tmp/fhem-code/fhem/contrib/HMCCU $ netstat -an | grep 7401
tcp        0      0 0.0.0.0:7401            0.0.0.0:*               LISTEN     
tcp      262      0 192.168.1.25:7401       192.168.1.30:53035      VERBUNDEN 
pi@pi3 /opt/fhem/tmp/fhem-code/fhem/contrib/HMCCU $ netstat -an | grep 7401
tcp        0      0 0.0.0.0:7401            0.0.0.0:*               LISTEN     
tcp      262      0 192.168.1.25:7401       192.168.1.30:53035      VERBUNDEN 
pi@pi3 /opt/fhem/tmp/fhem-code/fhem/contrib/HMCCU $ netstat -an | grep 7401
tcp        0      0 0.0.0.0:7401            0.0.0.0:*               LISTEN     
tcp      262      0 192.168.1.25:7401       192.168.1.30:53035      VERBUNDEN 
pi@pi3 /opt/fhem/tmp/fhem-code/fhem/contrib/HMCCU $ cat ccurpcd.log
19.12.2015 18:12:54 Creating file queue
19.12.2015 18:12:54 Initializing RPC server
19.12.2015 18:12:54 callback server created
19.12.2015 18:12:54 Adding callback for events
19.12.2015 18:12:54 Adding callback for new devices
19.12.2015 18:12:54 Adding callback for deleted devices
19.12.2015 18:12:54 Adding callback for modified devices
19.12.2015 18:12:54 Registering callback
19.12.2015 18:16:56 Creating file queue
19.12.2015 18:16:56 Initializing RPC server
19.12.2015 18:16:56 callback server created
19.12.2015 18:16:56 Adding callback for events
19.12.2015 18:16:56 Adding callback for new devices
19.12.2015 18:16:56 Adding callback for deleted devices
19.12.2015 18:16:56 Adding callback for modified devices
19.12.2015 18:16:56 Registering callback
19.12.2015 18:19:57 RPC callback with URL http://192.168.1.24:7401/fh initialized
19.12.2015 18:19:57 Entering server loop. Use kill -SIGINT 20537 to terminate program
19.12.2015 18:19:57 ListDevices
19.12.2015 18:19:57 NewDevice: received 56 device specifications
19.12.2015 19:06:28 Shutdown RPC server
19.12.2015 19:06:28 RPC server terminated
19.12.2015 20:29:31 Creating file queue
19.12.2015 20:31:59 Error: ccurpcd.pl is already running (PID=7809)
19.12.2015 20:34:04 Error: ccurpcd.pl is already running (PID=7825)
19.12.2015 20:35:00 Error: ccurpcd.pl is already running (PID=7834)
19.12.2015 20:36:36 Creating file queue
19.12.2015 20:36:36 Initializing RPC server
19.12.2015 20:36:38 callback server created
19.12.2015 20:36:38 Adding callback for events
19.12.2015 20:36:38 Adding callback for new devices
19.12.2015 20:36:38 Adding callback for deleted devices
19.12.2015 20:36:38 Adding callback for modified devices
19.12.2015 20:36:38 Registering callback
19.12.2015 21:01:23 Creating file queue
19.12.2015 21:01:23 Initializing RPC server
19.12.2015 21:01:24 callback server created
19.12.2015 21:01:24 Adding callback for events
19.12.2015 21:01:24 Adding callback for new devices
19.12.2015 21:01:24 Adding callback for deleted devices
19.12.2015 21:01:24 Adding callback for modified devices
19.12.2015 21:01:24 Registering callback
19.12.2015 21:01:25 nach listmethods. Sende jetzt:inithttp://192.168.1.25:7401/fhCB1
19.12.2015 21:13:14 Creating file queue
19.12.2015 21:13:14 Initializing RPC server
19.12.2015 21:13:15 callback server created
19.12.2015 21:13:15 Adding callback for events
19.12.2015 21:13:15 Adding callback for new devices
19.12.2015 21:13:15 Adding callback for deleted devices
19.12.2015 21:13:15 Adding callback for modified devices
19.12.2015 21:13:15 Registering callback
19.12.2015 21:13:15 nach listmethods. Sende jetzt:inithttp://192.168.1.25:7401/fhCB1
20.12.2015 11:17:23 Creating file queue
20.12.2015 11:17:23 Initializing RPC server
20.12.2015 11:17:25 callback server created
20.12.2015 11:17:25 Adding callback for events
20.12.2015 11:17:25 Adding callback for new devices
20.12.2015 11:17:25 Adding callback for deleted devices
20.12.2015 11:17:25 Adding callback for modified devices
20.12.2015 11:17:25 Registering callback
20.12.2015 11:17:25 nach listmethods. Sende jetzt:inithttp://192.168.1.25:7401/fhCB1
20.12.2015 11:17:25 RPC callback with URL http://192.168.1.25:7401/fh initialized
20.12.2015 11:17:25 Entering server loop. Use kill -SIGINT 10888 to terminate program
20.12.2015 11:19:01 Shutdown RPC server
20.12.2015 11:19:01 RPC server terminated
20.12.2015 11:19:38 Creating file queue
20.12.2015 11:19:38 Initializing RPC server
20.12.2015 11:19:40 callback server created
20.12.2015 11:19:40 Adding callback for events
20.12.2015 11:19:40 Adding callback for new devices
20.12.2015 11:19:40 Adding callback for deleted devices
20.12.2015 11:19:40 Adding callback for modified devices
20.12.2015 11:19:40 Registering callback
20.12.2015 11:19:40 nach listmethods. Sende jetzt:inithttp://192.168.1.25:7401/fhCB1
20.12.2015 11:35:43 Creating file queue
20.12.2015 11:35:43 Initializing RPC server
20.12.2015 11:35:44 callback server created
20.12.2015 11:35:44 Adding callback for events
20.12.2015 11:35:44 Adding callback for new devices
20.12.2015 11:35:44 Adding callback for deleted devices
20.12.2015 11:35:44 Adding callback for modified devices
20.12.2015 11:35:45 Registering callback
20.12.2015 11:35:45 nach listmethods. Sende jetzt:inithttp://192.168.1.25:7401/fhCB1
20.12.2015 11:19:38 Creating file queue
20.12.2015 11:19:38 Initializing RPC server
20.12.2015 11:19:40 callback server created
20.12.2015 11:19:40 Adding callback for events
20.12.2015 11:19:40 Adding callback for new devices
20.12.2015 11:19:40 Adding callback for deleted devices
20.12.2015 11:19:40 Adding callback for modified devices
20.12.2015 11:19:40 Registering callback
20.12.2015 11:19:40 nach listmethods. Sende jetzt:inithttp://192.168.1.25:7401/fhCB1
20.12.2015 11:35:43 Creating file queue
20.12.2015 11:35:43 Initializing RPC server
20.12.2015 11:35:44 callback server created
20.12.2015 11:35:44 Adding callback for events
20.12.2015 11:35:44 Adding callback for new devices
20.12.2015 11:35:44 Adding callback for deleted devices
20.12.2015 11:35:44 Adding callback for modified devices
20.12.2015 11:35:45 Registering callback
20.12.2015 11:35:45 nach listmethods. Sende jetzt:inithttp://192.168.1.25:7401/fhCB1

192.168.1.25 ist der pi, .30 die CCU.
Du siehst in dem Log-Ausschnitt eine Stelle, wo er die Serverloop erreicht. Da habe ich das send_request("init",... auskommentiert. Dann ist der Server auch da und per brwoeser ansrepchbar (gibt ein 403). Aber natürlich liefert die CCU keine Daten an.
Für mich sieht das so aus:
- unter ubuntu hängt das Hochfahren ziemlich genau 3 Minuten in dem send_request("init" fest, dann geht es weiter, der Server lauscht auf dem Port und die CCU kann senden.
- auf dem pi kommt der Prozess nie aus send_request("init" zurück, daher kann die CCU auch nichts senden und hängt ihrerseits (timeouts scheint es da nicht zugeben oder die sind sehr lang). Wenn ich den ccurpcd dann töte, fällt die Verbindung zusammen und der rfd beschwert sich im Log file.

Ich denke, ich werde das noch mal auf einem anderen Raspberry ausprobieren. Vielleicht habe ich auf diesem hier irgendwas im Netzwerkbereich oder in der Perlinstallation kaputt gespielt.

zap

#103
Wenn ich heute noch dazu komme, suche ich Dir mal die Versionen der relevanten Perl-Module raus, die ccurpcd.pl verwendet.

Update: Direkt von CPAN installiert. RPC::XML Version 0.79
2xCCU3 mit ca. 100 Aktoren, Sensoren
Entwicklung: FHEM auf Proxmox Debian VM
Produktiv inzwischen auf Home Assistant gewechselt.
Maintainer: HMCCU, (Fully, AndroidDB)

mifh

Das wäre toll, denn es ist wohl ein Konfigurationsproblem. Auf einem anderem Raspberry haut es hin.
Ich musste nur die rpc-xml Library installieren. An der hing allerdings noch ziemlich viel Kram dran.
Und so sieht es dann aus:

pi@pi2:/tmp$ tail -f *.log
20.12.2015 17:30:31 Creating file queue
20.12.2015 17:30:31 Initializing RPC server
20.12.2015 17:30:33 callback server created
20.12.2015 17:30:33 Adding callback for events
20.12.2015 17:30:33 Adding callback for new devices
20.12.2015 17:30:33 Adding callback for deleted devices
20.12.2015 17:30:33 Adding callback for modified devices
20.12.2015 17:30:33 Registering callback
20.12.2015 17:33:34 RPC callback with URL http://192.168.1.29:7401/fh initialized
20.12.2015 17:33:34 Entering server loop. Use kill -SIGINT 5147 to terminate program
20.12.2015 17:33:34 ListDevices
20.12.2015 17:33:35 NewDevice: received 56 device specifications


Weiter komme ich auf diesem Pi nicht, denn da läuft kein fhem drauf.
Mal sehen, wie ich die Perl-Installation auf dem anderen Pi wieder sauber kriege.