FHEM Forum

FHEM - Hausautomations-Systeme => Homematic => Thema gestartet von: selfarian am 19 Juni 2026, 12:56:22

Titel: RPC Server startet nicht (mehr)
Beitrag von: selfarian am 19 Juni 2026, 12:56:22
Hallo zusammen,

kurz zur Geschichte: Ich habe vor einiger Zeit meine FHEM Instanz von einem Raspberry auf einen Docker auf meiner Synology umgezogen.

Jetzt habe ich Dödel einfach blindlings ein Update des Images eingespielt ohne die Konfiguration zu sichern (bzw. habe nur eine alte Sicherung vom Raspberry). Somit habe ich eine frische Installation.
Nun hatte ich als erstes die CCU3 via Define eingebunden und wollte anschließend den RPC Server starten - ging nicht. Dann habe ich im Wiki noch einmal nachgesehen und die fehlende Software via apt und cpan installiert.
Aber auch danach ging es leider nicht.
Das Attribut attr d_ccu rpcserver on habe ich gesetzt und jedes Mal, wenn ich auf On klicke hängt sich FHEM quasi komplett auf. Erst nach einiger Zeit reagiert es wieder. Hier ist der Log-Ausschnitt:
026.06.19 11:56:00.758 2: HMCCURPCPROC [d_rpc150012BidCos_RF] RPC request init failed: RPC::XML::Client::simple_request: RPC::XML::Client::send_request: HTTP server error: read timeout
2026.06.19 11:56:00.758 2: HMCCURPCPROC [d_rpc150012BidCos_RF] Retrying request init
2026.06.19 11:56:00.759 1: HMCCURPCPROC [d_rpc150012BidCos_RF] Failed to register callback for ID CB2001000002150012: RPC request init failed: RPC::XML::Client::simple_request: RPC::XML::Client::send_request: HTTP server error: read timeout
2026.06.19 11:56:00.761 2: HMCCURPCPROC [d_rpc150012BidCos_RF] Checking if RPC server process is running
2026.06.19 11:56:00.762 1: HMCCURPCPROC [d_rpc150012BidCos_RF] RPC server process not running. Cleaning up
2026.06.19 11:56:00.762 1: HMCCURPCPROC [d_rpc150012BidCos_RF] Housekeeping called. Cleaning up RPC environment
2026.06.19 11:56:00.763 2: HMCCURPCPROC [d_rpc150012BidCos_RF] Sending signal INT to RPC server process CB2001000002150012 with PID=8234
2026.06.19 11:56:00.763 2: HMCCURPCPROC [d_rpc150012BidCos_RF] CB2001000002150012 received signal INT
2026.06.19 11:56:00.763 1: HMCCURPCPROC [d_rpc150012BidCos_RF] RPC server CB2001000002150012 stopped handling connections. PID=8234 run=0
2026.06.19 11:56:00.764 2: HMCCURPCPROC [d_rpc150012BidCos_RF] Number of I/O errors = 0
2026.06.19 11:56:02.764 2: HMCCURPCPROC [d_rpc150012BidCos_RF] RPC server process CB2001000002150012 deleted
2026.06.19 11:56:02.765 2: HMCCURPCPROC [d_rpc150012BidCos_RF] Stop I/O handling
2026.06.19 11:56:02.766 2: HMCCURPCPROC [d_rpc150012BidCos_RF] RPC server stopped. Cancel delayed shutdown.

Habt Ihr da eventuell eine Idee? Das Docker Image ist fhem/fhem.

Vielen Dank schon einmal und beste Grüße,
Alex
Titel: Aw: RPC Server startet nicht (mehr)
Beitrag von: passibe am 19 Juni 2026, 13:12:39
Ggfs. war die IP vom Raspberry in der CCU-Firewall whitelisted aber die der Synology ist es noch nicht? Klingt irgendwie ein bisschen nach einem Firewall-Problem.

Unabhängig davon, kannst du bitte mal einen etwas größeren Logauszug posten? Allein daraus werde jedenfalls ich noch nicht schlau, an welcher Stelle genau der Fehler jetzt auftritt. Am besten einfach nach einem shutdown restart von FHEM alles, was mit HMCCU zusammenhängt, rauskopieren und posten.

Ansonsten muss übrigens im Container auch der jeweilige Port freigegeben sein. Weiß nicht mehr genau, was es für BidCos_RF ist, für HmIP ist es aber z.B. 7420. Auf dem Port lauscht der RPC Server auf Daten von der CCU, d.h. er muss von der CCU aus ohne Weiteres erreichbar sein.
Titel: Aw: RPC Server startet nicht (mehr)
Beitrag von: selfarian am 19 Juni 2026, 13:25:50
Danke schon einmal für die erste Einschätzung. Meine Tendenz wäre auch irgendwas mit den Ports. Die CCU selbst hat eigentlich keine Firewall aktiv, also da steht alles auf Ports offen und Vollzugriff.
Bezüglich der Ports des Docker Images, hier sind die folgenden weitergeleitet:
14702, 34190, 34206, 45426, 7411, 7420, 8083
Da habe ich nichts verändert.

Hier ist einmal der komplette Log eines Reboots. Was mir auffällt ist die IP 172.17.0.2, die die IP des bridge-Netzwerkes des Dockers ist. Allerdings ist FHEM über das "normale" netz 192.168.150.x erreichbar. Die 172.17.0.2 ist von außen nicht erreichbar. Eventuell hängt es schon daran?
Wie/wo kann ich denn den RPC Server konfigurieren, auf welchem Port/IP er lauscht?

2026.06.19 13:15:24.526 1: HMCCURPCPROC [d_rpc150012HmIP_RF] Stopping RPC server CB2010000002150012
2026.06.19 13:15:24.527 1: HMCCURPCPROC [d_rpc150012HmIP_RF] Deregistering RPC server http://172.17.0.2:7420/fh2010 with ID CB2010000002150012 at http://192.168.150.12:2010
2026.06.19 13:15:24.538 1: HMCCURPCPROC [d_rpc150012HmIP_RF] Callback for RPC server CB2010000002150012 deregistered
2026.06.19 13:15:24.539 2: HMCCURPCPROC [d_rpc150012HmIP_RF] Sending signal INT to RPC server process CB2010000002150012 with PID=5366
2026.06.19 13:15:24.539 2: HMCCURPCPROC [d_rpc150012HmIP_RF] Cleaning up immediately
2026.06.19 13:15:24.539 1: HMCCURPCPROC [d_rpc150012HmIP_RF] Housekeeping called. Cleaning up RPC environment
2026.06.19 13:15:24.539 2: HMCCURPCPROC [d_rpc150012HmIP_RF] CB2010000002150012 received signal INT
2026.06.19 13:15:24.539 2: HMCCURPCPROC [d_rpc150012HmIP_RF] CB2010000002150012 received signal INT
2026.06.19 13:15:24.540 1: HMCCURPCPROC [d_rpc150012HmIP_RF] RPC server CB2010000002150012 stopped handling connections. PID=5366 run=0
2026.06.19 13:15:24.540 2: HMCCURPCPROC [d_rpc150012HmIP_RF] Number of I/O errors = 0
2026.06.19 13:15:26.540 2: HMCCURPCPROC [d_rpc150012HmIP_RF] RPC server process CB2010000002150012 deleted
2026.06.19 13:15:26.540 2: HMCCURPCPROC [d_rpc150012HmIP_RF] Stop I/O handling
2026.06.19 13:15:26.541 2: HMCCURPCPROC [d_rpc150012HmIP_RF] RPC server stopped. Cancel delayed shutdown.
2026.06.19 13:15:27.542 1: HMCCURPCPROC [d_rpc150012VirtualDevices] Stopping RPC server CB9292000002150012
2026.06.19 13:15:27.543 1: HMCCURPCPROC [d_rpc150012VirtualDevices] Deregistering RPC server http://172.17.0.2:14702/fh9292 with ID CB9292000002150012 at http://192.168.150.12:9292/groups
2026.06.19 13:15:27.553 1: HMCCURPCPROC [d_rpc150012VirtualDevices] Callback for RPC server CB9292000002150012 deregistered
2026.06.19 13:15:27.554 2: HMCCURPCPROC [d_rpc150012VirtualDevices] Sending signal INT to RPC server process CB9292000002150012 with PID=5364
2026.06.19 13:15:27.554 2: HMCCURPCPROC [d_rpc150012VirtualDevices] Cleaning up immediately
2026.06.19 13:15:27.554 1: HMCCURPCPROC [d_rpc150012VirtualDevices] Housekeeping called. Cleaning up RPC environment
2026.06.19 13:15:27.554 2: HMCCURPCPROC [d_rpc150012VirtualDevices] CB9292000002150012 received signal INT
2026.06.19 13:15:27.555 2: HMCCURPCPROC [d_rpc150012VirtualDevices] CB9292000002150012 received signal INT
2026.06.19 13:15:27.555 1: HMCCURPCPROC [d_rpc150012VirtualDevices] RPC server CB9292000002150012 stopped handling connections. PID=5364 run=0
2026.06.19 13:15:27.555 2: HMCCURPCPROC [d_rpc150012VirtualDevices] Number of I/O errors = 0
2026.06.19 13:15:29.555 2: HMCCURPCPROC [d_rpc150012VirtualDevices] RPC server process CB9292000002150012 deleted
2026.06.19 13:15:29.556 2: HMCCURPCPROC [d_rpc150012VirtualDevices] Stop I/O handling
2026.06.19 13:15:29.556 2: HMCCURPCPROC [d_rpc150012VirtualDevices] RPC server stopped. Cancel delayed shutdown.
2026.06.19 13:15:30.557 2: HMCCURPCPROC [d_rpc150012BidCos_RF] Found no running processes. Cleaning up ...
2026.06.19 13:15:30.557 1: HMCCURPCPROC [d_rpc150012BidCos_RF] Housekeeping called. Cleaning up RPC environment
2026.06.19 13:15:30.558 2: HMCCURPCPROC [d_rpc150012BidCos_RF] RPC server stopped. Cancel delayed shutdown.
2026.06.19 13:15:30.558 1: Server shutdown delayed due to d_rpc150012BidCos_RF,CCU3,d_rpc150012VirtualDevices,d_rpc150012HmIP_RF for max 10 sec
2026.06.19 13:15:40.572 0: Server shutdown
2026.06.19 13:15:40.572 1: HMCCU [CCU3] Graceful shutdown
2026.06.19 13:15:44.252 3: From the FHEM_GLOBALATTR environment: attr global updateInBackground 1
2026.06.19 13:15:44.253 3: From the FHEM_GLOBALATTR environment: attr global pidfilename log/fhem.pid
2026.06.19 13:15:44.253 3: From the FHEM_GLOBALATTR environment: attr global logfile log/fhem-%Y-%m-%d.log
2026.06.19 13:15:44.253 3: From the FHEM_GLOBALATTR environment: attr global nofork 0
2026.06.19 13:15:44.255 1: Including fhem.cfg
2026.06.19 13:15:44.398 3: WEB: port 8083 opened
2026.06.19 13:15:44.433 2: eventTypes: loaded 341 lines from ./log/eventTypes.txt
2026.06.19 13:15:45.510 1: HMCCU [CCU3] CCU port 8181 is reachable
2026.06.19 13:15:45.510 1: HMCCU [CCU3] Initialized version 2024-12
2026.06.19 13:15:45.511 1: HMCCU [CCU3] Initializing device
2026.06.19 13:15:45.609 3: HMCCU [CCU3] Updating device table
2026.06.19 13:15:45.612 1: HMCCU [CCU3] Can't read virtual groups from CCU. Response:
2026.06.19 13:15:45.634 1: HMCCU [CCU3] Read 30 devices with 245 channels, 8 programs, 0 virtual groups from CCU 192.168.150.12
2026.06.19 13:15:45.727 1: HMCCURPCPROC [d_rpc150012BidCos_RF] Initialized version 2024-12 for interface BidCos-RF with I/O device CCU3
2026.06.19 13:15:45.738 2: HMCCURPCPROC [d_rpc150012VirtualDevices] CCU interface VirtualDevices doesn't support RPC multicalls
2026.06.19 13:15:45.738 1: HMCCURPCPROC [d_rpc150012VirtualDevices] Initialized version 2024-12 for interface VirtualDevices with I/O device CCU3
2026.06.19 13:15:45.750 2: HMCCURPCPROC [d_rpc150012HmIP_RF] CCU interface HmIP-RF doesn't support RPC multicalls
2026.06.19 13:15:45.750 1: HMCCURPCPROC [d_rpc150012HmIP_RF] Initialized version 2024-12 for interface HmIP-RF with I/O device CCU3
2026.06.19 13:15:47.813 1: Including ./log/fhem.save
2026.06.19 13:15:47.829 3: From the FHEM_GLOBALATTR environment: attr global updateInBackground 1
2026.06.19 13:15:47.829 3: From the FHEM_GLOBALATTR environment: attr global pidfilename log/fhem.pid
2026.06.19 13:15:47.829 3: From the FHEM_GLOBALATTR environment: attr global logfile log/fhem-%Y-%m-%d.log
2026.06.19 13:15:47.829 3: From the FHEM_GLOBALATTR environment: attr global nofork 0
2026.06.19 13:15:47.830 1: Messages collected while initializing FHEM:SecurityCheck:
  WEB is not password protected

Protect this FHEM installation by defining an allowed device with define allowed allowed
You can disable this message with attr global motd none

2026.06.19 13:15:47.830 0: HMCCU [CCU3] Scheduling post FHEM initialization tasks in 12 seconds
2026.06.19 13:15:47.936 1: usb create starting
2026.06.19 13:15:48.010 1: usb create end
2026.06.19 13:15:48.010 0: Featurelevel: 6.4
2026.06.19 13:15:48.010 0: Server started with 29 defined entities (fhem.pl:31310/2026-05-28 perl:5.038005 os:linux user:fhem pid:13301)
2026.06.19 13:15:48.820 3: telnetForBlockingFn_1781867748.81421: port 35016 opened
2026.06.19 13:15:48.826 3: [ug.fl.fritzbox||154.08.25|Readout_API_Check.10399] - BASIC:boxUser for checkAPIs: fritz0720
2026.06.19 13:15:48.854 3: [ug.fl.fritzbox|FRITZ!Box 7590|154.08.25|Readout_API_Check.10502] - BASIC:Read 'jason_boxinfo.xml' from 192.168.150.1
2026.06.19 13:15:50.237 3: [ug.fl.fritzbox|FRITZ!Box 7590|154.08.25|Readout_API_Check.10719] - BASIC:boxUser is set to: fritz0720
2026.06.19 13:15:53.464 3: [ug.fl.fritzbox|FRITZ!Box 7590|154.08.25|Readout_API_Check.11029] - BASIC:open Web_Connection succeeded
2026.06.19 13:15:59.832 1: HMCCU [CCU3] Reading device config from CCU. This may take a couple of seconds ...
2026.06.19 13:15:59.832 2: HMCCU [CCU3] Reading device configuration for interfaces HmIP-RF,VirtualDevices,BidCos-RF
2026.06.19 13:16:02.627 2: HMCCURPCPROC [d_rpc150012VirtualDevices] Can't get device description for address HU-Philips hue
2026.06.19 13:16:02.627 2: HMCCURPCPROC [d_rpc150012VirtualDevices] Can't get device description for address HU-Spieltisc03
2026.06.19 13:16:02.627 2: HMCCURPCPROC [d_rpc150012VirtualDevices] Can't get device description for address HU-Spieltisc02
2026.06.19 13:16:02.627 2: HMCCURPCPROC [d_rpc150012VirtualDevices] Can't get device description for address HU-Spieltisch
2026.06.19 13:16:02.628 2: HMCCURPCPROC [d_rpc150012VirtualDevices] Can't get device description for address HU-Spieltisc01
2026.06.19 13:16:04.032 2: HMCCU [CCU3] Read descriptions of 275 devices, 601 paramsets, 15 links
2026.06.19 13:16:04.032 2: HMCCU [CCU3] Detecting devices of interfaces BidCos-RF,HmIP-RF,VirtualDevices
2026.06.19 13:16:04.050 2: HMCCU [CCU3] Read device configuration in 4.21750211715698 seconds: devices/channels=275 parametersets=601 links=15
2026.06.19 13:16:04.050 2: HMCCU [CCU3] RPC device for interface HmIP-RF: d_rpc150012HmIP_RF
2026.06.19 13:16:04.050 2: HMCCU [CCU3] RPC device for interface BidCos-RF: d_rpc150012BidCos_RF
2026.06.19 13:16:04.050 2: HMCCU [CCU3] RPC device for interface VirtualDevices: d_rpc150012VirtualDevices
2026.06.19 13:16:04.054 2: HMCCURPCPROC [d_rpc150012HmIP_RF] RPC server process started for interface HmIP-RF with PID=13371
2026.06.19 13:16:04.055 2: HMCCURPCPROC [d_rpc150012HmIP_RF] Initializing RPC server CB2010000002150012 for interface HmIP-RF
2026.06.19 13:16:04.057 1: HMCCURPCPROC [d_rpc150012HmIP_RF] RPC server starting
2026.06.19 13:16:04.062 2: HMCCURPCPROC [d_rpc150012BidCos_RF] RPC server process started for interface BidCos-RF with PID=13372
2026.06.19 13:16:04.062 2: HMCCURPCPROC [d_rpc150012BidCos_RF] Initializing RPC server CB2001000002150012 for interface BidCos-RF
2026.06.19 13:16:04.064 1: HMCCURPCPROC [d_rpc150012BidCos_RF] RPC server starting
2026.06.19 13:16:04.069 2: HMCCURPCPROC [d_rpc150012VirtualDevices] RPC server process started for interface VirtualDevices with PID=13373
2026.06.19 13:16:04.070 2: HMCCURPCPROC [d_rpc150012VirtualDevices] Initializing RPC server CB9292000002150012 for interface VirtualDevices
2026.06.19 13:16:04.071 1: HMCCURPCPROC [d_rpc150012VirtualDevices] RPC server starting
2026.06.19 13:16:04.072 2: HMCCU [CCU3] RPC server start: 3 started, 0 already running, 0 failed to start
2026.06.19 13:16:04.082 2: HMCCURPCPROC [d_rpc150012HmIP_RF] Callback server CB2010000002150012 created. Listening on port 7420
2026.06.19 13:16:04.082 2: HMCCURPCPROC [d_rpc150012HmIP_RF] CB2010000002150012 accepting connections. PID=13371
2026.06.19 13:16:04.084 2: HMCCURPCPROC [d_rpc150012HmIP_RF] RPC server CB2010000002150012 enters server loop
2026.06.19 13:16:04.085 2: HMCCURPCPROC [d_rpc150012HmIP_RF] Registering callback http://172.17.0.2:7420/fh2010 of type A with ID CB2010000002150012 at http://192.168.150.12:2010
2026.06.19 13:16:04.091 2: HMCCURPCPROC [d_rpc150012BidCos_RF] Callback server CB2001000002150012 created. Listening on port 7411
2026.06.19 13:16:04.092 2: HMCCURPCPROC [d_rpc150012BidCos_RF] CB2001000002150012 accepting connections. PID=13372
2026.06.19 13:16:04.095 2: HMCCURPCPROC [d_rpc150012VirtualDevices] Callback server CB9292000002150012 created. Listening on port 14702
2026.06.19 13:16:04.096 2: HMCCURPCPROC [d_rpc150012VirtualDevices] CB9292000002150012 accepting connections. PID=13373
2026.06.19 13:16:04.099 1: HMCCURPCPROC [d_rpc150012HmIP_RF] RPC server CB2010000002150012 running
2026.06.19 13:16:04.102 2: HMCCURPCPROC [d_rpc150012BidCos_RF] RPC server CB2001000002150012 enters server loop
2026.06.19 13:16:04.102 2: HMCCURPCPROC [d_rpc150012BidCos_RF] Registering callback http://172.17.0.2:7411/fh2001 of type A with ID CB2001000002150012 at http://192.168.150.12:2001
2026.06.19 13:19:04.171 2: HMCCURPCPROC [d_rpc150012BidCos_RF] RPC request init failed: RPC::XML::Client::simple_request: RPC::XML::Client::send_request: HTTP server error: read timeout
2026.06.19 13:19:04.171 2: HMCCURPCPROC [d_rpc150012BidCos_RF] Retrying request init
2026.06.19 13:22:04.253 2: HMCCURPCPROC [d_rpc150012BidCos_RF] RPC request init failed: RPC::XML::Client::simple_request: RPC::XML::Client::send_request: HTTP server error: read timeout
2026.06.19 13:22:04.253 2: HMCCURPCPROC [d_rpc150012BidCos_RF] Retrying request init
2026.06.19 13:22:04.254 1: HMCCURPCPROC [d_rpc150012BidCos_RF] Failed to register callback for ID CB2001000002150012: RPC request init failed: RPC::XML::Client::simple_request: RPC::XML::Client::send_request: HTTP server error: read timeout
2026.06.19 13:22:04.256 2: HMCCURPCPROC [d_rpc150012VirtualDevices] RPC server CB9292000002150012 enters server loop
2026.06.19 13:22:04.256 2: HMCCURPCPROC [d_rpc150012VirtualDevices] Registering callback http://172.17.0.2:14702/fh9292 of type A with ID CB9292000002150012 at http://192.168.150.12:9292/groups
2026.06.19 13:22:14.267 1: HMCCURPCPROC [d_rpc150012VirtualDevices] RPC server CB9292000002150012 running
2026.06.19 13:22:14.270 2: HMCCURPCPROC [d_rpc150012BidCos_RF] Checking if RPC server process is running
2026.06.19 13:22:14.270 1: HMCCURPCPROC [d_rpc150012BidCos_RF] RPC server process not running. Cleaning up
2026.06.19 13:22:14.270 1: HMCCURPCPROC [d_rpc150012BidCos_RF] Housekeeping called. Cleaning up RPC environment
2026.06.19 13:22:14.270 2: HMCCURPCPROC [d_rpc150012BidCos_RF] Sending signal INT to RPC server process CB2001000002150012 with PID=13372
2026.06.19 13:22:14.271 2: HMCCURPCPROC [d_rpc150012BidCos_RF] CB2001000002150012 received signal INT
2026.06.19 13:22:14.271 1: HMCCURPCPROC [d_rpc150012BidCos_RF] RPC server CB2001000002150012 stopped handling connections. PID=13372 run=0
2026.06.19 13:22:14.271 2: HMCCURPCPROC [d_rpc150012BidCos_RF] Number of I/O errors = 0
2026.06.19 13:22:16.272 2: HMCCURPCPROC [d_rpc150012BidCos_RF] RPC server process CB2001000002150012 deleted
2026.06.19 13:22:16.272 2: HMCCURPCPROC [d_rpc150012BidCos_RF] Stop I/O handling
2026.06.19 13:22:16.273 2: HMCCURPCPROC [d_rpc150012BidCos_RF] RPC server stopped. Cancel delayed shutdown.
Titel: Aw: RPC Server startet nicht (mehr)
Beitrag von: Ralli am 19 Juni 2026, 14:54:58
Ja, genau daran liegt es.

In der Hilfe von HMCCU steht

rpcserveraddr <ip-or-name>
Specify network interface by IP address or DNS name where RPC server should listen on.
By default HMCCU automatically detects the IP address.
This attribute should be used if the FHEM server has more than one network interface.

Im Container kennt HMCCU nur die interne IP, daher gibt HMCCU diese auch an die CCU "als Rückrufadresse". Dementsprechend wird da nie was ankommen trotz Port-Weiterleitung. Trage mal die IP des Hosts bei dem Attribut ein.
Titel: Aw: RPC Server startet nicht (mehr)
Beitrag von: selfarian am 19 Juni 2026, 15:20:24
Oh man... danke Dir! Ich hatte irgendwie schon gedacht, dass es etwas "einfaches" ist, aber da hatte ich Tomaten auf den Augen.

Vielen Dank nochmal!