Nebeneffekt -> Server restart lässt credits hochlaufen mit "time information"

Begonnen von arm9999, 11 März 2021, 10:31:24

Vorheriges Thema - Nächstes Thema

arm9999

Hallo,
ist bestimmt ein config Thema bei mir, aber ich stehe auf dem Schlauch und kann es einfach nicht finden ...

Nach dem Umstieg von FHEM unter Windows auf FHEM unter Debian habe ich das Thema, das beim
restart/neubooten des Servers die credits unter MAX hochlaufen und sich nicht mehr von alleine
beruhigen. In der Sendqueue tauchen immer wieder time information packets auf - wie in einer Dauerschleife.
Beruhigen kann ich das nur mit einen "shutdown restart" und dem manuellen löschen der sendqueue.

Was habe ich bei der config übersehen/vergessen, dass beim restart kein ordentlicher reset passiert?


Internals:
   DEF        xxxxxx
   FUUID      xxxxxxx
   IODev      MaxCUL
   LASTInputDev MaxCUL
   MSGCNT     160
   MaxCUL_MSGCNT 160
   MaxCUL_RAWMSG Z0ED702021BD37810C65A0001180014
   MaxCUL_RSSI -70
   MaxCUL_TIME 2021-03-11 10:24:35
   NAME     MaxGW
   NR         49
   STATE    MaxCUL:ok
   SVN       22175
   TYPE      CUL_MAX
   addr       xxxxxxx
   cnt         0
   pairmode   0
   retryCount 0
   sq             0
   READINGS:
     2021-03-11 10:24:35   state           MaxCUL:ok
   sendQueue:
Attributes:
   IODev      MaxCUL
   broadcastTimeDiff 45
   event-on-change-reading .*
   fakeSCaddr 222222
   fakeWTaddr 111111
   icon         cul_max
   room       MAX,Übersicht
   showtime   0
   stateFormat state
   verbose    2


Als CUL kommt ein geflashter MAXLAN zum Einsatz mit CUBe und funktioniert sonst einwandfrei.
Der Server bezieht beim Start seine Systemzeit über einen NTP Server im Netz und FHEM bekommt
auch die korrekte Zeit.

Wer hat eine Idee was ich hier übersehen habe?

Wzut

Du hast zwar broadcastTimeDiff schon auf 45 Sekunden gesetzt, aber ich befürchte deine FHEM Systemzeit passt so gar nicht zu den HTs/WTs.
Klären kann man das nur mit einem verbose 5 Log des CUL_MAX Device.
Im Log sieht mann dann immer wie groß der Zeitunterschied aktuell ist und warum CUL_MAX meint diese nachziehen zu müssen.
Bzw. dieses Nachziehen ist bei dir vermutlich auch nicht erfolgreich und so kommt es ständig zu neuen Zeit Anforderungen was natürlich ein Alptraum für die Creadits ist.
Maintainer der Module: MAX, MPD, UbiquitiMP, UbiquitiOut, SIP, BEOK, readingsWatcher

Wernieman

Wird eigentlich fhem vor oder nach dem ntp-Server gestartet?

Kenne jetzt MAX nicht, aber wir hatten im Forum schon mal Probleme, weil FHEM vor dem ntp-Deamon gestartet wurde und durch den Zeitsprung Notifys durcheinander kamen.
- Bitte um Input für Output
- When there is a Shell, there is a Way
- Wann war Dein letztes Backup?

Wie man Fragen stellt: https://tty1.net/smart-questions_de.html

arm9999

Ein ntp wird durch das System gestartet, sobald das Netzwerkinterface zur Verfügung steht. Ich habe jetzt mal den Start von FHEM um 5 Sekunden nach einem reboot verzögert ... mal sehen ob das den erwünschten Erfolg bringt  ::)

adn77

Ich hole das Thema nochmal hoch...
Seitdem ich an einigen WTs die Batterien getauscht habe, bekomme ich das gleiche Fehlerbild (verwende die aktuelle Beta). Hab jetzt mal das broadcastTimeDiff gesetzt.

@arm9999 wie konntest du das Problem lösen?

Wzut

Zitat von: Wzut am 11 März 2021, 17:39:50
Klären kann man das nur mit einem verbose 5 Log des CUL_MAX Device.
Im Log sieht mann dann immer wie groß der Zeitunterschied aktuell ist und warum CUL_MAX meint diese nachziehen zu müssen.
Bis heute kein Log !
Maintainer der Module: MAX, MPD, UbiquitiMP, UbiquitiOut, SIP, BEOK, readingsWatcher

arm9999

Sorry für die verspätete Antwort, habe es eben erst gesehen ...

@adn77,
wirklich lösen konnte ich das Problem nicht, habe aber stattdessen einen workaround für mich gefunden.

Aber mal kurz zusammengefasst:
- Das Problem besteht nur auf einer Linux/Debian Hardware, unter Windows hatte ich den Effekt nicht.
- Hardware CUL = geflashter MAXLAN mit CUBe
- FHEM Service wird explizit (und mit Verzögerung) nach dem Netzwerkinterface und dem NTP Dienst gestartet (bringt keine Veränderung)
- broadcastTimeDiff auf 45 Sekunden bringt auch keine Veränderung
- tritt nur auf, wenn FHEM das erste Mal neu gestartet wird
   => meine Vermutung: bei der Initialisierung der Variablen für den CUL geht was schief/fehlt was

mein Workaround nach dem FHEM das erste Mal gestartet wurde:
   -> 2x den Befehl Sendqueue löschen auslösen
   -> danach "shutdown restart" für FHEM

Nachteil, die Credits sind bereits hochgelaufen, aber reduzieren sich dann wieder.

@Wzut,
wirklich dahinter gekommen was die Ursache ist bin noch nicht. Was ich aber erkennen kann:
- es hängt mit dem Neustart von FHEM auf einer LINUX/Debian Hardware zusammen
- der NTP Dienst ist nicht der Auslöser
- die broadcastTimeDiff hat keinen Einfluss
- als erstes taucht im logfile immer einer der WTs auf, danach schaukelt es sich hoch
- obwohl auf jede Nachricht des CUL eine Quittung und Antwort der WTs erfolgt, werden diese immer wieder mit der gleichen Nachricht
   angefunkt, das löst dann die Kettenreaktion aus.

  -> daher meine Annahme, das nach der "Erstinitialisierung von FHEM und MAXCUL" irgendwo ein Zähler/eine Variable noch nicht richtig
       gesetzt ist. Nachdem die ersten Nachrichten ausgetauscht wurden, scheint diese Variable belegt worden zu sein, so dass ein "FHEM
       shutdown restart" den CUL und das Modul wieder korrekt initialisiert.

- getestet habe ich auch, ob nur eine Neuinitialisierung des CUL etwas bewirken kann, hat leider keine Veränderung gegeben.
       
- Der Ansatz könnte aber sein, dass es etwas mit der Sendqueue zu tun hat. Denn der Befehl "Sendqueue löschen" bewirkt auf jeden Fall etwas.
  Lässt man diesen Weg und macht nur einen "FHEM shutdown restart"  schaukelt sich das System weiter hoch.
 

Wzut

Zitat von: arm9999 am 29 Oktober 2021, 09:11:14
mein Workaround nach dem FHEM das erste Mal gestartet wurde:
   -> 2x den Befehl Sendqueue löschen auslösen
   -> danach "shutdown restart" für FHEM
shutdown restart löscht auch die Sendeque ! D.h. den Schritt könntest du dir sparen.
Aber wie soll man hier wirklich weiterhelfen wenn die simple Bitte nach einem verbose 5 Log so hartnäckig ignoriert wird ?
Maintainer der Module: MAX, MPD, UbiquitiMP, UbiquitiOut, SIP, BEOK, readingsWatcher

arm9999

Hallo Wzut,

sorry, wollte nicht unhöflich sein und deine Bitte ignorieren. Ich bin seit ein paar Monaten viel unterwegs und dann habe ich es auch verbaselt, nachdem der workaround funktionierte. ( Die Befehlssequenz wird bei mir von einem Home Assistant Server (weiterer Server in meiner Hausautomatisierung) quasi remote auf FHEM ausgeführt, wenn der Fehler auftritt). Hole ich aber nach!

Welche Geräte/Module soll ich denn auf den Level5 setzen - nur den MaxCUL? Reicht dir dann eine Kopie der Ansicht aus dem Event Monitor oder welchen log brauchst du genau?

Der Hinweis von dir, dass beim "shutdown restart" auch die Sendequeue gelöscht wird, ist ein wichtiger Tipp. Denn nur ein "shutdown restart" löst das Problem mit den Credits nicht, erst wenn man den Befehl vorher ausführt und dann einen "shutdown restart" macht, gelingt es. Hier scheint der Unterschied zu liegen - was macht denn die Routine noch vor dem löschen der Sendequeue?

LG

arm9999

Nachtrag zu meinem letzten Post:

Ich verwende einen geflashten MaxCUL mit der SW Version:
V 1.26.08 a-culfw Build: private build (unknown) CUBe (F-Band: 868MHz)

Der CUL wird via seiner IP Adresse angesprochen, das DEF lautet:
192.168.x.xxx:2323 0000

Default Init-String in FHEM:
X21
Zr
Za0xxxx1  (xxxx = natürlich die richtige Adresse des CUL)
Zw111111

Als "Reset-Sequenz" für meinen MaxCUL, wenn die credits nach einem Neustart aus dem Ruder laufen, verwende ich:
- set MaxCUL raw B00
- 2 Sekunden warten
- set MaxCUL raw X21 Zr Za0xxxx1 Zw111111
- 4 Sekunden warten
- set MaxGW deleteSendQueue
- 4 Sekunden warten
- set MaxGW deleteSendQueue
- shutdown restart

Danach geht der Credit Wert auf "natürlichem Wege", sprich wie vorgeschrieben, wieder kontinuierlich auf den Wert 0 zurück.
Die Sequenz oben ist experimentell entstanden und vlt. ist der eine oder andere Zwischenschritt redundant, aber nur so konnte
ich das Problem als workaround fixen. Aktuell wird bei jedem Neustart von FHEM, z.B. nach einem update, das "Credithochl-
aufproblem" ausgelöst.

adn77

Bei mir verschwand das Problem nachdem ich broadcastTimeDiff auf 60 gesetzt habe.
(Ich kannte das Attribut vorher gar nicht...)

Alex

Wzut

Zitat von: arm9999 am 08 November 2021, 10:31:32
- set MaxCUL raw B00
wenn du mit solchen Mitteln an deinen CUL nach Neustart ran musst dann wird sich das Problem nicht auf MAX Modulebene lösen lassen.
Hier sind andere Profis bzw Unterforen gefragt zumal das Ganze ja wohl auch noch vom eingesetzen OS Unterbau abhängig ist.
Maintainer der Module: MAX, MPD, UbiquitiMP, UbiquitiOut, SIP, BEOK, readingsWatcher

arm9999

Ist auch nur ein workaround, da es keine Lösung gibt.

Warum beim Neustart von FHEM das MaxGW den CUL ständig was senden lässt und vor allem warum, ist ja noch nicht gefunden. Was genau wie initialisiert wird, ob da Variablen nicht vollständig belegt sind oder zufällige oder alte Werte drinnen sind, hatte ich ja schon öfters formuliert. Auch Ansätze wo oder woher das kommen könnte.

An der Zeitsynchronisierung der hardware mit dem RTC oder über NTP zu FHEM liegt es definitiv nicht.

Zum Glück habe ich das Problem nur nach einem update mit Restart von FHEM .... mein workaround hilft vorerst das System zu stabilisieren, bis ich die Zeit habe den Modulcode vollständig zu lesen und zu prüfen. Vlt. ergeben sich daraus dann Ansätze.