Sonos crashed FHEM

[m0urs]

Hi,

ich bin ratlos. Seit heute nacht scheint FHEM zwar ohne Fehler zu starten, aber man kann nicht mehr per Browser zugreifen, egal welche FHEMWEB-Instanz. Alle hören zwar noch auf ihren Port, Zugriffe laufen aber ins Leere. Als Übeltäter konnte ich jetzt nach längerem Suchen das SONOS-Modul ausmachen.

Wenn ich alle SONOS-definitionen lösche, funktioniert alles problemlos.

Wenn ich das Sonos-Device aktiviere mit

Code: [Auswählen]

define SONOS SONOS localhost:4711 120 1 5
dann geht auch noch alles. Solange bis das Sonos-Device auf "opened" geht und dann alle Player definiert. Sobald das passiert, ist der Zugriff per Web tot.

Geändert habe ich m.E. seit gestern in der Umgebung von Fhem oder Sonos nichts. Allerdings wurde gestern eine neue Fritzbox installiert, die die alte Box abgelöst hat. Da die Fritzbox aber lediglich als exposed Host auf meinen eigenen Router durchschleift, sollte das keinen Einfluss haben.

Hat noch jemand eine Idee?? Dankeschön!

[m0urs]

Hm, es sieht aus, als würden HABRIDGE und SONOS  beide auf Port 1900/UDP lauschen:

Code: [Auswählen]

#netstat -tulpn | grep :1900
udp        0      0 0.0.0.0:1900            0.0.0.0:*                           9273/java
udp   164864      0 0.0.0.0:1900            0.0.0.0:*                           6390/perl
udp        0      0 0.0.0.0:1900            0.0.0.0:*                           6390/perl

# ps aux | grep 6390
fhem      6390  3.8  6.0 101880 60864 ?        Sl   11:37   0:38 /usr/bin/perl ./FHEM/00_SONOS.pm 4711 3 0 startedbyfhem

Dann ist aber die Frage, seit wann ist das so? HABRIDGE hab ich in letzter Zeit nicht angefasst, das Sonos-Modul wurde vor kurzem m.W. per Fhem-Update aktualisiert. Wurde im Sonos-Modul diesbezüglich etwas geändert?
[/code]
Wenn ich HABRIDGE stoppe, komme cih auch wieder auf die Web-Oberfläche von FHEM.

UPDATE:

Das war es wohl doch nicht. Auch wenn ich HABRIDGE gar nicht starte, habe ich das Problem. Es sieht so aus, als würde FHEM komplett blockieren, sobald der erste Zugriff auf ein Sonos-Device erfolgt. Wenn ich "usedonlyIPs" auf eine nicht vorhandene IP setze (z.B. "192.168.1.2542), dann kann ich FHEM weiter ansprechen. Natürlich geht dann die Sonos-Integration nicht.

UPDATE:

Obwohl die Weboberfläche keine Reaktion mehr zeigt, scheint die Sonos-Schnittstelle weiterhin zu arbeiten und Logeinträge zu produzieren:

Code: [Auswählen]

2020.03.05 13:15:42 1: FHEMWEB SSL/HTTPS error: Broken pipe SSL accept attempt failed (peer: 192.168.1.128)
2020.03.05 13:15:42 3: MQTT2: MQTT2_192.168.4.60_63211/DVES_9ACB60 left us (keepalive check)
2020.03.05 13:15:42 3: MQTT2: MQTT2_192.168.4.62_64613/DVES_9B2269 left us (keepalive check)
2020.03.05 13:15:42 3: MQTT2: MQTT2_192.168.4.61_49414/DVES_27DEA7 left us (keepalive check)
2020.03.05 13:15:44 3: SONOS1: Setting MinMaxVolumes of device 'RINCON_B8E937E061E001400_MR' to a new value ~ minVolume = 0
2020.03.05 13:15:46 3: SONOS1: Setting MinMaxVolumes of device 'RINCON_000E5871C40201400_MR' to a new value ~ minVolume = 0
...
2020.03.05 13:16:46 3: SONOS1: Event: End of ZoneGroupTopology-Event for Zone "SONOS_Michael".
2020.03.05 13:16:46 3: SONOS1: Event: Received DeviceProperties-Event for Zone "SONOS_Wohnzimmer".
2020.03.05 13:16:46 3: SONOS1: Event: End of DeviceProperties-Event for Zone "SONOS_Wohnzimmer".
2020.03.05 13:16:46 3: SONOS1: Event: Received ContentDirectory-Event for Zone "SONOS_Wohnzimmer".
2020.03.05 13:16:46 3: SONOS1: ContainerUpdateIDs: Q:1,6
2020.03.05 13:16:46 3: SONOS1: Event: End of ContentDirectory-Event for Zone "SONOS_Wohnzimmer".
2020.03.05 13:16:46 3: SONOS1: Event: Received GroupRendering-Event for Zone "SONOS_Wohnzimmer".
2020.03.05 13:16:46 3: SONOS1: Event: End of GroupRendering-Event for Zone "SONOS_Wohnzimmer".
2020.03.05 13:16:46 3: SONOS1: Event: Received ZoneGroupTopology-Event for Zone "SONOS_Bad".
2020.03.05 13:16:46 3: SONOS1: Event: End of ZoneGroupTopology-Event for Zone "SONOS_Bad".
2020.03.05 13:16:46 3: SONOS1: Event: Received ZoneGroupTopology-Event for Zone "SONOS_Kueche".
2020.03.05 13:16:46 3: SONOS1: Event: End of ZoneGroupTopology-Event for Zone "SONOS_Kueche".
2020.03.05 13:16:46 3: SONOS1: Event: Received ZoneGroupTopology-Event for Zone "SONOS_Wohnzimmer_SW".
2020.03.05 13:16:46 3: SONOS1: Event: End of ZoneGroupTopology-Event for Zone "SONOS_Wohnzimmer_SW".
2020.03.05 13:16:46 3: SONOS1: Event: Received ZoneGroupTopology-Event for Zone "SONOS_Schlafzimmer".
2020.03.05 13:16:46 3: SONOS1: Event: End of ZoneGroupTopology-Event for Zone "SONOS_Schlafzimmer".
2020.03.05 13:16:48 3: SONOS1: Event: Received Transport-Event for Zone "SONOS_Michael".
2020.03.05 13:16:49 3: SONOS1: Event: End of Transport-Event for Zone "SONOS_Michael".
2020.03.05 13:16:49 3: SONOS1: Event: Received Transport-Event for Zone "SONOS_Michael".
2020.03.05 13:16:49 3: SONOS1: Event: End of Transport-Event for Zone "SONOS_Michael".
2020.03.05 13:16:49 3: SONOS1: Event: Received ZoneGroupTopology-Event for Zone "SONOS_Sabine".
2020.03.05 13:16:49 3: SONOS1: Event: End of ZoneGroupTopology-Event for Zone "SONOS_Sabine".
2020.03.05 13:16:49 3: SONOS1: Event: Received ZoneGroupTopology-Event for Zone "SONOS_Wohnzimmer_SW".
2020.03.05 13:16:49 3: SONOS1: Event: End of ZoneGroupTopology-Event for Zone "SONOS_Wohnzimmer_SW".
2020.03.05 13:16:49 3: SONOS1: Event: Received ZoneGroupTopology-Event for Zone "SONOS_Schlafzimmer".
2020.03.05 13:16:49 3: SONOS1: Event: End of ZoneGroupTopology-Event for Zone "SONOS_Schlafzimmer".
2020.03.05 13:16:49 3: SONOS1: Event: Received ZoneGroupTopology-Event for Zone "SONOS_Kueche".
2020.03.05 13:16:49 3: SONOS1: Event: End of ZoneGroupTopology-Event for Zone "SONOS_Kueche".
2020.03.05 13:16:49 3: SONOS1: Event: Received ZoneGroupTopology-Event for Zone "SONOS_GaesteBad".
2020.03.05 13:16:49 3: SONOS1: Event: End of ZoneGroupTopology-Event for Zone "SONOS_GaesteBad".
2020.03.05 13:16:49 3: SONOS1: Event: Received ZoneGroupTopology-Event for Zone "SONOS_Wohnzimmer".
2020.03.05 13:16:49 3: SONOS1: Event: End of ZoneGroupTopology-Event for Zone "SONOS_Wohnzimmer".
2020.03.05 13:16:49 3: SONOS1: Event: Received ZoneGroupTopology-Event for Zone "SONOS_Bad".
2020.03.05 13:16:49 3: SONOS1: Event: End of ZoneGroupTopology-Event for Zone "SONOS_Bad".
2020.03.05 13:16:49 3: SONOS1: Event: Received DeviceProperties-Event for Zone "SONOS_Michael".
2020.03.05 13:16:49 3: SONOS1: Event: End of DeviceProperties-Event for Zone "SONOS_Michael".
2020.03.05 13:16:50 3: SONOS1: Event: Received ZoneGroupTopology-Event for Zone "SONOS_Michael".
2020.03.05 13:16:50 3: SONOS1: Event: End of ZoneGroupTopology-Event for Zone "SONOS_Michael".
2020.03.05 13:16:51 3: SONOS1: Event: Received Transport-Event for Zone "SONOS_Michael".
2020.03.05 13:16:51 3: SONOS1: Event: End of Transport-Event for Zone "SONOS_Michael".
2020.03.05 13:16:52 3: SONOS1: Event: Received DeviceProperties-Event for Zone "SONOS_Michael".
2020.03.05 13:16:52 3: SONOS1: Event: End of DeviceProperties-Event for Zone "SONOS_Michael".
2020.03.05 13:16:53 3: SONOS1: Event: Received Transport-Event for Zone "SONOS_Michael".
2020.03.05 13:16:53 3: SONOS1: Event: End of Transport-Event for Zone "SONOS_Michael".
2020.03.05 13:17:00 2: SONOS1: Discover Sonosplayer 'Wohnzimmer' (Sub) Software Revision 10.6.1 with ID 'RINCON_949F3E9112F801400_MR'
2020.03.05 13:17:00 2: SONOS1: SonosPlayer 'Wohnzimmer_SW' (Sub) with ID 'RINCON_949F3E9112F801400_MR' is already defined (as 'SONOS_Wohnzimmer_SW') and will only be updated
2020.03.05 13:17:00 3: SONOS1: ProxyObject does not exists
2020.03.05 13:17:00 2: SONOS1: SonosPlayer 'Wohnzimmer_SW' is now updated
2020.03.05 13:17:00 1: SONOS1: Service-subscribing not possible due to missing TransportService
2020.03.05 13:17:00 2: SONOS1: Alarm-Service-subscribing successful with SID=uuid:RINCON_949F3E9112F801400_sub0000000344
2020.03.05 13:17:00 2: SONOS1: ZoneGroupTopology-Service-subscribing successful with SID=uuid:RINCON_949F3E9112F801400_sub0000000345
2020.03.05 13:17:00 2: SONOS1: DeviceProperties-Service-subscribing successful with SID=uuid:RINCON_949F3E9112F801400_sub0000000346
2020.03.05 13:17:00 3: SONOS1: Discover: End of discover-event for "Wohnzimmer".
2020.03.05 13:17:00 3: SONOS1: Event: Received Alarm-Event for Zone "SONOS_Wohnzimmer_SW".
2020.03.05 13:17:00 3: SONOS1: Event: End of Alarm-Event for Zone "SONOS_Wohnzimmer_SW".
2020.03.05 13:17:00 3: SONOS1: Event: Received ZoneGroupTopology-Event for Zone "SONOS_Wohnzimmer_SW".
2020.03.05 13:17:00 3: SONOS1: Event: End of ZoneGroupTopology-Event for Zone "SONOS_Wohnzimmer_SW".
2020.03.05 13:17:00 3: SONOS1: Event: Received DeviceProperties-Event for Zone "SONOS_Wohnzimmer_SW".
2020.03.05 13:17:00 3: SONOS1: Event: End of DeviceProperties-Event for Zone "SONOS_Wohnzimmer_SW".

Ist es eigentlich normal, dass neben dem FHEM-Hauptprozess und dem Sonos-Sub-prozess noch weitere FHEM-Tasks existieren (ist mir nie so bewusst aufgefallen):

Code: [Auswählen]

fhem     25506 12.2 10.2 107832 101988 ?       S    12:57   2:54 /usr/bin/perl fhem.pl fhem.cfg
fhem     30504  7.3  6.1 101896 61260 ?        Sl   13:12   0:39 /usr/bin/perl ./FHEM/00_SONOS.pm 4711 3 0 startedbyfhem
fhem     30897  0.0  9.7 107276 96916 ?        S    13:15   0:00 /usr/bin/perl fhem.pl fhem.cfg
fhem     30898  0.0  9.7 107276 96916 ?        S    13:15   0:00 /usr/bin/perl fhem.pl fhem.cfg
fhem     30899  0.0  9.7 107276 96916 ?        S    13:15   0:00 /usr/bin/perl fhem.pl fhem.cfg
fhem     30900  0.0  9.6 107276 96724 ?        S    13:15   0:00 /usr/bin/perl fhem.pl fhem.cfg

Eben probiert:

Code: [Auswählen]

delete SONOS
define SONOS SONOS

Alle Sonos-Devices werden gelöscht und danach alle wieder neu angelegt. Sobald das Sonos-Device aber auf "opened" wechselt, komme ich weder per Web noch Telnet auf Fhem.

Und noch ein Test: Nur einen einzigen Player im Netz, alle anderen vom Strom getrennt. Und ein neues "define SONOS SONOS". Gleicher Effekt.

[Otto123]

Hi,

Da die Fritzbox aber lediglich als exposed Host auf meinen eigenen Router durchschleift, sollte das keinen Einfluss haben

Das klingt komisch ... Wozu exposed Host?

Ich denke die neue FB macht irgendwie DLNA und Sonos beisst sich fest.
Was ist mit usedOnlyIps auf die exisitierenden Player? Danach neu starten!

Siehe auch hier : https://forum.fhem.de/index.php/topic,10033.msg1027172.html#msg1027172
Und ein paar Beiträge weiter lesen

Gruß Otto

[m0urs]

Hallo Otto,

Wozu exposed Host?

Mein eigenes Netzwerk steht hinter einer pfSense Firewall / Router. Eigentlich sollte die Fritzbox nur im Bridged Mode arbeiten, aber dann hab ich Probleme mit den DECT- und IP-Telefonen, die ja dann nicht an der Fritzbox angemeldet sein können. Daher Exposed Host. Sprich alles was aus dem Internet kommt wird von der Fritzbox komplett an meine pfSense weitergeleitet und dort wird dann gefiltert etc.

Auf der Fritzbox ist alles was nach DLNA "riecht" eigentlich abgeschaltet und aus dem internen Netzwerk, da wo FHEM steht, sollte auch kein solcher Traffic Richtung Fritzbox rausgehen, weil durch pfSense geblockt.

Ich hatte auch schon in diese Richtung vermutet, aber kann es mir irgendwi nicht vorstellen, wie das gehen soll.

Bis gestern Abend ging auch mit der neuen Fritzbox alles problemlos. Heute Nacht um 01:00 Uhr hat mir Unitymedia dann die Box auf FritzOS 7.13 upgedatet und danach war anscheinend alles im Eimer. Bis auf die Fritzbox hab ich alles schon mal neu gestartet, aber es bleibt kaputt.

Die Fritzbox kommt jetzt auch gleich noch mal dran, ging bisher noch nicht. Aber ob das was hilft? :-(

Auf jeden Fall kann ich das Problem beliebige reproduzieren.

"usedonlyIPs" hab ich ja schon probiert und mal nur einen der Player eingetragen. Mit gleichem "Erfolg". Wenn man eine nicht existierende IP einträgt, dann kommt man auf FHEM wieder drauf, aber dann geht natürlich auch keine Sonos-Integration mehr.

[m0urs]

Kurzer Zwischenstand:

Neustart der Fritzbox hat nicht viel gebracht.

Ich habe jetzt mal dem Raspi, auf dem FHEM läuft, per Firewall jeglichen Traffic ausserhalb des lokalen Netzwerks verboten, also weder ins Internet noch an die Fritzbox. Das scheint (to be verified), zu helfen. Die Fhem-Instanz bleibt weiter ansprechbar, die Sonos-Devices sind auch aktiv und lassen sich steuern.

Leider ist das natürlich keine Lösung, denn der Zugriff aufs Internet muss natürlich möglich sein.

Ein versuch eine Rule zu erstellen, womit nur Port 80/44-ZTraffic nach aussen gehen darf, war auf den ersten Blick nicht erfolgreich. Die Hänger sind dann trotzdem passiert. Obwohl ich mir nicht vorstellen kann, welcher ausgehender HTTP/HTTPS-Traffic hier schuld sein soll. Broadcast/Multicast hätte ich ja noch verstanden.

Ich muss hier noch ein wenig weiter forschen. Wenn aber jemand noch eine Idee hat, immer her damit ;-)

Update:

Muss mich die Meldung "SONOS1: Service-subscribing not possible due to missing TransportService" neunruhigen? Die kam m.W. aber auch früher schon!?

[CoolTux]

Klingt so als wenn Deine Default Regel für das zum WAN Interface alles durch lässt

[m0urs]

Ja, korrekt. Outbound werden nur bekannte Malwaresites geblockt. Das sollte auch kein Problem sein. Und bis gestern Abend war auch noch alles ok.

[CoolTux]

Durchaus möglich das so aber auch multicast durch geht.
Das Prinzip einer Firewall ist eigentlich auch eher alles blocken und nur durchlassen was benötigt wird. Ich habe 2 OPNSense Firewalls, ist im Grunde wie bei Dir. Internet -> Fritzbox (DMZ) -> OPNSense -> internes Netzwerk.
Per Default ist ja eh alles verbosen und dann habe ich Regeln für die einzelnen Subnetze und natürlich für den Weg ins Internet.

[m0urs]

Ja, schon klar.

Ich habe derzeit ja testweise alles geblockt (damit geht es) und dann zusätzlich eine Regel, die HTTP/HTTPS an alle nach draußen Hosts freigibt. Sobald diese Rule aktiv ist, sind die Hänger wieder da. D.h. 80/TCP und 443/TCP reicht schon. Sprich, es liegt nicht am Multicast-Traffic, reiner TCP HTTP-Traffic scheint schon zu reichen. Und das versteh ich nicht.

[m0urs]

So, ich denke ich bin einen Schritt weiter. Wenn ich mich nicht ganz irre, ist folgender Traffic verantwortlich:

Code: [Auswählen]

Outbound Port 80/TCP zu mehreren Adressen im Netz 104.17.0.0/16
Die IPs gehören zu Cloudflare, was es nicht leicht macht, die wahre Destination (und damit die Quelle in FHEM) zu ermitteln. Jedenfalls, wenn ich diesen Traffic auf der Firewall bockiere, läuft FHEM mit SONOS wieder ganz normal.

Hat da jemand zufällig eine zündende Idee, wie ich den Task in FHEM ausmachen kann, der den Traffic verursacht??

Update:

Mal ins Unreine  gesprochen:

https://securitytrails.com/list/ip/104.17.107.184

liefert mir Hinweise auf TuneIn. Derzeit läuft auf Sonos ein Radiosender über TuneIn. Kann es also sein, dass der Sonos-Task in FHEM hier doch die eigentliche Ursache ist:

Code: [Auswählen]

Name:    api-auw1-cf.radiotime.com.cdn.cloudflare.net
Addresses:  104.17.106.184
          104.17.107.184
Aliases:  api.tunein.com
          api.radiotime.com
          api-auw-00pct.radiotime.com


[Otto123]

BTW: Wenn dein Provider die Box wirklich "verwaltet" dann können die auch die Konfiguration ändern. Also Du schaltest alles ab und die schalten alles wieder ein. -> https://de.wikipedia.org/wiki/TR-069

Ich bleibe mal hartnäckig bei dem Gedanken, weil Du ja sagst da besteht ein unmittelbarer Zusammenhang.

Mein Verständnis Sonos FHEM ist: FHEM bedient Sonos, Sonos arbeitet für sich. Wenn Sonos TuneIn spielt dann hat der Traffic mit FHEM nichts zu tun.

[m0urs]

Also ich kann bestätigen:

Wenn ich dem Raspi mit FHEM per Firewall-Rule verbiete mit den beiden Cloudflare-Adressen (hinter denen sich TuneIn verbirgt) zu reden, dann funktioniert alles einwandfrei. Öffne ich den Zugriff wieder, bleibt FHEM innerhalb einiger Sekunden hängen und kommt auch nicht mehr wieder.

Wenn ich FHEM runterfahre, hört der Traffic an die beiden Adressen auf. Also geht er schon von FHEM aus.

Das einzige was mir bei FHEM und TuneIn einfällt, ist die Sonos-Integration.

Also bleibe ich, bis zum Beweis des Gegenteils (:-)) dabei, irgendwas im Sonos-Modul geht kaputt wenn der Zugriff offen ist.

Ist jetzt erst mal nicht mehr so problematisch da ich mit der Firewall-Rule eine Lösung habe, die aus meiner Sicht keine Einschränkung bedeutet. Damit kann ich gut leben.

Ich mag es aber lieber Probleme zu verstehen und nicht nur die Symptome zu behandeln, daher bleiben für mich noch folgende Fragen offen.

• Warum hat das bis vorgestern Nacht problemlos funktioniert?
• Liegt es tatsächlich an der neuen Fritzbox oder war es ein dummer Zufall?
• Wenn es an der Fritzbox liegt, was ist die Root Cause? Ich kann mir irgendwie keinen grund vorstellen.
• Wenn es nicht an der Fritzbox liegt, was war dann der Grund?
• Wenn es nicht an der Fritzbox liegt, warum scheine nur ich das Problem zu haben? Oder hören andere keine TuneIn-Sender mit Sonos?

Antworten zu den Fragen wären sehr willkommen.

Zum Thema TR-069: Genau das ist der Grund, warum bei mir nach der Fritzbox mein eigener Router/Firewall basierend auf pfSense kommt. Egal, was er Provider auf der Fritzbox konfiguriert, in mein Netz und aus meinem Netz fließt nur Traffic, den ich approved habe ;-)

Update:

Kann es sein, dass der TuneIn-Zugriff vom Sonos-Modul in FHEM dazu dient irgendwelche Titelinformationen / Coverbilder ec. von TuneIn nachzuladen?

[djcysmic]

Bei mir tritt diese Problematik auch nach einem der letzten Updates auf - selbe Konstellation Sonos mit TuneIn.

Ich habe eben kurzerhand die beiden IPs per /etc/hosts geblockt und es scheint wieder zu laufen - vielen Dank schon einmal dafür.

Es muss an einem Modulupdate etc. gelegen haben, da ich nichts an der Hardware geändert habe.


Update: Das brachte leider nur kurzzeitig eine Verbesserung - das Sonosmodul blockiert leider wieder mein FHEM