Sonos Player disappeared

Reinerlein · 24 Juni 2020, 21:55:11

Hi det.,

hat dein Fhem-Rechner keinen Zugriff auf das Internet?
Er kommt ja weder an https- noch an http-Seiten ran...

Vielleicht muss ich dieses ganze Nachladen aus dem Netz mal deaktivierbar machen... Fehlen dir auch Cover z.B. von Spotify (falls du das verwendest)?

Grüße
Reinerlein

det. · 24 Juni 2020, 22:12:41

Hallo Reinerlein,

Mein Fhem hat natürlich Zugriff auf das Internet. Ich nutze nur Radio (Amazon Prime Ultimat, Sonos Radio und TuneIn) und da kommen die Cover einwandfrei. Natürlich ist mein Server mit Nginx und Fail2Ban hoffentlich gegen Angriffe von Außen ordentlich gesichert. Aktuell, eben noch mal gecheckt läuft Musik mit Coveranzeige, ist mit verbose 0 nichts weiter im log aufgelaufen. - d.h. Von meiner Seite alles ok. Die Log Einträge scheinen immer beim Player Neustart zu kommen. Wenn Du die unterdrücken könntest, wäre ich mit dem aktuellen Stand rundum zufrieden.

Reinerlein · 24 Juni 2020, 22:44:04

Hi det.,

unterdrücken ist allgemein schwierig... geht halt nur als Konfiguration (Attribut), also vom Anwender entschieden, da ja einiges dann nicht mehr geladen wird.
Aber wenn dein Fhem-Rechner Zugriff auf das Internet hat, sollten die Fehler eigentlich auch nicht auftreten...

Kannst du mal auf der Konsole deines Fhem-Rechners versuchen eine der angemerkten URLs z.B. per wget oder cURL zu laden?

Grüße
Reinerlein

Jamo · 24 Juni 2020, 22:57:53

Hi Reiner,
ich habe gerade deine Versionen aus dem Post #317 runtergeladen und bei mir installiert.
FHEM startet aber nicht mehr, es kommt die Fehlermeldung:

Code Auswählen

Can't call method "sockopt" on an undefined value at ./FHEM/00_SONOS.pm line 1085.
Das ist die Zeile " $hash->{TCPDev}->sockopt(SO_LINGER, pack("ii", 1, 0)); " im SONOS_StopSubProcess.
Ich habe die Zeile auskommentiert, damit geht es erstmal wieder.

Danke für das tolle Modul! ! !

Reinerlein · 25 Juni 2020, 00:53:37

Hi Jamo,

das das mal undefined sein kann... damit rechnet ja auch niemand... egal, ich habe eine Prüfung eingebaut, sodass das nicht mehr als Fehler rauskommt...

Ich arbeite an einer Veröffentlichung im SVN zum Wochenende... ist dann mit drin...

Grüße
Reinerlein

Jamo · 25 Juni 2020, 09:00:19

Hallo Reiner,
danke! Hier noch einer, der öfters bei mir auftaucht:

Code Auswählen

ERROR evaluating {groupSonos()}: Can't use an undefined value as a HASH reference at ./FHEM/00_SONOS.pm line 2140.
Den fix von unten mit der Prüfung auf undefined, das hast Du noch nicht mit in den 00_SONOS.pm vom Post 317 mit eingebaut, oder?

Reinerlein · 25 Juni 2020, 09:11:35

Hi Jamo,

also der Fehler ist auch komisch. Da wurde vom Sonos-System eine Gruppierung mitgeteilt, und mindestens einen Player dieser Liste hast du nicht in deinem Fhem...

Ich fürchte, da müsstest du mal ein Log auf Level 5 machen. Da ich für diesen Fall nur die Ausgabe des SubProzesses benötige, kannst du mit dem Attribut "SubProcessLogfileName" am Sonos-Device arbeiten. Dann sind zumindest diese Ausgaben schon mal nicht im normalen FHEM-Log...

Grüße
Reinerlein

P.S.: Ich wollte die Datei nicht mehr Nachts hochladen

Jetzt schauen wir erstmal, was der Grund für diese Meldung ist...

det. · 25 Juni 2020, 09:13:18

Zitat von: Reinerlein am 24 Juni 2020, 22:44:04
Hi det.,

unterdrücken ist allgemein schwierig... geht halt nur als Konfiguration (Attribut), also vom Anwender entschieden, da ja einiges dann nicht mehr geladen wird.
Aber wenn dein Fhem-Rechner Zugriff auf das Internet hat, sollten die Fehler eigentlich auch nicht auftreten...

Kannst du mal auf der Konsole deines Fhem-Rechners versuchen eine der angemerkten URLs z.B. per wget oder cURL zu laden?

Grüße
Reinerlein

Hallo Reinerlein,
gesagt - getan - siehe Dateianhang. mit --no-check-certificate geht es
Diese LOG Meldungen nach jedem Sonos Player Neustart gibt es aber erst nach Deinen letzten Änderungen. Im Ursprungsmodul und in der von mumpitzstuff angepassten Version waren die nicht zu sehen. Die ordnungsgemäße Funktion scheint das auch nicht zu beeinträchtigen.

sTaN · 25 Juni 2020, 22:59:59

Hallo Zusammen,

nach meinem Routerwechsel hatte ich doch tatsächlich Probleme mit den Sonos Playern, da er sich augenscheinlich eine alte DHCP Adresse gemerkt hatte. Nach Neuanlage des Sonos Devices und der Player lief alles soweit normal.
Außer nach einem Raspberry Neustart schien sich das Sonos Modul soweit aufzuhängen, dass FHEM komplett blockiert wurde. Web Interface war nicht mehr erreichbar. Konnte es nur schaffen, in dem ich die 00_SONOS.pm umbenannt hatte in 00_SONOS.pm_offline und anschließendem Pi Neustart.

Nun habe ich heute ein Update gemacht und gesehen, dass es eine neuere Version der 00_SONOS.pm gab.
In den letzten Beiträgen wurde ja einiges daran verändert, aber ihr hattet dies doch noch gar nicht eingecheckt oder? Das verwirrt mich gerade etwas!

Auf jeden Fall scheint das Modul gerade alles andere als stabil zu sein.

Viele Grüße
sTaN

Reinerlein · 25 Juni 2020, 23:17:37

Hi sTaN,

das Modul hat noch nie Fhem blockiert, da es extra dafür einen eigenen Prozess startet. Da wäre es schon interressant, was so im Log auftaucht...

Wenn bei einem Update eine neuere Version kam, war deine Version wohl mehr als 2 Jahre alt. Die offizielle Version ist von April 2018. Hier im Thread gibt es gerade den Beta-Release-Candidate-Test

Die Version soll dann am Wochenende eingecheckt werden.

Hauptsächlich sind so Dinge korrigiert worden, die eine Selbstrettung des Moduls ermöglichen sollen...

Es sind auch noch einige andere Dinge behoben/verbessert/stabilisiert worden, sodass wir jetzt demnächst auf die Suche nach dem eigentlichen, gemeldeten, Problem gehen können...

Grüße
Reinerlein

sTaN · 26 Juni 2020, 00:05:39

Ja das Update kam logischerweise, da ich zuvor die 00_SONOS.pm in 00_SONOS.pm_offline umbenannt hatte.

Im sonoslog sind die letzten Zeilen die folgenden:

Code Auswählen

2020.06.25 23:56:56 3: SONOS0: Disconnecting client and shutdown server...
2020.06.25 23:56:56 3: SONOS0: Trying to kill Sonos_Thread...
2020.06.25 23:56:56 3: SONOS0: Trying to kill LongJobs_Thread...
2020.06.25 23:56:56 3: SONOS0: Trying to kill IsAlive_Thread...
2020.06.25 23:56:56 3: SONOS0: Trying to kill PlayerRestore_Thread...
2020.06.25 23:56:56 0: SONOS0: Das Lauschen auf der Schnittstelle wurde beendet. Prozess endet nun auch...

Ich habe verbose noch mal auf 5 gesetzt. Mal schauen, ob er mir noch mehr rein schreibt.

Gruß
sTaN

Reinerlein · 26 Juni 2020, 00:11:14

Hi sTaN,

das sind nur Ausgaben, dass der SubProzess beendet werden sollte, und das auch getan hat... war das von einem Fhem-Neustart?

Naja, wir warten mal auf das detailliertere Log...

Grüße
Reinetlein

sTaN · 26 Juni 2020, 00:16:42

Also ich habe verbose 5 gesetzt und FHEM neugestartet um ca. 00:06:35 Uhr.
Anschließend waren die Player online und nach knapp 6 Minuten war wieder Schluss.

Hier nun das detaillierte Logfile:

EDIT: Scheinbar was das Log zu groß für das code-Tag. Deshalb als Datei

mumpitzstuff · 26 Juni 2020, 00:37:21

Zitat von: sTaN am 26 Juni 2020, 00:05:39
Ja das Update kam logischerweise, da ich zuvor die 00_SONOS.pm in 00_SONOS.pm_offline umbenannt hatte.

Im sonoslog sind die letzten Zeilen die folgenden:
Code Auswählen Erweitern
2020.06.25 23:56:56 3: SONOS0: Disconnecting client and shutdown server... 2020.06.25 23:56:56 3: SONOS0: Trying to kill Sonos_Thread... 2020.06.25 23:56:56 3: SONOS0: Trying to kill LongJobs_Thread... 2020.06.25 23:56:56 3: SONOS0: Trying to kill IsAlive_Thread... 2020.06.25 23:56:56 3: SONOS0: Trying to kill PlayerRestore_Thread... 2020.06.25 23:56:56 0: SONOS0: Das Lauschen auf der Schnittstelle wurde beendet. Prozess endet nun auch...

Ich habe verbose noch mal auf 5 gesetzt. Mal schauen, ob er mir noch mehr rein schreibt.

Gruß
sTaN

Das ist eins der typischen Fehlerbilder des Originalmoduls. Das habe ich in diversen Logausschnitten schon gesehen. Es wird ein Shutdown ausgeführt, dann wird das gemacht:

Code Auswählen


.
# Stoppen...
InternalTimer(gettimeofday() + 1, 'SONOS_StopSubProcess', $hash, 0);
		
# Starten...
InternalTimer(gettimeofday() + 30, 'SONOS_DelayStart', $hash, 0);
.

DelayStart funktioniert nicht, weil der Socket noch halblebig da ist und danach ist alles weg.

sTaN · 26 Juni 2020, 00:47:08

Interessanterweise hatte ich jetzt ewig Ruhe! Um genau zu sein, seitdem 12.04.
Da hatte ich unter anderem das ignoredIP Attribut um meinen LG TV erweitert.

Nun musste ich meine FritzBox Cable 6490 durch eine 6591 tauschen.
Ein paar DHCP Adressen haben sich leider verändert. Das musste ich nachziehen. Hab die ignoredIP Liste dahingegen auch angepasst, aber irgendwas scheint ihm jetzt nicht mehr zu schmecken, weshalb sie sofort nach 5-6 Minuten auf disappeared gehen.

Ich hatte damals noch dokumentiert, dass ich das Sonos device wie folgt editiert hatte:

Code Auswählen

 defmod Sonos SONOS localhost:4711 120 1 5

Das probiere ich mal noch