Ankündigung

Einklappen
Keine Ankündigung bisher.

Widget status.log: Mehrfache identische Einträge

Einklappen
X
 
  • Filter
  • Zeit
  • Anzeigen
Alles löschen
neue Beiträge

  • bmx
    antwortet
    Um das ganze etwas gezielter zu beleuchten habe ich ein Issue auf Github erstellt

    Einen Kommentar schreiben:


  • Onkelandy
    antwortet
    Ich hab's jetzt mal mit dem Fix probiert. Ging ne Weile ganz gut, jetzt hagelt es wieder die Meldung:
    Code:
    Aug 15 23:57:32 ERROR    modules.websocket update_log - Error in 'await websocket.send(data)': received 1001 (going away); then sent 1001 (going away)
    Traceback (most recent call last):
      File "/usr/local/smarthome/modules/websocket/__init__.py", line 1018, in update_log
        await websocket.send(msg)
      File "/home/smarthome/.local/lib/python3.9/site-packages/websockets/legacy/protocol.py", line 620, in send
        await self.ensure_open()
      File "/home/smarthome/.local/lib/python3.9/site-packages/websockets/legacy/protocol.py", line 921, in ensure_open
        raise self.connection_closed_exc()
    websockets.exceptions.ConnectionClosedOK: received 1001 (going away); then sent 1001 (going away)
    Hab nochmals kontrolliert, websocket init ist die Version hier: https://github.com/smarthomeNG/smart...91fe093a6f8f5b

    Einen Kommentar schreiben:


  • Onkelandy
    antwortet
    Also bei mir führte das status log recht konstant zum großen Chaos und Neustart, deshalb hab ich das Widget rausgenommen gehabt. Gerne teste ich nun mal mit dem Fix und wieder aktiviertem Status Widget.

    Einen Kommentar schreiben:


  • wvhn
    antwortet
    aschwith Problem saß vor dem Rechner. Beim Umstellen auf den geänderten Treiber hatte ich die Ports vom visu_websocket plugin erwischt, da das Websocket-Modul bei mir nicht auf den Standard-Ports läuft.

    Somit kann ich 3 Aussagen treffen:
    • wenn man die richtigen Ports verwendet, dann ist der Fehler mit dem Websocket Modul eindeutig reproduzierbar
    • mit dem visu_websocket-Plugin tritt der Fehler nicht auf
    • alle überzähligen Messages auf dem Websocket werden jetzt von der Konsolenausgabe angezeigt. D.h. hier gibt es am Treiber keinen Untersuchungsbedarf mehr.
    Um dIe vierte Aussage abschließend zu treffen, ist es noch etwas früh: aktuell behebt Dein Fix auch bei mir den Fehler zuverlässig. Ich teste das weiter.

    Vielen Dank!

    Gruß
    Wolfram

    Einen Kommentar schreiben:


  • aschwith
    antwortet
    Onkelandy Tritt der Berserker Modus bei Dir in letzter Zeit noch auf? Hast du dazu noch die Log Dateien?

    Eine Sache ist mir beim Debuggen von obigem Problem noch aufgefallen: Solange ein Loghandler durch eine geöffnete Smartvisu aktiv sind, gibt es die Gefahr, Event Schleifen zu generieren. Beispiel: Tritt im module websocket in der Verarbeitung eines Log Events eine Log Meldung auf (z.B. Warning) auf, triggert dies wiederum die log Event Verarbeitung. So können gefährliche Dauerschleifen entstehen.
    Zuletzt geändert von aschwith; 03.07.2022, 17:37.

    Einen Kommentar schreiben:


  • aschwith
    antwortet
    Hallo Wolfram,

    Ich habe ins Develop einen Fix für das smarthomeNg websocket modul geschoben, welches das mehrfache Registrieren des log Handlers verhindert. Vorher wurde bei jedem forcierten Neuladen von Smartvisu ein zusätzlicher identischer Eventhandler registriert und damit jeweils doppelte, dreifache usw. Einträge erzeugt. Das Thema sehe ich damit als gelöst an. Msinn kann den Fix gerne nochmal kritisch begutachten, sobal er Zeit hat.

    Ein Tool zum Mithören auf dem Websocket habe ich nicht direkt zur Hand. Meinst du, wir müssen uns deinen Aspekt auf Smartvisu Seite nochmal anschauen?

    Einen Kommentar schreiben:


  • wvhn
    antwortet
    aschwith Danke für die Recherche. Hast Du ein Tool, mit dem Du auf dem Websocket mithören kannst? Mich wundert, dass die Konsolenausgabe der Websocket-Message im Event-Handler io.socket.onmessage nur einmal ausgeführt wird, während im selben Handler direkt anschließend im "switch (data.cmd) … case log:" das "else" mehrfach durchlaufen wird.

    Hinsichtlich des shNG-Anteils gibt es ein issue im Repo von shNG um das Thema zu Ende zu verfolgen.

    Onkelandy vlt. ist damit ein Ansatz für Deinen Berserker-Modus bei Verwendung des Log-Widgets gefunden? Exponentieller (?) Anstieg der Eventhandler bis zum Neustart von shNG?

    Gruß
    Wolfram
    Zuletzt geändert von bmx; 16.08.2022, 07:25. Grund: issue erstellt und Text angepasst

    Einen Kommentar schreiben:


  • aschwith
    antwortet
    Das ist gar kein Problem. Das Thema hat Zeit. Arbeit geht vor. VG

    Einen Kommentar schreiben:


  • Msinn
    antwortet
    Zitat von aschwith Beitrag anzeigen
    Msinn, Kannst Du hier unterstützen? Ich habe das Problem bis in den smarthomeNG websocket zurückverfolgt. Die Funktion
    Im Prinzip ja, aber ich bin im Moment beruflich stark eingespannt und komme erst in 3 bis 4 Wochen wieder dazu mich mit SmartHomeNG Themen zu beschäftigen.

    Einen Kommentar schreiben:


  • aschwith
    antwortet
    wvhn: Die mehrfachen Logeteinträge kommen aus den Tiefen von SmarthomeNG.

    @Msinn: Die Einträge werden sogar vor der Janus Queue schon durch mehrfaches Ausführen der module.websocketfunktion "update_visulog" erzeugt. Das Problem ist in der Tat, dass in der Funktion


    Code:
    async def smartVISU_protocol_v4(self, websocket):
    
        self._sh.add_event_listener(['log'], self.update_visulog)
    jedes Mal ein neuer Event Listener angelegt wird, auch wenn dieser schon exisitiert. Sobald mehrere Listerener für das Event "log" exitistieren, werden diese natürlich auch mehrmals getriggert und führen zu den ganzen Problem, siehe oben. Können wir dafür sorgen, dass der Listener definitiv nur einmal registriert wird?

    Danke und Gruß
    Alex
    Zuletzt geändert von aschwith; 02.07.2022, 19:34.

    Einen Kommentar schreiben:


  • aschwith
    antwortet
    Msinn, Kannst Du hier unterstützen? Ich habe das Problem bis in den smarthomeNG websocket zurückverfolgt. Die Funktion

    Code:
    async def update_log(self, log_entry):
    wird schon mehrmals mit gleichem Inhalt getriggert. Ich habe noch nicht gefunden, wo die log Daten in die Janus Queue geschrieben werden. Geht beim Schreiben in die Queue evtl. schon was schief und Einträge werden gedoppelt?

    Einen Kommentar schreiben:


  • aschwith
    antwortet
    Im Treiber smarthome.py.js habe ich eine Konsolenausgabe hinzugefügt:

    Code:
    case 'log':
        if (data.init) {
            widget.update(data.name, data.log);
        }
        else {
    
            console.log("[log received without init]: ", data.name, data.log.length);
    
            var log = widget.get(data.name); // only a reference
    
            for (var i = 0; i < data.log.length; i++) {
                log.unshift(data.log[i]);
    
                if (log.length >= 50) {
                    log.pop();
                }
            }
    
            widget.update(data.name);
        }
        break;
    Bereits das "else" wird mehrmals mit identischen Werten getriggert. Der Fehler kommt also schon aus dem websocket Treiber von smarthomeNG?
    Zuletzt geändert von aschwith; 02.07.2022, 16:42.

    Einen Kommentar schreiben:


  • aschwith
    antwortet
    Hallo Wolfram,

    danke für die Erläuterung. Ich habe jetzt auch gesehen, dass man im Debugger den widget.buffer aufklappen kann. Finde dort jetzt auch den Eintrag "klingellogger". Du hast recht, die mehrfachen Einträge tauchen bereits im widget.buffer auf.

    Kann ich noch unterstützen und bei mir logs hinzufügen?

    Einen Kommentar schreiben:


  • wvhn
    antwortet
    Hi Alex,
    leider ist das mit dem Nachstellen doch nicht so einfach. Mein Entwicklungssystem (smartVISU auf PC mit shNG-Backend auf meinem Test-Pi) hat den Fehler nicht. smartVISU develop auf meinem Test-Pi zeigte diesen Fehler zunächst. Nachdem ich in eine Kopie des Treibers ein paar Konsolenausgaben eingebaut habe, ist der Fehler weg - auch nach Zurückwechseln auf den vorherigen Treiber. Lediglich mein Produktiv-Pi (SV3.2.2) zeigt den Fehler noch. Da der Cache aktiviert ist, bekomme ich aber keine Konsolenausgaben...

    widget.buffer registriert alles, was an Daten für die Widgets gebraucht wird. Dein item "klingellogger" muss auch dabei sein. Es sollte ein Array sein, dessen Länge die Anzahl der Einträge ist. Beispiel:

    Die Logger von shNG schicken beim ersten Abfragen ein JSON mit allen Einträgen und einem Attribut "init":"y". Wenn "init" = "y" ist, schreibt der Treiber io_smarthomeNG.js die Daten per "widget.update(item, data)" in den buffer - mit dem jünsten Eintrag zuerst (index 0). Werden neue Logeinträge über den Websocket übertragen, dann fehlt das "init"-Attribut. In diesem Fall schreibt der Treiber die neuen Einträge in einer Schleife mit der js-Funktion "unshift" an die ersten Stellen im widget.buffer und triggert dann die Update-Methode für das item (ohne Daten, da die ja schon im buffer sind).

    Bei meinen Beobachtungen stehen die fälschlich mehrfachen Einträge in widget.buffer. D.h. der Fehler muss schon im Treiber auftreten. Weitere Anhaltspunkte habe ich leider noch nicht.

    Gruß
    Wolfram

    Einen Kommentar schreiben:


  • aschwith
    antwortet
    Hi Wolfram,

    perfekt, dass Du es auch nachstellen kannst. Das Konsolenausgabe zu Widget.buffer bringt mich nicht weiter. Hier werden nur Items gelistet, die gar keine Relevanz für das status.log haben. Funktioniert die Kommunikation zwischen status.log und dem SmarthomeNG plugin (z.B. operationlog) überhaupt über ein reguläres Item? Sieht mir gerade nicht danach aus. (Es gibt ja auch für das smarthome log auf der Statusseite kein Zugehöriges Item, in das man z.B. im Admin Interface schauen könnte, oder? Ich verstehe gerade noch nicht, wie der Update Mechanismus hier funktioniert.

    Einen Kommentar schreiben:

Lädt...
X