Hallo Forum,
ich bin nun seit einiger Zeit in der FHEM Gemeinde, habe bereits viele Dinge installiert und vieles ausprobiert.
Gestartet bin ich mit einem Windows Server und strawberry perl und einem CUNO, um nur Homematic Komponenten zu installieren. Da ich allerdings auch irgendwann Geräte mit Burst Modus besaß, musste ich gezwungenermaßen auf ein HMLAN umsteigen. Seit diesem Tag gab es 1000e Disconnects, ich habe hier daraufhin viel gelesen, geloggt, getan gemacht, weder WOL, noch presence ist bei mir aktiv. Das komische war: Ich habe mal alle devices (bis auf dummy devices) aus der cfg entnommen, und selbst dann kamen disconnects (zur Erinnerung: NIE!! ein disconnect beim CUNO). D.h. mein internes GBLan konnte es eigentlich nicht sein, überlastung des Windows Rechners auch nicht......
Entscheidend war ein Hinweis für mich von Martin: Der HMLAN muss alle 30 sec. gestreichelt werden....
Daraufhin habe ich (bei response Zeit Einstellung von 3) die 00_HMLAN.pm geändert in den Funktionen:
HMLAN_DoInit und HMLAN_KeepAlive jeweils die Zeilen:
InternalTimer(gettimeofday()+25 <----- , "HMLAN_KeepAlive", "keepAlive:".$name, 0);
Ich setzte die 25 sec (die ja eigentlich ausreichend wären) sukzessive runter. Momentan bin ich bei 10 angekommen, und die Disconnects hören ganz auf (bei jedem Runtersetzen wurde es besser).
@ Martin : Ist dies eine Lösung oder ist der interne Ablauf dadurch nun überlastet ?? Und wieso kann das sein ? Die 5 sec Karenzzeit, wie es ursprünglich war müssten ja eigentlich ausreichen.
Wohlgemerkt immer im Hinterkopf: Das ging auch immer so ohne!! jegliche Devices
Ein Kommentar von Martin wäre sehr toll........ (falls du nicht zuviel zu tun hast :-) )
Achja, und ich fahre alles momentan mit der neuesten Version, die ich gestern noch per update upgedatet habe.....
Cheers, Mcfly
Hi McFly,
5sec sollten eigentlich ausreichen. Dass du erst ruhe bekommst wenn du auf 10 sec runtergehst und damit 20sec delay vorbeugst ist sicher zu hoch. Da hat dein Ausbau irgend ein Problem. Es bedeuted, dass irgendetwas dein system bis zu ~19 sec blockiert.
WOL ist das einzige identifizierte Modul dass (bis es korrigiert ist) ein solchen Problem verursacht. Presence dispatched und forked, sollte also kein Problem verursachen (so lange die CPU noch Luft hat und die process prios stimmen....)
Ich wuerde an deiner Stelle versuchen die Ursachen zu finden. Zum ersten also der Normalbetrieb mit 25sec Einstellung: wie oft kommen die Probleme?
Zum 2. dann eine Analyse der FHEM jobs und timer. Wenn du alles raus nimmst heisst es, dass du ein quasi leeren fhem.cfg hast? Wir koennen mit einer instrumentierten load die FHEM tasks analysieren und sehen, ob hier ein schlaefer dabei ist.
Ich gehe davon aus, dass dein System nicht generell ueberlastet ist
Gruss
Martin
Nebensatz zur CUNO: die keep-alive message des HMLAN, auch wenn es hie und da zu disconnects kommt, gefaellt mir eigentlich gut. Bei einer CUNO wuerde ich mir das gleiche wuenschen. ggf. werde ich mir sogar ein keep-alive fuer jeden einzelnen Aktor einbauen, der beispielsweise den Status abfragt.
Hallo Martin:
> Wir koennen mit einer instrumentierten load die FHEM tasks analysieren und sehen, ob hier ein schlaefer dabei ist
Das würde ich gerne machen. Was muss ich dazu tun ??? Wäre irgendwie toll, wenn dann im Log sowas steht wie: Prozess xy oder Funktion xy Startzeit : xx:yy:zz und Endzeit xx:yy:zz oder sowas in der Art. Dann würde man ja sehen, wo der sich solange aufhält....
ich werde einmal ein file basteln (das letzte habe ich schon wieder weggeworfen...)
Super, sagst du mir - wenn es fertig ist - bitte bescheid ? Dann sauge ich es und probiere es sofort aus....
Vielen Dank schonmal im voraus
mcfy
Hi mcfly71,
mit dem fhem.pl bekommst du alle timer-gesteuerten Prozesse ins logfile - schau nach process und schalte mseglog ein.
Du kannst auch noch die Kommentarzeichen in Zeile 482/487/492 und 494 entfernen, dann werden alle Processe geprintet.
Gruss
Martin
Hallo Martin,
habe jetzt mal einen kleinen Schnipsel des Logs. Habe die anderen Disconnects ebenfalls untersucht. Diese sehen alle ähnlich aus:
Da, wo ich die Pfeile gemacht habe, finde ich die Diff-Werte etwas hoch, und die Fkt.
FW_closeOldClients wird auch nicht in jedem Zyklus aufgerufen. Leider gilt, dass
diese Funktion nicht immer, aber sehr häufig im Zyklus vor dem Disconnect aufgerufen wird...
Natürlich ist <***** der größte Abstand, aber ich schätze, das liegt anderen Ablauf innerhalb
der START:STEUERUNG_HM Funktion.
Hast du hierdurch eine Idee, was zu untersuchen ist, oder woran es liegt ?
Es sind 11 Disconnect's passiert zwischen gestern 20:00 Uhr und heute morgen 04:13 Uhr...
unregelmäßig ca. 20 Uhr, 21:30 Uhr, 22:13, 00:47, 01:02, 01:31, 02:34, 02:46, 03:50, 04:08, 04:13
2013.05.10 01:02:07.982 1: process start: HMLAN_KeepAliveCheck:keepAliveCk:STEUERUNG_HM
2013.05.10 01:02:07.982 1: process end:HMLAN_KeepAliveCheck:keepAliveCk:STEUERUNG_HM
2013.05.10 01:02:10.996 1: process soc start:WEB
2013.05.10 01:02:10.996 1: process soc end:WEB
2013.05.10 01:02:10.996 1: process soc start:STEUERUNG_HM
2013.05.10 01:02:10.996 1: process soc end:STEUERUNG_HM
2013.05.10 01:02:10.999 1: process soc start:WEB
2013.05.10 01:02:10.999 1: process soc end:WEB
2013.05.10 01:02:10.000 1: process soc start:STEUERUNG_HM
2013.05.10 01:02:10.000 1: process soc end:STEUERUNG_HM
2013.05.10 01:02:10.000 1: process start: FW_closeOldClients:0
2013.05.10 01:02:10.000 1: process end:FW_closeOldClients:0 <-------------------
2013.05.10 01:02:29.233 1: process soc start:WEB <----------------------------
2013.05.10 01:02:29.233 1: process soc end:WEB
2013.05.10 01:02:29.233 1: process soc start:STEUERUNG_HM
2013.05.10 01:02:29.233 1: process soc end:STEUERUNG_HM
2013.05.10 01:02:35.730 1: process soc start:WEB
2013.05.10 01:02:35.730 1: process soc end:WEB
2013.05.10 01:02:35.730 1: process soc start:STEUERUNG_HM <**********************
2013.05.10 01:02:35.730 1: 192.168.2.171:1000 disconnected, waiting to reappear
2013.05.10 01:02:40.730 1: process soc end: <**********************
2013.05.10 01:02:40.734 1: 192.168.2.171:1000 reappeared (STEUERUNG_HM)
hier noch ein nicht disconnect Zyklus:
2013.05.10 04:09:50.668 1: process start: HMLAN_KeepAlive:keepAlive:STEUERUNG_HM
2013.05.10 04:09:50.668 1: process end:HMLAN_KeepAlive:
2013.05.10 04:09:50.671 1: process soc start:WEB
2013.05.10 04:09:50.671 1: process soc end:WEB
2013.05.10 04:09:50.671 1: process soc start:STEUERUNG_HM
2013.05.10 04:09:50.671 1: process soc end:STEUERUNG_HM
2013.05.10 04:09:50.936 1: process soc start:WEB
2013.05.10 04:09:50.936 1: process soc end:WEB
2013.05.10 04:09:50.936 1: process soc start:STEUERUNG_HM
2013.05.10 04:09:50.940 1: process soc end:STEUERUNG_HM
2013.05.10 04:09:53.668 1: process soc start:WEB
2013.05.10 04:09:53.668 1: process soc end:WEB
2013.05.10 04:09:53.668 1: process soc start:STEUERUNG_HM
2013.05.10 04:09:53.668 1: process soc end:STEUERUNG_HM
2013.05.10 04:09:53.668 1: process soc start:WEB
2013.05.10 04:09:53.669 1: process soc end:WEB
2013.05.10 04:09:53.669 1: process soc start:STEUERUNG_HM
2013.05.10 04:09:53.669 1: process soc end:STEUERUNG_HM
2013.05.10 04:09:53.669 1: process start: HMLAN_KeepAliveCheck:keepAliveCk:STEUERUNG_HM
2013.05.10 04:09:53.669 1: process end:HMLAN_KeepAliveCheck:keepAliveCk:STEUERUNG_HM
2013.05.10 04:10:01.308 1: process soc start:WEB
2013.05.10 04:10:01.308 1: process soc end:WEB
2013.05.10 04:10:01.308 1: process soc start:STEUERUNG_HM
2013.05.10 04:10:01.315 1: process soc end:STEUERUNG_HM
2013.05.10 04:10:01.589 1: process soc start:WEB
2013.05.10 04:10:01.589 1: process soc end:WEB
2013.05.10 04:10:01.589 1: process soc start:STEUERUNG_HM
2013.05.10 04:10:01.594 1: process soc end:STEUERUNG_HM
2013.05.10 04:10:03.011 1: process soc start:WEB
2013.05.10 04:10:03.011 1: process soc end:WEB
2013.05.10 04:10:03.011 1: process soc start:STEUERUNG_HM
2013.05.10 04:10:03.011 1: process soc end:STEUERUNG_HM
2013.05.10 04:10:03.011 1: process start: FW_closeOldClients:0
2013.05.10 04:10:03.012 1: process end:FW_closeOldClients:0
2013.05.10 04:10:15.668 1: process soc start:WEB
2013.05.10 04:10:15.668 1: process soc end:WEB
2013.05.10 04:10:15.668 1: process soc start:STEUERUNG_HM
2013.05.10 04:10:15.668 1: process soc end:STEUERUNG_HM
2013.05.10 04:10:15.668 1: process soc start:WEB
2013.05.10 04:10:15.669 1: process soc end:WEB
2013.05.10 04:10:15.669 1: process soc start:STEUERUNG_HM
2013.05.10 04:10:15.669 1: process soc end:STEUERUNG_HM
2013.05.10 04:10:15.669 1: process start: HMLAN_KeepAlive:keepAlive:STEUERUNG_HM
2013.05.10 04:10:15.669 1: process end:HMLAN_KeepAlive:
2013.05.10 04:10:15.672 1: process soc start:WEB
2013.05.10 04:10:15.672 1: process soc end:WEB
2013.05.10 04:10:15.672 1: process soc start:STEUERUNG_HM
2013.05.10 04:10:15.672 1: process soc end:STEUERUNG_HM
2013.05.10 04:10:18.668 1: process soc start:WEB
2013.05.10 04:10:18.668 1: process soc end:WEB
2013.05.10 04:10:18.668 1: process soc start:STEUERUNG_HM
2013.05.10 04:10:18.668 1: process soc end:STEUERUNG_HM
2013.05.10 04:10:18.669 1: process soc start:WEB
2013.05.10 04:10:18.670 1: process soc end:WEB
2013.05.10 04:10:18.670 1: process soc start:STEUERUNG_HM
2013.05.10 04:10:18.670 1: process soc end:STEUERUNG_HM
2013.05.10 04:10:18.670 1: process start: HMLAN_KeepAliveCheck:keepAliveCk:STEUERUNG_HM
2013.05.10 04:10:18.670 1: process end:HMLAN_KeepAliveCheck:keepAliveCk:STEUERUNG_HM
2013.05.10 04:10:28.589 1: process soc start:WEB
2013.05.10 04:10:28.589 1: process soc end:WEB
2013.05.10 04:10:28.589 1: process soc start:STEUERUNG_HM
2013.05.10 04:10:28.589 1: process soc end:STEUERUNG_HM
2013.05.10 04:10:28.591 1: process soc start:WEB
2013.05.10 04:10:28.591 1: process soc end:WEB
2013.05.10 04:10:28.591 1: process soc start:STEUERUNG_HM
2013.05.10 04:10:28.591 1: process soc end:STEUERUNG_HM
2013.05.10 04:10:28.592 1: process start: Weather_GetUpdate:HASH(0x14c8ff4)
2013.05.10 04:10:28.691 1: process end:Weather_GetUpdate:HASH(0x14c8ff4)
2013.05.10 04:10:32.824 1: process soc start:WEB
2013.05.10 04:10:32.824 1: process soc end:WEB
2013.05.10 04:10:32.824 1: process soc start:STEUERUNG_HM
2013.05.10 04:10:32.827 1: process soc end:STEUERUNG_HM
2013.05.10 04:10:40.668 1: process soc start:WEB
2013.05.10 04:10:40.668 1: process soc end:WEB
2013.05.10 04:10:40.668 1: process soc start:STEUERUNG_HM
2013.05.10 04:10:40.668 1: process soc end:STEUERUNG_HM
2013.05.10 04:10:40.669 1: process soc start:WEB
2013.05.10 04:10:40.669 1: process soc end:WEB
2013.05.10 04:10:40.669 1: process soc start:STEUERUNG_HM
2013.05.10 04:10:40.669 1: process soc end:STEUERUNG_HM
2013.05.10 04:10:40.670 1: process start: HMLAN_KeepAlive:keepAlive:STEUERUNG_HM
2013.05.10 04:10:40.670 1: process end:HMLAN_KeepAlive:
2013.05.10 04:10:40.672 1: process soc start:WEB
2013.05.10 04:10:40.672 1: process soc end:WEB
2013.05.10 04:10:40.672 1: process soc start:STEUERUNG_HM
2013.05.10 04:10:40.673 1: process soc end:STEUERUNG_HM
2013.05.10 04:10:41.933 1: process soc start:WEB
2013.05.10 04:10:41.933 1: process soc end:WEB
2013.05.10 04:10:41.933 1: process soc start:STEUERUNG_HM
2013.05.10 04:10:41.937 1: process soc end:STEUERUNG_HM
2013.05.10 04:10:43.668 1: process soc start:WEB
2013.05.10 04:10:43.668 1: process soc end:WEB
2013.05.10 04:10:43.668 1: process soc start:STEUERUNG_HM
2013.05.10 04:10:43.668 1: process soc end:STEUERUNG_HM
2013.05.10 04:10:43.670 1: process soc start:WEB
2013.05.10 04:10:43.670 1: process soc end:WEB
2013.05.10 04:10:43.670 1: process soc start:STEUERUNG_HM
2013.05.10 04:10:43.670 1: process soc end:STEUERUNG_HM
2013.05.10 04:10:43.671 1: process start: HMLAN_KeepAliveCheck:keepAliveCk:STEUERUNG_HM
2013.05.10 04:10:43.671 1: process end:HMLAN_KeepAliveCheck:keepAliveCk:STEUERUNG_HM
Ich selbe sitze mit Hmmmmmm davor, und weiß nicht, wo ich ansetzen soll....
Hallo MyFly,
auf die Schnelle:
die Zeit zwischen end und start kann auch mal gross sein, kein Problem. FHEM hat eben auch mal nichts zu tun. Kritisch sind die Zeiten zwischen start und end.
Leider sehe ich im Fehlerfall nicht den "HMLAN_KeepAlive:keepAlive," Mutmasslich liegt der 3sec vor HMLAN_KeepAliveCheck:keepAliveCk, also um 01:02:04. Der sollte also um 01:02:29 wieder kommen.
Ich nehme an, dass respTime bei dir auf 3 gesetzt ist.
Der timer haette sogar noch zeit zwischen 1:2:29 und 1:2:34 anzuschlagen. Hier liegt pottentiell das Problem, FHEM prueft den abgelaufenen Timer nicht. Dass der timer verschwunden ist, kann ich mir nicht vorstellen.
Ein paar logs mehr vor dem crash waeren gut gewesen (auch gezipped ok)
Gruss
Martin
Hallo Martin,
ja du hast recht: Die respTime steht bei mir aus 3.
Anbei schicke ich dir das gesamte Log gezippt.
Ich hoffe du kannst dann was sagen......
VG McFly
Moin @ all,
Da ich das Problem auch schon seit längerem habe, habe ich mal den Ansatz mit Wireshark befolgt,
und eventuell einen Ansatz gefunden.
Bei mir passiert das disconnect immer dann, wenn mein Home-Server neugierig wird.
2013.05.09 23:02:30.507 1: HMLAN_Parse: HM_CFG_LAN V:03C1 sNo:IEQ0061863 d:169012 O:061863 t:4A81784A IDcnt:0000
2013.05.09 23:02:55.506 1: HMLAN_Send: HM_CFG_LAN I:K
2013.05.09 23:02:55.514 1: HMLAN/RAW: /HHM-LAN-IF,03C1,IEQ0061863,169012,061863,4A81D9FF,0000
2013.05.09 23:02:55.517 1: HMLAN_Parse: HM_CFG_LAN V:03C1 sNo:IEQ0061863 d:169012 O:061863 t:4A81D9FF IDcnt:0000
2013.05.09 23:03:20.517 1: HMLAN_Send: HM_CFG_LAN I:K
2013.05.09 23:03:22.526 1: HMLAN_Send: HM_CFG_LAN I:K
2013.05.09 23:03:24.536 1: HMLAN_Send: HM_CFG_LAN I:K
2013.05.09 23:03:25.429 1: 172.16.19.105:1000 disconnected, waiting to reappear
2013.05.09 23:06:44.017 1: 172.16.19.105:1000 reappeared (HM_CFG_LAN)
2013.05.09 23:06:44.021 1: HMLAN_Send: HM_CFG_LAN I:A061863
2013.05.09 23:06:44.026 1: HMLAN_Send: HM_CFG_LAN I:C
2013.05.09 23:06:44.029 1: HMLAN_Send: HM_CFG_LAN I:Y01,01,
2013.05.09 23:06:44.034 1: HMLAN_Send: HM_CFG_LAN I:Y02,00,
2013.05.09 23:06:44.037 1: HMLAN_Send: HM_CFG_LAN I:Y03,00,
2013.05.09 23:06:44.041 1: HMLAN_Send: HM_CFG_LAN I:Y03,00,
2013.05.09 23:06:44.046 1: HMLAN_Send: HM_CFG_LAN I:T191ECC64,04,00,00000000
2013.05.09 23:06:44.070 1: HMLAN/RAW: /HHM-LAN-IF,03C1,IEQ0061863,169012,061863,4A8556BA,0000
I00,00,00,00
I00,00,00,00
I00,00,00,00
I00,00,00,00
2013.05.09 23:06:44.076 1: HMLAN_Parse: HM_CFG_LAN V:03C1 sNo:IEQ0061863 d:169012 O:061863 t:4A8556BA IDcnt:0000
2013.05.09 23:07:09.057 1: HMLAN_Send: HM_CFG_LAN I:K
2013.05.09 23:07:09.067 1: HMLAN/RAW: /HHM-LAN-IF,03C1,IEQ0061863,169012,061863,4A85B891,0000
zu dieser Zeit bombardiert er mein Netzwerk mit APR-Anfragen
(siehe Anhang / see attachement)
Ich weiß allerdings nicht, wie das zu deuten oder zu vermeiden ist.
Gruß Joachim
Hallo Joachim,
das ist die 2. Moeglichkeit eines delays: wenn FHEM sich nicht selbst blockiert kann es sein, dass die CPU oder das netzwerk ueberlastet ist.
Belasten die arps auch die CPU zu 100%?
Um die arps zu begrenzen musst du natuerlich in die Application, die sie startet. Offensichtlich ein netzwert-screening, warum auch immer.
In deinem fall hat FHEM keine Antwort den HMLAN bekommen, offensichtlich wegen der last am ethernet.
Bei MyFly ist es das Ausbleiben des FHEM triggers - FHEM verpennt den keepalive. Das Problem liegt also anderswo.
Wie gesagt, bei dir musst du den "ARPer" finden. evtl ein DHCP server?
Gruss
Martin
Servus Martin,
das Ausbleiben des Triggers ist dann ein FHEM Fehler, oder Perl selbst Oder wo liegt der Fehler.. ?
Ich benutze das neueste Strawberry Perl (nur falls das von Interesse sein sollte)....
cheers
McFly
Hi McFly,
den Grund habe ich noch nicht gefunden. Könnte sein, dass es an FHEM liegt. Ist aber nicht normal, i.A. fehlt da nichts.
Gruss
Martin
Hallo Martin, ich habe selbst mal begonnen zu untersuchen:
Meine noch nicht ausgewerten Ergebnisse:
Habe im 00_HMLAN.pm immer mitgeloggt wann der InternalTimer für das nöchste KeepAlive gesetzt wird,
und wann es tatsächlich aufgerufen wird. Da kommen jetzt komische Dinge raus. Erstmal die Änderung in der pm-Datei (global Variablen oben nach dem main deklariert, unsauber, aber fürs debuggen ok:
##############################################
# $Id: 00_HMLAN.pm 3148 2013-05-03 17:36:26Z martinp876 $
package main;
$mcflyTest= 0;
$mcflyTest1= 0;
:
:
sub HMLAN_KeepAlive($) {#######################################################
my($in ) = shift;
$main::mcflyTest1= gettimeofday();
my(undef,$name) = split(':',$in);
my $hash = $defs{$name};
$hash->{helper}{keepAliveRec} = 0; # reset indicator
return if(!$hash->{FD});
HMLAN_SimpleWrite($hash, "K");
RemoveInternalTimer( "keepAlive:".$name);# avoid duplicate timer
my $rt = AttrVal($name,"respTime",1);
if ( $main::mcflyTest != 0 )
{
if ( $main::mcflyTest != $main::mcflyTest1 )
{
my $Diff= $main::mcflyTest1 - $main::mcflyTest;
Log 1, "Aufruf KeepAlive Diff: $Diff: IST: $main::mcflyTest1 SOLL: $main::mcflyTest";
}
}
$main::mcflyTest= gettimeofday()+25;
InternalTimer(gettimeofday()+$rt,"HMLAN_KeepAliveCheck","keepAliveCk:".$name,1);
InternalTimer($main::mcflyTest,"HMLAN_KeepAlive", "keepAlive:".$name, 1);
}
Und nun der Auszug der Log-Datei:
2013.05.13 09:45:13.681 1: Aufruf KeepAlive Diff: 0.000303983688354492: IST: 1368431113.6809 SOLL: 1368431113.6806
2013.05.13 09:45:38.685 1: Aufruf KeepAlive Diff: 0.00428509712219238: IST: 1368431138.6854 SOLL: 1368431138.68111
2013.05.13 09:46:03.697 1: Aufruf KeepAlive Diff: 0.0120542049407959: IST: 1368431163.69766 SOLL: 1368431163.6856
2013.05.13 09:46:28.710 1: Aufruf KeepAlive Diff: 0.0120019912719727: IST: 1368431188.70987 SOLL: 1368431188.69787
2013.05.13 09:46:53.710 1: Aufruf KeepAlive Diff: 0.000391006469726563: IST: 1368431213.71047 SOLL: 1368431213.71007
2013.05.13 09:47:18.718 1: Aufruf KeepAlive Diff: 0.00815510749816895: IST: 1368431238.71883 SOLL: 1368431238.71067
2013.05.13 09:47:43.719 1: Aufruf KeepAlive Diff: 0.000301122665405273: IST: 1368431263.71933 SOLL: 1368431263.71903
2013.05.13 09:48:08.727 1: Aufruf KeepAlive Diff: 0.00818800926208496: IST: 1368431288.72772 SOLL: 1368431288.71954
2013.05.13 09:48:09.728 1: Aufruf KeepAlive Diff: -23.9993870258331: IST: 1368431289.72854 SOLL: 1368431313.72793
2013.05.13 09:48:10.729 1: Aufruf KeepAlive Diff: -23.9992699623108: IST: 1368431290.72942 SOLL: 1368431314.72869
2013.05.13 09:48:11.730 1: Aufruf KeepAlive Diff: -23.9994440078735: IST: 1368431291.73017 SOLL: 1368431315.72962
2013.05.13 09:48:12.731 1: 192.168.2.171:1000 disconnected, waiting to reappear
2013.05.13 09:48:18.065 1: 192.168.2.171:1000 reappeared (STEUERUNG_HM)
2013.05.13 09:48:43.066 1: Aufruf KeepAlive Diff: 6.33647799491882: IST: 1368431323.06681 SOLL: 1368431316.73033
2013.05.13 09:49:08.067 1: Aufruf KeepAlive Diff: 0.00035405158996582: IST: 1368431348.06737 SOLL: 1368431348.06701
2013.05.13 09:49:33.068 1: Aufruf KeepAlive Diff: 0.000345945358276367: IST: 1368431373.06792 SOLL: 1368431373.06757
2013.05.13 09:49:58.068 1: Aufruf KeepAlive Diff: 0.000320911407470703: IST: 1368431398.06846 SOLL: 1368431398.06814
2013.05.13 09:50:23.069 1: Aufruf KeepAlive Diff: 0.000382900238037109: IST: 1368431423.06904 SOLL: 1368431423.06866
2013.05.13 09:50:48.081 1: Aufruf KeepAlive Diff: 0.0120549201965332: IST: 1368431448.08131 SOLL: 1368431448.06925
2013.05.13 09:51:13.082 1: Aufruf KeepAlive Diff: 0.000339984893798828: IST: 1368431473.08185 SOLL: 1368431473.08151
2013.05.13 09:51:38.090 1: Aufruf KeepAlive Diff: 0.00815391540527344: IST: 1368431498.09021 SOLL: 1368431498.08205
Mit negativen Werten habe ich jetzt so garnicht garnicht gerechnet..... Werde selbst noch überlegen was es bedeutet. Aber vielleicht hilft es dir als hint......
VG
mcfly
Ok, habe es verstanden, ist die 3 malige Wiederholung der KeepAliveCheck's.
Sind aber irgendwie so aus, als ob fhem alles richtig macht. nur beim Zeitpunkt
09:48:08.727 kommt kein ACK vom HMLAN, deswegen 3 WDH und dann disconnect...
da stimme ich zu, das Problem ist das fehlende ACK in diesem Fall.
Hallo Martin,
also lasse ich das Thema ruhen, da keine Lösung für mich ? Entweder ich lebe dann mit den Disconnects oder ich setze wieder auf 10 sec um, um diese so gut wie auf 0 zu reduzieren.....
Solltest du mal eine Lösung finden, dann sag doch bitte bescheid, jedenfalls vielen Dank, dass du dich mit mir beschäftigt hast.
Hier nochmals die Zusammenfassung HMLAN Modul mit neuester Firmware:
1) Windows Rechner XP (strawberry Perl)
2) Perl Prozess Priorität alles ausprobiert (momentan auf "above normal")
3) CPU Auslastung nicht besonders hoch, da Rechner sonst nur als EMail Server und FileServer eingesetzt
4) Kein WOL oder Presence Modul in Aktion
5) Beim entfernen aller defines aus der cfg (bis auf HMLAN und dummy's) trotzdem viele Disconnects
6) Neueste nightly build FHEM Version
7) Keine Peek Netzwerkdatenstöme auf meinem GIGABIT Netzwerk
Viele Disconnects und keine Lösung :-(
Hi,
ja, sorry, habe keine Loesung. Wie du festgestellt hast sendet FHEM korrekt aber HMLAN antwortet nicht, jedenfalls nicht in 4 sec.
Nachdem FHEM korrekt nach 1 sec nachfragt hat es nichts mit WOL oder anderen internen Verzoegerungen zu tun.
Moeglich waere mit wireshark o.ae. zu loggen. Der setzt sehr weit unten an und koennte feststellen, ob HMLAN sendet und es im strawberry verloren geht. Mehr habe ich leider nicht
Gruss
Martin
Hallo Martin,
ich wollte dir mal einen kurzen Zwischenstand geben.
Die disconnects sind immer noch da, allerdings konnte ich schonmal deren Anzahl minimieren,
da ich alle!!! notify's und at - Befehle ans Ende der cfg gesetzt habe. Eine Erklärung habe ich leider nicht.
Vorher konnte ich mehrere Set Befehle an meine vcd senden, und die Uhr danach stellen, dass in 2-3 Minuten ein disconnect kam. Seit ich das oben beschriebene gemacht habe, sind diese disconnects weg.
Auch hier habe ich keinerlei Erklärung, aber wenigstens wurde es reduziert.
Fazit:
AT- notify Befehle ziemlich am Anfang, teilweise vor der Definition der devices, die ein notify abfangen soll: disconnects bei vielen Set Befehlen, die im script 99_myUtils abliefen.
Alle diese Befehle ans Ende: Diese disconnects sind nicht mehr da....
Leider andere schon noch..
MfG
Mcfly
Hallo McFly,
seht interessant - erklaerung habe ich auch keine.
generell rate ich mit notifies sparsam zu sein und ungenutzte zu entfernen. Dazu zaehlen auch logs/filelogs. Eben alles, was auf Events reagiert.
Ich werde einmal versuchen, es zu testen.
Falls du logs ziehen wuerdest, mit
attr global verbose 5
beide Faelle aufnehmen (notify vorne und hinten), gleiche Kommandos ausfuehren. In den logs sollte man erkennen koennen, was laenger dauert und welcher Teil.
Die Beobachtung halte ich fuer bedenklich... FHEM sollte so nicht arbeiten.
Zu den disconnects (falls wir es oben nicht finden)
- wie haeufig kommen die jetzt?
- kannst du logs ziehen, messages im Rohformat bitte.
Gruss
Martin