Hallo zusammen,
seit ein paar Tagen stürzt nach der Fehlermeldung (im Log)
CCURPC: [d_rpcBidCos_RF] Sending data to FHEM failed 100 times. select found no reader
mein FHEM (auf 2 unterschiedlichen Systemen) komplett ab und die Web-Oberfläche ist nicht mehr erreichbar.
Die CCU2 selber funktioniert weiterhin und kann (z.B. duch iobroker) gesteuert werden.
Hier ein List der CCU2 (ohne die Devices, IP-Adressen geändert):
Internals:
CCUNum 1
Clients :HMCCUDEV:HMCCUCHN:HMCCURPC:HMCCURPCPROC:
DEF 192.168.xx.yy
NAME ccu2
NR 76
NTFY_ORDER 50-ccu2
RPCState error
STATE rpcserver: OK
TYPE HMCCU
ccuaddr BidCoS-RF
ccuchannels 256
ccudevices 33
ccuif BidCos-RF
ccuinterfaces System,HmIP-RF,CUxD,BidCos-RF,BidCos-Wired,VirtualDevices
ccuip 192.168.xx.yy
ccuname HM-RCV-50 BidCoS-RF
ccustate active
ccutype CCU2
host 192.168.xx.yy
version 4.2.003
.attraggr:
.attreocr:
.*
.attrminint:
READINGS:
2018-03-28 18:09:00 AZi_Hzg_Sommerbetrieb true
2018-03-28 18:09:00 Anwesenheit true
2018-03-28 18:09:00 CCU_Status false
2018-03-28 18:09:00 Einschaltzeit 0
2018-03-28 18:09:00 Erster_Advent nicht erreicht
2018-03-28 18:09:00 Feiertag_heute false
2018-03-28 18:09:00 Feiertag_morgen false
2018-03-28 18:09:00 Frei_ganztags false
2018-03-28 18:09:00 Fruehdienst true
2018-03-28 18:09:00 HUE1 false
2018-03-28 18:09:00 HUE2 false
2018-03-28 18:09:00 HUE3 false
2018-03-28 18:09:00 Monat_Zahl 3
2018-03-28 18:09:00 Regen_gestern 7.375
2018-03-28 18:09:00 Regen_heute 9.145
2018-03-28 18:09:00 Sommerzeit true
2018-03-28 18:09:00 Sonn_Aufgang 7.14
2018-03-28 18:09:00 Sonn_Untergang 19.56
2018-03-28 18:09:00 Spaetdienst false
2018-03-28 18:09:00 Systemvariable_TMP true
2018-03-28 18:09:00 Time_SunRise 07:14
2018-03-28 18:09:00 Time_SunSet 19:56
2018-03-28 18:09:00 Urlaub false
2018-03-28 18:09:00 Ventilstatus_ArbZi 86
2018-03-28 18:09:00 WBaum_steht false
2018-03-28 18:09:00 Weihn_EU false
2018-03-28 18:09:00 Weihnachtszeit false
2018-03-28 18:09:00 Weihnachtszeit_Ende nicht erreicht
2018-03-28 18:09:00 Windrichtung 20 Grad - N
2018-03-28 18:09:00 Wochenende false
2018-03-28 18:08:30 battery_count 0
2018-03-28 18:08:30 battery_list Batterien OK
2018-03-28 18:08:30 battery_match 0
2018-03-28 18:08:30 battery_state ok
2018-03-28 18:09:00 max__LF_AZi 58
2018-03-28 18:09:00 max__LF_Db 58
2018-03-28 18:09:00 max__LF_Terr 96
2018-03-28 18:09:00 max__LF_Wohnz 48
2018-03-28 18:09:00 max__Temp_AZi 21.7
2018-03-28 18:09:00 max__Temp_Db 15.3
2018-03-28 18:09:00 max__Temp_Terr 8.9
2018-03-28 18:09:00 max__Temp_Wohnz 22.8
2018-03-28 18:09:00 min__LF_AZi 53
2018-03-28 18:09:00 min__LF_Db 55
2018-03-28 18:09:00 min__LF_Terr 89
2018-03-28 18:09:00 min__LF_Wohnz 47
2018-03-28 18:09:00 min__Temp_AZi 18.6
2018-03-28 18:09:00 min__Temp_Db 14.5
2018-03-28 18:09:00 min__Temp_Terr 5.8
2018-03-28 18:09:00 min__Temp_Wohnz 21.7
2018-03-28 18:02:25 rpcstate error
2018-03-28 18:09:00 sonne_azimut 254.1
2018-03-28 18:09:00 sonne_elevation 15.3
2018-03-28 18:03:00 state OK
hmccu:
evtime 0
evtimeout 0
rpccount 0
rpcports 2001,8701,9292
updatetime 0
adr:
Bad_Waschtisch_Lampe:
address HEQ0159327:1
addtype chn
valid 1
....
ifports:
2000 BidCos-Wired
2001 BidCos-RF
2002 System
2010 HmIP-RF
8701 CUxD
9292 VirtualDevices
interfaces:
BidCos-RF:
device d_rpcBidCos_RF
flags forceASCII
host 192.168.xx.yy
manager HMCCU
port 2001
prot http
state error
type A
url http://192.168.xx.yy:2001
BidCos-Wired:
flags forceASCII
host 192.168.xx.yy
manager null
port 2000
prot http
state inactive
type A
url http://192.168.xx.yy:2000
CUxD:
device d_rpcCUxD
flags forceInit
host 192.168.xx.yy
manager HMCCU
port 8701
prot xmlrpc_bin
state error
type B
url xmlrpc_bin://192.168.xx.yy:8701
HmIP-RF:
flags _
host 192.168.xx.yy
manager null
port 2010
prot http
state inactive
type A
url http://192.168.xx.yy:2010
System:
flags
host 192.168.xx.yy
manager null
port 2002
prot xmlrpc_bin
state inactive
type B
url xmlrpc_bin://192.168.xx.yy:2002
VirtualDevices:
device d_rpcVirtualDevices
flags _
host 192.168.xx.yy
manager HMCCU
port 9292
prot http
state error
type A
url http://192.168.xx.yy:9292/groups
rpc:
Attributes:
ccuaggregate name:battery,filter:IODev=ccu2,read:battery,if:any=1,else:ok,prefix:battery_,coll:comment!Batterien OK;
ccudef-readingname ^(.+\.)?LOW_?BAT$:battery
ccuflags procrpc
ccuget State
event-on-change-reading .*
icon control_building_modern_s_2og_all
room Homematic,Wohnzimmer
rpcinterfaces BidCos-RF,CUxD,VirtualDevices
rpcinterval 3
rpcport 2001,8701,9292
rpcqueue /tmp/ccuqueue
rpcserver on
stateFormat rpcserver: state
stripnumber 2
Hier der Verursacher d_rpcBidCos_RF:
Internals:
.eventMapCmd on:noArg off:noArg
CCUNum 1
DEF 192.168.xx.yy BidCos-RF
FD 71
IODev ccu2
NAME d_rpcBidCos_RF
NR 602
RPCPID 2549
RPCState running
STATE running/OK
TYPE HMCCURPCPROC
ccuip 192.168.xx.yy
ccustate active
ccutype CCU2
host 192.168.xx.yy
rpcinterface BidCos-RF
rpcport 2001
version 1.0.002
.attraggr:
.attrminint:
READINGS:
2018-03-28 18:02:16 rpcstate running
2018-03-28 18:02:16 state OK
hmccu:
evtime 0
localaddr 192.168.xx.255
rpcstarttime 1522252936
rpc:
avgdelay 0.177536231884058
cbport 7411
cburl http://192.168.aa.ccc:7411/fh2001
clurl http://192.168.xx.yy:2001
evtime 1522253643
pid 2549
port 2001
state running
sumdelay 49
rec:
DD 0
EV 276
EX 0
IN 0
ND 183
RA 0
RD 0
SL 1
TO 0
UD 0
snd:
DD 0
EV 0
EX 0
IN 0
ND 0
RA 0
RD 0
SL 0
TO 0
UD 0
Attributes:
alias CCU RPC BidCos-RF
ccuflags expert,reconnect
eventMap /rpcserver on:on/rpcserver off:off/
icon control_building_modern_s_2og_all
room Homematic,Wohnzimmer
stateFormat rpcstate/state
verbose 2
Kann mir hier jemand sagen, was da schief läuft?
Auch ist mir aufgefallen, dass die Devices nach einem Neustart von FHEM immer den Status "Initialized" haben und erst durch ein "get <device> update" den richtigen Status anzeigen.
Vielen Dank schon mal.
Gruß
Hans-Ulrich
Dass nach dem Neustart alle Devices auf ,,initialized" stehen ist normal. Erst beim Start des RPC Servers wird automatisch ein ,,get update" auf alle Devices ausgeführt. Das sollte auch im Logfile nachvollziehbar sein. Da steht dann sowas wie ,,all rpc servers running" und danach eine Meldung, wie viele Devices aktualisiert wurden. Wenn das nicht so ist, müsstest du mal auf eventuelle Fehlermeldungen achten, die stattdessen kommen.
Das andere Problem ,,select found no reader" bedeutet, dass der RPC Server Prozess in FHEM keinen Socket findet, der bereit ist, Daten entgegenzunehmen. Die Ursache muss nicht zwingend HMCCU sein. Kann auch durch ein anderes Modul oder sogar durch Linux selbst verursacht werden. Gibt es weitere Fehlermeldungen im Logfile, auch von anderen Modulen oder FHEM selbst?
Letztendlich kann die Fehlermeldung auch besagen, dass FHEM abgestürzt ist. Dann wäre die Meldung die Wirkung und nicht die Ursache.
An deiner Config kann ich nichts auffälliges entdecken. Sieht soweit gut aus.
Zitat von: zap am 29 März 2018, 08:35:03
Dass nach dem Neustart alle Devices auf ,,initialized" stehen ist normal. Erst beim Start des RPC Servers wird automatisch ein ,,get update" auf alle Devices ausgeführt. Das sollte auch im Logfile nachvollziehbar sein. Da steht dann sowas wie ,,all rpc servers running" und danach eine Meldung, wie viele Devices aktualisiert wurden. Wenn das nicht so ist, müsstest du mal auf eventuelle Fehlermeldungen achten, die stattdessen kommen.
Das andere Problem ,,select found no reader" bedeutet, dass der RPC Server Prozess in FHEM keinen Socket findet, der bereit ist, Daten entgegenzunehmen. Die Ursache muss nicht zwingend HMCCU sein. Kann auch durch ein anderes Modul oder sogar durch Linux selbst verursacht werden. Gibt es weitere Fehlermeldungen im Logfile, auch von anderen Modulen oder FHEM selbst?
Letztendlich kann die Fehlermeldung auch besagen, dass FHEM abgestürzt ist. Dann wäre die Meldung die Wirkung und nicht die Ursache.
An deiner Config kann ich nichts auffälliges entdecken. Sieht soweit gut aus.
Hallo zap,
danke für Deine Antwort.
Ich habe FHEM derzeit auf 2 unterschiedlichen Systemen (Intel NUC und RPi 2) laufen. Bei beiden Systemen der identische Fehler. Beide Systeme sind per ssh erreichbar und es laufen nach dem Absturz jeweils noch ein paar Prozesse von FHEM:
18239 pts/0 S+ 0:00 grep fhem
30408 pts/1 R 551:33 perl fhem.pl fhem.cfg
30557 pts/1 S 0:25 perl fhem.pl fhem.cfg
30612 pts/1 Sl 16:47 /usr/local/bin/perl ./FHEM/00_SONOS.pm 4711 2 1 startedbyfhem
30723 ? S 2:24 /usr/local/bin/perl fhem.pl fhem.cfg
Auf beiden Systemen ist FHEM nicht mehr über die Weboberfläche erreichbar und es werden keine notifys, doifs, at-Befehle, usw. ausgeführt.
Den Log-Eintrag, dass alle RPC-Server laufen und die Anzahl der aktualisierten Devices finde ich nicht.
Die im Eingangspost aufgeführte Zeile ist jeweils die letzt im Log. Danach passiert nichts mehr.
Auch im syslog beider Systeme kann ich keine Auffälligkeiten feststellen.
Hier noch einmal ein Auszug aus dem Logfile nach dem Neustart von FHEM:
2018.03.29 06:09:47.308 1: PERL WARNING: Use of uninitialized value within %HMCCU_RPC_FLAG in pattern match (m//) at ./FHEM/88_HMCCU.pm line 3775, <$f$
2018.03.29 06:09:47.308 1: stacktrace:
2018.03.29 06:09:47.308 1: main::__ANON__ called by ./FHEM/88_HMCCU.pm (3775)
2018.03.29 06:09:47.308 1: main::HMCCU_GetDeviceList called by ./FHEM/88_HMCCU.pm (429)
2018.03.29 06:09:47.308 1: main::HMCCU_Define called by fhem.pl (3550)
2018.03.29 06:09:47.308 1: main::CallFn called by fhem.pl (1959)
2018.03.29 06:09:47.308 1: main::CommandDefine called by fhem.pl (1194)
2018.03.29 06:09:47.308 1: main::AnalyzeCommand called by fhem.pl (1044)
2018.03.29 06:09:47.308 1: main::AnalyzeCommandChain called by fhem.pl (1332)
2018.03.29 06:09:47.308 1: main::CommandInclude called by fhem.pl (568)
2018.03.29 06:09:48.669 1: HMCCU: Read 33 devices with 256 channels from CCU 192.168.xx.yy
2018.03.29 06:09:48.669 1: HMCCU: Read 6 interfaces from CCU 192.168.xx.yy
2018.03.29 06:09:54.462 1: HMCCURPCPROC: [d_rpcBidCos_RF] Initialized version 1.0.002 for interface BidCos-RF
2018.03.29 06:09:54.463 1: HMCCURPCPROC: [d_rpcVirtualDevices] Initialized version 1.0.002 for interface VirtualDevices
2018.03.29 06:09:54.464 1: HMCCURPCPROC: [d_rpcCUxD] Initialized version 1.0.002 for interface CUxD
2018.03.29 06:10:02.063 0: HMCCU: Start of RPC server after FHEM initialization in 12 seconds
2018.03.29 06:10:02.528 2: HMCCURPCPROC: [d_rpcBidCos_RF] RPC server process started for interface BidCos-RF with PID=822
2018.03.29 06:10:02.530 2: CCURPC: [d_rpcBidCos_RF] Initializing RPC server CB2001 for interface BidCos-RF
2018.03.29 06:10:02.535 1: HMCCURPCPROC: [d_rpcBidCos_RF] RPC server starting
2018.03.29 06:10:02.542 2: HMCCURPCPROC: [d_rpcBidCos_RF] Callback server CB2001 created. Listening on port 7411
2018.03.29 06:10:02.542 2: CCURPC: [d_rpcBidCos_RF] CB2001 accepting connections. PID=822
2018.03.29 06:10:02.543 2: HMCCURPCPROC: [d_rpcCUxD] RPC server process started for interface CUxD with PID=823
2018.03.29 06:10:02.545 2: CCURPC: [d_rpcCUxD] Initializing RPC server CB8701 for interface CUxD
2018.03.29 06:10:02.546 2: CCURPC: [d_rpcCUxD] CB8701 accepting connections. PID=823
2018.03.29 06:10:02.550 1: HMCCURPCPROC: [d_rpcCUxD] RPC server starting
2018.03.29 06:10:05.721 2: HMCCURPCPROC: [d_rpcBidCos_RF] RPC server CB2001 enters server loop
2018.03.29 06:10:05.727 2: HMCCURPCPROC: [d_rpcBidCos_RF] Registering callback http://192.168.aa.bb:7411/fh2001 of type A with ID CB2001 at http://19$
2018.03.29 06:10:06.399 1: HMCCURPCPROC: [d_rpcBidCos_RF] RPC server CB2001 running
2018.03.29 06:10:06.573 2: HMCCURPCPROC: [d_rpcCUxD] RPC server CB8701 enters server loop
2018.03.29 06:10:06.578 2: HMCCURPCPROC: [d_rpcCUxD] Registering callback xmlrpc_bin://192.168.aa.bb:14111/fh8701 of type B with ID CB8701 at xmlrpc_$
2018.03.29 06:10:06.718 2: CCURPC: [d_rpcBidCos_RF] CB2001 NewDevice received 183 device and channel specifications
2018.03.29 06:10:08.592 1: HMCCURPCPROC: [d_rpcCUxD] RPC server CB8701 running
Wo kann ich noch suchen?
Die RPC Server starten nicht richtig. HMCCU ist auf beiden FHEMs konfiguriert mit den gleichen Schnittstellen mit der gleichen CCU2?
Eine solche Konfiguration wird von HMCCU nicht unterstützt. Grund: jeder RPC Server regisitriert sich bei der CCU mit einem Namen. Dieser Name ist immer gleich (zB ,,CB2010"). Wenn nun zwei FHEMs den gleichen RPC Server registrieren, weiß die CCU nicht mehr, wo sie die Events hinschicken soll.
Werde versuchen, das in einem der nächsten Releases einzubauen.
Zitat von: zap am 29 März 2018, 22:14:19
Die RPC Server starten nicht richtig. HMCCU ist auf beiden FHEMs konfiguriert mit den gleichen Schnittstellen mit der gleichen CCU2?
Eine solche Konfiguration wird von HMCCU nicht unterstützt. Grund: jeder RPC Server regisitriert sich bei der CCU mit einem Namen. Dieser Name ist immer gleich (zB ,,CB2010"). Wenn nun zwei FHEMs den gleichen RPC Server registrieren, weiß die CCU nicht mehr, wo sie die Events hinschicken soll.
Werde versuchen, das in einem der nächsten Releases einzubauen.
Ja, beide Systeme sind identisch, weil ich nach und nach vom RPi auf den NUC umziehen möchte. Gibt es für mich evtl. die Möglichkeit, die RPC-Server umzubenennen, oder geht dieses nur mit Eingriff in die Module? Das traue ich mir allerdings nicht zu.
Das ist tief im Modul an vielen Stellen verankert. Wenn du noch ein paar Tage Geduld hast, pass ich das so an, dass es parallel funktioniert.
Bis dahin kannst Du das nur je Interface trennen, dh auf einem Rachner zB BidCos und auf dem anderen HMIP.
So, nachdem ich jetzt auf dem NUC mal alle HM-Devices aus der cfg gelöscht habe, hat sich leider nichts geändert: beide Systeme stürzen nach wie vor und ganz willkürlich ab. Bislang bin ich noch nicht dazu gekommen, Ursachenforschung zu betreiben.
Ich denke, dass ich wohl auf einen früheren Stand zurückgehen muss...
Auch in den letzten Tagen ist FHEM auf dem RPi mehrfach stehen geblieben, obwohl er als einziger mit den HMCCU-Modulen auf die CCU zugreift.
Die Fehlermeldung lautet wieder
CCURPC: [d_rpcBidCos_RF] Sending data to FHEM failed 100 times. select found no reader
Aber wie ich soeben festgestellt habe, belegt fhem.pl bei beiden Installationen nahezu 100% der CCU.
Scheinbar handelt es sich nicht nur um ein Problem mit den HMCCU-Modulen.
Möglicherweise ein I/O Problem. Sowas kann ein Linux System lahmlegen. Die Frage ist, welches FHEM die I/O Last erzeugt.
Inzwischen hängt sich FHEM jede Nacht auf. Immer mit der Meldung aus dem Anfangspost.
Es muss der Hauptprozesss von FHEM sein, denn wenn ich den mittels "kill -9" beende, ist die Webseite nicht mehr erreichbar, obwohl noch ein paar Tasks von FHEM laufen.
Zitat von: zap am 31 März 2018, 09:47:09
Das ist tief im Modul an vielen Stellen verankert. Wenn du noch ein paar Tage Geduld hast, pass ich das so an, dass es parallel funktioniert.
Bis dahin kannst Du das nur je Interface trennen, dh auf einem Rachner zB BidCos und auf dem anderen HMIP.
Hallo zap,
hast Du die Anpassung in der aktuellen Version vorgenommen, oder muss ich mich noch ein wenig gedulden?
Gruß
Hans-Ulrich
PS: der Übeltäter war das HomeConnect-Modul
Ja, seit der letzten Version können mehrere FHEMS zu ein und derselben CCU connecten
Suuuuper, vielen Dank :D
Gruß
Hans-Ulrich
ZitatJa, seit der letzten Version können mehrere FHEMS zu ein und derselben CCU connecten
muss da etwas besonders beachtet werden?
LG Thomas
Nein. Früher wurden die RPC Server immer identisch benannt. Dadurch konnte sich FHEM nur einmal bei der CCU registrieren. Mittlerweile enthält der Name der RPC Server einen Teil der IP Adresse des Raspis, dadurch kann die CCU mehrere FHEM Instanzen auseinander halten.