[Nearing Release] Sonos Advanced Controller

I have a basic rule that sets volume to a certain level (36), starts playback of a particular favorite source on one of the speakers, and then sets a group. It worked beautifully for a month or so, and then the speaker that started playback started dropping the volume down to 3 somewhere in the routine. I've also had an issue with one of the speakers randomly losing contact with the network and needing to be reset, after which it will join again. Happens multiple times a day, and I think it started after I began using the Advanced Controller. I suspect you need more info to help (I'm fairly new to this), so please let me know what else I can provide. Thanks in advance.

Is there an issue with discovery and Unifi AP's? Asking as I've just disconnected my Boost to use the AP's instead. My Sonos are working fine now with Sonos Advanced but will I have issues if I need to re-discover?

I don't have a separate vlan for Sonos but now I ensure my guest network is isolated so it can't access Sonos. Did you know that Spotify Connect will stay connected to your Sonos speaker even after leaving the house and travelling miles away. We found out it did, shaking the house at 2am whilst my friend was miles away turning up the volume on my Play 5 thinking the sound should be coming out of his headphones :rofl:

Just to add a little more information: After further testing, I've determined that the individual speaker volumes attributes stop updating almost precisely 1 hour after a hub reboot. This behavior is consistent and reproducible. Perhaps the player is not resubscribing to MRRC_EVENTS after the 3600 sec timeout?

I've got a couple of automations and one dashboard not working because of this, but none are critical, so just whenever you have time. Otherwise, everything is working perfectly!

Let me know if you have any questions. Sincerest thanks again for all your work on this!

EDIT 5/28/24: Resolved in this post.

Hey Dan,

For the last two days I've been getting some random hub lockups. I don't think its your app/driver, but as the hub was slowing down, I can see issues with your app/drivers.

I actually think its something in the hub firmware as it started after the recent update to .125....

Anyway, I thought I'd try disabling things in your app/driver that I don't use... One that stood out was the disable artist, album and track events in preferences.

I disabled that item and saved the preferences, but immediately started getting this error for all 17 Sonos devices. What exactly does this do? Should I re-enabled it?

dev:26132024-03-12 10:04:17.411errorgroovy.lang.MissingMethodException: No signature of method: user_driver_dwinks_Sonos_Advanced_Player_2467.setCurrentArtistAlbumTrack() is applicable for argument types: (null, null, null, java.lang.Integer) values: [null, null, null, 0] on line 1819 (method secondaryConfiguration)

EDIT: I re-enabled the option and it removed the errors, but I am seeing this in the logs... Maybe it is this app/driver that is slowing down the hub over time?

dev:61472024-03-12 10:39:10.045warnmethod initialize of child device Sonos Master Bedroom ran for 131,164ms

dev:61362024-03-12 10:37:32.658warnmethod initialize of child device Sonos Back Patio ran for 140,331ms

When your hub locks up, do you see any errors being reported prior to the lockup.
The reason I'm asking is I had hub lockups too and it did point to this app and devices.

The only way to stop it was to delete the app/devices and re-install it.
All the errors then stopped.
A bit drastic I know but it may be a way out of your issue. :man_shrugging:

I couldn't really tell. The problem I have is the app is on my backup hub with the devices all mirrored to the main hub. I can see the errors on both hubs, but its the main hub that has been locking up...

I updated all my hubs to the latest firmware .125 on Saturday. Prior to that, they were all on .123 with the current version of this app.

Sunday, Monday and today, my main hub has locked up at around 0630 and starts spewing errors... I can see errors on both hubs prior to all that, but it really isn't clear.

I have remote hubs using HubConnect that are connected to my main hub also. Wondering if its a combination of a bunch of things that is taking it down.

This is what I was getting just prior to the hub locking up. I retrieved these from past logs.

Summary
Summary

Yes, I was getting the com.hubitat.app.exception.LimitExceededException: Device xxx a whole bunch... Those errors were flooding the logs... But there were for all kinds of devices, not just the sonos devices created by this app... So i wasn't sure if that was the cause or a by-product of the lockup.

Haven't seen the JSON from failed websocket parse error, but my logs were literally flooded and it was hard to see them all...

Hey all... quick update post. So no idea what I did, possibly too much time sitting motionless at my desk in bad positions, possibly getting old, possibly both, or possibly something else entirely, but here for the last week I've been 'knocked out' with pretty awful lower back pain.

I'll catch up here and get back to squashing some bugs soon, but for the near term I'm giving my back a few days more rest.

Pulled my office chair entirely out of my office so I'm not tempted to sit on it too long. Now my only option is standing or leaning on my 'wobble stool'. I've got a balance board thing on order too, and have a few core/back exercises I'm adding on my Total Gym to help keep the ravages of age at bay in the future. But it'll be a bit before I work up to being back to being at my computer for more than a couple hours a day, and those hours are all spent on my work PC.

Things on the mend here, feeling much better now than last weekend. Still stiff and sore, but I expect I'll have a few hours this weekend at the very least to dive back into a few issues here, and hopefully figure out a cause and solution for some of the lock up issues. I've been thinking of a few things to look into when I get back on.

Still pretty clueless as to how anything in my code would ever take 120+ seconds. I've triple checked that there's no paths that could end up in an infinite loop. Everything is just "take incoming XML/JSON, process it, raise some events, possibly raise them on the followers, go back to sleep". That takes just a few milliseconds on my 2 Hubitats, and never seems to get the 120+ second thing. It should only take a few milliseconds for everyone else too, but there's a few people where it frequently takes 120+ seconds (well, it times out after that long, so I can just presume that it would never stop running if Hubitat hadn't killed it). So what it's getting hung up on still eludes me.

I'll have some more time here this weekend if all is well. I'll catch up on the various comments above then. Have a great week!

8 Likes

Hey Daniel,

Any chance of listing version 7.1 on your github? I see it goes from 7.0 to 7.3... I'd like to try 7.1 as that seemed to be running most stable for me...

EDIT: Cancel that... I restored a backup from one of my hubs that had 0.7.1 on it... I really don't think its your current app, cause I updated to it about a week ago... The only change that recently happened was updating the hub firmware to 125 this weekend... But I'm rolling back to 0.7.1 of this app just to make sure...

So I'm not sure if reverting to 7.1 was what worked, but this morning my hub was not locked up. I did see some elevated stats when I rebooted the hub last night around 930. After the reboot, whatever the app does to re-sync or reconnect to devices spun it up for a bit, but then it settled down.

But, in all honesty, I did some other cleanup of stuff with both my main and backup hubs, so there might be something I did there to fix the lockup issues.

I PM'd Bobby @bobbyD to have him look at the engineering logs, but haven't heard from him yet.

So I'm not 100% sure it is something between 7.1 and 7.3, but I'm gonna wait for a bit before updating back to 7.3...

Got your message. We identified a platform issue that will be fixed in the next release.

11 Likes

Thanks @bobbyD !

You guys are awesome!

2 Likes

Interesting to see a platform issue fix on 2.3.8.128 that very likely was impacting this application. Sonos Advanced does a LOT of events in a really short time when there's many speakers in a group. Easily 100+ within a few milliseconds of each other as it updates the coordinator with all the new events then updates all the followers right after. If you have a dozen speakers in a group this can very easily hit well over 100 events spanning a dozen devices in a very short timeframe. The absurd amount of optimization I've put in on the code to make it fast would maybe have even made this worse, since it would compress the events down into a smaller timeframe since it's running faster.

So... has anyone here seen the lockups still happening on 2.3.8.128? I really hope the HE patch fixes this, since there's really nothing I can see in the Sonos Advanced app on my end of things that I could change, short of just removing a bunch of features.

3 Likes

Yes, my hub locked up again Tuesday afternoon. So not sure they completely got this figured out on their end.

Question for you though. Is there any issue with Sonos speakers that might leave the environment? I have Roam that I take when I travel for work. That was not the case with my most recent lockup on 128, but wondering if when I take it, and the system can't find it, what happens?

It should be mostly fine. Every hour or two it'll fail to connect and redo the subscriptions. There'll be an error or two in the logs, but it won't cause any real issues.

When you return with it, it'll take up to 2 hours for it to resubscribe all on its own. initialize() will reconnect it right away, if it matters for that.

1 Like

I'm still having the issue described in this post. The workaround I have in place for now is to send an initialize() command via webCoRE to each speaker every hour, with a gap of around 10 minutes between the speakers.

Any thoughts?

EDIT 5/28/24: Resolved in this post.

I'm experiencing the same issue, @daniel.winks. Just like @bthrock, I use webCoRE for regular initialization.

1 Like

@daniel.winks had a odd one today i have heard it before but not for a while. It was if multiple events where queued up and about 5 MP3 files played one after the other mostly the same file. Any idea why that would happen?

I upgraded from a very old version and now my favorites will not show up? Should I have deleted the devices and the app and the done a fresh install?