HMLAN Disconnect vermeintlich gelöst

[mcfly71]

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

[martinp876]

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.

[mcfly71]

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....

[martinp876]

ich werde einmal ein file basteln (das letzte habe ich schon wieder weggeworfen...)

[mcfly71]

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

[martinp876]

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

[mcfly71]

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....

[martinp876]

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

[mcfly71]

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

[Joachim]

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.

Code Auswählen Erweitern


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

[martinp876]

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

[mcfly71]

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

[martinp876]

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

[mcfly71]

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

[mcfly71]

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...