Leider wieder das Thema MissingAck

[Init]

Hallo zusammen,

es gibt ja schon zahlreiche Themen hier im Forum zu ,,MissingAck", aber leider konnte ich meine Fehler nicht beheben.

Das Problem besteht ca. seit dem 10.07.13.

Anfang des Jahres hatte ich eine Beschattungssteuerung integriert und alles funktionierte ohne Fehler (MissingAck).

Am 09.07.13 hatte ich dann das Problem, dass sich 2 Jalousieaktoren verabschiedet haben. Ursache war wahrscheinlich ein driveTurn von 0.

Danach hatte ich alle meine Aktoren auf driveTurn gleich 1 gesetzt und habe zeitgleich von der Fritzbox auf einen RaspberryPI gewechselt. Danach hatte ich ständig E-Mails mit ,,missingAck" (Habe ein notify, welches jedes ,,missingAck" per Mail verschickt).

Jetzt habe ich 2 für mich 3 Ursachen in Betracht gezogen:
 1) Wechsel auf PI
 2) Wechsel von driveTurn auf 1
 3) Aktuelle FHEM-Version (resend?)

Gestern habe ich dann zurück auf die Fritzbox gewechselt, aber leider habe ich immer noch die Emails.

Interessant ist, dass ich teilweise ein MissingAck von Strukturen bekomme.

Des Weiteren habe ich festgestellt, dass ich das Problem nur habe, wenn ich alle Jalousien ansprechen (morgens und abends). Tagsüber, wenn nur eine Hausseite runter oder hochfährt, habe ich das Problem nicht.

Im Anhang habe ich mal das Log von heute Abend.

Hoffe es hat jemand eine Idee.

VG
Marc

[martinp876]

hm - wenn ich mir den Ablauf ansehe verstehe ich den nicht.

Es werden jede Mange Rollos "off" gesetzt. Vorab gibt es ein "stop" (das ist 'neu' seit dieser Zeit - als zu untersuchen)
Die Offs werden zwischen 21:11:16 und 12:12:00 gesendet - das dauert 45sec - warum? Das habe ich schon schneller gesehen.
danach kommt eine email
um 21:12:04-07 werden die acks empfangen (4) und die eigentlichen "off" gesendet. 11 weitere ACKs kommen nicht und es wird ein weiteres mal gesendet. - alles in einer sekunde.
um 21:21:09 sind weitere 4 erfolgreich
um 21:12:11 kommt der nächste Schub retries.


weiter habe ich noch nicht geschaut.

Zum einen verstehe ich die verzögerung am Anfang nicht - hat dein System hier eine Problem?
zum 2. verstehe ich nicht warum alle resend zum gleiche Zeitpunkt kommen. Die werder zufällig um 1-4 sek verzögert. Die dürfen nicht in der selben Sekunden kommen.

Bist du auf der neusten Version?

Gruss Martin

Nachträge
- sind deine Rollos eigentlich gepairt? Warum senden die einen infoStatus an "broadcast"
- um 21:12:50 bis 13:10 scheint ja alles zu kommen, was gefehlt hat.
=> bist du sicher dass dein System nicht etwas verzögert?
- kannst du das ganze ohne hmProtokollEvents aufzeichnen, also nur mit HMLAN logs roh messages? Die sind viel näher am ethernet timing. Ausserdem verzögert hmProtokollEvents ziemlich.
milisekundenauflösung wäre hilfreich

[Init]

Hi Martin,

danke für die Antwort.

diese Verzögerung kommt durch ein sleep(2), weil ich dachte, dass eine verzögerung die Probleme behebt. Leider nicht...

Version von FHEM ist auf dem Stand von gestern.

Was meinst du genau mit dem "stop" am Anfang? Schickst du das intern vorab?

VG
Marc

[Init]

Hi Martin,

soll ich mal für morgen Abend dei Rev. 3371 einspielen?

Dann hätten wir einen Hinweis, ob es an dem Stop liegt.

VG
Marc

[martinp876]

Hallo Marc,

im Anhang ist die aktuelle Version aber mit abgeschaltetem "pre-stop". Also erst ein Update machen dann das File einspielen (oder HMConfig updaten).

Ich denke aber nicht, dass es daran liegt.

Sicher ist, dass keine einzige message nicht beantwortet wurde. Die Antworten kommen nur unendlich spät. Da sind verzögerungen von über 10 sekunden vorhanden. So lange darf es aber nicht dauern. Ich vermute die Verzögerung nicht in der "Luft" oder HM sondern in FHEM oder dem PI.

Mit den Rohmessages könnte man mehr zum Timing sagen.

Gruss Martin

[Init]

Hallo Martin,

habe mal die Logs umgeschaltet und dir ein aktulles Log in den Anhang gepackt (ohne patch von 08:44).

Interessant ist meiner Meinung nach auch, dass nicht nur das Ack auf sich warten läßt, sondern auch die Jalousien erst nach ca. 10 sec anfangen sich zu bewegen, aber dann gleichmäßig. Also alle 2 sec (sleep 2) fängt die nächste an sich zu bewegen.

Sehr merkwürdig.

Wie kann ich deine Frage verstehen, ob die Rollos gepairt sind? Würden die sonst überhaupt funktionieren? Hatte jedenfalls initial alle Aktoren über HMLAN gepairt. Bin nur zwischenzeitlich mit der Installation auf den PI und wieder zurück, aber immer der gleiche HMLAN.

Dank dir für die Analyse

Gruß
Marc

[justme1968]

das mit dem plötzlich später bewegen habe ich auch schon beobachtet. keine 10  minuten aber etwa 5.

zwischendurch konnte ich sie ganz normal über den taster bedienen und nach einer weile fahren sie dann doch noch automatisch.

gruss
  andre

[Newbie]

Hallo,


also ich beobachte bei mir seit ca. 2 Wochen Ähnliches, meine beiden Rollladen im Wohnzimmer werden über "structure" geschalten. Bis dahin immer gleichzeitig, jetzt hab ich einen Versatz der Schaltzeiten von ca. 2sec und meist noch ein missing act im Webinterface(für den Rollladen der als zweites runterfährt), was aber gar nicht stimmt. Fhem läuft auf einer Fritzbox.

mfg Jens

[martinp876]

Hi Zusammen,

bislang habe ich "nur" logs auf CUL_HM ebene. Da ist noch IO (HMLAN oder CUL) drunter. Die Info ist also nicht komplett.

Für alle zum Mitdenken und verstehen was zu sehen ist
- die messages werden gesendet
- die messages werden ggf wiederholt
- es kommen alle Antworten - ggf auch auf einen repeat-request
=> der Ablauf ist komplett und ohne eine fehlende message
- das timing ist exterm fraglich
-- die Antworten kommen eklatant zu spät
-- die Send-requests werden gestaffelt gesendet - 13 requests mit je 3-4 sec Abstand.
?? wo kommen die 3-4 sekunden her? Sind die Absicht, wenn ja wo? wie wird "geschlafen"?
- das Empfangen der 4 erfolgreichen ACKs kommt je in 1 sec Abstand - leider haben wir nur Sekunden Auflösung. Eigentlich sollte dies in 1sec möglich sein
?? hmProtokolEvents ist auf max-level? Das könnte erheblichen Delay erzeugen. Mein Rat: Abschalten - zumindest den Level!
- Die erfolgreichen ACKs werden 4sec nach dem Letzten Send empfangen - und 48sec !!! nach dem Kommando. Das unterstützt HM sowieso nicht - ein ack kann kaum länger als 1-2 sec dauern (MAX!!!) Das bedeuted, dass die Nachricht erheblich früher in HMLAN empfangen und an FHEM gesendet wurde. Dann steckt sie sicher in irgend einem Puffer und warten - aber wo, und wer blockiert?
- die Resends (erste Staffel) kommen direkt nach dem Empfangen der Message, alle auf einmal. Das ist nicht logisch. Ein resend kommt spätestens nach 4 sec. => auch die resend-timer werden aufgehalten.

Zusammenfassend
- das timing ist eigentlich eine einzige Katastrophe
?? welchen Delays bist du dir bewusst? Wo hast du irgendwelche sleeps, waits oder timings eingebaut? Wenn möglich entferne alle. Allen voran hmProtokollEvents.
- Beachte, dass viele Notifies pervormance benötigen. Jedes Logfile ist auch ein Notify! Schreiben in ein File kann - je nach System dauern.

Zum Pairing - du musst es einfach kontorllieren. So würde ich dies machen - kleine Anleitung:
# setze autoRegRead in allen Devices, ausser devices die nur "Config" können, also RCs

Code Auswählen Erweitern

define hm HMInfo
set hm param -de PairedTo autoReadReg
#=> setze in allen Devices das Attribut autoReagReg auf 4 (ausser RC)
falls die Daten noch nicht gelesen sind mache ein

Code Auswählen Erweitern

set hm autoReadReg
=> alle Device die autoReadReg gesetzt haben werden erneut gelesen - und zwar zeitlich gestaffelt.
mit

Code Auswählen Erweitern

set hm update
erzeugt hm einen Statusreport - danach kannst du die Readings ansehen (u.a. Batteriestatus...). Im reading

Code Auswählen Erweitern

I_autoReadPend
von hm kannst du sehen, wer noch in der Queue hängt. Wenn die leer ist sollte alles da sein.
ein erneutes

Code Auswählen Erweitern

set hm param -de PairedTo autoReadReg
zeigt den Status.

Nur gepairte Devices sind gute Devices (sieht nicht jeder so, aber ich schon;-))
Nur getConfig (alternativ attr autoReadReg) können den Status prüfen

Gruss Martin

[Init]

Hallo Martin,

momentan bin ich mir nur bewusst, dass zwischen jedem ansprechen eines aktors ein sleep von 2 ist. Dies kann du auch in den Logs sehen.
Notifys habe ich momentan 11 verbaut.

Um zu die pairings zu kontollieren versuche ich mal deine Anleitung zu befolgen.

Als erstes hier mein HMLAN config:

Code Auswählen Erweitern

define HMLAN1 HMLAN 192.168.146.15:1000
attr HMLAN1 hmId 123ABC
attr HMLAN1 hmProtocolEvents 0
attr HMLAN1 wdTimer 25
attr HMLAN1 loglevel 1

Und nun die Steps aus deiner Anleitung:

1) Ich füge folgendes meiner config hinzu

Code Auswählen Erweitern

define hm HMInfo

2) Führe folgendes aus:

Code Auswählen Erweitern

set hm param -de PairedTo autoReadReg

3) Danach füge ich allen jalousieAktoren folgende zeile hinzu:

Code Auswählen Erweitern

attr <name> autoReadReg 4

4) Danach führe ich folgendes aus:

Code Auswählen Erweitern

set hm autoReadReg
und
set hm update

5) Danach die readings vom hm (HMInfo) anschauen --> I_autoReadPend
6) Als letzte erneut

Code Auswählen Erweitern

set hm param -de PairedTo autoReadReg ausführen um den Status zu sehen.
Sehe ich dann da, welche Aktoren paired sind und welche nicht?
Oder was sehe ich da alles?

Habe ich alles richtig verstanden?
Wenn ja, dann stelle ich das jetzt alles ein.

Gruß
Marc

PS: Habe für heute Abend das File mit abgeschaltetem "pre-stop" eingespielt.

[Init]

Hi Martin,

mein AT für Jalousie runter am Abend ist um 21:08 gelaufen, aber diesmal ist rein gar nichts passiert?!? Komisch... Kann es an dem Patch ohne "pre-stop" liegen?

Nachdem die Automatik nicht funktionierte, konnte ich aber über die Oberfläche bedienen.

Im Anhang mein Log, vielleicht kannst du ja etwas erkennen. Hatte auch "sleep(2)" ausgebaut.

VG
Marc

[Init]

Hallo Martin,

habe Punkt 2 und 3 getauscht.

Bei Punkt 3 (set hm param -de PairedTo autoReadReg) bekomme ich folgende Ausgabe:

Code Auswählen Erweitern


param done:
 param list
    CUL_HM_threeStateSensor_19F43F: -                   |-                  
    CUL_HM_threeStateSensor_19F525: -                   |-                  
    LC_EG_1_NO_Rollo_Kueche: 0x123ABC             |4                  
    LC_EG_2_SO_Rollo_Kueche: 0x123ABC             |4                  
    LC_EG_3_SO_Rollo_Esszimmer: 0x123ABC             |4                  
    LC_EG_4_SW_Rollo_Esszimmer: 0x123ABC             |4                  
    LC_EG_5_SW_Rollo_Wohnzimmer: 0x123ABC             |4                  
    LC_EG_6_SW_Rollo_Wohnzimmer: 0x123ABC             |4                  
    LC_EG_7_NW_Rollo_Gaestezimmer: 0x123ABC             |4                  
    LC_EG_8_NO_Rollo_Gaestebad: 0x123ABC             |4                  
    LC_EG_9_NO_Rollo_Flur: 0x123ABC             |4                  
    LC_OG_10_SO_Rollo_Maike: 0x123ABC             |4                  
    LC_OG_11_SO_Rollo_Jacob: 0x123ABC             |4                  
    LC_OG_12_NW_Rollo_Eltern: 0x123ABC             |4                  
    LC_OG_13_NW_Rollo_Ankleide: 0x123ABC             |4                  
    WDS_NW              : -                   |-                  
    WDS_SO              : -                   |-                  
    WDS_SW              : -                   |-          Danach habe ich "set hm autoReadReg" ausgeführt und folgende Ausgabe bekommen:

Code Auswählen Erweitern


autoReadReg done:
 cleared
    LC_EG_1_NO_Rollo_Kueche
    LC_EG_2_SO_Rollo_Kueche
    LC_EG_3_SO_Rollo_Esszimmer
    LC_EG_4_SW_Rollo_Esszimmer
    LC_EG_5_SW_Rollo_Wohnzimmer
    LC_EG_6_SW_Rollo_Wohnzimmer
    LC_EG_7_NW_Rollo_Gaestezimmer
    LC_EG_8_NO_Rollo_Gaestebad
    LC_EG_9_NO_Rollo_Flur
    LC_OG_10_SO_Rollo_Maike
    LC_OG_11_SO_Rollo_Jacob
    LC_OG_12_NW_Rollo_Eltern
    LC_OG_13_NW_Rollo_AnkleideDanach habe ich dann "set hm update" ausgeführt.

Punkt 5 zeigte mir dann in den Readings folgendes:

Code Auswählen Erweitern


CFGFN homematic.cfg
C_sumDefined entities:25 device:18 channel:22 virtual:1
ERRactNames WDS_SW,WDS_SO,CUL_HM_threeStateSensor_19F525,CUL_HM_threeStateSensor_19F43F,WDS_NW

I_HM_IOdevices HMLAN1:ok
I_actTotal alive:0 dead:0 unkn:5 off:0
I_autoReadPend LC_EG_6_SW_Rollo_Wohnzimmer,LC_EG_7_NW_Rollo_Gaestezimmer,LC_EG_8_NO_Rollo_Gaestebad,LC_EG_9_NO_Rollo_Flur,LC_OG_10_SO_Rollo_Maike,LC_OG_11_SO_Rollo_Jacob,LC_OG_12_NW_Rollo_Eltern,LC_OG_13_NW_Rollo_Ankleide

I_rssiMinLevel 59<:2 60>:14 80<:0 99>:0
NAME hm
NR 104
STATE updated:2013-08-23 11:33:03
TYPE HMinfo
Version 01
W_sum_motor stop:on:6;stop:35 %:7;
Nun habe ich 5 min gewartet und erneut ,,set hm update" ausgeführt. Nun war ,,I_autoReadPend" verschwunden.

Habe dann alle Devices kontrolliert und festgestellt, dass alle gepairt sind im Zeitraum zwischen 11:33 und 11:35.
Allerdings sind die Readings teilweise total unterschiedlich. Mal habe ich 15  Werte und bei anderen habe ich dann wieder 76 Werte. Ist das normal?

VG
Marc

Nachtrag:
Habe noch ein aktuelles Log angehängt (aktuelles fhem + alle Devices gepairt)

[Init]

Hallo zusammen,

habe heute Abend alle "notify" ausgebaut.

Gefühlt läuft alles viel schneller und sauberer.

Allerdings finde ich immer noch 16 mal "no ACK from Device" im Log.

Habe das Log noch mal angehängt.

@Martin: Wäre wirklich super, wenn du dir das noch mal anschauen kannst und evtl. etwas findest.

Viele Grüße
Marc

[martinp876]

Hi,

so, mal sehen, dass ich alles Beantworte:

11 notifyes sollten schon gehen, perfornamcemessungen habe ich nicht. Bedenke, dass jedes einzelen Logfile auch quasi ein Notify ist.

Bedenklich sehe ich dein Sleep. Es sieht wie ein aktives Warten aus. Das wäre verherend - und absolut kontraproduktiv. Dass es aktiv (also nicht unterbrechbar) ist zeigtmir, dass keine Antworten in der zwischenzeit kommen. Wenn das so ist machst du damit alles kaputt.
Warum brauchst du die? Sind sie notwendig? Wenn ja suche eine passive möglichkeit zu warten, wenn nein werfe sie einfach raus.

Sehe ich dann da, welche Aktoren paired sind und welche nicht?
Oder was sehe ich da alles?
=> einfach ausprobieren

Habe dann alle Devices kontrolliert und festgestellt, dass alle gepairt sind im Zeitraum zwischen 11:33 und 11:35.
=> das ist der Zeitstempel, wann es gelesen wurde.

Ich habe nur das letzte Log angesehen. Wieder das Timingproblem. Alle Antworten müssen in deiner Konfig warten bis deine sleeps beendet sind. Ich bin eigentlich sicher dass alles besser läuft wenn du diese einfach entfernst. Dann können wir noch einmal nachsehen.
Mit den Sleeps hat es keinen Sinn.

Im Prinzip sollte die FHEM SW das Mini-warten berücksichtigen - sleeps sollten nur in wenigen speziellen Fällen notwendig sein.
Sorry, ich mag keine Sleeps, aktive schon 2mal nicht

Gruss Martin

[Init]

Hi Martin,

danke für die Antwort!

Ich verstehe es echt nicht mehr :-(

Habe jetzt folgende Änderungen vorgenommen:

 1) ALLE sleeps ausgebaut
 2) Von 11 auf 4 notify abgespeckt
 3) 7 structuren für die Jalousien entfernt

Trotzdem immer noch diese Verzögerung und 12 MissingAck

Aktuelles Log im Anhang.

Bin echt ratlos, keine Ahnung was ich noch abspecken soll, damit die Probleme weg sind

Hast du oder jemand anders noch eine Idee?

VG
Marc