SONOS Player Disappeared ... immer und immer wieder

kjmEjfu · 05 Juni 2018, 09:02:02

Bei mir hat sich das Problem gelöst, nachdem ich den Raspberry (auf dem FHEM läuft) aus dem WLAN genommen, direkt ans LAN gehangen und(!) auf dem PI das WLAN hart unterbunden habe. Die Sonos Boxen laufen natürlich weiterhin normal im WLAN.
Seitdem hatte ich kein disable o.ä. mehr.
Den Pingtype habe ich auf UDP gestellt.

blofield · 05 Juni 2018, 09:13:33

Moin,

Bei mir tritt das Problem auf, wenn des RPi ordentlich Last hat z.B. beim Bereinigen der DbLog.
Bei mir hat geholfen den Timeout ordentlich hoch zu setzen.

blofield

Gesendet von meinem ONEPLUS A5000 mit Tapatalk

DS_Starter · 05 Juni 2018, 09:47:21

Bei mir hängt alles am Draht, kein WLAN in diesem Umfeld und der NUC hat genug Power auch bei größerer Belastung.
Habe mich jetzt noch nicht so intensiv mit den umfangreichen Einstellmöglichkeiten des Moduls beschäftigt. Auf jeden Fall geht der Subprocess, das Sonos-Device, in den disabled-Status. Der Player geht dann nur folgerichtig in disappeard. Nachdem Sonos-Device wieder läuft klappts auch wieder mit dem Player.
Das mit dem Timeout und Pngtyp UDP ist eine gute Idee. Muss ich heutexAbend mal schauen.

Danke und Grüße,
Heiko

DS_Starter · 12 Juni 2018, 08:35:29

Die Umstellung des Pingtyps auf UDP hat bei mir nichts gebracht. Eine Einstellung für einen Timeout habe ich für Sonos.pm nicht gefunden, ist auch nicht beschrieben.
Aufgefallen ist mir, dass das Sonos-Device mit der Eventfolge LastProcessRestart -> LastProcessRestartCount in den disabled Modus geht:

2018-06-12   07:59:38   Notice   fhem.myds.me   syslog   Prod_event   : global MODIFIED Sonos
2018-06-11   18:24:29   Notice   fhem.myds.me   syslog   Prod_event   : Sonos LastProcessRestartCount: 11
2018-06-11   18:24:29   Notice   fhem.myds.me   syslog   Prod_event   : Sonos LastProcessRestart: 2018-06-11 18:24:29
2018-06-11   18:23:49   Notice   fhem.myds.me   syslog   Prod_event   : Sonos LastProcessAnswer: 1528734229.37623

Gestern 18:24:29 passiert. Seitdem gab es (natürlich) keine Events mehr von Sonos und erst heute morgen nach dem Workaround mit disable 1 -> 0 bzw. Restart klappt es (erstmal) wieder -> "global MODIFIED Sonos" .
Vielleicht ist es ein Hinweis für dich Reinerlein. Es gibt zwar die Möglichkeiten sich einen Workaround zu basteln aber schöner wäre es schon die Ursache für dieses Problem zu finden und abzustellen.

blofield · 12 Juni 2018, 08:48:56

Moin,

Mit Timeout meinte ich die "Waittime" im define.
localhost:4711 XX

Die (XX) hatte ich gem. Wiki bei mir auf 30. Eine Erhöhung auf 120 hat bei mir die Problematik beseitigt, ohne das ich eine Einschränkung bemerkt hätte.

Viel Erfolg
blofield

Gesendet von meinem ONEPLUS A5000 mit Tapatalk

DS_Starter · 12 Juni 2018, 08:52:45

Zitat
Mit Timeout meinte ich die "Waittime" im define.
localhost:4711 XX

Achso, ja damit hatte ich auch schon ohne Erfolg experimentiert, allerdings hatte ich noch nicht so hohe Werte eingestellt.
Werde ich versuchen, danke für den Hinweis.

Grüße,
Heiko

Reinerlein · 12 Juni 2018, 20:59:42

Hi Heiko,

hast du zufällig die Speak-Funktionalität in Benutzung?
Dort gibt es definitiv ein Problem, welches ich durch einen internen Umbau dieser temporären Wiedergabe beheben muss. Das ist einfach nicht gut umgesetzt und blockiert irgendwann die Kommunikationsmöglichkeiten des Hauptthreads

Ich hoffe, dass ich demnächst mal dazu komme, mir da ein Kontept zu überlegen, und es natürlich auch umzusetzen

Wenn es andere Gründe für diese Aussetzer gibt, so müssen wir die noch herausfinden...

Grüße
Reiner

DS_Starter · 12 Juni 2018, 22:22:44

Hi Reiner,

Zitathast du zufällig die Speak-Funktionalität in Benutzung?

Nein. Ich bin bei der Nutzung von Sonos (und des Moduls) noch ganz am Anfang.
Bislang benutze ich einfach nur das Stoppen und die weitere Wiedergabe eines Radiosenders .... also das primitivste was es gibt.
Zur Zeit hält mich eben diese doch recht störende Unzuverlässigkeit davon ab weitere Integrationen vorzunehmen und das Thema voranzutreiben.
Eigentlich hatte ich vor meine ganze Audioanlage wegen der FHEM-Unterstützung auf Sonos umzustellen, aber diese doch nicht unerhebliche Investition kommt erst in Frage wenn ich mir sicher bin. Mein erster Play1 ist quasi der "Versuchsballon".
Wenn ich etwas unterstützen kann, will ich das gerne tun ... aber mir fehlen da etwas die Grundlagen in der Audio-Steueungs-Welt.

Danke für deine Arbeit !

LG,
Heiko

Reinerlein · 13 Juni 2018, 19:16:06

Hallo Heiko,

es wäre noch das Log (möglichst auf 5 beim Sonos-Device) interessant...

Aber wie ist dein Sonos-Device definiert. Nach deinen Ausgaben gab es um 18:23:49 noch eine Antwort, und nur 40 Sekunden später wurde schon neugestartet.

Normalerweise passiert der Neustart erst, wenn die letzte Antwort 4*Intervall (also die erste Zahl bei der Definition, wenn nicht angegeben, dann 30) Sekunden her ist.
Das würde bei dir bedeuten, dass dort eine 10 oder so steht... das wäre schon sehr klein...

Hast du irgendwelche event-Attribute definiert (also sowas wie ein event-min-intervall oder so)?

Sonst hilft uns jetzt nur ein hohes Loglevel weiter. Für den SubProzess kannst du ein eigenes Logfile angeben, dann landet das schon mal nicht im Fhem-Log... der Fhem-Device-Teil landet natürlich im Fhem-Log...

Grüße
Reiner

DS_Starter · 15 Juni 2018, 16:34:29

Hallo Reiner,

sorry dass ich mich so spät melde. Ich war mit eigenen Entwicklungen beschäftigt und konnte deswegen auch mein Prod nicht ungestört durchlaufen lassen.

Zitat
Normalerweise passiert der Neustart erst, wenn die letzte Antwort 4*Intervall (also die erste Zahl bei der Definition, wenn nicht angegeben, dann 30) Sekunden her ist.
Das würde bei dir bedeuten, dass dort eine 10 oder so steht... das wäre schon sehr klein...

Ja, ich hatte 10 drin stehen. Laut Hilfe ist das aber auch der default zur Zeit wenn man es nicht definiert. Vllt. stimmt die Hilfe auch nicht mehr. Jedenfalls hatte ich den Wert inzwischen auf 120 geändert

Code Auswählen

defmod Sonos SONOS localhost:4711 120 1 5
aber hat auch nicht gebracht.

Zitat
Hast du irgendwelche event-Attribute definiert (also sowas wie ein event-min-intervall oder so)?

Nein, nichts dergleichen gesetzt. Ich habe jetzt ein separates Logfile definiert und den Loglevel für den Subprozess auf 5 gedreht.
Die Attribute sehen nun so aus:

Code Auswählen


attr Sonos SubProcessLogfileName sonoslog
attr Sonos disable 0
attr Sonos ignoredIPs 192.168.2.30,192.168.2.14,169.254.100.156,192.168.2.15
attr Sonos pingType tcp
attr Sonos room Sonos
attr Sonos verbose 5
attr Sonos widgetOverride ignoredIPs:textField-long

Wenn das Device wieder auf disabled geht melde ich mich.

LG,
Heiko

marwal · 20 Juni 2018, 12:32:17

Hallo Zusammen,

bezugnehmend auf den Post #76 https://forum.fhem.de/index.php/topic,80388.msg791400.html#msg791400
habe ich nun endlich das Problem gefunden (16 Tage keinen Ausfall der Sonos) und kann es auch rekonstruieren.
Sobald das Modul [82_LGTV_WebOS.pm] aktiv ist und der Fernseher ausgeschalten wird, verabscheiden sich die Sonos ca 15min später auch.

15min nachdem der Fernseher aus ist:

Code Auswählen

2018.06.20 11:26:48 2: SONOS0: LastProcessAnswer way too old (Lastanswer: 1529486087 ~ 2018-06-20 11:14:47)... try to restart the process and connection...
2018.06.20 11:26:48 4: SONOS0: ReadingsBeginUpdate from Module for "Sonos"
2018.06.20 11:26:48 4: SONOS0: ReadingsEndUpdate from Module for "Sonos"
2018.06.20 11:26:48 5: SONOS0: Received from UPnP-Server: 'rePing:undef::'
2018.06.20 11:26:49 5: SW: shutdown

Ich vermute hier mal den UPnP-Server der Sonos, welcher den Fernseher nicht mehr erreichen kann. Aber warum passiert das nur, wenn das Modul aktiv ist? Ein ignoredIPs auf den Fernseher brachte auch keinen Erfolg. Der TV hängt per LAN im Netz und ließ sich auch ohne Probleme steuern. Lösche ich das Modul, funktioniert funktioniert das Sonos-System einwandfrei. Evtl hat ja der ein oder andere das gleiche Problem / bzw. kann es so vorerst beheben.

Liebe Grüße

Jamo · 21 Juni 2018, 23:45:51

Hallo Rainer,
ich hänge mich hier nochmal rein, ich glaube es gibt immer noch ein Problem mit der Bridge, die anscheinend ab und zu immer noch als SONOSPLAYER erkannt wird, siehe auch https://forum.fhem.de/index.php/topic,87278.msg799453.html#msg799453 letzter Beitrag.

Ich bekomme immer wieder den Fehler:

Code Auswählen

2018.06.20 00:15:51 0: SONOS0: The Method 'SONOS_getSonosPlayerByUDN' cannot find the FHEM-Device according to '_MR'. This should not happen!
2018.06.20 00:15:51 3: SonosRG: <{getGroupsRG()}@ZoneGroupState>: Can't use an undefined value as a HASH reference at ./FHEM/00_SONOS.pm line 2111.

Hier auch nochmal mein Reading "ZoneGroupState"

Code Auswählen

<ZoneGroups><ZoneGroup Coordinator="RINCON_5CAAFD22856E01400" ID="RINCON_5CAAFD22856E01400:186"><ZoneGroupMember UUID="RINCON_B8E937B0815001400" Location="http://172.21.0.13:1400/xml/device_description.xml" ZoneName="Bad" Icon="x-rincon-roomicon:living" Configuration="1" SoftwareVersion="42.2-51240" MinCompatibleVersion="41.0-00000" LegacyCompatibleVersion="36.0-00000" BootSeq="3176" TVConfigurationError="0" WirelessMode="0" WirelessLeafOnly="0" HasConfiguredSSID="0" ChannelFreq="2462" BehindWifiExtender="0" WifiEnabled="1" Orientation="0" RoomCalibrationState="1" SecureRegState="2" VoiceState="0"/><ZoneGroupMember UUID="RINCON_949F3E0498E401400" Location="http://172.21.0.43:1400/xml/device_description.xml" ZoneName="Flur" Icon="x-rincon-roomicon:tvroom" Configuration="1" SoftwareVersion="42.2-51240" MinCompatibleVersion="41.0-00000" LegacyCompatibleVersion="36.0-00000" BootSeq="1834" TVConfigurationError="0" WirelessMode="0" WirelessLeafOnly="0" HasConfiguredSSID="0" ChannelFreq="2462" BehindWifiExtender="0" WifiEnabled="1" Orientation="0" RoomCalibrationState="1" SecureRegState="2" VoiceState="0"/><ZoneGroupMember UUID="RINCON_B8E9378ED7EC01400" Location="http://172.21.0.11:1400/xml/device_description.xml" ZoneName="Kueche" Icon="x-rincon-roomicon:living" Configuration="1" SoftwareVersion="42.2-51240" MinCompatibleVersion="41.0-00000" LegacyCompatibleVersion="36.0-00000" ChannelMapSet="RINCON_B8E9378ED7EC01400:LF,LF;RINCON_B8E9378B0AA601400:RF,RF" BootSeq="2282" TVConfigurationError="0" WirelessMode="0" WirelessLeafOnly="0" HasConfiguredSSID="0" ChannelFreq="2462" BehindWifiExtender="0" WifiEnabled="1" Orientation="0" RoomCalibrationState="1" SecureRegState="2" VoiceState="0"/><ZoneGroupMember UUID="RINCON_B8E9378B0AA601400" Location="http://172.21.0.12:1400/xml/device_description.xml" ZoneName="Kueche" Icon="x-rincon-roomicon:living" Configuration="1" Invisible="1" SoftwareVersion="42.2-51240" MinCompatibleVersion="41.0-00000" LegacyCompatibleVersion="36.0-00000" ChannelMapSet="RINCON_B8E9378ED7EC01400:LF,LF;RINCON_B8E9378B0AA601400:RF,RF" BootSeq="1893" TVConfigurationError="0" WirelessMode="0" WirelessLeafOnly="0" HasConfiguredSSID="0" ChannelFreq="2462" BehindWifiExtender="0" WifiEnabled="1" Orientation="0" RoomCalibrationState="5" SecureRegState="2" VoiceState="0"/><ZoneGroupMember UUID="RINCON_5CAAFD228CD401400" Location="http://172.21.0.42:1400/xml/device_description.xml" ZoneName="Schlaf" Icon="x-rincon-roomicon:masterbedroom" Configuration="1" Invisible="1" SoftwareVersion="42.2-51240" MinCompatibleVersion="41.0-00000" LegacyCompatibleVersion="36.0-00000" ChannelMapSet="RINCON_5CAAFD22856E01400:LF,LF;RINCON_5CAAFD228CD401400:RF,RF" BootSeq="3159" TVConfigurationError="0" WirelessMode="0" WirelessLeafOnly="0" HasConfiguredSSID="0" ChannelFreq="2462" BehindWifiExtender="0" WifiEnabled="1" Orientation="0" RoomCalibrationState="5" SecureRegState="2" VoiceState="0"/><ZoneGroupMember UUID="RINCON_5CAAFD22856E01400" Location="http://172.21.0.41:1400/xml/device_description.xml" ZoneName="Schlaf" Icon="x-rincon-roomicon:masterbedroom" Configuration="1" SoftwareVersion="42.2-51240" MinCompatibleVersion="41.0-00000" LegacyCompatibleVersion="36.0-00000" ChannelMapSet="RINCON_5CAAFD22856E01400:LF,LF;RINCON_5CAAFD228CD401400:RF,RF" BootSeq="3143" TVConfigurationError="0" WirelessMode="0" WirelessLeafOnly="0" HasConfiguredSSID="0" ChannelFreq="2462" BehindWifiExtender="0" WifiEnabled="1" Orientation="0" RoomCalibrationState="1" SecureRegState="2" VoiceState="0"/></ZoneGroup><ZoneGroup Coordinator="RINCON_B8E93702F1C401400" ID="RINCON_B8E93702F1C401400:732923909"><ZoneGroupMember UUID="RINCON_B8E93702F1C401400" Location="http://172.21.0.10:1400/xml/device_description.xml" ZoneName="BOOST" Icon="x-rincon-roomicon:viper" Configuration="1" Invisible="1" IsZoneBridge="1" SoftwareVersion="42.2-51240" MinCompatibleVersion="41.0-00000" LegacyCompatibleVersion="36.0-00000" BootSeq="3110" TVConfigurationError="0" WirelessMode="0" WirelessLeafOnly="0" HasConfiguredSSID="0" ChannelFreq="2462" BehindWifiExtender="0" WifiEnabled="1" Orientation="-1" RoomCalibrationState="0" SecureRegState="2" VoiceState="0"/></ZoneGroup></ZoneGroups>

Beste Grüsse!

DS_Starter · 22 Juni 2018, 10:09:06

Hallo Reiner,

seit nun ein paar Tagen habe ich für Sonos_device verbose 5 eingestellt und bisher keinen "disabled" Status beobachten können.
Wo ist die versteckte Kamera ?

Es ist wirklich sehr verwunderlich, denn sonst dauert es gewöhnlich nicht solange.
EIn extra Logfile habe ich auch angegeben und das wird auch fleißig beschrieben. Allerdings tauchen im normalen Log ebenfalls verbose 5 Meldungen auf.
Vielleicht musst du da nochmal schauen, sollte m.M. nach nicht passieren.

Ich beobachte weiter ...

Grüße
Heiko

Reinerlein · 23 Juni 2018, 09:21:08

Hallo Heiko,

im normalen Log tauchen die Meldungen des unter Fhem laufenden Modulteils auf. Das ist auch Absicht.
Lediglich die Meldungen des SubProzesses werden in die angegebene Datei umgelenkt...
Ursprünglich habe ich das eingebaut, weil unter Windows die beiden Systeme (SubProzess & Fhem) sich gegenseitig die Log-Einträge überschreiben, und dann einige Informationen verloren gehen

@inoma: Ich schaue da mal rein...

Grüße
Reiner

Jamo · 23 Juni 2018, 12:36:17

Hallo Reiner,
danke!
Ich glaube es liegt daran, das in der sub SONOS_getSonosPlayerByUDN(;$), in Zeile 9554 die Abfrage auf $main::defs{$fhem_dev}{TYPE} eq 'SONOSPLAYER' gemacht wird.
Die Bridge hat aber als 'Type' auch "SONOSPLAYER', hier mal die Internals der Bridge:

Code Auswählen


CHANGED
DEF           RINCON_B8E93702F1C401400_MR
NAME          Sonos_BOOST
NOTIFYDEV     Sonos_BOOST
NR            3467
NTFY_ORDER    50-Sonos_BOOST
STATE         appeared
TYPE          SONOSPLAYER
UDN           RINCON_B8E93702F1C401400_MR

Oder?
Beste Grüsse!