Autor Thema: Sonos Player disappeared  (Gelesen 32384 mal)

Offline sTaN

  • Full Member
  • ***
  • Beiträge: 315
Antw:Sonos Player disappeared
« Antwort #375 am: 28 Juni 2020, 16:42:44 »
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
CUL CC1101-USB-Lite 868MHz
FS20 Komponenten, Philips HUE, Alexa-Fhem, MAX! Geräte, harmony, Unifi, FirtzBox

Offline Reinerlein

  • Developer
  • Hero Member
  • ****
  • Beiträge: 2083
Antw:Sonos Player disappeared
« Antwort #376 am: 28 Juni 2020, 17:05:07 »
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

Offline sTaN

  • Full Member
  • ***
  • Beiträge: 315
Antw:Sonos Player disappeared
« Antwort #377 am: 28 Juni 2020, 18:29:38 »
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 perl5. 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
« Letzte Änderung: 28 Juni 2020, 19:14:31 von sTaN »
Raspberry Pi 3
CUL CC1101-USB-Lite 868MHz
FS20 Komponenten, Philips HUE, Alexa-Fhem, MAX! Geräte, harmony, Unifi, FirtzBox

Offline sTaN

  • Full Member
  • ***
  • Beiträge: 315
Antw:Sonos Player disappeared
« Antwort #378 am: 28 Juni 2020, 19:59:45 »
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

« Letzte Änderung: 28 Juni 2020, 20:03:27 von sTaN »
Raspberry Pi 3
CUL CC1101-USB-Lite 868MHz
FS20 Komponenten, Philips HUE, Alexa-Fhem, MAX! Geräte, harmony, Unifi, FirtzBox

Offline Reinerlein

  • Developer
  • Hero Member
  • ****
  • Beiträge: 2083
Antw:Sonos Player disappeared
« Antwort #379 am: 28 Juni 2020, 20:27:45 »
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
« Letzte Änderung: 30 Juni 2020, 12:47:30 von Reinerlein »

Offline sTaN

  • Full Member
  • ***
  • Beiträge: 315
Antw:Sonos Player disappeared
« Antwort #380 am: 28 Juni 2020, 20:43:38 »
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
CUL CC1101-USB-Lite 868MHz
FS20 Komponenten, Philips HUE, Alexa-Fhem, MAX! Geräte, harmony, Unifi, FirtzBox

Offline det.

  • Hero Member
  • *****
  • Beiträge: 1292
Antw:Sonos Player disappeared
« Antwort #381 am: 28 Juni 2020, 21:06:53 »
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.

Offline Reinerlein

  • Developer
  • Hero Member
  • ****
  • Beiträge: 2083
Antw:Sonos Player disappeared
« Antwort #382 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

Offline sTaN

  • Full Member
  • ***
  • Beiträge: 315
Antw:Sonos Player disappeared
« Antwort #383 am: 28 Juni 2020, 21:21:25 »
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
CUL CC1101-USB-Lite 868MHz
FS20 Komponenten, Philips HUE, Alexa-Fhem, MAX! Geräte, harmony, Unifi, FirtzBox

Offline Tobias

  • Developer
  • Hero Member
  • ****
  • Beiträge: 3826
Antw:Sonos Player disappeared
« Antwort #384 am: 30 Juni 2020, 10:51:56 »
Hi Reinerlein,

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

DANKE :)
FHEM auf ASRock J3455-ITX im 19" Rack mit Homematic, MAX, PCA301, Panstamps, RPi für BLE Bodenfeuchtesenoren, Text2Speech.
Maintainer der Module: Text2Speech, TrashCal, MediaList

Meine Projekte auf https://github.com/tobiasfaust
u.a. PumpControl v2: allround Bewässerungssteuerung mit ESP und FHEM

Offline Reinerlein

  • Developer
  • Hero Member
  • ****
  • Beiträge: 2083
Antw:Sonos Player disappeared
« Antwort #385 am: 30 Juni 2020, 12:56:19 »
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
Gefällt mir Gefällt mir x 6 Liste anzeigen

Offline aski71

  • Full Member
  • ***
  • Beiträge: 287
Antw:Sonos Player disappeare
« Antwort #386 am: 03 Juli 2020, 07:07:59 »
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
« Letzte Änderung: 03 Juli 2020, 07:17:33 von aski71 »

Offline Reinerlein

  • Developer
  • Hero Member
  • ****
  • Beiträge: 2083
Antw:Sonos Player disappeared
« Antwort #387 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

Offline aski71

  • Full Member
  • ***
  • Beiträge: 287
Antw:Sonos Player disappeared
« Antwort #388 am: 03 Juli 2020, 15:32:47 »
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.
« Letzte Änderung: 03 Juli 2020, 15:46:39 von aski71 »

 

decade-submarginal