FHEM Forum

FHEM - Hausautomations-Systeme => Homematic => Thema gestartet von: kjmEjfu am 23 Juni 2022, 10:50:04

Titel: [gelöst] HMCCU blockiert beim Hochfahren (war: HMCCU und XML-API 1.22)
Beitrag von: kjmEjfu am 23 Juni 2022, 10:50:04
Ahoi,

für die XML-API gab es ein Update auf die 1.22
Seit ich die installiert habe, habe ich beim FHEM Restart einen sehr langen Hänger (22:49:57.942 für 12 Minuten):

2022.06.22 22:49:38.854 1: HMCCU [d_ccu] Reading device config from CCU. This may take a couple of seconds ...
2022.06.22 22:49:40.160 2: HMCCU [d_ccu] Reading Device Descriptions for interface BidCos-RF
2022.06.22 22:49:41.550 2: HMCCU [d_ccu] Read 154 Device Descriptions for interface BidCos-RF
2022.06.22 22:49:41.550 2: HMCCU [d_ccu] Reading Paramset Descriptions for interface BidCos-RF
2022.06.22 22:49:53.694 2: HMCCU [d_ccu] Read 225 Paramset Descriptions for interface BidCos-RF
2022.06.22 22:49:53.694 2: HMCCU [d_ccu] Reading Peer Descriptions for interface BidCos-RF
2022.06.22 22:49:55.016 2: HMCCU [d_ccu] Read 62 Peer Descriptions for interface BidCos-RF
2022.06.22 22:49:56.328 2: HMCCU [d_ccu] Reading Device Descriptions for interface HmIP-RF
2022.06.22 22:49:57.942 2: HMCCU [d_ccu] Read 355 Device Descriptions for interface HmIP-RF
2022.06.22 22:49:57.942 2: HMCCU [d_ccu] Reading Paramset Descriptions for interface HmIP-RF
2022.06.22 23:02:06.801 2: HMCCU [d_ccu] Read 531 Paramset Descriptions for interface HmIP-RF
2022.06.22 23:02:06.801 2: HMCCU [d_ccu] Reading Peer Descriptions for interface HmIP-RF
2022.06.22 23:02:08.191 2: HMCCU [d_ccu] Read 30 Peer Descriptions for interface HmIP-RF
2022.06.22 23:02:08.251 2: HMCCU [d_ccu] Read device configuration in 749.397107124329 seconds: devices/channels=509 parametersets=756 links=92
2022.06.22 23:02:08.251 2: HMCCU [d_ccu] RPC device for interface HmIP-RF: d_rpcHmIP_RF
2022.06.22 23:02:08.251 2: HMCCU [d_ccu] RPC device for interface BidCos-RF: d_rpcBidCos_RF
2022.06.22 23:02:08.257 2: HMCCURPCPROC [d_rpcHmIP_RF] RPC server process started for interface HmIP-RF with PID=11540
2022.06.22 23:02:08.260 2: HMCCURPCPROC [d_rpcHmIP_RF] Initializing RPC server CB2010050051178059 for interface HmIP-RF
2022.06.22 23:02:08.261 1: HMCCURPCPROC [d_rpcHmIP_RF] RPC server starting
2022.06.22 23:02:08.269 2: HMCCURPCPROC [d_rpcBidCos_RF] RPC server process started for interface BidCos-RF with PID=11541
2022.06.22 23:02:08.272 2: HMCCURPCPROC [d_rpcBidCos_RF] Initializing RPC server CB2001050051178059 for interface BidCos-RF
2022.06.22 23:02:08.273 1: HMCCURPCPROC [d_rpcBidCos_RF] RPC server starting
2022.06.22 23:02:08.274 2: HMCCU [d_ccu] RPC server start: 2 started, 0 already running, 0 failed to start
2022.06.22 23:02:08.280 2: HMCCURPCPROC [d_rpcHmIP_RF] Callback server CB2010050051178059 created. Listening on port 7420
2022.06.22 23:02:08.281 2: HMCCURPCPROC [d_rpcHmIP_RF] CB2010050051178059 accepting connections. PID=11540
2022.06.22 23:02:08.291 2: HMCCURPCPROC [d_rpcBidCos_RF] Callback server CB2001050051178059 created. Listening on port 7411
2022.06.22 23:02:08.292 2: HMCCURPCPROC [d_rpcBidCos_RF] CB2001050051178059 accepting connections. PID=11541


Firewalleinstellungen auf der CCU3 sind weiterhin:
Firewall-Richtline: Ports offen
Homematic XML-RPC API: Eingeschränkt
Remote Homematic-Script-API: EIngeschränkt
Port-Freigabe: (nix)
IP-Adressen für den eingeschränkten Zugriff: 192.168.0.0/16

Damit hat es vorher auch gut funktioniert.
Irgendeine Idee, woran das jetzt liegen kann?

FHEM ist aktuell und läuft auf Basis des latest-Docker-Containers, librpc-xml-perl ist da schon installiert.
Titel: Antw:HMCCU und XML-API 1.22
Beitrag von: frank am 23 Juni 2022, 11:47:50
am längsten dauert dieses einlesen:
2022.06.22 22:49:57.942 2: HMCCU [d_ccu] Reading Paramset Descriptions for interface HmIP-RF
2022.06.22 23:02:06.801 2: HMCCU [d_ccu] Read 531 Paramset Descriptions for interface HmIP-RF


hat sich hier der datenumfang vielleicht deutlich erhöht?
oder dieses lesen hat ein problem.
Titel: Antw:HMCCU und XML-API 1.22
Beitrag von: kjmEjfu am 23 Juni 2022, 11:51:37
Da hat sich nichts dran verändert.
Habe weder neue Geräte, noch irgendwas umgestellt.

Im Changelog der XML-API steht

limit the update-check.cgi to parse for cmd=download and not parse arbitrary query string options.

k.A. ob HMCCU das nutzt und jetzt gebremst wird.
Titel: Antw:HMCCU und XML-API 1.22
Beitrag von: zap am 23 Juni 2022, 12:57:07
HMCCU nutzt das XML-API Addon nicht.
Titel: Antw:HMCCU und XML-API 1.22
Beitrag von: kjmEjfu am 23 Juni 2022, 14:05:34
Puh, ok.

Hast du dann eine Idee, woran das liegen könnte?
Am Netzwerk hat sich nichts geändert, auf der CCU3 nur das Addon, bei HMCCU gab es keine Änderungen in letzter Zeit ... dubios.
Habe ich eventuell einen Anhaltspunkt wenn ich Verbose hochdrehe?
Titel: Antw:HMCCU und XML-API 1.22
Beitrag von: kjmEjfu am 27 Juni 2022, 10:22:13
Update auf die neue 3.63.9.20220625 von RaspberryMatic hat auch nichts verbessert.
Titel: Antw:HMCCU und XML-API 1.22
Beitrag von: zap am 27 Juni 2022, 11:58:06
Ich bin etwas hintendran mit meinen CCU Updates. Versuche mal folgendes:

- RPC Server oder FHEM stoppen
- CCU neu starten und mal 5-10 Minuten warten (die CCU ist nach einem Neustart ziemlich beschäftigt)
- Dann RPC Server oder FHEM wieder starten

Falls das nicht hilft, mal im Log von der CCU schauen ob da Fehlermeldungen dring stehen.
Titel: Antw:HMCCU und XML-API 1.22
Beitrag von: kjmEjfu am 27 Juni 2022, 13:05:21
"RPC Server stoppen, CCU neu starten, RPC neu starten" funktioniert ziemlich gut.
Liegt allerdings IMO daran, dass dieser Teil:

2022.06.27 02:21:58.135 2: HMCCU [d_ccu] Reading Paramset Descriptions for interface HmIP-RF
2022.06.27 02:38:22.638 2: HMCCU [d_ccu] Read 531 Paramset Descriptions for interface HmIP-RF


bei dem es so ewig dauert, ja nur bei einem Neustart von FHEM passiert.
Titel: Antw:HMCCU und XML-API 1.22
Beitrag von: kjmEjfu am 07 Juli 2022, 11:32:16
So, im Log der CCU ist nichts zu finden.
Sehr dubios, da ich HMCCU ja quasi nutze seit es das gibt.

Apptime zeigt mir noch sowas an:

name                                     function                               max    count      total  average   maxDly   avgDly TS Max call     param Max call
tmr-HMCCURPCPROC_RPCPing                 HASH(0x55c9b3d7df68)                  4666        8   35091.13  4386.39   979.61   124.39 07.07. 11:20:53 HASH(d_rpcBidCos_RF)


Womit der RPCPing beim average auf Platz 1 ist.
Ist das normal?
Titel: Antw:HMCCU blockiert beim Hochfahren (war: HMCCU und XML-API 1.22)
Beitrag von: kjmEjfu am 07 Juli 2022, 19:01:42
Vielleicht ist aber auch irgendwas in meiner Config nicht in Ordnung, was bisher aus irgendwelchen Gründen kein Problem erzeugt hat?

HMCCU:

defmod d_ccu HMCCU 192.168.178.59 waitforccu=180
attr d_ccu userattr rpcinterfaces:multiple-strict,HmIP-RF,BidCos-RF,VirtualDevices
attr d_ccu ccuReqTimeout 10
attr d_ccu ccuaggregate name:battery,filter:type=HMCCUDEV|HMCCUCHN,read:(LOWBAT|LOW_BAT),if:any=yes,else:no,prefix:battery_,coll:comment!Batterien OK;;\
name:unreachable,filter:type=HMCCUDEV|HMCCUCHN,read:Activity,if:any=dead,else:alive,prefix:unreach_,coll:comment!Alle Devices erreichbar;;
attr d_ccu ccudef-hmstatevals UNREACH!(1|true):unreachable;;FAULT_REPORTING!#1-3:err_f_${value},#5:err_f_${value},#7-9:err_f_${value};;ERROR_OVERHEAT!(1|true):err_overheated;;ERROR_OVERLOAD!(1|true):err_overloaded;;ERROR_REDUCED!(1|true):err_reduced;;ERROR!#1-3:err_${value},#5-9:err_${value};;INHIBIT!(1|true):locked;;DIRECTION!1:up,2:down,3:undefined;;WORKING!(1|true):working;;MOTION!.*:${MOTION};;LEVEL!#0-0:off,#1-99:${LEVEL},#100-100:on;;STATE!.*:${STATE};;VALVE_STATE!.*:${VALVE_STATE}%;;CONTROL_MODE!.*:${CONTROL_MODE};;FAULT_REPORTING!6:warn_battery;;LOW_?BAT!(1|true):warn_battery;;ERROR!4:warn_battery;;UNREACH!0:ok;;
attr d_ccu ccudef-readingformat datapoint
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;;SABOTAGE!0:false,1:true;;WORKING!0:false,1:true;;INHIBIT!(0|false):unlocked,(1|true):locked
attr d_ccu ccuflags procrpc,nonBlocking,reconnect
attr d_ccu cmdIcon on:general_an off:general_aus
attr d_ccu event-on-change-reading .*
attr d_ccu room Homematic
attr d_ccu rpcinterfaces BidCos-RF,HmIP-RF
attr d_ccu rpcserver on
attr d_ccu rpcserveraddr 192.168.50.51
attr d_ccu rpctimeout 5
attr d_ccu stateFormat rpcstate/state
attr d_ccu stripnumber 1


BidCos-RPC:

defmod d_rpcBidCos_RF HMCCURPCPROC 192.168.178.59 BidCos-RF
attr d_rpcBidCos_RF alias CCU RPC BidCos-RF
attr d_rpcBidCos_RF ccuflags expert
attr d_rpcBidCos_RF eventMap /rpcserver on:on/rpcserver off:off/
attr d_rpcBidCos_RF room Homematic
attr d_rpcBidCos_RF rpcServerAddr 192.168.50.51
attr d_rpcBidCos_RF stateFormat rpcstate/state
attr d_rpcBidCos_RF verbose 2


HM-IP RPC:

defmod d_rpcHmIP_RF HMCCURPCPROC 192.168.178.59 HmIP-RF
attr d_rpcHmIP_RF alias CCU RPC HmIP-RF
attr d_rpcHmIP_RF ccuflags expert
attr d_rpcHmIP_RF eventMap /rpcserver on:on/rpcserver off:off/
attr d_rpcHmIP_RF room Homematic
attr d_rpcHmIP_RF rpcServerAddr 192.168.50.51
attr d_rpcHmIP_RF stateFormat rpcstate/state
attr d_rpcHmIP_RF verbose 2
Titel: Antw:HMCCU blockiert beim Hochfahren (war: HMCCU und XML-API 1.22)
Beitrag von: kjmEjfu am 08 Juli 2022, 10:56:41
So, hab den Fehler beseitigt. Auch wenn ich bei der Ursache nicht ganz sicher bin.

Folgendes habe ich getan:
1. die beiden RPC Devices gelöscht und neu anlegen lassen
2. ein "configdb reorg" durchführen lassen

jetzt läuft ein Neustart (mehrfach getestet) ohne Pause/Blockieren innerhalb von Sekunden durch.