[SOLVED] Sonos Binding -> Beam play notification while playing TV Source

I updated my PR to apply the fix to Playbar and Playbase. So you can test with the jar provided in the PR to validate the fix for Playbar.

Just to be sure:

  1. Download this file: org.openhab.binding.sonos-2.5.0-SNAPSHOT.zip
  2. Put it for example in directory /home/pi ( don’t put it in your openHAB addons folder ).
  3. Run the following command in the openHAB console to get your bundle id: bundle:list -s | grep sonos
  4. run the following command to replace your Sonos binding, assuming the previous command returned 245: bundle:update 245 file:///home/pi/org.openhab.binding.sonos-2.5.0-SNAPSHOT.jar

?

Yes, that is the procedure. With console he means to login with karaf:

My set-up:
RPi3 running Openhabian
openHAB 2.5.0.M1 Milestone Build
1 sonos Playbar + 2 Play1 as surround; Livingroom (+LS+RS).
Some other Sonos in other places in the house.

First step:

openhab> bundle:list -s | grep sonos
219 x Active   x  80 x 0.11.0.oh250M1         x org.eclipse.smarthome.binding.sonos
openhab>

Update the Sonos binding:

openhab> bundle:update 219 file:///home/openhabian/org.openhab.binding.sonos-2.5.0-SNAPSHOT.jar
openhab> bundle:list -s | grep sonos
219 x Active   x  80 x 2.5.0.201909160633     x org.openhab.binding.sonos

That seems to work. Binding is updated. Stop/Start the binding.

Now in my log I see several entries with:

2019-09-16 20:34:22.552 [ERROR] [org.openhab.binding.sonos           ] - FrameworkEvent ERROR - org.openhab.binding.sonos

Caused by: java.lang.ClassNotFoundException: org.eclipse.smarthome.core.thing.binding.BaseDynamicStateDescriptionProvider cannot be found by org.openhab.binding.sonos_2.5.0.201909160633

events.log states:

2019-09-16 20:30:12.151 [hingStatusInfoChangedEvent] - 'sonos:PLAY1:RINCON_B8E937BB7D2C01400' changed from ONLINE to UNINITIALIZED

2019-09-16 20:30:12.338 [hingStatusInfoChangedEvent] - 'sonos:PLAY1:RINCON_B8E937BB7D2C01400' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)

2019-09-16 20:30:12.372 [hingStatusInfoChangedEvent] - 'sonos:PLAY3:RINCON_B8E937D9463A01400' changed from ONLINE to UNINITIALIZED

2019-09-16 20:30:12.410 [vent.ItemStateChangedEvent] - GoogleDNSLastseen changed from 2019-09-16T20:29:09.631+0200 to 2019-09-16T20:30:11.015+0200

2019-09-16 20:30:12.473 [hingStatusInfoChangedEvent] - 'sonos:PLAY3:RINCON_B8E937D9463A01400' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)

2019-09-16 20:30:12.478 [hingStatusInfoChangedEvent] - 'sonos:PLAY1:RINCON_B8E937B9E0E401400' changed from ONLINE to UNINITIALIZED

2019-09-16 20:30:12.536 [hingStatusInfoChangedEvent] - 'sonos:PLAY1:RINCON_B8E937B9E0E401400' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)

2019-09-16 20:30:12.547 [hingStatusInfoChangedEvent] - 'sonos:PLAY1:RINCON_5CAAFD9C7B6601400' changed from ONLINE to UNINITIALIZED

2019-09-16 20:30:12.623 [hingStatusInfoChangedEvent] - 'sonos:PLAY1:RINCON_5CAAFD9C7B6601400' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)

2019-09-16 20:30:12.630 [hingStatusInfoChangedEvent] - 'sonos:PLAYBAR:RINCON_B8E937749EF501400' changed from ONLINE to UNINITIALIZED

2019-09-16 20:30:12.708 [hingStatusInfoChangedEvent] - 'sonos:PLAYBAR:RINCON_B8E937749EF501400' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)

2019-09-16 20:30:12.719 [hingStatusInfoChangedEvent] - 'sonos:PLAY1:RINCON_B8E937B9D00E01400' changed from ONLINE to UNINITIALIZED

2019-09-16 20:30:12.766 [hingStatusInfoChangedEvent] - 'sonos:PLAY1:RINCON_B8E937B9D00E01400' changed from UNINITIALIZED to UNINITIALIZED (HANDLER_MISSING_ERROR)

and a snap-shot from my openhab.log

2019-09-16 20:30:15.116 [ERROR] [org.openhab.binding.sonos           ] - FrameworkEvent ERROR - org.openhab.binding.sonos
org.osgi.framework.ServiceException: Exception in org.apache.felix.scr.impl.manager.SingleComponentManager.getService()
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:222) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.getService(ServiceFactoryUse.java:111) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceConsumer$2.getService(ServiceConsumer.java:45) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:508) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.getService(ServiceRegistry.java:461) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.getService(BundleContextImpl.java:624) ~[?:?]
	at org.apache.felix.scr.impl.manager.SingleRefPair.getServiceObject(SingleRefPair.java:73) ~[?:?]
	at org.apache.felix.scr.impl.inject.BindParameters.getServiceObject(BindParameters.java:47) ~[?:?]
	at org.apache.felix.scr.impl.inject.methods.BindMethod.getServiceObject(BindMethod.java:664) ~[?:?]
	at org.apache.felix.scr.impl.manager.DependencyManager.getServiceObject(DependencyManager.java:2308) ~[?:?]
	at org.apache.felix.scr.impl.manager.DependencyManager.doInvokeBindMethod(DependencyManager.java:1805) ~[?:?]
	at org.apache.felix.scr.impl.manager.DependencyManager.invokeBindMethod(DependencyManager.java:1788) ~[?:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.invokeBindMethod(SingleComponentManager.java:436) ~[?:?]
	at org.apache.felix.scr.impl.manager.DependencyManager$MultipleDynamicCustomizer.addedService(DependencyManager.java:333) ~[?:?]
	at org.apache.felix.scr.impl.manager.DependencyManager$MultipleDynamicCustomizer.addedService(DependencyManager.java:302) ~[?:?]
	at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1216) ~[?:?]
	at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1137) ~[?:?]
	at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.trackAdding(ServiceTracker.java:944) ~[?:?]
	at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.track(ServiceTracker.java:880) ~[?:?]
	at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:1168) ~[?:?]
	at org.apache.felix.scr.impl.BundleComponentActivator$ListenerInfo.serviceChanged(BundleComponentActivator.java:125) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:109) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:920) ~[?:?]
	at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) ~[?:?]
	at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:862) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry$1.run(ServiceRegistry.java:805) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry$1.run(ServiceRegistry.java:1) ~[?:?]
	at java.security.AccessController.doPrivileged(Native Method) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:803) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.register(ServiceRegistrationImpl.java:127) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.registerService(ServiceRegistry.java:225) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:469) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:906) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:892) ~[?:?]
	

I guess I did something wrong since all the sonos things have status Status: UNINITIALIZED - HANDLER_MISSING_ERROR.

2.5M2 is the minimum requirement due to the new use of org.eclipse.smarthome.core.thing.binding.BaseDynamicStateDescriptionProvider in current binding code.

I’ll back-up my system and upgrade to 2.5M3

So I upgraded to 2.5.0.M3

When I play something from Spotify to my Playbar (with the Play1’s as surround) I can hear the notification (I have a test rule triggerd) and then the music continues.

When I change to TV as input and I trigger the rule again the volume is changed (as stated in my rule; I set the volume to 40%) but the sound from the TV is not stopped and I can’t hear the notification.
When the notification is ‘done’ playing the sound level is changed back to the original value again.

Was it with the updated binding (from the PR) ?

Yes, after updating to .m3 I updated the sonos binding again.
Could I help you with any kind of logs?

I am surprised… Are you sure to run the new version?
Please run this command and show the result: bundle:list -s | grep sonos

openhab> bundle:list -s | grep sonos
256 x Active x  80 x 2.5.0.201909160633    x org.openhab.binding.sonos
openhab>

I will re-add logs for you…

I see that you have a setup with Playbar+Play1 as surround, maybe that is the problem.
Please be sure to send your notification to the Playbar thing.
If possible, unlink your Play:1 from the Playbar and try again when the playbar is grouped with no other devices.
By the way, I made a little mistake by checking the destination thing type rather than the group coordinator thing type. I will change that.

Something strange is happening.

I checked again what version of the binding was running and found this:

openhab> bundle:list -s | grep sonos
256 x Active x  80 x 2.5.0.M3              x org.openhab.binding.sonos

Seems like something went wrong. I had to remove the power supply yesterday so my Pi was restarted.
I’ll download the jar again and try.

By the way, you can get an updated jar in the PR. Please try with this one.
If you have still problems, you can download this jar with additional logs and show me your logs (INFO level) when playing the notification.

@Maurits28 : as I updated my fix, that would be kind if you could try again with your Beam (jar from the PR) and confirm that it is still working for you.

I guess I’m doing something wrong. I dowloaded the file and watend to update again.

So check the bundle-nr:

openhab> bundle:list -s | grep sonos
302 x Active x  80 x 2.5.0.M3              x org.openhab.binding.sonos

Now update bundle 302 with the file just downloadend:

openhab> bundle:update 302 file:///home/openhabian/sonos.jar

Now check again; indeed it’s changed

openhab> bundle:list -s | grep sonos
302 x Active x  80 x 2.5.0.201909191908    x org.openhab.binding.sonos

Restart the bundle, and just to be sure check version again

openhab> bundle:restart 302
openhab> bundle:list -s | grep sonos
302 x Active x  80 x 2.5.0.M3              x org.openhab.binding.sonos

And I’m back on the old version.
Or am I misinterpreting this?

By the way; I’ve disconnected the Play-1’s and not I’m only listening to the TV on the Playbar.
This didn’t change the situation; notification is played when listening to Spotify; sound-level is changed but no notification when listening to TV. But maybe that has someting to do with the fact that the update is somehow not persisting.

It might be that your SD-card is dying. When it happens, one of the symptom is that some new files are replaced with old ones without reason or even disappear.

Would removing the original Sonos binding via PaperUI; and then installing this binding work?

After a few corrupted SD-cards in the past I started to use a SSD. I sure hopte this is not also getting corrupt.

To be tried. Maybe you will get missing dependencies, maybe it will work.