music-assistant / hass-music-assistant

Turn your Home Assistant instance into a jukebox, hassle free streaming of your favorite media to Home Assistant media players.
Apache License 2.0
1.31k stars 47 forks source link

SONOS players unavailable when S1 and S2 speakers are connected to the network #1184

Closed ranoydegraaf closed 1 year ago

ranoydegraaf commented 1 year ago

What version of Music Assistant has the issue?

2.0.0b27

The problem

When SONOS speakers from the S1 and S2 app are connected at the samen time, the S2 speakers are unavaible through Music Asisstant

How to reproduce

Connect S1 and S2 speaker to your network

Relevant log output

No response

Additional information

No response

What version of Home Assistant Core are your running

2023.4.0

What type of installation are you running?

Home Assistant OS

On what type of hardware are you running?

Generic x86-64 (e.g. Intel NUC)

OzGav commented 1 year ago

Sorry the MA version you have indicated above is not valid. Please recheck and amend

ranoydegraaf commented 1 year ago

Sorry the MA version you have indicated above is not valid. Please recheck and amend

Sorry, edited the original post.

OzGav commented 1 year ago

You wrote

When SONOS speakers from the S1 and S2 app are connected

I don’t use SONOS but looking online it appears that S1 and S2 are different apps and only certain speakers work with those apps. If that is correct then I think you need to specify the speaker models that aren’t working instead of referring to the apps (as they won’t have anything to do with MA)

DutchJaFO commented 1 year ago

the S2 app is supposed to have replaced the S1 app. I've got both versions of Sonos speakers on my network (Sonos Play:1 original, Ikea Symfonysk). I haven't upgraded HA itself to 2023.4 version as I'm still using the automations that MA v1 has in 2023.2.5

note : there is a known issue with the Sonos speaker and access to the queue in MA v2 when someone has used the Sonos app to play music through the Sonos speakers. I believe that issue will be fixed in the next beta after v2b27.

OzGav commented 1 year ago

So is there a confirmed issue here?

DutchJaFO commented 1 year ago

in v2b27 there was an issue whenever the Sonos app was used to play music. This is resolved in v2b29 However as of that version I am unable to play anything on my Sonos system from the MA v2 music player.

Given that I've got both versions of the Sonos speakers on my network I suspect that whatever was changed is now causing issues on my system.

Possibly related : I have HAOS updated to v10

marcelveldt commented 1 year ago

Is there anything related in the logs ? What happens when you start playback ? Does the app show anything ? Does playback to another playback device work ?

DutchJaFO commented 1 year ago

The discovery/startup of MA v2b29 was showing errors in the log for one of the Sonos speakers.

I had posted in the discord thread on my issues with v2b29:

Traceback (most recent call last): File "/usr/local/lib/python3.11/site-packages/music_assistant/server/providers/websocket_api/init.py", line 244, in _run_handler result = await result ^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/music_assistant/server/controllers/player_queues.py", line 213, in play_media await self.play_index(queue_id, 0) File "/usr/local/lib/python3.11/site-packages/music_assistant/server/controllers/player_queues.py", line 487, in play_index await player_prov.cmd_play_media( File "/usr/local/lib/python3.11/site-packages/music_assistant/server/providers/sonos/init.py", line 321, in cmd_play_media await self._enqueue_item( File "/usr/local/lib/python3.11/site-packages/music_assistant/server/providers/sonos/init.py", line 591, in _enqueue_item await asyncio.to_thread( File "/usr/local/lib/python3.11/asyncio/threads.py", line 25, in to_thread return await loop.run_in_executor(None, func_call) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/concurrent/futures/thread.py", line 58, in run result = self.fn(self.args, self.kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/soco/services.py", line 206, in _dispatcher return self.send_command(action,args, kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/soco/services.py", line 514, in send_command self.handle_upnp_error(response.text) File "/usr/local/lib/python3.11/site-packages/soco/services.py", line 567, in handle_upnp_error raise SoCoUPnPException( soco.exceptions.SoCoUPnPException: UPnP Error 804 received: from 192.168.0.121 restarted v2b29 again .. Exception occurred during processing of request from ('192.168.0.134', 42372) Traceback (most recent call last): File "/usr/local/lib/python3.11/socketserver.py", line 691, in process_request_thread self.finish_request(request, client_address) File "/usr/local/lib/python3.11/socketserver.py", line 361, in finish_request self.RequestHandlerClass(request, client_address, self) File "/usr/local/lib/python3.11/site-packages/soco/events.py", line 98, in init super().init(*args, **kwargs) File "/usr/local/lib/python3.11/socketserver.py", line 755, in init self.handle() File "/usr/local/lib/python3.11/http/server.py", line 432, in handle self.handle_one_request() File "/usr/local/lib/python3.11/http/server.py", line 420, in handle_one_request method() File "/usr/local/lib/python3.11/site-packages/soco/events.py", line 107, in do_NOTIFY self.handle_notification(headers, content) File "/usr/local/lib/python3.11/site-packages/soco/events_base.py", line 234, in handle_notification variables = parse_event_xml(content) ^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/soco/events_base.py", line 104, in parse_event_xml value = from_didl_string(value)[0] ^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/soco/data_structures_entry.py", line 31, in from_didl_string root = XML.fromstring(string.encode("utf-8")) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/xml/etree/ElementTree.py", line 1338, in XML parser.feed(text) xml.etree.ElementTree.ParseError: not well-formed (invalid token): line 1, column 768

DutchJaFO commented 1 year ago

new clean install of v2b29

Expected result : playback starts within a few seconds

Actual result : no playback and the queue claiming it is 'empty' : Screenshot image

Log entry : 2023-04-21 18:22:01 ERROR music_assistant.websocket_api -- [140241466388944] Error handling message: CommandMessage(message_id=11, command='players/queue/play_media', args={'queue_id': 'RINCON_B8E9378C73DC01400', 'media': [{'item_id': 'Weird Al Yankovic/Mandatory Fun', 'provider': 'filesystem_smb', 'name': 'Mandatory Fun', 'provider_mappings': [{'item_id': 'Weird Al Yankovic/Mandatory Fun', 'provider_domain': 'filesystem_smb', 'provider_instance': 'filesystem_smb', 'available': True, 'content_type': '?', 'sample_rate': 44100, 'bit_depth': 16, 'bit_rate': 320, 'details': None, 'url': 'Weird Al Yankovic/Mandatory Fun'}], 'metadata': {'description': None, 'review': None, 'explicit': None, 'images': [{'type': 'thumb', 'path': 'Weird Al Yankovic/Mandatory Fun/cover.jpg', 'provider': 'filesystem_smb'}], 'genres': None, 'mood': None, 'style': None, 'copyright': None, 'lyrics': None, 'ean': None, 'label': None, 'links': None, 'chapters': None, 'performers': None, 'preview': None, 'replaygain': None, 'popularity': None, 'last_refresh': 1682094118, 'checksum': '1681926723'}, 'in_library': False, 'media_type': 'album', 'sort_name': 'mandatory fun', 'uri': 'filesystem_smb://album/Weird Al Yankovic/Mandatory Fun', 'timestamp_added': 0, 'timestamp_modified': 0, 'version': '', 'year': 2014, 'artists': [{'item_id': 'Weird Al Yankovic', 'provider': 'filesystem_smb', 'name': '"Weird Al" Yankovic', 'provider_mappings': [{'item_id': 'Weird Al Yankovic', 'provider_domain': 'filesystem_smb', 'provider_instance': 'filesystem_smb', 'available': True, 'content_type': '?', 'sample_rate': 44100, 'bit_depth': 16, 'bit_rate': 320, 'details': None, 'url': 'Weird Al Yankovic'}], 'metadata': {'description': None, 'review': None, 'explicit': None, 'images': None, 'genres': None, 'mood': None, 'style': None, 'copyright': None, 'lyrics': None, 'ean': None, 'label': None, 'links': None, 'chapters': None, 'performers': None, 'preview': None, 'replaygain': None, 'popularity': None, 'last_refresh': None, 'checksum': '1681926723'}, 'in_library': False, 'media_type': 'artist', 'sort_name': '"weird al" yankovic', 'uri': 'filesystem_smb://artist/Weird Al Yankovic', 'timestamp_added': 0, 'timestamp_modified': 0, 'musicbrainz_id': '7746d775-9550-4360-b8d5-c37bd448ce01'}], 'album_type': 'album', 'barcode': ['888430937529'], 'musicbrainz_id': '958cacd0-22e9-4e74-8cc8-2a61acce9fbe'}], 'option': 'replace'}) Traceback (most recent call last): File "/usr/local/lib/python3.11/site-packages/music_assistant/server/providers/websocket_api/init.py", line 244, in _run_handler result = await result ^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/music_assistant/server/controllers/player_queues.py", line 213, in play_media await self.play_index(queue_id, 0) File "/usr/local/lib/python3.11/site-packages/music_assistant/server/controllers/player_queues.py", line 487, in play_index await player_prov.cmd_play_media( File "/usr/local/lib/python3.11/site-packages/music_assistant/server/providers/sonos/init.py", line 321, in cmd_play_media await self._enqueue_item( File "/usr/local/lib/python3.11/site-packages/music_assistant/server/providers/sonos/init.py", line 591, in _enqueue_item await asyncio.to_thread( File "/usr/local/lib/python3.11/asyncio/threads.py", line 25, in to_thread return await loop.run_in_executor(None, func_call) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/concurrent/futures/thread.py", line 58, in run result = self.fn(*self.args, *self.kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/soco/services.py", line 206, in _dispatcher return self.send_command(action, args, **kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/soco/services.py", line 514, in send_command self.handle_upnp_error(response.text) File "/usr/local/lib/python3.11/site-packages/soco/services.py", line 567, in handle_upnp_error raise SoCoUPnPException( soco.exceptions.SoCoUPnPException: UPnP Error 804 received: from 192.168.0.121

DutchJaFO commented 1 year ago

= disabled UPnP, Airplay and Chromecast = restarted MA

log is showing this : 2023-04-21 18:28:35 INFO music_assistant.players -- Player registered: RINCON_B8E9378C73DC01400/Slaapkamer 2023-04-21 18:28:35 WARNING asyncio -- Executing <Task pending name='Task-26' coro=<SonosPlayerProvider._run_discovery() running at /usr/local/lib/python3.11/site-packages/music_assistant/server/providers/sonos/init.py:428> wait_for=<Future pending cb=[_chain_future.._call_check_cancel() at /usr/local/lib/python3.11/asyncio/futures.py:387, Task.task_wakeup()] created at /usr/local/lib/python3.11/asyncio/base_events.py:427> cb=[MusicAssistant.create_task..task_done_callback() at /usr/local/lib/python3.11/site-packages/music_assistant/server/server.py:261] created at /usr/local/lib/python3.11/site-packages/music_assistant/server/server.py:254> took 0.124 seconds 2023-04-21 18:28:35 INFO music_assistant.players -- Player registered: RINCON_949F3EF61A0801400/Hobbyruimte 2023-04-21 18:28:35 INFO music_assistant.providers.slimproto -- Starting SLIMProto server on port 3483 2023-04-21 18:28:35 INFO music_assistant -- Loaded player provider Slimproto 2023-04-21 18:28:36 WARNING asyncio -- Executing <Task finished name='Task-2' coro=<run..new_coro() done, defined at /usr/local/lib/python3.11/site-packages/aiorun.py:227> result=None> took 0.804 seconds

starting playback of the same album resulted in the same error again : raceback (most recent call last): File "/usr/local/lib/python3.11/site-packages/music_assistant/server/providers/websocket_api/init.py", line 244, in _run_handler result = await result ^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/music_assistant/server/controllers/player_queues.py", line 213, in play_media await self.play_index(queue_id, 0) File "/usr/local/lib/python3.11/site-packages/music_assistant/server/controllers/player_queues.py", line 487, in play_index await player_prov.cmd_play_media( File "/usr/local/lib/python3.11/site-packages/music_assistant/server/providers/sonos/init.py", line 321, in cmd_play_media await self._enqueue_item( File "/usr/local/lib/python3.11/site-packages/music_assistant/server/providers/sonos/init.py", line 591, in _enqueue_item await asyncio.to_thread( File "/usr/local/lib/python3.11/asyncio/threads.py", line 25, in to_thread return await loop.run_in_executor(None, func_call) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/concurrent/futures/thread.py", line 58, in run result = self.fn(*self.args, *self.kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/soco/services.py", line 206, in _dispatcher return self.send_command(action, args, **kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/soco/services.py", line 514, in send_command self.handle_upnp_error(response.text) File "/usr/local/lib/python3.11/site-packages/soco/services.py", line 567, in handle_upnp_error raise SoCoUPnPException( soco.exceptions.SoCoUPnPException: UPnP Error 804 received: from 192.168.0.121

DutchJaFO commented 1 year ago

with only the Sonos provider I'm noticing 2 distinct issues : (1) the stereo-pair is listed as 'Slaapkamer +1'

(2) some sort of XML parsing error :```

Exception occurred during processing of request from ('192.168.0.134', 55154) Traceback (most recent call last): File "/usr/local/lib/python3.11/socketserver.py", line 691, in process_request_thread self.finish_request(request, client_address) File "/usr/local/lib/python3.11/socketserver.py", line 361, in finish_request self.RequestHandlerClass(request, client_address, self) File "/usr/local/lib/python3.11/site-packages/soco/events.py", line 98, in init super().init(*args, **kwargs) File "/usr/local/lib/python3.11/socketserver.py", line 755, in init self.handle() File "/usr/local/lib/python3.11/http/server.py", line 432, in handle self.handle_one_request() File "/usr/local/lib/python3.11/http/server.py", line 420, in handle_one_request method() File "/usr/local/lib/python3.11/site-packages/soco/events.py", line 107, in do_NOTIFY self.handle_notification(headers, content) File "/usr/local/lib/python3.11/site-packages/soco/events_base.py", line 234, in handle_notification variables = parse_event_xml(content) ^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/soco/events_base.py", line 104, in parse_event_xml value = from_didl_string(value)[0] ^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/soco/data_structures_entry.py", line 31, in from_didl_string root = XML.fromstring(string.encode("utf-8")) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/xml/etree/ElementTree.py", line 1338, in XML parser.feed(text) xml.etree.ElementTree.ParseError: not well-formed (invalid token): line 1, column 768

DutchJaFO commented 1 year ago

after ungrouping the speakers in Sonos app : = Hobbyruimte (Sonos Player:1) : no playback, error in log = Huiskamer (Sonos Port) is functional = Keuken (Ikea Symfonysk) is functional = Slaapkamer (paired Sonos Player:1) :no playback, error in log

It looks like only the v2 devices are functioning as expected. The v1 Sonos devices do not work.

DutchJaFO commented 1 year ago

Error is pretty consistent :

2023-04-22 01:36:39 ERROR music_assistant.websocket_api -- [139930763877072] Error handling message: CommandMessage(message_id=31, command='players/queue/play_media', args={'queue_id': 'RINCON_949F3EF61A0801400', 'media': [{'item_id': '212', 'provider': 'database', 'name': 'Mandatory Fun', 'provider_mappings': [{'item_id': 'Weird Al Yankovic/Mandatory Fun', 'provider_domain': 'filesystem_smb', 'provider_instance': 'filesystem_smb', 'available': True, 'content_type': '?', 'sample_rate': 44100, 'bit_depth': 16, 'bit_rate': 320, 'details': None, 'url': 'Weird Al Yankovic/Mandatory Fun'}], 'metadata': {'description': 'Mandatory Fun is the fourteenth studio album by American musician "Weird Al" Yankovic. Self-produced, the album was released by RCA Records in the United States on July 15, 2014. The release includes parodies of songs by Pharrell Williams, Robin Thicke, Iggy Azalea, Lorde and Imagine Dragons. It also features original songs in the form of pastiche, imitating the styles of the Pixies; Cat Stevens; Foo Fighters; Crosby, Stills & Nash; and Southern Culture on the Skids. During the closing stages of the Alpocalypse tour, Yankovic stated in an interview with The Morning Call that he had one more album on his contract; the paper and other sources took to mean that this album would be his last. Yankovic later clarified that this was the last album on the current recording contract with his label, that he is currently "weighing his options" for renewing the contract or looking to another publisher, and made it clear that he was not retiring from music in the foreseeable future. In a later interview with NPR\'s "Weekend Edition", he stated that this might be his last conventional album, turning instead to more frequent releases of singles and EPs, as with the time between producing full-length albums, "chances are a lot of the material is going to be somewhat dated by the time it comes out".\n\nThe first tracks conceived for the album were original songs in the style of various bands as, compared to direct parodies, the pastiches "age better". Prior to composing these songs, he had been listening to older acts such as Cat Stevens, Foo Fighters, and Southern Culture on the Skids for his own amusement. His Crosby, Stills & Nash style parody "Mission Statement" draws from his experiences attending executive meetings in his music career. Shortly after completing the song, Yankovic encountered Graham Nash, who coincidentally asked Yankovic to parody a Crosby, Stills & Nash song. "First World Problems" is an original composition emulating the style of the Pixies, whom Yankovic had performed alongside for a charity concert two years prior.\n\nYankovic noted that his usual method of generating parody ideas is to scan Billboard charts, radio play and online buzz in order to create a master list of candidates. From that point, he works out possible puns on the song titles, the potential for humor and general direction for his versions. Fans speculated ahead of the album\'s release that Yankovic would parody "Let It Go" from the Disney film Frozen, due to the song\'s popularity. He later explained that he considered making a Frozen parody titled "Make It So" about Star Trek: The Next Generation, but decided not to after discovering such a parody already existed. Yankovic observed that the existing spoof "had gotten enough attention online to make the Disney legal department ask them to take it down! I couldn\'t think of an idea that I liked as much as \'Make It So\', so... I gave up!".', 'review': '', 'explicit': None, 'images': [{'type': 'thumb', 'path': 'Weird Al Yankovic/Mandatory Fun/cover.jpg', 'provider': 'filesystem_smb'}], 'genres': ['Comedy'], 'mood': 'Humorous', 'style': 'Urban/R&B', 'copyright': None, 'lyrics': None, 'ean': None, 'label': 'RCA', 'links': [{'type': 'wikipedia', 'url': 'https://wikipedia.org/wiki/Mandatory_Fun'}, {'type': 'allmusic', 'url': 'https://www.allmusic.com/album/mw0002694675'}], 'chapters': None, 'performers': None, 'preview': None, 'replaygain': None, 'popularity': None, 'last_refresh': 1682094118, 'checksum': '1681926723'}, 'in_library': False, 'media_type': 'album', 'sort_name': 'mandatory fun', 'uri': 'database://album/212', 'timestamp_added': 1682093304, 'timestamp_modified': 1682094118, 'version': '', 'year': 2014, 'artists': [{'item_id': '202', 'provider': 'database', 'name': '"Weird Al" Yankovic', 'provider_mappings': [{'item_id': 'Weird Al Yankovic', 'provider_domain': 'filesystem_smb', 'provider_instance': 'filesystem_smb', 'available': True, 'content_type': '?', 'sample_rate': 44100, 'bit_depth': 16, 'bit_rate': 320, 'details': None, 'url': 'Weird Al Yankovic'}, {'item_id': '"Weird Al" Yankovic', 'provider_domain': 'filesystem_smb', 'provider_instance': 'filesystem_smb', 'available': True, 'content_type': '?', 'sample_rate': 44100, 'bit_depth': 16, 'bit_rate': 320, 'details': None, 'url': '"Weird Al" Yankovic'}], 'metadata': {'description': 'Alfred Matthew "Weird Al" Yankovic born October 23, 1959) is an American singer-songwriter, music producer, accordionist, actor, comedian, writer, satirist, and parodist. Yankovic is known for his humorous songs that make light of popular culture and that often parody specific songs by contemporary musical acts. Since his first-aired comedy song in 1976, he has sold more than 12 million albums (as of 2007), recorded more than 150 parody and original songs, and has performed more than 1,000 live shows. His works have earned him three Grammy Awards among nine nominations, four gold records, and six platinum records in the United States. Yankovic\'s first top ten Billboard album (Straight Outta Lynwood) and single ("White & Nerdy") were both released in 2006, nearly three decades into his career.\nYankovic\'s success comes in part from his effective use of music video to further parody popular culture, the song\'s original artist, and the original music videos themselves, scene-for-scene in some cases. He directed later videos himself and went on to direct for other artists including Ben Folds, Hanson, Black Crowes, and The Presidents of the United States of America. In addition to recording his albums, Yankovic wrote and starred in the film, UHF, and television show, The Weird Al Show. He has also made guest appearances on many television shows, in addition to starring in Al TV specials on MTV.', 'review': None, 'explicit': None, 'images': [{'type': 'thumb', 'path': 'http://assets.fanart.tv/fanart/music/7746d775-9550-4360-b8d5-c37bd448ce01/artistthumb/yankovic-weird-al-4ff2db1caec76.jpg', 'provider': 'url'}, {'type': 'thumb', 'path': 'http://assets.fanart.tv/fanart/music/7746d775-9550-4360-b8d5-c37bd448ce01/artistthumb/yankovic-weird-al-51201c0638d1d.jpg', 'provider': 'url'}, {'type': 'logo', 'path': 'http://assets.fanart.tv/fanart/music/7746d775-9550-4360-b8d5-c37bd448ce01/hdmusiclogo/yankovic-weird-al-504f810b1b77b.png', 'provider': 'url'}, {'type': 'logo', 'path': 'http://assets.fanart.tv/fanart/music/7746d775-9550-4360-b8d5-c37bd448ce01/hdmusiclogo/yankovic-weird-al-5a8821f28004e.png', 'provider': 'url'}, {'type': 'logo', 'path': 'http://assets.fanart.tv/fanart/music/7746d775-9550-4360-b8d5-c37bd448ce01/hdmusiclogo/yankovic-weird-al-5a4acc71a230b.png', 'provider': 'url'}, {'type': 'logo', 'path': 'http://assets.fanart.tv/fanart/music/7746d775-9550-4360-b8d5-c37bd448ce01/hdmusiclogo/yankovic-weird-al-55ba8f51c5273.png', 'provider': 'url'}, {'type': 'logo', 'path': 'http://assets.fanart.tv/fanart/music/7746d775-9550-4360-b8d5-c37bd448ce01/hdmusiclogo/yankovic-weird-al-5916d97d9d9db.png', 'provider': 'url'}, {'type': 'banner', 'path': 'http://assets.fanart.tv/fanart/music/7746d775-9550-4360-b8d5-c37bd448ce01/musicbanner/yankovic-weird-al-505b2f1d41068.jpg', 'provider': 'url'}, {'type': 'fanart', 'path': 'http://assets.fanart.tv/fanart/music/7746d775-9550-4360-b8d5-c37bd448ce01/artistbackground/yankovic-weird-al-4ff2dadfebfa4.jpg', 'provider': 'url'}, {'type': 'fanart', 'path': 'http://assets.fanart.tv/fanart/music/7746d775-9550-4360-b8d5-c37bd448ce01/artistbackground/yankovic-weird-al-4ff2dad4c8284.jpg', 'provider': 'url'}], 'genres': ['Comedy'], 'mood': 'Humorous', 'style': 'Urban/R&B', 'copyright': None, 'lyrics': None, 'ean': None, 'label': None, 'links': [{'type': 'website', 'url': 'www.weirdal.com'}, {'type': 'twitter', 'url': '1'}, {'type': 'facebook', 'url': 'www.facebook.com/weirdal'}], 'chapters': None, 'performers': None, 'preview': None, 'replaygain': None, 'popularity': None, 'last_refresh': 1682094118, 'checksum': '1681926723'}, 'in_library': False, 'media_type': 'artist', 'sort_name': '"weird al" yankovic', 'uri': 'database://artist/202', 'timestamp_added': 1682093288, 'timestamp_modified': 1682094118, 'musicbrainz_id': '7746d775-9550-4360-b8d5-c37bd448ce01'}], 'album_type': 'album', 'barcode': ['888430937529'], 'musicbrainz_id': '958cacd0-22e9-4e74-8cc8-2a61acce9fbe'}], 'option': 'replace'}) Traceback (most recent call last): File "/usr/local/lib/python3.11/site-packages/music_assistant/server/providers/websocket_api/init.py", line 244, in _run_handler result = await result ^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/music_assistant/server/controllers/player_queues.py", line 213, in play_media await self.play_index(queue_id, 0) File "/usr/local/lib/python3.11/site-packages/music_assistant/server/controllers/player_queues.py", line 487, in play_index await player_prov.cmd_play_media( File "/usr/local/lib/python3.11/site-packages/music_assistant/server/providers/sonos/init.py", line 321, in cmd_play_media await self._enqueue_item( File "/usr/local/lib/python3.11/site-packages/music_assistant/server/providers/sonos/init.py", line 591, in _enqueue_item await asyncio.to_thread( File "/usr/local/lib/python3.11/asyncio/threads.py", line 25, in to_thread return await loop.run_in_executor(None, func_call) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/concurrent/futures/thread.py", line 58, in run result = self.fn(*self.args, *self.kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/soco/services.py", line 206, in _dispatcher return self.send_command(action, args, **kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/soco/services.py", line 514, in send_command self.handle_upnp_error(response.text) File "/usr/local/lib/python3.11/site-packages/soco/services.py", line 567, in handle_upnp_error raise SoCoUPnPException( soco.exceptions.SoCoUPnPException: UPnP Error 804 received: from 192.168.0.107

DutchJaFO commented 1 year ago

Because S2 players are functioning on their own I attempted a second test by making a new group (in the Sonos app) that has the S2 Port as the master ... The error remains the same : 2023-04-22 09:24:41 DEBUG music_assistant.websocket_api -- [139783230393808] Handling command players/queue/items 2023-04-22 09:24:50 DEBUG music_assistant.websocket_api -- [139783230393808] Handling command players/queue/play_index 2023-04-22 09:24:50 DEBUG music_assistant.audio -- start media stream for: filesystem_smb://track/Weird Al Yankovic/Mandatory Fun/02 Lame Claim To Fame.mp3 2023-04-22 09:24:50 ERROR music_assistant.websocket_api -- [139783230393808] Error handling message: CommandMessage(message_id=16, command='players/queue/play_index', args={'queue_id': 'RINCON_48A6B820F79E01400', 'index': '8131aaf02a9a40259be2aaca2bd039b3'}) Traceback (most recent call last): File "/usr/local/lib/python3.11/site-packages/music_assistant/server/providers/websocket_api/init.py", line 244, in _run_handler result = await result ^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/music_assistant/server/controllers/player_queues.py", line 487, in play_index await player_prov.cmd_play_media( File "/usr/local/lib/python3.11/site-packages/music_assistant/server/providers/sonos/init.py", line 321, in cmd_play_media await self._enqueue_item( File "/usr/local/lib/python3.11/site-packages/music_assistant/server/providers/sonos/init.py", line 591, in _enqueue_item await asyncio.to_thread( File "/usr/local/lib/python3.11/asyncio/threads.py", line 25, in to_thread return await loop.run_in_executor(None, func_call) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/concurrent/futures/thread.py", line 58, in run result = self.fn(*self.args, *self.kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/soco/services.py", line 206, in _dispatcher return self.send_command(action, args, **kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/soco/services.py", line 514, in send_command self.handle_upnp_error(response.text) File "/usr/local/lib/python3.11/site-packages/soco/services.py", line 567, in handle_upnp_error raise SoCoUPnPException( soco.exceptions.SoCoUPnPException: UPnP Error 804 received: from 192.168.0.12 [mp3 @ 0x56314c3e1280] Estimating duration from bitrate, this may be inaccurate

DutchJaFO commented 1 year ago

Googling for SoC + UPnP 804 error gave me this : https://github.com/SoCo/SoCo/issues/137 I suspect they are related ?

DutchJaFO commented 1 year ago

Grouped Port + Symfonysk + Debug level enabled

In theory this should work, because both are S2 type players. I tried a different track to see if things would be different, but it is not.

2023-04-22 09:36:11 DEBUG music_assistant.event -- queue_items_updated RINCON_949F3EF61A0801400 2023-04-22 09:36:11 DEBUG music_assistant.event -- queue_updated RINCON_949F3EF61A0801400 2023-04-22 09:36:12 DEBUG music_assistant.audio -- start media stream for: filesystem_smb://track/Abney_Park/Nomad/01 Tribal Nomad(by Abney Park).mp3 2023-04-22 09:36:12 DEBUG music_assistant.providers.sonos -- Enqued track (Abney Park - Tribal Nomad) to player Hobbyruimte 2023-04-22 09:36:12 DEBUG music_assistant.providers.sonos -- Received AVTransport event for Player Hobbyruimte 2023-04-22 09:36:12 DEBUG music_assistant.event -- queue_updated RINCON_949F3EF61A0801400 2023-04-22 09:36:12 DEBUG music_assistant.streams -- Got GET request to /stream/RINCON_949F3EF61A0801400/5133494cc48349fab335c735ec9c33b6/bFuUoc4gsUkabTcjDMt4X6.mp3 from 192.168.0.134 headers: <CIMultiDictProxy('Connection': 'close', 'Host': '192.168.0.5:8095', 'Accept': '/', 'User-Agent': 'Linux UPnP/1.0 Sonos/72.2-40060 (ZPS21)', 'X-Sonos-SWGen': '2', 'X-Sonos-Firmware': '72.2-40060', 'X-Sonos-Muse-Api': '1.33.2', 'X-Sonos-Id-Hash': 'qb4MRB7lTBMNsymqLoU3myGjV22aH8aUjOIN5ZPXuQE=')> 2023-04-22 09:36:12 DEBUG music_assistant.streams -- Start serving audio stream bFuUoc4gsUkabTcjDMt4X6 to Hobbyruimte 2023-04-22 09:36:12 DEBUG music_assistant.streams -- Got GET request to /stream/RINCON_949F3EF61A0801400/5133494cc48349fab335c735ec9c33b6/bFuUoc4gsUkabTcjDMt4X6.mp3 from 192.168.0.107 headers: <CIMultiDictProxy('Connection': 'close', 'Host': '192.168.0.5:8095', 'Accept': '/', 'User-Agent': 'Linux UPnP/1.0 Sonos/72.2-40060 (ZPS12)', 'X-Sonos-SWGen': '2', 'X-Sonos-Firmware': '72.2-40060', 'X-Sonos-Muse-Api': '1.33.2', 'X-Sonos-Id-Hash': 'qb4MRB7lTBMNsymqLoU3myGjV22aH8aUjOIN5ZPXuQE=')> 2023-04-22 09:36:12 ERROR music_assistant.streams -- Player Hobbyruimte is making multiple requests for the same stream, please create an issue report on the Music Assistant issue tracker. 2023-04-22 09:36:12 DEBUG music_assistant.streams -- Got HEAD request to /stream/RINCON_949F3EF61A0801400/5133494cc48349fab335c735ec9c33b6/bFuUoc4gsUkabTcjDMt4X6.mp3 from 192.168.0.107 headers: <CIMultiDictProxy('Connection': 'close', 'Host': '192.168.0.5:8095', 'User-Agent': 'Linux UPnP/1.0 Sonos/72.2-40060 (ZPS12)', 'X-Sonos-SWGen': '2', 'X-Sonos-Firmware': '72.2-40060', 'X-Sonos-Muse-Api': '1.33.2', 'X-Sonos-Id-Hash': 'qb4MRB7lTBMNsymqLoU3myGjV22aH8aUjOIN5ZPXuQE=')> 2023-04-22 09:36:12 DEBUG music_assistant.streams -- Got GET request to /stream/RINCON_949F3EF61A0801400/5133494cc48349fab335c735ec9c33b6/bFuUoc4gsUkabTcjDMt4X6.mp3 from 192.168.0.107 headers: <CIMultiDictProxy('Connection': 'close', 'Host': '192.168.0.5:8095', 'Accept': '/', 'User-Agent': 'Linux UPnP/1.0 Sonos/72.2-40060 (ZPS12)', 'X-Sonos-SWGen': '2', 'X-Sonos-Firmware': '72.2-40060', 'X-Sonos-Muse-Api': '1.33.2', 'X-Sonos-Id-Hash': 'qb4MRB7lTBMNsymqLoU3myGjV22aH8aUjOIN5ZPXuQE=')> 2023-04-22 09:36:12 ERROR music_assistant.streams -- Player Hobbyruimte is making multiple requests for the same stream, please create an issue report on the Music Assistant issue tracker. 2023-04-22 09:36:12 DEBUG music_assistant.streams -- Got HEAD request to /stream/RINCON_949F3EF61A0801400/5133494cc48349fab335c735ec9c33b6/bFuUoc4gsUkabTcjDMt4X6.mp3 from 192.168.0.107 headers: <CIMultiDictProxy('Connection': 'close', 'Host': '192.168.0.5:8095', 'User-Agent': 'Linux UPnP/1.0 Sonos/72.2-40060 (ZPS12)', 'X-Sonos-SWGen': '2', 'X-Sonos-Firmware': '72.2-40060', 'X-Sonos-Muse-Api': '1.33.2', 'X-Sonos-Id-Hash': 'qb4MRB7lTBMNsymqLoU3myGjV22aH8aUjOIN5ZPXuQE=')> Guessed Channel Layout for Input Stream #0.0 : stereo 2023-04-22 09:36:12 DEBUG music_assistant.streams -- Got HEAD request to /stream/RINCON_949F3EF61A0801400/5133494cc48349fab335c735ec9c33b6/bFuUoc4gsUkabTcjDMt4X6.mp3 from 192.168.0.107 headers: <CIMultiDictProxy('Connection': 'close', 'Host': '192.168.0.5:8095', 'User-Agent': 'Linux UPnP/1.0 Sonos/72.2-40060 (ZPS12)', 'X-Sonos-SWGen': '2', 'X-Sonos-Firmware': '72.2-40060', 'X-Sonos-Muse-Api': '1.33.2', 'X-Sonos-Id-Hash': 'qb4MRB7lTBMNsymqLoU3myGjV22aH8aUjOIN5ZPXuQE=')>

Exception occurred during processing of request from ('192.168.0.107', 53428) Traceback (most recent call last): File "/usr/local/lib/python3.11/socketserver.py", line 691, in process_request_thread self.finish_request(request, client_address) File "/usr/local/lib/python3.11/socketserver.py", line 361, in finish_request self.RequestHandlerClass(request, client_address, self) File "/usr/local/lib/python3.11/site-packages/soco/events.py", line 98, in init super().init(*args, **kwargs) File "/usr/local/lib/python3.11/socketserver.py", line 755, in init self.handle() File "/usr/local/lib/python3.11/http/server.py", line 432, in handle self.handle_one_request() File "/usr/local/lib/python3.11/http/server.py", line 420, in handle_one_request method() File "/usr/local/lib/python3.11/site-packages/soco/events.py", line 107, in do_NOTIFY self.handle_notification(headers, content) File "/usr/local/lib/python3.11/site-packages/soco/events_base.py", line 234, in handle_notification variables = parse_event_xml(content) ^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/soco/events_base.py", line 104, in parse_event_xml value = from_didl_string(value)[0] ^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/soco/data_structures_entry.py", line 31, in from_didl_string root = XML.fromstring(string.encode("utf-8")) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/xml/etree/ElementTree.py", line 1338, in XML parser.feed(text) xml.etree.ElementTree.ParseError: not well-formed (invalid token): line 1, column 664

2023-04-22 09:36:12 DEBUG music_assistant.streams -- Got HEAD request to /stream/RINCON_949F3EF61A0801400/5133494cc48349fab335c735ec9c33b6/bFuUoc4gsUkabTcjDMt4X6.mp3 from 192.168.0.134 headers: <CIMultiDictProxy('Connection': 'close', 'Host': '192.168.0.5:8095', 'User-Agent': 'Linux UPnP/1.0 Sonos/72.2-40060 (ZPS21)', 'X-Sonos-SWGen': '2', 'X-Sonos-Firmware': '72.2-40060', 'X-Sonos-Muse-Api': '1.33.2', 'X-Sonos-Id-Hash': 'qb4MRB7lTBMNsymqLoU3myGjV22aH8aUjOIN5ZPXuQE=')> 2023-04-22 09:36:12 DEBUG music_assistant.streams -- Got HEAD request to /stream/RINCON_949F3EF61A0801400/5133494cc48349fab335c735ec9c33b6/bFuUoc4gsUkabTcjDMt4X6.mp3 from 192.168.0.134 headers: <CIMultiDictProxy('Connection': 'close', 'Host': '192.168.0.5:8095', 'User-Agent': 'Linux UPnP/1.0 Sonos/72.2-40060 (ZPS21)', 'X-Sonos-SWGen': '2', 'X-Sonos-Firmware': '72.2-40060', 'X-Sonos-Muse-Api': '1.33.2', 'X-Sonos-Id-Hash': 'qb4MRB7lTBMNsymqLoU3myGjV22aH8aUjOIN5ZPXuQE=')> 2023-04-22 09:36:13 DEBUG music_assistant.audio -- stripped 3.19 seconds of silence from end of pcm audio. bytes stripped: 562220 2023-04-22 09:36:13 DEBUG music_assistant.audio -- finished media stream for: filesystem_smb://track/Abney_Park/Nomad/01 Tribal Nomad(by Abney Park).mp3 2023-04-22 09:36:13 DEBUG music_assistant.audio -- Start analyzing audio for filesystem_smb://track/Abney_Park/Nomad/01 Tribal Nomad(by Abney Park).mp3

DutchJaFO commented 1 year ago

It's almost as if as soon as the UPnP 804 error is seen every Sonos device in MA v2b29 stops working. Even ungrouping and restarting MA didn't work ...

ranoydegraaf commented 1 year ago

Been away for a while but i'm back for testing the beta with the Sonos v1 and v2 devices. It looks like the v2 devices are working good in my setup, but as soon as a v1 device connects to the network and got discovered in MA all the Sonos devices are greyed out in the speaker list.

Restarting the MA add-on works for a while. But the device with the V1 firmware is gone in the speaker list. It is still shown in settings but with the loading icon next to it. Log doesn't show anything about the speaker.

DutchJaFO commented 1 year ago

@ranoydegraaf do you have similar results in your log as I do ? AFAIK all my Sonos devices have the latest firmware.

DutchJaFO commented 1 year ago

update : changed the WiFi connection on my Sonos devices from my 2.4 GHz to 5GHz network .... and now it kind of works ? This is weird. Tried a Spotify track ... works Tried a local track ... it does not. Although I have to say that for some reason the track I tried was part of an album that wasn't listed under the artist it belongs to. Not sure what's going on there.

DutchJaFO commented 1 year ago

Important to note that one of my Sonos devices is still connected by wire. I'm still getting UPnP errors in the log, but they don't appear to affect playback as much :

2023-04-23 20:44:12 ERROR music_assistant.websocket_api -- [140072846549072] Error handling message: CommandMessage(message_id=24, command='players/queue/play_pause', args={'queue_id': 'RINCON_B8E9378C73DC01400'}) Traceback (most recent call last): File "/usr/local/lib/python3.11/site-packages/music_assistant/server/providers/websocket_api/init.py", line 244, in _run_handler result = await result ^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/music_assistant/server/controllers/player_queues.py", line 371, in play_pause await self.pause(queue_id) File "/usr/local/lib/python3.11/site-packages/music_assistant/server/controllers/player_queues.py", line 362, in pause await self.players.cmd_pause(queue_id) File "/usr/local/lib/python3.11/site-packages/music_assistant/server/controllers/players.py", line 276, in cmd_pause await player_provider.cmd_pause(player_id) File "/usr/local/lib/python3.11/site-packages/music_assistant/server/providers/sonos/init.py", line 335, in cmd_pause await asyncio.to_thread(sonos_player.soco.pause) File "/usr/local/lib/python3.11/asyncio/threads.py", line 25, in to_thread return await loop.run_in_executor(None, func_call) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/concurrent/futures/thread.py", line 58, in run result = self.fn(*self.args, self.kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/soco/core.py", line 148, in inner_function return function(self, *args, *kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/soco/core.py", line 836, in pause self.avTransport.Pause([("InstanceID", 0), ("Speed", 1)]) File "/usr/local/lib/python3.11/site-packages/soco/services.py", line 206, in _dispatcher return self.send_command(action, args, kwargs) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/soco/services.py", line 514, in send_command self.handle_upnp_error(response.text) File "/usr/local/lib/python3.11/site-packages/soco/services.py", line 567, in handle_upnp_error raise SoCoUPnPException( soco.exceptions.SoCoUPnPException: UPnP Error 701 received: Transition not available from 192.168.0.121

marcelveldt commented 1 year ago

The log is complaining about a transition. Could it be that V1 speakers do not support crossfade and you have crossfade enabled ?

DutchJaFO commented 1 year ago

I've got crossfade enabled ... and AFAIK V1 supports crossfade.

Was that something that got changed in previous beta? Or is there a subtle difference between V1 and V2 for crossfade ?

I'm guessing MA v1 did crossfade in a different way so I never ran into these problems before ?

OzGav commented 1 year ago

Try turning it off and see if those errors go away?

DutchJaFO commented 1 year ago

errors haven't been consistent (I wish they were). Currently playing with crossfade disabled and I'm seeing the familliar 'stream already started' error again :

2023-04-24 19:35:23 WARNING music_assistant.streams -- Got stream request for an already finished stream job for player Slaapkamer

Exception occurred during processing of request from ('192.168.0.121', 38785) Traceback (most recent call last): File "/usr/local/lib/python3.11/socketserver.py", line 691, in process_request_thread self.finish_request(request, client_address) File "/usr/local/lib/python3.11/socketserver.py", line 361, in finish_request self.RequestHandlerClass(request, client_address, self) File "/usr/local/lib/python3.11/site-packages/soco/events.py", line 98, in init super().init(*args, **kwargs) File "/usr/local/lib/python3.11/socketserver.py", line 755, in init self.handle() File "/usr/local/lib/python3.11/http/server.py", line 432, in handle self.handle_one_request() File "/usr/local/lib/python3.11/http/server.py", line 420, in handle_one_request method() File "/usr/local/lib/python3.11/site-packages/soco/events.py", line 107, in do_NOTIFY self.handle_notification(headers, content) File "/usr/local/lib/python3.11/site-packages/soco/events_base.py", line 234, in handle_notification variables = parse_event_xml(content) ^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/soco/events_base.py", line 104, in parse_event_xml value = from_didl_string(value)[0] ^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/site-packages/soco/data_structures_entry.py", line 31, in from_didl_string root = XML.fromstring(string.encode("utf-8")) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.11/xml/etree/ElementTree.py", line 1338, in XML parser.feed(text) xml.etree.ElementTree.ParseError: not well-formed (invalid token): line 1, column 725

I must admit that it didn't feel like crossfade was doing anything except add a delay before the new track would be shown ... The crossfade effect in MA v1 was better, but I assume that would require enabling 'queue flow mode' again.

DutchJaFO commented 1 year ago

I thought it was 100% operational, but it looks I'm wrong. The tracks that I get from Spotify do play on the Sonos without any issues.

The ones that are on the remote share do not. It's also with these that I'm getting the SoCo related errors in the log. Like the UPnP 804

OzGav commented 1 year ago

Any updates on this with b35?

DutchJaFO commented 1 year ago

I haven't done a pure remote-share only test, but the remote share files I've tested so far are working flawlessly in v2b35 beta. Things are queued as expected.

OzGav commented 1 year ago

Ok closing then. Please raise another issue if problems present in the future.