Sonos things are offline

kernest · November 9, 2017, 9:39pm

Hi,

I have a problem, with all my Sonos devices are offline.

When I change / update my .things, all devices are changed from OFFLINE to ONLINE and less than a second after, to OFFLINE.

22:22:00.275 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'sonos.things'
22:22:00.459 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'sonos:CONNECTAMP:gaestevaerelse' changed from OFFLINE to ONLINE
22:22:00.460 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'sonos:CONNECTAMP:gaestevaerelse' changed from ONLINE to OFFLINE
22:22:00.476 [INFO ] [smarthome.event.ThingUpdatedEvent   ] - Thing 'sonos:CONNECTAMP:gaestevaerelse' has been updated.
22:22:00.482 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'sonos:CONNECTAMP:stue1sal' changed from OFFLINE to ONLINE
22:22:00.484 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'sonos:CONNECTAMP:stue1sal' changed from ONLINE to OFFLINE
22:22:00.494 [INFO ] [smarthome.event.ThingUpdatedEvent   ] - Thing 'sonos:CONNECTAMP:stue1sal' has been updated.
22:22:00.502 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'sonos:CONNECTAMP:tvstue' changed from OFFLINE to ONLINE
22:22:00.502 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'sonos:CONNECTAMP:tvstue' changed from ONLINE to OFFLINE
22:22:00.513 [INFO ] [smarthome.event.ThingUpdatedEvent   ] - Thing 'sonos:CONNECTAMP:tvstue' has been updated.
22:22:00.528 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'sonos:CONNECTAMP:alrum' changed from ONLINE to OFFLINE
22:22:00.528 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'sonos:CONNECTAMP:alrum' changed from OFFLINE to ONLINE
22:22:00.539 [INFO ] [smarthome.event.ThingUpdatedEvent   ] - Thing 'sonos:CONNECTAMP:alrum' has been updated.
22:22:00.544 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'sonos:CONNECTAMP:bad1sal' changed from OFFLINE to ONLINE
22:22:00.548 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'sonos:CONNECTAMP:bad1sal' changed from ONLINE to OFFLINE
22:22:00.557 [INFO ] [smarthome.event.ThingUpdatedEvent   ] - Thing 'sonos:CONNECTAMP:bad1sal' has been updated.
22:22:00.569 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'sonos:CONNECTAMP:sovevaerelse' changed from OFFLINE to ONLINE
22:22:00.572 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'sonos:CONNECTAMP:sovevaerelse' changed from ONLINE to OFFLINE
22:22:00.622 [INFO ] [smarthome.event.ThingUpdatedEvent   ] - Thing 'sonos:CONNECTAMP:sovevaerelse' has been updated.
22:22:00.628 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'sonos:CONNECTAMP:nora' changed from OFFLINE to ONLINE
22:22:00.630 [INFO ] [me.event.ThingStatusInfoChangedEvent] - 'sonos:CONNECTAMP:nora' changed from ONLINE to OFFLINE
22:22:00.645 [INFO ] [smarthome.event.ThingUpdatedEvent   ] - Thing 'sonos:CONNECTAMP:nora' has been updated.

It was working at some point, so im not sure if it is an OH update, Sonos update or what is wrong.

I can find all devices with the UPNP search tool, so don’t believe that UPNP is the issue.

Im running Sonos 8.1.1 and OH 2.1.0-1.

Looking forward to any help!

dan12345 · November 11, 2017, 1:23pm

I too have all my Sonos items showing as offline

Lolodomo · November 11, 2017, 2:52pm

What OH version are you running ?
Kai mentioned a major change in UPnP in last ESH stable and so in last OH snapshots.

kernest · November 11, 2017, 3:09pm

Running 2.1.0 release build.

Isn’t this the newest stable version?

dan12345 · November 11, 2017, 3:37pm

I’m running the latest snapshot.

So wonder if this is a change in the Sonos api rather than something on the openHAB end?

Lolodomo · November 11, 2017, 3:44pm

Are they still offline after 1 or 2 minutes ?
Sometimes they are first offline because GENA suscriptions are failing but in this case this is ok the next time one minute later and they are online again.

dan12345 · November 11, 2017, 3:45pm

no, it’s not that usual effect - they flip offline and then stay off for ever until I restart openhab.

Lolodomo · November 11, 2017, 3:48pm

I have no problem with snapshot 1065.
I will install last snapshot this weekend and i will let you know what happen for me.

Lolodomo · November 11, 2017, 3:50pm

What you describe let me think that they are no more discovered by UPnP.

kernest · November 11, 2017, 6:12pm

I have the same as dan12345. After save of the things file with Sonos, they are back online but then offline within a second. Just like the log shows.

Sonos can be found anytime with the UPNP scanner/tester.

You also have the 8.1.1 Sonos version Lolodomo?

Lolodomo · November 11, 2017, 6:20pm

I can confirm the problem with snapshot 1078. One of my 2 things have this behaviour. Apparently, the UPnP call is no more working. I suspect the new jUPnP library version we rely on.

Issue opened: https://github.com/eclipse/smarthome/issues/4531

I am switching back to snapshot 1065 to check that everything is working again.

Lolodomo · November 11, 2017, 6:31pm

After restoring snapshot 1065, everything is ok again.

So something relative to UPnP was briken between 1065 and 1078.

kernest · November 11, 2017, 6:36pm

Thanks for the testing and the opening of issue on Github!

Did you just restore from a backup or is it easy to rollback to an older snapshot?

Lolodomo · November 11, 2017, 6:38pm

I am using my own way to backup/restore and it is fully manual but very easy as everything is in one unique place.

Lolodomo · November 11, 2017, 6:43pm

Of course, this problem should not impact users running OH 2.1 but only users running the last snapshot.

Lolodomo · November 11, 2017, 8:07pm

If others have this problem with snapshots starting at 1077, please tell us. I have difficulties to convince there is a real problem with UPnP in ESH. If we are not only 2, maybe this will help.

kernest · November 11, 2017, 8:50pm

After i uninstalled Sonos Binding and rebooted and then installed again, it is working for me in OH 2.1.

Dries · November 12, 2017, 9:12am

I,
I have a similar problem (I created a separate topic for this, because I overlooked this one):

I have a Sonos 5 and a Sonos Connect:amp.

Although openhab.log was empty, I did notice these in events.log:

2017-11-12 10:14:54.235 [hingStatusInfoChangedEvent] - 'sonos:CONNECTAMP:RINCON_000E583F6C4A01400' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR): The Sonos player RINCON_000E583F6C4A01400 is not available in local network.
2017-11-12 10:03:43.673 [hingStatusInfoChangedEvent] - 'sonos:PLAY5:RINCON_000E58834E6A01400' changed from OFFLINE (COMMUNICATION_ERROR): The Sonos player RINCON_000E58834E6A01400 is not available in local network. to ONLINE

Lolodomo · November 12, 2017, 10:37am

Yes, you confirm the problem.
By the way, the problem is easy to reproduce in Eclipse. The problem is due to our upgrade to the new version of the jUPnP library.
Until this is fixed, I will try to find a manual workaround to replace the new library by the previous version of the library in the deployed 1078 distribution.

scratch009 · November 12, 2017, 1:12pm

Same here, was on Snapshot 1069 (now upraded to latest to see if it was fixed). And 1 of my 2 sonos players is offline. Tried to reboot openhab but can’t get it online so far.