Firmware zu CUL, CUNX und Co. mit Timestamp Option ASKSIN tsculfw V0.41

Begonnen von noansi, 09 Juni 2014, 19:16:01

Vorheriges Thema - Nächstes Thema

noansi

Hallo Jörg,

danke für die Tests.

Mit dem virtuellen TH bin ich jetzt gut weiter gekommen und baue den virtuellen TC entsprechend um. Dann gibt's wieder Testbedarf.

Gruß, Ansgar.

noansi

Hallo Jörg,

anbei nochmal was zum testen.

Ich habe in der Firmware die Wiederholung der Ventil- und TH Messages abgeschaltet, weil die mangels Info, ob die erste Message oder ein Repeat empfangen wurde, kontraproduktiv sind.
Daher erst mal die Firmware des nano auf neuen Stand bringen (ich habe auch mal eine hex für den CUL V3 beigepackt, falls jemand mit CUL V3 testen möchte). Natürlich auch alle Module aus der Zip.

4 Attribute gibt es nun.

cyclicMsgRecWinHalf: Damit setzt man die Hälfte des des Empfangsfensters, entsprechend dem des Empfängers, in ms. 125 ist default und sollte dem VD entsprechen. Solltest Du nicht anpassen müssen.

cyclicMsgCorr: Wie schon bekannt ein Korrekturwert für die Zeit. 0 default. Solltest Du nicht ändern müssen, sofern Deine Pi Uhr nicht nach dem Mond geht und auch nich die der VDs.

cyclicMsgMissOffs: Damit wird eine Intervallverlängerung im Fall von misses (keine Antwort vom VD) in 125ms Schritten eingestellt. 0 bis 4 können eingestellt werden. 2 ist default und "Spielwiese" für Dich. Da das Empfangsfenster größer werden soll, wird damit der Sendezeitpunkt verschoben um da rein zu fallen. Das müsste beim "Einfangen" helfen, wenn das Empfangsfenster einseitg vergrößert wird (beim RT ist mein Eindruck so, der muss sich aber nicht wie ein VD verhalten).
0 wäre der alte Zustand, sprich im normalen Sendeinterval wird weiter gesendet.

cyclicMsgRtAck: Nur für Tests mit RT. Damit wird mit einer TH Message ein Ack angefordert. Damit kann man im Log an den Rohmessages sehen, ob die Messages empfangen werden. 0 default.

CUL_HM sendet nun grundsätzlich etwas verzögert zum regulären Intervall (etwa 62ms). Das soll etwas FHEM Jitter abdämpfen. Außerdem sendet CUL_HM gar nicht, wenn FHEM den Timer so unpünktlich aufruft, so dass nicht damit zu rechnen ist, dass der Empfänger wach ist. Damit bleibt das Syncen in einem genaueren Rahmen und es wird auch nicht sinnlos gesendet.
Mit RT hat das gut geholfen. FHEM neigt bisweilen zu mehreren Sekunden Verzögerung. Durch diese Änderung bleibt es besser im Sendetakt und der Empfänger sieht so nur einen garantierten "Empfangsausfall", statt eines verschobenen Sendeintervalls in der Folge.

Kommt ein Ack, wird auf Basis des letzten Sendezeitpunkt zum VD weiter gesendet, wie das auch zuvor schon so war.

Ich bin gespannt, ob das auch beim VD so besser funktioniert.
Wie gehabt mit verbose 4 beim nano und verbose 2 beim virtuellen TC.

Gruß, Ansgar.

noansi

Hallo Jörg,

nochmal ein kleines Update.
Nur 00_TSCUL.pm und 10_CUL_HM.pm sind zum letzten Stand verändert.
In TSCUL habe ich entsprechend der fehlenden Wiederholungen den Queue Sendetimeout für das Warten auf Antwort noch angepasst.
In CUL_HM hatte ich noch ein Fehler beim peerIDs Handling gemacht, was beim Setzen von Templates auffallen würde.

Deswegen erwarte ich aber keinen wesentlichen Unterschied im VD Kommunikationstestergebnis, also kein Grund für eine aufwändige Testserie.

Gruß, Ansgar.

Adimarantis

Hi Ansgar,

dein neustes update habe ich jetzt erst gesehen. An gewohnter Stelle findest du ein Logfile der Version von gestern. Mit dem cyclicMsgMissOffs hab ich ein wenig gespielt (siehst du am Logfile wann ich das geändert habe?) und bin am Ende bei "0" gelandet - das lief meine ich am Besten, aber die Timeouts kommen nach wie vor regelmäßig. Ich spiele jetzt dein letztes update ein und lasse das einfach mit "0" weiterlaufen.

Gruß,
Jörg
Raspberry 4 + HM-MOD-RPI-PCB (pivCCU) + RfxTrx433XL + 2xRaspberry 1
Module: 50_Signalbot, 52_I2C_ADS1x1x , 58_RPI_1Wire, (50_SPI_MAX31865)

Lowbird

Hallo Ansgar,

ich habe das Problem, dass wenn ich mit der 00_TSCUL.pm das System neu starten möchte, FHEM gar nicht bis in WebUi lädt. In der Logdatei habe ich folgende Meldung als Problem festgestellt:

2021.01.01 20:03:49 0: Server shutdown
Undefined subroutine &main::RemoveInternalTimerM called at ./FHEM/00_TSCUL.pm line 7535.
2021.01.01 20:03:51 1: Including fhem.cfg
2021.01.01 20:03:51 3: WEB: port 8083 opened
2021.01.01 20:03:52 2: eventTypes: loaded 1556 events from ./log/eventTypes.txt
Undefined subroutine &main::RemoveInternalTimerM called at ./FHEM/00_TSCUL.pm line 7630, <$fh> line 31.



Wenn ich die Timer in Zeile 7535,7630,7631 und 7632 auskommentiere, startet er ohne Fehlermeldung.

Alle nötigen Dateien gemäß deinem Post #1037 ersetzt.

nanoCul gefüttert mit der VTS 0.37 CSM868


Wenn du noch internals zur Fehlerbehebung benötigst sag Bescheid.


Ich danke dir für deine Zeit.

LG Chris
FHEM 5.7
FritzBox 7490
Vu+ Duo2
IP-Cam Instar 6012HD
IP-Cam Instar 5907HD

noansi

Hallo Chris,

ZitatAlle nötigen Dateien gemäß deinem Post #1037 ersetzt.
98_timerTS.pm war wohl nicht dabei, aber die muss auch ergänzt werden.  ;)

Gruß, Ansgar.

Lowbird

Hallo Ansgar,

keine Ahnung warum die 97_timerTS.pm nicht mitkopiert wurde. Aber das war der Fehler.
Danke dir fürs supporten.

LG Chris
FHEM 5.7
FritzBox 7490
Vu+ Duo2
IP-Cam Instar 6012HD
IP-Cam Instar 5907HD

noansi

Hallo Jörg,

anbei wieder was neues zum Testen (nur Module verändert, Firmware ist gleich).

Ich habe ein Reading ergänzt:
timing        mc: 37 miss: 0 tQ: 0.545 rQ: 0.600 mSkp: 0 mNck: 5 dtu: 130500 errS: -2 errC: -1
mc: ist der HM Message Counter für die letzte gesendete Nachricht dezimal
miss: ist die anzahl misses seit letztem Ack
tQ: ist ein Qualitätsindikator für die Übertragung als "Summe der bestätigten messages"/"Summe aller gesendeten messages" -> 1 ist Spitze, 0 nix geht
rQ: ist ein Qualitätsindikator für das Resyncen als "Summe der Übertragunsunterbrechungen"/"Summe der nicht bestätigten messages" -> 1 ist Spitze für Recovery, 0 nix geht
mSkp: ist die Anzahl ausgelassener Übertragungen, wenn nicht explizit angefordert, dann gibt es die "Störungen" des Timer-Timings an
mNck: ist die Anzahl nicht bestätigter messages, kann Funkübetragungsprobleme bedeuten oder Systemtimingprobleme oder was auch immer inklusive meiner Bugs  ;)
dtu: ist das für diese message genutzte Timerintervall
errS: der dabei mittels Rückmeldung vom CUL ermittelte Systemtimingfehler (Ist-Soll -> positiv=später)
errC: der dabei nach CUL Timestamp ermittelte Sendetimingfehler (Ist-Soll -> positiv=später)

im Log gibt es bei verbose 2 beim virtuellen TC ein oder zwei Einträge
2021.01.02 16:40:51.217 2: CUL_HM V_ValveCtrl_TC 11222001 hI:125ms S:0 A:0 O:2 mc:21->22  dtp: 159500 ms  dtF: 159500 ms  dtcall: 5 ms  nv:n
2021.01.02 16:41:21.363 2: CUL_HM V_ValveCtrl_TC 11222001 mc:22  tQ: 0.625  rQ: 0.667  dtu: 173754 ms  errS: 2 ms  errC: 2 ms  miss: 1
2021.01.02 16:43:30.715 2: CUL_HM V_ValveCtrl_TC 11222001 hI:125ms S:0 A:0 O:2 mc:22->23  dtp: 145000 ms  dtF: 145000 ms  dtcall: 5 ms  nv:n  miss: 1
2021.01.02 16:44:00.848 2: CUL_HM V_ValveCtrl_TC 11222001 mc:23  tQ: 0.556  rQ: 0.500  dtu: 159500 ms  errS: -3 ms  errC: 0 ms  miss: 2

hI: ist die halbe (angenommene) Empfangsfenstergröße nach Attribut cyclicMsgRecWinHalf
S: Sendezeitpunktshifting entsprechend Attribut cyclicMsgDoShift
A: Sendeintervallsverlängerung entsprechend Attribut cyclicMsgMissAdd
O: Zeitbasis für Sendezeitpunktshifting und dtcall limit nach Attribut cyclicMsgMissOffs
mc: ist der HM Message Counter für die letzte gesendete Nachricht hexadezimal
dtp: ist das vorherberechnete Sendeintervall zur nächsten message
dtF: ist das vorherberechnete Sendeintervall zur nächsten message im Fall ausbleibender message Bestätigung
dtcall: ist die Verspätung des Timeraufrufs
nv: n -> keine neue Ventilstellung, Y -> neue Ventilstellung zu übertragen

Damit kannst Du jetzt auch selbst recht einfach sehen, wie der Erfolg einer Änderung ist.
Wenn eines der Attribute gändert wird, dann wird die Statistik auch mit zurück gesetzt. Vor dem Spielen also besser erst notieren. Ansonsten bei verbose 2 beim TC auch noch im Log nachvollziehbar.

Aus Deinem vorletzten Log nehme ich an, dass sich die beiden VD Firmwareversionen 1.4 und 2.0 im Timing anders verhalten.
Dem 1.4er hat Shifting und Recovery Sendeintervallvergrößerung eher nicht gefallen. Wenn es mit einem Ackausfall wieder kürzer wird, scheint er sich wieder zu fangen. Mal sehen, wie er mit der jetzigen Defaulteinstellung arbeitet.
Dem 2.0er schien das Shifting eher zu gefallen und auch beim Recovery sah eine Sendeintervallvergrößerung eher besser aus. Da wäre cyclicMsgDoShift=1 und/oder cyclicMsgMissAdd=1 oder 2 hoffnungsvoll.

Insgesammt gibt es aber viele Ack-Ausfälle die allein aus dem Timing nicht wirklich zu erklären sind. Irgendwas anderes scheint mit zu stören. (Netzteil vom Pi? Ein 868.3MHz Slow RF Gerät? Die Wanze in Deiner Tischlampe? ;) Die Qualität der VD Firmware? Ein Rechner oder Laptop oder...? Mein übersehener Bug?  ;D ).
Für aussagekräftige Ergebnisse bringt es wohl nur was, wenn Du nach jeder Änderung den Beobachtungszeitraum deutlich vergrösserst. Dafür sind die Qualitätsindikatoren hoffentlich hilfreich.

Wenn Du mir Log Daten zum virtuellen TC zukommen lassen möchtest, dann bitte erst mal nur die mit verbose 2 von oben. Logging vom nano hilft nicht weiter, da darin schon verarbeitet.
Ich bin gespannt.

Gruß, Ansgar.

frank

wow, hört sich super an.
funktioniert das auch mit anderen io oder nur mit cul?
FHEM: 6.0(SVN) => Pi3(buster)
IO: CUL433|CUL868|HMLAN|HMUSB2|HMUART
CUL_HM: CC-TC|CC-VD|SEC-SD|SEC-SC|SEC-RHS|Sw1PBU-FM|Sw1-FM|Dim1TPBU-FM|Dim1T-FM|ES-PMSw1-Pl
IT: ITZ500|ITT1500|ITR1500|GRR3500
WebUI [HMdeviceTools.js (hm.js)]: https://forum.fhem.de/index.php/topic,106959.0.html

noansi

Hallo Frank,

Zitatfunktioniert das auch mit anderen io oder nur mit cul?
Das reine Intervalltiming zu den VDs hat nichts mit dem IO zu tun (wenn ich brav war ;) ). Die Qualitätsindikatoren hängen auch nur an Zählern in CUL_HM.

Das Messen des Timings hängt am tscul, weil ich mir die Daten aus der tscul Sendebstätigung (also nicht das ACK vom device) im TSCUL Modul ziehe und von da direkt ins HM device zur weiteren Verarbeitung durch CUL_HM schreibe.
Wenn Du Deinen CUL noch nicht verschrottet hast, kannst Du natürlich gerne mit testen. Mich würde ohnehin interessieren, ob es auch mit HMLAN & Co. im Mischbetrieb noch alles funktioniert. Kann ich selber nicht testen.

Natürlich ist zu beachten, dass gerade Winter ist und eine funktionierende Heizung somit von Vorteil ist... . Backup etc...

Nebenbei, ich vermute es war der F1 Bug bei den VDs bei voller Öffnung, die zur Begrenzung des Ventilöffnungsgrads geführt hat.

Gruß, Ansgar.

Adimarantis

Alles klar. Test läuft mit FW1.4 komplett auf defaults and FW2.0 mit cyclicMsgDoShift=1 und cyclicMsgMissAdd=1
Nano wieder auf Verbose 0.
Als Netzteil kommt aktuell ein Hutschienen-China-Teil zum Einsatz - und das ist ziemlich nah am Raspi - schon möglich das da was stört.
Ich selbst habe außer den anderen 50+ Homematic Devices nichts auf 868Mhz, aber wer weiss was mein Nachbar so macht. Zumindest mein rfxtrx433 findet massig Fremdgeräte - gut möglich dass der auch auf 868 fleissig ist. Ich hab jetzt auch noch die crontab geputzt und in FHEM noch ein paar weitere Dinge disabled so das jetzt hoffentlich von der Seite nix mehr stört.

Die ersten 20 Minuten des aktuellen Test lief alles super (rq/tq=1.000) aber plötzlich habe ich auf beiden gehäuft "misses". ErrS/ErrC sind meist einstellig, selten mal (+/-)15-20ms. Die größte Varianz sehe ich bei dtu/dtp/dtF.
Ich lasse das jetzt weiter mit Ventiländerung alle 20 Minuten (versetzt um 10 Minuten) über Nacht laufen und morgen gibts dann ein log.

Auf den 1.4er würde ich nicht all zu viel Energie verschwenden. Nicht umsonst gibt es HW/FW Revisionen - der hat sicher seine Fehler.

Gruß,
Jörg
Raspberry 4 + HM-MOD-RPI-PCB (pivCCU) + RfxTrx433XL + 2xRaspberry 1
Module: 50_Signalbot, 52_I2C_ADS1x1x , 58_RPI_1Wire, (50_SPI_MAX31865)

noansi

Hallo Jörg,

ZitatAls Netzteil kommt aktuell ein Hutschienen-China-Teil zum Einsatz - und das ist ziemlich nah am Raspi - schon möglich das da was stört.
Das wird sich doch ändern lassen + Versorgunsleitung ein paar mal um einen Ferritkern.  ;)

ZitatErrS/ErrC sind meist einstellig, selten mal (+/-)15-20ms.
Ja, dass Du diesbezüglich eigentlich traumhafte Verhältnisse auf Deinem Pi hast, ist mir auch schon aufgefallen. Ab und zu durch Fehltiming nachvollziehbare Aussetzer wären eigentlich zum Testen eher zu begrüßen.

ZitatDie größte Varianz sehe ich bei dtu/dtp/dtF.
Das die sich ändern ist normal, da pseudozufällig gerechnet. dtp ist das gerechnete "Ideal". Auf dtF wird was drauf gerechnet je nach Einstellung und auch so bei dtu.

ZitatAuf den 1.4er würde ich nicht all zu viel Energie verschwenden. Nicht umsonst gibt es HW/FW Revisionen - der hat sicher seine Fehler.
Es gab mal die Möglichkeit, die bei ELV einzuschicken und gegen kleines Entgeld updaten zu lassen. Over The Air geht bei denen leider nicht.

Versorgst Du die VD mit Batterie oder auch über ein Netzteil?

Gruß, Ansgar.

noansi

Hallo Jörg,

anbei eine neue Version zum Testen, wieder nur Module geändert.

der 2.0er hat mit einem miss noch gut Resynct. Ab 2 war dann Ende. Entweder habe ich einen Miss zu früh mit dem Add angefangen oder der zusätzlich wachsende Shift hat ein Problem gemacht, oder Add ist ein Holzweg.
Wenn cyclicMsgMissAdd=1 dann wird jetzt nur noch minimal geshiftet ohne zu erweitern. Das Verlängern des Intervalls passiert jetzt einen Miss später.

Bitte teste nochmal mit FW2.0 mit cyclicMsgDoShift=1 und cyclicMsgMissAdd=1. Sehen muss ich mindestens 3, besser 4, Misses in Folge im Log.

Für den 1.4er kannst Du mal mit cyclicMsgDoShift=1 testen und nach und nach cyclicMsgMissOffs 1 bis 4 durchspielen.

Gruß, Ansgar.

noansi

Hallo Jörg,

anbei eine neue Version der Module, Firmware wieder unverändert.

Ich habe CUL_HM bezüglich des Updates der Readings geändert. Die Readings werden, so weit möglich, mit Timern etwas verzögert aktualisiert. Das verringert die direkten Verzögerungen insbesondere beim devices mit vielen Readings. Durch die Art der Abarbeitung von Timern sind damit Summenverzögerungen allerdings auch nicht ausgeschlossen.

Setz bei beiden VD Versionen cyclicMsgMissAdd=0 erst mal 0. cyclicMsgDoShift und cyclicMsgMissOffs bleiben Spielwiese.

Bei TSCUL habe ich ein set getFreqOffsEst ergänzt. Damit kann vom CUL das lesen des Frequency Offset Estimate Register getriggert werden und damit das Reading FreqOffsEst mittels notify aktualisiert werden.
Das gibt die Möglichkeit mittels notify auf eine einzelene Aktualiserung eines Status eines der HM devices hin das FreqOffsEst reading zu aktualisieren und beim CUL zu loggen.
Die Werte von FreqOffsEst sind aber mit Verstand und Vorsicht zu genießen, da sie damit nicht zwingend wirklich dem HM device zuzordnen sind (wenn z.B. ein weiteres device mittlerweile empfangen wurde oder im Multi-CUL Betrieb, weil es nur von einem anderen CUL empfangen wurde). Nutzbar ist es ohnehin nur bei Protokollen, die das Register auch seitens cc1101 nutzbar machen, also auf jeden Fall nicht bei SlowRf.

Gruß, Ansgar.

Adimarantis

Hi Ansgar,

Ja, das mit dem GetFreqOffsEst wird bei mir schwierig, da aufgrund der vielen HM Device einiges los ist.

Also bisher muss ich leider sagen, dass sich die Situation eher immer weiter verschlechtert. Die Misses zählen fast ununterbrochen hoch und die Antriebe gehen sogar teilweise auf Fehlerposition.
Hab auch schon versucht die Antriebe in andere Zimmer zu stellen und habe auch die Antenne vom Nano nachgelötet (da hatte ich auch den Eindruck, das da was vom umherräumen gelitten hatte). Die Antriebe sind jetzt auch auf Netzbetrieb umgebaut (Hohlstecker sind angekommen) und einer läuft jetzt mit Netzteil.
Das Spielen mit den Parametern hat leider auch keinen nachvollziehbaren Effekt. Ich hab jetzt alle Attribute gelöscht (=Default) und der 2.0er scheint sich gerade ein bisschen zu fangen.

Gruß, Jörg
Raspberry 4 + HM-MOD-RPI-PCB (pivCCU) + RfxTrx433XL + 2xRaspberry 1
Module: 50_Signalbot, 52_I2C_ADS1x1x , 58_RPI_1Wire, (50_SPI_MAX31865)