Sonos Integration Error ControlPoint.pm line 850

Begonnen von Luco, 12 April 2017, 13:32:04

Vorheriges Thema - Nächstes Thema

Luco

Ich vermute die letzte Fehlermeldung kam dann, da ich den ganzen Sonos Block (siehe meine Nachricht von 10:35:20Uhr) aus der Config genommen habe.
Ich nutze extra ausschließlich define Sonos SONOS localhost:4711 30 5 5 und lasse FHEM die Sonos Boxen selbst entdecken und anlegen, was aber letztlich nicht gelingt wegen
500 Internal Server Error at FHEM/lib/UPnP/ControlPoint.pm line 850 thread 7.

Da komme ich leider nicht weiter.

Reinerlein

Hi Luco,

wie ich schon schrieb, brauche ich ein 5er Log, kurz vor dem Zeitpunkt, wo er aussteigt. Der 500er Server Fehler deutet daraufhin, dass ein Soap-Befehl an ein Device gesendet wurde, welches diesen nicht versteht (weil es z.B. kein Sonosplayer ist, oder irgend etwas anderes)...
Das müssen wir finden...

Grüße
Reinerlein

Luco

#17
Hallo,

ich habe sowohl bei den beiden Playern als auch global verbose auf 5 gesetzt.
Das sind die letzten Zeilen mit Sonos Bezug kurz vor dem 500er Error:

2017.04.28 20:09:51 2: SONOS13: SonosPlayer 'Wohnzimmer' (S1) with ID 'RINCON_5CAAFD7BFE3001400_MR' is already defined (as 'Sonos_Wohnzimmer') and will only be updated
2017.04.28 20:09:52 2: SONOS13: SonosPlayer 'Wohnzimmer' is now updated
2017.04.28 20:09:52 5: SONOS0: Received from UPnP-Server: 'getstore('http://192.168.178.65:1400/img/icon-S1.png', $attr{global}{modpath}.'/www/images/default/icoSONOSPLAYER_icon-S1.png');'
2017.04.28 20:09:52 5: SONOS0: MainTrigger()-Line: getstore('http://192.168.178.65:1400/img/icon-S1.png', $attr{global}{modpath}.'/www/images/default/icoSONOSPLAYER_icon-S1.png');
2017.04.28 20:09:52 2: SONOS13: Service-subscribing successful with SID=uuid:RINCON_5CAAFD7BFE3001400_sub0000000349
2017.04.28 20:09:52 5: SONOS0: Received from UPnP-Server: 'SONOS_RefreshIconsInFHEMWEB('/www/images/default/icoSONOSPLAYER_icon-S1.png');'
2017.04.28 20:09:52 5: SONOS0: MainTrigger()-Line: SONOS_RefreshIconsInFHEMWEB('/www/images/default/icoSONOSPLAYER_icon-S1.png');
2017.04.28 20:09:52 5: Cmd: >set WEB rereadicons<
2017.04.28 20:09:52 2: SONOS13: Rendering-Service-subscribing successful with SID=uuid:RINCON_5CAAFD7BFE3001400_sub0000000350
2017.04.28 20:09:52 2: SONOS13: GroupRendering-Service-subscribing successful with SID=uuid:RINCON_5CAAFD7BFE3001400_sub0000000351
2017.04.28 20:09:52 2: SONOS13: ContentDirectory-Service-subscribing successful with SID=uuid:RINCON_5CAAFD7BFE3001400_sub0000000352
2017.04.28 20:09:52 2: SONOS13: Alarm-Service-subscribing successful with SID=uuid:RINCON_5CAAFD7BFE3001400_sub0000000353
2017.04.28 20:09:52 5: Starting notify loop for WEB, 1 event(s), first is rereadicons
2017.04.28 20:09:52 5: End notify loop for WEB
2017.04.28 20:09:52 5: SONOS0: Received from UPnP-Server: 'ReadingsBeginUpdate:RINCON_5CAAFD7BFE3001400_MR'
2017.04.28 20:09:52 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7BFE3001400_MR:presence:appeared'
2017.04.28 20:09:52 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7BFE3001400_MR:Volume:9'
2017.04.28 20:09:52 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7BFE3001400_MR:Balance:0'
2017.04.28 20:09:52 2: SONOS13: ZoneGroupTopology-Service-subscribing successful with SID=uuid:RINCON_5CAAFD7BFE3001400_sub0000000354
2017.04.28 20:09:52 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7BFE3001400_MR:roomName:Wohnzimmer'
2017.04.28 20:09:52 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7BFE3001400_MR:roomNameAlias:Wohnzimmer - Links'
2017.04.28 20:09:52 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7BFE3001400_MR:saveRoomName:Wohnzimmer'
2017.04.28 20:09:52 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7BFE3001400_MR:playerType:S1'
2017.04.28 20:09:52 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7BFE3001400_MR:Volume:9'
2017.04.28 20:09:52 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7BFE3001400_MR:location:http://192.168.178.65:1400/xml/device_description.xml'
2017.04.28 20:09:52 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7BFE3001400_MR:softwareRevision:7.2'
2017.04.28 20:09:52 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7BFE3001400_MR:serialNum:5C-AA-FD-7B-FE-30:F'
2017.04.28 20:09:52 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7BFE3001400_MR:fieldType:LF'
2017.04.28 20:09:52 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7BFE3001400_MR:IsBonded:0'
2017.04.28 20:09:52 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7BFE3001400_MR:IsMaster:1'
2017.04.28 20:09:52 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7BFE3001400_MR:MasterPlayer:Sonos_Wohnzimmer'
2017.04.28 20:09:52 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7BFE3001400_MR:SlavePlayer:['Sonos_Wohnzimmer_RF']'
2017.04.28 20:09:52 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7BFE3001400_MR:SlavePlayerNotBonded:[]'
2017.04.28 20:09:52 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7BFE3001400_MR:transportState:STOPPED'
2017.04.28 20:09:52 2: SONOS13: DeviceProperties-Service-subscribing successful with SID=uuid:RINCON_5CAAFD7BFE3001400_sub0000000355
2017.04.28 20:09:52 3: SONOS13: Discover: End of discover-event for "Wohnzimmer".
2017.04.28 20:09:52 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7BFE3001400_MR:currentTrackURI:x-rincon-mp3radio://http://1live.akacast.akamaistream.net/7/706/119434/v1/gnl.akacast.akamaistream.net/1live'
2017.04.28 20:09:52 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7BFE3001400_MR:currentTrackProvider:'
2017.04.28 20:09:52 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7BFE3001400_MR:currentTrackDuration:0:00:00'
2017.04.28 20:09:52 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7BFE3001400_MR:currentTrackPosition:0:00:00'
2017.04.28 20:09:52 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7BFE3001400_MR:currentTrackPositionSec:1'
2017.04.28 20:09:52 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7BFE3001400_MR:currentTrack:1'
2017.04.28 20:09:52 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7BFE3001400_MR:numberOfTracks:1'
2017.04.28 20:09:52 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7BFE3001400_MR:currentStreamAudio:1'
2017.04.28 20:09:52 5: SONOS0: Received from UPnP-Server: 'ReadingsBulkUpdateIfChanged:RINCON_5CAAFD7BFE3001400_MR:currentNormalAudio:'
2017.04.28 20:09:52 3: SONOS13: Event: Received Transport-Event for Zone "Sonos_Wohnzimmer_RF".
2017.04.28 20:09:52 5: SONOS0: Received from UPnP-Server: 'ReadingsEndUpdate:RINCON_5CAAFD7BFE3001400_MR'
2017.04.28 20:09:52 5: Starting notify loop for Sonos_Wohnzimmer, 1 event(s), first is presence: appeared
2017.04.28 20:09:52 5: Sonos_WohnzimmerRG: not on any display, ignoring notify
2017.04.28 20:09:52 5: Sonos_WohnzimmerRG_Favourites: not on any display, ignoring notify
2017.04.28 20:09:52 5: Sonos_WohnzimmerRG_Playlists: not on any display, ignoring notify
2017.04.28 20:09:52 5: Sonos_WohnzimmerRG_Queue: not on any display, ignoring notify
2017.04.28 20:09:52 5: Sonos_WohnzimmerRG_Radios: not on any display, ignoring notify
2017.04.28 20:09:52 5: End notify loop for Sonos_Wohnzimmer
2017.04.28 20:09:52 5: SONOS0: Received from UPnP-Server: 'CommandAttrWithUDN:RINCON_5CAAFD7BFE3001400_MR:model Sonos_S1'
2017.04.28 20:09:52 5: Starting notify loop for global, 1 event(s), first is ATTR Sonos_Wohnzimmer model Sonos_S1
2017.04.28 20:09:52 5: End notify loop for global
2017.04.28 20:09:52 2: SONOS13: Error during UPnP-Handling: 500 Internal Server Error at FHEM/lib/UPnP/ControlPoint.pm line 850 thread 13.

2017.04.28 20:09:52 3: SONOS13: UPnP-Thread wurde beendet.


Zur Konstellation:
Aktuell gibt es einen Play1 Sonos_Wohnzimmer und einen weiteren Play1 als Stereopaar eingerichtet mit Sonos_Wohnzimmer_RF

Was mich halt wundert. Ihr meint die Definitionen der beiden Player sieht in FHEM korrekt aus. der 500er Fehler kommt immer "nur", wenn FHEM checkt ob es neue Player gibt?
Warum funktioniert dann das einfache Steuern der Player nicht über FHEM? Ich hatte das nur einmalig laufen, als ich die Player jeweils separat alleine konfiguriert hatte ohne Gruppe oder Stereopaar.

Reinerlein

Hi Luco,

irgendwie kommen keine 5er Logmeldungen aus dem SubProzess im Log an.
Hast du am Sonos-Device Verbose auf 5 gesetzt?

Grüße
Reinerlein