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.

Sign up for GitHub

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

Jump to bottom

[Sonos] all speaker things flapping every minute (OH in docker) #14742

Open
JustinGeorgi opened this issue Apr 3, 2023 · 5 comments
Open

[Sonos] all speaker things flapping every minute (OH in docker) #14742

JustinGeorgi opened this issue Apr 3, 2023 · 5 comments
Labels
bug An unexpected problem or unintended behavior of an add-on

Comments

@JustinGeorgi
Copy link

I have 8 sonos speakers. My sonos system has been reliably connected to OH for several years, but I have noticed in the last week now that the things for all 8 speakers go offline for a second or two and then come back online again once every minute.

A forum discussion about the issue can be seen here: https://community.openhab.org/t/all-sonos-things-flapping-every-minute/145765 but no resolution has been found.

System:
OH 4.0 snapshot Build #3392 (also occurs on 4.0M1)
Docker container network: host
Docker running on ubuntu 22.04
All sonos speakers on same lan as OH
Sonos system fully up-to-date

  • 5x Play1
  • 1x Play3
  • 1x OneSL
  • 1x Roam

JUPnP settings in runtime.cfg

org.jupnp:threadPoolSize=25
org.jupnp:asyncThreadPoolSize=25
org.jupnp:retryAfterSeconds=300
org.jupnp:retryIterations=8
org.jupnp:timeoutSeconds=15

Have also tried org.jupnp:threadPoolSize and org.jupnp:asyncThreadPoolSize set to -1 but this does not fix the issue.

Logs:
events.log (example of one speaker)

2023-04-02 09:32:37.702 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'sonos:PLAY1:RINCON_949F3E89854601400' changed from ONLINE to OFFLINE (COMMUNICATION_ERROR)
2023-04-02 09:32:40.019 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'sonos:PLAY1:RINCON_949F3E89854601400' changed from OFFLINE (COMMUNICATION_ERROR) to ONLINE

openhab.log (org.openhab.binding.sonos log level DEBUG, example of one speaker)

2023-04-02 09:31:56.045 [DEBUG] [s.internal.handler.ZonePlayerHandler] - RINCON_949F3E89854601400: Subscription to service RenderingControl succeeded
2023-04-02 09:31:56.056 [DEBUG] [s.internal.handler.ZonePlayerHandler] - RINCON_949F3E89854601400: Subscription to service AVTransport succeeded
2023-04-02 09:31:56.075 [DEBUG] [s.internal.handler.ZonePlayerHandler] - RINCON_949F3E89854601400: Subscription to service ContentDirectory succeeded
2023-04-02 09:32:08.060 [DEBUG] [s.internal.handler.ZonePlayerHandler] - RINCON_949F3E89854601400: Subscription to service RenderingControl succeeded
2023-04-02 09:32:08.067 [DEBUG] [s.internal.handler.ZonePlayerHandler] - RINCON_949F3E89854601400: Subscription to service AVTransport succeeded
2023-04-02 09:32:08.069 [DEBUG] [s.internal.handler.ZonePlayerHandler] - RINCON_949F3E89854601400: Subscription to service ContentDirectory succeeded
2023-04-02 09:32:18.056 [DEBUG] [s.internal.handler.ZonePlayerHandler] - RINCON_949F3E89854601400: Subscription to service ContentDirectory succeeded
2023-04-02 09:32:18.056 [DEBUG] [s.internal.handler.ZonePlayerHandler] - RINCON_949F3E89854601400: Subscription to service RenderingControl succeeded
2023-04-02 09:32:19.121 [DEBUG] [s.internal.handler.ZonePlayerHandler] - RINCON_949F3E89854601400: Subscription to service AVTransport succeeded
2023-04-02 09:32:28.120 [DEBUG] [s.internal.handler.ZonePlayerHandler] - Polling job
2023-04-02 09:32:32.051 [DEBUG] [s.internal.handler.ZonePlayerHandler] - RINCON_949F3E89854601400: Subscription to service RenderingControl succeeded
2023-04-02 09:32:32.051 [DEBUG] [s.internal.handler.ZonePlayerHandler] - RINCON_949F3E89854601400: Subscription to service AVTransport succeeded
2023-04-02 09:32:32.077 [DEBUG] [s.internal.handler.ZonePlayerHandler] - RINCON_949F3E89854601400: Subscription to service ContentDirectory succeeded
2023-04-02 09:32:36.943 [DEBUG] [s.internal.handler.ZonePlayerHandler] - Polling job
2023-04-02 09:32:37.702 [INFO ] [s.internal.handler.ZonePlayerHandler] - UPnP device RINCON_949F3E89854601400 is absent (thing sonos:PLAY1:RINCON_949F3E89854601400)
2023-04-02 09:32:37.703 [DEBUG] [overy.ZonePlayerDiscoveryParticipant] - Discovered a Sonos 'sonos:PLAY1' thing with UDN 'RINCON_949F3E89854601400'
2023-04-02 09:32:39.033 [DEBUG] [s.internal.handler.ZonePlayerHandler] - Polling job
2023-04-02 09:32:39.120 [DEBUG] [s.internal.handler.ZonePlayerHandler] - Polling job
2023-04-02 09:32:40.017 [INFO ] [s.internal.handler.ZonePlayerHandler] - UPnP device RINCON_949F3E89854601400 is present (thing sonos:PLAY1:RINCON_949F3E89854601400)
2023-04-02 09:32:40.017 [DEBUG] [overy.ZonePlayerDiscoveryParticipant] - Discovered a Sonos 'sonos:PLAY1' thing with UDN 'RINCON_949F3E89854601400'
2023-04-02 09:32:40.017 [DEBUG] [s.internal.handler.ZonePlayerHandler] - Polling job
2023-04-02 09:32:40.027 [DEBUG] [s.internal.handler.ZonePlayerHandler] - Polling job
2023-04-02 09:32:41.073 [DEBUG] [s.internal.handler.ZonePlayerHandler] - RINCON_949F3E89854601400: Subscription to service ContentDirectory succeeded
2023-04-02 09:32:44.061 [DEBUG] [s.internal.handler.ZonePlayerHandler] - RINCON_949F3E89854601400: Subscription to service ContentDirectory succeeded
2023-04-02 09:32:44.065 [DEBUG] [s.internal.handler.ZonePlayerHandler] - RINCON_949F3E89854601400: Subscription to service RenderingControl succeeded

openhab.log (org.jupnp log level DEBUG)

2023-04-02 18:14:17.033 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.1:42804 on local interface: enp5s0 and address: 192.168.1.105
2023-04-02 18:14:17.034 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2023-04-02 18:14:17.034 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.1:42804 on local interface: enp5s0 and address: 192.168.1.105
2023-04-02 18:14:17.034 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2023-04-02 18:14:17.035 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.1:42804 on local interface: enp5s0 and address: 192.168.1.105
2023-04-02 18:14:17.035 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2023-04-02 18:14:17.036 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.1:42804 on local interface: enp5s0 and address: 192.168.1.105
2023-04-02 18:14:17.036 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2023-04-02 18:14:17.038 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.1:42804 on local interface: enp5s0 and address: 192.168.1.105
2023-04-02 18:14:17.038 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2023-04-02 18:14:17.039 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.1:42804 on local interface: enp5s0 and address: 192.168.1.105
2023-04-02 18:14:17.039 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2023-04-02 18:14:17.046 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.1:42804 on local interface: enp5s0 and address: 192.168.1.105
2023-04-02 18:14:17.046 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2023-04-02 18:14:17.047 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.1:42804 on local interface: enp5s0 and address: 192.168.1.105
2023-04-02 18:14:17.047 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2023-04-02 18:14:17.048 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.1:42804 on local interface: enp5s0 and address: 192.168.1.105
2023-04-02 18:14:17.048 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2023-04-02 18:14:17.048 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.1:42804 on local interface: enp5s0 and address: 192.168.1.105
2023-04-02 18:14:17.048 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2023-04-02 18:14:17.049 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.1:42804 on local interface: enp5s0 and address: 192.168.1.105
2023-04-02 18:14:17.049 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2023-04-02 18:14:17.285 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.1:42804 on local interface: enp5s0 and address: 192.168.1.105
2023-04-02 18:14:17.286 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2023-04-02 18:14:17.286 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.1:42804 on local interface: enp5s0 and address: 192.168.1.105
2023-04-02 18:14:17.286 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2023-04-02 18:14:17.286 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.1:42804 on local interface: enp5s0 and address: 192.168.1.105
2023-04-02 18:14:17.287 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2023-04-02 18:14:17.287 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.1:42804 on local interface: enp5s0 and address: 192.168.1.105
2023-04-02 18:14:17.287 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2023-04-02 18:14:17.287 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.1:42804 on local interface: enp5s0 and address: 192.168.1.105
2023-04-02 18:14:17.287 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2023-04-02 18:14:17.291 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.1:42804 on local interface: enp5s0 and address: 192.168.1.105
2023-04-02 18:14:17.291 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2023-04-02 18:14:17.294 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.1:42804 on local interface: enp5s0 and address: 192.168.1.105
2023-04-02 18:14:17.294 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2023-04-02 18:14:17.295 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.1:42804 on local interface: enp5s0 and address: 192.168.1.105
2023-04-02 18:14:17.295 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2023-04-02 18:14:17.299 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.1:42804 on local interface: enp5s0 and address: 192.168.1.105
2023-04-02 18:14:17.299 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2023-04-02 18:14:17.299 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.1:42804 on local interface: enp5s0 and address: 192.168.1.105
2023-04-02 18:14:17.300 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2023-04-02 18:14:17.300 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.1:42804 on local interface: enp5s0 and address: 192.168.1.105
2023-04-02 18:14:17.300 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2023-04-02 18:14:17.550 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingActionRequestMessage) POST http://192.168.1.18:1400/DeviceProperties/Control
2023-04-02 18:14:18.419 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingActionRequestMessage) POST http://192.168.1.41:1400/DeviceProperties/Control
2023-04-02 18:14:18.829 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingActionRequestMessage) POST http://192.168.1.132:1400/DeviceProperties/Control
2023-04-02 18:14:23.067 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingActionRequestMessage) POST http://192.168.1.17:1400/DeviceProperties/Control
2023-04-02 18:14:24.105 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 169.254.221.238:49361 on local interface: veth0fffc8d and address: 169.254.155.67
2023-04-02 18:14:24.105 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 169.254.85.236:55625 on local interface: vethac53f5d and address: 169.254.155.67
2023-04-02 18:14:24.105 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 169.254.155.67:35740 on local interface: veth66a1bab and address: 169.254.155.67
2023-04-02 18:14:24.105 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 169.254.199.104:54524 on local interface: veth73c8cd2 and address: 169.254.155.67
2023-04-02 18:14:24.105 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) M-SEARCH
2023-04-02 18:14:24.105 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) M-SEARCH
2023-04-02 18:14:24.105 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 169.254.131.88:52377 on local interface: veth8437ba6 and address: 169.254.155.67
2023-04-02 18:14:24.105 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) M-SEARCH
2023-04-02 18:14:24.105 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.105:37788 on local interface: enp5s0 and address: 192.168.1.105
2023-04-02 18:14:24.106 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) M-SEARCH
2023-04-02 18:14:24.106 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) M-SEARCH
2023-04-02 18:14:24.105 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) M-SEARCH
2023-04-02 18:14:24.107 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 169.254.54.176:48093 on local interface: enp5s0 and address: 169.254.155.67
2023-04-02 18:14:24.107 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) M-SEARCH
2023-04-02 18:14:26.416 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingRenewalRequestMessage) SUBSCRIBE http://192.168.1.41:1400/MediaRenderer/RenderingControl/Event
2023-04-02 18:14:26.416 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingRenewalRequestMessage) SUBSCRIBE http://192.168.1.18:1400/MediaRenderer/AVTransport/Event
2023-04-02 18:14:26.416 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingRenewalRequestMessage) SUBSCRIBE http://192.168.1.41:1400/MediaRenderer/AVTransport/Event
2023-04-02 18:14:26.423 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingSubscribeRequestMessage) SUBSCRIBE http://192.168.1.18:1400/MediaRenderer/AVTransport/Event
2023-04-02 18:14:26.423 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingSubscribeRequestMessage) SUBSCRIBE http://192.168.1.41:1400/MediaRenderer/AVTransport/Event
2023-04-02 18:14:26.424 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingSubscribeRequestMessage) SUBSCRIBE http://192.168.1.41:1400/MediaRenderer/RenderingControl/Event
2023-04-02 18:14:26.442 [INFO ] [np.transport.impl.async.AsyncServlet] - HttpServlet.service(): id:   0, request URI: /upnpcallback/dev/RINCON_7828CAAEE2FC01400_MR/svc/upnp-org/AVTransport/event/cb
2023-04-02 18:14:26.442 [DEBUG] [np.transport.impl.async.AsyncServlet] - Handling Servlet request asynchronously: org.ops4j.pax.web.service.spi.servlet.OsgiHttpServletRequestWrapper@36dc5017
2023-04-02 18:14:26.442 [DEBUG] [org.jupnp.transport.Router          ] - Received synchronous stream: 855248641
2023-04-02 18:14:26.443 [INFO ] [np.transport.impl.async.AsyncServlet] - HttpServlet.service(): id:   1, request URI: /upnpcallback/dev/RINCON_7828CAABC74601400_MR/svc/upnp-org/AVTransport/event/cb
2023-04-02 18:14:26.443 [DEBUG] [np.transport.impl.async.AsyncServlet] - Handling Servlet request asynchronously: org.ops4j.pax.web.service.spi.servlet.OsgiHttpServletRequestWrapper@6dca47a3
2023-04-02 18:14:26.443 [DEBUG] [np.transport.impl.async.AsyncServlet] - AsyncListener.onComplete(): id:   0, duration:    1, response: HTTP/1.1 200 
Connection: close
Content-Type: text/xml
Date: Mon, 03 Apr 2023 01:14:26 GMT


2023-04-02 18:14:26.444 [DEBUG] [org.jupnp.transport.Router          ] - Received synchronous stream: 1780789212
2023-04-02 18:14:26.455 [DEBUG] [np.transport.impl.async.AsyncServlet] - AsyncListener.onComplete(): id:   1, duration:   12, response: HTTP/1.1 200 
Connection: close
Content-Type: text/xml
Date: Mon, 03 Apr 2023 01:14:26 GMT


2023-04-02 18:14:26.466 [INFO ] [np.transport.impl.async.AsyncServlet] - HttpServlet.service(): id:   2, request URI: /upnpcallback/dev/RINCON_7828CAABC74601400_MR/svc/upnp-org/RenderingControl/event/cb
2023-04-02 18:14:26.466 [DEBUG] [np.transport.impl.async.AsyncServlet] - Handling Servlet request asynchronously: org.ops4j.pax.web.service.spi.servlet.OsgiHttpServletRequestWrapper@d5453f4
2023-04-02 18:14:26.466 [DEBUG] [org.jupnp.transport.Router          ] - Received synchronous stream: 1865733976
2023-04-02 18:14:26.468 [DEBUG] [np.transport.impl.async.AsyncServlet] - AsyncListener.onComplete(): id:   2, duration:    2, response: HTTP/1.1 200 
Connection: close
Content-Type: text/xml
Date: Mon, 03 Apr 2023 01:14:26 GMT


2023-04-02 18:14:27.417 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingRenewalRequestMessage) SUBSCRIBE http://192.168.1.18:1400/MediaRenderer/RenderingControl/Event
2023-04-02 18:14:27.417 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingRenewalRequestMessage) SUBSCRIBE http://192.168.1.132:1400/MediaServer/ContentDirectory/Event
2023-04-02 18:14:27.417 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingRenewalRequestMessage) SUBSCRIBE http://192.168.1.41:1400/MediaServer/ContentDirectory/Event
2023-04-02 18:14:27.418 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingRenewalRequestMessage) SUBSCRIBE http://192.168.1.18:1400/MediaServer/ContentDirectory/Event
2023-04-02 18:14:27.418 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingRenewalRequestMessage) SUBSCRIBE http://192.168.1.151:1400/MediaServer/ContentDirectory/Event
2023-04-02 18:14:27.418 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingRenewalRequestMessage) SUBSCRIBE http://192.168.1.151:1400/MediaRenderer/RenderingControl/Event
2023-04-02 18:14:27.418 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingRenewalRequestMessage) SUBSCRIBE http://192.168.1.132:1400/MediaRenderer/RenderingControl/Event
2023-04-02 18:14:27.419 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingRenewalRequestMessage) SUBSCRIBE http://192.168.1.132:1400/MediaRenderer/AVTransport/Event
2023-04-02 18:14:27.419 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingRenewalRequestMessage) SUBSCRIBE http://192.168.1.151:1400/MediaRenderer/AVTransport/Event
2023-04-02 18:14:27.423 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingSubscribeRequestMessage) SUBSCRIBE http://192.168.1.18:1400/MediaRenderer/RenderingControl/Event
2023-04-02 18:14:27.427 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingSubscribeRequestMessage) SUBSCRIBE http://192.168.1.132:1400/MediaServer/ContentDirectory/Event
2023-04-02 18:14:27.430 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingSubscribeRequestMessage) SUBSCRIBE http://192.168.1.41:1400/MediaServer/ContentDirectory/Event
2023-04-02 18:14:27.431 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingSubscribeRequestMessage) SUBSCRIBE http://192.168.1.151:1400/MediaServer/ContentDirectory/Event
2023-04-02 18:14:27.432 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingSubscribeRequestMessage) SUBSCRIBE http://192.168.1.151:1400/MediaRenderer/RenderingControl/Event
2023-04-02 18:14:27.433 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingSubscribeRequestMessage) SUBSCRIBE http://192.168.1.18:1400/MediaServer/ContentDirectory/Event
2023-04-02 18:14:27.434 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingSubscribeRequestMessage) SUBSCRIBE http://192.168.1.132:1400/MediaRenderer/RenderingControl/Event
2023-04-02 18:14:27.446 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingSubscribeRequestMessage) SUBSCRIBE http://192.168.1.132:1400/MediaRenderer/AVTransport/Event
2023-04-02 18:14:27.449 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingSubscribeRequestMessage) SUBSCRIBE http://192.168.1.151:1400/MediaRenderer/AVTransport/Event
2023-04-02 18:14:27.463 [INFO ] [np.transport.impl.async.AsyncServlet] - HttpServlet.service(): id:   3, request URI: /upnpcallback/dev/RINCON_7828CAABC74601400_MS/svc/upnp-org/ContentDirectory/event/cb
2023-04-02 18:14:27.463 [DEBUG] [np.transport.impl.async.AsyncServlet] - Handling Servlet request asynchronously: org.ops4j.pax.web.service.spi.servlet.OsgiHttpServletRequestWrapper@40f7df0a
2023-04-02 18:14:27.463 [DEBUG] [org.jupnp.transport.Router          ] - Received synchronous stream: 759607854
2023-04-02 18:14:27.464 [DEBUG] [pnp.transport.spi.GENAEventProcessor] - Value RINCON_38420B14A8AC01400,84 for the state variable RadioFavoritesUpdateID ignored: Can't convert string to number or not in range: RINCON_38420B14A8AC01400,84
2023-04-02 18:14:27.464 [DEBUG] [pnp.transport.spi.GENAEventProcessor] - Value RINCON_38420B14A8AC01400,515 for the state variable RadioLocationUpdateID ignored: Can't convert string to number or not in range: RINCON_38420B14A8AC01400,515
2023-04-02 18:14:27.465 [DEBUG] [np.transport.impl.async.AsyncServlet] - AsyncListener.onComplete(): id:   3, duration:    2, response: HTTP/1.1 200 
Connection: close
Content-Type: text/xml
Date: Mon, 03 Apr 2023 01:14:27 GMT


2023-04-02 18:14:27.465 [INFO ] [np.transport.impl.async.AsyncServlet] - HttpServlet.service(): id:   4, request URI: /upnpcallback/dev/RINCON_7828CAAEE2FC01400_MR/svc/upnp-org/RenderingControl/event/cb
2023-04-02 18:14:27.466 [DEBUG] [np.transport.impl.async.AsyncServlet] - Handling Servlet request asynchronously: org.ops4j.pax.web.service.spi.servlet.OsgiHttpServletRequestWrapper@23cf8087
2023-04-02 18:14:27.466 [DEBUG] [org.jupnp.transport.Router          ] - Received synchronous stream: 1778912689
2023-04-02 18:14:27.467 [DEBUG] [np.transport.impl.async.AsyncServlet] - AsyncListener.onComplete(): id:   4, duration:    2, response: HTTP/1.1 200 
Connection: close
Content-Type: text/xml
Date: Mon, 03 Apr 2023 01:14:27 GMT


2023-04-02 18:14:27.468 [INFO ] [np.transport.impl.async.AsyncServlet] - HttpServlet.service(): id:   5, request URI: /upnpcallback/dev/RINCON_949F3E89854601400_MS/svc/upnp-org/ContentDirectory/event/cb
2023-04-02 18:14:27.469 [DEBUG] [np.transport.impl.async.AsyncServlet] - Handling Servlet request asynchronously: org.ops4j.pax.web.service.spi.servlet.OsgiHttpServletRequestWrapper@380febf1
2023-04-02 18:14:27.469 [DEBUG] [org.jupnp.transport.Router          ] - Received synchronous stream: 2006640995
2023-04-02 18:14:27.470 [DEBUG] [pnp.transport.spi.GENAEventProcessor] - Value RINCON_38420B14A8AC01400,84 for the state variable RadioFavoritesUpdateID ignored: Can't convert string to number or not in range: RINCON_38420B14A8AC01400,84
2023-04-02 18:14:27.470 [DEBUG] [pnp.transport.spi.GENAEventProcessor] - Value RINCON_38420B14A8AC01400,515 for the state variable RadioLocationUpdateID ignored: Can't convert string to number or not in range: RINCON_38420B14A8AC01400,515
2023-04-02 18:14:27.470 [DEBUG] [np.transport.impl.async.AsyncServlet] - AsyncListener.onComplete(): id:   5, duration:    2, response: HTTP/1.1 200 
Connection: close
Content-Type: text/xml
Date: Mon, 03 Apr 2023 01:14:27 GMT


2023-04-02 18:14:27.490 [INFO ] [np.transport.impl.async.AsyncServlet] - HttpServlet.service(): id:   6, request URI: /upnpcallback/dev/RINCON_5CAAFD5BA47001400_MS/svc/upnp-org/ContentDirectory/event/cb
2023-04-02 18:14:27.490 [DEBUG] [np.transport.impl.async.AsyncServlet] - Handling Servlet request asynchronously: org.ops4j.pax.web.service.spi.servlet.OsgiHttpServletRequestWrapper@1103dd7f
2023-04-02 18:14:27.491 [DEBUG] [org.jupnp.transport.Router          ] - Received synchronous stream: 1003241323
2023-04-02 18:14:27.491 [DEBUG] [pnp.transport.spi.GENAEventProcessor] - Value RINCON_38420B14A8AC01400,84 for the state variable RadioFavoritesUpdateID ignored: Can't convert string to number or not in range: RINCON_38420B14A8AC01400,84
2023-04-02 18:14:27.492 [DEBUG] [pnp.transport.spi.GENAEventProcessor] - Value RINCON_38420B14A8AC01400,515 for the state variable RadioLocationUpdateID ignored: Can't convert string to number or not in range: RINCON_38420B14A8AC01400,515
2023-04-02 18:14:27.492 [DEBUG] [np.transport.impl.async.AsyncServlet] - AsyncListener.onComplete(): id:   6, duration:    2, response: HTTP/1.1 200 
Connection: close
Content-Type: text/xml
Date: Mon, 03 Apr 2023 01:14:27 GMT


2023-04-02 18:14:27.496 [INFO ] [np.transport.impl.async.AsyncServlet] - HttpServlet.service(): id:   7, request URI: /upnpcallback/dev/RINCON_7828CAAEE2FC01400_MS/svc/upnp-org/ContentDirectory/event/cb
2023-04-02 18:14:27.497 [DEBUG] [np.transport.impl.async.AsyncServlet] - Handling Servlet request asynchronously: org.ops4j.pax.web.service.spi.servlet.OsgiHttpServletRequestWrapper@28377863
2023-04-02 18:14:27.498 [DEBUG] [org.jupnp.transport.Router          ] - Received synchronous stream: 88075216
2023-04-02 18:14:27.499 [DEBUG] [pnp.transport.spi.GENAEventProcessor] - Value RINCON_38420B14A8AC01400,84 for the state variable RadioFavoritesUpdateID ignored: Can't convert string to number or not in range: RINCON_38420B14A8AC01400,84
2023-04-02 18:14:27.499 [DEBUG] [pnp.transport.spi.GENAEventProcessor] - Value RINCON_38420B14A8AC01400,515 for the state variable RadioLocationUpdateID ignored: Can't convert string to number or not in range: RINCON_38420B14A8AC01400,515
2023-04-02 18:14:27.500 [DEBUG] [np.transport.impl.async.AsyncServlet] - AsyncListener.onComplete(): id:   7, duration:    4, response: HTTP/1.1 200 
Connection: close
Content-Type: text/xml
Date: Mon, 03 Apr 2023 01:14:27 GMT


2023-04-02 18:14:27.501 [INFO ] [np.transport.impl.async.AsyncServlet] - HttpServlet.service(): id:   8, request URI: /upnpcallback/dev/RINCON_949F3E89854601400_MR/svc/upnp-org/AVTransport/event/cb
2023-04-02 18:14:27.501 [DEBUG] [np.transport.impl.async.AsyncServlet] - Handling Servlet request asynchronously: org.ops4j.pax.web.service.spi.servlet.OsgiHttpServletRequestWrapper@60297f95
2023-04-02 18:14:27.501 [DEBUG] [org.jupnp.transport.Router          ] - Received synchronous stream: 2028365436
2023-04-02 18:14:27.502 [DEBUG] [np.transport.impl.async.AsyncServlet] - AsyncListener.onComplete(): id:   8, duration:    2, response: HTTP/1.1 200 
Connection: close
Content-Type: text/xml
Date: Mon, 03 Apr 2023 01:14:27 GMT


2023-04-02 18:14:27.514 [INFO ] [np.transport.impl.async.AsyncServlet] - HttpServlet.service(): id:   9, request URI: /upnpcallback/dev/RINCON_949F3E89854601400_MR/svc/upnp-org/RenderingControl/event/cb
2023-04-02 18:14:27.514 [DEBUG] [np.transport.impl.async.AsyncServlet] - Handling Servlet request asynchronously: org.ops4j.pax.web.service.spi.servlet.OsgiHttpServletRequestWrapper@76d4b7b2
2023-04-02 18:14:27.514 [DEBUG] [org.jupnp.transport.Router          ] - Received synchronous stream: 741992804
2023-04-02 18:14:27.515 [DEBUG] [np.transport.impl.async.AsyncServlet] - AsyncListener.onComplete(): id:   9, duration:    1, response: HTTP/1.1 200 
Connection: close
Content-Type: text/xml
Date: Mon, 03 Apr 2023 01:14:27 GMT


2023-04-02 18:14:27.518 [INFO ] [np.transport.impl.async.AsyncServlet] - HttpServlet.service(): id:  10, request URI: /upnpcallback/dev/RINCON_5CAAFD5BA47001400_MR/svc/upnp-org/AVTransport/event/cb
2023-04-02 18:14:27.518 [DEBUG] [np.transport.impl.async.AsyncServlet] - Handling Servlet request asynchronously: org.ops4j.pax.web.service.spi.servlet.OsgiHttpServletRequestWrapper@7abb4ff8
2023-04-02 18:14:27.518 [DEBUG] [org.jupnp.transport.Router          ] - Received synchronous stream: 1523216445
2023-04-02 18:14:27.523 [DEBUG] [np.transport.impl.async.AsyncServlet] - AsyncListener.onComplete(): id:  10, duration:    5, response: HTTP/1.1 200 
Connection: close
Content-Type: text/xml
Date: Mon, 03 Apr 2023 01:14:27 GMT


2023-04-02 18:14:27.538 [INFO ] [np.transport.impl.async.AsyncServlet] - HttpServlet.service(): id:  11, request URI: /upnpcallback/dev/RINCON_5CAAFD5BA47001400_MR/svc/upnp-org/RenderingControl/event/cb
2023-04-02 18:14:27.538 [DEBUG] [np.transport.impl.async.AsyncServlet] - Handling Servlet request asynchronously: org.ops4j.pax.web.service.spi.servlet.OsgiHttpServletRequestWrapper@13b1c285
2023-04-02 18:14:27.539 [DEBUG] [org.jupnp.transport.Router          ] - Received synchronous stream: 1772800584
2023-04-02 18:14:27.540 [DEBUG] [np.transport.impl.async.AsyncServlet] - AsyncListener.onComplete(): id:  11, duration:    2, response: HTTP/1.1 200 
Connection: close
Content-Type: text/xml
Date: Mon, 03 Apr 2023 01:14:27 GMT


2023-04-02 18:14:34.106 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 169.254.85.236:55625 on local interface: vethac53f5d and address: 169.254.155.67
2023-04-02 18:14:34.106 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.105:37788 on local interface: enp5s0 and address: 192.168.1.105
2023-04-02 18:14:34.106 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 169.254.155.67:35740 on local interface: veth66a1bab and address: 169.254.155.67
2023-04-02 18:14:34.106 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 169.254.199.104:54524 on local interface: veth73c8cd2 and address: 169.254.155.67
2023-04-02 18:14:34.106 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 169.254.131.88:52377 on local interface: veth8437ba6 and address: 169.254.155.67
2023-04-02 18:14:34.106 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 169.254.221.238:49361 on local interface: veth0fffc8d and address: 169.254.155.67
2023-04-02 18:14:34.107 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) M-SEARCH
2023-04-02 18:14:34.107 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) M-SEARCH
2023-04-02 18:14:34.107 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) M-SEARCH
2023-04-02 18:14:34.107 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) M-SEARCH
2023-04-02 18:14:34.107 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) M-SEARCH
2023-04-02 18:14:34.106 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) M-SEARCH
2023-04-02 18:14:34.109 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 169.254.54.176:48093 on local interface: enp5s0 and address: 169.254.155.67
2023-04-02 18:14:34.109 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) M-SEARCH
2023-04-02 18:14:40.544 [INFO ] [s.internal.handler.ZonePlayerHandler] - UPnP device RINCON_7828CAABC74601400 is absent (thing sonos:PLAY1:RINCON_7828CAABC74601400)
2023-04-02 18:14:40.546 [INFO ] [s.internal.handler.ZonePlayerHandler] - UPnP device RINCON_949F3E89844201400 is absent (thing sonos:PLAY1:RINCON_949F3E89844201400)
2023-04-02 18:14:40.547 [INFO ] [s.internal.handler.ZonePlayerHandler] - UPnP device RINCON_38420B14A8AC01400 is absent (thing sonos:OneSL:RINCON_38420B14A8AC01400)
2023-04-02 18:14:40.551 [INFO ] [s.internal.handler.ZonePlayerHandler] - UPnP device RINCON_7828CAAEE2FC01400 is absent (thing sonos:PLAY1:RINCON_7828CAAEE2FC01400)
2023-04-02 18:14:40.555 [INFO ] [s.internal.handler.ZonePlayerHandler] - UPnP device RINCON_949F3E89854601400 is absent (thing sonos:PLAY1:RINCON_949F3E89854601400)
2023-04-02 18:14:40.556 [INFO ] [s.internal.handler.ZonePlayerHandler] - UPnP device RINCON_7828CAA5029201400 is absent (thing sonos:PLAY1:RINCON_7828CAA5029201400)
2023-04-02 18:14:40.559 [INFO ] [s.internal.handler.ZonePlayerHandler] - UPnP device RINCON_5CAAFD5BA47001400 is absent (thing sonos:PLAY3:RINCON_5CAAFD5BA47001400)
2023-04-02 18:14:40.567 [INFO ] [s.internal.handler.ZonePlayerHandler] - UPnP device RINCON_F0F6C13140DE01400 is absent (thing sonos:RoamSL:RINCON_F0F6C13140DE01400)
2023-04-02 18:14:40.570 [DEBUG] [org.jupnp.transport.Router          ] - Disabling network services...
2023-04-02 18:14:40.571 [DEBUG] [org.jupnp.transport.Router          ] - Stopping stream client connection management/pool
2023-04-02 18:14:40.572 [DEBUG] [org.jupnp.transport.Router          ] - Stopping stream server on address: /169.254.221.238
2023-04-02 18:14:40.573 [DEBUG] [org.jupnp.transport.Router          ] - Stopping stream server on address: /172.17.0.1
2023-04-02 18:14:40.573 [DEBUG] [org.jupnp.transport.Router          ] - Stopping stream server on address: /169.254.226.255
2023-04-02 18:14:40.573 [DEBUG] [org.jupnp.transport.Router          ] - Stopping stream server on address: /192.168.1.105
2023-04-02 18:14:40.573 [DEBUG] [org.jupnp.transport.Router          ] - Stopping stream server on address: /169.254.18.215
2023-04-02 18:14:40.573 [DEBUG] [org.jupnp.transport.Router          ] - Stopping stream server on address: /169.254.117.53
2023-04-02 18:14:40.573 [DEBUG] [org.jupnp.transport.Router          ] - Stopping stream server on address: /169.254.155.67
2023-04-02 18:14:40.573 [DEBUG] [org.jupnp.transport.Router          ] - Stopping stream server on address: /169.254.54.176
2023-04-02 18:14:40.573 [DEBUG] [org.jupnp.transport.Router          ] - Stopping stream server on address: /169.254.242.241
2023-04-02 18:14:40.573 [DEBUG] [org.jupnp.transport.Router          ] - Stopping multicast receiver on interface: enp5s0
2023-04-02 18:14:40.573 [DEBUG] [upnp.transport.spi.MulticastReceiver] - Leaving multicast group
2023-04-02 18:14:40.574 [DEBUG] [org.jupnp.transport.Router          ] - Stopping multicast receiver on interface: veth73c8cd2
2023-04-02 18:14:40.574 [DEBUG] [upnp.transport.spi.MulticastReceiver] - Socket closed
2023-04-02 18:14:40.574 [DEBUG] [upnp.transport.spi.MulticastReceiver] - Leaving multicast group
2023-04-02 18:14:40.574 [DEBUG] [org.jupnp.transport.Router          ] - Stopping multicast receiver on interface: veth0fffc8d
2023-04-02 18:14:40.574 [DEBUG] [upnp.transport.spi.MulticastReceiver] - Leaving multicast group
2023-04-02 18:14:40.574 [DEBUG] [org.jupnp.transport.Router          ] - Stopping multicast receiver on interface: vethac53f5d
2023-04-02 18:14:40.574 [DEBUG] [upnp.transport.spi.MulticastReceiver] - Leaving multicast group
2023-04-02 18:14:40.574 [DEBUG] [upnp.transport.spi.MulticastReceiver] - Socket closed
2023-04-02 18:14:40.574 [DEBUG] [org.jupnp.transport.Router          ] - Stopping multicast receiver on interface: veth66a1bab
2023-04-02 18:14:40.574 [DEBUG] [upnp.transport.spi.MulticastReceiver] - Leaving multicast group
2023-04-02 18:14:40.574 [DEBUG] [org.jupnp.transport.Router          ] - Stopping multicast receiver on interface: veth8437ba6
2023-04-02 18:14:40.574 [DEBUG] [upnp.transport.spi.MulticastReceiver] - Leaving multicast group
2023-04-02 18:14:40.574 [DEBUG] [upnp.transport.spi.MulticastReceiver] - Socket closed
2023-04-02 18:14:40.574 [DEBUG] [org.jupnp.transport.Router          ] - Stopping multicast receiver on interface: docker0
2023-04-02 18:14:40.574 [DEBUG] [upnp.transport.spi.MulticastReceiver] - Leaving multicast group
2023-04-02 18:14:40.574 [DEBUG] [org.jupnp.transport.Router          ] - Stopping datagram I/O on address: /169.254.221.238
2023-04-02 18:14:40.575 [DEBUG] [org.jupnp.transport.Router          ] - Stopping datagram I/O on address: /172.17.0.1
2023-04-02 18:14:40.575 [DEBUG] [upnp.transport.spi.MulticastReceiver] - Socket closed
2023-04-02 18:14:40.575 [DEBUG] [upnp.transport.spi.MulticastReceiver] - Socket closed
2023-04-02 18:14:40.575 [DEBUG] [.jupnp.transport.impl.DatagramIOImpl] - Socket closed
2023-04-02 18:14:40.575 [DEBUG] [upnp.transport.spi.MulticastReceiver] - Socket closed
2023-04-02 18:14:40.575 [DEBUG] [org.jupnp.transport.Router          ] - Stopping datagram I/O on address: /169.254.226.255
2023-04-02 18:14:40.575 [DEBUG] [.jupnp.transport.impl.DatagramIOImpl] - Socket closed
2023-04-02 18:14:40.575 [DEBUG] [org.jupnp.transport.Router          ] - Stopping datagram I/O on address: /192.168.1.105
2023-04-02 18:14:40.575 [DEBUG] [.jupnp.transport.impl.DatagramIOImpl] - Socket closed
2023-04-02 18:14:40.575 [DEBUG] [.jupnp.transport.impl.DatagramIOImpl] - Socket closed
2023-04-02 18:14:40.575 [DEBUG] [org.jupnp.transport.Router          ] - Stopping datagram I/O on address: /169.254.18.215
2023-04-02 18:14:40.575 [DEBUG] [.jupnp.transport.impl.DatagramIOImpl] - Socket closed
2023-04-02 18:14:40.576 [DEBUG] [org.jupnp.transport.Router          ] - Stopping datagram I/O on address: /169.254.117.53
2023-04-02 18:14:40.576 [DEBUG] [.jupnp.transport.impl.DatagramIOImpl] - Socket closed
2023-04-02 18:14:40.576 [DEBUG] [org.jupnp.transport.Router          ] - Stopping datagram I/O on address: /169.254.155.67
2023-04-02 18:14:40.576 [DEBUG] [.jupnp.transport.impl.DatagramIOImpl] - Socket closed
2023-04-02 18:14:40.576 [DEBUG] [org.jupnp.transport.Router          ] - Stopping datagram I/O on address: /169.254.54.176
2023-04-02 18:14:40.576 [DEBUG] [.jupnp.transport.impl.DatagramIOImpl] - Socket closed
2023-04-02 18:14:40.576 [DEBUG] [org.jupnp.transport.Router          ] - Stopping datagram I/O on address: /169.254.242.241
2023-04-02 18:14:40.576 [DEBUG] [.jupnp.transport.impl.DatagramIOImpl] - Socket closed
2023-04-02 18:14:40.576 [DEBUG] [org.jupnp.transport.Router          ] - Starting networking services...
2023-04-02 18:14:40.577 [DEBUG] [upnp.transport.spi.MulticastReceiver] - Socket closed
2023-04-02 18:14:40.577 [DEBUG] [org.jupnp.transport.Router          ] - Init multicast receiver on interface: veth66a1bab
2023-04-02 18:14:40.577 [DEBUG] [upnp.transport.spi.MulticastReceiver] - Creating wildcard socket (for receiving multicast datagrams) on port: 1900
2023-04-02 18:14:40.577 [DEBUG] [upnp.transport.spi.MulticastReceiver] - Joining multicast group: /239.255.255.250:1900 on network interface: veth66a1bab
2023-04-02 18:14:40.577 [DEBUG] [org.jupnp.transport.Router          ] - Init multicast receiver on interface: veth73c8cd2
2023-04-02 18:14:40.577 [DEBUG] [upnp.transport.spi.MulticastReceiver] - Creating wildcard socket (for receiving multicast datagrams) on port: 1900
2023-04-02 18:14:40.577 [DEBUG] [upnp.transport.spi.MulticastReceiver] - Joining multicast group: /239.255.255.250:1900 on network interface: veth73c8cd2
2023-04-02 18:14:40.577 [DEBUG] [org.jupnp.transport.Router          ] - Init multicast receiver on interface: veth8437ba6
2023-04-02 18:14:40.577 [DEBUG] [upnp.transport.spi.MulticastReceiver] - Creating wildcard socket (for receiving multicast datagrams) on port: 1900
2023-04-02 18:14:40.577 [DEBUG] [upnp.transport.spi.MulticastReceiver] - Joining multicast group: /239.255.255.250:1900 on network interface: veth8437ba6
2023-04-02 18:14:40.578 [DEBUG] [org.jupnp.transport.Router          ] - Init multicast receiver on interface: veth0fffc8d
2023-04-02 18:14:40.578 [DEBUG] [upnp.transport.spi.MulticastReceiver] - Creating wildcard socket (for receiving multicast datagrams) on port: 1900
2023-04-02 18:14:40.578 [DEBUG] [upnp.transport.spi.MulticastReceiver] - Joining multicast group: /239.255.255.250:1900 on network interface: veth0fffc8d
2023-04-02 18:14:40.578 [DEBUG] [org.jupnp.transport.Router          ] - Init multicast receiver on interface: vethac53f5d
2023-04-02 18:14:40.578 [DEBUG] [upnp.transport.spi.MulticastReceiver] - Creating wildcard socket (for receiving multicast datagrams) on port: 1900
2023-04-02 18:14:40.578 [DEBUG] [upnp.transport.spi.MulticastReceiver] - Joining multicast group: /239.255.255.250:1900 on network interface: vethac53f5d
2023-04-02 18:14:40.578 [DEBUG] [org.jupnp.transport.Router          ] - Init multicast receiver on interface: docker0
2023-04-02 18:14:40.578 [DEBUG] [upnp.transport.spi.MulticastReceiver] - Creating wildcard socket (for receiving multicast datagrams) on port: 1900
2023-04-02 18:14:40.578 [DEBUG] [upnp.transport.spi.MulticastReceiver] - Joining multicast group: /239.255.255.250:1900 on network interface: docker0
2023-04-02 18:14:40.578 [DEBUG] [org.jupnp.transport.Router          ] - Init multicast receiver on interface: enp5s0
2023-04-02 18:14:40.579 [DEBUG] [upnp.transport.spi.MulticastReceiver] - Creating wildcard socket (for receiving multicast datagrams) on port: 1900
2023-04-02 18:14:40.579 [DEBUG] [upnp.transport.spi.MulticastReceiver] - Joining multicast group: /239.255.255.250:1900 on network interface: enp5s0
@JustinGeorgi JustinGeorgi added the bug An unexpected problem or unintended behavior of an add-on label Apr 3, 2023
@openhab-bot
Copy link
Collaborator

This issue has been mentioned on openHAB Community. There might be relevant details there:

https://community.openhab.org/t/all-sonos-things-flapping-every-minute/145765/9

@lolodomo lolodomo changed the title [Sonos] all speaker things flapping every minute [Sonos] all speaker things flapping every minute (OH in docker) May 1, 2023
@lsiepel
Copy link
Contributor

lsiepel commented Feb 20, 2024 •
edited

Not sure if you still experience this issue, but the last snapshot build's have an upgraded jUPnP library. Maybe worth a while to test if that improves on the matter. From the binding perspective, i don't think there is anything that can be done to fix this issue. Docker / network / uPnP that is all sort of transparant to the binding.

@JustinGeorgi
Copy link
Author

the last snapshot build's have an upgraded jUPnP library

That very interesting news, thank you. I have been able to manage the issue, but that's not the same as fixing it, so I will definitely take a look at the new snapshots when I have a chance.

@lolodomo
Copy link
Contributor

You can find answers on the community forum or in documentation:
https://next.openhab.org/docs/installation/docker.html#universal-plug-and-play-upnp

@JustinGeorgi
Copy link
Author

You can find answers on the community forum or in documentation:

I've followed all the forum threads about this. Every time I try the Dorg.jupnp.network.useInterfaces Dorg.jupnp.network.useAddresses suggestions (and I've done it three or four times), far from fixing the problem, my container looses all connection to the internet. I don't know what I'm doing wrong or is different about my setup that causes this problem. I'll have time to try again soon and report back if the new update changes anything.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug An unexpected problem or unintended behavior of an add-on
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@openhab-bot @lolodomo @lsiepel @JustinGeorgi