Seit Update vom 05.02. ständige disconnected Meldungen vom HMLAN

[Dennis D.]

Hallo zusammen,

seit dem heutigen Update wird mein log von folgender Meldung geflutet:

2013.02.05 18:02:50 1: 192.168.178.39:1000 disconnected, waiting to reappear
2013.02.05 18:02:58 1: 192.168.178.39:1000 reappeared (LANInterface)
2013.02.05 18:05:25 1: 192.168.178.39:1000 disconnected, waiting to reappear
2013.02.05 18:05:36 1: 192.168.178.39:1000 reappeared (LANInterface)
2013.02.05 18:08:03 1: 192.168.178.39:1000 disconnected, waiting to reappear
2013.02.05 18:08:13 1: 192.168.178.39:1000 reappeared (LANInterface)
2013.02.05 18:10:43 1: 192.168.178.39:1000 disconnected, waiting to reappear
2013.02.05 18:10:55 1: 192.168.178.39:1000 reappeared (LANInterface)
2013.02.05 18:11:29 1: 192.168.178.39:1000 disconnected, waiting to reappear
2013.02.05 18:11:39 1: 192.168.178.39:1000 reappeared (LANInterface)
2013.02.05 18:12:41 1: 192.168.178.39:1000 disconnected, waiting to reappear
2013.02.05 18:12:54 1: 192.168.178.39:1000 reappeared (LANInterface)
2013.02.05 18:13:25 1: 192.168.178.39:1000 disconnected, waiting to reappear
2013.02.05 18:13:35 1: 192.168.178.39:1000 reappeared (LANInterface)
2013.02.05 18:15:57 1: 192.168.178.39:1000 disconnected, waiting to reappear
2013.02.05 18:16:03 1: 192.168.178.39:1000 reappeared (LANInterface)
2013.02.05 18:17:29 1: 192.168.178.39:1000 disconnected, waiting to reappe

Kann das noch jemand bestätigen?

[kossmann]

Ich kann dies zumindest nicht bestätigen. Bei mir taucht weiterhin alle 30 Sekunden folgendes Keep-Alive-Meldung (inkl. der Leerzeile) auf, allerdings kein einziges disconnected...

Code Auswählen Erweitern

2013.02.05 20:04:25.245 1: HMLAN_Send:  K
2013.02.05 20:04:25.248 1: HMLAN/RAW: /HHM-LAN-IF,03C1,JEQ0185...,1ACAC0,<hmId>,434E4BE8,0008

2013.02.05 20:04:25.249 1: HMLAN_Parse: MyHMLAN V:03C1 sNo:JEQ0185... d:1ACAC0 O:<hmId> m:434E4BE8 IDcnt:0008
Sie kommt natürlich daher, da ich z.Zt. das loglevel und hmProtocolEvents entsprechend gesetzt habe, aber mir hat immer noch niemand gesagt, dass dies alle 30 Sekunden so richtig ist und warum dort eine Leerzeile auftaucht.

Vielleicht hast du nur ein Netz-/Switch-Problem. Mach doch mal alles Stromlos, d.h. die Kiste auf der FHEM läuft, HMLAN und einen eventuell dazwischen hängenden Switch.

[Martin Thomas Schrott]

hi ja k alle 30 sec ist normal und notwendig sonst disconnected er.
Leerzeile muss martin beantworten. Entweder zum leichteren erkennen od. Ein typo?
Lg
martin

[Jumbo]

habe exact das gleiche problem !

[kossmann]

Ich habe noch mal nachgesehen, bei mir tauchen die Meldungen auch auf, aber nicht öfter, als sonst auch - hier alle Meldungen der letzten 3 Wochen (letztes Update wurde heute früh durchgeführt, inkl. diverser Neustarts heute):

Code Auswählen Erweitern

2013.01.16 02:31:34.005 1: 10.81.0.2:1000 disconnected, waiting to reappear
2013.01.16 07:19:54.832 1: 10.81.0.2:1000 disconnected, waiting to reappear
2013.01.17 02:23:29.180 1: 10.81.0.2:1000 disconnected, waiting to reappear
2013.01.19 02:22:33.890 1: 10.81.0.2:1000 disconnected, waiting to reappear
2013.01.19 17:32:38.719 1: 10.81.0.2:1000 disconnected, waiting to reappear
2013.01.21 07:49:48.566 1: 10.81.0.2:1000 disconnected, waiting to reappear
2013.01.22 12:10:30.118 1: 10.81.0.2:1000 disconnected, waiting to reappear
2013.01.23 02:20:44.085 1: 10.81.0.2:1000 disconnected, waiting to reappear
2013.01.23 14:16:44.501 1: 10.81.0.2:1000 disconnected, waiting to reappear
2013.01.23 18:19:10.061 1: 10.81.0.2:1000 disconnected, waiting to reappear
2013.01.24 02:27:44.948 1: 10.81.0.2:1000 disconnected, waiting to reappear
2013.01.25 01:05:10.836 1: 10.81.0.2:1000 disconnected, waiting to reappear
2013.01.28 02:26:01.241 1: 10.81.0.2:1000 disconnected, waiting to reappear
2013.01.28 11:27:19.323 1: 10.81.0.2:1000 disconnected, waiting to reappear
2013.01.28 17:50:43.722 1: 10.81.0.2:1000 disconnected, waiting to reappear
2013.01.28 22:34:10.040 1: 10.81.0.2:1000 disconnected, waiting to reappear
2013.01.30 15:05:50.892 1: 10.81.0.2:1000 disconnected, waiting to reappear
2013.01.30 18:00:32.937 1: 10.81.0.2:1000 disconnected, waiting to reappear
2013.02.01 13:20:21.676 1: 10.81.0.2:1000 disconnected, waiting to reappear
2013.02.02 02:15:59.332 1: 10.81.0.2:1000 disconnected, waiting to reappear
2013.02.02 10:58:16.128 1: 10.81.0.2:1000 disconnected, waiting to reappear
2013.02.02 17:40:51.476 1: 10.81.0.2:1000 disconnected, waiting to reappear
2013.02.02 18:25:39.707 1: 10.81.0.2:1000 disconnected, waiting to reappear
2013.02.02 19:10:25.189 1: 10.81.0.2:1000 disconnected, waiting to reappear
2013.02.03 15:48:33.286 1: 10.81.0.2:1000 disconnected, waiting to reappear
2013.02.03 16:48:19.552 1: 10.81.0.2:1000 disconnected, waiting to reappear
2013.02.03 17:18:39.415 1: 10.81.0.2:1000 disconnected, waiting to reappear
2013.02.04 08:44:46.569 1: 10.81.0.2:1000 disconnected, waiting to reappear
2013.02.04 14:40:55.407 1: 10.81.0.2:1000 disconnected, waiting to reappear
2013.02.05 10:15:58.791 1: 10.81.0.2:1000 disconnected, waiting to reappear
2013.02.05 16:47:32.730 1: 10.81.0.2:1000 disconnected, waiting to reappear
2013.02.05 17:02:21.720 1: 10.81.0.2:1000 disconnected, waiting to reappear

[MisterEltako]

Hi!

Bei mir sind es auch tgl. 2 Meldungen über Disconnect's früh (ca 7:07 Uhr) und abends (ca. 19:10).
An diesen Zeitpunkten schaltet bei mir nix, kann dadurch also nicht dadurch erzeugt sein, sondern erscheint spontan...

MfG, MisterEltako.

[Dennis D.]

also hardwareseitig gab es keine veränderungen. 1-2 disconntected meldungen am Tag hatte ich früher auch. seit dem update kommen sie aber alle 1-3 Minuten. habe die alte CUL_HM zurückgespielt und nun lief es wieder. ich schau mir das aber mal genauer an.

[MisterEltako]

Hi!

Also ich habe gerstern Abend ein aktelles Update gemacht bis zu dem Update vom 27.01.13 hatte ich keinerlei Disconnect's. Seit dem und den dann jeweils tgl. durchgeführten Updates kommen immer früh und abends wie oben schon geschrieben (2 früh, 2 abends)die Disconnect's. Schade war froh das diese Meldungen weg waren. Das hatten damals Änderungen von Martin876 behoben. Er wird sicher wieder den Fehler finden. Leider komme ich erst heute Abend dazu meine genauen Log's zu posten.

[martinp876]

Hi Alle,

kleinigkeiten: Die Leerzeile war schon vor mir - kommt von der Methode, wie die message gesplittet und dann geloggt werden. Da mich das sowieso nervt und in diesem Teil noch nie ein Fehler auftrat (danke Rudi) schalte ich das immer ab. Dazu kann man in 00_hmlan debug auf 1 setzen. Ein User-interface dazu habe ich nicht eingebaut - aber wenne s mehr wünschen... In der Regel lesen die User diesen level aber wohl eher nicht.


Zum Problem, meine Einschaetzung:
Ich denke nicht, dass das Problem in HM liegt. FHEM hat ein generelles Problem mit timings - man muss allen Applikationen vertrauen, dass sie einen wieder ranlassen.
Falls es jemand beobachtet hat, das letzte mal war es das wake-on-lan modul (das meines wissens immer noch nicht repariert ist). Es macht Probleme wenn es geschlagene 10sec nach nicht vorhandenen devices pingt. Wenn der Startpunkt ungünstig liegt wird damit HM daran gehindert das HMLAN zu triggern.

Zum eingrenzen sind Fragen zu klaeren:
- kann ich logs haben(HMLAN messages) wenn der disconnect auftritt? Besonders einen Teil vor dem disconnect
- seit wann tritt das Problem auf und welches war die letzte gute HM-version?
- welche Applikationen laufen sonst noch?

Gruss
Martin

[Jumbo]

Wie soll ich Loggen ? mit Verbose 5 ?

oder langt dir 3 ?

[martinp876]

die hmlan logs.

am besten ist
attr global mseclog 1
attr global verbose 1
attr <hmlan> hmProtocolEvents 1
attr <hmlan> loglevel 1

[Martin Thomas Schrott]

Hi zusammen,

und weil wir eben wieder bim Thema sind: was spricht jetzt eigentlich dagegen das keep alive als eigenen Prozess laufen zu lassen, damit eben diese Timing Probleme wenigstens nicht zum HMLAN disconnect führen?
Löst nicht das Problem verzögerter notifies aber zumindest die Verbindung wäre stabiler.
Sollte doch in Perl ohne gröbere Probleme machbar sein das keep alive extra laufen zu lassen. Hab zwar mit multithreading auch noch nicht gearbeitet, aber irgendjemand hier im Forum hat das letztens erwähnt und am Laufen! Sollte sich mit der Suche finden lassen, wer das war.Dieser welcher sollte hier ja helfen können, falls du Martin, das auch noch nicht gemacht hast.

Denke es wäre eine sinnvolle erweiterung/Umstellung.

lG
Martin

[Dennis D.]

Also nach heutigem Update konnte ich keine disconnected-meldungen mehr feststellen. mittlerweile habe ich aber auch eine vermutung, woran es - zumindest bei mir - gelegen haben könnte.

meine NAS war durch einen prozess so stark ausgelastet, dass FHEM träge reagierte. dies äußerte sich zum beispiel dadurch, dass ein aktion bis zu 10 sekunden nach auslösung (fernbedienung/schalter) ausgeführt wurden.

vielleicht konnte durch die auslastung auch das LANInterface nicht mehr richtig angesprochen werden. ich werde das mal weiter beobachten.

[martinp876]

zum Thema multithreating:

- wenn das Problem an der Performance den Systems liegt hilft das garnichts (Dennis's Vermutung)
- welcher Prozess ausgelagert wird sollte gut ueberlegt sein. Ich wuerde nicht den keep-alive auslagern sonder die "schlaefer". Der main-thread sollte ein Verlaessliches timing aufweisen. Das keep-alive hat nur relativ geringe Anforderungen. Ein TC und andere stellen da noch -erheblich-hoehere.
- was dagegen spricht ist ausserdem die kontrolle aller zum HMLAN gesendeten Messages. HMLAN wuerde nun aus 2 Quellen gespeist - unabhaengig voneinander. gefaellt mir nicht => das IO sollte immer ein thread sein
- Falls du dich mit multi-thread auskennst weisst du sicher ueber die wesentiche Problematik der IPC. Du musst trigger abschicken ueber den Zustand des threads, den Zustand der keep-alives, den neustart des Threads bei disconnect
... hier koennen wir noch einige andere Punkte auffuehren, die geklaert werden muessen.

==> HMLAN keep-alive auszulagern ist eine Symptombehandlung, leider keine Ursachenbehebung und daher mit Nebenwirkungen behaftet und laesst andere weiter im Regen stehen.


Ich habe etwas experimentiert wie ich den "ping" des WOL forken kann. geht schon ganz gut und waere mein Weg. Ausserdem sollte der main thread 'timing-suender' alarmieren/loggen die unangemessen lange brauchen. Schliesslich ist das HMLAN keep-alive nicht die einzige timing-anforderung in FHEM.

Im uebrigen habe ich die Downzeit reduziert - es sollte erheblich schneller reconnected werden.

so - das war ein unsortierter Auszug meiner Meinung zu multithreating und timing in fhem.

Gruss
Martin

[Martin Thomas Schrott]

*patsch* danke!
Jetzt weiß ich auch, warum ich ab und zu disconnects habe, ich ruf ja eine externe webseite auf und wenn die zu lange nicht fertig geladen ist blockiert die auch fhem am weiterarbeiten! :-(
Muss die Seite anders gestalten, die muss gleich ein done zurückgeben und alles ausgelagert verarbeiten.
Ja, Martin du hast natürlich recht, alles andere muss multigethreated werden, nicht die Haupt-Prozesse! :-)