Sonos: DISAPPEARED durch PlayURI+Speak

r_e_a_d_y · 02 Januar 2019, 23:27:49

Hallo liebe Community, hallo Reinerlein,

Längere Zeit habe ich mein (noch bestehendes) Sonos-Problem liegen lassen. Nun möchte ich es doch noch mal aufgreifen:

Meine Sonos-Player gehen immer mal wieder sporadisch in den State disappeared. Leider steht es in keinem Zusammenhang mit irgendeiner Aktion. Das Sonos-Device hängt in diesem Fall auch im State "disappeared".

Workaround: Erst wenn ich für das Sonos Device das Attribute "disable" = 1 setze und gleich wieder lösche, steht der Status von Sonos erst in "disconnected" und kurze Zeit später wieder auf "opened". Kurz darauf sind auch die Player wieder "appeared". Ich habe mich daher eine Zeit lang damit beholfen, dass ich automatisch das Attribut "disable" = 1 setze+lösche im Falle von Player=disappeared, damit sich das System selbst korrigiert. Das ist jedoch kein Zustand, da die Sonos-Umgebung meist zur falschen Zeit aussteigt (und der Regenerierungsprozess dauert manchmal mehrere Minuten).

Logs: Im Zusammenhang damit steht meist in den Logs:

Code Auswählen

2019.01.02 20:49:31 2: SONOS0: LastProcessAnswer way too old (Lastanswer: 1546458421 ~ 2019-01-02 20:47:01)... try to restart the process and connection...
2019.01.02 20:49:32 3: SONOS0: Disconnecting client and shutdown server...
2019.01.02 20:49:32 3: SONOS0: Trying to kill Sonos_Thread...
2019.01.02 20:49:32 3: SONOS0: Trying to kill LongJobs_Thread...
2019.01.02 20:49:32 3: SONOS0: Trying to kill IsAlive_Thread...
2019.01.02 20:49:32 3: SONOS0: Trying to kill PlayerRestore_Thread...
2019.01.02 20:49:32 0: SONOS0: Das Lauschen auf der Schnittstelle wurde beendet. Prozess endet nun auch...
2019.01.02 20:50:04 1: SONOS0: Kein UPnP-Server gefunden... Starte selber einen und warte 1 Sekunde(n) darauf...
2019.01.02 20:50:06 1: SONOS0: ./FHEM/00_SONOS.pm is started by fhem...
2019.01.02 20:50:06 0: SONOS0: Can't bind Port 4711: Bind failed: Address already in use at ./FHEM/00_SONOS.pm line 9870.
2019.01.02 20:50:36 1: SONOS0: ./FHEM/00_SONOS.pm is listening to Port 4711
2019.01.02 20:51:05 3: SONOS0: Connection accepted from raspberrypi.fritz.box:37982

UPnP-Server: Ich hatte früher schon einmal den Tipp von Reinerlein bekommen, dass sich bei mir Windows-Rechner im Netzwerk als UPnP-Server zeigten, was man über ignoredIPs umgehen kann.

Code Auswählen

attr Sonos ignoredIPs 192.168.XXX.XXX,192.168..XXX.XXX,192.168..XXX.XXX

Leider war das noch nicht die finale Lösung.

Eventuelle Zusammenhänge: Ich verwende immer wieder PlayURI sowie Text to Speak.

Code Auswählen

set Sonos_Wohnzimmer PlayURI http://absolut.hoerradar.de/absolutradio-relax-mp3
set Sonos_Wohnzimmer Speak 20 de ausgegebener Text

Manchmal habe ich das Gefühl, dass ich das System mit dem wechselseitigen und zu schnellen Aufruf dieser Befehle das System (z.B. Senderwechsel über Taster) überfordere.

Ich bin leider mit meinem Latain am Ende. Vielleicht habt ihr noch eine Idee?

Viele Grüße, r_e_a_d_y

r_e_a_d_y · 03 Januar 2019, 02:25:42

Hi nochmal,

ich glaube, ich komme dem Problem so langsam auf die Schliche ...

Wie es aussieht, haben die Sonos-Player ein Problem damit, wenn man die beiden Befehle PlayURI und v.a. Speak kurz hintereinander mehrmals wechselseitig absetzt. Gerade wenn der eingegebene TTS-Text noch nicht vollständig beendet ist und man gleich noch über PlayURI einen Musikstream nachschiebt, hat der Player Schwierigkeiten damit.

Der Player scheint sich dann zu verschlucken und reagiert dann einfach nicht mehr auf die Fhem-Befehle. Erst wenn man den Play/Pause-Knopf an der Box selbst mehrmals drückt, merkt man, wie die Box nach und nach die abgesetzten Befehle ausspuckt.

Das Ganze habe ich an einer Sonos Play:1 sowie Sonos One getestet (immer das gleiche Muster).

Testen könnt ihr es, wenn ihr z.B. die folgenden Befehle auf einmal bzw. hintereinander absetzt:

Code Auswählen

set Sonos_Wohnzimmer PlayURI http://absolut.hoerradar.de/absolutradio-relax-mp3
set Sonos_Wohnzimmer Speak 10 de Gleich verschluckt sich der Player.
set Sonos_Wohnzimmer PlayURI http://absolut.hoerradar.de/absolutradio-relax-mp3
set Sonos_Wohnzimmer Speak 10 de Gleich verschluckt sich der Player.

Gleich darauf ist der Player auch nicht mehr über das Fhem-UI ansprechbar (ich teste es immer, indem ich die Lautstärke über Fhem versuche zu verändern). Zwei bis drei Minuten später kommt bei mir auch der "disappeared"-Fehler (alle Player verabschieden sich und dann auch das Sonos-Device auf "disabled").

Logs:

Code Auswählen

2019.01.03 02:19:59 3: SONOS1: Hole die Durchsage aus dem Cache...
2019.01.03 02:19:59 3: SONOS1: Temporary playing of "\\192.168.XXX.XXX\SonosSpeak/RINCON_7828CAB5F95201400_MR_Speak_f6b3305dce286bebfbd09a948f74f9e12b0ba6a4.mp3" must wait, because another playing is in work...
2019.01.03 02:20:00 3: SONOS4: Restorethread has found a job. Waiting for stop playing...
2019.01.03 02:22:29 2: SONOS0: LastProcessAnswer way too old (Lastanswer: 1546478399 ~ 2019-01-03 02:19:59)... try to restart the process and connection...
2019.01.03 02:22:31 3: SONOS0: Disconnecting client and shutdown server...
2019.01.03 02:22:31 3: SONOS0: Trying to kill Sonos_Thread...
2019.01.03 02:22:31 3: SONOS0: Trying to kill LongJobs_Thread...
2019.01.03 02:22:31 3: SONOS0: Trying to kill IsAlive_Thread...
2019.01.03 02:22:31 3: SONOS0: Trying to kill PlayerRestore_Thread...
2019.01.03 02:22:31 0: SONOS0: Das Lauschen auf der Schnittstelle wurde beendet. Prozess endet nun auch...

Kann man dies vielleicht über das Modul irgendwie abfangen?

Reinerlein · 04 Januar 2019, 02:17:46

Hi r_e_a_d_y,

wenn deine Vermutung zutrifft, dann habe ich das mittlerweile endlich mal in Arbeit.
Ich baue gerade eine saubere Warteschlange für die Speak-Befehle ein, die auch ordentlich mit mehreren Playern umgehen kann (das Problem dürfte auch auftreten, wenn du diese Speak und PlayURI Anweisungen an verschiedene Player sendest, oder auch nur mehrere Speak-Anweisungen direkt hintereinander).
Momentan ist das einfach nicht gut gelöst, und es kann zu einer Blockade des Haupt-Sub-Thread kommen. In Folge dazu kommt irgendwann keine Reaktion mehr nach außen, wodurch dann irgendwann auch alles auf "disappeared" geht...

Leider ist das so überhaupt nicht trivial, sodass ich da noch etwas rumbasteln muss

Gib mir noch etwas Zeit. Ich konnte immerhin schon über die Feiertage anfangen...

Grüße
Reinerlein

r_e_a_d_y · 04 Januar 2019, 11:03:12

Hi Reinerlein,

danke für deine schnelle Antwort!!

Ja das ist richtig ... auch das unterschiedliche Ansprechen verschiedener Speaker, aber auch "mehrere Speak-Anweisungen direkt hintereinander" führen wohl zum Overload des Systems.
Das glaube ich dir gern! Hier eine perfekte Logik zu finden ist sicher nicht einfach.

Es freut mich zu hören, dass ich mit meiner Vermutung nicht ganz auf dem Holzweg war und das Problem zumindest ansatzweise erkannt ist.
Nimmt dir die Zeit, die du brauchst. Falls du einen Lösungsansatz hast und ich mal irgendwann testen soll, lass es mich hier im Thread einfach wissen.

Grüße, r_e_a_d_y

deppennase · 28 Mai 2019, 09:21:48

Hi Reinerlein,

Gibt es hier schon Neuigkeiten? Mein Sonos-Prozess crasht ca. alle zwei Tage, in der Regel ca. 1-2h nach der Nutzung von Sonos Speak.

Ich wollte dem Problem auf die Schliche kommen und habe die letzten zwei Tage verbose für Sonos auf 5 gestellt. Mein Sonos ist jetzt seitdem auch schon wieder gecrasht.

EDIT: hier ist glaube ich die Fehlermeldung zum Absturz, davor haben die Player reagiert:

Zitat2019.05.27 16:35:47 4: SONOS3: 192.168.5.107 is alive
2019.05.27 16:36:30 5: SW: DoWork:undef:refreshProcessAnswer:

2019.05.27 16:36:30 5: SONOS0: Received: 'DoWork:undef:refreshProcessAnswer:'
2019.05.27 16:36:30 2: SONOS0: LastProcessAnswer way too old (Lastanswer: 1558967190 ~ 2019-05-27 16:26:30)... try to restart the process and connection...
2019.05.27 16:36:30 4: SONOS0: ReadingsBeginUpdate from Module for "Sonos"
2019.05.27 16:36:30 4: SONOS0: ReadingsEndUpdate from Module for "Sonos"
2019.05.27 16:36:31 5: SW: shutdown

2019.05.27 16:36:31 5: SONOS0: Received: 'shutdown'
2019.05.27 16:36:31 3: SONOS0: Disconnecting client and shutdown server...
2019.05.27 16:36:31 3: SONOS0: Trying to kill Sonos_Thread...
2019.05.27 16:36:31 3: SONOS0: Trying to kill LongJobs_Thread...
2019.05.27 16:36:31 3: SONOS0: Trying to kill IsAlive_Thread...
2019.05.27 16:36:31 3: SONOS0: Trying to kill PlayerRestore_Thread...
2019.05.27 16:36:31 0: SONOS0: Das Lauschen auf der Schnittstelle wurde beendet. Prozess endet nun auch...

Eine andere Lösung wäre es solange das Problem nicht gelöst ist beim Crash des Sonos-Systems FHEM automatisch neu zu starten, hat das schonmal jemand gemacht?

Danke!

r_e_a_d_y · 28 Mai 2019, 10:48:18

Hi deppennase,

wie oben beschrieben habe bzw. hatte ich das gleiche Problem.
Nach einigen Analysen von damals tritt das Problem immer dann auf, wenn SonosSpeak die normale Stream-Wiedergabe (bei mir z.B. Internetradio) oder gar eine noch laufende SonosSpeak-Wiedergabe unterbricht (letzteres ist glaube problematischer).

Ich habe mir daher nach einem recht einfachen Prinzip einen Workaround gebaut: Warteschlange für SonosSpeak
Somit wird erst ein SonosSpeak-Befehl abgearbeitet, wenn der vorherige wirklich vollständig abgearbeitet + ausgegeben wurde.

- Über die 99_myUtils.pm habe ich mir einfach ein paar Funktionen gebaut, die zum Einen die Queue (was lediglich ein zusätzliches Reading im Player ist) befüllt oder die Queue wieder nacheinander abarbeitet.
- Über ein Notify (nämlich wenn sich der Status des Players verändert), trigger ich einfach die Queue-Abarbeitung
- in der Queue-Abarbeitung achte ich darauf, dass
> der Player verfürbar ist (presence = appeared)
> gerade keine Sprachdurchsage läuft

Ich hoffe, das hilft erstmal etwas weiter.

@Reinerlein: Vielleicht macht es Sinn, ja so ein Warteschlangen-Prinzip auch in dem Modul einzubauen.

Grüße, r_e_a_d_y

deppennase · 28 Mai 2019, 13:51:26

Hallo r_e_a_d_y,

Vielen Dank für die schnelle Antwort!

Könntest Du Deine Funktionen für die Queue-Abarbeitung posten?
Dann müsste ich das Rad nicht neuerfinden.

Toll endlich zu wissen, warum mein Sonos ständig crasht. Die Freundin ist seit geraumer Zeit von der Heimautomatisierung wenig begeistert wenn der Lieblingssender morgens jeden 2. Tag nicht spielt...

Kurzer Exkurs: Ich erkenne wann es an der Haus- bzw. Wohnungstür klingelt über entfremdete Fensterkontakte. Wenn es klingelt sagt Sonos "Es klingelt oben" oder eben "Es klingelt unten".
Da das irgendwann passiert haut das natürlich manchmal in die bestehende Wiedergabe rein. Darüber hinaus kommt es zu mehrfachem Triggern des Befehls wenn mehrfach geklingelt wird und der Sprachbefehl noch nicht abgeschlossen ist.

Vielen Dank!!!

DanielGab · 27 Juni 2019, 21:32:58

Hi FHEM'ler,
bei mir tritt das disappeared-Problem auch regelmäßig auf. Ich dachte es liegt an mir, dass ich irgendein Pearl falsch programmiert habe. Allerdings fällt mir nach diesem Tread auf, dass es sich genauso mit meinen Playern verhält wie beim TE.

Ein ähnliches Problem gibt es auch, wenn mein Sonos Play 5 (2.Gen) auf Alarm getriggert wird. Dann kann ich keine Befehle senden, ohne dass es disappeared wird. Wenn ich den Play 1 auf die gleiche Weise triggere, stürzt Sonos nicht ab. Im Zusammenhang mit allem geht es allerdings um entfernen von Playern aus der Gruppe oder playURI.. Auch kann ich beim Play 5 AlarmRunning 1 nicht "set Stop" und dann "set Play" setzen, dann spielt der Player das Türbuch bin letzter Nacht weiter und nicht den Radiosender oder die Spotifyplaylist des Weckers. Aber ich vermute, das ist sonospezifisch.

Gibt es vielleicht einen anderen workaround, der Erfolg verspricht bzw. gibt's vom Modul-Entwickler Neuigkeiten?

Liebe Grüße, Daniel

miner · 07 August 2019, 12:35:35

Hi an die FHEM-Gemeinde,

ich moechte hier nur mal kurz meine Erfahrung (und meine Loesung) des Problems teilen:

Ich habe 10 Play:1, 1 Bridge, 1ZP (iss wohl heute der Boost?!), 1 Playbar, 1 Subwoofer - alles im kabelgebundenen Modus - also Bridge mit SONOS-Net

Ich nutze FHEM (laeuft auf 'nem offline WinXP Netbook) ausschliesslich fuer die SONOS-Integration in mein selbstgestricktes Smarthome.
Dabei werden meine SONOS kreuz und quer mit Ansagen beballert - egal was da auch gerade drauf laeuft.
Ich habe diverse Kalender (Ansagen fuer Muell-, Privat- und Fussballspieltermine etc) darueber laufen.
Ich bekomme darueber die Ladezustaende aller im Haus benutzten Smartphones angesagt bzw die Ladeaufforderung.
Wenn jemand anruft, wird mir der Anrufer genannt, Wetteransagen, ToDos, Status-Infos von Sensoren usw. usw.
Meine Frau sagt auch schon - Freddy (ja so heisst mein SONOS-Hausgeist) sabbelt schon den ganzen Tag.

Ich habe/hatte nie "disappeared"-Ausfaelle - egal welche wirren set-Kommandoketten ich an das Modul geschickt habe, bis - ja bis ich
ich mir vor einer Woche 'ne WebCam zugelegt habe (keine FHEM-Anbindung!!) - und vorbei war's mit der Herrlichkeit. Ausfaelle am Fliessband.

Fuer mich stand fest - ein derart stabiles Modul kann eigentlich nicht Ursache des Problems sein und habe den Fehler in meinem Netz vermutet.

Also keine Logs durchforstet sondern meine Bridge rausgeschmissen, Netzwerkgeraete umgesteckt, um den ZP (fungiert nun als Bridge) aus einem Switch direkt an die Fritzbox klemmen zu koennen. Jetzt haengen alle SONOS ueber den ZP am LAN1 der Fritzbox (vorher haben sich einige SONOS an der Bridge angemeldet, andere an den am Switch haengenden ZP - und das auch noch im staendigen Wechsel)

Und was soll ich sagen: Das Modul laeuft wieder wie eine 1 - aktuell keine Ausfaelle seit 2 Tagen - davor beinahe stuendlich. Und die Cam laeuft 24/7

Was ich damit sagen will - manchmal haelt man sich viel zu viel mit der Symptomatik auf statt vielleicht erstmal die Basics aufzuraeumen.

Gruesse
Andreas