M3 testing results

Issue opened, link above.

1 Like

No problems to report. I’m actually on the snapshots from a couple days ago but my comments should also apply to M3.

OS: Ubuntu 18.4 server, OH running in Docker
Version: 2.5.0 Build #1686

add-ons:

  • paper
  • basic
  • habmin
  • habpanel
  • habot
  • resdocs
  • mapdb
  • influxdb
  • map
  • jsonpath
  • regex
  • javascript
  • xslt
  • openhabcloud
  • market
  • ruleengine
  • zwave
  • astro
  • expire1
  • network
  • http1
  • mqtt1 # I’ve still a couple of Items I’ve not moved to the 2.5 binding yet pending some other changes I want to make first
  • zigbee # still no devices yet so it’s installed but not really being used yet
  • networkupstools1
  • nest
  • mqtt
  • openweathermap
  • mail

I noticed a lot of new entries in the log and discovered that there are a bunch of new stuff added to the logging config. Once I downloaded the latest config file and re-added my customization the logs are back to normal.

NOTE: For fellow Docker users, after upgrading look in $OH_USERDATA/logs/update.log. All the important notes that apt-get users get (e.g. list of breaking changes like the REST Docs moving to the UIs category) are saved there.

The container also prints this to stdout so it will show up if you start the container in the foreground (undetached) or when showing the container logs using the command: docker logs CONTAINER

1 Like

I just upgraded and everything seems to be working well again. I had to restart a few times and clean-cache but after that all works.

I’m using the following bindings:

  • Air Quality
  • Astro
  • Broadlink
  • Exec
  • Icloud
  • Kodi
  • Logreader
  • Network
  • OpenWeathermap
  • Jointspace1
  • Mqtt1
  • Sonos
  • Systeminfo
  • Telegram binding
  • Tradfri

OS: Ubuntu 16.04 LTS / HP laptop

Is that considered normal for upgrades? I know I needed to do that from M1 to M2 but I also removed some manual bindings.

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

1 Like

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.

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

1 Like

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 ?

appears to be
Was this right after start up Peter?

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.

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.

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

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

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?

1 Like

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.

This is about load1 not load (and OSHI)

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 :wink:
Thanks for pointing me into the right direction!

Ok my mistake. Thought it was the same.

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 :wink:

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 :wink: