Sonos steuern

[Reinerlein]

Hi Fixel,

diese Meldungen kommen, weil du nicht den SubProzess vor dem Löschen beendet hast. Dadurch wird noch versucht auf Player zuzugreifen, die gar nicht mehr existieren...

Am Besten du beendest mal den Prozess mit dem Setzen des Attributs "disable" am Sonos-Device. Wartest mal 30 Sekunden oder so, und löschst das Attribut wieder.

Grüße
Reiner

[Fixel2012]

Nach dem disablen/enablen des Sonos Moduls und dem löschen aller Player, habe ich bisher keine Fehlermeldungen mehr wahrnehmen können.

Danke dir trotzdem für deine Hilfe!

[Phiolin]

Bei mir stürzt neuerdings (bisher 2 mal in den letzten 2-3 Tagen) der 00_SONOS Prozess ab.
Bin noch nicht dahinter gekommen, warum...
Da der Subprozess sich nicht automatisch neu startet, merkt man es immer erst, wenn die Sonos Geräte benutzt werden sollen und nichts passiert.
Hier ein Auszug aus dem Log. Ideen zur Fehlersuche?

Code Auswählen Erweitern

2017.05.23 09:02:59 3: SONOS0: Connection accepted from localhost:47090
2017.05.23 09:03:29 3: SONOS0: Connection accepted from localhost:47108
2017.05.23 09:03:59 3: SONOS0: Connection accepted from localhost:47122
2017.05.23 09:04:29 3: SONOS0: Connection accepted from localhost:47140
2017.05.23 09:04:59 3: SONOS0: Connection accepted from localhost:47162
2017.05.23 09:05:29 3: SONOS0: Connection accepted from localhost:47170
2017.05.23 09:05:59 3: SONOS0: Connection accepted from localhost:47192
2017.05.23 09:06:29 3: SONOS0: Connection accepted from localhost:47210
Can't call method "kill" on an undefined value at ./FHEM/00_SONOS.pm line 97
30, <$client> line 3.

[viegener]

Ich habe ein ähnliches Verhalten, habe aber erst heute auf die neue Version upgedated:

Code Auswählen Erweitern

2017.05.25 19:30:50 2: SONOS1: Error during UPnP-Handling: 500 read timeout at FHEM/lib/UPnP/ControlPoint.pm line 867 thread 1

        (in cleanup) Unsubscription request failed with error: 500 Can't connect to 192.168.2.35:1400 (No route to host) at FHEM/lib/UPnP/ControlPoint.pm line 1083 thread 1
Can't call method "kill" on an undefined value at ./FHEM/00_SONOS.pm line 9730, <$client> line 46.
Perl exited with active threads:
        2 running and unjoined
        1 finished and unjoined
        0 running and detached


Bei mir lief es weniger als 2 h mit der neuen Version.

Ich habe einen Player, der bei mir an einer Schaltsteckdose hängt erst eingeschaltet und konnte ihn auch steuern, dann habe ich ihn wieder abgeschaltet (vom Netz getrennt per schaltsteckdose) und dann konnte ich kurz darauf die noch laufenden Player nicht mehr bedienen

[Fixel2012]

Ich habe ein ähnliches Verhalten, habe aber erst heute auf die neue Version upgedated:

Code Auswählen Erweitern

2017.05.25 19:30:50 2: SONOS1: Error during UPnP-Handling: 500 read timeout at FHEM/lib/UPnP/ControlPoint.pm line 867 thread 1

        (in cleanup) Unsubscription request failed with error: 500 Can't connect to 192.168.2.35:1400 (No route to host) at FHEM/lib/UPnP/ControlPoint.pm line 1083 thread 1
Can't call method "kill" on an undefined value at ./FHEM/00_SONOS.pm line 9730, <$client> line 46.
Perl exited with active threads:
        2 running and unjoined
        1 finished and unjoined
        0 running and detached


Bei mir lief es weniger als 2 h mit der neuen Version.

Ich habe einen Player, der bei mir an einer Schaltsteckdose hängt erst eingeschaltet und konnte ihn auch steuern, dann habe ich ihn wieder abgeschaltet (vom Netz getrennt per schaltsteckdose) und dann konnte ich kurz darauf die noch laufenden Player nicht mehr bedienen

Habe das gleiche Verhalten wie bei dir mit der Funksteckdose geschrieben. 

[Avatar]

Hallo Reiner

mit der neuen Version kommt dieser Fehler wieder auf:
Subscription request failed with error: 500 Internal Server Error at ./FHEM/00_SONOS.pm line 6075 thread 1.

Es sind die Surround/Sub welche, wenn di IP ausgeschlossen wird, der Eintrag nicht mehr auftaucht.
Aber wie schon erwähnt fehlt dann jegliche Information von denen, was ja auch nicht das Ziel ist.

-> Wie damals schon erwähnt, wenn das Attribut minVolume bei den Surround gelöscht wird ist die Fehlermeldung weg.

was aber noch bleibt ist dieser Eintrag im Log:
at ./FHEM/00_SONOS.pm line 4310 thread 1.
at ./FHEM/00_SONOS.pm line 5022 thread 3.

Da ich zwei Surround Lautsprecher habe, könnte es ja sein dass es von denen herkommt.
Oder?

Grüsse
Eric

[Reinerlein]

Hi Eric,

ich dachte, dass wir das mit den Surrounds drin hätten Ich schaue mir das nochmal an.
Zu den beiden "leeren" Fehlermeldung: Die habe ich gefunden. Es sind tatsächlich keine Fehler, und der Fluss wird dadurch auch nicht behindert...

Grüße
Reiner

[Phiolin]

Bei mir ist es dagegen so, dass ich, wenn ich genau den String aus dem Forum kopiere, auch den Fehler bekomme (Safari/MacOS).

Code Auswählen Erweitern

set Sonos_Schlafzimmer speak 20 de Meistens klar. Vereinzelt Frost möglich. Höchsttemperatur 9 °C. Wind aus NO mit 10 bis 15 km/h.

Der Fehler liegt wohl auch nicht im MSG Modul, da ich die Meldung auch bekommen, wenn ich über

Code Auswählen Erweitern

set Sonos_Schlafzimmer speak 20 de [wu.Gladbeck:fc0_text]

den Text direkt aus dem Wunderground Forecast Reading hole.
Ein kurzer Blick ins Wunderground Modul lässt mich zumindest vermuten, dass dort die über JSON ausgelesenen Daten alle UTF-8 codiert sein sollten. Scheint wohl ein eher komplexeres Problem zu sein.
Gebe ich manuell einen String per Tastatur mit entsprechenden Zeichen ein, funktioniert übrigens alles normal...

Kurze Info: Habe das "Problem" im Wunderground Modul wohl identifiziert, siehe hier.

Möchte das hier noch mal aufgreifen. Da Loredo auf dem chr(0x202F) im Wunderground Modul besteht, da es zur korrekten typographischen Darstellung der Einheit gehört, können wir diesen speziellen Character bei der Sprachausgabe im Sonos Modul filtern? Für die Sprachausgabe selber ist der "narrow-no-brake-space" völlig unwichtig, die funktioniert ohne genauso gut. Nur mit dem Character klappt es nicht, weil dann die Hash Generierung auf die Nase fällt.
Da der Benutzer praktisch keine Handhabe darüber hat, welche Strings nun wie an das Sonos Modul übergeben werden - außer man baut in alle DOIFs, Notifies und ähnliches immer entsprechende Charakter-Konvertierungen ein - sollte das Problem doch eher im Backend gelöst werden. Also entweder gibt Wunderground dieses Zeichen nicht aus, oder Sonos filtert die eingehenden Zeichenketten für die Sprachausgabe entsprechend, damit die Verarbeitung der Daten ordentlich läuft.
Wahrscheinlich wäre eine Lösung im Sonos Modul wohl logischer und einfacher, denn als Endnutzer würde ich erwarten, dass das Modul mit allem klar kommt, was ich ihm so vorwerfe - Stichwort "Data validation" als Coding "Best-Practice"?

[Reinerlein]

Hi,

@phiolin: Ich habe das von dir vorgeschlagene Prozedere eingebaut, wenn es eine Wide-Character Fehlermeldung bei der Hashberechnung geben sollte.

@Eric: Ich habe daraus jetzt eine abgefangene Fehlmeldung gemacht. Da ich an der Stelle noch keine umfangreichen Informationen über diesen Player vorliegen habe, war das die einzige Möglichkeit, dass wenigstens der Erkennungsprozess sauber abgeschlossen wird...

Bei den anderen Problemen: Ich versuche gerade ein Problem beim Abschalten von Playern zu provozieren, bin dabei aber Erfolglos... Bei mir geht das Problemfrei, was im Prinzip gut ist, aber leider bei der Fehlersuche nicht weiterhilft...
Außerdem habe ich das Modul mal ohne Neustart betrieben. Auf meiner Entwicklungsmaschine (Windows 2003) lief das 10 Tage Problemfrei, dann habe ich neuen Code produziert, und musste mal neustarten Auf meinem Produktivsystem konnte ich es mal 20 Tage laufen lassen, dann habe ich auch dort ein Update machen müssen... In der ganzen Zeit gab es noch nicht mal eine Fehlermeldung... das ist alles sehr verwirrend...

Grüße
Reiner

[Phiolin]

Bei mir lief das Modul jetzt auch einige Tage problemlos durch. Gestern habe ich dann mal wieder einen FHEM restart gemacht und direkt wurde am Abend der Sonos Player im Schlafzimmer nicht gefunden "disappeared". Habe dann das Sonos Device mal kurz für eine Minute auf disabled gesetzt und danach wieder aktiviert, dann lief der Player wieder...

Ursache war wohl wieder der bekannte Fehler aus dem Log:

Code Auswählen Erweitern

2017.05.29 13:17:28 3: SONOS0: Connection accepted from localhost:45904
Can't call method "kill" on an undefined value at ./FHEM/00_SONOS.pm line 9730, <$client> line 3.


Danach ist das Sonos Modul erst mal tot und muss manuell wiederbelebt werden, was über einen Restart oder disable/enable wohl funktioniert.
Nach dem setattr disable 1 und deleteattr disable wird der UPnP Server neu gestartet:

Code Auswählen Erweitern

2017.05.29 23:09:53 1: SONOS0: Kein UPnP-Server gefunden... Starte selber einen und warte 8 Sekunde(n) darauf...
2017.05.29 23:09:54 1: SONOS0: ./FHEM/00_SONOS.pm is listening to Port 4711
2017.05.29 23:10:01 3: Opening Sonos device localhost:4711
2017.05.29 23:10:01 3: SONOS0: Connection accepted from localhost:35772
2017.05.29 23:10:01 3: Sonos device opened
2017.05.29 23:10:03 3: SONOS1: UPnP-Thread gestartet.


Und dann läuft es halt auch wieder...
Warum der UPnP Thread manchmal verstirbt ist mir aber noch nicht klar.

Den wide-character fix werde ich dann testen, sobald er im update drin ist.

[Reinerlein]

Hi Phiolin,

kannst du das Log denn mal bis zum nächsten Sonos-SubProzess-Tod auf 5 hochsetzen?
Dann sehen wir vielleicht, was als letztes hin- und hergesendet wurde, und warum er der Meinung ist, sterben zu müssen.
Die Fehlermeldung mit dem "can't kill..." ist nur eine Folgemeldung des eigentlichen Problems...

Grüße
Reiner

[Phiolin]

Reicht es, wenn ich das Sonos Device auf verbose 5 stelle, oder muss ich das global setzen?

[Reinerlein]

Hi Phiolin,

das kann ich dir gar nicht so genau sagen
Primär geht es erstmal um Verbose am Sonos-Device.
Aber wenn du global auf 5 stellst, sieht man ja sogar jedes Byte, welches per DevIO an die Gegenstelle übertragen wird. Unter Umständen ist das dann doch wichtig, je nachdem, was mein Modul so loggt, oder eben auch nicht loggt...

Ich würde es im ersten Schritt mit Verbose 5 am Sonos-Device versuchen, und sehen, ob was dabei rauskommt...

Grüße
Reiner

[JoWiemann]

Hallo,

mit der aktuellen Version bekomme ich folgenden Stack Trace:

Code Auswählen Erweitern


2017.05.30 12:11:11 1: readingsUpdate(Sonos_Bad,MasterPlayer,Sonos_Bad) missed to call readingsBeginUpdate first.
2017.05.30 12:11:11 1: stacktrace:
2017.05.30 12:11:11 1:     main::readingsBulkUpdate            called by /usr/share/fhem/FHEM/00_SONOS.pm (9289)
2017.05.30 12:11:11 1:     main::SONOS_readingsBulkUpdateIfChanged called by /usr/share/fhem/FHEM/00_SONOS.pm (1265)
2017.05.30 12:11:11 1:     main::SONOS_Read                    called by /usr/share/fhem/fhem.pl (3412)
2017.05.30 12:11:11 1:     main::CallFn                        called by /usr/share/fhem/fhem.pl (686)


Da scheint ein readingsBeginUpdate zu fehlen!

Grüße Jörg

[Reinerlein]

Hallo Jörg,

vermutlich nicht
Es geht bei dir nur auf dem Weg vom SubProzess hin zu Fhem verloren... Das ist ja bei manchen Anwendern anscheinend das Problem, dass Dinge zwischen den beiden Instanzen verloren gehen...

Leider gestaltet sich dabei die Suche etwas schwierig.

Grüße
Reiner