FritzBox 7390, HM-CC-RT-DN Anfangsprobleme

[KaiK]

Ahh cool.
Ist das im Update der 00_CUL.pm drin?

VG
Kai

[martinp876]

es ist in 10_CUL_HM.pm

und es ist heute eingecheckt, also morgen im update (oder heute manuell in SVN)

[Thorsten Pferdekaemper]

Hi,
so, heute war der dritte RT dran. Vorher aber update check und update...
Der RT hat für das Pairing nur einen Anlauf gebraucht und beim runterzählen ist er nicht einmal zur 29 gekommen. Die Kanäle wurden angelegt und soweit ich das erkennen kann wird auch alles angezeigt.

ABER: Leider wurden die FileLogs nicht automatisch angelegt. Per createlog-Kommando ging's dann komischerweise. Hier ist der ensprechende Log-Auszug:

Code Auswählen Erweitern


2014.01.05 17:33:59 3: CUL_HM Unknown device CUL_HM_HM_CC_RT_DN_21F833 is now defined
2014.01.05 17:34:00 3: Device CUL_HM_HM_CC_RT_DN_21F833 added to ActionDetector with 000:10 time
2014.01.05 17:34:00 3: CUL_HM pair: CUL_HM_HM_CC_RT_DN_21F833 thermostat, model HM-CC-RT-DN serialNr KEQ0506349
2014.01.05 17:34:00 2: CUL_HM set CUL_HM_HM_CC_RT_DN_21F833 getConfig
2014.01.05 17:34:05 3: Device CUL_HM_HM_CC_RT_DN_21F833 added to ActionDetector with 000:10 time
2014.01.05 17:35:53 1: 192.168.178.152:1000 disconnected, waiting to reappear
2014.01.05 17:35:53 1: HMLAN_Parse: HMLAN1 new condition disconnected
2014.01.05 17:36:58 1: 192.168.178.152:1000 reappeared (HMLAN1)
2014.01.05 17:36:58 1: HMLAN_Parse: HMLAN1 new condition init
2014.01.05 17:36:58 2: CUL_HM set CUL_HM_HM_CC_RT_DN_21F833_Clima getConfig
2014.01.05 17:36:58 1: HMLAN_Parse: HMLAN1 new condition ok
2014.01.05 17:39:06 2: CUL_HM set CUL_HM_HM_CC_RT_DN_21F833_ClimaTeam getConfig
2014.01.05 17:41:26 2: CUL_HM set CUL_HM_HM_CC_RT_DN_21F833_remote getConfig
2014.01.05 17:57:43 3: Device CUL_HM_HM_CC_RT_DN_21F833 added to ActionDetector with 000:10 time
2014.01.05 17:57:43 3: CUL_HM pair: CUL_HM_HM_CC_RT_DN_21F833 thermostat, model HM-CC-RT-DN serialNr KEQ0506349
2014.01.05 17:57:43 2: CUL_HM set CUL_HM_HM_CC_RT_DN_21F833 getConfig
2014.01.05 18:04:22 3: CUL_HM Unknown device CUL_HM_HM_CC_RT_DN_21F833 is now defined
2014.01.05 18:04:22 3: Device CUL_HM_HM_CC_RT_DN_21F833 added to ActionDetector with 000:10 time
2014.01.05 18:04:22 3: CUL_HM pair: CUL_HM_HM_CC_RT_DN_21F833 thermostat, model HM-CC-RT-DN serialNr KEQ0506349
2014.01.05 18:04:22 2: CUL_HM set CUL_HM_HM_CC_RT_DN_21F833 getConfig
2014.01.05 18:04:27 3: Device CUL_HM_HM_CC_RT_DN_21F833 added to ActionDetector with 000:10 time
2014.01.05 18:06:30 2: CUL_HM set CUL_HM_HM_CC_RT_DN_21F833_WindowRec getConfig
2014.01.05 18:07:47 1: 192.168.178.152:1000 disconnected, waiting to reappear
2014.01.05 18:07:47 1: HMLAN_Parse: HMLAN1 new condition disconnected
2014.01.05 18:08:52 1: 192.168.178.152:1000 reappeared (HMLAN1)
2014.01.05 18:08:52 1: HMLAN_Parse: HMLAN1 new condition init
2014.01.05 18:08:52 1: HMLAN_Parse: HMLAN1 new condition ok
2014.01.05 18:09:24 2: CUL_HM set CUL_HM_HM_CC_RT_DN_21F833_Clima getConfig
2014.01.05 18:10:36 2: autocreate: define FileLog_CUL_HM_HM_CC_RT_DN_21F833 FileLog ./log/CUL_HM_HM_CC_RT_DN_21F833-%Y%m%d.log CUL_HM_HM_CC_RT_DN_21F833
Use of uninitialized value $val in substitution (s///) at fhem.pl line 1241.
Use of uninitialized value $val in substitution (s///) at fhem.pl line 1242.
Use of uninitialized value $val in concatenation (.) or string at fhem.pl line 1243.
Use of uninitialized value $val in substitution (s///) at fhem.pl line 1241.
Use of uninitialized value $val in substitution (s///) at fhem.pl line 1242.
Use of uninitialized value $val in concatenation (.) or string at fhem.pl line 1243.
Use of uninitialized value $val in substitution (s///) at fhem.pl line 1241.
Use of uninitialized value $val in substitution (s///) at fhem.pl line 1242.
Use of uninitialized value $val in concatenation (.) or string at fhem.pl line 1243.
Use of uninitialized value $val in substitution (s///) at fhem.pl line 1241.
Use of uninitialized value $val in substitution (s///) at fhem.pl line 1242.
Use of uninitialized value $val in concatenation (.) or string at fhem.pl line 1243.
Use of uninitialized value $val in substitution (s///) at fhem.pl line 1241.
Use of uninitialized value $val in substitution (s///) at fhem.pl line 1242.
Use of uninitialized value $val in concatenation (.) or string at fhem.pl line 1243.
Use of uninitialized value $val in substitution (s///) at fhem.pl line 1241.
Use of uninitialized value $val in substitution (s///) at fhem.pl line 1242.
Use of uninitialized value $val in concatenation (.) or string at fhem.pl line 1243.
2014.01.05 18:12:08 2: CUL_HM set CUL_HM_HM_CC_RT_DN_21F833_ClimaTeam getConfig
2014.01.05 18:13:36 2: autocreate: define FileLog_CUL_HM_HM_CC_RT_DN_21F833_Clima FileLog ./log/CUL_HM_HM_CC_RT_DN_21F833_Clima-%Y%m%d.log CUL_HM_HM_CC_RT_DN_21F833_Clima
Use of uninitialized value $val in substitution (s///) at fhem.pl line 1241.
Use of uninitialized value $val in substitution (s///) at fhem.pl line 1242.
Use of uninitialized value $val in concatenation (.) or string at fhem.pl line 1243.
Use of uninitialized value $val in substitution (s///) at fhem.pl line 1241.
Use of uninitialized value $val in substitution (s///) at fhem.pl line 1242.
Use of uninitialized value $val in concatenation (.) or string at fhem.pl line 1243.
Use of uninitialized value $val in substitution (s///) at fhem.pl line 1241.
Use of uninitialized value $val in substitution (s///) at fhem.pl line 1242.
Use of uninitialized value $val in concatenation (.) or string at fhem.pl line 1243.
Use of uninitialized value $val in substitution (s///) at fhem.pl line 1241.
Use of uninitialized value $val in substitution (s///) at fhem.pl line 1242.
Use of uninitialized value $val in concatenation (.) or string at fhem.pl line 1243.
Use of uninitialized value $val in substitution (s///) at fhem.pl line 1241.
Use of uninitialized value $val in substitution (s///) at fhem.pl line 1242.
Use of uninitialized value $val in concatenation (.) or string at fhem.pl line 1243.
Use of uninitialized value $val in substitution (s///) at fhem.pl line 1241.
Use of uninitialized value $val in substitution (s///) at fhem.pl line 1242.
Use of uninitialized value $val in concatenation (.) or string at fhem.pl line 1243.
2014.01.05 18:14:27 2: CUL_HM set CUL_HM_HM_CC_RT_DN_21F833_remote getConfig
2014.01.05 18:15:15 1: 192.168.178.152:1000 disconnected, waiting to reappear
2014.01.05 18:15:15 1: HMLAN_Parse: HMLAN1 new condition disconnected
Use of uninitialized value $val in substitution (s///) at fhem.pl line 1241.
Use of uninitialized value $val in substitution (s///) at fhem.pl line 1242.
Use of uninitialized value $val in concatenation (.) or string at fhem.pl line 1243.
Use of uninitialized value $val in substitution (s///) at fhem.pl line 1241.
Use of uninitialized value $val in substitution (s///) at fhem.pl line 1242.
Use of uninitialized value $val in concatenation (.) or string at fhem.pl line 1243.
Use of uninitialized value $val in substitution (s///) at fhem.pl line 1241.
Use of uninitialized value $val in substitution (s///) at fhem.pl line 1242.
Use of uninitialized value $val in concatenation (.) or string at fhem.pl line 1243.
Use of uninitialized value $val in substitution (s///) at fhem.pl line 1241.
Use of uninitialized value $val in substitution (s///) at fhem.pl line 1242.
Use of uninitialized value $val in concatenation (.) or string at fhem.pl line 1243.
Use of uninitialized value $val in substitution (s///) at fhem.pl line 1241.
Use of uninitialized value $val in substitution (s///) at fhem.pl line 1242.
Use of uninitialized value $val in concatenation (.) or string at fhem.pl line 1243.
Use of uninitialized value $val in substitution (s///) at fhem.pl line 1241.
Use of uninitialized value $val in substitution (s///) at fhem.pl line 1242.
Use of uninitialized value $val in concatenation (.) or string at fhem.pl line 1243.
2014.01.05 18:16:16 1: 192.168.178.152:1000 reappeared (HMLAN1)
2014.01.05 18:16:16 1: HMLAN_Parse: HMLAN1 new condition init
2014.01.05 18:16:17 1: HMLAN_Parse: HMLAN1 new condition ok

Noch ein paar Kommentare dazu:
17:33:59 Hier habe ich das erste Pairing gemacht. Es hat auch funktioniert, bis auf die Logs.
17:35:53 Hier hat sich anscheinend der HMLAN mal kurz abgemeldet, keine Ahnung warum. Ich habe auch keine Probleme bemerkt.
17:57:43 Ich dachte ein erneutes Pairing würde die Logs erzeugen, das war aber nicht so.
18:07:47 Mal wieder "HMLAN disconnected", aber keine Probleme bemerkt
18:10:36 Das kommt wohl vom manuellen "createlog". Vielleicht haben die Fehlermeldungen danach was mit dem Problem zu tun. Das createlog hat aber funktioniert.
18:13:36 Noch ein createlog für den Clima-Channel, siehe oben.
18:15:15 Mal wieder ein HMLAN disconnect, aber wieder habe ich nichts gespürt.

Für mich funktioniert das jetzt, aber ich denke mal dass der autocreate eigentlich die Logs automatisch anlegen sollte.
Gruß,
   Thorsten

[martinp876]

Hi Thorsten,

ok, das mit den Logfiles habe ich nicht geprüft (da ich eh ein gegner davon bin..... wer braucht diese unmengen einzelner logfiles...)
um es in einem zug durchziehen zu können musste ich einen shortcut einbauen. Ich werde mal nach dem logfile generator suchen...
Danke für den Tip.

das mit deinen disconnects solltest du untersuchen. Da hast du mittelfristig ein Problem. Oder waren die 3 disconnects eine ausnahme?

Gruss Martin

[Thorsten Pferdekaemper]

Hi Martin,

mir persönlich ist inzwischen eigentlich egal, ob die Logfiles automatisch angelegt werden oder nicht. Ich denke aber, dass es funktionieren sollte wenn der autocreate schon eine Einstellung dafür hat. Soweit ich das sehe, kann man es ja auch abschalten.

Von wegen disconnects: Normalerweise passiert das nicht, aber so alle zwei Tage schon. Ich glaube aber, dass es nur vorkommt, wenn man ein Pairing vornimmt oder irgendwas macht, was die FritzBox belastet. Allerdings sind das nur Vermutungen. Was könnte ich denn tun, um das Problem einzukreisen?

Gruß,
  Thorsten

[martinp876]

Hi Thorsten
ja, autocreate sollte das anlegen der Logfiles unterstützen
ja, man kann es abschalten (mein default)

um disconnects einzukreisen kannst du
- nachsehen, was HMLAN meldet und wie
   msgKeepAlive dlyMax:3.014 bufferMin:1
   msgLoadEst 1hour:0% 10min steps: 0/0/0/0/0/0
   msgParseDly min:1 max:3112 last:10 cnt:1603
stehen. keepAlive max delay von 5 sec zeigt, dass du an der Grenze zum disconnect bist. Eingentlich sollte es kleiner 1 sec sein.
mit appptime kannst du suchen, welchen jobs lange dauern und damit gefährlich sind

Gruss Martin

[Thorsten Pferdekaemper]

Tja...

Code Auswählen Erweitern

msgKeepAlive dlyMax:8.612 bufferMin:-3
msgLoadEst 1hour:0% 10min steps: 0/0/0/0/0/0
msgParseDly min:-2 max:9320 last:9 cnt:2081

und

Code Auswählen Erweitern

                                name             function    max  count    total  average param Max call
             FileLog_og_bd_HeizungOp          FileLog_Get   2173      3     6434  2144.67 HASH(0xfce368); FileLog_og_bd_HeizungOp; CURRENT; INT; 2014-01-06_00:00:00; 2014-01-07_00:00:01; 4:og_bd_HeizungOp.desired-temp\x3a::; 4:og_bd_HeizungOp.measured-temp\x3a::; 4:og_bd_HeizungOp.ValvePosition\x3a::
             FileLog_og_sz_HeizungOp          FileLog_Get   2159      3     6415  2138.33 HASH(0xd934f0); FileLog_og_sz_HeizungOp; CURRENT; INT; 2014-01-06_00:00:00; 2014-01-07_00:00:01; 4:og_sz_HeizungOp.desired-temp\x3a::; 4:og_sz_HeizungOp.measured-temp\x3a::; 4:og_sz_HeizungOp.ValvePosition\x3a::
             FileLog_og_ku_HeizungOp          FileLog_Get   2136      3     6366  2122.00 HASH(0xd921f8); FileLog_og_ku_HeizungOp; CURRENT; INT; 2014-01-06_00:00:00; 2014-01-07_00:00:01; 4:og_ku_HeizungOp.desired-temp\x3a::; 4:og_ku_HeizungOp.measured-temp\x3a::; 4:og_ku_HeizungOp.ValvePosition\x3a::
        FHEMWEB:192.168.178.24:49262              FW_Read   1307     12     1360   113.33 HASH(0x1083050)
                              HMLAN1           HMLAN_Read    396      9      570    63.33 HASH(0xa662e8)

Kann es sein, dass FHEM beim Aufbereiten der SVG-Grafiken alles andere vergisst?

Gruß,
   Thorsten

[martinp876]

Hi Thorsten,

klar - grafik ist immer aufwändig.

msgParseDly min:-2 max:9320 last:9 cnt:2081

9,3 sec delay beim message verarbeiten - da klappen selbst wiederholer nicht

FileLog_og_bd_HeizungOp          FileLog_Get   2173      3     6434  2144.67 ...

über 2 sec pause - ggf sogar akkumuliert durch mehrere aufeinander folgende Darstellungen

Du solltest dich bei den Machern der Grafik erkundigen, wie sie dies auslagern können.

Du kannst mit dem Attribut wdTimer das austimen es keepalive verhindern - setze es auf 20 oder kleiner. Aber generell ist das timing der Frontends kritisch und nicht echtzeit-geeignet

Gruss Martin

[Thorsten Pferdekaemper]

Hi,
an dem wdTimer mache ich erstmal nichts, da ich nicht verstehe, was das macht. Außerdem habe ich noch keine Probleme an der tatsächlichen Funktion des Ganzen feststellen können. Mir ist auch nicht so recht klar, was diese disconnects tatsächlich bedeuten.

Soweit ich das aber verstehe, macht FHEM kein Multithreading mit Prioritäten, sondern es passiert alles in einem Task. Das ist natürlich problematisch für Anwendungen, die mit externen Systemen kommunizieren sollen. Ich werde da mal weiterforschen. 

Gruß,
    Thorsten

[martinp876]

Hi Thorsten,

HMLAN wird per default alle 25 sec getriggert. Diese Zeit kannst du runtersetzen, dann passiert es öfter. Wenn der Trigger nicht nach 30sec erscheint startet HMLANdie Connection neu. Es kann zu message-verlusten kommen.

Gruss Martin

[Thorsten Pferdekaemper]

Hi,
aha, das bedeutet also, dass nichts länger dauern darf als (30 - wdTimer) Sekunden. Ok, da werde ich aber erstmal versuchen, die SVGs zu beschleunigen.
Danke&Gruß,
   Thorsten

[martinp876]

Hi Thorsten,

nach 30sec disconnected HLAN 'sicher'.
wir triggern 5 sec vor ablauf, also alle 25sec. Damit bleiben 5 sec (kann der User einstellen).
Diese zeit ist natürlich die Akkumulierte aus allem, was dazwischen kommen.
Cool wäre es lange Auswertungen zu dispatchen. Nachteil ist, dass man es nicht sofort zurückgeben kann und damit die web-darstellung schwieriger wird - ich habe auch ein paar kandidaten.
Blocking bietet eine, wenn auch performance-lastige möglichkeit.

Beschleunigen ist immer gut.
Letztendlich sollte es (wie alle Frontend aktionen) in einem anderen Prozess laufen, mit geringer prio um echtzeit- tasks laufen zu lassen

Gruss Martin

[Thorsten Pferdekaemper]

Hi,
danke. Ich denke, ich schaffe es, die plots auf unter eine Sekunde zu drücken. Siehe hier: http://forum.fhem.de/index.php/topic,18442.msg123486.html#msg123486. Das mit den parallelen Prozessen scheint mit plotfork zu gehen, aber das habe ich noch nicht ausprobiert.
Gruß,
    Thorsten

[martinp876]

Hi Thorsten,

wie schon gesagt, optimieren ist immer gut!

plotfork habe ich einmal getestet (hatte es bisher nicht gesehen...)- funktioniert gut in meinem Fall.
Wie prospektiert werden die Aktionen in einen anderen Prozess ausgelagert. Die Latenz des aktuellen Prozesses ist immer unter 500ms geblieben. Es waren so 250ms - der Ausreißer von 480ms könnte einem Linux taskswitch geschuldet sein.

plotfork sollte man DRINGEND allen empfehlen, die Grafik nutzen. Es sollte default sein... leider ist windows ausgeschlossen was natürlich den Default probleme macht. Warum eigentlich? fork sollte auch in windows funktionieren

In meinem Fall ist die processdauer leicht über 10sec - und je nach gewähltem plot-Ausschnitt sicher noch deutlich größer.

Gruss Martin

[Thorsten Pferdekaemper]

leider ist windows ausgeschlossen was natürlich den Default probleme macht. Warum eigentlich? fork sollte auch in windows funktionieren

Anscheinend nicht wirklich:
https://www.google.de/search?q=fork+windows&rlz=

Gruß,
   Thorsten