Sonos Player disappeared

[hoppel118]

Das mit dem Pärchen ist lustig... Aber schön, dass sie noch funktionieren...

Muss doch nochmal kurz darauf eingehen. Habe mich gerade nochmal damit auseinandergesetzt. Ich habe gerade über die Sonos App einen Musik-Stream im Schlafzimmer gestartet. Seither ist die WLAN-Verbindung zu beiden Symfonisk stabil. Von einem PC aus habe ich einen PING auf das Gerät laufen. Es gibt keinerlei Timeouts.

Dennoch bleibt "state disappeared". Der Stream läuft jetzt seit knappen 10min.

Warum ist das so bzw. sollte der Player nicht eigentlich irgendwann wieder in den "state appeared" wechseln?

Gruß Hoppel

[hoppel118]

betreibst Du die Dinger mit extra Wlan? Einfach Sonos Wlan und gut? Einen zentralen Player ans LAN.

Wenn ich ehrlich bin, habe ich keine Lust darauf, dass neben meinen Access Points noch ein Sonos eigenes WLAN im 2,4GHz Bereich mitfunkt. Die Kanäle 1, 6 und 11 sind bereits durch mein WLAN belegt. Wenn das SonosNet nun noch dazu kommt, kann das eigentlich nur zu Störungen führen.

Dann erreichst sich das Pärchen doch untereinander und die sind zufrieden? Oder habe ich da was falsch im Kopf?
https://support.sonos.com/s/article/3235?language=de

Jo, das hast du (glaube ich zumindest) richtig verstanden. Momentan hängt bei mir aber kein einziger Sonos Lautsprecher per Ethernet im Netzwerk. Alle laufen in meinem Unifi WLAN. Bisher gab es damit auch noch nie Probleme. Mal abgesehen von dieser einen Sonos Box. Wenn ich einen Lautsprecher per Eth anbinde, werden sofort alle ins SonosNet gezogen. Das will ich aufgrund zuvor genannter Gründe auf keinen Fall.

Viele Grüße Hoppel

[87insane]

Also das sonos eigene und unsichtbare mesh stört bei mir kein Stück. Dazu kommen bei mir noch andere auf 2.4ghz laufende Systeme.
Man kann viel meckern aber das muss man den Sonos lassen, die laufen super im WLAN und auch untereinander.

[Otto123]

Das will ich aufgrund zuvor genannter Gründe auf keinen Fall.

Naja, aber ich meine: dann bist Du ev. auch ein Hauptgrund für Deine Probleme

Sonos ist bei mir im Netzwerk (mit meinen Augen ) fast unsichtbar und funktioniert einfach. Das war ein Hauptgrund für meine Begeisterung von Anfang an: Einfach anschließen und geht. Andere habe sich einen Kopf gemacht, ich - weiß und kann - es nicht besser

Gruß Otto

[hoppel118]

Moin Jungs,

habe ich gemeckert? Nein, ich bin wirklich zufrieden, wie mein WLAN und meine Sonos-Umgebung funktionieren.

Einzig das Stereo-Paar im Schlafzimmer zickt ein wenig aufgrund der WLAN-Empfangsprobleme. Aber da muss ich mir entweder um eine Neupositionierung meiner APs Gedanken machen oder einen weiteren kaufen.

Mittlerweile sind übrigens beide Schlafzimmer Lautsprecher im FHEM Modul auf disappeared und kommen nicht mehr wieder.

Mit der Sonos App kann ich das Stereo Paar aber weiterhin ohne Probleme steuern.

Kann das am pingType ,,syn" liegen? Macht es evtl. Sinn den pingType auf ,,tcp" oder ,,udp" umzustellen? (Das werde ich nachher mal testen).

Ich hätte die Erwartungshaltung an das Modul, dass die Geräte irgendwann automatisch wieder in den Status appeared gehen. Mit der Sonos App sind die Geräte ja auch steuerbar. Warum passiert das bei mir nicht, unabhängig davon, dass sie nicht über Sonosnet laufen, sondern in meinem eigenen WLAN?

Gruß Hoppel

[hoppel118]

So, habe nochmal schnell folgendes getestet:

• "pingType udp" konfiguriert, 5 min gewartet - keine Änderung des Status im Sonos Modul
• "pingType tcp" konfiguriert, 5 min gewartet - keine Änderung des Status im Sonos Modul
• beide Lautsprecher Stromlos gemacht, Schlafzimmer Stereopaar war sofort in der Sonos App verschwunden
• nochmal einen Blick auf das FHEM Web Interface geworfen, Status ist gewechselt auf ,,appeared"

Es läuft also bei mir jetzt erstmal mit ,,pingType tcp". Ich werde das weiter beobachten. Bisher gab es sonst noch keine weiteren Probleme. Das Modul hat sich noch nicht vollständig ,,disabled".

Es bleibt natürlich trotzdem die Frage, warum die Schlafzimmer Lautsprecher im Status ,,disappeared" geblieben sind, obwohl sie in der Sonos App erreichbar waren.

Gruß Hoppel

[Reinerlein]

Hi Hoppel,

das "appearen" und "disappearen" sind zwei völlig verschiedene Wege:
- Der PingChecker (das was du per "pingType" konfigurierst) prüft zyklisch als vorhanden markierte Player auf Existenz im Netz. Schlägt das mehrfach fehl, wird der Player auf "disappeared" gestellt, es wird dem Sonos-System der Verlust dieses Player mitgeteilt (Sonos selbst bekommt den fehlenden Player sonst nicht mit, sondern erst, wenn du ihn steuern willst), und eine sofortige Neu-Erkennung wird angestartet (falls das Problem doch nur temporär war)
- Das Erkennen eines vorhandenen Players müssen die Player selber mitteilen. Das tun sie, wenn man sie einschaltet o.ä.
  - Diese Erkennung kannst mit "RescanNetwork" manuell im Modul anstossen. Damit wird eine Meldungsaufforderug ins lokale Netz per Broadcast (UPnP) gesendet, und die Player, die vorhanden sind, müssen sich melden.

Wenn also das Modul selbst nicht auf "disappeared" steht, dann haben sich fehlende Player bislang einfach nicht (wieder) gemeldet.
Bei deinem Pärchen kann also das Problem sein, dass ein Player einen Netzverlust erleidet, und bei Rückkehr der Verbindung keine Broadcast-Meldung ausgibt... Das genau schreibt UPnP aber vor, es könnte sich ja alles mögliche (wie IP-Adresse o.ä.) geändert haben...

Grüße
Reinerlein

P.S.: Zum pingType: Wenn man die Möglichkeit hat (weil fhem sowieso als root läuft, oder entsprechend passende Rechte hat), sollte man "icmp" verwenden (das ist der Standard-Ping-Befehl des Netzes). Dieses ist der sicherste und ressourcensparendste Weg... wegen der notwendigen Rechte ist das nur nicht der Standard...

[hoppel118]

Hallo @Reinlein

danke erstmal für die Erläuterung.

Nun ist es gerade passiert. Mein DOIF hat mich darüber informiert, dass mein Sonos-Modul im state "disabled" war. Also kurz geschaut, alles hat sich von selbst repariert und das Modul ist bereits wieder im Zustand "opened".

Wie vereinbart habe ich alles im verbose 5 mitgeloggt. Wie viel Minuten drumherum benötigst du, um die beiden Logs (FHEM Logfile und Subprozess Logfile) vernünftig auswerten zu können?

Fast 3GB Logfile kann ich schlecht irgendwo hochladen...

Gruß Hoppel

[hoppel118]

Hallo Reinerlein,

da die logfiles einfach zu riesig sind, kann ich sie anscheinend nirgends hochladen. Das Subprocess log ist sogar über 2GB groß. Da habe ich jetzt schon Probleme die Datei überhaupt geöffnet zu bekommen. Habe gerade verschiedene Editoren (bspw. PSPad, EditPad Lite) unter Windows ausprobiert. Die scheitern alle an der Größe.

Habe mir das Logfile nun per Putty und "cat" auf der Command Line anzeigen lassen und eine knappe halbe Stunde in der das Problem auftritt in eine txt-Datei extrahiert. Wenn hier jemand eine komfortablere Möglichkeit kennt, immer her damit, gern auch ein Command Line Tool.

Um 13:23 Uhr hat mich mein DOIF per yowsup darüber informiert, dass sich das Modul im state "disabled" befindet. Kann ich dir die Dateien per Email zukommen lassen? (Wenn ja, schicke mir deine Email-Adresse bitte per "Persönliche Nachricht" hier im Forum.)

Die beiden Logfiles haben nun eine Gesamtgröße von ca. 7,31MB. Immer noch zu groß für den kostenlosen Service von pastebin.com. Oder hat hier jemand eine Alternative, wo man größere Logdateien kostenlos hochladen kann?

EDIT: Ich habe mein Log jetzt bis auf weiteres erstmal wieder zurück auf verbose 1 gedreht. Dabei springt mir im Logfile direkt folgendes ins Auge:

Code Auswählen Erweitern

2020.07.27 15:49:16 1: SONOS1: Service-subscribing not possible due to missing TransportService
2020.07.27 15:49:16 1: SONOS1: Rendering-Service-subscribing NOT successful: Subscription request failed with error: 503 Service Unavailable at ./FHEM/00_SONOS.pm line 6198 thread 1.

Ich habe nun auch direkt ein FHEM Update durchgeführt. Diese Meldung gab es aber vorher auch schon. Da am Ende "Service Unavailable at ./FHEM/00_SONOS.pm line 6198 thread 1" steht, bin ich mir unsicher, ob das eigentlich so sein soll.

Danke und Gruß Hoppel

[Reinerlein]

Hi Hoppel,

die letzten Zeilen im Log kann man sich mittels "cat" und "tail" auf der Kommandozeile ausgeben lassen:

Code Auswählen Erweitern

cat fhem-2020-07.log | tail -n 200Gibt z.B. die letzten 200 Zeilen aus.

Code Auswählen Erweitern

cat fhem-2020-07.log | tail -n 200 | head -n 100 Gibt ab 200 Zeilen vor Ende der Datei aber nur 100 Zeilen davon aus.

Code Auswählen Erweitern

cat fhem-2020-07.log | tail -n 200 | head -n 100 > newlogfile.logspeichert das ganze in eine Datei.

Hochladen kann man hier im Forum, aber ich weiß nicht bis zu welcher Größe (denke aber, dass 7MB gehen sollten), meine Mailadresse steht im Modulheader.
Wenn hier im Forum, dann nachdem ich sie habe, einfach wieder löschen...

Interessant ist, ob es eine Zeile mit den Worten "Bei der Player-IsAlive-Prüfung ist ein Fehler aufgetreten:" beginnend gibt.
Das dahinter sollte hoffentlich eine Fehlermeldung aus Ping sein.

Natürlich könnte es auch eine andere Fehlerursache sein, und nicht an dem Ping-Ding gescheitert sein...
Dann bräuchte ich ein paar Minuten vor der disabled-Zeit, und ein paar Zeilen danach.

Grüße
Reinerlein

[hoppel118]

Danke für die Erläuterung!

Kann man mit tail auch einen bestimmten Zeitraum eines Logfiles von einer Datei in eine andere Datei schreiben?

Die beiden Log-Dateien findest du im Anhang. Gib Bescheid, wenn du sie hast. Dann entferne ich sie hier wieder.

Gruß Hoppel

[Reinerlein]

Hi Hoppel,

tail und head haben erstmal keinerlei Wissen über den Inhalt einer Datei. Die beziehen sich nur auf den Zeilenumbruch.

Du könntest vielleicht was mit grep machen, wenn es zeitlich gerade passt:

Code Auswählen Erweitern

cat fhem-2020-07.log | grep "2020.07.20 22:01:" aber auch hier gibt es keine Interpretation des Zeitstempels.
Das geht sicherlich auch, ist aber vermutlich dem Problem nicht angemessen Stichwort wäre dabei "awk", mit dem man kleine Programme in einem Kommandozeilenparameter mitgibt.

Ich habe die beiden Dateien heruntergeladen...

Grüße
Reinerlein

[hoppel118]

Perfekt!

Du könntest vielleicht was mit grep machen, wenn es zeitlich gerade passt:

Code Auswählen Erweitern

cat fhem-2020-07.log | grep "2020.07.20 22:01:"

Perfekt, damit kann ich mir einzelne Stunden eines bestimmten Tages aus dem Log ziehen!

Super, danke dir!

Die beiden Logfiles habe ich nun wieder entfernt!

Hoffentlich findest du darin etwas, dass uns weiter bringt. Bei solchen Tests kann man das FHEM Logfile für andere Dinge echt nicht mehr gebrauchen...

Gruß Hoppel

[Reinerlein]

Hallo Hoppel,

also, ich habe da ein Problem gefunden (aber nicht den von mir erhofften ):
Wenn ein Player als abwesend markiert wurde (in deinem Fall war der TCP-Ping um 13:17:41 endgültig not alive), und dann noch ein Event dafür reinkommt, dann wird die Erkennung neu angestartet, da offensichtlich etwas unstimmig ist.
Das allerdings hat anscheinend nicht korrekt gearbeitet. Das habe ich schon mal umgebaut.

Aber mich wundert, dass er überhaupt versucht hat (bzw. es auch geschafft hat), den Prozess neuzustarten. Ich habe kurzzeitig eigentlich eine wirklich sehr lange Wartezeit eingestellt (400000 * Interval), damit der SubProzess nicht neugestartet wird, während Ping nicht wiederkommt... Ich wollte ja die Fehlermeldung des länger brauchenden Ping-Befehls.
Er hätte also niemals den Sub Prozess neu anstarten dürfen (zumindest erst sehr viel später)...

Ich würde aber immer noch gerne das Problem im Ping finden...
Aktuell scheinst aber nur du einen Neustart erhalten zu haben. Bei mir passiert es auf meiner Testumgebung oder Produktivumgebung auch überhaupt nicht... sehr ärgerlich...

Ich würde dir jetzt erstmal ein Löschen der LogFiles und einen Neustart von Fhem empfehlen... damit die Dateien erstmal wieder kleiner werden...

Grüße
Reinerlein

[hoppel118]

Ich würde aber immer noch gerne das Problem im Ping finden...
Aktuell scheinst aber nur du einen Neustart erhalten zu haben. Bei mir passiert es auf meiner Testumgebung oder Produktivumgebung auch überhaupt nicht... sehr ärgerlich...

OK, was schlägst du vor? Soll ich den FHEM Server weiter mit verbose 5 laufen lassen? Soll noch irgendwas spezielles für das Logging eingebaut werden?

Ich würde dir jetzt erstmal ein Löschen der LogFiles und einen Neustart von Fhem empfehlen... damit die Dateien erstmal wieder kleiner werden...

Das hatte ich natürlich direkt nach der Aktion gemacht.

Gruß Hoppel