HMCCU reagiert in Verbindung mit pivccu3 (Version3.43.14) extrem langsam

Begonnen von theseer105, 01 März 2019, 14:14:05

Vorheriges Thema - Nächstes Thema

theseer105

Hallo,

ich verwende FHEM jetzt schon einige Zeit und lese hier mit. Bis jetzt konnte ich alle Probleme mit Hilfe des Forums durch lesen lösen. Dafür schon mal ein herzliches Dankeschön.
Jetzt fehlt mir aber jeglicher Ansatzpunkt. Seit Montag reagiert meine Homematic Installation, die ich über FHEM vor allem mit HUE lampen verknüpft habe sehr langsam. Je mehr Lampen geschaltet werden, desto deutlicher wird dabei die Verzögerung.
Mein FHEM-Server lauft auf einem thinkerboard, auf dem über pivccu auch eine CCU3 (Version 3.43.14) emuliert wird. Seltsam ist, dass eine weitere CCU2 (Version 2.41.5, ebenfalls pivccu) sehr schnell angesprochen wird.

ein list CCU_EG ergibt:

Internals:
   CCUNum     1
   Clients    :HMCCUDEV:HMCCUCHN:HMCCURPC:HMCCURPCPROC:
   DEF        192.168.2.144 ccudelay=10
   FUUID      5c44972e-f33f-a21d-008a-a0790245cb686964
   NAME       CCU_EG
   NOTIFYDEV  global,TYPE=(HMCCU|HMCCUDEV|HMCCUCHN)
   NR         26
   NTFY_ORDER 50-CCU_EG
   RPCState   running
   STATE      running/OK
   TYPE       HMCCU
   ccuaddr    BidCoS-RF
   ccuchannels 225
   ccudevices 41
   ccuif      BidCos-RF
   ccuinterfaces BidCos-RF,VirtualDevices,HmIP-RF
   ccuip      192.168.2.144
   ccuname    CCU_EG
   ccustate   active
   ccutype    CCU2/3
   host       192.168.2.144
   prot       http
   version    4.3.014
   READINGS:
     2019-03-01 08:26:18   count_channels  225
     2019-03-01 08:26:18   count_devices   41
     2019-03-01 08:26:18   count_groups    0
     2019-03-01 08:26:18   count_interfaces 3
     2019-03-01 08:26:18   count_programs  2
     2018-11-12 20:04:55   iface_addr_1    PEQ0625058
     2018-11-12 20:04:55   iface_addr_2    3014F711A0001F58A992F1A2
     2018-11-12 20:04:55   iface_conn_1    1
     2018-11-12 20:04:55   iface_conn_2    1
     2018-11-12 20:04:55   iface_ducy_1    30
     2018-11-12 20:04:55   iface_ducy_2    31
     2018-11-12 20:04:55   iface_type_1    CCU2
     2018-11-12 20:04:55   iface_type_2    HMIP_CCU2
     2019-03-01 13:37:43   rpcstate        running
     2019-03-01 13:38:51   state           OK
   hmccu:
     defInterface BidCos-RF
     defPort    2001
     evtime     0
     evtimeout  0
     rpccount   0
     rpcports   2001,2010
     updatetime 0
     adr:
       CCU_EG:
         address    BidCoS-RF
         addtype    dev
         valid      1
       CCU_EG:0:
         address    BidCoS-RF:0
         addtype    chn
         valid      1
...
     rpc:
Attributes:
   ccuflags   procrpc
   room       Homematic
   rpcinterfaces BidCos-RF,HmIP-RF
   rpcinterval 1
   rpcport    2001,2010
   rpcqueue   /tmp/ccuqueue
   rpcserver  on
   stateFormat rpcstate/state


ein get CCU_EG rpcevents ergibt:
Event statistics for server CB2001002024002144
Average event delay = 22.65
========================================
ET Sent by RPC server   Received by FHEM
----------------------------------------
EV                  0                 40

ND                  0                161

DD                  0                  0

RD                  0                  0

RA                  0                  0

UD                  0                  0

IN                  0                  0

EX                  0                  0

SL                  0                  1

TO                  0                  0

Event statistics for server CB2010002024002144
Average event delay = 8.49420289855072
========================================
ET Sent by RPC server   Received by FHEM
----------------------------------------
EV                345                690

ND                154                154

DD                  0                  0

RD                  0                  0

RA                  0                  0

UD                  0                  0

IN                  0                  0

EX                  0                  0

SL                  1                  1

TO                  0                  0


Die Systemlast des thinkerboards ist niedrig.
Der Fehler tritt gefühlt auf, seitdem die pivccu-module aktualisiert wurden.

Ich verwende seit ca. 20 Jahren Linux. Aber eigentlich als reiner Anwender. Ich habe eigentlich keine Programierkenntnisse.

Vielen Dank für eure Hilfe

zap

Verstehe ich das richtig: 2 virtuelle CCUs auf einem Rechner?
FHEM auf dem gleichen Rechner?
Die Hue Lampen sind an der CCU angelernt? Wenn ja, warum und warum nicht direkt an FHEM?
2xCCU3 mit ca. 100 Aktoren, Sensoren
Entwicklung: FHEM auf Proxmox Debian VM
Produktiv inzwischen auf Home Assistant gewechselt.
Maintainer: HMCCU, (Fully, AndroidDB)

theseer105

Hallo zap,

nein. Eine CCU3 (im EG) auf dem thinkerboard und eine CCU2 (im OG) auf einem pi. Die hue-Lampen werden über zwei hue bridges (wieder eine im EG und eine im OG) direkt über fhem angesprochen. Die Lampen funktionieren, wenn ich sie zum Beispiel mit
set HUEGroup2 on
anspreche ohne Verzögerung.

Danke

zap

#3
Eine Event Verzögerung von 22 Sekunden ist wirklich unterirdisch.
Schau mal in den CCU Logs nach, ob da Fehlermeldungen drin stehen.

fHem log ist sauber?

Oder du änderst den Betreff mal in irgendwas mit pivccu, wenn es tatsächlich am Update liegt
2xCCU3 mit ca. 100 Aktoren, Sensoren
Entwicklung: FHEM auf Proxmox Debian VM
Produktiv inzwischen auf Home Assistant gewechselt.
Maintainer: HMCCU, (Fully, AndroidDB)

theseer105

Hallo,

eines fällt mir noch ein Beim Start von FHEM wird bemängelt, dass die HomematicIP Fenster-/Türkontake nicht Antworten (steht dann beim Start von FHEM auch in der CCU unter Servicemeldungen). Die Meldungen verschwindet dann aber nach einer Zeit, bzw. wenn ich die Fenster öffne. Beim Start von FHEM hängt er einige Zeit und lässt sich nicht ansprechen (in diesem Zeitraum tauchen auch die Servicemeldungen auf). FHEM log:


2019.03.01 13:34:58 1: HMCCURPCPROC: [d_rpc002144BidCos_RF] Stopping RPC server CB2001002024002144
2019.03.01 13:34:58 1: HMCCURPCPROC: [d_rpc002144BidCos_RF] Deregistering RPC server http://192.168.2.24:7411/fh2001 with ID CB2001002024002144 at http://192.168.2.144:2001
2019.03.01 13:35:01 2: HMCCURPCPROC: [d_rpc002144BidCos_RF] RPC request error RPC::XML::Client::simple_request: RPC::XML::Client::send_request: HTTP server error: Can't connect to 192.168.2.144:2001
2019.03.01 13:35:04 2: HMCCURPCPROC: [d_rpc002144BidCos_RF] RPC request error RPC::XML::Client::simple_request: RPC::XML::Client::send_request: HTTP server error: Can't connect to 192.168.2.144:2001
2019.03.01 13:35:04 1: HMCCURPCPROC: [d_rpc002144BidCos_RF] Failed to deregister RPC server CB2001002024002144
2019.03.01 13:35:04 2: HMCCURPCPROC: [d_rpc002144BidCos_RF] Sending signal INT to RPC server process CB2001002024002144 with PID=10283
2019.03.01 13:35:04 2: HMCCURPCPROC: [d_rpc002144BidCos_RF] Scheduling cleanup in 30 seconds
2019.03.01 13:35:04 2: CCURPC: [d_rpc002144BidCos_RF] CB2001002024002144 received signal INT
2019.03.01 13:35:04 1: CCURPC: [d_rpc002144BidCos_RF] RPC server CB2001002024002144 stopped handling connections. PID=10283
2019.03.01 13:35:04 2: CCURPC: [d_rpc002144BidCos_RF] Number of I/O errors = 73
2019.03.01 13:35:05 1: HMCCURPCPROC: [d_rpc002144HmIP_RF] Stopping RPC server CB2010002024002144
2019.03.01 13:35:05 1: HMCCURPCPROC: [d_rpc002144HmIP_RF] Deregistering RPC server http://192.168.2.24:7420/fh2010 with ID CB2010002024002144 at http://192.168.2.144:2010
2019.03.01 13:35:07 2: HMCCURPCPROC: [d_rpc002144HmIP_RF] RPC request error RPC::XML::Client::simple_request: RPC::XML::Client::send_request: HTTP server error: Can't connect to 192.168.2.144:2010
2019.03.01 13:35:10 2: HMCCURPCPROC: [d_rpc002144HmIP_RF] RPC request error RPC::XML::Client::simple_request: RPC::XML::Client::send_request: HTTP server error: Can't connect to 192.168.2.144:2010
2019.03.01 13:35:10 1: HMCCURPCPROC: [d_rpc002144HmIP_RF] Failed to deregister RPC server CB2010002024002144
2019.03.01 13:35:10 2: HMCCURPCPROC: [d_rpc002144HmIP_RF] Sending signal INT to RPC server process CB2010002024002144 with PID=10284
2019.03.01 13:35:10 2: HMCCURPCPROC: [d_rpc002144HmIP_RF] Scheduling cleanup in 30 seconds
2019.03.01 13:35:10 2: CCURPC: [d_rpc002144HmIP_RF] CB2010002024002144 received signal INT
2019.03.01 13:35:10 1: CCURPC: [d_rpc002144HmIP_RF] RPC server CB2010002024002144 stopped handling connections. PID=10284
2019.03.01 13:35:10 2: CCURPC: [d_rpc002144HmIP_RF] Number of I/O errors = 55
2019.03.01 13:35:11 1: HMCCURPCPROC: [d_rpc002144HmIP_RF] RPC server process CB2010002024002144 terminated.
2019.03.01 13:35:11 2: HMCCURPCPROC: [d_rpc002144HmIP_RF] Stop I/O handling
2019.03.01 13:35:12 1: HMCCURPCPROC: [d_rpc002144BidCos_RF] RPC server process CB2001002024002144 terminated.
2019.03.01 13:35:12 1: HMCCU: [CCU_EG] All RPC servers inactive
2019.03.01 13:35:12 2: HMCCURPCPROC: [d_rpc002144BidCos_RF] Stop I/O handling
2019.03.01 13:35:30 3: go_eCharger: Read callback: Error: read from http://192.168.2.25:80 timed out
2019.03.01 13:36:30 3: go_eCharger: Read callback: Error: read from http://192.168.2.25:80 timed out
2019.03.01 13:37:42 2: HMCCU: [CCU_EG] Get RPC device for interface BidCos-RF
2019.03.01 13:37:42 2: HMCCU: [CCU_EG] Get RPC device for interface HmIP-RF
2019.03.01 13:37:42 2: HMCCURPCPROC: [d_rpc002144BidCos_RF] RPC server process started for interface BidCos-RF with PID=13021
2019.03.01 13:37:42 2: CCURPC: [d_rpc002144BidCos_RF] Initializing RPC server CB2001002024002144 for interface BidCos-RF
2019.03.01 13:37:42 2: HMCCURPCPROC: [d_rpc002144BidCos_RF] Callback server CB2001002024002144 created. Listening on port 7411
2019.03.01 13:37:42 2: CCURPC: [d_rpc002144BidCos_RF] CB2001002024002144 accepting connections. PID=13021
2019.03.01 13:37:42 1: HMCCURPCPROC: [d_rpc002144BidCos_RF] RPC server starting
2019.03.01 13:37:42 2: HMCCURPCPROC: [d_rpc002144HmIP_RF] RPC server process started for interface HmIP-RF with PID=13022
2019.03.01 13:37:42 2: CCURPC: [d_rpc002144HmIP_RF] Initializing RPC server CB2010002024002144 for interface HmIP-RF
2019.03.01 13:37:42 2: HMCCURPCPROC: [d_rpc002144HmIP_RF] Callback server CB2010002024002144 created. Listening on port 7420
2019.03.01 13:37:42 2: CCURPC: [d_rpc002144HmIP_RF] CB2010002024002144 accepting connections. PID=13022
2019.03.01 13:37:42 1: HMCCURPCPROC: [d_rpc002144HmIP_RF] RPC server starting
2019.03.01 13:37:42 2: HMCCURPCPROC: [d_rpc002144HmIP_RF] RPC server CB2010002024002144 enters server loop
2019.03.01 13:37:42 2: HMCCURPCPROC: [d_rpc002144HmIP_RF] Registering callback http://192.168.2.24:7420/fh2010 of type A with ID CB2010002024002144 at http://192.168.2.144:2010
2019.03.01 13:37:43 1: HMCCURPCPROC: [d_rpc002144HmIP_RF] RPC server CB2010002024002144 running
2019.03.01 13:37:43 2: HMCCURPCPROC: [d_rpc002144BidCos_RF] RPC server CB2001002024002144 enters server loop
2019.03.01 13:37:43 2: HMCCURPCPROC: [d_rpc002144BidCos_RF] Registering callback http://192.168.2.24:7411/fh2001 of type A with ID CB2001002024002144 at http://192.168.2.144:2001
2019.03.01 13:37:43 1: HMCCURPCPROC: [d_rpc002144BidCos_RF] RPC server CB2001002024002144 running
2019.03.01 13:37:43 1: HMCCU: [CCU_EG] All RPC servers running
2019.03.01 13:37:43 2: CCURPC: [d_rpc002144HmIP_RF] CB2010002024002144 NewDevice received 154 device and channel specifications
2019.03.01 13:37:43 2: CCURPC: [d_rpc002144BidCos_RF] CB2001002024002144 NewDevice received 161 device and channel specifications
2019.03.01 13:38:01 2: HMCCU: [CCU_EG] HMScript failed. http://192.168.2.144:8181/tclrega.exe: Select timeout/error:
2019.03.01 13:38:01 2: HMCCU: Update of device 00109709A8F421 failed
2019.03.01 13:38:06 2: HMCCU: [CCU_EG] HMScript failed. http://192.168.2.144:8181/tclrega.exe: Select timeout/error:
2019.03.01 13:38:06 2: HMCCU: Update of device 000C98A991E3B8 failed
2019.03.01 13:38:16 2: HMCCU: [CCU_EG] HMScript failed. http://192.168.2.144:8181/tclrega.exe: Select timeout/error:
2019.03.01 13:38:16 2: HMCCU: Update of device 00135709960DA9 failed
2019.03.01 13:38:20 2: HMCCU: [CCU_EG] HMScript failed. http://192.168.2.144:8181/tclrega.exe: Select timeout/error:
2019.03.01 13:38:20 2: HMCCU: Update of device 00109709ADBC9A failed
2019.03.01 13:38:51 2: HMCCU: [CCU_EG] Updated devices. Success=65 Failed=4


log der CCU im Anhang

theseer105

Nachdem ich die rpcserver gelöscht habe und fhem neu gestartet habe sind nun für jede ccu 2 rpcserver vorhanden (je einer für BidCos-RF und einer für HmIP-RF). Jetzt funktioniert es wieder