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

[samsungtv] Not all services found, some channels not available #7406

Closed
martin5233 opened this issue Apr 18, 2020 · 7 comments · Fixed by #11487
Closed

[samsungtv] Not all services found, some channels not available #7406

martin5233 opened this issue Apr 18, 2020 · 7 comments · Fixed by #11487
Labels
bug An unexpected problem or unintended behavior of an add-on

Comments

@martin5233
Copy link

Expected Behavior

The binding should recognize all UPNP services offered by the TV set (UE32ES6300) and therefore should provide access to all supported channels like current channel, source etc.

Current Behavior

Instead only the MediaRenderer service is recognized, which provides access to channels, such as brightness, color etc. The other two services RemoteControlReceiver and MainTVServer2 are not recognized and therefore the channels for the current program, source etc. are missing. I have verified the existence of the other services using other programs like gupnp-universal-cp.
I managed to get all services once after adding the missing MAC address. However after turning the TV off and on again, they were not recognized anymore.
I have attached three log files:

  • The one successful attempt with DEBUG level turned on for the SamsungTV binding
2020-04-17 06:45:30.869 [DEBUG] [tv.internal.handler.SamsungTvHandler] - Initializing Samsung TV handler for uid 'samsungtv:tv:0ee6b281_00fa_1000_a4e3_1c5a3e65d29d'
2020-04-17 06:45:30.935 [DEBUG] [tv.internal.handler.SamsungTvHandler] - thingDiscovered: 192.168.1.20, DiscoveryResult [thingUID=samsungtv:tv:0ee6b281_00fa_1000_a4e3_1c5a3e65d29d, properties={hostName=192.168.1.20}, representationProperty=null, flag=NEW, label=[TV]UE32ES6300, bridgeUID=null, ttl=-1, timestamp=1587097438741]
2020-04-17 06:45:30.953 [DEBUG] [tv.internal.handler.SamsungTvHandler] - thingDiscovered, thingUID=samsungtv:tv:0ee6b281_00fa_1000_a4e3_1c5a3e65d29d, discoveredUID=samsungtv:tv:0ee6b281_00fa_1000_a4e3_1c5a3e65d29d
2020-04-17 06:45:30.959 [DEBUG] [tv.internal.handler.SamsungTvHandler] - Check and create missing UPnP services
2020-04-17 06:45:30.978 [DEBUG] [rnal.service.RemoteControllerService] - Creating a Samsung TV RemoteController service: true
2020-04-17 06:45:30.988 [INFO ] [rnal.service.RemoteControllerService] - Using Legacy interface
2020-04-17 06:45:31.012 [DEBUG] [rnal.protocol.RemoteControllerLegacy] - Open connection to host '192.168.1.20:55000'
2020-04-17 06:45:31.038 [DEBUG] [rnal.protocol.RemoteControllerLegacy] - Connection successfully opened...querying access
2020-04-17 06:45:31.100 [DEBUG] [rnal.protocol.RemoteControllerLegacy] - Access granted
2020-04-17 06:45:31.105 [DEBUG] [tv.internal.handler.SamsungTvHandler] - Started service for: UE32ES6300, RemoteControlReceiver (0e4e1c00-00f0-1000-9043-1c5a3e65d29d)
2020-04-17 06:45:31.213 [DEBUG] [nternal.service.MediaRendererService] - Creating a Samsung TV MediaRenderer service
2020-04-17 06:45:31.231 [DEBUG] [nternal.service.MediaRendererService] - Start refresh task, interval=1000
2020-04-17 06:45:31.272 [DEBUG] [tv.internal.handler.SamsungTvHandler] - Started service for: UE32ES6300, MediaRenderer (0ee6b281-00fa-1000-a4e3-1c5a3e65d29d)
2020-04-17 06:45:31.356 [DEBUG] [internal.service.MainTVServerService] - Creating a Samsung TV MainTVServer service
2020-04-17 06:45:31.462 [DEBUG] [internal.service.MainTVServerService] - Start refresh task, interval=1000
2020-04-17 06:45:31.534 [DEBUG] [tv.internal.handler.SamsungTvHandler] - Started service for: UE32ES6300, MainTVServer2 (0ee6b280-00fa-1000-aba1-1c5a3e65d29d)
2020-04-17 06:45:31.591 [DEBUG] [tv.internal.handler.SamsungTvHandler] - Received value 'volume':'16' for thing 'samsungtv:tv:0ee6b281_00fa_1000_a4e3_1c5a3e65d29d'
2020-04-17 06:45:31.636 [DEBUG] [tv.internal.handler.SamsungTvHandler] - Check and create missing UPnP services
2020-04-17 06:45:31.677 [DEBUG] [tv.internal.handler.SamsungTvHandler] - Service rediscovered, clearing caches: UE32ES6300, RemoteControlReceiver (0e4e1c00-00f0-1000-9043-1c5a3e65d29d)
2020-04-17 06:45:31.773 [DEBUG] [tv.internal.handler.SamsungTvHandler] - Received value 'mute':'ON' for thing 'samsungtv:tv:0ee6b281_00fa_1000_a4e3_1c5a3e65d29d'
2020-04-17 06:45:31.795 [DEBUG] [tv.internal.handler.SamsungTvHandler] - Service rediscovered, clearing caches: UE32ES6300, MediaRenderer (0ee6b281-00fa-1000-a4e3-1c5a3e65d29d)
2020-04-17 06:45:31.900 [DEBUG] [tv.internal.handler.SamsungTvHandler] - Service rediscovered, clearing caches: UE32ES6300, MainTVServer2 (0ee6b280-00fa-1000-aba1-1c5a3e65d29d)
2020-04-17 06:45:32.294 [DEBUG] [tv.internal.handler.SamsungTvHandler] - Received value 'channel':'1' for thing 'samsungtv:tv:0ee6b281_00fa_1000_a4e3_1c5a3e65d29d'
2020-04-17 06:45:32.378 [DEBUG] [tv.internal.handler.SamsungTvHandler] - Received value 'brightness':'45' for thing 'samsungtv:tv:0ee6b281_00fa_1000_a4e3_1c5a3e65d29d'
2020-04-17 06:45:32.412 [DEBUG] [tv.internal.handler.SamsungTvHandler] - Received value 'sourceId':'0' for thing 'samsungtv:tv:0ee6b281_00fa_1000_a4e3_1c5a3e65d29d'
2020-04-17 06:45:32.429 [DEBUG] [tv.internal.handler.SamsungTvHandler] - Received value 'sourceName':'TV' for thing 'samsungtv:tv:0ee6b281_00fa_1000_a4e3_1c5a3e65d29d'
2020-04-17 06:45:32.502 [DEBUG] [tv.internal.handler.SamsungTvHandler] - Received value 'contrast':'95' for thing 'samsungtv:tv:0ee6b281_00fa_1000_a4e3_1c5a3e65d29d'
2020-04-17 06:45:32.589 [DEBUG] [tv.internal.handler.SamsungTvHandler] - Received value 'sharpness':'20' for thing 'samsungtv:tv:0ee6b281_00fa_1000_a4e3_1c5a3e65d29d'
2020-04-17 06:45:32.721 [DEBUG] [tv.internal.handler.SamsungTvHandler] - Received value 'colorTemperature':'3' for thing 'samsungtv:tv:0ee6b281_00fa_1000_a4e3_1c5a3e65d29d'
2020-04-17 06:45:33.767 [DEBUG] [tv.internal.handler.SamsungTvHandler] - Received value 'volume':'16' for thing 'samsungtv:tv:0ee6b281_00fa_1000_a4e3_1c5a3e65d29d'
2020-04-17 06:45:33.809 [DEBUG] [tv.internal.handler.SamsungTvHandler] - Received value 'channel':'1' for thing 'samsungtv:tv:0ee6b281_00fa_1000_a4e3_1c5a3e65d29d'
2020-04-17 06:45:33.835 [DEBUG] [tv.internal.handler.SamsungTvHandler] - Received value 'mute':'ON' for thing 'samsungtv:tv:0ee6b281_00fa_1000_a4e3_1c5a3e65d29d'
  • A failing attempt with DEBUG level turned on for the SamsungTV binding
2020-04-17 14:29:22.168 [DEBUG] [tv.internal.handler.SamsungTvHandler] - Initializing Samsung TV handler for uid 'samsungtv:tv:0ee6b281_00fa_1000_a4e3_1c5a3e65d29d'
2020-04-17 14:29:22.281 [DEBUG] [tv.internal.handler.SamsungTvHandler] - thingDiscovered: 192.168.1.20, DiscoveryResult [thingUID=samsungtv:tv:0ee6b281_00fa_1000_a4e3_1c5a3e65d29d, properties={hostName=192.168.1.20}, representationProperty=null, flag=NEW, label=[TV]UE32ES6300, bridgeUID=null, ttl=-1, timestamp=1587126457119]
2020-04-17 14:29:22.319 [DEBUG] [tv.internal.handler.SamsungTvHandler] - thingDiscovered, thingUID=samsungtv:tv:0ee6b281_00fa_1000_a4e3_1c5a3e65d29d, discoveredUID=samsungtv:tv:0ee6b281_00fa_1000_a4e3_1c5a3e65d29d
2020-04-17 14:29:22.333 [DEBUG] [tv.internal.handler.SamsungTvHandler] - Check and create missing UPnP services
2020-04-17 14:29:22.378 [DEBUG] [nternal.service.MediaRendererService] - Creating a Samsung TV MediaRenderer service
2020-04-17 14:29:22.405 [DEBUG] [nternal.service.MediaRendererService] - Start refresh task, interval=1000
2020-04-17 14:29:22.445 [DEBUG] [tv.internal.handler.SamsungTvHandler] - Started service for: UE32ES6300, MediaRenderer (0ee6b281-00fa-1000-a4e3-1c5a3e65d29d)
2020-04-17 14:29:22.540 [DEBUG] [rnal.service.RemoteControllerService] - Creating a Samsung TV RemoteController service: false
2020-04-17 14:29:22.577 [INFO ] [rnal.service.RemoteControllerService] - Using Legacy interface
2020-04-17 14:29:22.613 [DEBUG] [rnal.protocol.RemoteControllerLegacy] - Open connection to host '192.168.1.20:55000'
2020-04-17 14:29:22.652 [DEBUG] [rnal.protocol.RemoteControllerLegacy] - Connection successfully opened...querying access
2020-04-17 14:29:22.736 [DEBUG] [rnal.protocol.RemoteControllerLegacy] - Access granted
2020-04-17 14:29:22.780 [DEBUG] [tv.internal.handler.SamsungTvHandler] - Received value 'volume':'16' for thing 'samsungtv:tv:0ee6b281_00fa_1000_a4e3_1c5a3e65d29d'
2020-04-17 14:29:22.797 [DEBUG] [tv.internal.handler.SamsungTvHandler] - Check and create missing UPnP services
2020-04-17 14:29:22.842 [DEBUG] [tv.internal.handler.SamsungTvHandler] - Service rediscovered, clearing caches: UE32ES6300, MediaRenderer (0ee6b281-00fa-1000-a4e3-1c5a3e65d29d)
2020-04-17 14:29:22.926 [DEBUG] [tv.internal.handler.SamsungTvHandler] - Received value 'mute':'OFF' for thing 'samsungtv:tv:0ee6b281_00fa_1000_a4e3_1c5a3e65d29d'
2020-04-17 14:29:23.037 [DEBUG] [tv.internal.handler.SamsungTvHandler] - Received value 'brightness':'45' for thing 'samsungtv:tv:0ee6b281_00fa_1000_a4e3_1c5a3e65d29d'
2020-04-17 14:29:23.133 [DEBUG] [tv.internal.handler.SamsungTvHandler] - Received value 'contrast':'95' for thing 'samsungtv:tv:0ee6b281_00fa_1000_a4e3_1c5a3e65d29d'
2020-04-17 14:29:23.228 [DEBUG] [tv.internal.handler.SamsungTvHandler] - Received value 'sharpness':'20' for thing 'samsungtv:tv:0ee6b281_00fa_1000_a4e3_1c5a3e65d29d'
2020-04-17 14:29:23.379 [DEBUG] [tv.internal.handler.SamsungTvHandler] - Received value 'colorTemperature':'3' for thing 'samsungtv:tv:0ee6b281_00fa_1000_a4e3_1c5a3e65d29d'
2020-04-17 14:29:24.477 [DEBUG] [tv.internal.handler.SamsungTvHandler] - Received value 'volume':'16' for thing 'samsungtv:tv:0ee6b281_00fa_1000_a4e3_1c5a3e65d29d'
2020-04-17 14:29:24.575 [DEBUG] [tv.internal.handler.SamsungTvHandler] - Received value 'mute':'OFF' for thing 'samsungtv:tv:0ee6b281_00fa_1000_a4e3_1c5a3e65d29d'

  • A failing attempt with additionally turned on DEBUG info for org,jupnp
2020-04-17 17:54:50.953 [DEBUG] [p.protocol.RetrieveRemoteDescriptors] - Sending device descriptor retrieval message: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_2_
2020-04-17 17:54:50.993 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_2_
2020-04-17 17:54:51.002 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.20:24234 on local interface: eth0 and address: 192.168.1.41
2020-04-17 17:54:51.015 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2020-04-17 17:54:51.028 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.20:24234 on local interface: eth0 and address: 192.168.1.41
2020-04-17 17:54:51.034 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2020-04-17 17:54:51.062 [WARN ] [.util.SpecificationViolationReporter] - UPnP specification violation: org.eclipse.jetty.client.HttpResponseException: HTTP protocol violation: Authentication challenge without WWW-Authenticate header
2020-04-17 17:54:51.068 [WARN ] [p.protocol.RetrieveRemoteDescriptors] - Device descriptor retrieval failed, no response: http://192.168.1.20:7676/smp_2_
2020-04-17 17:54:51.073 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.20:24234 on local interface: eth0 and address: 192.168.1.41
2020-04-17 17:54:51.087 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2020-04-17 17:54:51.091 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.20:24234 on local interface: eth0 and address: 192.168.1.41
2020-04-17 17:54:51.084 [DEBUG] [p.protocol.RetrieveRemoteDescriptors] - Sending device descriptor retrieval message: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_2_
2020-04-17 17:54:51.098 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_2_
2020-04-17 17:54:51.107 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2020-04-17 17:54:51.107 [DEBUG] [org.jupnp.transport.spi.StreamClient] - Will not attempt request because it failed in the last 600 seconds: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_2_
2020-04-17 17:54:51.114 [WARN ] [p.protocol.RetrieveRemoteDescriptors] - Device descriptor retrieval failed, no response: http://192.168.1.20:7676/smp_2_
2020-04-17 17:54:51.128 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.20:24234 on local interface: eth0 and address: 192.168.1.41
2020-04-17 17:54:51.128 [DEBUG] [p.protocol.RetrieveRemoteDescriptors] - Sending device descriptor retrieval message: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_6_
2020-04-17 17:54:51.143 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_6_
2020-04-17 17:54:51.146 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2020-04-17 17:54:51.162 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.20:24234 on local interface: eth0 and address: 192.168.1.41
2020-04-17 17:54:51.191 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2020-04-17 17:54:51.199 [WARN ] [.util.SpecificationViolationReporter] - UPnP specification violation: org.eclipse.jetty.client.HttpResponseException: HTTP protocol violation: Authentication challenge without WWW-Authenticate header
2020-04-17 17:54:51.208 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.20:24234 on local interface: eth0 and address: 192.168.1.41
2020-04-17 17:54:51.217 [WARN ] [p.protocol.RetrieveRemoteDescriptors] - Device descriptor retrieval failed, no response: http://192.168.1.20:7676/smp_6_
2020-04-17 17:54:51.214 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2020-04-17 17:54:51.252 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.20:24234 on local interface: eth0 and address: 192.168.1.41
2020-04-17 17:54:51.250 [DEBUG] [p.protocol.RetrieveRemoteDescriptors] - Sending device descriptor retrieval message: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_6_
2020-04-17 17:54:51.259 [DEBUG] [p.protocol.RetrieveRemoteDescriptors] - Sending device descriptor retrieval message: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_10_
2020-04-17 17:54:51.264 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_10_
2020-04-17 17:54:51.265 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_6_
2020-04-17 17:54:51.268 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2020-04-17 17:54:51.282 [DEBUG] [org.jupnp.transport.spi.StreamClient] - Will not attempt request because it failed in the last 600 seconds: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_6_
2020-04-17 17:54:51.297 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.20:24234 on local interface: eth0 and address: 192.168.1.41
2020-04-17 17:54:51.286 [WARN ] [p.protocol.RetrieveRemoteDescriptors] - Device descriptor retrieval failed, no response: http://192.168.1.20:7676/smp_6_
2020-04-17 17:54:51.303 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2020-04-17 17:54:51.317 [WARN ] [.util.SpecificationViolationReporter] - UPnP specification violation: org.eclipse.jetty.client.HttpResponseException: HTTP protocol violation: Authentication challenge without WWW-Authenticate header
2020-04-17 17:54:51.322 [WARN ] [p.protocol.RetrieveRemoteDescriptors] - Device descriptor retrieval failed, no response: http://192.168.1.20:7676/smp_10_
2020-04-17 17:54:51.329 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.20:24234 on local interface: eth0 and address: 192.168.1.41
2020-04-17 17:54:51.341 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2020-04-17 17:54:51.352 [DEBUG] [p.protocol.RetrieveRemoteDescriptors] - Sending device descriptor retrieval message: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_10_
2020-04-17 17:54:51.364 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_10_
2020-04-17 17:54:51.363 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.20:24234 on local interface: eth0 and address: 192.168.1.41
2020-04-17 17:54:51.372 [DEBUG] [org.jupnp.transport.spi.StreamClient] - Will not attempt request because it failed in the last 600 seconds: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_10_
2020-04-17 17:54:51.381 [WARN ] [p.protocol.RetrieveRemoteDescriptors] - Device descriptor retrieval failed, no response: http://192.168.1.20:7676/smp_10_
2020-04-17 17:54:51.386 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2020-04-17 17:54:51.391 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.20:24234 on local interface: eth0 and address: 192.168.1.41
2020-04-17 17:54:51.411 [DEBUG] [p.protocol.RetrieveRemoteDescriptors] - Sending device descriptor retrieval message: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_18_
2020-04-17 17:54:51.414 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_18_
2020-04-17 17:54:51.420 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2020-04-17 17:54:51.425 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.20:24234 on local interface: eth0 and address: 192.168.1.41
2020-04-17 17:54:51.445 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2020-04-17 17:54:51.498 [DEBUG] [p.protocol.RetrieveRemoteDescriptors] - Received root device descriptor: (StreamResponseMessage) 200 OK
2020-04-17 17:54:51.482 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.20:24234 on local interface: eth0 and address: 192.168.1.41
2020-04-17 17:54:51.510 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2020-04-17 17:54:51.515 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.20:24234 on local interface: eth0 and address: 192.168.1.41
2020-04-17 17:54:51.522 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2020-04-17 17:54:51.536 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.20:24234 on local interface: eth0 and address: 192.168.1.41
2020-04-17 17:54:51.542 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2020-04-17 17:54:51.558 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.20:24234 on local interface: eth0 and address: 192.168.1.41
2020-04-17 17:54:51.570 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) M-SEARCH
2020-04-17 17:54:51.592 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.20:24234 on local interface: eth0 and address: 192.168.1.41
2020-04-17 17:54:51.608 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) M-SEARCH
2020-04-17 17:54:51.627 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.20:24234 on local interface: eth0 and address: 192.168.1.41
2020-04-17 17:54:51.645 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) M-SEARCH
2020-04-17 17:54:51.663 [DEBUG] [p.protocol.RetrieveRemoteDescriptors] - Remote device described (without services) notifying listeners: (RemoteDevice) Identity: (RemoteDeviceIdentity) UDN: uuid:0ee6b281-00fa-1000-a4e3-1c5a3e65d29d, Descriptor: http://192.168.1.20:7676/smp_18_, Root: true
2020-04-17 17:54:51.665 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.20:24234 on local interface: eth0 and address: 192.168.1.41
2020-04-17 17:54:51.683 [DEBUG] [p.protocol.RetrieveRemoteDescriptors] - Hydrating described device's services: (RemoteDevice) Identity: (RemoteDeviceIdentity) UDN: uuid:0ee6b281-00fa-1000-a4e3-1c5a3e65d29d, Descriptor: http://192.168.1.20:7676/smp_18_, Root: true
2020-04-17 17:54:51.674 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) M-SEARCH
2020-04-17 17:54:51.695 [DEBUG] [p.protocol.RetrieveRemoteDescriptors] - Sending service descriptor retrieval message: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_19_
2020-04-17 17:54:51.714 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.20:24234 on local interface: eth0 and address: 192.168.1.41
2020-04-17 17:54:51.724 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) M-SEARCH
2020-04-17 17:54:51.724 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_19_
2020-04-17 17:54:51.751 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.20:24234 on local interface: eth0 and address: 192.168.1.41
2020-04-17 17:54:51.765 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) M-SEARCH
2020-04-17 17:54:51.791 [DEBUG] [p.protocol.RetrieveRemoteDescriptors] - Received service descriptor, hydrating service model: (StreamResponseMessage) 200 OK
2020-04-17 17:54:51.803 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.20:24234 on local interface: eth0 and address: 192.168.1.41
2020-04-17 17:54:51.813 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2020-04-17 17:54:51.827 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.20:24234 on local interface: eth0 and address: 192.168.1.41
2020-04-17 17:54:51.834 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2020-04-17 17:54:51.838 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.20:24234 on local interface: eth0 and address: 192.168.1.41
2020-04-17 17:54:51.845 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2020-04-17 17:54:51.857 [DEBUG] [p.protocol.RetrieveRemoteDescriptors] - Sending device descriptor retrieval message: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_2_
2020-04-17 17:54:51.871 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_2_
2020-04-17 17:54:51.877 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.20:24234 on local interface: eth0 and address: 192.168.1.41
2020-04-17 17:54:51.876 [DEBUG] [org.jupnp.transport.spi.StreamClient] - Will not attempt request because it failed in the last 600 seconds: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_2_
2020-04-17 17:54:51.886 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2020-04-17 17:54:51.914 [WARN ] [p.protocol.RetrieveRemoteDescriptors] - Device descriptor retrieval failed, no response: http://192.168.1.20:7676/smp_2_
2020-04-17 17:54:51.895 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.20:24234 on local interface: eth0 and address: 192.168.1.41
2020-04-17 17:54:51.930 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2020-04-17 17:54:51.947 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.20:24234 on local interface: eth0 and address: 192.168.1.41
2020-04-17 17:54:51.963 [DEBUG] [p.protocol.RetrieveRemoteDescriptors] - Sending device descriptor retrieval message: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_2_
2020-04-17 17:54:51.966 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2020-04-17 17:54:51.990 [DEBUG] [p.protocol.RetrieveRemoteDescriptors] - Sending device descriptor retrieval message: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_6_
2020-04-17 17:54:51.991 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_2_
2020-04-17 17:54:51.990 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.20:24234 on local interface: eth0 and address: 192.168.1.41
2020-04-17 17:54:51.995 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_6_
2020-04-17 17:54:52.011 [DEBUG] [org.jupnp.transport.spi.StreamClient] - Will not attempt request because it failed in the last 600 seconds: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_6_
2020-04-17 17:54:52.028 [WARN ] [p.protocol.RetrieveRemoteDescriptors] - Device descriptor retrieval failed, no response: http://192.168.1.20:7676/smp_6_
2020-04-17 17:54:52.015 [DEBUG] [org.jupnp.transport.spi.StreamClient] - Will not attempt request because it failed in the last 600 seconds: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_2_
2020-04-17 17:54:52.045 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2020-04-17 17:54:52.044 [WARN ] [p.protocol.RetrieveRemoteDescriptors] - Device descriptor retrieval failed, no response: http://192.168.1.20:7676/smp_2_
2020-04-17 17:54:52.062 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.20:24234 on local interface: eth0 and address: 192.168.1.41
2020-04-17 17:54:52.073 [DEBUG] [p.protocol.RetrieveRemoteDescriptors] - Sending device descriptor retrieval message: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_6_
2020-04-17 17:54:52.087 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_6_
2020-04-17 17:54:52.069 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2020-04-17 17:54:52.100 [DEBUG] [org.jupnp.transport.spi.StreamClient] - Will not attempt request because it failed in the last 600 seconds: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_6_
2020-04-17 17:54:52.103 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.20:24234 on local interface: eth0 and address: 192.168.1.41
2020-04-17 17:54:52.121 [WARN ] [p.protocol.RetrieveRemoteDescriptors] - Device descriptor retrieval failed, no response: http://192.168.1.20:7676/smp_6_
2020-04-17 17:54:52.148 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2020-04-17 17:54:52.164 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.20:24234 on local interface: eth0 and address: 192.168.1.41
2020-04-17 17:54:52.177 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2020-04-17 17:54:52.188 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.20:24234 on local interface: eth0 and address: 192.168.1.41
2020-04-17 17:54:52.207 [DEBUG] [p.protocol.RetrieveRemoteDescriptors] - Sending device descriptor retrieval message: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_10_
2020-04-17 17:54:52.204 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2020-04-17 17:54:52.217 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_10_
2020-04-17 17:54:52.225 [DEBUG] [p.protocol.RetrieveRemoteDescriptors] - Sending device descriptor retrieval message: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_6_
2020-04-17 17:54:52.245 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.20:24234 on local interface: eth0 and address: 192.168.1.41
2020-04-17 17:54:52.240 [DEBUG] [org.jupnp.transport.spi.StreamClient] - Will not attempt request because it failed in the last 600 seconds: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_10_
2020-04-17 17:54:52.268 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2020-04-17 17:54:52.268 [WARN ] [p.protocol.RetrieveRemoteDescriptors] - Device descriptor retrieval failed, no response: http://192.168.1.20:7676/smp_10_
2020-04-17 17:54:52.273 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_6_
2020-04-17 17:54:52.291 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.20:24234 on local interface: eth0 and address: 192.168.1.41
2020-04-17 17:54:52.311 [DEBUG] [p.protocol.RetrieveRemoteDescriptors] - Sending device descriptor retrieval message: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_10_
2020-04-17 17:54:52.307 [DEBUG] [org.jupnp.transport.spi.StreamClient] - Will not attempt request because it failed in the last 600 seconds: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_6_
2020-04-17 17:54:52.316 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_10_
2020-04-17 17:54:52.327 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) NOTIFY
2020-04-17 17:54:52.327 [WARN ] [p.protocol.RetrieveRemoteDescriptors] - Device descriptor retrieval failed, no response: http://192.168.1.20:7676/smp_6_
2020-04-17 17:54:52.338 [DEBUG] [org.jupnp.transport.spi.StreamClient] - Will not attempt request because it failed in the last 600 seconds: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_10_
2020-04-17 17:54:52.343 [WARN ] [p.protocol.RetrieveRemoteDescriptors] - Device descriptor retrieval failed, no response: http://192.168.1.20:7676/smp_10_
2020-04-17 17:54:52.409 [DEBUG] [p.protocol.RetrieveRemoteDescriptors] - Sending device descriptor retrieval message: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_10_
2020-04-17 17:54:52.417 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_10_
2020-04-17 17:54:52.421 [DEBUG] [org.jupnp.transport.spi.StreamClient] - Will not attempt request because it failed in the last 600 seconds: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_10_
2020-04-17 17:54:52.431 [WARN ] [p.protocol.RetrieveRemoteDescriptors] - Device descriptor retrieval failed, no response: http://192.168.1.20:7676/smp_10_
2020-04-17 17:54:52.509 [DEBUG] [p.protocol.RetrieveRemoteDescriptors] - Sending service descriptor retrieval message: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_22_
2020-04-17 17:54:52.517 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_22_
2020-04-17 17:54:52.555 [DEBUG] [p.protocol.RetrieveRemoteDescriptors] - Received service descriptor, hydrating service model: (StreamResponseMessage) 200 OK
2020-04-17 17:54:52.695 [DEBUG] [p.protocol.RetrieveRemoteDescriptors] - Sending service descriptor retrieval message: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_25_
2020-04-17 17:54:52.702 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_25_
2020-04-17 17:54:52.777 [DEBUG] [p.protocol.RetrieveRemoteDescriptors] - Received service descriptor, hydrating service model: (StreamResponseMessage) 200 OK
2020-04-17 17:54:53.100 [DEBUG] [p.protocol.RetrieveRemoteDescriptors] - Adding fully hydrated remote device to registry: (RemoteDevice) Identity: (RemoteDeviceIdentity) UDN: uuid:0ee6b281-00fa-1000-a4e3-1c5a3e65d29d, Descriptor: http://192.168.1.20:7676/smp_18_, Root: true
2020-04-17 17:54:53.112 [DEBUG] [covery.SamsungTvDiscoveryParticipant] - Retrieved Thing UID for a Samsung TV '[TV]UE32ES6300' model 'UE32ES6300' thing with UDN '0ee6b281_00fa_1000_a4e3_1c5a3e65d29d'
2020-04-17 17:54:53.117 [DEBUG] [covery.SamsungTvDiscoveryParticipant] - Created a DiscoveryResult for device 'UE32ES6300' with UDN '0ee6b281-00fa-1000-a4e3-1c5a3e65d29d' and properties: {hostName=192.168.1.20}
2020-04-17 17:54:53.133 [DEBUG] [tv.internal.handler.SamsungTvHandler] - thingDiscovered: 192.168.1.20, DiscoveryResult [thingUID=samsungtv:tv:0ee6b281_00fa_1000_a4e3_1c5a3e65d29d, properties={hostName=192.168.1.20}, representationProperty=null, flag=NEW, label=[TV]UE32ES6300, bridgeUID=null, ttl=-1, timestamp=1587138893116]
2020-04-17 17:54:53.137 [DEBUG] [tv.internal.handler.SamsungTvHandler] - thingDiscovered, thingUID=samsungtv:tv:0ee6b281_00fa_1000_a4e3_1c5a3e65d29d, discoveredUID=samsungtv:tv:0ee6b281_00fa_1000_a4e3_1c5a3e65d29d
2020-04-17 17:54:53.144 [DEBUG] [tv.internal.handler.SamsungTvHandler] - Check and create missing UPnP services
2020-04-17 17:54:53.163 [DEBUG] [nternal.service.MediaRendererService] - Creating a Samsung TV MediaRenderer service
2020-04-17 17:54:53.173 [DEBUG] [nternal.service.MediaRendererService] - Start refresh task, interval=1000
2020-04-17 17:54:53.179 [DEBUG] [tv.internal.handler.SamsungTvHandler] - Started service for: UE32ES6300, MediaRenderer (0ee6b281-00fa-1000-a4e3-1c5a3e65d29d)
2020-04-17 17:54:53.281 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingActionRequestMessage) POST http://192.168.1.20:7676/smp_20_
2020-04-17 17:54:53.255 [DEBUG] [rnal.service.RemoteControllerService] - Creating a Samsung TV RemoteController service: false
2020-04-17 17:54:53.295 [INFO ] [rnal.service.RemoteControllerService] - Using Legacy interface
2020-04-17 17:54:53.300 [DEBUG] [rnal.protocol.RemoteControllerLegacy] - Open connection to host '192.168.1.20:55000'
2020-04-17 17:54:53.340 [DEBUG] [rnal.protocol.RemoteControllerLegacy] - Connection successfully opened...querying access
2020-04-17 17:54:53.443 [DEBUG] [rnal.protocol.RemoteControllerLegacy] - Access granted
2020-04-17 17:54:53.450 [DEBUG] [tv.internal.handler.SamsungTvHandler] - Received value 'volume':'16' for thing 'samsungtv:tv:0ee6b281_00fa_1000_a4e3_1c5a3e65d29d'
2020-04-17 17:54:53.508 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingActionRequestMessage) POST http://192.168.1.20:7676/smp_20_
2020-04-17 17:54:53.557 [DEBUG] [tv.internal.handler.SamsungTvHandler] - Received value 'mute':'OFF' for thing 'samsungtv:tv:0ee6b281_00fa_1000_a4e3_1c5a3e65d29d'
2020-04-17 17:54:53.584 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingActionRequestMessage) POST http://192.168.1.20:7676/smp_20_
2020-04-17 17:54:53.627 [DEBUG] [tv.internal.handler.SamsungTvHandler] - Received value 'brightness':'45' for thing 'samsungtv:tv:0ee6b281_00fa_1000_a4e3_1c5a3e65d29d'
2020-04-17 17:54:53.641 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingActionRequestMessage) POST http://192.168.1.20:7676/smp_20_
2020-04-17 17:54:53.704 [DEBUG] [tv.internal.handler.SamsungTvHandler] - Received value 'contrast':'95' for thing 'samsungtv:tv:0ee6b281_00fa_1000_a4e3_1c5a3e65d29d'
2020-04-17 17:54:53.747 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingActionRequestMessage) POST http://192.168.1.20:7676/smp_20_
2020-04-17 17:54:53.808 [DEBUG] [tv.internal.handler.SamsungTvHandler] - Received value 'sharpness':'20' for thing 'samsungtv:tv:0ee6b281_00fa_1000_a4e3_1c5a3e65d29d'
2020-04-17 17:54:53.833 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingActionRequestMessage) POST http://192.168.1.20:7676/smp_20_
2020-04-17 17:54:53.897 [DEBUG] [tv.internal.handler.SamsungTvHandler] - Received value 'colorTemperature':'3' for thing 'samsungtv:tv:0ee6b281_00fa_1000_a4e3_1c5a3e65d29d'
2020-04-17 17:54:54.918 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingActionRequestMessage) POST http://192.168.1.20:7676/smp_20_
2020-04-17 17:54:55.057 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingActionRequestMessage) POST http://192.168.1.20:7676/smp_20_
2020-04-17 17:54:55.185 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingActionRequestMessage) POST http://192.168.1.20:7676/smp_20_
2020-04-17 17:54:55.299 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingActionRequestMessage) POST http://192.168.1.20:7676/smp_20_
2020-04-17 17:54:55.327 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.1:53391 on local interface: eth0 and address: 192.168.1.41
2020-04-17 17:54:55.333 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) M-SEARCH
2020-04-17 17:54:55.353 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.1:53391 on local interface: eth0 and address: 192.168.1.41
2020-04-17 17:54:55.358 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) M-SEARCH
2020-04-17 17:54:55.378 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.1:53391 on local interface: eth0 and address: 192.168.1.41
2020-04-17 17:54:55.384 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) M-SEARCH
2020-04-17 17:54:55.409 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.1:53391 on local interface: eth0 and address: 192.168.1.41
2020-04-17 17:54:55.414 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) M-SEARCH
2020-04-17 17:54:55.442 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.1:53391 on local interface: eth0 and address: 192.168.1.41
2020-04-17 17:54:55.468 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) M-SEARCH
2020-04-17 17:54:55.477 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingActionRequestMessage) POST http://192.168.1.20:7676/smp_20_
2020-04-17 17:54:55.490 [DEBUG] [upnp.transport.spi.MulticastReceiver] - UDP datagram received from: 192.168.1.1:53391 on local interface: eth0 and address: 192.168.1.41
2020-04-17 17:54:55.501 [DEBUG] [org.jupnp.transport.Router          ] - Received asynchronous message: (IncomingDatagramMessage) M-SEARCH
2020-04-17 17:54:55.581 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingActionRequestMessage) POST http://192.168.1.20:7676/smp_20_
2020-04-17 17:54:56.640 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingActionRequestMessage) POST http://192.168.1.20:7676/smp_20_
2020-04-17 17:54:56.685 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingActionRequestMessage) POST http://192.168.1.20:7676/smp_20_
2020-04-17 17:54:56.747 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingActionRequestMessage) POST http://192.168.1.20:7676/smp_20_
2020-04-17 17:54:56.808 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingActionRequestMessage) POST http://192.168.1.20:7676/smp_20_
2020-04-17 17:54:56.897 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingActionRequestMessage) POST http://192.168.1.20:7676/smp_20_
2020-04-17 17:54:56.982 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingActionRequestMessage) POST http://192.168.1.20:7676/smp_20_
2020-04-17 17:54:58.065 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingActionRequestMessage) POST http://192.168.1.20:7676/smp_20_
2020-04-17 17:54:58.168 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingActionRequestMessage) POST http://192.168.1.20:7676/smp_20_
2020-04-17 17:54:58.258 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingActionRequestMessage) POST http://192.168.1.20:7676/smp_20_
2020-04-17 17:54:58.317 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingActionRequestMessage) POST http://192.168.1.20:7676/smp_20_
2020-04-17 17:54:58.373 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingActionRequestMessage) POST http://192.168.1.20:7676/smp_20_
2020-04-17 17:54:58.437 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingActionRequestMessage) POST http://192.168.1.20:7676/smp_20_
2020-04-17 17:54:59.514 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingActionRequestMessage) POST http://192.168.1.20:7676/smp_20_
2020-04-17 17:54:59.593 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingActionRequestMessage) POST http://192.168.1.20:7676/smp_20_
2020-04-17 17:54:59.703 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingActionRequestMessage) POST http://192.168.1.20:7676/smp_20_
2020-04-17 17:54:59.846 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingActionRequestMessage) POST http://192.168.1.20:7676/smp_20_
2020-04-17 17:54:59.960 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingActionRequestMessage) POST http://192.168.1.20:7676/smp_20_
2020-04-17 17:55:00.036 [DEBUG] [org.jupnp.transport.Router          ] - Sending via TCP unicast stream: (OutgoingActionRequestMessage) POST http://192.168.1.20:7676/smp_20_

Possible Solution

In the log file with jupnp debug info enabled I found two suspicious messages:
Device descriptor retrieval failed, no response: http://192.168.1.20:7676/smp_2_
and

Will not attempt request because it failed in the last 600 seconds: (StreamRequestMessage) GET http://192.168.1.20:7676/smp_6_

I suspect, that the jupnp subsystem has a bug, which causes these messages. When trying out to access the services with gupnp-universal-cp, I also got similar messages:
``** (gupnp-universal-cp:32241): WARNING **: 07:03:04.802: Failed to GET http://192.168.1.20:7676/smp_2_: Unauthorised, retrying in 5 seconds

but the services were still displayed.

Your Environment

  • Version used: OpenHAB 2.5.3, SamsungTV 2.5.3
  • Operating System and version (desktop or mobile, Windows 10, Raspbian Buster, ...):
    Debian Buster running on a Cubietruck
    Samsung TV is connected via WiFi
@martin5233 martin5233 added the bug An unexpected problem or unintended behavior of an add-on label Apr 18, 2020
@lolodomo
Copy link
Contributor

lolodomo commented Apr 19, 2020

What is interesting too is these errors:

UPnP specification violation: org.eclipse.jetty.client.HttpResponseException: HTTP protocol violation: Authentication challenge without WWW-Authenticate header

As your alternative way to request this URL shows, the server (TV) returns a 401 error (Unauthorised). So either this response is missing the expected WWW-Authenticate header or Jetty HTTP client is failing to parse it.
Can you try this URL in a WEB browser to see what happens ?
Why Samsung is protecting these URLs ?!
As I previously said, I see two possibilities:

  1. a bad implementation in the Samsung TV leading to the HTTP protocol violation
  2. a bug in Jetty HTTP client not parsing correctly the HTTP reponse

In JUPnP library, I don't see what we could do better with that. At least, the library is detecting the problem.

@lolodomo
Copy link
Contributor

lolodomo commented Apr 19, 2020

But I understand that you got this 401 response only sometimes and not always ?
Maybe when the TV is not yet really ready, even if UPnP device is found ?

@lolodomo
Copy link
Contributor

In case the GET request to retrieve the device description succeeds after a certain time, we could avoid in the JUPnP library to ignore such requests during 10 minutes after a first failure.
I know how to fix that. First I am waiting for your feedback if the issue (request returning 401) is temporary or not.

@martin5233
Copy link
Author

Thanks for your quick reply. I played around with this a bit more and I think, that there is some timing issue involved. I can access the services via the browser, but sometimes got an error code 401. When I repeated the same request by a reload, it worked. I think, if it would be possible to simply retry to retrieve the service information in case of an error code 401, things would work for my case.

Basically the Samsung implementation is probably buggy. But then it also seems, that other UPNP clients seem to be a bit forgiving, when it comes to protocol violations.

@jlaur
Copy link
Contributor

jlaur commented Oct 31, 2021

@martin5233 - can you try this JAR? https://drive.google.com/file/d/1fG2pukbBj5z7XujGfRZ9a8O4_mVNh9CK/view?usp=sharing - it's a build from #11487

I suspect your issue might be a duplicate of #7055, at least the part about services not working after turning the TV off and on again.

@martin5233
Copy link
Author

@jlaur I have tried this out, and it seems, that now everything is working as it should. I turned the TV off and on again multiple times and each time the online status changed immediately as expected. Also the previously missing services 'RemoteControlReceiver' and 'MainTVServer2' were always detected. Thanks a lot for improving the addon!

@jlaur
Copy link
Contributor

jlaur commented Nov 7, 2021

@jlaur I have tried this out, and it seems, that now everything is working as it should. I turned the TV off and on again multiple times and each time the online status changed immediately as expected. Also the previously missing services 'RemoteControlReceiver' and 'MainTVServer2' were always detected. Thanks a lot for improving the addon!

@martin5233 - thanks for your feedback. I'm glad that it resolved your issues. :-)

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

Successfully merging a pull request may close this issue.

3 participants