HMCCURPC: Multithreaded RPC Server für HMCCU

[Chris8888]

Hallo Zap,

danke für deine Mühe!!!!

Firewalleinstellung habe ich geändert, leider ohne Erfolg. Ich versuche die Tage nochmal einen kompletten Reboot.
In der CCU habe ich keine Geräte mit Leerzeichen in den Namen. Ich verwende immer - oder _ dazwischen.

Dann lebe ich damit wohl erst einmal bzw nutze den internen Server wieder.

Wenn du noch eine Idee hast...gerne her damit!

Viele Grüße
Christian

[zap]

Das sieht aber schon nach Leerzeichen aus:

Name=HmIP-WTH-2 000A9569A3A519:1

Nach WTH-2

[Chris8888]

Hallo Zap,

das verstehe ich nicht. Alle meine CCU-Devices haben Namen ohne Leerzeichen.
Bei den einzelnen Kanälen (in deinem Beispiel Kanal 1 meines Wohnzimmer-Thermostats) habe ich die Namen tatsächlich nie angepasst.
Ist das auch notwendig? Die Kanäle spreche ich doch nirgends im Fhem überhaupt an. Die sehe ich doch noch nicht einmal einzeln, oder?

Kannst du mir da auf die Spünge helfen?

Danke!

VG
Christian

PS Gestern Abend ist anscheinend FHEM komplett ausgestiegen. Meine Rollos waren heute morgen noch oben.
Das Log war voll mit diesen Einträgen:
CCURPC: CB2010 maximum queue size reached
CCURPC: Size of event queue exceeds 500

FHEM hat nicht mehr reagiert und ich musste den PI komplett neu starten.
Eine Idee dazu?

[zap]

Datenpunkte sind immer Kanälen zugeordnet und werden daher auch über Kanäle angesprochen. Allerdings verwendet HMCCU dafür die Adresse und nicht den Namen. Daher spielen Leerzeichen im Namen eigntlich keine Rolle. Meine Kanäle haben teilweise auch Leerzeichen und es funktioniert alles. War nur der berühmte letzte Strohhalm.

Die Meldung mit der vollen Queue ist die Wirkung, nicht die Ursache. Die kommt von einem der Threadsnim Hintergrund und meint eigentlich nur, dass FHEM keine Daten mehr abholt. Ursache ist ebene, dass FHEM offensichtlich ausgestiegen ist.

Ich kann mir das alles nicht erklären. Du bist anscheinend der einzige, der diese Probleme hat. Vielleicht liegt es auch an einem anderen Device. Sonst keine Fehler im Log?

Heute oder morgen gibt es eine neue Version. Mach halt mal das Update. Vielleicht hilft es ja.


Auch diese Connection lost Meldungen sind seltsam.

Mein FHEM läuft momentan mit 4 RPC Schnittstellen zur CCU. Darüber melden >60 Geräte mit fast 400 Kanälen ihre Infos an FHEM ohne irgendwelche Hänger oder Performance Probleme. Alles auf einem Raspi 3, der zusätzlich noch einen Apache Webserver drauf hat.

[Chris8888]

Hallo Zap,

kann es ggf. etwas damit zu tun haben das ich nur HmIP-Devices an der CCU habe?
"Normale" HM-Geräte hängen direkt in FHEM. D.h. mein Server läuft nur noch auf Port 2010.

Der Absturz könnte damit zu tun haben das ich an dem Abend meine FAL (Ansteuerung Fussbodenheizung) upgedatet habe.
Das Gerät hat nach dem Reboot normal weitergearbeitet, in der CCU und FHEM sah alles gut aus.
Ich habe dann gestern noch den geplanten Reboot zwecks Aktivierung der Firewall-Regeln durchgeführt, danach war die FAL im Geräteeingang und ich musste es neu akzeptieren. Ich schätze, die FAL ist durch das Update da irgendwie aus der Konfiguration gepflogen und dadurch konnte FHEM/HMCCU nicht mehr sauber darauf zugreifen.

Jetzt sieht alles wieder normal aus.

Aber das Thema "Connection lost" bei ext. Server bleibt.
Andere Fehler habe ich im Log nicht. Alles läuft wie gewohnt extrem stabil.
Dann muss ich halt mit dem int. Server leben, der tut ja auch was er soll.

Viele Grüße
Christian

[mrfloppy]

Habe gestern auf den extRPC umgestellt.
Wollte nur Feedback geben und danke sagen fürs Modul.
Hat auf Anhieb geklappt. Keine Probleme feststellbar.
Außer einmal hatte ich heute

Code Auswählen Erweitern

2017.04.20 08:34:58 2: CCURPC: I/O error during data processing (Select found no reader
sonst bleibt das Logfile leer.

LG Thomas

[zap]

Die Meldung kann ab und zu mal kommen, wenn FHEM sehr beschäftigt ist und die RPC Server Threads ihre Daten nicht los bekommen. Es gehen aber keine Daten verloren, da alle CCU Events in einer Queue gepuffert werden. Die Daten werden dann bei nächster Gelegenheit übermittelt.

[Ralli]

Auf einer alternativen fhem-Installation habe ich versuchsweise HMCCU mit neuem HMRPC installiert. Folgender "Fehler" in Verbindung mit HMW taucht auf, allerdings kommen die Events rein, wie es sein soll:

Code Auswählen Erweitern


2017.04.22 08:05:27.774 1: HMCCURPC: Received IN event. RPC server CB2000 running.
2017.04.22 08:05:27.884 2: CCURPC: CB2000 NewDevice received 94 device specifications
2017.04.22 08:05:27.885 1: PERL WARNING: Use of uninitialized value in concatenation (.) or string at ./FHEM/88_HMCCURPC.pm line 2106.
2017.04.22 08:05:27.924 2: HMCCURPC: Wrong number of parameters in event ND|CB2000|D|BidCoS-Wir|HMW-RCV-50|3|2.27.8|. Expected 6
2017.04.22 08:05:28.034 2: HMCCURPC: Wrong number of parameters in event ND|CB2000|D|HMW123456|HMW-IO-12-Sw14-DR|12|1.00|. Expected
2017.04.22 08:05:28.035 2: HMCCURPC: Wrong number of parameters in event ND|CB2000|D|HMW654321|HMW-Sen-SC-12-DR|7|3.01|. Expected 6
2017.04.22 08:05:29.262 1: PERL WARNING: Use of uninitialized value $par[1] in hash element at ./FHEM/88_HMCCURPC.pm line 619.


[zap]

Muss ich mir im Detail mal anschauen. Ich habe keine Wired Devices und daher ist diese Schnittstelle für mich etwas Entwicklung im Blindflug. Das Log von dir hilft hier definitv weiter. Anscheinend unterscheiden sich die Wired Events etwas von den anderen.
Scheint aber nur für die NewDevice Events zu gelten, daher funktioniert die Aktualisierung der Datenpunkte bzw Readings

[smart.builder]

Hallo,

der RPC-Server funktionierte auf meinem Raspberry bisher einwandfrei. Nun habe ich mein Fhem auf einen größeren Server umgezogen.
Es läuft alles in einem Docker-Container.
Leider bekomme ich den RPC-Server nicht zum laufen. Sowohl intrpc als auch extrpc startet nicht.

Ich bekomme mit verbose 5 folgende Logeinträge:

Code Auswählen Erweitern


2017.09.14 18:03:20 2: HMCCURPC: Starting thread for data processing
2017.09.14 18:03:20 2: HMCCURPC: Started thread for data processing. TID=4
2017.09.14 18:03:20 2: CCURPC: Thread DATA processing RPC events. TID=4
2017.09.14 18:03:20 2: HMCCURPC: RPC server thread started for interface BidCos-RF with TID=5
2017.09.14 18:03:20 2: CCURPC: Initializing RPC server CB2001 for interface BidCos-RF
2017.09.14 18:03:20 2: HMCCURPC: Callback server CB2001 created. Listening on port 7411
2017.09.14 18:03:20 2: CCURPC: CB2001 accepting connections. TID=5
2017.09.14 18:03:20 2: CCURPC: Initializing RPC server CB2010 for interface HmIP-RF
2017.09.14 18:03:20 2: HMCCURPC: RPC server thread started for interface HmIP-RF with TID=6
2017.09.14 18:03:20 2: HMCCURPC: Callback server CB2010 created. Listening on port 7420
2017.09.14 18:03:20 2: CCURPC: CB2010 accepting connections. TID=6
2017.09.14 18:03:21 1: HMCCURPC: RPC server(s) starting
2017.09.14 18:03:21 1: HMCCURPC: Received SL event. RPC server DATA enters server loop
2017.09.14 18:03:21 1: HMCCURPC: Received SL event. RPC server CB2001 enters server loop
2017.09.14 18:03:21 1: HMCCURPC: Received SL event. RPC server CB2010 enters server loop
2017.09.14 18:03:21 1: HMCCURPC: All threads working
2017.09.14 18:03:21 2: HMCCURPC: Registering callback http://172.19.0.3:7411/fh2001 with ID CB2001 at http://192.168.178.62:2001/
2017.09.14 18:03:21 1: HMCCURPC: RPC callback with URL http://172.19.0.3:7411/fh2001 registered
2017.09.14 18:03:21 2: HMCCURPC: Registering callback http://172.19.0.3:7420/fh2010 with ID CB2010 at http://192.168.178.62:2010/
2017.09.14 18:03:21 1: HMCCURPC: RPC callback with URL http://172.19.0.3:7420/fh2010 registered
2017.09.14 18:04:11 2: HMCCURPC: Checking if all threads are running
2017.09.14 18:04:11 1: HMCCURPC: Only 1 of 3 threads are running. Cleaning up
2017.09.14 18:04:11 1: HMCCURPC: Housekeeping called. Cleaning up RPC environment
2017.09.14 18:04:11 1: HMCCURPC: Deregistering RPC server http://172.19.0.3:7420/fh2010 with ID CB2010 at http://192.168.178.62:2010/
2017.09.14 18:04:11 1: HMCCURPC: RPC callback for server CB2010 deregistered
2017.09.14 18:04:11 1: HMCCURPC: Deregistering RPC server http://172.19.0.3:7411/fh2001 with ID CB2001 at http://192.168.178.62:2001/
2017.09.14 18:04:11 1: HMCCURPC: RPC callback for server CB2001 deregistered
2017.09.14 18:04:11 2: HMCCURPC: Stop I/O handling
2017.09.14 18:04:11 2: HMCCURPC: Close child socket
2017.09.14 18:04:11 2: HMCCURPC: Close parent socket
2017.09.14 18:04:11 2: HMCCURPC: Sending signal INT to thread CB2010 TID=6
2017.09.14 18:04:11 2: HMCCURPC: Sending signal INT to thread DATA TID=4
2017.09.14 18:04:11 2: HMCCURPC: Sending signal INT to thread CB2001 TID=5
2017.09.14 18:04:11 2: CCURPC: DATA stopped event processing. TID=4
2017.09.14 18:04:11 2: CCURPC: RPC server CB2010 stopped handling connections. TID=6
2017.09.14 18:04:12 2: CCURPC: RPC server CB2001 stopped handling connections. TID=5
2017.09.14 18:04:13 2: HMCCURPC: Thread CB2010 with TID=6 is in state stopping. Can't delete it
2017.09.14 18:04:13 2: HMCCURPC: Thread DATA with TID=4 is in state stopping. Can't delete it
2017.09.14 18:04:13 2: HMCCURPC: Thread CB2001 with TID=5 is in state stopping. Can't delete it
   
 
Beim Docker-Container sind die Ports 2000, 2001, 2010, 5544, 8701 freigegeben.
Innerhalb des Containers ist die IP des eth0: 172.19.0.3 
Der Docker-Host hat nach außen hin die IP-Adresse: 192.168.178.61

Beim iobroker gab es anscheinend eine ähnliche Problematik: https://github.com/ioBroker/ioBroker.hm-rpc/issues/37

Kann man da was machen?
Danke!

Gruß
Viktor

[Rewe2000]

Hallo,

habe gestern auch HMCCURPC installiert (Über das I/O Device), nach anfänglichen Problemen mit der Nachinstallation von den Perl Modulen (@betateilchen sei Dank) hat es dann geklappt.
Ein deutlicher Geschwindigkeitsgewinn war sofort feststellbar, alles lief ohne Fehler, so wie es sein sollte.
Auch nach einem "shutdown restart" lief die Kommunikation den ganzen Abend Fehlerfrei.

Danach habe ich in Fhem noch ein "update all" (nach ca einer Woche) ausgeführt, auch nach dem "shutdown restart" tauchten keinerlei Fehler auf.

Dachte mir, jetzt bring ich noch meinen Raspi auf den aktuellen Stand (letztes fehlerfreies Update vor ca. 1 Woche). Nachdem das Update ohne Fehler durchgeführt wurde, habe ich "sudo reboot" ausgeführt.

Folgendes Verhalten lässt sich bei mir immer reproduzieren, nachdem ich den Raspi mit:

Code Auswählen Erweitern

sudo /etc/init.d/fhem stop
sudo reboot

neustarte.

Die WEBserver von Fhem ist zunächst verfügbar (ca. 10-30 Sekunden).
Eine Abfrage vom Raspi aus ergibt:

Code Auswählen Erweitern

sudo /etc/init.d/fhem status
fhem is running

Nach ca. 30 Sekunden ist dieser nicht mehr erreichbar und eine Abrage über Raspi ergibt:

Code Auswählen Erweitern

sudo /etc/init.d/fhem status
fhem is not running

Starte ich dann den Fhem wieder über den Raspi, läuft es absolut Problemlos und ohne Fehler im Log seit über einen Tag.

Code Auswählen Erweitern

sudo /etc/init.d/fhem start
fhem is running

Nur beim Neustart des Raspi gibt es diese anfänglichen Probleme. Das Log zeigt zum Zeitpunkt des Fehlers folgende Einträge in Verbose 2:

Code Auswählen Erweitern

2017.10.11 21:33:30 1: Perfmon: possible freeze starting at 21:33:29, delay is 1.969
2017.10.11 21:40:53 0: Server shutdown
2017.10.11 21:40:53 1: HMCCURPC: Found 3 threads. Stopping ...
2017.10.11 21:40:53 1: HMCCURPC: Deregistering RPC server http://192.168.1.33:7420/fh2010 with ID CB2010 at http://192.168.1.32:2010/
2017.10.11 21:40:53 1: HMCCURPC: RPC callback for server CB2010 deregistered
2017.10.11 21:40:53 1: HMCCURPC: Deregistering RPC server http://192.168.1.33:7411/fh2001 with ID CB2001 at http://192.168.1.32:2001/
2017.10.11 21:40:53 1: HMCCURPC: RPC callback for server CB2001 deregistered
2017.10.11 21:40:53 2: HMCCURPC: Sending signal INT to thread CB2010 TID=3
2017.10.11 21:40:53 2: HMCCURPC: Sending signal INT to thread CB2001 TID=2
2017.10.11 21:40:54 2: CCURPC: RPC server CB2010 stopped handling connections. TID=3
2017.10.11 21:40:54 2: CCURPC: RPC server CB2001 stopped handling connections. TID=2
2017.10.11 21:40:54 1: HMCCURPC: Found 1 threads. Stopping ...
2017.10.11 21:42:26 2: HMCCU: Received no events from interface CB2001 for 29557496.5880101 seconds
Can't locate object method "HMCCURPC_RPC_NUMPORT" via package "2001" (perhaps you forgot to load "2001"?) at ./FHEM/88_HMCCURPC.pm line 654.
2017.10.11 21:44:40 2: Perfmon: ready to watch out for delays greater than one second
2017.10.11 21:44:40 1: Including fhem.cfg
2017.10.11 21:44:41 2: eventTypes: loaded 3244 events from ./log/eventTypes.txt
2017.10.11 21:44:41 2: Switched COC rfmode to HomeMatic
2017.10.11 21:44:43 1: HMCCU: Device CCU2. Initialized version 4.1.001
2017.10.11 21:44:47 1: HMCCU: Read 51 devices with 237 channels from CCU 192.168.1.32
2017.10.11 21:44:49 1: HMCCURPC: Device CCU2_rpc. Initialized version 0.96 beta
2017.10.11 21:44:49 1: Including ./log/fhem.save
2017.10.11 21:44:50 0: HMCCU: Start of RPC server after FHEM initialization in 12 seconds
2017.10.11 21:44:50 1: usb create starting
2017.10.11 21:44:50 1: usb create end
2017.10.11 21:44:50 0: Featurelevel: 5.8
2017.10.11 21:44:50 0: Server started with 271 defined entities (fhem.pl:15182/2017-10-03 perl:5.024001 os:linux user:fhem pid:1413)
2017.10.11 21:44:50 1: Perfmon: possible freeze starting at 21:44:41, delay is 9.991
2017.10.11 21:44:51 1: PERL WARNING: Use of uninitialized value in numeric eq (==) at ./FHEM/36_ModbusTCPServer.pm line 342.
2017.10.11 21:44:51 1: ModbusTCPServer_Parse: bad frame, sent: SimpleWrite [20 10 00 00 00 06] 00 03 20 10 00 05
2017.10.11 21:44:51 1: ModbusTCPServer_Parse: bad frame, received:  [20 10 00 00 00 03] 00 83 02
2017.10.11 21:45:02 2: HMCCURPC: Starting thread for data processing
2017.10.11 21:45:02 2: HMCCURPC: Started thread for data processing. TID=1
2017.10.11 21:45:02 2: CCURPC: Thread DATA processing RPC events. TID=1
2017.10.11 21:45:03 2: HMCCURPC: RPC server thread started for interface BidCos-RF with TID=2
2017.10.11 21:45:03 2: CCURPC: Initializing RPC server CB2001 for interface BidCos-RF
2017.10.11 21:45:03 2: HMCCURPC: Callback server CB2001 created. Listening on port 7411
2017.10.11 21:45:03 2: CCURPC: CB2001 accepting connections. TID=2
2017.10.11 21:45:03 2: HMCCURPC: RPC server thread started for interface HmIP-RF with TID=3
2017.10.11 21:45:03 2: CCURPC: Initializing RPC server CB2010 for interface HmIP-RF
2017.10.11 21:45:03 2: HMCCURPC: Callback server CB2010 created. Listening on port 7420
2017.10.11 21:45:03 2: CCURPC: CB2010 accepting connections. TID=3
2017.10.11 21:45:04 1: HMCCURPC: RPC server(s) starting
2017.10.11 21:45:04 1: HMCCURPC: Received SL event. RPC server DATA enters server loop
2017.10.11 21:45:04 1: HMCCURPC: Received SL event. RPC server CB2001 enters server loop
2017.10.11 21:45:04 1: HMCCURPC: Received SL event. RPC server CB2010 enters server loop
2017.10.11 21:45:04 1: HMCCURPC: All threads working
2017.10.11 21:45:04 2: HMCCURPC: Registering callback http://192.168.1.33:7411/fh2001 with ID CB2001 at http://192.168.1.32:2001/
2017.10.11 21:45:04 1: CCURPC: CB2001 ListDevices. Sending init to HMCCU
2017.10.11 21:45:05 1: HMCCURPC: RPC callback with URL http://192.168.1.33:7411/fh2001 registered
2017.10.11 21:45:05 2: HMCCURPC: Registering callback http://192.168.1.33:7420/fh2010 with ID CB2010 at http://192.168.1.32:2010/
2017.10.11 21:45:05 1: HMCCURPC: RPC callback with URL http://192.168.1.33:7420/fh2010 registered
2017.10.11 21:45:05 1: HMCCURPC: Received IN event. RPC server CB2001 running.
2017.10.11 21:45:05 1: Perfmon: possible freeze starting at 21:45:03, delay is 2.103
2017.10.11 21:45:05 2: CCURPC: CB2001 NewDevice received 69 device and channel specifications
2017.10.11 21:45:05 1: CCURPC: CB2010 ListDevices. Sending init to HMCCU
2017.10.11 21:45:05 1: HMCCURPC: Received IN event. RPC server CB2010 running.
2017.10.11 21:45:05 1: HMCCURPC: All RPC servers running
2017.10.11 21:45:07 2: CCURPC: CB2010 NewDevice received 219 device and channel specifications
2017.10.11 21:45:08 2: HMCCURPC: Updated devices. Success=52 Failed=0


Das Problem tritt definitiv nur beim Neustart des Raspi auf, starte ich danach Fhem über den Raspi neu, läuft Fhem ohne Fehler weiter.

Habt ihr eine Idee woran dies liegen könnte, braucht ihr noch mehr Infos?

Gruß Reinhard

[zap]

Das ist ein Bug in HMCCURPC, der nur in wenigen Fällen auftritt. Daher ist das bisher nicht aufgefallen. Wird zeitnah behoben.

[Rewe2000]

Hallo zap,

nur noch ein kurzer Hinweis, ev. hilft es noch für die Fehlerbehebung (in der alten HMCCURPC - Version).

Der Fehler tritt in gleicher Weise bei mir auf, wenn ich bei laufendem Fhem und RPC Server die CCU2 (habe nur Hardware) neu starte.
Bis Fhem stoppt, kann ich noch HmIP Schalter über Fhem bedienen, aber die Readings (z.B. 4.State) wird dabei nicht mehr aktualisiert.

Gruß Reinhard

[Axxl]

Hallo,

der RPC-Server funktionierte auf meinem Raspberry bisher einwandfrei. Nun habe ich mein Fhem auf einen größeren Server umgezogen.
Es läuft alles in einem Docker-Container.
Leider bekomme ich den RPC-Server nicht zum laufen. Sowohl intrpc als auch extrpc startet nicht.

+1
Ich habe genau das gleiche Problem. Im Docker Container bekomme ich den RPC Server auch nicht zum laufen.

[zap]

Es ist immer hilfreich, wenn ihr bei solchen Problemen die wahrscheinlich vorhandenen Fehlermeldungen im FHEM Logfile mitliefert. Bei einer neuen Linux Installation würde ich erst mal vermuten, dass Perl Module fehlen. Wenn es das nicht ist, kann man das Loglevel beim externen RPC Server auf 4 setzen, dann wird er wesentlich geschwätziger.