[Gelöst] RPC-Server startet nicht

[manne44]

Hallo, wieder einmal der RPC-Server, der nicht starten will, obwohl ich meine, dass ich alles so gemacht habe, wie es beschrieben ist.
Um meinen BananaPi, auf dem FHEM läuft zu entlasten, habe ich mir mit einem RPI3B+, den ich noch hatte, und einem Funk-Modul RPI-RF-MOD eine CCU3 (Charly) zusammengebaut und die SD-Card mit RaspberryMatic-3.47.22.20191026-rpi3 geflasht. CCU startet und kann nach Belieben bedient werden. Auf dem BananaPi habe ich nun wie beschrieben d_ccu definiert:

Internals:
   CCUNum     1
   CFGFN      ./FHEM/99_CCU3.cfg
   Clients    :HMCCUDEV:HMCCUCHN:HMCCURPC:HMCCURPCPROC:
   DEF        192.168.178.84
   NAME       d_ccu
   NOTIFYDEV  global,TYPE=(HMCCU|HMCCUDEV|HMCCUCHN)
   NR         2172
   NTFY_ORDER 50-d_ccu
   RPCState   inactive
   STATE      inactive/Error
   TYPE       HMCCU
   ccuaddr    BidCoS-RF
   ccuchannels 118
   ccudevices 5
   ccuif      BidCos-RF
   ccuinterfaces VirtualDevices,BidCos-RF,HmIP-RF
   ccuip      192.168.178.84
   ccuname    CCU3-BidCos-RF
   ccustate   active
   ccutype    CCU2/3
   host       192.168.178.84
   version    4.3.004
   READINGS:
     2019-11-18 01:26:02   count_channels  118
     2019-11-18 01:26:02   count_devices   5
     2019-11-18 01:26:02   count_groups    0
     2019-11-18 01:26:02   count_interfaces 3
     2019-11-18 01:26:02   count_programs  1
     2019-11-17 18:52:24   rpcstate        inactive
     2019-11-18 01:56:34   state           Error

Attributes:
DbLogExclude .*
ccudef-readingfilter ^(LOW_?BAT|UNREACH)$
ccudef-readingname ^(.+\.)?LOW_?BAT$:battery;^(.+\.)?UNREACH$:activity
ccudef-substitute AES_KEY!(0|false):off,(1|true):on;LOWBAT,LOW_BAT!(0|false):ok,(1|true):low;UNREACH!(0|false):alive,(1|true):dead;MOTION!(0|false):noMotion,1|true):motion;DIRECTION!0:stop,1:up,2:down,3:undefined;WORKING!0:false,1:true;INHIBIT!0|false):unlocked,(1|true):locked
ccuflags procrpc
cmdIcon on:general_an off:general_aus
event-on-change-reading .*
eventMap /rpcserver on:on/rpcserver off:off/
room CCU3
rpcinterfaces BidCos-RF
rpcport 32001
rpcserver on
stateFormat rpcstate/state
stripnumber 1
verbose 5

Auf CCU-Seite habe ich in den Firewall-Einstellungen alles auf Vollzugriff und Ports offen eingestellt und bei Sicherheit die Authentifizierung entkreuzt, also abgewählt. Was kann ich denn da noch machen? Ratlos!

Wenn der Server gestartet werden soll, dann kommen folgende Fehlermeldungen:

Code Auswählen Erweitern


2019.11.18 10:50:20 1: HMCCU: [d_ccu] No RPC device defined for interface BidCos-RF
2019.11.18 10:50:20 1: HMCCU: [d_ccu] Creating new RPC device d_rpcBidCos_RF
2019.11.18 10:50:20 1: HMCCU: [d_ccu] Definition of RPC device failed.
2019.11.18 10:50:20 1: HMCCU: [d_ccu] d_rpcBidCos_RF already defined, delete it first
2019.11.18 10:50:20 0: HMCCU: [d_ccu] Definition of some RPC devices failed
2019.11.18 10:50:20 1: HMCCU: d_ccu Start of RPC server failed


Aber d_rpcBidCos_RF wird erzeugt und es werden auch die Testgeräte aus der CCU übernommen, wenn eingegeben wird:

Code Auswählen Erweitern


get d_ccu devicelist create ^hm.* t=dev f=_%n defattr save room=CCU3

2019.11.18 11:08:50 2: HMCCUDEV: Created device _hmSWplug_2
2019.11.18 11:08:52 2: HMCCUDEV: Created device _hmWinVelux
2019.11.18 11:08:57 2: HMCCUDEV: Created device _hmHzgVelux

Der Schalter kann auch von FHEM aus bedient werden.

Ich wollte so gern FHEM von den Homematik-Geräten "befreien", aber ich kriege den Server nicht gestartet und weiß auch nicht was ich noch machen kann. Vielleicht hat jemand eine Idee.
Vielen Dank schon mal.

[frank]

schon mal ohne include-file probiert?

[manne44]

Ich habe den ganzen Eintrag

Code Auswählen Erweitern


# Verbindung zur Homematic CCU3
# include ./FHEM/99_CCU3.cfg
# ------------------------------------------------------------
define d_ccu HMCCU 192.168.178.84
attr d_ccu DbLogExclude .*
attr d_ccu ccudef-readingfilter ^(LOW_?BAT|UNREACH)$
attr d_ccu ccudef-readingname ^(.+\.)?LOW_?BAT$:battery;;^(.+\.)?UNREACH$:activity
attr d_ccu ccudef-substitute AES_KEY!(0|false):off,(1|true):on;;LOWBAT,LOW_BAT!(0|false):ok,(1|true):low;;UNREACH!(0|false):alive,(1|true):dead;;MOTION!(0|false):noMotion,(1|true):motion;;DIRECTION!0:stop,1:up,2:down,3:undefined;;WORKING!0:false,1:true;;INHIBIT!(0|false):unlocked,(1|true):locked
attr d_ccu ccuflags procrpc
attr d_ccu cmdIcon on:general_an off:general_aus
attr d_ccu comment Um eine automatische Liste der Geräte in der CCU3 zu erhalten:\
get d_ccu devicelist create ^hm.* t=dev f=_%n defattr save room=CCU3
attr d_ccu event-on-change-reading .*
attr d_ccu eventMap /rpcserver on:on/rpcserver off:off/
attr d_ccu room CCU3
attr d_ccu rpcinterfaces BidCos-RF
attr d_ccu rpcport 32001
attr d_ccu rpcqueue /tmp/ccuqueue
attr d_ccu rpcserver on
attr d_ccu stateFormat rpcstate/state
attr d_ccu stripnumber 1
attr d_ccu verbose 5

direkt in die fhem.cfg geschrieben, was ich bei der Definition per WEB-UI erst auch gemacht hatte und wo sich der gleich Text am Ende der Datei befand, der jetzt etwas in die Mitte verschoben wurde. Es zeigt die Log-Datei einen anderen Eintrag, aber die Web-Oberfläche ist nicht mehr erreichbar, weil hier offenbar eine Endlosschleife oder so "abgearbeitet" wird. Weiter Einträge im Logfile gibt es auch nach 10 Minuten nicht.

Code Auswählen Erweitern


2019.11.18 12:56:29 2: CCURPC: [d_rpcBidCos_RF] Initializing RPC server CB32001178040 for interface BidCos-RF
2019.11.18 12:56:29 2: CCURPC: [d_rpcBidCos_RF] CB32001178040 accepting connections. PID=2118
2019.11.18 12:56:29 1: HMCCURPCPROC: [d_rpcBidCos_RF] RPC server starting
2019.11.18 12:56:36 2: HMCCURPCPROC: [d_rpcBidCos_RF] RPC server CB32001178040 enters server loop
2019.11.18 12:56:36 2: HMCCURPCPROC: [d_rpcBidCos_RF] Registering callback xmlrpc_bin://192.168.178.40:37411/fh32001 of type B with ID CB32001178040 at xmlrpc_bin://192.168.178.84:32001


[manne44]

Wenn ich das Attribut

Code Auswählen Erweitern


attr d_ccu rpcserver on

auskommentiere, dann geht alles seinen Gang. Wenn ich dann im WEB-UI

Code Auswählen Erweitern


set d_ccu rpcserver on

anwähle, dann das gleiche Bild, nichts geht mehr.

[kjmEjfu]

Hast du noch irgendwo ein d_rpcBidCos_RF device? Wenn ja, dann lösch das mal. Aus irgendwelchen Gründen meckert er ja im Logfile, dass es nicht vorhanden wäre, aber beim Neuanlegen scheitert FHEM ja auch.

Was passiert denn, wenn du bei rpcinterfaces den BidCos-RF rausnimmst und stattdessen mal nur mit HmIP-RF versuchst?

[manne44]

HmIP-Devices habe ich erst einmal nicht, nur normale Homematic-Teile.
Wenn ich das Attribut rpcinterfaces lösche und den Server von Hand starten will, das gleiche Bild, keine Änderung:

Code Auswählen Erweitern

019.11.18 13:45:47 2: HMCCURPCPROC: [d_rpcBidCos_RF] Found no running processes. Cleaning up ...
2019.11.18 13:45:47 1: HMCCURPCPROC: [d_rpcBidCos_RF] Housekeeping called. Cleaning up RPC environment
2019.11.18 13:46:56 1: HMCCU: [d_ccu] No RPC device defined for interface BidCos-RF
2019.11.18 13:46:56 1: HMCCU: [d_ccu] Creating new RPC device d_rpcBidCos_RF
2019.11.18 13:46:56 1: HMCCURPCPROC: [d_rpcBidCos_RF] Initialized version 1.0.007 for interface BidCos-RF with I/O device d_ccu
2019.11.18 13:46:59 1: HMCCU: [d_ccu] Saving FHEM config
2019.11.18 13:46:59 2: HMCCURPCPROC: [d_rpcBidCos_RF] RPC server process started for interface BidCos-RF with PID=3200
2019.11.18 13:46:59 2: CCURPC: [d_rpcBidCos_RF] Initializing RPC server CB32001178040 for interface BidCos-RF
2019.11.18 13:46:59 2: CCURPC: [d_rpcBidCos_RF] CB32001178040 accepting connections. PID=3200
2019.11.18 13:46:59 1: HMCCURPCPROC: [d_rpcBidCos_RF] RPC server starting
2019.11.18 13:47:03 2: HMCCURPCPROC: [d_rpcBidCos_RF] RPC server CB32001178040 enters server loop
2019.11.18 13:47:03 2: HMCCURPCPROC: [d_rpcBidCos_RF] Registering callback xmlrpc_bin://192.168.178.40:37411/fh32001 of type B with ID CB32001178040 at xmlrpc_bin://192.168.178.84:32001

Nichts geht mehr.

[frank]

Nichts geht mehr.

was heisst das?

wenn du eine loop hättest, müsste man die ja in fhem.log sehen, oder? eventuell mal verbose schrittweise erhöhen bei d_ccu und dem rpcserver.

dein letztes log sieht im prinzip gut aus, meine ich.
bei mir geht es allerdings dann noch weiter.

irgendwas ist aber bei dir nicht aktuell, denn mein log sagt

Code Auswählen Erweitern

2019.11.12 12:02:14.351 1: HMCCURPCPROC: [d_rpc001025BidCos_RF] Initialized version 1.8 for interface BidCos-RF with I/O device d_ccu


mach mal fhem update und dann restart.

ps: editiere fhem config nur, wenn du weisst, was du tust. 
machst du anschliessend rereadcfg oder fhem restart. rereadcfg habe ich irgendwann aufgegeben.

[zap]

Ich sehe da 2 grundlegende Probleme:

1. fhem.cfg manuell editiert. Kann man machen, wenn man weiß, was man tut. Support gibt's von mir dafür keinen.

2. HMCCURPCPROC Modul ist uralt. Also erst mal die Module auf den aktuellen Stand bringen.

[manne44]

@zap:
vielen Dank für die Infos. Zum manuellen Editieren der cfg-Datei sage ich nur, dass ich mich mit Programmiertools noch nie anfreunden konnte und dabei leicht die Übersicht verlor, denn ich habe während der letzten 20 Jahre meiner Berufstätigkeit sehr viel in Pascal und C programmieren müssen, aber immer im passenden Editor, was auch sehr gut geklappt hat, andere kamen damit nicht so gut zurecht und haben es anders gemacht. Meine FHEM-Installation habe ich seit Jahren nur per Editor begonnen und erweitert, aber habe mich weitestgehend seit einem dreiviertel Jahr so umgestellt, daß ich nun WEBUI nehme und bemerke, daß da auch nichts anderes gemacht wird, als ich es beim händischen Editieren gemacht habe, nur wird es immer an das Dateiende geschrieben, so daß die Datei selbst sehr schwer lesbar ist. Nun benutze ich fast ausschließlich die integrierte Entwicklungsumgebung, mit der eigentlich alles gut - wenn nicht besser - erledigt werden kann. Nur sortiere ich die Einträge der Übersichtlichkeit wegen dann von Zeit zu Zeit in verschiedene Include-Dateien, in denen dann genau das steht, was auch in der fhem.cfg stand. Das dürfte am Verhalten nun nichts ändern, denn ob es da oder da steht, das ist doch egal, es sei denn die Reihenfolge wäre wichtig.

Nun zu meinem Problem:
Ich habe für alle 88_HMCCU* ein Update gemacht. Beim Start von FHEM ergeben sich mit attr d_ccu rpcserver on folgende Log-Einträge mit verbose 5:

Code Auswählen Erweitern


2019.11.18 17:51:22 5: Loading ./FHEM/88_HMCCU.pm
2019.11.18 17:51:25 1: HMCCU: [d_ccu] Initialized version 4.3.019
2019.11.18 17:51:25 1: HMCCU: [d_ccu] HMCCU: Initializing device
2019.11.18 17:51:25 4: HMCCU: [d_ccu] Build URL = http://192.168.178.84:8181/tclrega.exe
2019.11.18 17:51:25 5: HttpUtils url=http://192.168.178.84:8181/tclrega.exe
2019.11.18 17:51:25 5: HttpUtils request header:
POST /tclrega.exe HTTP/1.0
Host: 192.168.178.84:8181
User-Agent: fhem
Accept-Encoding: gzip,deflate
Content-Length: 1054
Content-Type: application/x-www-form-urlencoded

2019.11.18 17:51:25 4: http://192.168.178.84:8181/tclrega.exe: HTTP response code 200
2019.11.18 17:51:25 5: HttpUtils http://192.168.178.84:8181/tclrega.exe: Got data, length: 6249
2019.11.18 17:51:25 5: HttpUtils response header:
HTTP/1.0 200 OK
Accept-Ranges: bytes
Cache-Control: private, no-cache, must-revalidate, no-transform, max-age=0
Content-Type: text/xml; charset=iso-8859-1
Content-Length: 6249
Date: Mon, 18 Nov 2019 17:51:25 GMT
X-Frame-Options: SAMEORIGIN
X-Content-Type-Options: nosniff
X-XSS-Protection: 1; mode=block
X-Robots-Tag: none
X-Download-Options: noopen
X-Permitted-Cross-Domain-Policies: none
Referrer-Policy: no-referrer
Connection: close
2019.11.18 17:51:25 4: HMCCU: [d_ccu] Build URL = http://192.168.178.84:8181/tclrega.exe
2019.11.18 17:51:25 5: HttpUtils url=http://192.168.178.84:8181/tclrega.exe
2019.11.18 17:51:25 5: HttpUtils request header:
POST /tclrega.exe HTTP/1.0
Host: 192.168.178.84:8181
User-Agent: fhem
Accept-Encoding: gzip,deflate
Content-Length: 215
Content-Type: application/x-www-form-urlencoded

2019.11.18 17:51:25 4: http://192.168.178.84:8181/tclrega.exe: HTTP response code 200
2019.11.18 17:51:25 5: HttpUtils http://192.168.178.84:8181/tclrega.exe: Got data, length: 316
2019.11.18 17:51:25 5: HttpUtils response header:
HTTP/1.0 200 OK
Accept-Ranges: bytes
Cache-Control: private, no-cache, must-revalidate, no-transform, max-age=0
Content-Type: text/xml; charset=iso-8859-1
Content-Length: 316
Date: Mon, 18 Nov 2019 17:51:25 GMT
X-Frame-Options: SAMEORIGIN
X-Content-Type-Options: nosniff
X-XSS-Protection: 1; mode=block
X-Robots-Tag: none
X-Download-Options: noopen
X-Permitted-Cross-Domain-Policies: none
Referrer-Policy: no-referrer
Connection: close
2019.11.18 17:51:25 4: HMCCU: [d_ccu] Build URL = http://192.168.178.84:8181/tclrega.exe
2019.11.18 17:51:25 5: HttpUtils url=http://192.168.178.84:8181/tclrega.exe
2019.11.18 17:51:25 5: HttpUtils request header:
POST /tclrega.exe HTTP/1.0
Host: 192.168.178.84:8181
User-Agent: fhem
Accept-Encoding: gzip,deflate
Content-Length: 971
Content-Type: application/x-www-form-urlencoded

2019.11.18 17:51:25 4: http://192.168.178.84:8181/tclrega.exe: HTTP response code 200
2019.11.18 17:51:25 5: HttpUtils http://192.168.178.84:8181/tclrega.exe: Got data, length: 17654
2019.11.18 17:51:25 5: HttpUtils response header:
HTTP/1.0 200 OK
Accept-Ranges: bytes
Cache-Control: private, no-cache, must-revalidate, no-transform, max-age=0
Content-Type: text/xml; charset=iso-8859-1
Content-Length: 17654
Date: Mon, 18 Nov 2019 17:51:25 GMT
X-Frame-Options: SAMEORIGIN
X-Content-Type-Options: nosniff
X-XSS-Protection: 1; mode=block
X-Robots-Tag: none
X-Download-Options: noopen
X-Permitted-Cross-Domain-Policies: none
Referrer-Policy: no-referrer
Connection: close
2019.11.18 17:51:25 1: HMCCU: [d_ccu] HMCCU: Read 5 devices with 118 channels from CCU 192.168.178.84
2019.11.18 17:51:25 1: HMCCU: [d_ccu] HMCCU: Read 3 interfaces from CCU 192.168.178.84
2019.11.18 17:51:25 1: HMCCU: [d_ccu] HMCCU: Read 1 programs from CCU 192.168.178.84
2019.11.18 17:51:25 1: HMCCU: [d_ccu] HMCCU: Read 0 virtual groups from CCU 192.168.178.84
2019.11.18 17:51:25 5: Cmd: >attr d_ccu DbLogExclude .*<
2019.11.18 17:51:25 5: Cmd: >attr d_ccu ccudef-readingfilter ^(LOW_?BAT|UNREACH)$<
2019.11.18 17:51:25 5: Cmd: >attr d_ccu ccudef-readingname ^(.+\.)?LOW_?BAT$:battery;^(.+\.)?UNREACH$:activity<
2019.11.18 17:51:25 5: Cmd: >attr d_ccu ccudef-substitute AES_KEY!(0|false):off,(1|true):on;LOWBAT,LOW_BAT!(0|false):ok,(1|true):low;UNREACH!(0|false):alive,(1|true):dead;MOTION!(0|false):noMotion,(1|true):motion;DIRECTION!0:stop,1:up,2:down,3:undefined;WORKING!0:false,1:true;INHIBIT!(0|false):unlocked,(1|true):locked<
2019.11.18 17:51:25 5: Cmd: >attr d_ccu ccuflags procrpc<
2019.11.18 17:51:25 5: Cmd: >attr d_ccu cmdIcon on:general_an off:general_aus<
2019.11.18 17:51:25 5: Cmd: >attr d_ccu comment Um eine automatische Liste der Geräte in der CCU3 zu erhalten:
get d_ccu devicelist create ^hm.* t=dev f=_%n defattr save room=CCU3<
2019.11.18 17:51:25 5: Cmd: >attr d_ccu event-on-change-reading .*<
2019.11.18 17:51:25 5: Cmd: >attr d_ccu eventMap /rpcserver on:on/rpcserver off:off/<
2019.11.18 17:51:25 5: Cmd: >attr d_ccu room CCU3<
2019.11.18 17:51:25 5: Cmd: >attr d_ccu stateFormat rpcstate/state<
2019.11.18 17:51:25 5: Cmd: >attr d_ccu stripnumber 1<
2019.11.18 17:51:25 5: Cmd: >attr d_ccu verbose 5<
2019.11.18 17:51:25 5: Cmd: >attr d_ccu rpcqueue /tmp/ccuqueue<
2019.11.18 17:51:25 5: Cmd: >attr d_ccu rpcserver on<

und WEB-UI von Fhem kann nicht mehr aufgerufen werden.

Wenn das Attribut attr d_ccu rpcserver on auskommentiert wurde, dann ergeben sich beim Start folgende Log-Einträge und WEB-UI ist erreichbar, aber nicht bedienbar, sondern stürzt nach der ersten Eingabe ab:

Code Auswählen Erweitern


2019.11.18 17:51:22 5: Loading ./FHEM/88_HMCCU.pm
2019.11.18 17:51:25 1: HMCCU: [d_ccu] Initialized version 4.3.019
2019.11.18 17:51:25 1: HMCCU: [d_ccu] HMCCU: Initializing device
2019.11.18 17:51:25 4: HMCCU: [d_ccu] Build URL = http://192.168.178.84:8181/tclrega.exe
2019.11.18 17:51:25 5: HttpUtils url=http://192.168.178.84:8181/tclrega.exe
2019.11.18 17:51:25 5: HttpUtils request header:
POST /tclrega.exe HTTP/1.0
Host: 192.168.178.84:8181
User-Agent: fhem
Accept-Encoding: gzip,deflate
Content-Length: 1054
Content-Type: application/x-www-form-urlencoded

2019.11.18 17:51:25 4: http://192.168.178.84:8181/tclrega.exe: HTTP response code 200
2019.11.18 17:51:25 5: HttpUtils http://192.168.178.84:8181/tclrega.exe: Got data, length: 6249
2019.11.18 17:51:25 5: HttpUtils response header:
HTTP/1.0 200 OK
Accept-Ranges: bytes
Cache-Control: private, no-cache, must-revalidate, no-transform, max-age=0
Content-Type: text/xml; charset=iso-8859-1
Content-Length: 6249
Date: Mon, 18 Nov 2019 17:51:25 GMT
X-Frame-Options: SAMEORIGIN
X-Content-Type-Options: nosniff
X-XSS-Protection: 1; mode=block
X-Robots-Tag: none
X-Download-Options: noopen
X-Permitted-Cross-Domain-Policies: none
Referrer-Policy: no-referrer
Connection: close
2019.11.18 17:51:25 4: HMCCU: [d_ccu] Build URL = http://192.168.178.84:8181/tclrega.exe
2019.11.18 17:51:25 5: HttpUtils url=http://192.168.178.84:8181/tclrega.exe
2019.11.18 17:51:25 5: HttpUtils request header:
POST /tclrega.exe HTTP/1.0
Host: 192.168.178.84:8181
User-Agent: fhem
Accept-Encoding: gzip,deflate
Content-Length: 215
Content-Type: application/x-www-form-urlencoded

2019.11.18 17:51:25 4: http://192.168.178.84:8181/tclrega.exe: HTTP response code 200
2019.11.18 17:51:25 5: HttpUtils http://192.168.178.84:8181/tclrega.exe: Got data, length: 316
2019.11.18 17:51:25 5: HttpUtils response header:
HTTP/1.0 200 OK
Accept-Ranges: bytes
Cache-Control: private, no-cache, must-revalidate, no-transform, max-age=0
Content-Type: text/xml; charset=iso-8859-1
Content-Length: 316
Date: Mon, 18 Nov 2019 17:51:25 GMT
X-Frame-Options: SAMEORIGIN
X-Content-Type-Options: nosniff
X-XSS-Protection: 1; mode=block
X-Robots-Tag: none
X-Download-Options: noopen
X-Permitted-Cross-Domain-Policies: none
Referrer-Policy: no-referrer
Connection: close
2019.11.18 17:51:25 4: HMCCU: [d_ccu] Build URL = http://192.168.178.84:8181/tclrega.exe


Ich werde mal ein vollständiges Update machen und mal sehen was das wird.

[manne44]

Nach dem vollständigen Update ist nun alles okay, der Server startet. Jetzt habe ich zwar die häßlichen, aber wohl notwendigen "setuuids" in den Config-Files, aber die sollen auch nicht editiert werden, was ich fast nicht mehr mache, deshalb alles gut.
Vielen Dank für die Geduld und Hilfe.