Sonos: Freezes durch TriggerCoverTitelLater

Begonnen von CQuadrat, 24 Mai 2017, 10:05:25

Vorheriges Thema - Nächstes Thema

CQuadrat

Hallo Zusammen,

ich habe gestern mal wieder ein Update durchgeführt.
Wenn Sonos nun abspielt, beobachte ich regelmäßige Freezes (etwa minütlich) von einer Länge zwischen 1,5 s und 3 s.
Mit apptime finde ich den Hinweis auf tmr-SONOS_TriggerCoverTitelLater.

Beobachtet das noch jemand? Wie lässt sich das wieder abstellen?


Danke und Gruß

Christoph


Nachtrag: Höre Radio, da ändert sich das Cover im Prinzip überhaupt nicht.

Nachtrag 2: Ich habe den Verbose-Level mal hochgesetzt. Das bekomme ich jeweils vor den Freezes:


2017.05.24 10:23:28.990 5: SONOS0: Radioservice-Metadata: <?xml version="1.0" encoding="utf-8"?><soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xmlns:xsd="http://www.w3.org/2001/XMLSchema"><soap:Body><getMediaMetadataResponse xmlns="http://www.sonos.com/Services/1.1"><getMediaMetadataResult><id>s25641</id><title>SWR1 Rheinland-Pfalz</title><itemType>stream</itemType><language>de</language><country>DEU</country><genreId>g88</genreId><genre>Variety</genre><twitterId>swr1rp</twitterId><liveNow>true</liveNow><onDemand>false</onDemand><streamMetadata><currentShowId>p237937</currentShowId><currentShow>Der Vormittag</currentShow><currentHost /><bitrate>128</bitrate><reliability>87</reliability><logo>http://cdn-radiotime-logos.tunein.com/s1561q.png</logo><title>99.5 FM</title><subtitle>Alf, Germany</subtitle><secondsRemaining>5893</secondsRemaining><secondsToNextShow>5893</secondsToNextShow><nextShowSeconds>0</nextShowSeconds></streamMetadata></getMediaMetadataResult></getMediaMetadataResponse></soap:Body></soap:Envelope>
2017.05.24 10:23:29.614 5: SONOS0: Player: Sonos_Bad ~ Slaves: []
2017.05.24 10:23:31.190 1: Perfmon: possible freeze starting at 10:23:30, delay is 1.19
2017.05.24 10:23:50.207 5: SONOS0: Radioservice-Metadata: <?xml version="1.0" encoding="utf-8"?><soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xmlns:xsd="http://www.w3.org/2001/XMLSchema"><soap:Body><getMediaMetadataResponse xmlns="http://www.sonos.com/Services/1.1"><getMediaMetadataResult><id>s25641</id><title>SWR1 Rheinland-Pfalz</title><itemType>stream</itemType><language>de</language><country>DEU</country><genreId>g88</genreId><genre>Variety</genre><twitterId>swr1rp</twitterId><liveNow>true</liveNow><onDemand>false</onDemand><streamMetadata><currentShowId>p237937</currentShowId><currentShow>Der Vormittag</currentShow><currentHost /><bitrate>128</bitrate><reliability>87</reliability><logo>http://cdn-radiotime-logos.tunein.com/s1561q.png</logo><title>99.5 FM</title><subtitle>Alf, Germany</subtitle><secondsRemaining>5799</secondsRemaining><secondsToNextShow>5799</secondsToNextShow><nextShowSeconds>0</nextShowSeconds></streamMetadata></getMediaMetadataResult></getMediaMetadataResponse></soap:Body></soap:Envelope>
2017.05.24 10:23:50.782 5: SONOS0: Player: Sonos_Bad ~ Slaves: []
2017.05.24 10:23:52.294 1: Perfmon: possible freeze starting at 10:23:51, delay is 1.293
2017.05.24 10:24:10.340 5: SONOS0: Radioservice-Metadata: <?xml version="1.0" encoding="utf-8"?><soap:Envelope xmlns:soap="http://schemas.xmlsoap.org/soap/envelope/" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xmlns:xsd="http://www.w3.org/2001/XMLSchema"><soap:Body><getMediaMetadataResponse xmlns="http://www.sonos.com/Services/1.1"><getMediaMetadataResult><id>s25641</id><title>SWR1 Rheinland-Pfalz</title><itemType>stream</itemType><language>de</language><country>DEU</country><genreId>g88</genreId><genre>Variety</genre><twitterId>swr1rp</twitterId><liveNow>true</liveNow><onDemand>false</onDemand><streamMetadata><currentShowId>p237937</currentShowId><currentShow>Der Vormittag</currentShow><currentHost /><bitrate>128</bitrate><reliability>87</reliability><logo>http://cdn-radiotime-logos.tunein.com/s1561q.png</logo><title>99.5 FM</title><subtitle>Alf, Germany</subtitle><secondsRemaining>5784</secondsRemaining><secondsToNextShow>5784</secondsToNextShow><nextShowSeconds>0</nextShowSeconds></streamMetadata></getMediaMetadataResult></getMediaMetadataResponse></soap:Body></soap:Envelope>
2017.05.24 10:24:10.951 5: SONOS0: Player: Sonos_Bad ~ Slaves: []
2017.05.24 10:24:12.471 1: Perfmon: possible freeze starting at 10:24:11, delay is 1.471
FHEM auf Mini-ITX-Server mit Intel Quad-Core J1900:
+ HM: HM-LAN, HM-USB, HM-MOD-UART mit div. HM-Komponenten
+ RFXtrx: Funkwetterstation Bresser mit ext. Thermometer, Regenmesser und Windmesser
+ TUL (KNX-Anbindung), KM271 (per ser2net), SONOS (div. Gimmicks), OneWire, Hue

Reinerlein

Hi Christoph,

das ganze wird vom Notify aufgerufen, wenn sich eines der folgenden Readings aktualisiert:

currentAlbumArtURL|currentTrackProviderIconRoundURL|currentTrackDuration|currentTrack|numberOfTracks|currentTitle|currentArtist|currentAlbum|nextAlbumArtURL|nextTrackProviderIconRoundURL|nextTitle|nextArtist|nextAlbum|currentSender|currentSenderInfo|currentSenderCurrent|transportState

Damit sind alle Änderungen erschlagen, die von der Cover-/Titelanzeige dargestellt werden können. Ausgelagert ist es deshalb, damit Fhem zwischen dem Auftreten des Triggers für eines oder mehrerer dieser Readings und dem Trigger für die Cover-/Titelanzeige kurz aktiv werden kann (und eigentlich genau *kein* Freeze auftreten sollte :) ).

Also nicht nur das Cover muss sich ändern, sondern auch z.B. der Titel, der auch bei Radiostreams aktualisiert wird, kann diesen Prozeduraufruf verursachen...

Natürlich dauert die Anzeige etwas;
Hast du die Proxy/Cachefunktionalität des Moduls aktiviert? Die hilft ungemein, da keinerlei Anfragen für identische Cover an die Player oder ins Internet gehen...

Grüße
Reiner

CQuadrat

Ja, das ist alles aktiviert.
Habe mich auch gerade davon überzeugt, dass in das Cache-Verzeichnis geschrieben wird.
FHEM auf Mini-ITX-Server mit Intel Quad-Core J1900:
+ HM: HM-LAN, HM-USB, HM-MOD-UART mit div. HM-Komponenten
+ RFXtrx: Funkwetterstation Bresser mit ext. Thermometer, Regenmesser und Windmesser
+ TUL (KNX-Anbindung), KM271 (per ser2net), SONOS (div. Gimmicks), OneWire, Hue

CQuadrat

Nachtrag:
Komisch ist auch, dass ich im SONOSPLAYER-Verzeichnis entsprechende *.ERROR-Dateien der Covers habe.
Die sind aber korrekt. Denn wenn ich sie umbenenne in *.png, kann ich die entsprechenden Cover öffnen.


FHEM auf Mini-ITX-Server mit Intel Quad-Core J1900:
+ HM: HM-LAN, HM-USB, HM-MOD-UART mit div. HM-Komponenten
+ RFXtrx: Funkwetterstation Bresser mit ext. Thermometer, Regenmesser und Windmesser
+ TUL (KNX-Anbindung), KM271 (per ser2net), SONOS (div. Gimmicks), OneWire, Hue

Reinerlein

Hi Christoph,

die Cover im lokalen Verzeichnis (also nicht der Cacheordner) sind mittlerweile eher überflüssig (ich überlege auch, diese abzuschaffen, bzw. zunächst mal abschaltbar zu machen). Das Problem ist nämlich, dass die Sonosplayer in immer weniger Fällen einen korrekten Mimetype zurückliefern, und somit eine korrekte Endung von mir nicht erraten/gefunden werden kann.
Das bedeutet, dass die Binärdaten zwar korrekt in (irgendeinem) Format vorliegen, mir aber keiner sicher verraten kann, in welchem Format :(
Vor allem ist es für den Durchschnittsuser Zeitverschwendung, da diese lokal abgelegten Cover wahrscheinlich niemand verwendet, und nur Zeit verbrauchen, um geladen zu werden...

Das ganze habe ich im Cache umgangen, indem die Dateiendungen immer ".image" lauten, und vom Browser schon irgendwie verstanden werden :)

Ich sehe mal zu, dass ich das mal abschaltbar gestalte... Das wird aber dein Problem vermutlich nicht beseitigen...

Grüße
Reiner

CQuadrat

Was verbirgt sich eigentlich im Reading MusicServicesList? Da stehen Meldungen, mit Verweis auf kostenpflichtige Dienste drin? Vielleicht wird da irgendwo "angeklopft" und es kommt keine Rückmeldung.
FHEM auf Mini-ITX-Server mit Intel Quad-Core J1900:
+ HM: HM-LAN, HM-USB, HM-MOD-UART mit div. HM-Komponenten
+ RFXtrx: Funkwetterstation Bresser mit ext. Thermometer, Regenmesser und Windmesser
+ TUL (KNX-Anbindung), KM271 (per ser2net), SONOS (div. Gimmicks), OneWire, Hue

Reinerlein

Hi Christoph,

diese Informationen werden alle bei Sonos (also in Kalifornien :) ) abgerufen. Das dauert tatsächlich etwas, wird aber nur bei Änderung der MusicservicesVersion durchgeführt, also im Normalfall sehr selten.

Anschließend bleiben die Informationen im Reading ja vorhanden, und werden nur verwendet. Anschließend werden über die dort abgelegten Informationen die TrackProvider-Bildchen bei Sonos besorgt, und die Radiocover angefragt. Die Schnittstelle ist aber eigentlich fix, und es werden ja auch nicht viele Informationen übertragen.

Aber auch da wollte ich nochmal ein Caching einbauen (damit auch das ermitteln der Cover-URL bei Radios nicht immer ins Netz zugreift, sondern nur beim Wechsel)...

Grüße
Reiner

CQuadrat

Aha, vielen Dank für die Infos.

Im Log habe ich noch

2017.05.24 11:04:40.865 4: SONOS0: Transport-Event: CoverArt konnte nicht gefunden werden. Verwende FHEM-Logo. Bilder-Download: SONOS_DownloadReplaceIfChanged('./FHEM/lib/UPnP/sonos_empty.jpg', './www/images/default/SONOSPLAYER/Sonos_Kueche_NextAlbumArt.png');
2017.05.24 11:04:40.868 5: SONOS0: Call of SONOS_DownloadReplaceIfChanged("./FHEM/lib/UPnP/sonos_empty.jpg", "./www/images/default/SONOSPLAYER/Sonos_Kueche_NextAlbumArt.png")

gefunden.
FHEM auf Mini-ITX-Server mit Intel Quad-Core J1900:
+ HM: HM-LAN, HM-USB, HM-MOD-UART mit div. HM-Komponenten
+ RFXtrx: Funkwetterstation Bresser mit ext. Thermometer, Regenmesser und Windmesser
+ TUL (KNX-Anbindung), KM271 (per ser2net), SONOS (div. Gimmicks), OneWire, Hue

CQuadrat

Bin jetzt wieder auf eine ältere Version zurückgegangen.

Die Freezes sind dadruch wieder verschwunden. Werde es mir bei Zeit irgendwann nochmal näher ansehen.
FHEM auf Mini-ITX-Server mit Intel Quad-Core J1900:
+ HM: HM-LAN, HM-USB, HM-MOD-UART mit div. HM-Komponenten
+ RFXtrx: Funkwetterstation Bresser mit ext. Thermometer, Regenmesser und Windmesser
+ TUL (KNX-Anbindung), KM271 (per ser2net), SONOS (div. Gimmicks), OneWire, Hue