M3 testing results

Maurits28 · September 13, 2019, 5:10pm

Not sure if it is considered normal, but I always have to do it…

5iver · September 13, 2019, 5:20pm

Not normal, but after clearing the cache, you need to restart twice to have OH startup properly. There was a seemingly related issue opened, but it was closed. Another issue should be opened for this.

rlkoshak · September 13, 2019, 6:28pm

Thanks for mentioning this. I always upgrade through Ansible so wouldn’t have noticed unless there was an error.

fibu-freak · September 13, 2019, 6:37pm

Just looked in the logger, I found this warnings:

2019-09-13 19:53:49.892 [INFO ] [rnal.service.RemoteControllerService] - Using WebSocket interface
2019-09-13 19:53:49.962 [WARN ] [l.protocol.RemoteControllerWebSocket] - Problem connecting to remote websocket
org.openhab.binding.samsungtv.internal.protocol.RemoteControllerException: java.lang.IllegalStateException: WebSocketClient@161718803 is not started
	at org.openhab.binding.samsungtv.internal.protocol.WebSocketBase.connect(WebSocketBase.java:77) ~[242:org.openhab.binding.samsungtv:2.5.0.M3]
	at org.openhab.binding.samsungtv.internal.protocol.RemoteControllerWebSocket.connectWebSockets(RemoteControllerWebSocket.java:175) [242:org.openhab.binding.samsungtv:2.5.0.M3]
	at org.openhab.binding.samsungtv.internal.protocol.RemoteControllerWebSocket.openConnection(RemoteControllerWebSocket.java:156) [242:org.openhab.binding.samsungtv:2.5.0.M3]
	at org.openhab.binding.samsungtv.internal.service.RemoteControllerService.start(RemoteControllerService.java:202) [242:org.openhab.binding.samsungtv:2.5.0.M3]
	at org.openhab.binding.samsungtv.internal.handler.SamsungTvHandler.checkCreateManualConnection(SamsungTvHandler.java:281) [242:org.openhab.binding.samsungtv:2.5.0.M3]
	at org.openhab.binding.samsungtv.internal.handler.SamsungTvHandler.checkAndCreateServices(SamsungTvHandler.java:220) [242:org.openhab.binding.samsungtv:2.5.0.M3]
	at org.openhab.binding.samsungtv.internal.handler.SamsungTvHandler.thingDiscovered(SamsungTvHandler.java:333) [242:org.openhab.binding.samsungtv:2.5.0.M3]
	at org.eclipse.smarthome.config.discovery.internal.DiscoveryServiceRegistryImpl$1.run(DiscoveryServiceRegistryImpl.java:265) [139:org.openhab.core.config.discovery:2.5.0.M3]
	at org.eclipse.smarthome.config.discovery.internal.DiscoveryServiceRegistryImpl$1.run(DiscoveryServiceRegistryImpl.java:1) [139:org.openhab.core.config.discovery:2.5.0.M3]
	at java.security.AccessController.doPrivileged(Native Method) ~[?:?]
	at org.eclipse.smarthome.config.discovery.internal.DiscoveryServiceRegistryImpl.thingDiscovered(DiscoveryServiceRegistryImpl.java:262) [139:org.openhab.core.config.discovery:2.5.0.M3]
	at org.eclipse.smarthome.config.discovery.AbstractDiscoveryService.thingDiscovered(AbstractDiscoveryService.java:279) [139:org.openhab.core.config.discovery:2.5.0.M3]
	at org.eclipse.smarthome.config.discovery.upnp.internal.UpnpDiscoveryService.remoteDeviceAdded(UpnpDiscoveryService.java:190) [244:org.openhab.core.config.discovery.upnp:2.5.0.M3]
	at org.jupnp.registry.RemoteItems$1.run(RemoteItems.java:114) [228:org.jupnp:2.5.2]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
	at java.lang.Thread.run(Thread.java:748) [?:?]
Caused by: java.lang.IllegalStateException: WebSocketClient@161718803 is not started
	at org.eclipse.jetty.websocket.client.WebSocketClient.connect(WebSocketClient.java:337) ~[?:?]
	at org.eclipse.jetty.websocket.client.WebSocketClient.connect(WebSocketClient.java:312) ~[?:?]
	at org.eclipse.jetty.websocket.client.WebSocketClient.connect(WebSocketClient.java:294) ~[?:?]
	at org.openhab.binding.samsungtv.internal.protocol.WebSocketBase.connect(WebSocketBase.java:75) ~[?:?]
	... 16 more
2019-09-13 19:53:49.979 [WARN ] [l.protocol.RemoteControllerWebSocket] - Problem connecting to artmode websocket
org.openhab.binding.samsungtv.internal.protocol.RemoteControllerException: java.lang.IllegalStateException: WebSocketClient@161718803 is not started
	at org.openhab.binding.samsungtv.internal.protocol.WebSocketBase.connect(WebSocketBase.java:77) ~[242:org.openhab.binding.samsungtv:2.5.0.M3]
	at org.openhab.binding.samsungtv.internal.protocol.RemoteControllerWebSocket.connectWebSockets(RemoteControllerWebSocket.java:182) [242:org.openhab.binding.samsungtv:2.5.0.M3]
	at org.openhab.binding.samsungtv.internal.protocol.RemoteControllerWebSocket.openConnection(RemoteControllerWebSocket.java:156) [242:org.openhab.binding.samsungtv:2.5.0.M3]
	at org.openhab.binding.samsungtv.internal.service.RemoteControllerService.start(RemoteControllerService.java:202) [242:org.openhab.binding.samsungtv:2.5.0.M3]
	at org.openhab.binding.samsungtv.internal.handler.SamsungTvHandler.checkCreateManualConnection(SamsungTvHandler.java:281) [242:org.openhab.binding.samsungtv:2.5.0.M3]
	at org.openhab.binding.samsungtv.internal.handler.SamsungTvHandler.checkAndCreateServices(SamsungTvHandler.java:220) [242:org.openhab.binding.samsungtv:2.5.0.M3]
	at org.openhab.binding.samsungtv.internal.handler.SamsungTvHandler.thingDiscovered(SamsungTvHandler.java:333) [242:org.openhab.binding.samsungtv:2.5.0.M3]
	at org.eclipse.smarthome.config.discovery.internal.DiscoveryServiceRegistryImpl$1.run(DiscoveryServiceRegistryImpl.java:265) [139:org.openhab.core.config.discovery:2.5.0.M3]
	at org.eclipse.smarthome.config.discovery.internal.DiscoveryServiceRegistryImpl$1.run(DiscoveryServiceRegistryImpl.java:1) [139:org.openhab.core.config.discovery:2.5.0.M3]
	at java.security.AccessController.doPrivileged(Native Method) ~[?:?]
	at org.eclipse.smarthome.config.discovery.internal.DiscoveryServiceRegistryImpl.thingDiscovered(DiscoveryServiceRegistryImpl.java:262) [139:org.openhab.core.config.discovery:2.5.0.M3]
	at org.eclipse.smarthome.config.discovery.AbstractDiscoveryService.thingDiscovered(AbstractDiscoveryService.java:279) [139:org.openhab.core.config.discovery:2.5.0.M3]
	at org.eclipse.smarthome.config.discovery.upnp.internal.UpnpDiscoveryService.remoteDeviceAdded(UpnpDiscoveryService.java:190) [244:org.openhab.core.config.discovery.upnp:2.5.0.M3]
	at org.jupnp.registry.RemoteItems$1.run(RemoteItems.java:114) [228:org.jupnp:2.5.2]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
	at java.lang.Thread.run(Thread.java:748) [?:?]
Caused by: java.lang.IllegalStateException: WebSocketClient@161718803 is not started
	at org.eclipse.jetty.websocket.client.WebSocketClient.connect(WebSocketClient.java:337) ~[?:?]
	at org.eclipse.jetty.websocket.client.WebSocketClient.connect(WebSocketClient.java:312) ~[?:?]
	at org.eclipse.jetty.websocket.client.WebSocketClient.connect(WebSocketClient.java:294) ~[?:?]
	at org.openhab.binding.samsungtv.internal.protocol.WebSocketBase.connect(WebSocketBase.java:75) ~[?:?]
	... 16 more
2019-09-13 19:53:49.997 [WARN ] [l.protocol.RemoteControllerWebSocket] - Problem connecting to V2 websocket
org.openhab.binding.samsungtv.internal.protocol.RemoteControllerException: java.lang.IllegalStateException: WebSocketClient@161718803 is not started
	at org.openhab.binding.samsungtv.internal.protocol.WebSocketBase.connect(WebSocketBase.java:77) ~[242:org.openhab.binding.samsungtv:2.5.0.M3]
	at org.openhab.binding.samsungtv.internal.protocol.RemoteControllerWebSocket.connectWebSockets(RemoteControllerWebSocket.java:188) [242:org.openhab.binding.samsungtv:2.5.0.M3]
	at org.openhab.binding.samsungtv.internal.protocol.RemoteControllerWebSocket.openConnection(RemoteControllerWebSocket.java:156) [242:org.openhab.binding.samsungtv:2.5.0.M3]
	at org.openhab.binding.samsungtv.internal.service.RemoteControllerService.start(RemoteControllerService.java:202) [242:org.openhab.binding.samsungtv:2.5.0.M3]
	at org.openhab.binding.samsungtv.internal.handler.SamsungTvHandler.checkCreateManualConnection(SamsungTvHandler.java:281) [242:org.openhab.binding.samsungtv:2.5.0.M3]
	at org.openhab.binding.samsungtv.internal.handler.SamsungTvHandler.checkAndCreateServices(SamsungTvHandler.java:220) [242:org.openhab.binding.samsungtv:2.5.0.M3]
	at org.openhab.binding.samsungtv.internal.handler.SamsungTvHandler.thingDiscovered(SamsungTvHandler.java:333) [242:org.openhab.binding.samsungtv:2.5.0.M3]
	at org.eclipse.smarthome.config.discovery.internal.DiscoveryServiceRegistryImpl$1.run(DiscoveryServiceRegistryImpl.java:265) [139:org.openhab.core.config.discovery:2.5.0.M3]
	at org.eclipse.smarthome.config.discovery.internal.DiscoveryServiceRegistryImpl$1.run(DiscoveryServiceRegistryImpl.java:1) [139:org.openhab.core.config.discovery:2.5.0.M3]
	at java.security.AccessController.doPrivileged(Native Method) ~[?:?]
	at org.eclipse.smarthome.config.discovery.internal.DiscoveryServiceRegistryImpl.thingDiscovered(DiscoveryServiceRegistryImpl.java:262) [139:org.openhab.core.config.discovery:2.5.0.M3]
	at org.eclipse.smarthome.config.discovery.AbstractDiscoveryService.thingDiscovered(AbstractDiscoveryService.java:279) [139:org.openhab.core.config.discovery:2.5.0.M3]
	at org.eclipse.smarthome.config.discovery.upnp.internal.UpnpDiscoveryService.remoteDeviceAdded(UpnpDiscoveryService.java:190) [244:org.openhab.core.config.discovery.upnp:2.5.0.M3]
	at org.jupnp.registry.RemoteItems$1.run(RemoteItems.java:114) [228:org.jupnp:2.5.2]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
	at java.lang.Thread.run(Thread.java:748) [?:?]
Caused by: java.lang.IllegalStateException: WebSocketClient@161718803 is not started
	at org.eclipse.jetty.websocket.client.WebSocketClient.connect(WebSocketClient.java:337) ~[?:?]
	at org.eclipse.jetty.websocket.client.WebSocketClient.connect(WebSocketClient.java:312) ~[?:?]
	at org.eclipse.jetty.websocket.client.WebSocketClient.connect(WebSocketClient.java:294) ~[?:?]
	at org.openhab.binding.samsungtv.internal.protocol.WebSocketBase.connect(WebSocketBase.java:75) ~[?:?]
	... 16 more

I’m not very experienced, but for me it looks like, if something’s wrong with the samsung-Binding. Isn’t it ?

Andrew_Rowe · September 13, 2019, 7:32pm

appears to be
Was this right after start up Peter?

fibu-freak · September 13, 2019, 10:08pm

Hi Andrew,
thx for reply.
No, not after startup.This is the first time, I saw this Warning. Maybe it’s happend when I switched on the TV, but I’m not shure.

Sometimes I got another Log, but as ERROR from the AVM-Binding

------------------------------------------------- AVM - fritz ---------------------------------------------------------------------------------------------------------------------------------------------------------
2019-08-13 23:04:49.960 [ERROR] [nal.common.AbstractInvocationHandler] - An error occurred while calling method 'ThingHandler.initialize()' on 'org.openhab.binding.avmfritz.internal.handler.BoxHandler@18debca': null
java.lang.NullPointerException: null
	at org.openhab.binding.avmfritz.internal.handler.AVMFritzBaseBridgeHandler.initialize(AVMFritzBaseBridgeHandler.java:140) ~[?:?]
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[?:?]
	at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:152) [133:org.openhab.core:2.5.0.M2]
	at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:53) [133:org.openhab.core:2.5.0.M2]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
	at java.lang.Thread.run(Thread.java:748) [?:?]
2019-08-13 23:04:49.972 [ERROR] [core.thing.internal.ThingManagerImpl] - Exception occurred while initializing handler of thing 'avmfritz:fritzbox:Fritz-Box-7490': null
java.lang.NullPointerException: null
	at org.openhab.binding.avmfritz.internal.handler.AVMFritzBaseBridgeHandler.initialize(AVMFritzBaseBridgeHandler.java:140) ~[?:?]
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]
	at java.lang.reflect.Method.invoke(Method.java:498) ~[?:?]
	at org.eclipse.smarthome.core.internal.common.AbstractInvocationHandler.invokeDirect(AbstractInvocationHandler.java:152) [133:org.openhab.core:2.5.0.M2]
	at org.eclipse.smarthome.core.internal.common.Invocation.call(Invocation.java:53) [133:org.openhab.core:2.5.0.M2]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
	at java.lang.Thread.run(Thread.java:748) [?:?]

This error occurs sometimes(not always) after startup since I’m on 2.5.M2. For that I gave a hint to @cweitkamp.
In that case one only has to restart the bundle via karaf.(as a workaround, for the moment).

But the WARNING of the Samsung-Binding I saw for the first time.

Somtimes I get other WARNING/INFO-Messages from the Logger

2019-09-13 01:11:57.779 [INFO ] [rnal.service.RemoteControllerService] - Using WebSocket interface
2019-09-13 01:17:13.294 [WARN ] [org.eclipse.jetty.io.ManagedSelector] - java.nio.channels.ClosedSelectorException
2019-09-13 01:17:13.299 [WARN ] [l.protocol.RemoteControllerWebSocket] - WebSocketClient failure: java.lang.InterruptedException

Maybe there’s a correlation ?

Cheers,
Peter

EDIT: When restarting the bundle, I can see these messages in the Logger:

2019-09-14 00:15:02.112 [WARN ] [core.thing.internal.ThingManagerImpl] - Disposing handler for thing 'samsungtv:tv:TV_UE46ES6300' takes more than 5000ms.
2019-09-14 00:15:07.188 [WARN ] [core.thing.internal.ThingManagerImpl] - Disposing handler for thing 'samsungtv:tv:0d1cef01_00dc_1000_960f_90f1aac88a51' takes more than 5000ms.

NCO · September 14, 2019, 7:11am

I am happy with M3 so far as well.

Raspb Pi 3 B - openhabian

binding = amazondashbutton,amazonechocontrol,astro,denonmarantz,exec,fritzboxtr0641,gpstracker,harmonyhub,http1,km200,neato,netatmo,network,ntp,openweathermap,systeminfo,tankerkoenig,wol1,zwave

ui = paper,habmin,habpanel

persistence = jdbc-sqlite,mapdb

action = telegram

The only strange thing I see is, that the system binding reports now the CPU with
{channel="systeminfo:computer:Homer:cpu#load1"} (or 5 min …)

I get data, but PaperUI does not even show this channel.

wborn · September 14, 2019, 7:56am

It’s a known issue that when new channels get added to Things you need to recreate existing Things to use these.

NCO · September 14, 2019, 8:01am

That’s what I did.
But even the new thing does not show the channel load1 etc.
The only CPU related channel is
systeminfo:computer:Homer:cpu#name

hilbrand · September 14, 2019, 8:16am

You mean in the detail of a thing with the list of channels in PaperUI? It’s an advanced channel, and will be shown when clicking Show More. But I’m guessing you already tried that?

Maurits28 · September 14, 2019, 10:13am

As you can read in the upgrade / release notes, the load channel of CPU is not supported anymore due to changes in the used OSGi library.

hilbrand · September 14, 2019, 10:38am

This is about load1 not load (and OSHI)

NCO · September 14, 2019, 10:43am

Damn it - you’re right.
I knew that once, but that’s what’s happening, when you don’t use PaperUI for a long time
Thanks for pointing me into the right direction!

Maurits28 · September 14, 2019, 11:26am

Ok my mistake. Thought it was the same.

NCO · September 15, 2019, 7:22am

I got a log entry I have never seen before:

Validation issues found in configuration model 'geofencing.rules', using it anyway:
Unreachable expression.

How to find out where the issue is?
Usually the log shows the location within the rule to check [xxx,xx]

So what is
Unreachable expression?

EDIT:
Got it with SmartHome Designer (instead of VSC) - actually very obvious

rule "Geo Distance"
when
    Member of G_Locations changed
then
	var itemName = triggeringItem.name.toString
// skip distance calculation for TripStart and TripEnd Locations
	if(itemName == "CarTripFromLoc" || itemName == "CarTripToLoc") {
		return; // failing fast
		logInfo("geofencing.rules", "G_Location change - TripStart / TripEnd skipped")
	}

return; was misplaced

Flole · September 28, 2019, 9:29am

Unfortunately since a few versions openhab is getting more and more unstable for me: Startups are sometimes randomly failing (the Webinterface is loading forever and bindings aren’t loaded after a few hours), bindings stop to work or don’t load/startup properly (execute binding for example needs a bundle:restart at least once) and not even to mention the loading of rules without the underlying system being ready (which causes all kinds of weird errors, delaying the loading gets around it though). I haven’t seen anything suspicious in the logs though, so that’s making it hard to post issues on all of these.

vzorglub · September 28, 2019, 9:48am

Are you running openHAB on a raspberry pi with sd card?

Flole · September 28, 2019, 10:13am

No, I am running on an odroid c2 with the rootfs being on a NFS Server.

Bruce_Osborne · September 28, 2019, 10:21am

Are you sure there is not something network or permission related causing issues? NFS can be tricky at times.
I would shy away from having rootfs network mounted unless absolutely necessary as a temporary workaround until a permanent solution is deployed.

Flole · September 28, 2019, 10:43am

This is a way better solution than SD cards and is a lot more reliable. If there would be network issues there would be “NFS Server x.x.x.x not responding, still trying” in dmesg, but it isn’t. There is also no permission issue as I have openhab running as root as its a dedicated device just for openhab.

I might need to mention that my installation is quite big with more than 600 items, loading those also takes a while and I think that is a contributing factor to my rule issues (which is still no excuse that the fundamental underlying environment isn’t setup when rules are executed and it then never recovers from that situation).