search

openhab / openhab-addons

Add-ons for openHAB
https://www.openhab.org/
Eclipse Public License 2.0
1.86k stars 3.58k forks source link

[samsungtv] Exception thrown when connecting to smart things #17228

Open vpant opened 1 month ago

vpant commented 1 month ago

Expected Behavior

Thing should be initialized

Current Behavior

After adding values for Smarthings PAT and device id, I am having this exception in the logs. The thing cannot be unitiliazed and hangs at status UNKNOWN. My TV model is UE50RU7402UXXH.

2024-08-10 22:55:38.823 [DEBUG] [tv.internal.handler.SamsungTvHandler] - 192.168.10.216: Received value 'channelName':'ERT 1 HD' for thing 'samsungtv:tv:SamsungTV'
2024-08-10 22:55:38.824 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method 'ThingHandler.thingUpdated()' on 'org.openhab.binding.samsungtv.internal.handler.SamsungTvHandler@2baea054': Cannot invoke "org.openhab.binding.samsungtv.internal.service.SmartThingsApiService.parseTVChannel(String)" because "this.this$0" is null
java.lang.NullPointerException: Cannot invoke "org.openhab.binding.samsungtv.internal.service.SmartThingsApiService.parseTVChannel(String)" because "this.this$0" is null
    at org.openhab.binding.samsungtv.internal.service.SmartThingsApiService$TvValues.lambda$11(SmartThingsApiService.java:250) ~[?:?]
    at java.util.Optional.map(Optional.java:260) ~[?:?]
    at org.openhab.binding.samsungtv.internal.service.SmartThingsApiService$TvValues.getTvChannel(SmartThingsApiService.java:250) ~[?:?]
    at org.openhab.binding.samsungtv.internal.service.SmartThingsApiService.lambda$2(SmartThingsApiService.java:488) ~[?:?]
    at java.util.Optional.ifPresent(Optional.java:178) ~[?:?]
    at org.openhab.binding.samsungtv.internal.service.SmartThingsApiService.updateTV(SmartThingsApiService.java:486) ~[?:?]
    at org.openhab.binding.samsungtv.internal.service.SmartThingsApiService.lambda$14(SmartThingsApiService.java:719) ~[?:?]
    at java.util.Optional.ifPresent(Optional.java:178) ~[?:?]
    at org.openhab.binding.samsungtv.internal.service.SmartThingsApiService.receiveSSEEvents(SmartThingsApiService.java:718) ~[?:?]
    at org.openhab.binding.samsungtv.internal.service.SmartThingsApiService.startSSE(SmartThingsApiService.java:613) ~[?:?]
    at org.openhab.binding.samsungtv.internal.service.SmartThingsApiService.start(SmartThingsApiService.java:867) ~[?:?]
    at org.openhab.binding.samsungtv.internal.handler.SamsungTvHandler.startService(SamsungTvHandler.java:701) ~[?:?]
    at org.openhab.binding.samsungtv.internal.handler.SamsungTvHandler.createService(SamsungTvHandler.java:652) ~[?:?]
    at org.openhab.binding.samsungtv.internal.handler.SamsungTvHandler.checkAndCreateServices(SamsungTvHandler.java:617) ~[?:?]
    at org.openhab.binding.samsungtv.internal.handler.SamsungTvHandler.initialize(SamsungTvHandler.java:457) ~[?:?]
    at org.openhab.core.thing.binding.BaseThingHandler.thingUpdated(BaseThingHandler.java:157) ~[?:?]
    at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
    at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77) ~[?:?]
    at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
    at java.lang.reflect.Method.invoke(Method.java:568) ~[?:?]
    at org.openhab.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:147) [bundleFile:?]
    at org.openhab.core.internal.common.Invocation.call(Invocation.java:52) [bundleFile:?]
    at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
    at java.lang.Thread.run(Thread.java:840) [?:?]

Steps to Reproduce (for Bugs)

  1. Create new Samsung TV thing and configure it.
  2. Configure Smarthings Connection and save
  3. Thing fails to initialize and logs report exception

Your Environment

RickyTR commented 1 month ago

I have exactly the same problem with both my Samsung TVs. After several tries (and regenerating a new PAT) I managed to configure correctly only one. The same procedure didn’t work on the second one.

lsiepel commented 3 weeks ago

A NPE shoudl certainly not occur, but there might be some unexpected situation before this happens. Maybe @NickWaterton can comment?

NickWaterton commented 3 weeks ago

This is caused by a method that is using a regex to try to extract the channel number from the string “ERT 1 HD” which is a UK satellite channel.

There must be a bug in the way the regex is parsing the string, resulting in the NPE. Usually, if the parse fails, it should return -1, but something else is happening.

I’ll take a look.

NickWaterton commented 3 weeks ago

Just checked, and “ERT 1 HD” is the channel name, which is correct. It’s the channel number that is throwing the error.

I don’t know what the channel number is though.

I haven’t been able to reproduce this yet.

@vpant can you give me the channel number of ERT 1 HD as shown in Smarthings, or on your TV?

vpant commented 3 weeks ago

Hello @NickWaterton,

thank you for your effort in investigating this issue.

The channel number is 1 here is a screenshot showing the channel number and the description of what is playing at the moment. The channels are Greek but I do not think that it has anyting to do with the error.

IMG_0245

Surprisingly, if I open youtube I can normally configure the TV Thing.

here is the logs during successfull initiliazation

==> /var/log/openhab/events.log <==
2024-08-25 18:18:13.144 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'Samsung_TV_Channel_Name' changed from OPEN BEYOND HD to 9Ur5IzDKqV.TizenYouTube

==> /var/log/openhab/openhab.log <==
2024-08-25 18:18:15.147 [DEBUG] [ternal.service.SmartThingsApiService] - 192.168.10.216: SSE job Failed
2024-08-25 18:18:15.147 [DEBUG] [tv.internal.handler.SamsungTvHandler] - 192.168.10.216: Started service for: UE50RU7402UXXH, SmartthingsApi ()
2024-08-25 18:18:15.148 [DEBUG] [tv.internal.handler.SamsungTvHandler] - 192.168.10.216: Start refresh task, interval=1000

==> /var/log/openhab/events.log <==
2024-08-25 18:18:15.149 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'samsungtv:tv:4561f668-a097-42dd-97ec-883605d6039e' changed from UNKNOWN to ONLINE

It seems that channel 9Ur5IzDKqV.TizenYouTube does not cause the NPE but "ERT 1 HD" does. "OPEN BEYOND HD" also have the same issue.

Also tried to configure it sucessfully by opening Youtube and then trying to watch some DTV and the error happended again. Below are the logs of that scenario.

2024-08-25 18:26:26.737 [DEBUG] [tv.internal.handler.SamsungTvHandler] - 192.168.10.216: Started service for: UE50RU7402UXXH, RemoteControlReceiver ()
2024-08-25 18:26:26.739 [DEBUG] [ternal.service.SmartThingsApiService] - 192.168.10.216: Creating a Samsung TV Smartthings Api service
2024-08-25 18:26:26.739 [INFO ] [ternal.service.SmartThingsApiService] - 192.168.10.216: SSE Creating Smartthings Subscription
2024-08-25 18:26:26.841 [DEBUG] [ngtv.internal.protocol.WebSocketBase] - 192.168.10.216: WebSocketArt connection established: 192.168.10.216
2024-08-25 18:26:26.876 [DEBUG] [ungtv.internal.protocol.WebSocketArt] - 192.168.10.216: Art channel connected
2024-08-25 18:26:26.877 [DEBUG] [ngtv.internal.protocol.WebSocketBase] - 192.168.10.216: WebSocketRemote connection established: 192.168.10.216
2024-08-25 18:26:26.927 [DEBUG] [tv.internal.protocol.WebSocketRemote] - 192.168.10.216: Remote channel connected. Token = 
2024-08-25 18:26:26.929 [DEBUG] [ngtv.internal.protocol.WebSocketBase] - 192.168.10.216: WebSocketV2 connection established: 192.168.10.216
2024-08-25 18:26:26.969 [DEBUG] [sungtv.internal.protocol.WebSocketV2] - 192.168.10.216: V2 channel connected. Token = null
2024-08-25 18:26:26.974 [DEBUG] [l.protocol.RemoteControllerWebSocket] - 192.168.10.216: Installed Apps: 3201907018807 = Netflix, 3202008021483 = ERTFLIX, 3201512006785 = Prime Video, 3201511006428 = Rakuten TV, 3201807016658 = Samsung Promotion, 3201704012154 = EON, 3201601007250 = Ταινίες και TV Google Play, 3201512006963 = Plex, 3201901017640 = Disney+, 3201807016597 = Apple TV, 111299001912 = YouTube, 3201805016322 = COSMOTE TV, 20192100002 = e-Manual, 3201909019271 = Επιλογές απορρήτου, 3201706012507 = SWEET.TV, 3201606009684 = Spotify - Μουσική και podcast, 3201710015037 = Gallery, 3202111025588 = ANT1+, 3201908019041 = Apple Music, 3202210028854 = Vodafone TV (GR), 3201710015016 = SmartThings, org.tizen.browser = Internet
2024-08-25 18:26:27.255 [DEBUG] [tv.internal.handler.SamsungTvHandler] - 192.168.10.216: Received value 'channelName':'9Ur5IzDKqV.TizenYouTube' for thing 'samsungtv:tv:4561f668-a097-42dd-97ec-883605d6039e'
2024-08-25 18:26:27.256 [DEBUG] [tv.internal.handler.SamsungTvHandler] - 192.168.10.216: Received value 'channel':'-1.0' for thing 'samsungtv:tv:4561f668-a097-42dd-97ec-883605d6039e'
2024-08-25 18:26:27.257 [DEBUG] [tv.internal.handler.SamsungTvHandler] - 192.168.10.216: Received value 'sourceName':'dtv' for thing 'samsungtv:tv:4561f668-a097-42dd-97ec-883605d6039e'
2024-08-25 18:26:27.257 [DEBUG] [tv.internal.handler.SamsungTvHandler] - 192.168.10.216: Received value 'sourceId':'0' for thing 'samsungtv:tv:4561f668-a097-42dd-97ec-883605d6039e'
2024-08-25 18:26:29.259 [DEBUG] [ternal.service.SmartThingsApiService] - 192.168.10.216: SSE job Failed
2024-08-25 18:26:29.260 [DEBUG] [tv.internal.handler.SamsungTvHandler] - 192.168.10.216: Started service for: UE50RU7402UXXH, SmartthingsApi ()
2024-08-25 18:26:29.260 [DEBUG] [tv.internal.handler.SamsungTvHandler] - 192.168.10.216: Start refresh task, interval=1000

==> /var/log/openhab/events.log <==
2024-08-25 18:26:29.260 [INFO ] [ab.event.ThingStatusInfoChangedEvent] - Thing 'samsungtv:tv:4561f668-a097-42dd-97ec-883605d6039e' changed from UNKNOWN to ONLINE

==> /var/log/openhab/openhab.log <==
2024-08-25 18:26:29.264 [DEBUG] [tv.internal.handler.SamsungTvHandler] - 192.168.10.216: PowerState is: on
2024-08-25 18:26:29.264 [DEBUG] [tv.internal.handler.SamsungTvHandler] - 192.168.10.216: Received value 'power':'ON' for thing 'samsungtv:tv:4561f668-a097-42dd-97ec-883605d6039e'
2024-08-25 18:26:29.265 [DEBUG] [tv.internal.handler.SamsungTvHandler] - 192.168.10.216: TV is ONLINE
2024-08-25 18:26:39.268 [DEBUG] [tv.internal.handler.SamsungTvHandler] - 192.168.10.216: Received value 'volume':'23' for thing 'samsungtv:tv:4561f668-a097-42dd-97ec-883605d6039e'
2024-08-25 18:26:39.273 [DEBUG] [tv.internal.handler.SamsungTvHandler] - 192.168.10.216: Received value 'mute':'OFF' for thing 'samsungtv:tv:4561f668-a097-42dd-97ec-883605d6039e'

==> /var/log/openhab/openhab.log <==
2024-08-25 18:27:15.804 [DEBUG] [tv.internal.handler.SamsungTvHandler] - 192.168.10.216: Polling Job exception: Cannot invoke "org.openhab.binding.samsungtv.internal.service.SmartThingsApiService.parseTVChannel(String)" because "this.this$0" is null
2024-08-25 18:27:16.917 [DEBUG] [tv.internal.handler.SamsungTvHandler] - 192.168.10.216: Polling Job exception: Cannot invoke "org.openhab.binding.samsungtv.internal.service.SmartThingsApiService.parseTVChannel(String)" because "this.this$0" is null

Let me know if there is any more information I can provide.

NickWaterton commented 3 weeks ago

@vpant the reason that YouTube does not cause the issue is that YouTube does not have a channel number, Neither does HDMI inputs.

Your DTV channels, however do have a channel name, and a number, but whatever it looks like, the channel number is not 1.

I suspect that there are some greek characters or something in the channel numbers, which causes my regular expression parsing to fail.

I can't reproduce the problem though, without knowing what smarthings is reporting as the channel number. I'll keep working on it.

vpant commented 3 weeks ago

@NickWaterton is there a way to find that value?

In the screenshot it also reports what is currently playing (news in this case). Maybe you could try "1 Αναλυτικό Δελτίο Ειδήσεων" as an input to the failing method.

NickWaterton commented 3 weeks ago

Still works on 1 Αναλυτικό Δελτίο Ειδήσεων, but I'm not testing the actual binding, just the code.

I have made a testing version of the samsungtv binding.

If you are familiar with how to test bindings, you would put the jar file (link below) in your addons directory, and uninstall the standard samsungtv binding.

https://github.com/NickWaterton/openhab-addons/releases/download/v2.0/org.openhab.binding.samsungtv-4.3.0-SNAPSHOT.jar

The new binding should be picked up and installed automatically.

This test binding traps the NPE (so avoiding the issue) - but will return -1 for the channel. It does log the channel number that is attempted to be parsed though.

Then, when switching to a DTV channel, look in the DEBUG log for the entry parsing TVChannel and post it here. That should tell me what the function is attempting (and failing) to parse.

If you get another error, post that as well, just in case I am wrong about what is happening.

Thanks for the help!

vpant commented 3 weeks ago

I tried uploaded the provided jar, added the information for smarthings and the moment I created an item for channel channelName I got this error

==> /var/log/openhab/events.log <==
2024-08-27 01:10:05.671 [INFO ] [openhab.event.ItemStateChangedEvent ] - Item 'Samsung_TV_Channel_Name' changed from NULL to OPEN BEYOND HD

==> /var/log/openhab/openhab.log <==
2024-08-27 01:10:05.673 [ERROR] [ore.common.registry.AbstractRegistry] - Cannot inform the listener "org.openhab.core.thing.internal.ChannelLinkNotifier@2e974dbe" about the "ADDED" event: Cannot invoke "org.openhab.binding.samsungtv.internal.service.SmartThingsApiService.parseTVChannel(String)" because "this.this$0" is null
java.lang.NullPointerException: Cannot invoke "org.openhab.binding.samsungtv.internal.service.SmartThingsApiService.parseTVChannel(String)" because "this.this$0" is null
    at org.openhab.binding.samsungtv.internal.service.SmartThingsApiService$TvValues.lambda$11(SmartThingsApiService.java:250) ~[?:?]
    at java.util.Optional.map(Optional.java:260) ~[?:?]
    at org.openhab.binding.samsungtv.internal.service.SmartThingsApiService$TvValues.getTvChannel(SmartThingsApiService.java:250) ~[?:?]
    at org.openhab.binding.samsungtv.internal.service.SmartThingsApiService.lambda$0(SmartThingsApiService.java:490) ~[?:?]
    at java.util.Optional.ifPresent(Optional.java:178) ~[?:?]
    at org.openhab.binding.samsungtv.internal.service.SmartThingsApiService.updateTV(SmartThingsApiService.java:488) ~[?:?]
    at org.openhab.binding.samsungtv.internal.service.SmartThingsApiService.lambda$12(SmartThingsApiService.java:721) ~[?:?]
    at java.util.Optional.ifPresent(Optional.java:178) ~[?:?]
    at org.openhab.binding.samsungtv.internal.service.SmartThingsApiService.receiveSSEEvents(SmartThingsApiService.java:720) ~[?:?]
    at org.openhab.binding.samsungtv.internal.service.SmartThingsApiService.startSSE(SmartThingsApiService.java:615) ~[?:?]
    at org.openhab.binding.samsungtv.internal.service.SmartThingsApiService.start(SmartThingsApiService.java:869) ~[?:?]
    at org.openhab.binding.samsungtv.internal.service.SmartThingsApiService.clearCache(SmartThingsApiService.java:881) ~[?:?]
    at org.openhab.binding.samsungtv.internal.handler.SamsungTvHandler.lambda$1(SamsungTvHandler.java:398) ~[?:?]
    at java.util.Spliterators$ArraySpliterator.forEachRemaining(Spliterators.java:992) ~[?:?]
    at java.util.stream.ReferencePipeline$Head.forEach(ReferencePipeline.java:762) ~[?:?]
    at org.openhab.binding.samsungtv.internal.handler.SamsungTvHandler.channelLinked(SamsungTvHandler.java:398) ~[?:?]
    at org.openhab.core.thing.internal.ChannelLinkNotifier.lambda$3(ChannelLinkNotifier.java:72) ~[?:?]
    at org.openhab.core.thing.internal.ChannelLinkNotifier.call(ChannelLinkNotifier.java:96) ~[?:?]
    at org.openhab.core.thing.internal.ChannelLinkNotifier.added(ChannelLinkNotifier.java:72) ~[?:?]
    at org.openhab.core.thing.internal.ChannelLinkNotifier.added(ChannelLinkNotifier.java:1) ~[?:?]
    at org.openhab.core.common.registry.AbstractRegistry.notifyListeners(AbstractRegistry.java:378) ~[?:?]
    at org.openhab.core.common.registry.AbstractRegistry.notifyListenersAboutAddedElement(AbstractRegistry.java:411) ~[?:?]
    at org.openhab.core.thing.link.ItemChannelLinkRegistry.notifyListenersAboutAddedElement(ItemChannelLinkRegistry.java:211) ~[?:?]
    at org.openhab.core.thing.link.ItemChannelLinkRegistry.notifyListenersAboutAddedElement(ItemChannelLinkRegistry.java:1) ~[?:?]
    at org.openhab.core.common.registry.AbstractRegistry.added(AbstractRegistry.java:175) ~[?:?]
    at org.openhab.core.common.registry.AbstractRegistry.added(AbstractRegistry.java:1) ~[?:?]
    at org.openhab.core.common.registry.AbstractProvider.notifyListeners(AbstractProvider.java:60) ~[?:?]
    at org.openhab.core.common.registry.AbstractProvider.notifyListeners(AbstractProvider.java:79) ~[?:?]
    at org.openhab.core.common.registry.AbstractProvider.notifyListenersAboutAddedElement(AbstractProvider.java:83) ~[?:?]
    at org.openhab.core.common.registry.AbstractManagedProvider.add(AbstractManagedProvider.java:66) ~[?:?]
    at org.openhab.core.common.registry.AbstractRegistry.add(AbstractRegistry.java:357) ~[?:?]
    at org.openhab.core.io.rest.core.internal.link.ItemChannelLinkResource.link(ItemChannelLinkResource.java:260) ~[?:?]
    at jdk.internal.reflect.GeneratedMethodAccessor65.invoke(Unknown Source) ~[?:?]
    at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
    at java.lang.reflect.Method.invoke(Method.java:569) ~[?:?]
    at org.apache.cxf.service.invoker.AbstractInvoker.performInvocation(AbstractInvoker.java:179) ~[bundleFile:3.6.2]
    at org.apache.cxf.service.invoker.AbstractInvoker.invoke(AbstractInvoker.java:96) ~[bundleFile:3.6.2]
    at org.apache.cxf.jaxrs.JAXRSInvoker.invoke(JAXRSInvoker.java:201) ~[bundleFile:3.6.2]
    at org.apache.cxf.jaxrs.JAXRSInvoker.invoke(JAXRSInvoker.java:104) ~[bundleFile:3.6.2]
    at org.apache.cxf.interceptor.ServiceInvokerInterceptor$1.run(ServiceInvokerInterceptor.java:59) ~[bundleFile:3.6.2]
    at org.apache.cxf.interceptor.ServiceInvokerInterceptor.handleMessage(ServiceInvokerInterceptor.java:96) ~[bundleFile:3.6.2]
    at org.apache.cxf.phase.PhaseInterceptorChain.doIntercept(PhaseInterceptorChain.java:307) ~[bundleFile:3.6.2]
    at org.apache.cxf.transport.ChainInitiationObserver.onMessage(ChainInitiationObserver.java:121) ~[bundleFile:3.6.2]
    at org.apache.cxf.transport.http.AbstractHTTPDestination.invoke(AbstractHTTPDestination.java:265) ~[bundleFile:3.6.2]
    at org.apache.cxf.transport.servlet.ServletController.invokeDestination(ServletController.java:234) ~[bundleFile:3.6.2]
    at org.apache.cxf.transport.servlet.ServletController.invoke(ServletController.java:208) ~[bundleFile:3.6.2]
    at org.apache.cxf.transport.servlet.ServletController.invoke(ServletController.java:160) ~[bundleFile:3.6.2]
    at org.apache.cxf.transport.servlet.CXFNonSpringServlet.invoke(CXFNonSpringServlet.java:225) ~[bundleFile:3.6.2]
    at org.apache.cxf.transport.servlet.AbstractHTTPServlet.handleRequest(AbstractHTTPServlet.java:304) ~[bundleFile:3.6.2]
    at org.apache.cxf.transport.servlet.AbstractHTTPServlet.doPut(AbstractHTTPServlet.java:234) ~[bundleFile:3.6.2]
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:520) ~[bundleFile:4.0.4]
    at org.apache.cxf.transport.servlet.AbstractHTTPServlet.service(AbstractHTTPServlet.java:279) ~[bundleFile:3.6.2]
    at org.ops4j.pax.web.service.spi.servlet.OsgiInitializedServlet.service(OsgiInitializedServlet.java:102) ~[bundleFile:?]
    at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:799) ~[bundleFile:9.4.54.v20240208]
    at org.eclipse.jetty.servlet.ServletHandler$ChainEnd.doFilter(ServletHandler.java:1656) ~[bundleFile:9.4.54.v20240208]
    at org.ops4j.pax.web.service.spi.servlet.OsgiFilterChain.doFilter(OsgiFilterChain.java:113) ~[bundleFile:?]
    at org.ops4j.pax.web.service.jetty.internal.PaxWebServletHandler.doHandle(PaxWebServletHandler.java:334) ~[bundleFile:?]
    at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143) ~[bundleFile:9.4.54.v20240208]
    at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:600) ~[bundleFile:9.4.54.v20240208]
    at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) ~[bundleFile:9.4.54.v20240208]
    at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:235) ~[bundleFile:9.4.54.v20240208]
    at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1624) ~[bundleFile:9.4.54.v20240208]
    at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233) ~[bundleFile:9.4.54.v20240208]
    at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1440) ~[bundleFile:9.4.54.v20240208]
    at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188) ~[bundleFile:9.4.54.v20240208]
    at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:505) ~[bundleFile:9.4.54.v20240208]
    at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1594) ~[bundleFile:9.4.54.v20240208]
    at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186) ~[bundleFile:9.4.54.v20240208]
    at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1355) ~[bundleFile:9.4.54.v20240208]
    at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) ~[bundleFile:9.4.54.v20240208]
    at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:234) ~[bundleFile:9.4.54.v20240208]
    at org.ops4j.pax.web.service.jetty.internal.PrioritizedHandlerCollection.handle(PrioritizedHandlerCollection.java:96) ~[bundleFile:?]
    at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:722) ~[bundleFile:9.4.54.v20240208]
    at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) ~[bundleFile:9.4.54.v20240208]
    at org.eclipse.jetty.server.Server.handle(Server.java:516) ~[bundleFile:9.4.54.v20240208]
    at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:487) ~[bundleFile:9.4.54.v20240208]
    at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:732) [bundleFile:9.4.54.v20240208]
    at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:479) [bundleFile:9.4.54.v20240208]
    at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:277) [bundleFile:9.4.54.v20240208]
    at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311) [bundleFile:9.4.54.v20240208]
    at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105) [bundleFile:9.4.54.v20240208]
    at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104) [bundleFile:9.4.54.v20240208]
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:338) [bundleFile:9.4.54.v20240208]
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:315) [bundleFile:9.4.54.v20240208]
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:173) [bundleFile:9.4.54.v20240208]
    at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:131) [bundleFile:9.4.54.v20240208]
    at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:409) [bundleFile:9.4.54.v20240208]
    at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:883) [bundleFile:9.4.54.v20240208]
    at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1034) [bundleFile:9.4.54.v20240208]
    at java.lang.Thread.run(Thread.java:840) [?:?]

This error happen only once.

That is not the case for channel channel (Number) which when I created an item for it I continuously get

...
2024-08-27 01:13:14.886 [DEBUG] [tv.internal.handler.SamsungTvHandler] - 192.168.10.216: Polling Job exception: Cannot invoke "org.openhab.binding.samsungtv.internal.service.SmartThingsApiService.parseTVChannel(String)" because "this.this$0" is null
2024-08-27 01:13:15.968 [DEBUG] [tv.internal.handler.SamsungTvHandler] - 192.168.10.216: Polling Job exception: Cannot invoke "org.openhab.binding.samsungtv.internal.service.SmartThingsApiService.parseTVChannel(String)" because "this.this$0" is null
2024-08-27 01:13:17.051 [DEBUG] [tv.internal.handler.SamsungTvHandler] - 192.168.10.216: Polling Job exception: Cannot invoke "org.openhab.binding.samsungtv.internal.service.SmartThingsApiService.parseTVChannel(String)" because "this.this$0" is null
2024-08-27 01:13:18.133 [DEBUG] [tv.internal.handler.SamsungTvHandler] - 192.168.10.216: Polling Job exception: Cannot invoke "org.openhab.binding.samsungtv.internal.service.SmartThingsApiService.parseTVChannel(String)" because "this.this$0" is null
...

And of course the same issue "HANDLER_INITIALIZING_ERROR" if I disable and renable the thing.

2024-08-27 01:24:01.531 [ERROR] [core.thing.internal.ThingManagerImpl] - Exception occurred while initializing handler of thing 'samsungtv:tv:4561f668-a097-42dd-97ec-883605d6039e': Cannot invoke "org.openhab.binding.samsungtv.internal.service.SmartThingsApiService.parseTVChannel(String)" because "this.this$0" is null
java.lang.NullPointerException: Cannot invoke "org.openhab.binding.samsungtv.internal.service.SmartThingsApiService.parseTVChannel(String)" because "this.this$0" is null
    at org.openhab.binding.samsungtv.internal.service.SmartThingsApiService$TvValues.lambda$11(SmartThingsApiService.java:250) ~[?:?]
    at java.util.Optional.map(Optional.java:260) ~[?:?]
    at org.openhab.binding.samsungtv.internal.service.SmartThingsApiService$TvValues.getTvChannel(SmartThingsApiService.java:250) ~[?:?]
    at org.openhab.binding.samsungtv.internal.service.SmartThingsApiService.lambda$0(SmartThingsApiService.java:490) ~[?:?]
    at java.util.Optional.ifPresent(Optional.java:178) ~[?:?]
    at org.openhab.binding.samsungtv.internal.service.SmartThingsApiService.updateTV(SmartThingsApiService.java:488) ~[?:?]
    at org.openhab.binding.samsungtv.internal.service.SmartThingsApiService.lambda$12(SmartThingsApiService.java:721) ~[?:?]
    at java.util.Optional.ifPresent(Optional.java:178) ~[?:?]
    at org.openhab.binding.samsungtv.internal.service.SmartThingsApiService.receiveSSEEvents(SmartThingsApiService.java:720) ~[?:?]
    at org.openhab.binding.samsungtv.internal.service.SmartThingsApiService.startSSE(SmartThingsApiService.java:615) ~[?:?]
    at org.openhab.binding.samsungtv.internal.service.SmartThingsApiService.start(SmartThingsApiService.java:869) ~[?:?]
    at org.openhab.binding.samsungtv.internal.handler.SamsungTvHandler.startService(SamsungTvHandler.java:704) ~[?:?]
    at org.openhab.binding.samsungtv.internal.handler.SamsungTvHandler.createService(SamsungTvHandler.java:655) ~[?:?]
    at org.openhab.binding.samsungtv.internal.handler.SamsungTvHandler.checkAndCreateServices(SamsungTvHandler.java:620) ~[?:?]
    at org.openhab.binding.samsungtv.internal.handler.SamsungTvHandler.initialize(SamsungTvHandler.java:460) ~[?:?]
    at jdk.internal.reflect.GeneratedMethodAccessor23.invoke(Unknown Source) ~[?:?]
    at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
    at java.lang.reflect.Method.invoke(Method.java:569) ~[?:?]
    at org.openhab.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:147) [bundleFile:?]
    at org.openhab.core.internal.common.Invocation.call(Invocation.java:52) [bundleFile:?]
    at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
    at java.lang.Thread.run(Thread.java:840) [?:?]

The behavior remains exactly the same.

NickWaterton commented 3 weeks ago

Did you deinstall the original samsungtv binding? The new test binding won't work unless the original is deinstalled.

vpant commented 3 weeks ago

I did

vpant commented 3 weeks ago

I managed to run openhab in debug mode and add some breakpoints. It seems that the issue is not related to the value at all.

image

According to this SO, this.this$0 has something to do with the inner class holding a reference to the outer class that created it and it is null.

NickWaterton commented 3 weeks ago

@vpant

Thank you, this is very helpful.

I had come to the conclusion that it wasn’t the parsing of the channel number that was the issue, rather the code that called the parsing.

I will dig into it more tomorrow.

NickWaterton commented 3 weeks ago

@vpant

Ok, I have a new version of the binding:

https://github.com/NickWaterton/openhab-addons/releases/download/v2.0/org.openhab.binding.samsungtv-4.3.0-SNAPSHOT.jar

See if this does anything different, and let me know.

vpant commented 3 weeks ago

@NickWaterton

Unfortunately, same exact error

NickWaterton commented 3 weeks ago

@vpant

Ok, try this again:

https://github.com/NickWaterton/openhab-addons/releases/download/v2.0/org.openhab.binding.samsungtv-4.3.0-SNAPSHOT.jar

I have trapped the NPE earlier, and added some more logging. Look for Getting tvChannel from in the logs, and it will give me a clue where it's going wrong.

It might help if you could set the binding logging level to TRACE as well.

Thanks!

RickyTR commented 3 weeks ago

With this version I have the following error:

Cannot read field "logger" because "this.this$0" is null

NickWaterton commented 3 weeks ago

Ok, well that's something I guess.

Did you enable TRACE debugging? if so, can you post the log, including the 5 lines of so before the error, that will at least tell me which call is failing.

RickyTR commented 3 weeks ago

I cannot modify debugging via the UI. The page with the addon log settings is empty. I suspect is related to the “logger” error…

RickyTR commented 3 weeks ago

I manually enabled TRACE debugging and this is what I have:

Received value 'channelName':'Sky TG24' for thing 'samsungtv:tv:xxxx-xxxx-xxx-xxx-xxxx'

2024-08-27 21:49:14.585 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method 'ThingHandler.thingUpdated()' on 'org.openhab.binding.samsungtv.internal.handler.SamsungTvHandler@1c4fb065': Cannot read field "logger" because "this.this$0" is null
vpant commented 3 weeks ago

I tried the new version and I am also getting the issue with the logger. Here is the logs after creating the channel `channel (Number)' with trace enabled

09:33:56.027 [INFO ] [n.jrule.internal.handler.JRuleHandler] - [JRuleHandler] Compiling generated sources
09:33:56.672 [INFO ] [n.jrule.internal.handler.JRuleHandler] - [JRuleHandler] Creating jrule-generated.jar
09:34:04.966 [TRACE] [gtv.internal.handler.SamsungTvHandler] - 192.168.10.216: channelLinked: samsungtv:tv:4561f668-a097-42dd-97ec-883605d6039e:channel
09:34:04.968 [TRACE] [nternal.service.SmartThingsApiService] - 192.168.10.216: SSE Starting job
09:34:04.969 [INFO ] [nternal.service.SmartThingsApiService] - 192.168.10.216: SSE Creating Smartthings Subscription
09:34:04.971 [TRACE] [nternal.service.SmartThingsApiService] - 192.168.10.216: subscription: {"subscriptionFilters":[{"type":"DEVICEIDS","value":["ebe898d3-ebeb-45d0-810a-e6ec04c18be7"]}],"name":"OpenHAB Subscription"}
09:34:04.973 [TRACE] [nternal.service.SmartThingsApiService] - 192.168.10.216: Sending https://api.smartthings.com:443/subscriptions
09:34:05.407 [TRACE] [nternal.service.SmartThingsApiService] - 192.168.10.216: Got response: {"subscriptionId":"77570fec-0b4d-4e33-bd8a-241f989f184a","registrationUrl":"https://spigot-regional.api.smartthings.com/filters/77570fec-0b4d-4e33-bd8a-241f989f184a/activate?filterRegion=us-east-2","name":"OpenHAB Subscription","version":1,"subscriptionFilters":[{"type":"DEVICEIDS","value":["ebe898d3-ebeb-45d0-810a-e6ec04c18be7"],"eventType":null,"attribute":null,"capability":null,"component":null}]}
09:34:05.410 [TRACE] [nternal.service.SmartThingsApiService] - 192.168.10.216: SSE got subscription ID: 77570fec-0b4d-4e33-bd8a-241f989f184a
09:34:05.550 [TRACE] [nternal.service.SmartThingsApiService] - 192.168.10.216: Received channel: channel, command: REFRESH
09:34:05.810 [TRACE] [nternal.service.SmartThingsApiService] - 192.168.10.216: SSE GOT Response Code: 200
09:34:05.811 [DEBUG] [nternal.service.SmartThingsApiService] - 192.168.10.216: SSE job Started
09:34:05.815 [TRACE] [nternal.service.SmartThingsApiService] - 192.168.10.216: SSE received: {data=welcome, event=CONTROL_EVENT}
09:34:05.817 [DEBUG] [nternal.service.SmartThingsApiService] - 192.168.10.216: SSE Decoding event: CONTROL_EVENT
09:34:05.819 [TRACE] [nternal.service.SmartThingsApiService] - 192.168.10.216: Sending https://api.smartthings.com:443/v1/devices/ebe898d3-ebeb-45d0-810a-e6ec04c18be7/components/main/status
09:34:05.913 [TRACE] [nternal.service.SmartThingsApiService] - 192.168.10.216: Got response: {"mediaPlayback":{"supportedPlaybackCommands":{"value":["play","pause","stop","fastForward","rewind"],"timestamp":"2024-01-27T23:20:33.354Z"},"playbackStatus":{"value":null}},"samsungvd.supportsPowerOnByOcf":{"supportsPowerOnByOcf":{"value":"false","timestamp":"2024-08-28T06:25:18.781Z"}},"samsungvd.deviceInfoPrivate":{},"mediaInputSource":{"supportedInputSources":{"value":["digitalTv","HDMI1","HDMI2","HDMI3"],"timestamp":"2024-01-27T23:20:33.370Z"},"inputSource":{"value":"digitalTv","timestamp":"2024-01-29T20:10:44.319Z"}},"switch":{"switch":{"value":"on","timestamp":"2024-08-28T06:25:17.273Z"}},"ocf":{"st":{"value":"2024-01-27T19:53:52Z","timestamp":"2024-01-27T23:20:35.352Z"},"mndt":{"value":"2019-01-01","timestamp":"2024-01-27T23:20:35.352Z"},"mnfv":{"value":"T-MSLDEUC-1420.0","timestamp":"2024-04-01T22:01:43.541Z"},"mnhw":{"value":"0-0","timestamp":"2024-01-27T23:20:35.352Z"},"di":{"value":"ebe898d3-ebeb-45d0-810a-e6ec04c18be7","timestamp":"2024-01-27T23:20:35.352Z"},"mnsl":{"value":"http://www.samsung.com/sec/tv/overview/","timestamp":"2024-01-27T23:20:35.352Z"},"dmv":{"value":"res.1.1.0,sh.1.1.0","timestamp":"2024-01-27T23:20:35.352Z"},"n":{"value":"[TV] Samsung 7 Series (50)","timestamp":"2024-01-27T23:20:35.352Z"},"mnmo":{"value":"UE50RU7402UXXH","timestamp":"2024-01-27T23:20:35.352Z"},"vid":{"value":"VD-STV_2018_K","timestamp":"2024-01-27T23:20:35.352Z"},"mnmn":{"value":"Samsung Electronics","timestamp":"2024-01-27T23:20:35.352Z"},"mnml":{"value":"http://www.samsung.com","timestamp":"2024-01-27T23:20:35.352Z"},"mnpv":{"value":"Tizen 5.0","timestamp":"2024-01-27T23:20:35.352Z"},"mnos":{"value":"4.1.10","timestamp":"2024-01-27T23:20:35.352Z"},"pi":{"value":"ebe898d3-ebeb-45d0-810a-e6ec04c18be7","timestamp":"2024-01-27T23:20:35.352Z"},"icv":{"value":"core.1.1.0","timestamp":"2024-01-27T23:20:35.352Z"}},"samsungvd.contentInfo":{},"custom.accessibility":{},"custom.disabledCapabilities":{"disabledCapabilities":{"value":["samsungvd.ambient","samsungvd.ambient18","samsungvd.ambientContent","sec.diagnosticsInformation"],"timestamp":"2024-01-27T23:20:33.354Z"}},"samsungvd.remoteControl":{},"sec.diagnosticsInformation":{"logType":{"value":null},"endpoint":{"value":null},"minVersion":{"value":null},"signinPermission":{"value":null},"setupId":{"value":null},"protocolType":{"value":null},"tsId":{"value":null},"mnId":{"value":null},"dumpType":{"value":null}},"custom.launchapp":{},"samsungvd.firmwareVersion":{"firmwareVersion":{"value":"2.4.0","timestamp":"2024-08-28T06:25:18.781Z"}},"audioVolume":{"volume":{"value":20,"unit":"%","timestamp":"2024-01-27T23:20:34.571Z"}},"samsungvd.mediaInputSource":{"supportedInputSourcesMap":{"value":[{"id":"dtv","name":"TV"},{"id":"HDMI1","name":"Shield"},{"id":"HDMI2","name":"Άγνωστο (HDMI 2)"},{"id":"HDMI3","name":"LG SOUND BAR"}],"timestamp":"2024-08-28T06:25:17.228Z"},"inputSource":{"value":"dtv","timestamp":"2024-08-28T06:25:17.228Z"}},"custom.tvsearch":{},"samsungvd.ambient":{},"refresh":{},"custom.error":{"error":{"value":null}},"execute":{"data":{"value":{"payload":{"rt":["x.com.samsung.tv.deviceinfo"],"if":["oic.if.baseline","oic.if.r"],"x.com.samsung.country":"GREECE","x.com.samsung.infolinkversion":"T-INFOLINK2019-1012","x.com.samsung.modelid":"19_MUSEL_UHD","x.com.samsung.tv.ambientsupport":false,"x.com.samsung.tv.blemac":"D0:03:DF:8D:AC:BB","x.com.samsung.tv.btmac":"D0:03:DF:8D:AC:BB","x.com.samsung.tv.category":"tv","x.com.samsung.tv.countrycode":"GR","x.com.samsung.tv.ethmac":"00:7c:2d:44:b7:04","x.com.samsung.tv.mnid":"0AJK","x.com.samsung.tv.onsupport":true,"x.com.samsung.tv.p2pmac":"d2:03:df:8d:ac:ba","x.com.samsung.tv.paneltime":52788,"x.com.samsung.tv.setupid":"101","x.com.samsung.tv.sn":"0ECD3HHM500265R","x.com.samsung.tv.swmodel":"URU7400","x.com.samsung.tv.thingversion":"2.4.0","x.com.samsung.tv.ttxsupport":true,"x.com.samsung.tv.udn":"4561f668-a097-42dd-97ec-883605d6039e","x.com.samsung.tv.wifimac":"d0:03:df:8d:ac:ba"}},"data":{"href":"/sec/tv/deviceinfo"},"timestamp":"2024-01-27T23:20:35.246Z"}},"tvChannel":{"tvChannel":{"value":"6","timestamp":"2024-08-28T06:30:52.412Z"},"tvChannelName":{"value":"OPEN BEYOND HD","timestamp":"2024-08-28T06:30:52.412Z"}},"custom.picturemode":{"pictureMode":{"value":"Φυσική εικόνα","timestamp":"2024-01-27T23:20:34.451Z"},"supportedPictureModes":{"value":["Δυναμική","Τυπικό","Φυσική εικόνα","Ταινία"],"timestamp":"2024-01-27T23:20:34.451Z"},"supportedPictureModesMap":{"value":[{"id":"modeDynamic","name":"Δυναμική"},{"id":"modeStandard","name":"Τυπικό"},{"id":"modeNatural","name":"Φυσική εικόνα"},{"id":"modeMovie","name":"Ταινία"}],"timestamp":"2024-01-27T23:20:34.451Z"}},"samsungvd.ambientContent":{"supportedAmbientApps":{"value":[],"timestamp":"2024-01-27T23:20:33.354Z"}},"custom.recording":{},"samsungvd.ambient18":{},"custom.soundmode":{"supportedSoundModesMap":{"value":[{"id":"modeStandard","name":"Τυπικό"}],"timestamp":"2024-01-27T23:20:34.647Z"},"soundMode":{"value":"Τυπικό","timestamp":"2024-01-27T23:20:34.647Z"},"supportedSoundModes":{"value":["Τυπικό"],"timestamp":"2024-01-27T23:20:34.647Z"}},"audioMute":{"mute":{"value":"unmuted","timestamp":"2024-01-27T23:20:34.571Z"}},"mediaTrackControl":{"supportedTrackControlCommands":{"value":null}}}
09:34:05.920 [TRACE] [gtv.internal.handler.SamsungTvHandler] - 192.168.10.216: Polling Job exception: 
java.lang.NullPointerException: Cannot read field "logger" because "this.this$0" is null
    at org.openhab.binding.samsungtv.internal.service.SmartThingsApiService$TvValues.getTvChannel(SmartThingsApiService.java:249) ~[?:?]
    at org.openhab.binding.samsungtv.internal.service.SmartThingsApiService.lambda$23(SmartThingsApiService.java:917) ~[?:?]
    at java.util.Optional.map(Optional.java:260) ~[?:?]
    at org.openhab.binding.samsungtv.internal.service.SmartThingsApiService.handleCommand(SmartThingsApiService.java:909) ~[?:?]
    at org.openhab.binding.samsungtv.internal.handler.SamsungTvHandler.lambda$12(SamsungTvHandler.java:566) ~[?:?]
    at java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:183) ~[?:?]
    at java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:179) ~[?:?]
    at java.util.Spliterators$ArraySpliterator.forEachRemaining(Spliterators.java:992) ~[?:?]
    at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509) ~[?:?]
    at java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499) ~[?:?]
    at java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:150) ~[?:?]
    at java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:173) ~[?:?]
    at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) ~[?:?]
    at java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:596) ~[?:?]
    at org.openhab.binding.samsungtv.internal.handler.SamsungTvHandler.lambda$10(SamsungTvHandler.java:566) ~[?:?]
    at java.util.stream.ForEachOps$ForEachOp$OfRef.accept(ForEachOps.java:183) ~[?:?]
    at java.util.stream.ReferencePipeline$2$1.accept(ReferencePipeline.java:179) ~[?:?]
    at java.util.Spliterators$ArraySpliterator.forEachRemaining(Spliterators.java:992) ~[?:?]
    at java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509) ~[?:?]
    at java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499) ~[?:?]
    at java.util.stream.ForEachOps$ForEachOp.evaluateSequential(ForEachOps.java:150) ~[?:?]
    at java.util.stream.ForEachOps$ForEachOp$OfRef.evaluateSequential(ForEachOps.java:173) ~[?:?]
    at java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234) ~[?:?]
    at java.util.stream.ReferencePipeline.forEach(ReferencePipeline.java:596) ~[?:?]
    at org.openhab.binding.samsungtv.internal.handler.SamsungTvHandler.poll(SamsungTvHandler.java:564) ~[?:?]
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:539) [?:?]
    at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) [?:?]
    at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) [?:?]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) [?:?]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) [?:?]
    at java.lang.Thread.run(Thread.java:840) [?:?]
NickWaterton commented 2 weeks ago

@vpant Ok, that helps quite a bit. Here is another try at working around the problem: https://github.com/NickWaterton/openhab-addons/releases/download/v2.0/org.openhab.binding.samsungtv-4.3.0-SNAPSHOT.jar

let me know how this goes...

vpant commented 2 weeks ago

@NickWaterton So, the good news is that I do not get the error any more. The bad news is that channel channel (Number) is not working any more. The value remains -1 no matter if I am watching dtv or Youtube.

I got this error multiple times and the it stopped

20:25:46.376 [TRACE] [nternal.service.SmartThingsApiService] - 192.168.10.216: Got response: {"mediaPlayback":{"supportedPlaybackCommands":{"value":["play","pause","stop","fastForward","rewind"],"timestamp":"2024-01-27T23:20:33.354Z"},"playbackStatus":{"value":null}},"samsungvd.supportsPowerOnByOcf":{"supportsPowerOnByOcf":{"value":"false","timestamp":"2024-08-28T06:25:18.781Z"}},"samsungvd.deviceInfoPrivate":{},"mediaInputSource":{"supportedInputSources":{"value":["digitalTv","HDMI1","HDMI2","HDMI3"],"timestamp":"2024-01-27T23:20:33.370Z"},"inputSource":{"value":"digitalTv","timestamp":"2024-01-29T20:10:44.319Z"}},"switch":{"switch":{"value":"on","timestamp":"2024-08-28T17:15:51.527Z"}},"ocf":{"st":{"value":"2024-01-27T19:53:52Z","timestamp":"2024-01-27T23:20:35.352Z"},"mndt":{"value":"2019-01-01","timestamp":"2024-01-27T23:20:35.352Z"},"mnfv":{"value":"T-MSLDEUC-1420.0","timestamp":"2024-04-01T22:01:43.541Z"},"mnhw":{"value":"0-0","timestamp":"2024-01-27T23:20:35.352Z"},"di":{"value":"ebe898d3-ebeb-45d0-810a-e6ec04c18be7","timestamp":"2024-01-27T23:20:35.352Z"},"mnsl":{"value":"http://www.samsung.com/sec/tv/overview/","timestamp":"2024-01-27T23:20:35.352Z"},"dmv":{"value":"res.1.1.0,sh.1.1.0","timestamp":"2024-01-27T23:20:35.352Z"},"n":{"value":"[TV] Samsung 7 Series (50)","timestamp":"2024-01-27T23:20:35.352Z"},"mnmo":{"value":"UE50RU7402UXXH","timestamp":"2024-01-27T23:20:35.352Z"},"vid":{"value":"VD-STV_2018_K","timestamp":"2024-01-27T23:20:35.352Z"},"mnmn":{"value":"Samsung Electronics","timestamp":"2024-01-27T23:20:35.352Z"},"mnml":{"value":"http://www.samsung.com","timestamp":"2024-01-27T23:20:35.352Z"},"mnpv":{"value":"Tizen 5.0","timestamp":"2024-01-27T23:20:35.352Z"},"mnos":{"value":"4.1.10","timestamp":"2024-01-27T23:20:35.352Z"},"pi":{"value":"ebe898d3-ebeb-45d0-810a-e6ec04c18be7","timestamp":"2024-01-27T23:20:35.352Z"},"icv":{"value":"core.1.1.0","timestamp":"2024-01-27T23:20:35.352Z"}},"samsungvd.contentInfo":{},"custom.accessibility":{},"custom.disabledCapabilities":{"disabledCapabilities":{"value":["samsungvd.ambient","samsungvd.ambient18","samsungvd.ambientContent","sec.diagnosticsInformation"],"timestamp":"2024-01-27T23:20:33.354Z"}},"samsungvd.remoteControl":{},"sec.diagnosticsInformation":{"logType":{"value":null},"endpoint":{"value":null},"minVersion":{"value":null},"signinPermission":{"value":null},"setupId":{"value":null},"protocolType":{"value":null},"tsId":{"value":null},"mnId":{"value":null},"dumpType":{"value":null}},"custom.launchapp":{},"samsungvd.firmwareVersion":{"firmwareVersion":{"value":"2.4.0","timestamp":"2024-08-28T06:25:18.781Z"}},"audioVolume":{"volume":{"value":20,"unit":"%","timestamp":"2024-01-27T23:20:34.571Z"}},"samsungvd.mediaInputSource":{"supportedInputSourcesMap":{"value":[{"id":"dtv","name":"TV"},{"id":"HDMI1","name":"Shield"},{"id":"HDMI2","name":"Άγνωστο (HDMI 2)"},{"id":"HDMI3","name":"LG SOUND BAR"}],"timestamp":"2024-08-28T17:15:51.596Z"},"inputSource":{"value":"dtv","timestamp":"2024-08-28T17:15:51.596Z"}},"custom.tvsearch":{},"samsungvd.ambient":{},"refresh":{},"custom.error":{"error":{"value":null}},"execute":{"data":{"value":{"payload":{"rt":["x.com.samsung.tv.deviceinfo"],"if":["oic.if.baseline","oic.if.r"],"x.com.samsung.country":"GREECE","x.com.samsung.infolinkversion":"T-INFOLINK2019-1012","x.com.samsung.modelid":"19_MUSEL_UHD","x.com.samsung.tv.ambientsupport":false,"x.com.samsung.tv.blemac":"D0:03:DF:8D:AC:BB","x.com.samsung.tv.btmac":"D0:03:DF:8D:AC:BB","x.com.samsung.tv.category":"tv","x.com.samsung.tv.countrycode":"GR","x.com.samsung.tv.ethmac":"00:7c:2d:44:b7:04","x.com.samsung.tv.mnid":"0AJK","x.com.samsung.tv.onsupport":true,"x.com.samsung.tv.p2pmac":"d2:03:df:8d:ac:ba","x.com.samsung.tv.paneltime":52788,"x.com.samsung.tv.setupid":"101","x.com.samsung.tv.sn":"0ECD3HHM500265R","x.com.samsung.tv.swmodel":"URU7400","x.com.samsung.tv.thingversion":"2.4.0","x.com.samsung.tv.ttxsupport":true,"x.com.samsung.tv.udn":"4561f668-a097-42dd-97ec-883605d6039e","x.com.samsung.tv.wifimac":"d0:03:df:8d:ac:ba"}},"data":{"href":"/sec/tv/deviceinfo"},"timestamp":"2024-01-27T23:20:35.246Z"}},"tvChannel":{"tvChannel":{"value":"","timestamp":"2024-08-28T17:20:47.202Z"},"tvChannelName":{"value":"9Ur5IzDKqV.TizenYouTube","timestamp":"2024-08-28T17:20:47.202Z"}},"custom.picturemode":{"pictureMode":{"value":"Φυσική εικόνα","timestamp":"2024-01-27T23:20:34.451Z"},"supportedPictureModes":{"value":["Δυναμική","Τυπικό","Φυσική εικόνα","Ταινία"],"timestamp":"2024-01-27T23:20:34.451Z"},"supportedPictureModesMap":{"value":[{"id":"modeDynamic","name":"Δυναμική"},{"id":"modeStandard","name":"Τυπικό"},{"id":"modeNatural","name":"Φυσική εικόνα"},{"id":"modeMovie","name":"Ταινία"}],"timestamp":"2024-01-27T23:20:34.451Z"}},"samsungvd.ambientContent":{"supportedAmbientApps":{"value":[],"timestamp":"2024-01-27T23:20:33.354Z"}},"custom.recording":{},"samsungvd.ambient18":{},"custom.soundmode":{"supportedSoundModesMap":{"value":[{"id":"modeStandard","name":"Τυπικό"}],"timestamp":"2024-01-27T23:20:34.647Z"},"soundMode":{"value":"Τυπικό","timestamp":"2024-01-27T23:20:34.647Z"},"supportedSoundModes":{"value":["Τυπικό"],"timestamp":"2024-01-27T23:20:34.647Z"}},"audioMute":{"mute":{"value":"unmuted","timestamp":"2024-01-27T23:20:34.571Z"}},"mediaTrackControl":{"supportedTrackControlCommands":{"value":null}}}
20:25:46.383 [TRACE] [nternal.service.SmartThingsApiService] - 192.168.10.216: Value '-1.0' for channel hasn't changed, ignoring update
20:25:47.385 [TRACE] [nternal.service.SmartThingsApiService] - 192.168.10.216: Received channel: channel, command: REFRESH
20:25:47.387 [TRACE] [nternal.service.SmartThingsApiService] - 192.168.10.216: Sending https://api.smartthings.com:443/v1/devices/ebe898d3-ebeb-45d0-810a-e6ec04c18be7/components/main/status

I get a whole lot of these logs. It seems that it calls the API every one second. Is that normal?

NickWaterton commented 2 weeks ago

@vpant Ok, so some progress anyway. -1.0 means that it can't read the channel number. I don't know why, it was working previously.

And yes, the binding calls the API every second, you can change the polling frequency in the Thing, its Refresh Interval in ms. this is only for certain channels though.

This is only polled every second if the subscription job is not running though. This is the SSE job. if this fails, the values are polled, if it succeeds, they are not.

Do you get any SSE events listed in the logs? those are Subscription events, and should update the channel name etc. If you have any can you post the logs, it might help.

So, the question now is, if the channelName can be read, why not the channel number?

lsiepel commented 2 weeks ago

@vpant Ok, so some progress anyway. -1.0 means that it can't read the channel number. I don't know why, it was working previously.

And yes, the binding calls the API every second, you can change the polling frequency in the Thing, its Refresh Interval in ms. this is only for certain channels though.

This is only polled every second if the subscription job is not running though. This is the SSE job. if this fails, the values are polled, if it succeeds, they are not.

Do you get any SSE events listed in the logs? those are Subscription events, and should update the channel name etc. If you have any can you post the logs, it might help.

So, the question now is, if the channelName can be read, why not the channel number?

Can’t you log the raw response? That might be used for testing (and if possible create unit tests)

NickWaterton commented 2 weeks ago

The line Got response is the raw response, and tvChannel is in there with value "6".

This is the code that is run:

if (fetchdata()) {
            return tvInfo.map(t -> {
                boolean result = false;
                if (command == RefreshType.REFRESH) {
                    switch (channel) {
                        case CHANNEL_NAME:
                            updateState(CHANNEL_NAME, t.getTvChannelName());
                            break;
                        case CHANNEL:
                            updateState(CHANNEL, parseTVChannel(t.getTvChannel()));
                            break;

This gets called for each channel that is polled. Here getTvChannelName() works, but getTvChannel() doesn't.

fetchdata() returns true if tvInfo is present, and fetches new data a maximum of every 1 second (to rate limit the api).

It could be a timing thing. if the smarthings api takes too long to respond, then fetchdata() may get called again, while the first call is still waiting for a response. the first call succeeds, but the second fails.

I need to look at the timing more closely.

lsiepel commented 2 weeks ago

There seems to be a problem with that timing, but that would be a race condition between the call fetchdata() and consuming tvInfo iw ould not expect that to be as reproducable as in this issue. Guess it must be something else.

NickWaterton commented 2 weeks ago

@vpant

Can't find anything wrong with the timing.

Here is another test binding, with a bit more logging to try to pinpoint it:

https://github.com/NickWaterton/openhab-addons/releases/download/v2.0/org.openhab.binding.samsungtv-4.3.0-SNAPSHOT.jar

lsiepel commented 2 weeks ago

Created a branch with a test here, might be usefull for debugging https://github.com/lsiepel/openhab-addons/tree/samsuntv-tests

The NPE was fixed by changing the parseTVChannel to static. It somehow does not like public static Number parseTVChannel(@Nullable String channel) {

The root cause looks very much like a timing issue. So there might be more issues hidden somewhere. the subclass calls the enclosing class that seems to be null.

vpant commented 2 weeks ago

@NickWaterton I tried the latest version. Did you change anything other than adding some logs?

Now it seems that the issue exists with the channel channelName and not with channel (Number)

00:01:21.311 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'TV_TV_Channel' changed from NULL to -1.0
00:01:21.329 [TRACE] [gtv.internal.handler.SamsungTvHandler] - 192.168.10.216: channelLinked: samsungtv:tv:tv:channel
00:01:21.331 [TRACE] [nternal.service.SmartThingsApiService] - 192.168.10.216: SSE Starting job
00:01:21.331 [INFO ] [nternal.service.SmartThingsApiService] - 192.168.10.216: SSE Creating Smartthings Subscription
00:01:21.333 [TRACE] [nternal.service.SmartThingsApiService] - 192.168.10.216: subscription: {"subscriptionFilters":[{"type":"DEVICEIDS","value":["ebe898d3-ebeb-45d0-810a-e6ec04c18be7"]}],"name":"OpenHAB Subscription"}
00:01:21.334 [TRACE] [nternal.service.SmartThingsApiService] - 192.168.10.216: Sending https://api.smartthings.com:443/subscriptions
00:01:21.432 [TRACE] [nternal.service.SmartThingsApiService] - 192.168.10.216: Received channel: channel, command: REFRESH
00:01:22.074 [TRACE] [nternal.service.SmartThingsApiService] - 192.168.10.216: Got response: {"subscriptionId":"a9d67f7b-8f2b-468a-9546-faa610b12dff","registrationUrl":"https://spigot-regional.api.smartthings.com/filters/a9d67f7b-8f2b-468a-9546-faa610b12dff/activate?filterRegion=us-east-2","name":"OpenHAB Subscription","version":1,"subscriptionFilters":[{"type":"DEVICEIDS","value":["ebe898d3-ebeb-45d0-810a-e6ec04c18be7"],"eventType":null,"attribute":null,"capability":null,"component":null}]}
00:01:22.079 [TRACE] [nternal.service.SmartThingsApiService] - 192.168.10.216: SSE got subscription ID: a9d67f7b-8f2b-468a-9546-faa610b12dff
00:01:22.083 [TRACE] [nternal.service.SmartThingsApiService] - 192.168.10.216: Sending https://api.smartthings.com:443/v1/devices/ebe898d3-ebeb-45d0-810a-e6ec04c18be7/components/main/status
00:01:22.187 [TRACE] [nternal.service.SmartThingsApiService] - 192.168.10.216: Got response: {"mediaPlayback":{"supportedPlaybackCommands":{"value":["play","pause","stop","fastForward","rewind"],"timestamp":"2024-01-27T23:20:33.354Z"},"playbackStatus":{"value":null}},"samsungvd.supportsPowerOnByOcf":{"supportsPowerOnByOcf":{"value":"false","timestamp":"2024-08-28T06:25:18.781Z"}},"samsungvd.deviceInfoPrivate":{},"mediaInputSource":{"supportedInputSources":{"value":["digitalTv","HDMI1","HDMI2","HDMI3"],"timestamp":"2024-01-27T23:20:33.370Z"},"inputSource":{"value":"digitalTv","timestamp":"2024-01-29T20:10:44.319Z"}},"switch":{"switch":{"value":"on","timestamp":"2024-08-28T17:15:51.527Z"}},"ocf":{"st":{"value":"2024-01-27T19:53:52Z","timestamp":"2024-01-27T23:20:35.352Z"},"mndt":{"value":"2019-01-01","timestamp":"2024-01-27T23:20:35.352Z"},"mnfv":{"value":"T-MSLDEUC-1420.0","timestamp":"2024-04-01T22:01:43.541Z"},"mnhw":{"value":"0-0","timestamp":"2024-01-27T23:20:35.352Z"},"di":{"value":"ebe898d3-ebeb-45d0-810a-e6ec04c18be7","timestamp":"2024-01-27T23:20:35.352Z"},"mnsl":{"value":"http://www.samsung.com/sec/tv/overview/","timestamp":"2024-01-27T23:20:35.352Z"},"dmv":{"value":"res.1.1.0,sh.1.1.0","timestamp":"2024-01-27T23:20:35.352Z"},"n":{"value":"[TV] Samsung 7 Series (50)","timestamp":"2024-01-27T23:20:35.352Z"},"mnmo":{"value":"UE50RU7402UXXH","timestamp":"2024-01-27T23:20:35.352Z"},"vid":{"value":"VD-STV_2018_K","timestamp":"2024-01-27T23:20:35.352Z"},"mnmn":{"value":"Samsung Electronics","timestamp":"2024-01-27T23:20:35.352Z"},"mnml":{"value":"http://www.samsung.com","timestamp":"2024-01-27T23:20:35.352Z"},"mnpv":{"value":"Tizen 5.0","timestamp":"2024-01-27T23:20:35.352Z"},"mnos":{"value":"4.1.10","timestamp":"2024-01-27T23:20:35.352Z"},"pi":{"value":"ebe898d3-ebeb-45d0-810a-e6ec04c18be7","timestamp":"2024-01-27T23:20:35.352Z"},"icv":{"value":"core.1.1.0","timestamp":"2024-01-27T23:20:35.352Z"}},"samsungvd.contentInfo":{},"custom.accessibility":{},"custom.disabledCapabilities":{"disabledCapabilities":{"value":["samsungvd.ambient","samsungvd.ambient18","samsungvd.ambientContent","sec.diagnosticsInformation"],"timestamp":"2024-01-27T23:20:33.354Z"}},"samsungvd.remoteControl":{},"sec.diagnosticsInformation":{"logType":{"value":null},"endpoint":{"value":null},"minVersion":{"value":null},"signinPermission":{"value":null},"setupId":{"value":null},"protocolType":{"value":null},"tsId":{"value":null},"mnId":{"value":null},"dumpType":{"value":null}},"custom.launchapp":{},"samsungvd.firmwareVersion":{"firmwareVersion":{"value":"2.4.0","timestamp":"2024-08-28T06:25:18.781Z"}},"audioVolume":{"volume":{"value":20,"unit":"%","timestamp":"2024-01-27T23:20:34.571Z"}},"samsungvd.mediaInputSource":{"supportedInputSourcesMap":{"value":[{"id":"dtv","name":"TV"},{"id":"HDMI1","name":"Shield"},{"id":"HDMI2","name":"Άγνωστο (HDMI 2)"},{"id":"HDMI3","name":"LG SOUND BAR"}],"timestamp":"2024-08-28T17:15:51.596Z"},"inputSource":{"value":"dtv","timestamp":"2024-08-28T17:15:51.596Z"}},"custom.tvsearch":{},"samsungvd.ambient":{},"refresh":{},"custom.error":{"error":{"value":null}},"execute":{"data":{"value":{"payload":{"rt":["x.com.samsung.tv.deviceinfo"],"if":["oic.if.baseline","oic.if.r"],"x.com.samsung.country":"GREECE","x.com.samsung.infolinkversion":"T-INFOLINK2019-1012","x.com.samsung.modelid":"19_MUSEL_UHD","x.com.samsung.tv.ambientsupport":false,"x.com.samsung.tv.blemac":"D0:03:DF:8D:AC:BB","x.com.samsung.tv.btmac":"D0:03:DF:8D:AC:BB","x.com.samsung.tv.category":"tv","x.com.samsung.tv.countrycode":"GR","x.com.samsung.tv.ethmac":"00:7c:2d:44:b7:04","x.com.samsung.tv.mnid":"0AJK","x.com.samsung.tv.onsupport":true,"x.com.samsung.tv.p2pmac":"d2:03:df:8d:ac:ba","x.com.samsung.tv.paneltime":52788,"x.com.samsung.tv.setupid":"101","x.com.samsung.tv.sn":"0ECD3HHM500265R","x.com.samsung.tv.swmodel":"URU7400","x.com.samsung.tv.thingversion":"2.4.0","x.com.samsung.tv.ttxsupport":true,"x.com.samsung.tv.udn":"4561f668-a097-42dd-97ec-883605d6039e","x.com.samsung.tv.wifimac":"d0:03:df:8d:ac:ba"}},"data":{"href":"/sec/tv/deviceinfo"},"timestamp":"2024-01-27T23:20:35.246Z"}},"tvChannel":{"tvChannel":{"value":"2","timestamp":"2024-08-28T17:27:16.465Z"},"tvChannelName":{"value":"ERT 2 HD","timestamp":"2024-08-28T17:27:16.465Z"}},"custom.picturemode":{"pictureMode":{"value":"Φυσική εικόνα","timestamp":"2024-01-27T23:20:34.451Z"},"supportedPictureModes":{"value":["Δυναμική","Τυπικό","Φυσική εικόνα","Ταινία"],"timestamp":"2024-01-27T23:20:34.451Z"},"supportedPictureModesMap":{"value":[{"id":"modeDynamic","name":"Δυναμική"},{"id":"modeStandard","name":"Τυπικό"},{"id":"modeNatural","name":"Φυσική εικόνα"},{"id":"modeMovie","name":"Ταινία"}],"timestamp":"2024-01-27T23:20:34.451Z"}},"samsungvd.ambientContent":{"supportedAmbientApps":{"value":[],"timestamp":"2024-01-27T23:20:33.354Z"}},"custom.recording":{},"samsungvd.ambient18":{},"custom.soundmode":{"supportedSoundModesMap":{"value":[{"id":"modeStandard","name":"Τυπικό"}],"timestamp":"2024-01-27T23:20:34.647Z"},"soundMode":{"value":"Τυπικό","timestamp":"2024-01-27T23:20:34.647Z"},"supportedSoundModes":{"value":["Τυπικό"],"timestamp":"2024-01-27T23:20:34.647Z"}},"audioMute":{"mute":{"value":"unmuted","timestamp":"2024-01-27T23:20:34.571Z"}},"mediaTrackControl":{"supportedTrackControlCommands":{"value":null}}}
00:01:22.199 [DEBUG] [gtv.internal.handler.SamsungTvHandler] - 192.168.10.216: Received value 'channelName':'ERT 2 HD' for thing 'samsungtv:tv:tv'
00:01:22.201 [DEBUG] [gtv.internal.handler.SamsungTvHandler] - 192.168.10.216: Received value 'channel':'2.0' for thing 'samsungtv:tv:tv'
00:01:22.203 [DEBUG] [gtv.internal.handler.SamsungTvHandler] - 192.168.10.216: Received value 'sourceName':'dtv' for thing 'samsungtv:tv:tv'
00:01:22.204 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'TV_TV_Channel' changed from -1.0 to 2.0
00:01:22.209 [DEBUG] [gtv.internal.handler.SamsungTvHandler] - 192.168.10.216: Received value 'sourceId':'0' for thing 'samsungtv:tv:tv'
00:01:22.892 [INFO ] [openhab.event.ItemUpdatedEvent       ] - Item 'TV_TV_Channel' has been updated.
00:01:22.951 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'TV_TV_Channel' changed from NULL to -1.0
00:01:22.967 [TRACE] [gtv.internal.handler.SamsungTvHandler] - 192.168.10.216: channelLinked: samsungtv:tv:tv:channel
00:01:24.219 [TRACE] [nternal.service.SmartThingsApiService] - 192.168.10.216: SSE GOT Response Code: -1
00:01:24.220 [DEBUG] [nternal.service.SmartThingsApiService] - 192.168.10.216: SSE job Failed
00:01:24.221 [TRACE] [nternal.service.SmartThingsApiService] - 192.168.10.216: SSE Starting job
00:01:24.223 [INFO ] [nternal.service.SmartThingsApiService] - 192.168.10.216: SSE Creating Smartthings Subscription
00:01:24.225 [TRACE] [nternal.service.SmartThingsApiService] - 192.168.10.216: subscription: {"subscriptionFilters":[{"type":"DEVICEIDS","value":["ebe898d3-ebeb-45d0-810a-e6ec04c18be7"]}],"name":"OpenHAB Subscription"}
00:01:24.226 [TRACE] [nternal.service.SmartThingsApiService] - 192.168.10.216: Sending https://api.smartthings.com:443/subscriptions
00:01:24.663 [TRACE] [nternal.service.SmartThingsApiService] - 192.168.10.216: Got response: {"subscriptionId":"8de18e9e-3da6-4cc5-a408-e356570d50ce","registrationUrl":"https://spigot-regional.api.smartthings.com/filters/8de18e9e-3da6-4cc5-a408-e356570d50ce/activate?filterRegion=us-east-2","name":"OpenHAB Subscription","version":1,"subscriptionFilters":[{"type":"DEVICEIDS","value":["ebe898d3-ebeb-45d0-810a-e6ec04c18be7"],"eventType":null,"attribute":null,"capability":null,"component":null}]}
00:01:24.665 [TRACE] [nternal.service.SmartThingsApiService] - 192.168.10.216: SSE got subscription ID: 8de18e9e-3da6-4cc5-a408-e356570d50ce
00:01:25.067 [TRACE] [nternal.service.SmartThingsApiService] - 192.168.10.216: SSE GOT Response Code: 200
00:01:25.069 [DEBUG] [nternal.service.SmartThingsApiService] - 192.168.10.216: SSE job Started
00:01:25.070 [TRACE] [nternal.service.SmartThingsApiService] - 192.168.10.216: Sending https://api.smartthings.com:443/v1/devices/ebe898d3-ebeb-45d0-810a-e6ec04c18be7/components/main/status
00:01:25.160 [TRACE] [nternal.service.SmartThingsApiService] - 192.168.10.216: Got response: {"mediaPlayback":{"supportedPlaybackCommands":{"value":["play","pause","stop","fastForward","rewind"],"timestamp":"2024-01-27T23:20:33.354Z"},"playbackStatus":{"value":null}},"samsungvd.supportsPowerOnByOcf":{"supportsPowerOnByOcf":{"value":"false","timestamp":"2024-08-28T06:25:18.781Z"}},"samsungvd.deviceInfoPrivate":{},"mediaInputSource":{"supportedInputSources":{"value":["digitalTv","HDMI1","HDMI2","HDMI3"],"timestamp":"2024-01-27T23:20:33.370Z"},"inputSource":{"value":"digitalTv","timestamp":"2024-01-29T20:10:44.319Z"}},"switch":{"switch":{"value":"on","timestamp":"2024-08-28T17:15:51.527Z"}},"ocf":{"st":{"value":"2024-01-27T19:53:52Z","timestamp":"2024-01-27T23:20:35.352Z"},"mndt":{"value":"2019-01-01","timestamp":"2024-01-27T23:20:35.352Z"},"mnfv":{"value":"T-MSLDEUC-1420.0","timestamp":"2024-04-01T22:01:43.541Z"},"mnhw":{"value":"0-0","timestamp":"2024-01-27T23:20:35.352Z"},"di":{"value":"ebe898d3-ebeb-45d0-810a-e6ec04c18be7","timestamp":"2024-01-27T23:20:35.352Z"},"mnsl":{"value":"http://www.samsung.com/sec/tv/overview/","timestamp":"2024-01-27T23:20:35.352Z"},"dmv":{"value":"res.1.1.0,sh.1.1.0","timestamp":"2024-01-27T23:20:35.352Z"},"n":{"value":"[TV] Samsung 7 Series (50)","timestamp":"2024-01-27T23:20:35.352Z"},"mnmo":{"value":"UE50RU7402UXXH","timestamp":"2024-01-27T23:20:35.352Z"},"vid":{"value":"VD-STV_2018_K","timestamp":"2024-01-27T23:20:35.352Z"},"mnmn":{"value":"Samsung Electronics","timestamp":"2024-01-27T23:20:35.352Z"},"mnml":{"value":"http://www.samsung.com","timestamp":"2024-01-27T23:20:35.352Z"},"mnpv":{"value":"Tizen 5.0","timestamp":"2024-01-27T23:20:35.352Z"},"mnos":{"value":"4.1.10","timestamp":"2024-01-27T23:20:35.352Z"},"pi":{"value":"ebe898d3-ebeb-45d0-810a-e6ec04c18be7","timestamp":"2024-01-27T23:20:35.352Z"},"icv":{"value":"core.1.1.0","timestamp":"2024-01-27T23:20:35.352Z"}},"samsungvd.contentInfo":{},"custom.accessibility":{},"custom.disabledCapabilities":{"disabledCapabilities":{"value":["samsungvd.ambient","samsungvd.ambient18","samsungvd.ambientContent","sec.diagnosticsInformation"],"timestamp":"2024-01-27T23:20:33.354Z"}},"samsungvd.remoteControl":{},"sec.diagnosticsInformation":{"logType":{"value":null},"endpoint":{"value":null},"minVersion":{"value":null},"signinPermission":{"value":null},"setupId":{"value":null},"protocolType":{"value":null},"tsId":{"value":null},"mnId":{"value":null},"dumpType":{"value":null}},"custom.launchapp":{},"samsungvd.firmwareVersion":{"firmwareVersion":{"value":"2.4.0","timestamp":"2024-08-28T06:25:18.781Z"}},"audioVolume":{"volume":{"value":20,"unit":"%","timestamp":"2024-01-27T23:20:34.571Z"}},"samsungvd.mediaInputSource":{"supportedInputSourcesMap":{"value":[{"id":"dtv","name":"TV"},{"id":"HDMI1","name":"Shield"},{"id":"HDMI2","name":"Άγνωστο (HDMI 2)"},{"id":"HDMI3","name":"LG SOUND BAR"}],"timestamp":"2024-08-28T17:15:51.596Z"},"inputSource":{"value":"dtv","timestamp":"2024-08-28T17:15:51.596Z"}},"custom.tvsearch":{},"samsungvd.ambient":{},"refresh":{},"custom.error":{"error":{"value":null}},"execute":{"data":{"value":{"payload":{"rt":["x.com.samsung.tv.deviceinfo"],"if":["oic.if.baseline","oic.if.r"],"x.com.samsung.country":"GREECE","x.com.samsung.infolinkversion":"T-INFOLINK2019-1012","x.com.samsung.modelid":"19_MUSEL_UHD","x.com.samsung.tv.ambientsupport":false,"x.com.samsung.tv.blemac":"D0:03:DF:8D:AC:BB","x.com.samsung.tv.btmac":"D0:03:DF:8D:AC:BB","x.com.samsung.tv.category":"tv","x.com.samsung.tv.countrycode":"GR","x.com.samsung.tv.ethmac":"00:7c:2d:44:b7:04","x.com.samsung.tv.mnid":"0AJK","x.com.samsung.tv.onsupport":true,"x.com.samsung.tv.p2pmac":"d2:03:df:8d:ac:ba","x.com.samsung.tv.paneltime":52788,"x.com.samsung.tv.setupid":"101","x.com.samsung.tv.sn":"0ECD3HHM500265R","x.com.samsung.tv.swmodel":"URU7400","x.com.samsung.tv.thingversion":"2.4.0","x.com.samsung.tv.ttxsupport":true,"x.com.samsung.tv.udn":"4561f668-a097-42dd-97ec-883605d6039e","x.com.samsung.tv.wifimac":"d0:03:df:8d:ac:ba"}},"data":{"href":"/sec/tv/deviceinfo"},"timestamp":"2024-01-27T23:20:35.246Z"}},"tvChannel":{"tvChannel":{"value":"2","timestamp":"2024-08-28T17:27:16.465Z"},"tvChannelName":{"value":"ERT 2 HD","timestamp":"2024-08-28T17:27:16.465Z"}},"custom.picturemode":{"pictureMode":{"value":"Φυσική εικόνα","timestamp":"2024-01-27T23:20:34.451Z"},"supportedPictureModes":{"value":["Δυναμική","Τυπικό","Φυσική εικόνα","Ταινία"],"timestamp":"2024-01-27T23:20:34.451Z"},"supportedPictureModesMap":{"value":[{"id":"modeDynamic","name":"Δυναμική"},{"id":"modeStandard","name":"Τυπικό"},{"id":"modeNatural","name":"Φυσική εικόνα"},{"id":"modeMovie","name":"Ταινία"}],"timestamp":"2024-01-27T23:20:34.451Z"}},"samsungvd.ambientContent":{"supportedAmbientApps":{"value":[],"timestamp":"2024-01-27T23:20:33.354Z"}},"custom.recording":{},"samsungvd.ambient18":{},"custom.soundmode":{"supportedSoundModesMap":{"value":[{"id":"modeStandard","name":"Τυπικό"}],"timestamp":"2024-01-27T23:20:34.647Z"},"soundMode":{"value":"Τυπικό","timestamp":"2024-01-27T23:20:34.647Z"},"supportedSoundModes":{"value":["Τυπικό"],"timestamp":"2024-01-27T23:20:34.647Z"}},"audioMute":{"mute":{"value":"unmuted","timestamp":"2024-01-27T23:20:34.571Z"}},"mediaTrackControl":{"supportedTrackControlCommands":{"value":null}}}
00:01:25.171 [DEBUG] [gtv.internal.handler.SamsungTvHandler] - 192.168.10.216: Received value 'channel':'2.0' for thing 'samsungtv:tv:tv'
00:01:25.171 [TRACE] [nternal.service.SmartThingsApiService] - 192.168.10.216: SSE received: {data=welcome, event=CONTROL_EVENT}
00:01:25.178 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'TV_TV_Channel' changed from -1.0 to 2.0

I do not see the per second requests to smarthings any more and I am getting SSE received events. The thing is when I change channels I do not get these events. I only get them if I have my smartthings app open in my mobile.

Here is the log when I changed channel with SmartThings mobile app open

00:17:44.255 [TRACE] [nternal.service.SmartThingsApiService] - 192.168.10.216: SSE received: {data={"eventTime":1724879864080,"eventType":"DEVICE_EVENT","deviceEvent":{"eventId":"f74ac15c-6582-11ef-b9a0-cb0b409e7360","locationId":"c5c8cddc-3525-44a4-8b4b-4317c8a6899b","ownerId":"c5c8cddc-3525-44a4-8b4b-4317c8a6899b","ownerType":"LOCATION","deviceId":"ebe898d3-ebeb-45d0-810a-e6ec04c18be7","componentId":"main","capability":"tvChannel","attribute":"tvChannelName","value":"ALPHA HD","valueType":"string","stateChange":true,"data":{},"subscriptionName":"OpenHAB Subscription","commandId":""}}, event=DEVICE_EVENT}
00:17:44.258 [TRACE] [nternal.service.SmartThingsApiService] - 192.168.10.216: SSE received: {data={"eventTime":1724879864080,"eventType":"DEVICE_EVENT","deviceEvent":{"eventId":"f74ac154-6582-11ef-9f78-b93cc264fccc","locationId":"c5c8cddc-3525-44a4-8b4b-4317c8a6899b","ownerId":"c5c8cddc-3525-44a4-8b4b-4317c8a6899b","ownerType":"LOCATION","deviceId":"ebe898d3-ebeb-45d0-810a-e6ec04c18be7","componentId":"main","capability":"tvChannel","attribute":"tvChannel","value":"8","valueType":"string","stateChange":true,"data":{},"subscriptionName":"OpenHAB Subscription","commandId":""}}, event=DEVICE_EVENT}
00:17:44.260 [DEBUG] [gtv.internal.handler.SamsungTvHandler] - 192.168.10.216: Received value 'channel':'8.0' for thing 'samsungtv:tv:tv'
00:17:44.261 [TRACE] [nternal.service.SmartThingsApiService] - 192.168.10.216: SSE Got TV Channel Name:  Channel: 8.0
00:17:44.262 [TRACE] [nternal.service.SmartThingsApiService] - 192.168.10.216: Value '' for channelName hasn't changed, ignoring update
00:17:44.262 [INFO ] [openhab.event.ItemStateChangedEvent  ] - Item 'TV_TV_Channel' changed from 6.0 to 8.0
00:17:44.567 [TRACE] [nternal.service.SmartThingsApiService] - 192.168.10.216: SSE received: {data={"eventTime":1724879864479,"eventType":"DEVICE_EVENT","deviceEvent":{"eventId":"f787a3de-6582-11ef-ab41-8f1e63e20322","locationId":"c5c8cddc-3525-44a4-8b4b-4317c8a6899b","ownerId":"c5c8cddc-3525-44a4-8b4b-4317c8a6899b","ownerType":"LOCATION","deviceId":"ebe898d3-ebeb-45d0-810a-e6ec04c18be7","componentId":"main","capability":"tvChannel","attribute":"tvChannelName","value":"ALPHA HD","valueType":"string","stateChange":false,"data":{},"subscriptionName":"OpenHAB Subscription","commandId":""}}, event=DEVICE_EVENT}
00:17:44.570 [TRACE] [nternal.service.SmartThingsApiService] - 192.168.10.216: SSE received: {data={"eventTime":1724879864478,"eventType":"DEVICE_EVENT","deviceEvent":{"eventId":"f7877be9-6582-11ef-b6a5-0fea847b1f45","locationId":"c5c8cddc-3525-44a4-8b4b-4317c8a6899b","ownerId":"c5c8cddc-3525-44a4-8b4b-4317c8a6899b","ownerType":"LOCATION","deviceId":"ebe898d3-ebeb-45d0-810a-e6ec04c18be7","componentId":"main","capability":"tvChannel","attribute":"tvChannel","value":"8","valueType":"string","stateChange":false,"data":{},"subscriptionName":"OpenHAB Subscription","commandId":""}}, event=DEVICE_EVENT}
00:17:44.575 [TRACE] [nternal.service.SmartThingsApiService] - 192.168.10.216: Value '8.0' for channel hasn't changed, ignoring update
00:17:44.577 [TRACE] [nternal.service.SmartThingsApiService] - 192.168.10.216: SSE Got TV Channel Name:  Channel: 8.0
00:17:44.578 [TRACE] [nternal.service.SmartThingsApiService] - 192.168.10.216: Value '' for channelName hasn't changed, ignoring update
NickWaterton commented 2 weeks ago

Created a branch with a test here, might be usefull for debugging https://github.com/lsiepel/openhab-addons/tree/samsuntv-tests

The NPE was fixed by changing the parseTVChannel to static. It somehow does not like public static Number parseTVChannel(@Nullable String channel) {

The root cause looks very much like a timing issue. So there might be more issues hidden somewhere. the subclass calls the enclosing class that seems to be null.

Wait, so the NPE was fixed just by making parseTVChannel static?

I can try that!

NickWaterton commented 2 weeks ago

@vpant Yes, I changed a couple of other things as well. maybe they worked?

the line: SSE Got TV Channel Name: Channel: 8.0 is saying that the Channel Name: is "" and the Channel: is "8.0", so it's getting "" for the channel name for channel 8. However that's via SSE, which is a different method to the polling channel.

The delay on updating the channel number is likely smarthings, it can take a little while to update if the app isn't open.

vpant commented 2 weeks ago

@NickWaterton

There is an sse for the for attribute tvChannelName and the value is ALPHA HD. That should normally update the channelName, right?

Polling seems more reliable in this case. Is there a way to interchange between polling and SSE?

NickWaterton commented 2 weeks ago

@vpant,

Here is a version containing @lsiepel fix and my fixes.

https://github.com/NickWaterton/openhab-addons/releases/download/v2.0/org.openhab.binding.samsungtv-4.3.0-SNAPSHOT.jar

There isn't a manual way of switching between polling and subscriptions for smarthings. Might be something to consider for the future.

With SSE both the channel number and name get updated at the same time (why I report it on one line), but it's parsed differently. I've changed that in this version, so they are parsed (and reported) separately.

I recommend restarting Openhab after adding the new jar, as the subscriptions can add up (they age out), and you are only allowed 15 I think. When manually adding jars, you can end up with multiple subscriptions at once, which confuses the matter.

vpant commented 2 weeks ago

@NickWaterton

I think that is the one. Both channels working as expected now. Having the smarthings app open changes the values almost immidiately.

It would be nice to have the ability to change between polling and SSE. I monitored it for some time and no SSE event is triggered without having smart things app open.

NickWaterton commented 2 weeks ago

Thanks for the help tracking this down. I'll see about adding a subscription override.

NickWaterton commented 2 weeks ago

@vpant here is a final new release, which incorporates a new channel (artOrientation), and a new config option to disable SmartThings subscription, and enable SmartThings polling (when the TV is ON).

https://github.com/NickWaterton/openhab-addons/releases/download/v2.0/org.openhab.binding.samsungtv-4.3.0-SNAPSHOT.jar

Please test it out, and give me feedback on whether this resolves your issues, or if there are any new bugs/problems.

Thanks,

vpant commented 2 weeks ago

@NickWaterton

It seems that even with polling the channel is not updated unless the smartthings app is open on my phone :disappointed:

Using polling only channel (Number) is updated but notchannelName`.

Regarding artOrientation I am not really sure if my TV supports that but I cannot be sure.

I am having issues with some other channels (eg brightness, contrast) not being updated but I think it has something to do with upnp because I can send a command on the channel but I do not receive updates (tried with sourceApp channel). Haven't figured out why yet.

NickWaterton commented 2 weeks ago

Brightness, Contrast aren’t supported on modern TV’s, they only work on really old TV’s.

sourceApp is for launching apps, you need to know the app name or id (you can get this from the logs).

Can you post your TRACE log? Polling is working for me, but I don’t have channel numbers/names, so I would have to see what Smartthings is returning in response to the polling.

vpant commented 1 week ago

@NickWaterton

sorry it took so much time to respond.

I retested it now and it seems channelName is updated. I might have done something wrong before.