Music Assistant Server crashes when using the Sonos provider

[igorvita]

What version of Music Assistant has the issue?

2.0.0b139

What version of the Home Assistant Integration have you got installed?

2024.4.0

Have you tried everything in the Troubleshooting FAQ and reviewed the Open and Closed Issues and Discussions to resolve this yourself?

• Yes

The problem

MA addon stops few seconds after starting.
Whatchdog try to restart but at every start addon stops and I cannot interact with the UI.
This happen for sure with 2.0.0b139, 2.0.0b138, 2.0.0b137 and 2.0.0b136.
Older versions used to work but at the moment I cannot say wich version worked because I didn't use it for months.

How to reproduce

Just start the addon

Music Providers

I have no access to MA so I cannot neither try to use music providers

Player Providers

I have no access to MA so I cannot neither try to use player providers

Full log output

This is the few lines I downloaded in the few seconds before crash:

2024-04-19 23:53:20.579 INFO (MainThread) [music_assistant] Starting Music Assistant Server (2a755ddc32514389927fd71783cae30f) version 2.0.0b138 - HA add-on: True
2024-04-19 23:53:20.634 INFO (MainThread) [music_assistant.cache] Initializing cache controller...
2024-04-19 23:53:20.734 INFO (MainThread) [music_assistant.webserver] Starting server on 172.30.32.1:8095 - base url: http://172.30.32.1:8095
2024-04-19 23:53:20.935 INFO (MainThread) [music_assistant.music] Using a sync interval of 180 minutes.
2024-04-19 23:53:21.811 WARNING (MainThread) [music_assistant.webserver] Invalid command: players/all
2024-04-19 23:53:21.880 WARNING (MainThread) [music_assistant.webserver] Invalid command: music/recently_played_items
2024-04-19 23:53:22.797 WARNING (MainThread) [music_assistant.webserver] Invalid command: config/providers
2024-04-19 23:53:23.660 WARNING (MainThread) [music_assistant.webserver] Invalid command: config/core
2024-04-19 23:53:23.692 WARNING (MainThread) [music_assistant.webserver] Invalid command: players/all
2024-04-19 23:53:23.707 INFO (MainThread) [music_assistant.streams] Detected ffmpeg version 6.0.1 with libsoxr support
2024-04-19 23:53:23.708 INFO (MainThread) [music_assistant.streams] Starting server on 0.0.0.0:8097 - base url: http://192.168.1.47:8097

This is a more detailed log from HA core log:
log.txt

Additional information

I installed HA OS into a VM with 4GB of dedicated RAM and 2 virtual cpus with execution cap set on 100% (VirtualBox v. 5.1.18 (114002) installed on a server based on NAS4Free).
Everything works fine but this.
Older versions of MA on older version of MA core worked flawlessly.
I tried everything, I reinstalled many times integration deleting manually old folders but nothing worked.
My last chance is install everything from scratch but I'm trying to find a fix.

What version of Home Assistant Core are your running

2024.4.3

What type of installation are you running?

Home Assistant OS in a VM

On what type of hardware are you running?

VM Linux based

[OzGav]

It is not clear what you have been doing as you use the term INTEGRATION yet you supply the ADDON server version. You indicate you are using HAOS but not the integration? You mention removing folders yet that is not possible if you are talking about the addon which resides in its own docker container. You even mention MAOS at one point which isn’t a thing? So please try again to explain exactly what you are doing.

[igorvita]

It is not clear what you have been doing as you use the term INTEGRATION yet you supply the ADDON server version. You indicate you are using HAOS but not the integration? You mention removing folders yet that is not possible if you are talking about the addon which resides in its own docker container. You even mention MAOS at one point which isn’t a thing? So please try again to explain exactly what you are doing.

Thank you OzGav and sorry for my confusion, it's a fact. Please help me to understand.
I'll try to explain:
I'm using HAOS installed in a VM linux based. VM runs into VirtualBox that is running inside my server based on Nas4Free.
I installed HACS. Inside HACS I configured MA repository. After that I used HACS --> Custom Integrations and from there I installed the MA integration.
Then I started the integration and it suddenly stops after few seconds with the log provided (as I said everything worked flawlessly with old version of MA).
Hope I have cleared the situation.
Sorry again for the confusion.

[OzGav]

Ok the integration (because you are running HAOS) will install the ADDON. So navigate to HA SETTINGS>>ADDONS>> MUSIC ASSISTANT and see if the ADDON is running. If it isn’t then try and remove it, restart HA and reinstall it.

[igorvita]

Thank you @OzGav for clarifications.
As you said I navigated to HA SETTINGS>>ADDONS>> MUSIC ASSISTANT. ADDON was not running (as ever).
I uninstalled it (I made it dozens of times), restarted HA, reinstalled and restarted it.
Same result: after few seconds I found ADDON stopped. If I try to restart it, it starts for about 10 seconds than it stops.
:-(

[OzGav]

Edit: I see you are running this in a VM. Please edit your initial post and ATTACH the whole log. You have pasted the start of the log and then it looks like you have attached part of the log?

[igorvita]

I edited the initial post to make it clear for everyone.
But i cannot find the whole log because addon closes in seconds and I cannot go into MA SETTINGS>>CORE.
In SETTINGS>>SYSTEM>>LOG>>MUSIC ASSISTANT BETA (I hope to have correct translated from italian) I only found this:

2024-04-20 22:12:18.892 INFO (MainThread) [music_assistant] Starting Music Assistant Server (62c090fc13b449f1923f28a1ed6f15c6) version 2.0.0b139 - HA add-on: True
2024-04-20 22:12:18.946 INFO (MainThread) [music_assistant.cache] Initializing cache controller...
2024-04-20 22:12:19.461 INFO (MainThread) [music_assistant.webserver] Starting server on 172.30.32.1:8095 - base url: http://172.30.32.1:8095
2024-04-20 22:12:19.682 INFO (MainThread) [music_assistant.music] Using a sync interval of 180 minutes.
2024-04-20 22:12:20.616 WARNING (MainThread) [music_assistant.webserver] Invalid command: players/all
2024-04-20 22:12:20.693 WARNING (MainThread) [music_assistant.webserver] Invalid command: music/recently_played_items
2024-04-20 22:12:22.416 INFO (MainThread) [music_assistant.streams] Detected ffmpeg version 6.0.1 with libsoxr support
2024-04-20 22:12:22.417 INFO (MainThread) [music_assistant.streams] Starting server on 0.0.0.0:8097 - base url: http://192.168.1.47:8097

If you can help me to provide a more detailed log I will post it.

[igorvita]

After launching and after auto stopping I went into SYSTEM>>ADDONS>>MUSIC ASSISTANT>>LOG and I found this:

log.txt

The only strange thing that I notice is that servers are started with strange IPs:
2024-04-21 14:01:53.506 INFO (MainThread) [music_assistant.webserver] Starting server on 172.30.32.1:8095 - base url: http://172.30.32.1:8095
2024-04-21 14:01:56.712 INFO (MainThread) [music_assistant.streams] Starting server on 0.0.0.0:8097 - base url: http://192.168.1.47:8097

HA IP is the last (192.168.1.47).
I don't know if this can be related to my problem.

I've dug deep for hours but I cannot find a real issue in the logs.
The addon stops without errors apparently.

[OzGav]

Also please advise what hardware this is running on? There is this report as well #2110

[igorvita]

As I said HA is running in a Linux VM.
The underlying hardware is a ASRock E350M1 with an integrated CPU AMD Dual-Core Zacate E350 with 16Gb of DDR3 RAM.
This is output of cat /proc/cpuinfo as well:
CPUInfo.txt

The report you indicated is interesting because last line of the log is the same (soco.data_structures_entry imported) so, as @marcelveldt said "at least its partially starting and then crashes".
The safe mode could be a good idea if introduced.

Another report that I found interesting because similar is this one: #1144

I'm available for any test.

[igorvita]

I installed last version of addon 2.0.0b140 and here you are the new log with a new WARNING:
NewLog.txt

[marcelveldt]

As you can read in my follow-up on #2110 I have added a safe mode to further diagnose this option.
This option is not yet available for the add-on. I'll add an option there as well.

[marcelveldt]

OK, released a new version (b141) which also included the safe mode toggle on the add-on

[igorvita]

I just tried, everything is fine!
I added local and remote share and it's ok.
Tomorrow I will try every provider and I will give you feedback about what it's causing troubles.
Thank you in advance,

[JochenDiekenbrock]

I am experiencing exactly the same problem as @igorvita. It stopped starting a few weeks ago after some update. Since then I installed every update and checked the logs. I also tried to delete and reinstall MA and the integration, that did not change anything.
With the safe mode switched on, MA works for me now.

My setup is the recommended HAOS setup on a dedicated (old) laptop (as described in https://www.home-assistant.io/installation/generic-x86-64).

OS Version: Home Assistant OS 11.4
Home Assistant Core: 2024.4.3

cpuinfo.txt

Please let me know if I can do anything to identify the problem and thanks for Music assitant!

[marcelveldt]

So, when MA starts with safe mode on, its actually loaded without any provider loaded (what we call integration in the HA world). Now go to Settings --> Providers and click the 3 dots next to a provider and hit reload. That will actually load it. Do that one by one until you find the one that is crashing the entire container.

[JochenDiekenbrock]

It's the SONOS player that is crashing

[marcelveldt]

OK thanks for letting us know, so indeed the soco package then. I will have a look at changes in both that package and our implementation side of things

[igorvita]

I confirm what @JochenDiekenbrock said: it's sonos player crashing.
It crashes before I press "Save" button.
This is a short clip:

2024-04-23.22-19-11.mp4

[marcelveldt]

Are you also running Home Assistant on this same machine ?
It would be very interesting to see if that also crashes when you try to add the Sonos integration (which is using the same soco package as MA does)

[igorvita]

I'm afraid to try... Is there a risk that HA will not boot anymore after installing Sonos integration?

[marcelveldt]

I'm afraid to try... Is there a risk that HA will not boot anymore after installing Sonos integration?

Yes, there is - so be sure to have a backup.
Also you may want to try HA beta 2024.5.0b0 as that includes an update we applied to MA as well

[JochenDiekenbrock]

Are you also running Home Assistant on this same machine ? It would be very interesting to see if that also crashes when you try to add the Sonos integration (which is using the same soco package as MA does)

I tried to add the Sonos integration, but that did not complete because I don't have Sonos devices. Sorry.

[marcelveldt]

this should be fixed in beta 142 - but please test!

[OzGav]

@igorvita please confirm if this has been fixed

[JochenDiekenbrock]

I just updated to beta 143, MA is still crashing as soon as I add the Sonos Player.

[igorvita]

@igorvita please confirm if this has been fixed

I update HA core to 2024.4.4 and MA to beta 143.
Rebooted HA.
Nothing changed: MA crashes 3 seconds after I try to add Sonos player exactly as showed in the video I posted above.

[marcelveldt]

OK, looks like we have 2 issues then. There was also a segfault introduced in orjson 3.10.1

I had a quick peek at the soco library and that one is a whole beast on its own, including dependencies on some aging xml libraries. So like 999 different ways a hard crash could be induced. Soco also got updated recently so maybe we start with reverting that as well but it may also just be one of its dependencies. I suspect a side effect from one of the xml libraries.

I intend to switch to the newer sonos api's anyways (as the UPNP api is going to be phased out) so maybe this is reason to do that sooner.

Do both of you really use the Sonos provider ?

[JochenDiekenbrock]

Do both of you really use the Sonos provider ?

I don't, for me, everything is fine now. I just try to help.

Thank you for your effort!

[igorvita]

I don't use Sonos, neither.
With safe mode I'm ok but I'm here for every test you want I do.
Thank you a lot for your attention.

[marcelveldt]

To sum up this issue. The Music Assistant container (or HA add-on) crashes on some older generation (Intel?) hardware when using the Sonos provider (which in turn uses the Soco python library), most likely due to some dependency (like one of the xml libraries) using CPU instructions not available on older gen x86 CPU's.

The crash seems to already happen as soon as the soco library is imported but we're not 100% sure about that.

Its really hard for us to exactly track what's going on without actual access to such hardware and the specific conditions.
Its a bit searching for a needle in some haystack. We will keep this issue open (and pinned) so people will at least know about this and they can choose to not use the Sonos provider. We have adjusted the code in Music Assistant that nothing will be imported when you did not add a provider to MA.

So workaround for now: Do not use the Sonos provider in MA when you run into this issue.
Longer term solution is going to be that we will switch away from the soco library in favor of the new Sonos api.