Ankündigung

Einklappen

Hinweis

Die Forenregeln wurden überarbeitet (Stand 7.11.22). Sie sind ab sofort verbindlich. Wir bitten um Beachtung.
Mehr anzeigen
Weniger anzeigen

SHNG Stürzt ab "worker threads", "ERROR modules.websocket update_item "

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

    SHNG Stürzt ab "worker threads", "ERROR modules.websocket update_item "

    Hallo zusammen,

    derzeit bekomme ich im Log eine Vielzahl von Einträgen "ERROR modules.websocket update_item". Dieses Problem hatte ich zuvor schon einmal, es war aber nicht so schlimm. Das hat sich jetzt geändert, denn SHNG geht nun wegen zu vieler worker threads in den Neustart.

    Da ich nicht weiß, was genau wichtig ist, poste ich hier einmal ein paar charakteristische Logeinträge. Der Log ist insgesamt extrem lang, weil immer wieder folgende Meldung kommt (geschätzt Hunderte davon):

    Code:
    2022-09-04  00:43:40 ERROR    modules.websocket   update_item - Error in 'await websocket.send(data)': received 1001 (going away) WebSocket is closed due to suspension.; then sent 1001 (going away) WebSocket is closed due to suspension.
    > Traceback (most recent call last):
    >   File "/usr/local/smarthome/modules/websocket/__init__.py", line 941, in update_item
    >     await websocket.send(msg)
    >   File "/home/smarthome/.local/lib/python3.7/site-packages/websockets/legacy/protocol.py", line 619, in send
    >     await self.ensure_open()
    >   File "/home/smarthome/.local/lib/python3.7/site-packages/websockets/legacy/protocol.py", line 920, in ensure_open
    >     raise self.connection_closed_exc()
    > websockets.exceptions.ConnectionClosedOK: received 1001 (going away) WebSocket is closed due to suspension.; then sent 1001 (going away) WebSocket is closed due to suspension.
    2022-09-04  00:43:41 ERROR    modules.websocket   update_item - Error in 'await websocket.send(data)': received 1001 (going away) WebSocket is closed due to suspension.; then sent 1001 (going away) WebSocket is closed due to suspension.
    > Traceback (most recent call last):
    >   File "/usr/local/smarthome/modules/websocket/__init__.py", line 941, in update_item
    >     await websocket.send(msg)
    >   File "/home/smarthome/.local/lib/python3.7/site-packages/websockets/legacy/protocol.py", line 619, in send
    >     await self.ensure_open()
    >   File "/home/smarthome/.local/lib/python3.7/site-packages/websockets/legacy/protocol.py", line 920, in ensure_open
    >     raise self.connection_closed_exc()
    > websockets.exceptions.ConnectionClosedOK: received 1001 (going away) WebSocket is closed due to suspension.; then sent 1001 (going away) WebSocket is closed due to suspension.
    Dann kommt irgendwann:

    Code:
    2022-09-04  00:44:11 ERROR    lib.scheduler       Needing more worker threads than the specified maximum of 20!  (30 worker threads active)
    2022-09-04  00:44:11 WARNING  lib.scheduler       Worker-Threads: plugins.database.Remove old: 28, plugins.database.Buffer dump: 2
    2022-09-04  00:44:11 WARNING  lib.smarthome.main  --------------------   SmartHomeNG restarting, initiated by SmartHomeNG (scheduler started too many worker threads (30))   --------------------
    2022-09-04  00:44:39 WARNING  plugins.database    Skipping dump, since an other database operation running! Data is buffered and dumped later.
    Zwischendurch kommt die Meldung vom database-Plugin "skipping dump" auch immer mal. Zudem die Meldung "Needing more worker threads".

    Für die Übersichtlichkeit schreibe ich in einem neuen Post weiter.
    Cheers
    Art Mooney

    #2
    Es fällt noch auf, dass das Log zwischendurch für viele Stunden ruhig ist. Zum Beispiel war heute Nacht ein Neustart von SHNG um 0:45, dann bis 7:09 alles ruhig. Um 7:09 ging es wieder los, aber nur mit den Meldungen "ERROR modules.websocket update_item".

    Das könnte daran liegen, dass "ERROR modules.websocket update_item" mit der Benutzung der VISU zu tun hat, die nachts niemand verwendet hat, richtig? Der Fehler mit den Worker Threads kam seit dem Neustart noch nicht wieder, "Skipping Dump" auch nicht.

    Könnte das etwas mit dem database-Plugin zu tun haben? Ich errreiche das WebIF des Plugins komischerweise nicht.

    Ich benutze das database-Plugin in der Version 1.5.15. Zudem nutze ich die Plugins avdevice, knx, mpd, russound und smartvisu.

    Unter "Schedulers" sehe ich folgende Threads:

    grafik.png


    Zuletzt noch ein paar Versionsinfos:

    SHNG-Version 1.8.2, Python 3.7.3, smartVISU 1.8.2

    Danke Euch schon jetzt für Eure Hilfe!
    Cheers
    Art Mooney

    Kommentar


      #3
      Hm. smartVISU 1.8.2 glaube ich jetzt nicht wirklich...

      SHNG 1.8.2 ist auch schon recht alt. Die von Dir beschriebenen Probleme sind IMHO in 1.9.2 bereits gefixt. Hat es einen bestimmten Grund, warum Du das bisher nicht aktualisiert hast?

      Kommentar


        #4
        Das Thema wurde hier schon mehrfach diskutiert und kann nachgelesen werden. Bisher trat dies vor allem in Verbindung mit der Verwendung des status.log Widgets in smartVISU für eigene Logger in shNG auf.

        Die beste Lösung ist sicherlich ein Update von shNG auf v1.9.2. Zusätzlich gibt es im Develop einen Fix für das Websocket-Modul. Das ist hier beschrieben.

        Gruß
        Wolfram

        Kommentar


          #5
          Danke für die Antworten. Die Themen habe ich wohl gefunden, nur die Lösung war mir nicht klar. Wenn ein Update es tut, umso besser. Ich mache eigentlich nur Updates, wenn ich Probleme habe, denn sonst läuft SHNG bei mir im Hintergrund und tut, was es soll. Da ändere ich lieber nichts ohne Grund.

          Ich mache jetzt das Update.
          Cheers
          Art Mooney

          Kommentar


            #6
            Hallo nochmal,

            nun habe ich das Update gemacht und zunächst dachte ich, das Problem sei weg. Jetzt bekomme ich aber wieder das Problem mit den Workerthreads und SHNG geht in den Neustart.

            Zudem ist mein Log voll von Meldungen, wonach kein Kontakt zum Russound-Verstärker (192.168.1.107) aufgebaut werden kann. Das ist auch kein Wunder, denn er ist meist ohne Strom und daher offline. In der Vorversion kam diese Meldung auch dann und wann aber nicht wie jetzt ca. alle 8 Sekunden.

            Ich post hier mal einen repräsentativen Ausschnitt aus dem Log:

            Code:
            2022-09-08  22:55:43 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 5/5 times, last error was: [Errno 113] No route to host
            2022-09-08  22:56:04 ERROR    lib.scheduler       Needing more worker threads than the specified maximum of 20!  (29 worker threads active)
            2022-09-08  22:56:21 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 1/5 times, last error was: [Errno 113] No route to host
            2022-09-08  22:56:29 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 2/5 times, last error was: [Errno 113] No route to host
            2022-09-08  22:56:37 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 3/5 times, last error was: [Errno 113] No route to host
            2022-09-08  22:56:45 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 4/5 times, last error was: [Errno 113] No route to host
            2022-09-08  22:56:53 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 5/5 times, last error was: [Errno 113] No route to host
            2022-09-08  22:57:05 ERROR    lib.scheduler       Needing more worker threads than the specified maximum of 20!  (30 worker threads active)
            2022-09-08  22:57:05 WARNING  lib.scheduler       Worker-Threads: plugins.mpd_zentral.update_status: 30
            2022-09-08  22:57:05 NOTICE   lib.smarthome       --------------------   SmartHomeNG restarting, initiated by SmartHomeNG (scheduler started too many worker threads (30))   --------------------
            2022-09-08  22:57:25 ERROR    lib.plugin          Plugin 'mpd' exception in stop() method: [Errno 107] Transport endpoint is not connected
            > Traceback (most recent call last):
            >   File "/usr/local/smarthome/lib/plugin.py", line 685, in stop
            >     self.plugin.stop()
            >   File "/usr/local/smarthome/plugins/mpd/__init__.py", line 148, in stop
            >     self._client.close()
            >   File "/usr/local/smarthome/lib/network.py", line 925, in close
            >     self._socket.shutdown(socket.SHUT_RD)
            > OSError: [Errno 107] Transport endpoint is not connected
            2022-09-08  22:57:51 NOTICE   lib.smarthome       --------------------   Init SmartHomeNG v1.9.2-master (cc57a0ad)   --------------------
            2022-09-08  22:57:51 NOTICE   lib.smarthome       Running in Python interpreter 'v3.9.2 final', from directory /usr/local/smarthome
            2022-09-08  22:57:51 NOTICE   lib.smarthome        - on Linux-5.10.0-17-amd64-x86_64-with-glibc2.31 (pid=40667)
            2022-09-08  22:57:51 NOTICE   lib.smarthome        - Loglevel NOTICE is set to value 31 because handler of root logger is set to level WARNING or higher  -  Set level of handler 'shng_warnings_file' to 'NOTICE'!
            Können die Workerthreads mit dem Russound-Plugin zu tun haben?

            Hier noch eine Auflistung der Threads:

            grafik.png

            Ideen?

            wvhn, ich habe den Link auf den anderen Thread gelesen. Das scheint aber nicht (mehr) das Problem bei mir zu sein, oder?
            Cheers
            Art Mooney

            Kommentar


              #7
              Diese Worker Thread Problematik hat meist ihren Ursprung in umfangreichen Datenbankabfragen. Schau mal diesen Thread dazu an.

              Das Russound Plugin verfügt aktuell über keine Ein/Aus Möglichkeit. Die Warnung kommt auch aus der lib.network diw vom Plugin genutzt wird.

              Benutzt Du mpd?

              Kommentar


                #8
                Danke. Ja, ich nutze mpd. Was könnte das Problem damit sein?

                database_maxage nutze ich nicht. Trotzdem kann es an Datenbankvorgängen liegen. Verstehe ich richtig, dass also database-Vorgänge worker threads belegen? Wenn ich also ein Ereignis habe, das viele Updates in items bewirkt, die in die Datenbank geschrieben werden, kann das die Ursache sein. Ich habe bei einigen Logiken eine von der Wetterstation gesendete Uhrzeit als Trigger. Das werde ich mir anschauen.

                Gibt es eine Möglichkeit, den TCP Connection failed Eintrag aus dem warnings log zu verbannen? So ist es arg unübesichtlich.
                Cheers
                Art Mooney

                Kommentar


                  #9
                  Zitat von Art Mooney Beitrag anzeigen
                  Danke. Ja, ich nutze mpd. Was könnte das Problem damit sein?
                  Nur das das einen Fehler wirft der nicht abgefangen wird. Könnte man mal im Plugin fixen.

                  Zitat von Art Mooney Beitrag anzeigen
                  Verstehe ich richtig, dass also database-Vorgänge worker threads belegen? Wenn ich also ein Ereignis habe, das viele Updates in items bewirkt, die in die Datenbank geschrieben werden, kann das die Ursache sein.
                  Eigentlich eher die Konstrukte, wo die Datenbank abgefragt wird, das reine Schreiben ist nicht so zeitaufwändig.
                  Und es gibt die SmartHomeNG eigenen Items wie z.B. env.core.memory die haben ein database_maxage gesetzt.

                  Zitat von Art Mooney Beitrag anzeigen
                  Gibt es eine Möglichkeit, den TCP Connection failed Eintrag aus dem warnings log zu verbannen? So ist es arg unübesichtlich.
                  Eventuell könnte man da einen Filter ins Log einbauen aber damit bin ich überfragt.

                  Ist das Russound Gerät denn an einer schaltbaren Steckdose? Ich meine das Plugin versucht ja immer wieder die Verbindung aufzubauen und wenn das Gerät nicht antworten kann weil es aus ist, dann ist das ja kontraproduktiv das Gerät immer wieder abzufragen.
                  Möglicherweise kann man das Plugin aufbohren und mit einem Item koppeln das den Versuch die Verbindung aufzubauen kontrollieren kann.

                  Kommentar


                    #10
                    Zu den logfiltern hab ich einiges in die doku geschrieben, gerne mal angucken

                    Kommentar


                      #11
                      Danke für Eure Beiträge.

                      Ich habe mir die Logs seit dem Update noch einmal näher angesehen. Es passierte dort fast nichts. Eigentlich kamen nur die Meldungen zum Russound, der über einen Schaltaktor stromlos geschaltet wird, wenn nicht benutzt. Zudem meldet sich mpd mit den zuvor schon gesehenen Logeinträgen. Die Meldung des database-Plugins "skipping dump" kommt nicht mehr.

                      Hier nochmal ein typischer Ausschnitt kurz vor Neustart:

                      Code:
                      2022-09-10  11:57:46 WARNING  lib.network         (TCP_Client_192.168.1.112:6600) unhandleded error on sending, cannot send data b'status\n'. Error: [Errno 104] Connection reset by peer
                      2022-09-10  11:57:46 ERROR    plugins.mpd_zentral.update_status Method plugins.mpd_zentral.update_status exception: [Errno 104] Connection reset by peer
                      Traceback (most recent call last):
                        File "/usr/local/smarthome/lib/scheduler.py", line 657, in _task
                          obj()
                        File "/usr/local/smarthome/plugins/mpd/__init__.py", line 193, in update_status
                          self.update_statusitems(warn)
                        File "/usr/local/smarthome/plugins/mpd/__init__.py", line 212, in update_statusitems
                          status = self._send('status')
                        File "/usr/local/smarthome/plugins/mpd/__init__.py", line 522, in _send
                          self._client.send((command + '\n').encode())
                        File "/usr/local/smarthome/lib/network.py", line 687, in send
                          bytes_sent = self._socket.send(message)
                      ConnectionResetError: [Errno 104] Connection reset by peer
                      2022-09-10  11:58:08 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 1/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  11:58:16 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 2/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  11:58:24 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 3/5 times, last error was: [Errno 113] [...]
                      No route to host
                      2022-09-10  12:12:38 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 4/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:12:46 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 5/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:13:20 ERROR    lib.scheduler       Needing more worker threads than the specified maximum of 20!  (20 worker threads active)
                      2022-09-10  12:13:24 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 1/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:13:32 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 2/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:13:40 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 3/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:13:48 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 4/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:13:56 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 5/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:14:21 ERROR    lib.scheduler       Needing more worker threads than the specified maximum of 20!  (21 worker threads active)
                      2022-09-10  12:14:34 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 1/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:14:42 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 2/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:14:50 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 3/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:14:59 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 4/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:15:07 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 5/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:15:22 ERROR    lib.scheduler       Needing more worker threads than the specified maximum of 20!  (22 worker threads active)
                      2022-09-10  12:15:45 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 1/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:15:53 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 2/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:16:01 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 3/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:16:09 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 4/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:16:17 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 5/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:16:24 ERROR    lib.scheduler       Needing more worker threads than the specified maximum of 20!  (23 worker threads active)
                      2022-09-10  12:16:55 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 1/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:17:03 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 2/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:17:11 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 3/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:17:19 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 4/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:17:25 ERROR    lib.scheduler       Needing more worker threads than the specified maximum of 20!  (24 worker threads active)
                      2022-09-10  12:17:28 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 5/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:18:06 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 1/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:18:14 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 2/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:18:22 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 3/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:18:26 ERROR    lib.scheduler       Needing more worker threads than the specified maximum of 20!  (25 worker threads active)
                      2022-09-10  12:18:30 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 4/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:18:38 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 5/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:19:16 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 1/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:19:24 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 2/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:19:27 ERROR    lib.scheduler       Needing more worker threads than the specified maximum of 20!  (26 worker threads active)
                      2022-09-10  12:19:32 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 3/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:19:40 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 4/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:19:49 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 5/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:20:27 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 1/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:20:28 ERROR    lib.scheduler       Needing more worker threads than the specified maximum of 20!  (27 worker threads active)
                      2022-09-10  12:20:35 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 2/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:20:43 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 3/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:20:51 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 4/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:20:59 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 5/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:21:29 ERROR    lib.scheduler       Needing more worker threads than the specified maximum of 20!  (28 worker threads active)
                      2022-09-10  12:21:37 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 1/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:21:45 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 2/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:21:53 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 3/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:22:01 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 4/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:22:10 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 5/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:22:31 ERROR    lib.scheduler       Needing more worker threads than the specified maximum of 20!  (29 worker threads active)
                      2022-09-10  12:22:48 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 1/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:22:56 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 2/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:23:04 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 3/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:23:12 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 4/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:23:20 WARNING  lib.network         (TCP_Client_192.168.1.107:9621) TCP connection failed 5/5 times, last error was: [Errno 113] No route to host
                      2022-09-10  12:23:32 ERROR    lib.scheduler       Needing more worker threads than the specified maximum of 20!  (30 worker threads active)
                      2022-09-10  12:23:32 WARNING  lib.scheduler       Worker-Threads: plugins.mpd_zentral.update_status: 30
                      2022-09-10  12:23:32 NOTICE   lib.smarthome       --------------------   SmartHomeNG restarting, initiated by SmartHomeNG (scheduler started too many worker threads (30))   --------------------
                      2022-09-10  12:23:54 ERROR    lib.plugin          Plugin 'mpd' exception in stop() method: [Errno 107] Transport endpoint is not connected
                      Traceback (most recent call last):
                        File "/usr/local/smarthome/lib/plugin.py", line 685, in stop
                          self.plugin.stop()
                        File "/usr/local/smarthome/plugins/mpd/__init__.py", line 148, in stop
                          self._client.close()
                        File "/usr/local/smarthome/lib/network.py", line 925, in close
                          self._socket.shutdown(socket.SHUT_RD)
                      OSError: [Errno 107] Transport endpoint is not connected
                      2022-09-10  12:24:17 NOTICE   lib.smarthome       --------------------   Init SmartHomeNG v1.9.2-master (cc57a0ad)   --------------------
                      So ging es mit ca. 1-2 Neustarts pro Tag, bis ich heute Mittag einmal den Russound gestartet habe. Seitdem sind die Russound-bezogenen Logeinträge weg und es gab auch keinen Neustart mehr, obwohl der Russound mittlerweile schon wieder seit ca. 14 Uhr keinen Strom hat. Ich beobachte das weiter.
                      Cheers
                      Art Mooney

                      Kommentar


                        #12
                        Hallo nochmal,

                        leider ist mein Problem noch nicht gelöst. Es fällt in der Tat auf, dass mpd einen Fehler meldet, wenn SHNG neu startet. Im mpd-Logfile steht folgendes:

                        Code:
                        Sep 22 22:11 : exception: error on client 85: Output buffer is full
                        Sep 22 22:11 : client: [85] closed
                        Sep 22 22:39 : client: [86] opened from 192.168.1.102:57678
                        Sep 24 11:51 : exception: error on client 86: Output buffer is full
                        Sep 24 11:51 : client: [86] closed
                        Sep 24 12:19 : client: [87] opened from 192.168.1.102:37498
                        Die Meldung um 11:51 am 24.9. ist zeitgleich mit folgender Meldung im SHNG-Log:

                        Code:
                        2022-09-24  11:51:56 ERROR    plugins.mpd_zentral.update_status Method plugins.mpd_zentral.update_status exception: [Errno 104] Connection reset by peer
                        > Traceback (most recent call last):
                        >   File "/usr/local/smarthome/lib/scheduler.py", line 657, in _task
                        >     obj()
                        >   File "/usr/local/smarthome/plugins/mpd/__init__.py", line 193, in update_status
                        >     self.update_statusitems(warn)
                        >   File "/usr/local/smarthome/plugins/mpd/__init__.py", line 212, in update_statusitems
                        >     status = self._send('status')
                        >   File "/usr/local/smarthome/plugins/mpd/__init__.py", line 522, in _send
                        >     self._client.send((command + '\n').encode())
                        >   File "/usr/local/smarthome/lib/network.py", line 687, in send
                        >     bytes_sent = self._socket.send(message)
                        > ConnectionResetError: [Errno 104] Connection reset by peer
                        Kurz danach (ca. 15 Minuten) kommt die bekannte Meldung "Needing more worker threads..."

                        Das war so am 24.9. - genau das gleiche passierte auch am 22.9. mit demselben zeitlichen Zusammenhang.

                        Ich setze jetzt mal den Output-Buffer in mpd.conf hoch, denn der soll ja angeblich voll sein.
                        Cheers
                        Art Mooney

                        Kommentar


                          #13
                          Art Mooney Es gibt im develop branch ein aktualisiertes mpd Plugin und auch ein aktualisiertes russound plugin. Beim russound habe ich zwei Funktionen hinzugefügt um den Netzwerkverkehr zur Russound zu unterbinden. Ein Item das z.B. den Netzschalter steuert kann eine Logik triggern und diese Funktionen dann aufrufen. Mangels Rusound kann ich das leider nicht testen aber wenn Du das mal ausprobieren würdest ...

                          Kommentar


                            #14
                            bmx, danke für den Hinweis auf den develop branch. Ich schaue mir das an.

                            Einstweilen habe ich probiert, mir einen Logging-Filter zu schreiben, der mir die Russound-Meldungen aus dem Log nimmt. Leider ist mir die Syntax für den Filter überhaupt nicht klar. In der Doku steht, die Strings können (nicht müssen?) Regular Expressions enthalten. Ich lese mich schon seit einiger Zeit in Regular Expressions ein. Finde das aber recht kompliziert. Ich habe mich vor allem an diesem HOWTO orientiert: Link.

                            Ich möchte eigentlich nur die Logmeldungen rausfiltern, die vom Russound kommen, also von der richtigen IP. Der Ausdruck, der in den Logmeldungen des Russound immer vorkommt ist "(TCP_Client_192.168.1.107:9621) TCP connection failed".

                            Also habe ich folgendes in die logging.yaml geschrieben. Es funktioniert allerdings nicht. Metacharaktere außer "" sollten doch in dem Klammerausdruck egal sein, oder?

                            Code:
                            version: 1
                            disable_existing_loggers: False
                            formatters:
                                shng_simple:
                                    format: '%(asctime)s %(levelname)-8s %(name)-19s %(message)s'
                                    datefmt: '%Y-%m-%d  %H:%M:%S'
                                shng_detail:
                                    format: '%(asctime)s %(levelname)-8s %(module)-17s %(threadName)-12s %(message)s  --  (%(filename)s:%(funcName)s:%(lineno)d)'
                                    datefmt: '%Y-%m-%d %H:%M:%S %Z'
                            filters:
                                russoundfilter:
                                    (): lib.logutils.Filter
                                    msg: [(TCP_Client_192.168.1.107:9621) TCP connection failed]            
                            handlers:
                                console:
                                    class: logging.StreamHandler
                                    formatter: shng_detail
                                    stream: ext://sys.stdout
                                shng_warnings_file:
                                    (): lib.log.ShngTimedRotatingFileHandler
                                    formatter: shng_simple
                                    level: WARNING
                                    when: midnight
                                    backupCount: 7
                                    filename: ./var/log/smarthome-warnings.log
                                    encoding: utf8
                                    filters: [russoundfilter]
                                shng_details_file:
                                    (): lib.log.ShngTimedRotatingFileHandler
                                    formatter: shng_detail
                                    level: DEBUG
                                    when: midnight
                                    backupCount: 7
                                    filename: ./var/log/smarthome-details.log
                                    encoding: utf8
                            loggers:
                                __main__:
                                    level: WARNING
                                    handlers: [shng_details_file]  
                                plugins.knx:
                                    handlers: [shng_details_file]
                                    level: DEBUG
                                
                            #  lib.scheduler:
                            #    level: DEBUG
                            #  plugins.cli:
                            #    level: DEBUG
                            
                            root:
                                level: WARNING
                                handlers: [shng_warnings_file]
                            Cheers
                            Art Mooney

                            Kommentar


                              #15
                              Ich behaupte es sollte so heißen..

                              Code:
                              "(.*)\\(TCP_Client_192\\.168\\.1\\.107:9621\\) TCP connection failed(.*)"
                              Siehe auch hier: https://www.smarthomeng.de/user/konf...practices.html

                              Kannst du bitte mal verlinken, wo was von "regex möglich" steht?
                              Zuletzt geändert von Onkelandy; 02.10.2022, 22:00. Grund: fixed regex

                              Kommentar

                              Lädt...
                              X