Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Sonos devices keep becoming unavailable #88341

Open
nplawes opened this issue Feb 17, 2023 · 43 comments
Open

Sonos devices keep becoming unavailable #88341

nplawes opened this issue Feb 17, 2023 · 43 comments
Assignees

Comments

@nplawes
Copy link

nplawes commented Feb 17, 2023

The problem

Since version 2023.2, I have found many of my speakers show "Subscription renewal failed" messages
After switching on debugging I get additional messages such as

2023-02-15 16:44:15.258 DEBUG (MainThread) [soco.events_base] 412, message='Precondition Failed', url=URL('http://10.87.2.104:1400/MediaServer/ContentDirectory/Event')
2023-02-15 16:44:15.268 WARNING (MainThread) [homeassistant.components.sonos.speaker] Subscription renewal failed for Garage: 412, message='Precondition Failed', url=URL('http://10.87.2.104:1400/MediaServer/ContentDirectory/Event')
2023-02-15 16:44:15.274 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Starting resubscription cooldown for Garage
2023-02-15 16:44:15.277 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Unsubscribing from events for Garage
2023-02-15 16:44:15.286 DEBUG (MainThread) [soco.events_base] 412, message='Precondition Failed', url=URL('http://10.87.2.104:1400/MediaRenderer/AVTransport/Event')
2023-02-15 16:44:15.288 DEBUG (MainThread) [soco.events_base] 412, message='Precondition Failed', url=URL('http://10.87.2.104:1400/MediaRenderer/RenderingControl/Event')
2023-02-15 16:44:15.290 DEBUG (MainThread) [soco.events_base] 412, message='Precondition Failed', url=URL('http://10.87.2.104:1400/ZoneGroupTopology/Event')

This is most noticeable when it is affecting the speaker I user in the media-control card, as it ‘blanks’ for a while, and normally after a minute or two, it fixes itself. Then the whole cycle repeats.

My setup is a bit non-standard as I run HASS on a different vlan/subnet to the speakers. Discovery and firewalls have been set up to handle this, and up to 2023.1.7, everything worked fine. And backing out to 2023.1.7 works fine, so I don't think it is a setup issue.

As a further test I set up HASS on a new machine on the same vlan/subnet as my main instance, with just the Sonos integration, and it does NOT exhibit the same behaviour. This seems odd, so I guess it is either a timing or load related issue with my main HASS instance. I doubt my installation ranks as overly complex ('state_count': 1154, 'automation_count': 261, 'integration_count': 88), and the load on the machine is low.

Something in the 2023.2 release clearly changed the subscription behaviour or timing. Perhaps someone in the know can shed some light on this...

I'm happy to install and test on newer versions, but cannot leave current versions on my live system as it breaks stuff, so will have to revert to 2023.1.7 after testing.

Is there anything I can extract from the debug log file that I saved to assist?

What version of Home Assistant Core has the issue?

2023.2.x

What was the last working version of Home Assistant Core?

2023.1.7

What type of installation are you running?

Home Assistant Container

Integration causing the issue

Sonos

Link to integration documentation on our website

https://www.home-assistant.io/integrations/sonos/

Diagnostics information

Unfortunately I get a 500 error in the diagnostics file, probably because it runs behind a reverse proxy, I will try to fix this

Example YAML snippet

No response

Anything in the logs that might be useful for us?

No response

Additional information

No response

@home-assistant
Copy link

Hey there @cgtobi, @jjlawren, mind taking a look at this issue as it has been labeled with an integration (sonos) you are listed as a code owner for? Thanks!

Code owner commands

Code owners of sonos can trigger bot actions by commenting:

  • @home-assistant close Closes the issue.
  • @home-assistant rename Awesome new title Change the title of the issue.
  • @home-assistant reopen Reopen the issue.
  • @home-assistant unassign sonos Removes the current integration label and assignees on the issue, add the integration domain after the command.

(message by CodeOwnersMention)


sonos documentation
sonos source
(message by IssueLinks)

@nplawes
Copy link
Author

nplawes commented Feb 17, 2023

Tried again and got the diagnostic info this time...

config_entry-sonos-f7da3f4df3f54dc69b49b518ef213e98.json.txt

@yestrdave
Copy link

yestrdave commented Feb 21, 2023

I'm seeing same behavior. Just started last week. Single VLan and same subnet for HA and Sonos

Source: components/sonos/speaker.py:411
Integration: Sonos ([documentation](https://www.home-assistant.io/integrations/sonos), [issues](https://github.com/home-assistant/home-assistant/issues?q=is%3Aissue+is%3Aopen+label%3A%22integration%3A+sonos%22))
First occurred: 10:32:14 AM (93 occurrences)
Last logged: 5:44:49 PM

Subscription renewal failed for Master Bathroom Sonos Five: 412, message='Precondition Failed', url=URL('http://192.168.91.174:1400/ZoneGroupTopology/Event')
Subscription renewal failed for Kitchen Sonos OneSL: 412, message='Precondition Failed', url=URL('http://192.168.91.94:1400/MediaServer/ContentDirectory/Event')
Subscription renewal failed for Kitchen Sonos OneSL: 412, message='Precondition Failed', url=URL('http://192.168.91.94:1400/ZoneGroupTopology/Event')
Subscription renewal failed for Master Bathroom Sonos Five: 412, message='Precondition Failed', url=URL('http://192.168.91.174:1400/MediaRenderer/RenderingControl/Event')
Subscription renewal failed for Kitchen Sonos OneSL: 412, message='Precondition Failed', url=URL('http://192.168.91.94:1400/MediaRenderer/RenderingControl/Event')```

Home Assistant 2023.2.5
Supervisor 2023.01.1
Operating System 9.5
Frontend 20230202.0 - latest

@yestrdave
Copy link

I think I solved this issue. I changed the spanning tree from RSTP to STP in the Network Config. Then unplugged all of the devices and let them reconnect. I have been running 6 hours with no errors. I will report back, but so far so good.

@nplawes
Copy link
Author

nplawes commented Feb 23, 2023

It would be interesting to figure out why the slower STP would fix the issue, and what changed in the 2023.2 release to cause it in the first place. In my case I have a working and a non-working instance on the same network layout. However the mini pc's are on different switches, so I couldn't rule anything out

@yestrdave
Copy link

From what I researched it is recommended by Sonos. I'm running an all ubiquiti network. I found several posts regarding the STP change. All I can comment on is it fixed my system.

@nplawes
Copy link
Author

nplawes commented Feb 23, 2023

Interesting... all but two 10G switches in my network are also ubiquiti, currently RTSP. I don't recall seeing any mention of switching to STP for Sonos, but can certainly try it. I'll have to look up the reason for it. Especially as it was all working fine prior to 2023.2, and is still working on my test setup. Maybe there was something else other than the Sonos code in the release causing it. I will try this change too this evening, thanks.

@nplawes
Copy link
Author

nplawes commented Feb 23, 2023

Sigh - switched to STP, put 2023.2.5 in, and have had 5 failures on each of 3 devices in the last hour :-(
Back to 2023.1.7 for me

@jjlawren
Copy link
Contributor

I hate to suggest it, but have you tried power cycling your Sonos devices? I've had a couple issues around subscriptions and callbacks where behavior didn't make sense which went away after a Sonos system reboot. I hope that isn't the reason, but it's good to rule out the difficult to troubleshoot issues first.

@Yazzcat
Copy link

Yazzcat commented Feb 24, 2023

I am seeing the same behavior. Also in my setup I am using multiple vlans and my Sonos setup is in a different vlan. It seems the entities become available right after I manually started some music on the Sonos. Issue started after my upgrade. However not sure when it was introduced as I skipped one month. I am having some issues with my harmony hub, but no clue if this is related on the networking level.

@nplawes
Copy link
Author

nplawes commented Feb 24, 2023

I hate to suggest it, but have you tried power cycling your Sonos devices? I've had a couple issues around subscriptions and callbacks where behavior didn't make sense which went away after a Sonos system reboot. I hope that isn't the reason, but it's good to rule out the difficult to troubleshoot issues first.

Next time I switch to the latest version I will try that... However as I have a test system that is not showing the issues, and reverting to the old version the issues go away, I don't hold out much hope

@nplawes
Copy link
Author

nplawes commented Feb 24, 2023

I am seeing the same behavior. Also in my setup I am using multiple vlans and my Sonos setup is in a different vlan. It seems the entities become available right after I manually started some music on the Sonos. Issue started after my upgrade. However not sure when it was introduced as I skipped one month. I am having some issues with my harmony hub, but no clue if this is related on the networking level.

I think my Harmony hub was okay on the new version, but I will check it when I test next.

@nplawes
Copy link
Author

nplawes commented Feb 24, 2023

From what I researched it is recommended by Sonos. I'm running an all ubiquiti network. I found several posts regarding the STP change. All I can comment on is it fixed my system.

I found some references to Sonos / STP. It looks like it's because Sonos use the older STP on their devices, so it can affect wired devices. Since all of my speakers are wireless, I don't think this should be an issue. I've switched back to RSTP.

@yestrdave
Copy link

@nplawes Based on what you wrote I decided to go back to RSTP, in which case this would mean unplugging all of my devices cleared my error. I have been running all afternoon with the RSTP turned on and only had one issue early on, but did not get the errors in HA I was getting. I am running 20 speakers. Ill keep you posted, but it looks like our issues may be different. I will be happy to to help, if I can.

@nplawes
Copy link
Author

nplawes commented Feb 25, 2023

@yestrdave If your speakers are hard-wired, then the STP issues raised elsewhere are most likely valid, which is why it fixed things for you. My speakers are all wireless, so I don't think STP applies anywhere.

I recently tried the new UI for Unifi controller and noticed there was an AP mesh option now. If the AP's are meshed, they would presumably benefit from [R]STP, but as it's the AP's rather than the speakers attached to the switches, I guess RSTP is the way to go. I haven't switched that feature on yet.

@Yazzcat
Copy link

Yazzcat commented Feb 28, 2023

Ok. Did some investigation and it seems my config.yaml was pointing to device that changed its IP address (long ago). When the integration loads, it breaks after trying to connect to the non-existing device. What seems to work for me, is to only put the main Sonos device in the config.yaml, turn off auto-discovery in the plugin (GUI). Not sure why, but this way, all my sonos devices were found. However a few hours later I got a 'pre-condition failed' error in the log and now I can control some devices, some are unavailable again and some do not update status (I can start music, but because status is not updated, I cannot stop it...). When I reload the integration, it again is telling me loading failed...

@nplawes
Copy link
Author

nplawes commented Feb 28, 2023

Originally I did put the speakers into the config file to avoid the need for discovery. However inter-vlan discovery can be made to work nicely using smcroute and automated iptables rule etc. on the router. At that point there's nagging in the log file that the ip addresses should be removed because the speakers were discovered fine, so I did remove them... And debugging does confirm that with lots of Activity on Lounge from discovery type messages.

With the new unifi UI there looks like options to help with this too, but I've not switched that on as yet. It's probably not good to replicate that sort of thing.

@nplawes
Copy link
Author

nplawes commented Mar 5, 2023

Interestingly, I installed 2023.3.0 a few days ago, and it seems a lot more stable. I've only seen 1 renewal failure so far. One device marked as unavailable, correctly, as it was powered down. One other marked unavailable a few times unexpectedly, so I will power-cycle that one.

I didn't see any changes listed for Sonos, so perhaps the issue was in library/core code used by the integration, and that has been fixed.

As far as I am aware nothing changed on my network.

I will monitor this for a little while longer before closing the issue.

@jjlawren
Copy link
Contributor

jjlawren commented Mar 5, 2023

Only a couple small changes in 2023.3, but nothing that would impact speaker availability--they were more about better handling the errors when they do become unavailable.

Networking stability is a big factor with Sonos devices. If subscriptions are working properly (arguably the most important factor for the HA integration), then it may come down to connections timing out or failing intermittently. Reviewing the connection "quality" on the speakers themselves is sometimes helpful at http://<any_sonos_speaker_ip>:1400/support/review and checking the "Network matrix" tab. If there are multiple orange/red squares, it may imply the connectivity between speakers is suspect.

@SteffenM-DE
Copy link

Same here, always these messages at the log. All over day and night and often 2-4 in one minute:

WARNING (MainThread) [homeassistant.components.sonos.speaker] Subscription renewal failed for Sonos [NAME]: 412, message='Precondition Failed', url=URL('http://[IP]:1400/ZoneGroupTopology/Event')

Sonos Network matrix looks fine and I have no problems with Sonos system over Sonos App. Sonos S2 with 13 different devices.

@SteffenM-DE
Copy link

I checked the Log if I disconnect a device then it shows:

Subscription renewal failed for Sonos [NAME]: Request timed out

So it seems the failed subscribtion renewal is no connection error over all.

@SteffenM-DE
Copy link

I have bought a new player and exchanged this player but the warning error is still at the log.

@jjlawren
Copy link
Contributor

Besides the logging, do you have actual usability problems?

The integration logs warnings when connectivity is unexpectedly lost. The native Sonos app may be experience similar issues but not display warnings to improve the user experience. HA relies on much longer-lived connections than normal use of the Sonos app, so losing those connections are more likely.

That being said, this is still likely caused by instability in your network/wifi. The integration tries to recover gracefully when losses occur, but we still log warnings so you're aware they're happening and can address them elsewhere.

@SteffenM-DE
Copy link

Music is still playing but at the HA Logbook shows devices as offline for 2-3 seconds if that happens and logged.

@SteffenM-DE
Copy link

So I testes many things and exchange players and there are always these mesages on some players (some are go away for weeks and come back again). Sonos support matrix is showing good connections and player are still playing but warnings are always there:

`
2023-05-15 14:41:53.739 WARNING (MainThread) [homeassistant.components.sonos.speaker] Subscription renewal failed for Sonos Bad: 412, message='Precondition Failed', url=URL('http://xxx:1400/ZoneGroupTopology/Event')
2023-05-15 14:41:54.070 WARNING (MainThread) [homeassistant.components.sonos.speaker] Subscription renewal failed for Sonos Keller: 412, message='Precondition Failed', url=URL('http://xxx:1400/ZoneGroupTopology/Event')
2023-05-15 14:41:59.031 WARNING (MainThread) [homeassistant.components.sonos.speaker] Subscription renewal failed for Sonos Computer: 412, message='Precondition Failed', url=URL('http://xxx:1400/ZoneGroupTopology/Event')

`

@f-f
Copy link

f-f commented Jul 20, 2023

I'm having this problems for close to a year now, and it's driving me mad - when I reboot HomeAssistant the Sonos system stays online for a few days, but after that it becomes extremely unreliable (and effectively impossible to control from HA), as it goes through this cycle of "being available for 3 seconds and then unavailable for a minute":
image

I see the same log entries as the reports above. Does anyone have any tips on how to debug this further?

@SteffenM-DE
Copy link

Same here without a solution. Sonos itself works fine and I changed devices (buy a new one) or change postion next to cabled device but again and again this messages ...

@SteffenM-DE
Copy link

Changed from SonosNet to WLAN, same errors still there, now more since before with SonosNet. I have 4 WLAN AP's and everywhere stabel WLAN. It happen always with HA Sonos integration Change player or Net.

@JoergBr
Copy link

JoergBr commented Aug 22, 2023

Same problem here, HA 2023.2.5, however only with one particular Sonos device.

@stevencoutts
Copy link

stevencoutts commented Sep 22, 2023

Same problem here too, just one Sonos device affected, 2023.9.2

Also to clarify, there is not instability in my network

@jhemak
Copy link

jhemak commented Oct 9, 2023

I believe I am having the same problem. My devices are fine in HA until they are not. Then the cards go blank and it can take a few to several minutes for the system to automatically recover (unless I reboot HA, which also resolves it temporarily). Here is one example from the logs yesterday of a device being marked inactive due to "no recent activity" despite what, to me, looks like activity and communication just a few minutes earlier.

2023-10-08 20:36:49.393 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Roam from SonosSpeaker.ping
2023-10-08 20:38:02.287 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Roam from ZoneGroupTopology subscription
2023-10-08 20:39:24.417 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Roam from DeviceProperties subscription
2023-10-08 20:39:24.547 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Roam from ZoneGroupTopology subscription
2023-10-08 20:39:28.256 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Roam from DeviceProperties subscription
2023-10-08 20:39:28.393 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Roam from ZoneGroupTopology subscription
2023-10-08 20:41:18.941 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Roam from DeviceProperties subscription
2023-10-08 20:41:19.016 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Roam from SonosSpeaker.fetch_battery_info
2023-10-08 20:41:19.094 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Roam from ZoneGroupTopology subscription
2023-10-08 20:41:21.035 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Roam from DeviceProperties subscription
2023-10-08 20:41:21.720 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Roam from ZoneGroupTopology subscription
2023-10-08 20:42:40.691 DEBUG (MainThread) [homeassistant.components.sonos.speaker] Activity on Roam from ZoneGroupTopology subscription
2023-10-08 20:47:50.308 WARNING (MainThread) [homeassistant.components.sonos.speaker] No recent activity and cannot reach Roam, marking unavailable

As others have said, the Sonos device works fine in the Sonos app during this timeframe. Thank you to anyone who is able to figure this out!

@jjlawren
Copy link
Contributor

@jhemak your example looks like the device is simply going offline. Subscriptions and polling are working to the device up until that point.

Roams seem to like to sleep fairly aggressively. I've found they tend to stay online if they're powered by wired USB, but not when they're on a Qi charger.

@jhemak
Copy link

jhemak commented Oct 11, 2023

Thanks, I know what you mean - but I see the same thing with my larger/wired speakers as well. And the Roam is still online in the Sonos app when it shows unavailable in HA.

@DubhAd
Copy link
Contributor

DubhAd commented Nov 13, 2023

I see exactly the same, but only with one (Sonos Play:1) speaker, the others are all fine. All are on the current S2 firmware.

2023-11-13 11:54:49.565 WARNING (MainThread) [homeassistant.components.sonos.speaker] Creating subscription failed for Office: 412, message='Precondition Failed', url=URL('http://192.168.42.180:1400/ZoneGroupTopology/Event')
2023-11-13 11:54:49.565 WARNING (MainThread) [homeassistant.components.sonos.speaker] Creating subscriptions failed for Office

This happens whether the speaker is wired or connected to SonosNet, and reliably happens every time HA is restarted. It will then resolve itself some time later (maybe minutes, maybe many hours) - so far at least 😁 Once it works it'll stay that way until the next restart of HA.

During this time I can control the speaker from the Sonos App, Spotify, and even send TTS using the Sonos Cloud custom integration.

@jjlawren
Copy link
Contributor

For anyone seeing "Precondition Failed" warnings in regards to subscriptions, that's the speaker responding that it doesn't know about the subscription we're trying to renew/extend, so we cancel and recreate the subscription. Previous to this occurring, it's likely the speaker has already stopped delivering updates (as it has "lost" our subscription).

This could happen for many reasons, but most common that I've seen is either (1) the speaker has restarted/lost power or (2) the speaker is unable to deliver subscription events back to the HA host at its callback listener (usually TCP port 1400).

The integration should be able to detect when (1) happens and automatically recreate subscriptions. Scenario (2) isn't easy to detect from the HA side but is usually related to network instability or restrictions (e.g., VLANs with an internal firewall).

The current subscription length is ~20 minutes. Perhaps we can reduce the chances of a subscription being "lost" by the speaker(s) by reducing that timespan.

@jhemak
Copy link

jhemak commented Nov 29, 2023

I am continuing to see this problem intermittently with all of my Sonos speakers. It seems a reboot of HA will immediately restore the connection to the unavailable speaker(s); and if I don't reboot HA then the speaker(s) usually and eventually (time seems to vary) will reconnect to HA on its own. Meanwhile, there is no issue controlling the speaker from the Sonos App.

@digidolphin
Copy link

digidolphin commented Dec 14, 2023

Not sure if this is directly related, but I am also experiencing unavailability. But mine persists even with a reboot, so 1 og 2 of my 9 devices will be unavailable, despite being perfectly functional through the sonos app. It is not the same speakers every time, but changes (I believe with each reboot).

@DubhAd
Copy link
Contributor

DubhAd commented Feb 2, 2024

I thought I'd cracked this by replacing the problem speaker, but sadly the new (Symfonisk bookshelf) speakers give the same error now:

Creating subscription failed for Office: 412, message='Precondition Failed', url=URL('http://192.168.42.180:1400/ZoneGroupTopology/Event')

These repeat every 10 minutes.

Both speakers are wired to the same switch that HA is connected to. Maybe my choice of room name is the problem 🤣

@wappinghigh
Copy link

Same problem here...

@f-f
Copy link

f-f commented Feb 17, 2024

I am not seeing this issue anymore with the latest Core version (2024.2), I'd try an upgrade and see if it goes away.

@levimenten
Copy link

Put all the Sonos players in one group and reboot home assistant and they will show up as available. Not really a fix but helpful with automations.

Hopefully they wil fix it in the future.

@jhemak
Copy link

jhemak commented Apr 5, 2024

@f-f I do still see the same problem, even on 2024.4.

@dabeeeenster
Copy link

I think I might have fixed this issue on my network by giving static IP addresses to my sonos speakers via my router and then explicitly defining the IP addresses as described here. Not had a disconnection for 24 hours and counting...🤞

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests