[HMCCU] ccudelay wirkt nicht

tndx · 16 Oktober 2019, 20:02:51

Guten Abend,

mein FHEM läuft zusammen mit piVCCU auf einem Raspberry Pi 3b. Wenn ich den Raspi mal neu starten muss, dann ist FHEM ja schneller und versucht HMCCU zu starten, obwohl die CCU noch gar nicht bereit ist. Aus diesem Grund gibt es ja den Parameter "ccudelay", den ich auch nutze:

Code Auswählen

DEF 192.168.178.135 ccudelay=180

Trotzdem startet HMCCU nach einem Neustart nicht, sondern bleibt im Zustand

Code Auswählen

RPCState 	inactive
STATE 	Initialized

hängen. Ein Blick in die Log-Datei offenbart folgendes (nicht Relevantes entfernt):

Code Auswählen

2019.10.16 19:24:53 1: HMCCU: [myHMCCU] Initialized version 4.3.018
2019.10.16 19:24:53 1: HMCCU: [myHMCCU] HMCCU: Initializing device
2019.10.16 19:24:53 1: HMCCU: [myHMCCU] HMCCU: Read 0 devices with 0 channels from CCU 192.168.178.135
2019.10.16 19:24:53 1: HMCCU: [myHMCCU] HMCCU: Read 0 interfaces from CCU 192.168.178.135
2019.10.16 19:24:53 1: HMCCU: [myHMCCU] HMCCU: Read 0 programs from CCU 192.168.178.135
2019.10.16 19:24:53 1: HMCCU: [myHMCCU] HMCCU: Read 0 virtual groups from CCU 192.168.178.135
2019.10.16 19:24:53 3: HMCCU: Illegal RPC interface BidCos-RF
2019.10.16 19:24:53 3: HMCCU: Illegal RPC port 2001
2019.10.16 19:24:53 2: HMCCUDEV: [HP_Pres] Cannot detect IO device, maybe CCU not ready. Trying later ...
2019.10.16 19:24:53 1: define d_rpc178135BidCos_RF HMCCURPCPROC http://192.168.178.135 BidCos-RF: Invalid port or interface BidCos-RF
2019.10.16 19:24:54 1: define d_rpc178135HmIP_RF HMCCURPCPROC http://192.168.178.135 HmIP-RF: Invalid port or interface HmIP-RF
2019.10.16 19:24:54 2: HMCCUDEV: [GWC_Pres] Cannot detect IO device, maybe CCU not ready. Trying later ...
2019.10.16 19:24:54 2: HMCCUDEV: [FlEG_Pres] Cannot detect IO device, maybe CCU not ready. Trying later ...
2019.10.16 19:24:54 3: eq3: Defined with URL https://www.eq-3.de/ajax/downloads/downloads_eq3.php and interval 604800 featurelevel 5.9
2019.10.16 19:24:54 3: eq3: added hint :text,reading,internal,expression,delete to attr readingMaxAgeReplacementMode in userattr list
2019.10.16 19:24:54 1: Including ./log/fhem.save
2019.10.16 19:24:56 1: configfile: ASKSIN not supported
HMCCU: Illegal RPC interface BidCos-RF
HMCCU: Illegal RPC port 2001
Invalid port or interface BidCos-RF
Please define d_rpc178135BidCos_RF 5d2cbc9b-f33f-7a7c-2390-e5ae5a52b0974e1d first
Invalid port or interface HmIP-RF
Please define d_rpc178135HmIP_RF 5d323256-f33f-7a7c-6d75-89e9bdbbc1978c2e first
./log/fhem.save: Please define d_rpc178135BidCos_RF first
Please define d_rpc178135BidCos_RF first
Please define d_rpc178135BidCos_RF first
Please define d_rpc178135HmIP_RF first
Please define d_rpc178135HmIP_RF first
Please define d_rpc178135HmIP_RF first

2019.10.16 19:25:22 2: HMCCU: [myHMCCU] Get RPC device for interface BidCos-RF
2019.10.16 19:25:22 0: HMCCU: [myHMCCU] Definition of some RPC devices failed

Scheint, als würde FHEM nicht mit der Initialisierung von HMCCU warten. Ein erneutes "shutdown restart" klappt dann ohne Probleme, erfordert aber immer noch einen manuellen Eingriff nach einem Neustart, was nicht immer wünschenswert ist. Gibt es evtl. Abhilfe?

zap · 16 Oktober 2019, 21:08:01

Ich glaube, das ist ein anderes Problem. Wenn die CCU nicht erreichbar ist, sehen die Logmeldungen so aus:

Code Auswählen

2019.10.14 21:06:07 1: HMCCU: [d_ccumw] CCU port 48181 is not reachable
2019.10.14 21:06:07 1: HMCCU: [d_ccumw] Initialized version 4.3.019
2019.10.14 21:06:07 1: HMCCU: [d_ccumw] Scheduling delayed initialization in 180 seconds

Hast Du das Attribut rpcinterfaces gesetzt?

tndx · 16 Oktober 2019, 21:39:59

Das Attribut war in der Tat nicht mehr gesetzt. Bin mir ziemlich sicher, dass ich das schon mal setzen/ändern musste, da ansonsten HMIP-RF-Interface nicht hoch kam. Aber zuletzt funktionierte ja alles, nur nach einem "shutdown restart".

Ich probiere den Neustart noch mal bei Gelegenheit mit dem gesetzten Attribut aus.

eurofinder · 17 Oktober 2019, 07:38:00

@zap:

ZitatHast Du das Attribut rpcinterfaces gesetzt?

Davon hatte ich auch schon mal berichtet, dass nach einen 'shutdown restart' plötzlich die Einstellungen unter rpcinterfaces nicht mehr vorhanden sind. Konnte dafür aber bisher noch keine reproduzierbare Systematik feststellen.

Gruß
eurofinder

zap · 17 Oktober 2019, 17:21:10

Lass mal den ccudelay Parameter weg. Default ist sowieso 180.

Setze rpcInterfaces auf die tatsächlich verwendeten Schnittstellen der CCU.

tndx · 19 Oktober 2019, 09:28:59

Guten Morgen,

habe meinen Raspi eben neu gestartet. Dummerweise habe ich nicht unmittelbar davor geschaut, ob das Attribut "rpcinterfaces" gesetzt war, aber ich habe es definitiv gesetzt als ich das letzte Mal das Problem hatte und hier gepostet habe. Jetzt nach dem Neustart klemmt es wieder und das Attribut ist weg.

Logfile sagt folgendes (Irrelevantes Zeug entfernt):

Code Auswählen

Line 1: 2019.10.19 09:08:36 1: HMCCURPCPROC: [d_rpc178135BidCos_RF] Graceful shutdown
Line 2: 2019.10.19 09:08:36 1: HMCCURPCPROC: [d_rpc178135BidCos_RF] Stopping RPC server CB2001178024178135
Line 3: 2019.10.19 09:08:36 1: HMCCURPCPROC: [d_rpc178135BidCos_RF] Deregistering RPC server http://192.168.178.24:7411/fh2001 with ID CB2001178024178135 at http://192.168.178.135:2001
Line 4: 2019.10.19 09:08:36 1: HMCCURPCPROC: [d_rpc178135BidCos_RF] Callback for RPC server CB2001178024178135 deregistered
Line 5: 2019.10.19 09:08:36 2: HMCCURPCPROC: [d_rpc178135BidCos_RF] Sending signal INT to RPC server process CB2001178024178135 with PID=4725
Line 6: 2019.10.19 09:08:36 2: HMCCURPCPROC: [d_rpc178135BidCos_RF] Scheduling cleanup in 8 seconds
Line 10: 2019.10.19 09:08:37 1: HMCCURPCPROC: [d_rpc178135HmIP_RF] Graceful shutdown
Line 11: 2019.10.19 09:08:38 1: HMCCURPCPROC: [d_rpc178135HmIP_RF] Stopping RPC server CB2010178024178135
Line 12: 2019.10.19 09:08:38 1: HMCCURPCPROC: [d_rpc178135HmIP_RF] Deregistering RPC server http://192.168.178.24:7420/fh2010 with ID CB2010178024178135 at http://192.168.178.135:2010
Line 13: 2019.10.19 09:08:38 1: HMCCURPCPROC: [d_rpc178135HmIP_RF] Callback for RPC server CB2010178024178135 deregistered
Line 14: 2019.10.19 09:08:38 2: HMCCURPCPROC: [d_rpc178135HmIP_RF] Sending signal INT to RPC server process CB2010178024178135 with PID=4726
Line 15: 2019.10.19 09:08:38 2: HMCCURPCPROC: [d_rpc178135HmIP_RF] Scheduling cleanup in 8 seconds
Line 20: 2019.10.19 09:08:39 1: HMCCURPCPROC: [d_rpc178135HmIP_RF] RPC server process CB2010178024178135 terminated.
Line 21: 2019.10.19 09:08:39 2: HMCCURPCPROC: [d_rpc178135HmIP_RF] Stop I/O handling
Line 22: 2019.10.19 09:08:39 1: HMCCURPCPROC: [d_rpc178135BidCos_RF] RPC server process CB2001178024178135 terminated.
Line 23: 2019.10.19 09:08:39 1: HMCCU: [myHMCCU] All RPC servers inactive
Line 24: 2019.10.19 09:08:39 2: HMCCURPCPROC: [d_rpc178135BidCos_RF] Stop I/O handling
Line 26: 2019.10.19 09:08:40 2: HMCCURPCPROC: [d_rpc178135BidCos_RF] Found no running processes. Cleaning up ...
Line 27: 2019.10.19 09:08:40 1: HMCCURPCPROC: [d_rpc178135BidCos_RF] Housekeeping called. Cleaning up RPC environment
Line 28: 2019.10.19 09:08:40 2: HMCCURPCPROC: [d_rpc178135HmIP_RF] Found no running processes. Cleaning up ...
Line 29: 2019.10.19 09:08:40 1: HMCCURPCPROC: [d_rpc178135HmIP_RF] Housekeeping called. Cleaning up RPC environment
Line 66: 2019.10.19 09:10:04 1: HMCCU: [myHMCCU] Initialized version 4.3.018
Line 67: 2019.10.19 09:10:04 1: HMCCU: [myHMCCU] HMCCU: Initializing device
Line 68: 2019.10.19 09:10:04 1: HMCCU: [myHMCCU] HMCCU: Read 0 devices with 0 channels from CCU 192.168.178.135
Line 69: 2019.10.19 09:10:04 1: HMCCU: [myHMCCU] HMCCU: Read 0 interfaces from CCU 192.168.178.135
Line 70: 2019.10.19 09:10:04 1: HMCCU: [myHMCCU] HMCCU: Read 0 programs from CCU 192.168.178.135
Line 71: 2019.10.19 09:10:04 1: HMCCU: [myHMCCU] HMCCU: Read 0 virtual groups from CCU 192.168.178.135
Line 72: 2019.10.19 09:10:04 3: HMCCU: Illegal RPC interface BidCos-RF
Line 73: 2019.10.19 09:10:04 3: HMCCU: Illegal RPC port 2001
Invalid port or interface BidCos-RF
Please define d_rpc178135BidCos_RF 5da75bb5-f33f-7a7c-cbec-eafb03630ab5967b first
Invalid port or interface HmIP-RF
Please define d_rpc178135HmIP_RF 5da75f92-f33f-7a7c-9a78-9b4106db95d8bc79 first
./log/fhem.save: Please define d_rpc178135BidCos_RF first
Please define d_rpc178135BidCos_RF first
Please define d_rpc178135BidCos_RF first
Please define d_rpc178135HmIP_RF first
Please define d_rpc178135HmIP_RF first
Please define d_rpc178135HmIP_RF first
Line 74: 2019.10.19 09:10:04 2: HMCCUDEV: [HP_Pres] Cannot detect IO device, maybe CCU not ready. Trying later ...
Line 75: 2019.10.19 09:10:05 2: HMCCUDEV: [GWC_Pres] Cannot detect IO device, maybe CCU not ready. Trying later ...
Line 76: 2019.10.19 09:10:05 2: HMCCUDEV: [FlEG_Pres] Cannot detect IO device, maybe CCU not ready. Trying later ...
Line 79: 2019.10.19 09:10:06 1: define d_rpc178135BidCos_RF HMCCURPCPROC http://192.168.178.135 BidCos-RF: Invalid port or interface BidCos-RF
Line 80: 2019.10.19 09:10:06 1: define d_rpc178135HmIP_RF HMCCURPCPROC http://192.168.178.135 HmIP-RF: Invalid port or interface HmIP-RF
Line 83: HMCCU: Illegal RPC interface BidCos-RF
Line 84: HMCCU: Illegal RPC port 2001

Falls das eine Rolle spielt: unter "rpcinterfaces" hatte ich auch das BidCos-RF-Interface stehen, obwohl ich gerade keine BidCos-Geräte an der CCU angelernt habe, kann das zu so einem Verhalten führen?

UPDATE:

Ich wollte das Attribut "rpcinterfaces" auf "HmIP-RF" setzen, also auf das tatsächlich verwendete Interface, aber da kam die Fehlermeldung (sinngemäß) "HMCCU: ungültiges Interface", das Attribut wurde nicht angelegt.
Nach einem "shutdown restart" läuft alles, wie es sollte, das Attribut "rpcinterfaces ist wie von Zauberhand wieder da, gesetzt auf "BidCos-RF,HmIP-RF"

zap · 19 Oktober 2019, 16:28:10

Da mehrere User festgestellt haben, dass rpcinterfaces verschwindet, muss das wohl ein Bug sein. Ich nehme an, das tritt auf, wenn man das Attribut nicht oder falsch setzt und HMCCU dann versucht, das richtige Interface automatisch zu erkennen.

Update: Habe den Bug vermutlich gefunden. Schlägt immer dann zu, wenn die CCU beim Start von FHEM nicht sofort antwortet oder aktiv ist.

tndx · 26 Oktober 2019, 09:48:10

Guten Morgen,

Zitat von: zap am 19 Oktober 2019, 16:28:10
Da mehrere User festgestellt haben, dass rpcinterfaces verschwindet, muss das wohl ein Bug sein. Ich nehme an, das tritt auf, wenn man das Attribut nicht oder falsch setzt und HMCCU dann versucht, das richtige Interface automatisch zu erkennen.

hatte es gestern noch mal ausprobiert, mit korrekt gestztem Attribut (in meinem Fall nur HmIP), trotzdem die gleichen Schwierigkeiten: das Attribut war weg und es wurde lt. Logfile auch nach BidCos-RF gesucht. Nach "shutdown restart" alles in Butter

Zitat von: zap am 19 Oktober 2019, 16:28:10
Update: Habe den Bug vermutlich gefunden. Schlägt immer dann zu, wenn die CCU beim Start von FHEM nicht sofort antwortet oder aktiv ist.

Hört sich gut an, d.h. aber, die Überschrift ist korrekt?

Jamo · 26 Oktober 2019, 14:30:39

Code Auswählen

Update: Habe den Bug vermutlich gefunden. Schlägt immer dann zu, wenn die CCU beim Start von FHEM nicht sofort antwortet oder aktiv ist.

Ja, das habe ich bei mir auch gesehen, hatte mich schon gewundert warum da sttribut immer verschwand . . .

Danke!

JMC · 12 Februar 2021, 05:53:42

Hi,

auch wenn es schon älter ist - mir passiert es auch immer wenn ich den Pi neustarte - ich muss dann immer nochmal shutdown restart machen damit das HmIP wieder in FHEM läuft. Gibts vielleicht einen Workaround der das zumindest automatisiert wenn der Bug noch nicht final gefixt ist?

Viele Grüße

zap · 13 Februar 2021, 19:10:26

Es scheint, als würde ccudelay nicht richtig funktionieren oder die 180 Sekunden sind zu wenig.

Es gibt mehrere Möglichkeiten. Alle erfordern eine Anpassung der I/O Device Definition.

1. ccudelay auf einen höheren Wert setzen, z.B. 240 Sekunden (FHEM blockiert nicht beim Start)

2. waitforccu auf einen hohen Wert setzen, z.B. 240 Sekunden (Achtung! FHEM blockiert beim Starten für die angegebene Zeit, sofern die CCU nicht erreichbar ist)

3. delayedinit auf einen hohen Wert setzen, z.B. 240 Sekunden. Dadurch wartet HMCCU immer die angegebene Zeit mit der Initialisierung, egal ob die CCU erreichbar ist oder nicht (FHEM blockiert nicht beim Start)

Mit den Zeitangaben musst Du mal ein wenig spielen. Das Problem ist häufig, dass die CCU zwar recht schnell startet, einzelne Dienste wie z.B. der HmIP-Server hinterher hinken.

Ich mach das immer so, wenn ich z.B. die CCU nach einem Software Update neu starten muss:

1. RPC Server in FHEM stoppen: set myCCU rpcserver off
2. CCU Update ausführen, CCU neu starten
3. 5-10 Minuten warten
4. RPC Server starten: set myCCU rpcserver on
oder stattdessen FHEM durchstarten

JMC · 23 März 2021, 07:29:15

Moin,

Danke für die Infos - ich habe ein wenig rumgetestet, war aber mit ccudelay immer noch nicht "zufrieden" weil es m.M. nach nicht richtig geklappt hat, bin jetzt einen anderen Weg gegangen:

Beim start des Pi wird FHEM nach 45 Sekunden neugestartet (über den Service) sowie Homebridge nur manuell gestartet.

Ich habe nämlich scheinbar endlich den Grund gefunden warum meine HmIP Sachen immer wieder mal in den Standardraum rutschen und ihre Einstellungen verlieren (also das der Kontakt ein Fenster ist etc...) - das passierte immer dann, wenn Homebridge gestart wurde aber der rpcserver im FHEM die CCU nicht erreicht hat.