Sonos Player disappeared

Begonnen von aherby, 22 Dezember 2015, 18:20:38

Vorheriges Thema - Nächstes Thema

sTaN

Jetzt habe ich noch mal alles gelöscht und wirklich mal das Sonos device direkt in der FHEM.cfg angelegt (nur mit einem Player im Büro):

Anschließend ist fhem gestartet, hat den Büro Player angelegt. Dieser ließ sich aber wieder nicht steuern, da der SubProcess relativ schnell gestoppt und neu gestartet ist und am Ende sogar komplett fhem zum Absturz gebracht hat:

2020.06.28 16:36:28 5: SW: StartThread

xxxx.xx.xx xx:xx:xx 5: ControlPoint: Accepted Search-Response: "CACHE-CONTROL: max-age = 1800
EXT:
LOCATION: http://192.168.188.216:1400/xml/device_description.xml
SERVER: Linux UPnP/1.0 Sonos/57.3-77280 (ZPS1)
ST: urn:schemas-upnp-org:device:ZonePlayer:1
USN: uuid:RINCON_5CAAFD7CE48801400::urn:schemas-upnp-org:device:ZonePlayer:1
X-RINCON-HOUSEHOLD: Sonos_BCudEzFDdsCyG8BAGUxmTyAd8b
X-RINCON-BOOTSEQ: 130
X-RINCON-WIFIMODE: 1
X-RINCON-VARIANT: 1
HOUSEHOLD.SMARTSPEAKER.AUDIO: Sonos_BCudEzFDdsCyG8BAGUxmTyAd8b.MY1Phm3TA8JMmMVolsKO

"
2020.06.28 16:36:37 5: SONOS0: Received from UPnP-Server: 'getstore('http://192.168.188.216:1400/img/icon-S1.png', $attr{global}{modpath}.'/www/images/default/icoSONOSPLAYER_icon-S1.png');'
2020.06.28 16:36:37 5: SONOS0: MainTrigger()-Line: getstore('http://192.168.188.216:1400/img/icon-S1.png', $attr{global}{modpath}.'/www/images/default/icoSONOSPLAYER_icon-S1.png');
2020.06.28 16:36:37 5: SONOS0: Received from UPnP-Server: 'SONOS_RefreshIconsInFHEMWEB('/www/images/default/icoSONOSPLAYER_icon-S1.png');'
2020.06.28 16:36:37 5: SONOS0: MainTrigger()-Line: SONOS_RefreshIconsInFHEMWEB('/www/images/default/icoSONOSPLAYER_icon-S1.png');
2020.06.28 16:36:37 5: SONOS0: Received from UPnP-Server: 'ReadingsBeginUpdate:RINCON_5CAAFD7CE48801400_MR'
2020.06.28 16:36:37 4: SONOS0: ReadingsBeginUpdate from SubProcess for "Sonos_Buero"
2020.06.28 16:36:37 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7CE48801400_MR:presence:appeared'
2020.06.28 16:36:37 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7CE48801400_MR:Volume:17'
2020.06.28 16:36:37 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7CE48801400_MR:Balance:0'
2020.06.28 16:36:37 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7CE48801400_MR:roomName:Buero'
2020.06.28 16:36:37 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7CE48801400_MR:roomNameAlias:Buero'
2020.06.28 16:36:37 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7CE48801400_MR:saveRoomName:Buero'
2020.06.28 16:36:37 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7CE48801400_MR:playerType:S1'
2020.06.28 16:36:37 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7CE48801400_MR:Volume:17'
2020.06.28 16:36:37 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7CE48801400_MR:location:http://192.168.188.216:1400/xml/device_description.xml'
2020.06.28 16:36:37 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7CE48801400_MR:softwareRevision:11.2'
2020.06.28 16:36:37 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7CE48801400_MR:softwareRevisionAvailable:11.2'
2020.06.28 16:36:37 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7CE48801400_MR:softwareRevisionInternal:57.3-77280'
2020.06.28 16:36:37 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7CE48801400_MR:softwareRevisionInternalAvailable:57.3-77280'
2020.06.28 16:36:37 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7CE48801400_MR:serialNum:5C-AA-FD-7C-E4-88:A'
2020.06.28 16:36:37 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7CE48801400_MR:fieldType:'
2020.06.28 16:36:37 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7CE48801400_MR:IsBonded:0'
2020.06.28 16:36:37 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7CE48801400_MR:IsMaster:1'
2020.06.28 16:36:37 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7CE48801400_MR:IsZoneBridge:0'
2020.06.28 16:36:37 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7CE48801400_MR:MasterPlayer:Sonos_Buero'
2020.06.28 16:36:37 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7CE48801400_MR:SlavePlayer:[]'
2020.06.28 16:36:37 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7CE48801400_MR:SlavePlayerNotBonded:[]'
2020.06.28 16:36:37 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7CE48801400_MR:SlavePlayerNotBondedList:'
2020.06.28 16:36:37 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7CE48801400_MR:SlavePlayerNotBondedListAlias:'
2020.06.28 16:36:37 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7CE48801400_MR:transportState:PAUSED_PLAYBACK'
2020.06.28 16:36:37 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7CE48801400_MR:currentTrackURI:x-sonos-spotify:spotify%3atrack%3a5HPWNRdTPZvloAkpqmMOKK?sid=9&flags=8224&sn=1'
2020.06.28 16:36:37 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7CE48801400_MR:currentTrackProvider:'
2020.06.28 16:36:37 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7CE48801400_MR:currentTrackProviderIconRoundURL:'
2020.06.28 16:36:37 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7CE48801400_MR:currentTrackProviderIconQuadraticURL:'
2020.06.28 16:36:37 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7CE48801400_MR:currentTrackDuration:0:03:12'
2020.06.28 16:36:37 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7CE48801400_MR:currentTrackDurationSec:192'
2020.06.28 16:36:37 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdate:RINCON_5CAAFD7CE48801400_MR:currentTrackPosition:0:01:46'
2020.06.28 16:36:37 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdate:RINCON_5CAAFD7CE48801400_MR:currentTrackPositionSec:106'
2020.06.28 16:36:37 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7CE48801400_MR:currentTrack:26'
2020.06.28 16:36:37 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7CE48801400_MR:numberOfTracks:87'
2020.06.28 16:36:37 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7CE48801400_MR:currentStreamAudio:'
2020.06.28 16:36:37 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7CE48801400_MR:currentNormalAudio:1'
2020.06.28 16:36:37 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7CE48801400_MR:LastSubscriptionsRenew:2020-06-28 16:36:36'
2020.06.28 16:36:37 5: SONOS0: Received from UPnP-Server: 'ReadingsEndUpdate:RINCON_5CAAFD7CE48801400_MR'
2020.06.28 16:36:37 4: SONOS0: ReadingsEndUpdate from SubProcess for "Sonos_Buero"
2020.06.28 16:36:37 5: SONOS0: Received from UPnP-Server: 'CommandAttrWithUDN:RINCON_5CAAFD7CE48801400_MR:model Sonos_S1'
2020.06.28 16:36:38 4: SONOS0: ReadingsBeginUpdate from Module for "Sonos_Buero"
2020.06.28 16:36:38 4: SONOS0: ReadingsEndUpdate from Module for "Sonos_Buero"
2020.06.28 16:37:37 5: SONOS0: Long time, no hear from SubProcess... sending ping-request
2020.06.28 16:37:37 5: SW: DoWork:undef:refreshProcessAnswer:

2020.06.28 16:38:07 5: SONOS0: Long time, no hear from SubProcess... sending ping-request
2020.06.28 16:38:07 5: SW: DoWork:undef:refreshProcessAnswer:

2020.06.28 16:38:37 5: SONOS0: Long time, no hear from SubProcess... sending ping-request
2020.06.28 16:38:37 5: SW: DoWork:undef:refreshProcessAnswer:

2020.06.28 16:38:40 0: SONOS0: The Method 'SONOS_getSonosPlayerByUDN' cannot find the FHEM-Device according to 'RINCON_5CAAFD7CE47801400_MR'. This should not happen!
Can't use an undefined value as a HASH reference at ./FHEM/00_SONOS.pm line 2142.
Raspberry Pi 3
2 x CUL CC1101-USB-Lite 868MHz
FS20 Komponenten, Philips HUE, Alexa-Fhem, MAX! Geräte, homebridge, harmony, Unifi, FirtzBox, MQTT, Aurora, Denon, Sonos, TabletUI, CALENDAR, EGPM2LAN, Pushover

Reinerlein

Hi sTaN,

wir brauchen das, was vor dem Eintrag mit "way too old..." bei verbose-Level 5 steht.
Vielleicht auch zur Verdeutlichung und Trennung des Fhem-Moduls und des SubProzesses das Attribut "SubProcessLogfileName" verwenden. Deine Ausgaben vom letzten Beitrag waren größtenteils nur vom Fhem-Modulteil...

Also:
define Sonos SONOS
attr Sonos SubProcessLogfileName subprocess.log
attr Sonos verbose 5


Und ich verstehe immer noch nicht, wieso der SubProzess dein Fhem aufhält... das müssen wir aus dem Log herausfinden...

Die Fehlermeldung mit dem Hash, und "should not happen" tauchen auf, weil du nicht alle Player erkennen läßt, und Sonos dir aber bei der Gruppenübersicht natürlich alle Player nennt. Auch die, die du nicht hast erkennen lassen...
Da baue ich noch was ein, damit nur die bekannten Player beachtet werden...

Grüße
Reinerlein

sTaN

#377
Hallo Reinerlein,

also alles noch mal auf Anfang:

1. Sonos attr disable 1 gesetzt, um SubProcess zu stoppen
2. Alle Sonos Player gelöscht
3. Sonos Device gelöscht
4. Fhem sicherheitshalber gestoppt und geprüft, ob SubProcess noch läuft mittels ps ax | grep perl
5. Fhem gestartet und über die Fhem.cfg manuell das Sonos device mit folgenden Attributen angelegt (enthält nur Player im Büro):
define Sonos SONOS localhost:4711 120 8 5
attr Sonos room Sonos
attr Sonos SubProcessLogfileName sonos_subprocess.log
attr Sonos verbose 5
attr Sonos usedonlyIPs 192.168.188.216
attr Sonos pingType tcp
attr Sonos reusePort 1

6. Das Sonos Device und der Player im Büro tauchten sofort nach Save Fhem.cfg auf und ich hatte Fhem deshalb nicht neugestartet. Lediglich noch mal den Save Config Button geklickt. Player war nun appeared aber ließ sich nicht steuern.
7. ca. 5 Minuten später war der Player disappeared und das Sonos Device im Status disabled.
8. Deshalb erneut FHEM gestoppt und geprüft, ob SubProcess sauber gestoppt wurde.
9. FHEM gestartet
10. Das Sonos device hatte den Status opened aber der Player war noch disappeared. Ca. 5 Minuten
11. Anschließend war der Player appeared und ließ sich tatsächlich wieder Steuern!
12. Nun wollte ich wieder die folgenden Attribute hinzufügen, damit meine Favoriten, Playlist, Queues und Radiosender immer aktuell mit der Sonos App sind:
attr Sonos getFavouritesListAtNewVersion 1
attr Sonos getListsDirectlyToReadings 1
attr Sonos getPlaylistsListAtNewVersion 1
attr Sonos getQueueListAtNewVersion 1
attr Sonos getRadiosListAtNewVersion 1


Tja und nun wurde es interessant. Mein Sonos Player ließ sich danach nicht mehr steuern. Auch das Cover bei Titel Wechsel aktualisierte nicht mehr.

13. Deshalb habe ich die Attribute wieder gelöscht.
14. Player ging nach kurzer Zeit auf disappeared und Sonos device auf disabled.
15. Sonos device wechselte nach kurzer Zeit auf opened
16. Player kam dann nach ca. 5 wieder hoch auf appeared und ließ sich wieder steuern

Wie soll ich jetzt am besten weiter vorgehen? Machen hier eventuell die Attribute für die Favoriten Probleme? Soll ich jetzt jeden Player nach und nach wieder hinzufügen? Wenn ja, wie am Besten. Attribut disable = 1 setzen, dann Attribut usedonlyIPs um einen neuen Sonos erweitern und disable Attribut wieder löschen?

EDIT: Anbei noch die Logdateien
EDIT2: Habe noch Mals versucht die Attribute für die Favoriten zu setzen.
1. 18:55 Uhr Sonos device disabled = 1
2. 18:57 Uhr Attribute gesetzt und disabled Attribut gelöscht:
attr Sonos getFavouritesListAtNewVersion 1
attr Sonos getListsDirectlyToReadings 1
attr Sonos getPlaylistsListAtNewVersion 1
attr Sonos getQueueListAtNewVersion 1
attr Sonos getRadiosListAtNewVersion 1

3. 18:57:10 Uhr Sonos device hatte Status opened
4. 19:01:15 Uhr ging erst Sonos Player auf appeared und ließ sich auch wieder steuern
5. 19:06:09 im Sonos Player Büro get FavouritesWithCovers ausgeführt:
2020.06.28 19:06:09 5: SONOS0: Received: 'DoWork:RINCON_5CAAFD7CE48801400_MR:getFavouritesWithCovers:'
2020.06.28 19:06:09 4: SONOS1: ProxyObject exists: UPnP::ControlPoint::ControlProxy=HASH(0x741d96e0)
2020.06.28 19:06:09 4: SONOS1: ProxyObject exists: UPnP::ControlPoint::ControlProxy=HASH(0x741d96e0)
2020.06.28 19:06:10 5: SONOS1: MakeCoverURL-Before: x-sonosapi-stream:s25221?sid=254&flags=8224&sn=0
2020.06.28 19:06:10 5: SONOS1: Radioservice-Metadata: <s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" xmlns:xsd="http://www.w3.org/2001/XMLSchema" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance">
  <s:Body>
    <getMediaMetadataResponse xmlns="http://www.sonos.com/Services/1.1">
      <getMediaMetadataResult>
        <id>s25221</id>
        <title>94.3 RS2</title>
        <itemType>stream</itemType>
        <language>de</language>
        <country>DEU</country>
        <genreId>g3</genreId>
        <genre>Adult Hits</genre>
        <twitterId>943rs2</twitterId>
        <liveNow>true</liveNow>
        <onDemand>false</onDemand>
        <streamMetadata>
          <currentShowId>p346634</currentShowId>
          <currentShow>Mein Wochenende</currentShow>
          <currentHost />
          <bitrate>128</bitrate>
          <reliability>99</reliability>
          <logo>http://cdn-radiotime-logos.tunein.com/s25221q.png</logo>
          <title>94.3 FM</title>
          <subtitle>Berlin, Germany</subtitle>
          <secondsRemaining>17732</secondsRemaining>
          <secondsToNextShow>17732</secondsToNextShow>
          <nextShowSeconds>0</nextShowSeconds>
        </streamMetadata>
      </getMediaMetadataResult>
    </getMediaMetadataResponse>
  </s:Body>
</s:Envelope>
2020.06.28 19:06:10 4: SONOS1: SONOS_Client_Data_Retreive(SONOS, attr, allowedWebAccess, .*) -> DEFAULT
2020.06.28 19:07:13 4: SONOS3: IsAlive-Event UDN=RINCON_5CAAFD7CE48801400_MR
2020.06.28 19:07:13 4: SONOS3: SONOS_Client_Data_Retreive(RINCON_5CAAFD7CE48801400_MR, reading, location, ) -> http://192.168.188.216:1400/xml/device_description.xml
2020.06.28 19:07:13 5: SONOS3: Location: http://192.168.188.216:1400/xml/device_description.xml
2020.06.28 19:07:13 5: SONOS3: PingType: tcp
2020.06.28 19:07:13 4: SONOS3: 192.168.188.216 is alive
2020.06.28 19:08:47 5: SONOS0: Received: 'DoWork:RINCON_5CAAFD7CE48801400_MR:pause:'
2020.06.28 19:08:55 5: SONOS0: Received: 'DoWork:RINCON_5CAAFD7CE48801400_MR:pause:'
2020.06.28 19:08:57 5: SONOS0: Received: 'DoWork:RINCON_5CAAFD7CE48801400_MR:next:'
2020.06.28 19:09:10 4: SONOS1: SONOS_Client_Data_Retreive(SONOS, attr, generateProxyAlbumArtURLs, 0) -> DEFAULT
2020.06.28 19:09:10 5: SONOS1: MakeCoverURL-After: http://cdn-radiotime-logos.tunein.com/s25221g.png
2020.06.28 19:09:10 5: SONOS1: MakeCoverURL-Before: x-rincon-cpcontainer:1006206cspotify%3auser%3aleaweissel%3aplaylist%3a35fizXL4fn3KwjpmGIU2Uf?sid=9&amp;flags=8300&amp;sn=1
2020.06.28 19:09:10 4: SONOS1: SONOS_Client_Data_Retreive(SONOS, attr, generateProxyAlbumArtURLs, 0) -> DEFAULT
2020.06.28 19:09:10 5: SONOS1: MakeCoverURL-After: https://mosaic.scdn.co/300/ab67616d0000b273143aaf19ecc28c7b41d42d9dab67616d0000b2736f1450f3ec5dd82455f266b1ab67616d0000b273b8a84dc61f405ad81e26632bab67616d0000b273cfad3895e54e7f7ddec854d5
2020.06.28 19:09:10 5: SONOS1: MakeCoverURL-Before: x-rincon-cpcontainer:1006206cspotify%3aplaylist%3a2Ud0IwiMTWva6GOaraet61?sid=9&amp;flags=8300&amp;sn=1
2020.06.28 19:09:11 4: SONOS1: SONOS_Client_Data_Retreive(SONOS, attr, generateProxyAlbumArtURLs, 0) -> DEFAULT
2020.06.28 19:09:11 5: SONOS1: MakeCoverURL-After: https://mosaic.scdn.co/300/ab67616d0000b2733502568481ff2ced683d4029ab67616d0000b2739604bf26e3aa4064882e5f36ab67616d0000b273e92a4ced8e2cfbd76fa0c399ab67616d0000b273ef883c94c02915cacc3b5b36
2020.06.28 19:09:11 5: SONOS1: MakeCoverURL-Before: x-rincon-cpcontainer:1006206cspotify%3auser%3aspotify%3aplaylist%3a37i9dQZEVXcCt3lH40S3bp
2020.06.28 19:09:11 4: SONOS1: SONOS_Client_Data_Retreive(SONOS, attr, generateProxyAlbumArtURLs, 0) -> DEFAULT
2020.06.28 19:09:11 5: SONOS1: MakeCoverURL-After: https://newjams-images.scdn.co/v2/discover-weekly/q1979QmlFXErhyKo1u9xfehezJJOHyKrCCUqFKFsYjZoyMDe4vkQ6UoAINelTXHFaVIIOx1ZbIKRFA7VDzaPTf-u4faChk6GMMqXrQ2FpaRvtjMOqSinHTNCOXPowSTlGj3IQJx4GK8FU5T8hoYurGwktqg-I2_oEE1HCBGQwrLRpHtql-BjGxslunWQhHUtbZGCcxR6ex5TvdtFC2O4vqG3GyW5oNvHYEvo-bq1GWWML8lM6Gc0UAjl4bw324qD6XWASJuuGetfBHsL-0V7yQxUjQb4vgEL8KN6aHc9JzwEWXwAWVy2QiHB_0C2OYflg1kTRiLbhKvBF2b1ihDwV57oQFgQk6K2YXnDYDJH9uSMv-TL9eJYlyI1SuTZ6McMWLSe2BHDst2rgH7HOWLLANtNobMDHCFayZ1K6_MIW1E=/NjA6NTA6OTFUMTEtNzAtMA==/default
2020.06.28 19:09:11 5: SONOS1: MakeCoverURL-Before: x-rincon-cpcontainer:1006206cspotify%3aplaylist%3a37i9dQZF1DWVCHIm2MEeIy?sid=9&amp;flags=8300&amp;sn=1
2020.06.28 19:09:11 4: SONOS1: SONOS_Client_Data_Retreive(SONOS, attr, generateProxyAlbumArtURLs, 0) -> DEFAULT
2020.06.28 19:09:11 5: SONOS1: MakeCoverURL-After: https://i.scdn.co/image/ab67706f00000002324739b678f2054b9263b8d2
2020.06.28 19:09:11 5: SONOS1: MakeCoverURL-Before: x-rincon-cpcontainer:0006206cspotify%3auser%3aspotify%3aplaylist%3a1GQLlzxBxKTb6tJsD4RxHI
2020.06.28 19:09:12 4: SONOS1: SONOS_Client_Data_Retreive(SONOS, attr, generateProxyAlbumArtURLs, 0) -> DEFAULT
2020.06.28 19:09:12 5: SONOS1: MakeCoverURL-After:
2020.06.28 19:09:12 5: SONOS1: MakeCoverURL-Before: x-rincon-cpcontainer:1006206cspotify%3auser%3aspotify_germany%3aplaylist%3a5w4R5dh4lY71G60lltHUl0
2020.06.28 19:09:12 4: SONOS1: SONOS_Client_Data_Retreive(SONOS, attr, generateProxyAlbumArtURLs, 0) -> DEFAULT
2020.06.28 19:09:12 5: SONOS1: MakeCoverURL-After: https://mosaic.scdn.co/300/ab67616d0000b2731ee947f0091a57d75a9b10f2ab67616d0000b273a99c0aa70b0b4c4aff2e1543ab67616d0000b273c844214789d3a6c3e336b15dab67616d0000b273fadc923914318c8053172a29
2020.06.28 19:09:12 5: SONOS1: MakeCoverURL-Before: x-rincon-cpcontainer:1006206cspotify%3auser%3afiltr.relax%3aplaylist%3a7yEK13KWGRE87VEFMakZtX?sid=9&amp;flags=8300&amp;sn=1
2020.06.28 19:09:12 4: SONOS1: SONOS_Client_Data_Retreive(SONOS, attr, generateProxyAlbumArtURLs, 0) -> DEFAULT
2020.06.28 19:09:12 5: SONOS1: MakeCoverURL-After: https://i.scdn.co/image/ab67706c0000da84f9c919f812daff1c06667b11
2020.06.28 19:09:12 5: SONOS1: MakeCoverURL-Before: x-rincon-cpcontainer:1006206cspotify%3auser%3adigsterdeutschland%3aplaylist%3a5pvJLjAhcKCHXGOb7pEbBZ?sid=9&amp;flags=8300&amp;sn=1
2020.06.28 19:09:13 4: SONOS1: SONOS_Client_Data_Retreive(SONOS, attr, generateProxyAlbumArtURLs, 0) -> DEFAULT
2020.06.28 19:09:13 5: SONOS1: MakeCoverURL-After: https://i.scdn.co/image/ab67706c0000da84b6dedc044e98d6bb04cf84b4
2020.06.28 19:09:13 5: SONOS1: MakeCoverURL-Before: x-rincon-cpcontainer:1006206cspotify%3auser%3aspotify%3aplaylist%3a37i9dQZF1DXa8NOEUWPn9W?sid=9&amp;flags=8300&amp;sn=1
2020.06.28 19:09:13 4: SONOS1: SONOS_Client_Data_Retreive(SONOS, attr, generateProxyAlbumArtURLs, 0) -> DEFAULT
2020.06.28 19:09:13 5: SONOS1: MakeCoverURL-After: https://i.scdn.co/image/ab67706f000000024caddd511d6e722c8e61460c
2020.06.28 19:09:13 5: SONOS1: MakeCoverURL-Before: x-rincon-cpcontainer:1006206cspotify%3auser%3a21wsee2ctddl7zruhpqhkfkoa%3aplaylist%3a6sk4Hz2WexS5bSplPif87D?sid=9&amp;flags=8300&amp;sn=1
2020.06.28 19:09:13 4: SONOS3: IsAlive-Event UDN=RINCON_5CAAFD7CE48801400_MR
2020.06.28 19:09:13 4: SONOS3: SONOS_Client_Data_Retreive(RINCON_5CAAFD7CE48801400_MR, reading, location, ) -> http://192.168.188.216:1400/xml/device_description.xml
2020.06.28 19:09:13 5: SONOS3: Location: http://192.168.188.216:1400/xml/device_description.xml
2020.06.28 19:09:13 5: SONOS3: PingType: tcp
2020.06.28 19:09:13 4: SONOS3: 192.168.188.216 is alive
2020.06.28 19:09:13 4: SONOS1: SONOS_Client_Data_Retreive(SONOS, attr, generateProxyAlbumArtURLs, 0) -> DEFAULT
2020.06.28 19:09:13 5: SONOS1: MakeCoverURL-After: https://i.scdn.co/image/ab67706c0000da84a79cbda8ddd20ac6e2ce2dd2
2020.06.28 19:09:13 5: SONOS1: MakeCoverURL-Before: x-rincon-cpcontainer:1006206cspotify%3auser%3aspotify_germany%3aplaylist%3a6moshDWncQBzxCod7NXlbj
2020.06.28 19:09:13 4: SONOS1: SONOS_Client_Data_Retreive(SONOS, attr, generateProxyAlbumArtURLs, 0) -> DEFAULT
2020.06.28 19:09:13 5: SONOS1: MakeCoverURL-After:
2020.06.28 19:09:13 5: SONOS1: MakeCoverURL-Before: x-rincon-cpcontainer:000d206cuser-fav%3a5587418
2020.06.28 19:09:13 5: SONOS1: resURL-1: x-rincon-cpcontainer%3A000d206cuser-fav%253a5587418
2020.06.28 19:09:13 5: SONOS1: resURL-2: x-rincon-cpcontainer%3A000d206cuser-fav%253a5587418
2020.06.28 19:09:13 4: SONOS1: SONOS_Client_Data_Retreive(RINCON_5CAAFD7CE48801400_MR, reading, location, ) -> http://192.168.188.216:1400/xml/device_description.xml
2020.06.28 19:09:13 5: SONOS1: resURL-3: http://192.168.188.216:1400/getaa?u=x-rincon-cpcontainer%3A000d206cuser-fav%253a5587418
2020.06.28 19:09:13 4: SONOS1: SONOS_Client_Data_Retreive(SONOS, attr, generateProxyAlbumArtURLs, 0) -> DEFAULT
2020.06.28 19:09:13 5: SONOS1: MakeCoverURL-After: http://192.168.188.216:1400/getaa?u=x-rincon-cpcontainer%3A000d206cuser-fav%253a5587418
2020.06.28 19:09:13 5: SONOS1: MakeCoverURL-Before: x-rincon-cpcontainer:1006206cspotify%3auser%3aspotify%3aplaylist%3a37i9dQZF1DX82pCGH5USnM?sid=9&amp;flags=8300&amp;sn=1
2020.06.28 19:09:14 4: SONOS1: SONOS_Client_Data_Retreive(SONOS, attr, generateProxyAlbumArtURLs, 0) -> DEFAULT
2020.06.28 19:09:14 5: SONOS1: MakeCoverURL-After: https://i.scdn.co/image/ab67706f0000000247717f4647be055f22633d6f
2020.06.28 19:09:14 5: SONOS1: MakeCoverURL-Before: x-sonosapi-stream:s6634?sid=254&amp;flags=8224&amp;sn=0
2020.06.28 19:09:14 5: SONOS1: Radioservice-Metadata: <s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" xmlns:xsd="http://www.w3.org/2001/XMLSchema" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance">
  <s:Body>
    <getMediaMetadataResponse xmlns="http://www.sonos.com/Services/1.1">
      <getMediaMetadataResult>
        <id>s6634</id>
        <title>MDR JUMP</title>
        <itemType>stream</itemType>
        <language>de</language>
        <country>DEU</country>
        <genreId>g3</genreId>
        <genre>Adult Hits</genre>
        <twitterId>mdrjump</twitterId>
        <liveNow>true</liveNow>
        <onDemand>false</onDemand>
        <streamMetadata>
          <bitrate>128</bitrate>
          <reliability>98</reliability>
          <logo>http://cdn-profiles.tunein.com/s6634/images/logoq.jpg?t=1</logo>
          <title>90.4 FM</title>
          <subtitle>Leipzig, Germany</subtitle>
          <secondsRemaining>43200</secondsRemaining>
          <secondsToNextShow>0</secondsToNextShow>
          <nextShowSeconds>0</nextShowSeconds>
        </streamMetadata>
      </getMediaMetadataResult>
    </getMediaMetadataResponse>
  </s:Body>
</s:Envelope>
2020.06.28 19:09:14 4: SONOS1: SONOS_Client_Data_Retreive(SONOS, attr, allowedWebAccess, .*) -> DEFAULT
2020.06.28 19:09:52 5: SONOS0: Received: 'DoWork:undef:refreshProcessAnswer:'


Danach lässt sich der Sonos Player nicht mehr über FHEM steuern! Also muss es doch damit zu tun haben, oder?

Gruß
sTaN
Raspberry Pi 3
2 x CUL CC1101-USB-Lite 868MHz
FS20 Komponenten, Philips HUE, Alexa-Fhem, MAX! Geräte, homebridge, harmony, Unifi, FirtzBox, MQTT, Aurora, Denon, Sonos, TabletUI, CALENDAR, EGPM2LAN, Pushover

sTaN

#378
Hallo Reinerlein,

hier noch weitere neue Erkenntnisse.
Nachdem ich die Attribute für die Favoriten wieder entfern hatte, wollte ich den Sonos One in der Küche hinzufügen. Im Büro ist es ein alter Sonos Play:1 und hier bestätigt sich die zweite Vermutung, dass der Player in der Küche der größte Übeltäter ist.

Nachdem hinzufügen der IP im Attribut usedonlyIPs und anschließendem Löschen des Attributes disable, wurde der Player hinzugefügt aber FHEM war wieder eine Ewigkeit blockiert. In der Zeit habe ich etwas gegessen und um ca. 19:40 Uhr in FHEM den Play Button des Sonos in der Küche betätigt. Danach lief Musik aber FHEM ist wieder blockiert worden.

Habe dann am Player direkt Pause gedrückt, um die Musik zu stoppen. (ca. 19:43 Uhr)
Ich hoffe man sieht in den Logfiles ab dem Hinzufügen (19:26:33 Uhr) des Sonos One in der Küche, wieso es hakt und warum ab 19:40 Uhr FHEM wieder bis ca. 19:58 Uhr für 15 Minuten!

Falls ich das FHEM.log ebenfalls noch anhängen soll, gib bitte kurz Bescheid.

Ich entferne mal wieder den Player in der Küche und füge nach und nach die Restlichen hinzu. Wenn es bei den problemlos klappt, zumindest mal das Ganze Thema eingegrenzt.

Gruß
sTaN

Raspberry Pi 3
2 x CUL CC1101-USB-Lite 868MHz
FS20 Komponenten, Philips HUE, Alexa-Fhem, MAX! Geräte, homebridge, harmony, Unifi, FirtzBox, MQTT, Aurora, Denon, Sonos, TabletUI, CALENDAR, EGPM2LAN, Pushover

Reinerlein

#379
Hi sTaN,

der hängt beim Coverladen für den Radiostream.
Allerdings steht da eigentlich auch ein Timeout (von 5 Sekunden) drin.

Ich habe nochmal ein paar Logausgaben eingebaut, und ein paar andere Fehlerhandlings...

Ich bräuchte also nochmal die langen Logs von dir...

Grüße
Reinerlein

sTaN

Hi Reinerlein,

ich hatte da so eine Vermutung und finde doch tatsächlich einen Thread dazu, dass ggf. mein pi-hole der Übeltäter sein könnte:

https://forum.fhem.de/index.php?topic=74032.0

https://discourse.pi-hole.net/t/what-ports-are-required-for-pihole-to-work/6203/3

Allerdings läuft er auf einem zweiten RPi. Nur dient der auch als DNS Server, wo alle Anfragen durch gehen. Ich hatte jetzt mal den Sonos Port auf 4712 geändert, wie es in dem Thread beschrieben war. Aber scheinbar löst das noch nicht mein Problem. Nachdem ich aber den pi-hole mal heruntergefahren habe, ist FHEM wieder erreichbar und auch die Sonos Player lassen sich bedienen.

Ich werde verrückt! Der pi-hole läuft bereits seit 2 Monaten ca.
Scheinbar macht der aber erst mit meinem Routertausch Probleme. Vermutlich weil sich die Sonos Player nun alle den pi-hole als DNS ziehen...
Raspberry Pi 3
2 x CUL CC1101-USB-Lite 868MHz
FS20 Komponenten, Philips HUE, Alexa-Fhem, MAX! Geräte, homebridge, harmony, Unifi, FirtzBox, MQTT, Aurora, Denon, Sonos, TabletUI, CALENDAR, EGPM2LAN, Pushover

det.

Hallo sTaN,


Ich hatte mal eine Ubiquiti mFi 6- Port Pro Steckdose im FHEM System eingebunden. Die Steckdose ging prima, nur das LAN/ WLAN machte seither komische Sachen. Besonders war Sonos davon betroffen. Verkauf der Steckdose und Ersatz durch z-wave und das Problem war weg. Ich will damit Deine Beobachtung nur bekräftigen, es lohnt durchaus die Fehlfunktion vom Sonos Player auch an ganz anderen Stellen im System zu suchen, die scheinbar gar nichts mit Sonos zu tun haben.
LG
det.

Reinerlein

Hi sTaN,

kannst du denn im piHole sehen, ob der DNS für die Adresse http://cdn-profiles.tunein.com/s9014/images/logoq.jpg?t=157616 geblockt wird?
Das würde auch erklären, warum der Timeout nicht greift...
Er hängt einfach bei der DNS-Auflösung bereits fest.

Grüße
Reinerlein

sTaN

Zitat von: Reinerlein am 28 Juni 2020, 21:14:28
Hi sTaN,

kannst du denn im piHole sehen, ob der DNS für die Adresse http://cdn-profiles.tunein.com/s9014/images/logoq.jpg?t=157616 geblockt wird?
Das würde auch erklären, warum der Timeout nicht greift...
Er hängt einfach bei der DNS-Auflösung bereits fest.

Grüße
Reinerlein

Nein eben genau nicht. Der pi-hole hat auf von meinem RPi mit FHEM oder den Sonos Playern nichts geblockt bisher! Deshalb bin ich auch relativ schnell wieder weg von dem Gedanken. Aber da der RPi als DNS fungiert und ich diesen in der FritzBox als Prefered DNS Server gesetzt habe, zieht sich natürlich jedes WLAN device diesen als DNS Server. Bei meinem FHEM RPi hatte ich ihn damals manuell als DNS Server gesetzt.

Was ich nur nicht verstehe, warum treten die Probleme erst mit dem Routertausch auf...Das ist für mich noch nicht logisch. Mein Unifi AP und meine alte FritzBox 6490 wurden zuvor auch schon mit vorhandenem pi-hole mehrfach neugestartet.

Aber für heute brauch ich mal eine Pause. Jetzt muss ich mir was einfallen lassen, wie ich den pi-hole einsetzen kann, ohne FHEM oder Sonos davon zu beeinflussen. Habe temporär mal in der FritzBox den DNS des pi-hole raus genommen. Mal die Tage schauen, ob es wirklich das Problem ist...

Gruß
sTaN
Raspberry Pi 3
2 x CUL CC1101-USB-Lite 868MHz
FS20 Komponenten, Philips HUE, Alexa-Fhem, MAX! Geräte, homebridge, harmony, Unifi, FirtzBox, MQTT, Aurora, Denon, Sonos, TabletUI, CALENDAR, EGPM2LAN, Pushover

Tobias

Hi Reinerlein,

mit der neuen Version kommen jetzt auch wieder die Infos (zb. CurrentTrackProvider) sauber rein wenn die Player die S2 Firmware haben :)

DANKE :)
Maintainer: Text2Speech, TrashCal, MediaList

Meine Projekte: https://github.com/tobiasfaust
* PumpControl v2: allround Bewässerungssteuerung mit ESP und FHEM
* Ein Modbus RS485 zu MQTT Gateway für SolarWechselrichter

Reinerlein

Hi Tobias,

schön, das gilt allerdings auch für die Player mit S1 Firmware...

Ich habe gerade eine neue Version eingecheckt...
Die läuft mittlerweile deutlich stabiler als die bisherige und kann sich selber retten... jetzt müssen wir noch die Probleme finden, weswegen manchmal der SubProzess hängenbleibt...

Grüße
Reinerlein

aski71

#386
Hallo Reinerlein,

ich habe seit dem neuen Modul auch wieder Probleme.

Das passiert scheinbar morgens, wenn zum ersten mal mein Script startet, das Lautsprecher automatisch zuschaltet.
Die Lautsprecher sind nachts stromlos.

Loading device description failed with error: 404 Not Found (Location: http://192.168.2.78:8081/xml/dial.xml) at ./FHEM/00_SONOS.pm line 2475 thread 1.
Loading device description failed with error: 404 Not Found (Location: http://192.168.2.78:8081/xml/dial.xml) at ./FHEM/00_SONOS.pm line 2475 thread 1.
Loading device description failed with error: 404 Not Found (Location: http://192.168.2.78:8081/xml/dial.xml) at ./FHEM/00_SONOS.pm line 2475 thread 1.
Loading device description failed with error: 404 Not Found (Location: http://192.168.2.78:8081/xml/dial.xml) at ./FHEM/00_SONOS.pm line 2475 thread 1.
Use of uninitialized value $resURLtemp in concatenation (.) or string at ./FHEM/00_SONOS.pm line 4650.
Use of uninitialized value $resURLtemp in concatenation (.) or string at ./FHEM/00_SONOS.pm line 4650.
Use of uninitialized value $resURLtemp in concatenation (.) or string at ./FHEM/00_SONOS.pm line 4650.
Use of uninitialized value $resURLtemp in concatenation (.) or string at ./FHEM/00_SONOS.pm line 4650.
Use of uninitialized value $resURLtemp in concatenation (.) or string at ./FHEM/00_SONOS.pm line 4650.
Use of uninitialized value $resURLtemp in concatenation (.) or string at ./FHEM/00_SONOS.pm line 4650.
Use of uninitialized value $resURLtemp in concatenation (.) or string at ./FHEM/00_SONOS.pm line 4650.
Use of uninitialized value $resURLtemp in concatenation (.) or string at ./FHEM/00_SONOS.pm line 4650.
Use of uninitialized value $resURLtemp in concatenation (.) or string at ./FHEM/00_SONOS.pm line 4650.
Use of uninitialized value $resURLtemp in concatenation (.) or string at ./FHEM/00_SONOS.pm line 4650.
Use of uninitialized value $resURLtemp in concatenation (.) or string at ./FHEM/00_SONOS.pm line 4650.
Use of uninitialized value $resURLtemp in concatenation (.) or string at ./FHEM/00_SONOS.pm line 4650.


Und ich bekomme jetzt nach disable/enable das hier:

2020.07.03 07:11:13 1: SONOS0: Kein UPnP-Server gefunden... Starte selber einen und warte 1 Sekunde(n) darauf...
2020.07.03 07:11:14 1: Sonos: Can't connect to localhost:9091: Connection refused

Reinerlein

Hi aski71,

da mischt sich also ein Nicht-Sonosplayer rein.
Kannst du mal bitte auf Verbose-Level 5 den Start des SubProcesses loggen. Dort tauchen dann Logausgaben der Controlpoint auf, wie dieses Ding sich meldet.

Den Fehler mit der Concatenation habe ich nun umgangen. Aber die Ursache könnte sein, dass kein Netz-Zugriff möglich ist. Taucht noch was anderes dazu auf?

Und mit dem Port 9091: Hast du das Modul überhaupt auf den Port konfiguriert?

Grüße
Reinerlein

aski71

#388
Zitat von: Reinerlein am 03 Juli 2020, 13:53:23
Hi aski71,

da mischt sich also ein Nicht-Sonosplayer rein.
Kannst du mal bitte auf Verbose-Level 5 den Start des SubProcesses loggen. Dort tauchen dann Logausgaben der Controlpoint auf, wie dieses Ding sich meldet.

Den Fehler mit der Concatenation habe ich nun umgangen. Aber die Ursache könnte sein, dass kein Netz-Zugriff möglich ist. Taucht noch was anderes dazu auf?

Und mit dem Port 9091: Hast du das Modul überhaupt auf den Port konfiguriert?

Grüße
Reinerlein

Ja. Ist auf 9091 konfiguriert.
Nach shutdown restart kommt die Meldung auch nicht.

Bzgl. der Concatenation: Aktuelle Version aus #345 downloaden? Oder woanders her?

Verbose 5 probier ich mal.

Das kann aber dann mein Problem nicht erklären, oder?

Ich hatte gestern früh und heute früh folgendes:
Bewegungsmelder soll Lautsprecher zu einer Hauptquelle zuschalten: Der Lautsprecher bleibt aber aus.
Obwohl das Sonos Device auf opened steht und alle relevanten Lautsprecher auf appeared.

Disable/enable führte dann zum Portproblem.
Nur Shutdown restart von fhem half.


Die obige IP Adresse ist tatsächlich ein Macbook im Schlafmodus.

sTaN

Heute habe ich FHEM noch mal aktualisiert und er hat die sich die neusten Module vom 30.06. gezogen. Nun funktionieren meine Sonos seit heute morgen wieder wie sie sollen!!!
Ich starte den SuProcess mittlerweile auf dem Port 4721 mittels localhost:4721 30 8 5. In meinem pi-hole habe ich über das Group Management die Sonos Player und meinen Raspberry PI FHEM Server von den Adlists ausgeschlossen.
Stand jetzt sieht es also gut aus und ich hoffe es bleibt dabei! ;-)
Auch das Aktualisieren meine Favoriten über die Attribute funktioniert wieder...

@Reinerlein: Hast du bzgl. noch etwas im Modul verändert oder ist das gerade wieder ein glücklicher Umstand?  ;D
Raspberry Pi 3
2 x CUL CC1101-USB-Lite 868MHz
FS20 Komponenten, Philips HUE, Alexa-Fhem, MAX! Geräte, homebridge, harmony, Unifi, FirtzBox, MQTT, Aurora, Denon, Sonos, TabletUI, CALENDAR, EGPM2LAN, Pushover