Jetty update, Karaf 4.1.3 upgrade and full LSP support

DanielMalmgren · November 22, 2017, 6:48am

For how long have they been untouched? I mean, this might very well have been in my config for a while, I seldom check the contents of that file. And everything seems to work fine anyway until OH is upgrading to 1083+.

Schorsch · November 22, 2017, 7:43am

In the meantime i made a reinstallation of OH2 and restored the backup (without tmp and cache). Now it works like a charm and better than ever bevor. The /opt/openhab2/userdata/etc/org.openhab.addons.cfg file is now “clean”, without “B” and and quotiation marks. I don’t know what the problem was, but it doesn’t matter. Best OH2 till now.

binderth · November 22, 2017, 8:00am

with backup I assume you just pasted the config files from /etc/openhab2/* ?

Kai · November 22, 2017, 8:02am

It is definitely not related to the upgrade scripts. My assumption is that this is due to an changed behavior of Felix FileInstall which has been updated to a more recent version in Karaf 4.1.3.
FileInstall writes such files as well, if configs are edited through Config Admin (e.g. by the Paper UI).
I’ll try to figure out what causes the file to be written by FileInstall here in the first place and also what goes wrong when parsing such a file. I have entered an issue for it.

Schorsch · November 22, 2017, 8:06am

yes. Bevor reinstalling OH i’ve modified the /opt/openhab2/userdata/etc/org.openhab.addons.cfg, since it was also wrong formatted as described here in this thread. Unfortunately i’ve not checked, how the file looks like directly after unpacking the new version.

sihui · November 22, 2017, 12:12pm

Similar issues where already reported 30 days ago:

norbert_jordan · November 23, 2017, 6:43am

having the same issue coming from 1074 to latest release.

Is there any quick fix/trick i could try. going back did not solve the situation. Trying to start immediately results in the log issues named above. Thanks a lot Norbert

Daniel_Linder · November 23, 2017, 8:53am

my logging died. cannot tell what my issue is.
any suggestions what to try?

toxiroxi · November 23, 2017, 9:21am

Hello Norbert,

check your addons.cfg file. Mine was completely empty after the upgrade and i just put in a few values:

package = standard
ui = basic,paper,habmin
remote = true
persistence = jdbc-mysql
action = mail

After that stop Openhab, clear cache and start OH again. All of the erros then went away.I am now on fully working #1088 at the moment and came from same version as you…

Cheers,

mas · November 23, 2017, 3:28pm

Is there actually a relationship between this warning

and the quotes issue in this file?

Or are these two completely different things?

Kai · November 23, 2017, 3:29pm

I doubt that there is a relation.

Dries · November 23, 2017, 5:50pm

@mas: I don’t think there is a relation. I never had the corrupt org.openhab.addons.cfg file.

I’m currently on #1094. No issues so far.

mas · November 23, 2017, 8:13pm

My org.openhab.addons.cfg isn’t also “corrupted”. But I have several config files that look like this. For example, the network bindings config file: “openhab2-userdata\config\binding\network.config”

allowDHCPlisten=B"true"
allowSystemPings=B"true"
arpPingToolPath="arping"
cacheDeviceStateTimeInMS="2000"
service.pid="binding.network"

All the booleans are preceded by a B in quotation marks. I do not think that all such files are broken.

martinvw · November 23, 2017, 8:31pm

I also had some small issues with my org.openhab.addons.cfg, from version 2.2 1068 +/- I had a file with quoted values but somehow it got messed up by new version and looked like

transformation = \"xslt,exec,javascript,scale,xpath,jsonpath\",map,regex

After installing the last two transformations, so we might need to address this with command line fu in our upgrade script, it does not seem create the mess in this release but it did become more sensitive to it, it seems.

However no B"true" for me

But my docker (production) is happily up and running

Kai · November 24, 2017, 8:50am

Did anyone find a way how to force a corrupted org.openhab.addons.cfg file? I’d need to find such a way in order to properly analyse and debug the issue…

martinvw · November 24, 2017, 9:11am

I started the new version with quoted values:

package = "expert"
ui = "classic,basic,paper,habpanel,habmin"
misc = "restdocs,market,dropbox1,homekit,openhabcloud"
transformation = "xslt,exec,javascript,scale,xpath,jsonpath"
remote = "true"
legacy = "true"
action = "telegram"
binding = "astro,expire1,hue,network,snmp1,systeminfo,windcentrale,zwave,ntp,mqtt1,exec"
persistence = "jdbc-mysql,mqtt,mysql,rrd4j,influxdb,mapdb"

By installing bindings on top of that it got corrupted.

binderth · November 24, 2017, 3:28pm

For what it’s worth, I just upgraded von stable to 2.2.0-Snapshot Build #1094 via ~/openhabian-config and my configuration isn’t corrupt, everything works fine.

Hardware: RPi1
Bindings: astro, exec, expire, http1, mqtt1, network, ntp, weather1

edit:
ran into https://github.com/eclipse/smarthome/issues/4591 as noted in Jetty update, Karaf 4.1.3 upgrade and full LSP support after some new configuration and stuff. But this only occurred after adding some changes (added weatherunderground binding with the respected items).

danielf · November 24, 2017, 10:58pm

For me the blocking issue went away after uninstalling caldav-personal1 (and restarting…)

Maybe we should try uninstalling bindings until everything works to find some culprits?

mhilbush · November 25, 2017, 3:17am

@Kai I installed build 1096, and I’m seeing a lot of these in my log. They seem to occur when I’m in vscode mousing over different parts of a rule. I haven’t been able to sort out the exact behavior that causes it, however.

2017-11-24 21:49:27.451 [WARN ] [eclipse.lsp4j.jsonrpc.RemoteEndpoint] - Unmatched cancel notification for request id 17
2017-11-24 21:49:30.863 [WARN ] [eclipse.lsp4j.jsonrpc.RemoteEndpoint] - Unmatched cancel notification for request id 21
2017-11-24 21:49:36.926 [WARN ] [eclipse.lsp4j.jsonrpc.RemoteEndpoint] - Unmatched cancel notification for request id 27
2017-11-24 21:49:39.066 [WARN ] [eclipse.lsp4j.jsonrpc.RemoteEndpoint] - Unmatched cancel notification for request id 29
2017-11-24 21:49:51.675 [WARN ] [eclipse.lsp4j.jsonrpc.RemoteEndpoint] - Unmatched cancel notification for request id 39
2017-11-24 21:50:07.464 [WARN ] [eclipse.lsp4j.jsonrpc.RemoteEndpoint] - Unmatched cancel notification for request id 46
2017-11-24 21:50:12.127 [WARN ] [eclipse.lsp4j.jsonrpc.RemoteEndpoint] - Unmatched cancel notification for request id 50
2017-11-24 21:50:17.225 [WARN ] [eclipse.lsp4j.jsonrpc.RemoteEndpoint] - Unmatched cancel notification for request id 55

I also saw this while using vscode, but again I’m not quite sure what I did that caused it.

2017-11-24 21:48:54.606 [ERROR] [eclipse.lsp4j.jsonrpc.RemoteEndpoint] - Internal error: com.google.common.util.concurrent.ExecutionError: java.lang.NoClassDefFoundError: org/objectweb/asm/ClassReader
java.util.concurrent.CompletionException: com.google.common.util.concurrent.ExecutionError: java.lang.NoClassDefFoundError: org/objectweb/asm/ClassReader
        at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:273) [?:?]
        at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:280) [?:?]
        at java.util.concurrent.CompletableFuture.uniApply(CompletableFuture.java:604) [?:?]
        at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:577) [?:?]
        at java.util.concurrent.CompletableFuture$Completion.run(CompletableFuture.java:442) [?:?]
        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: com.google.common.util.concurrent.ExecutionError: java.lang.NoClassDefFoundError: org/objectweb/asm/ClassReader
        at com.google.common.cache.LocalCache$Segment.get(LocalCache.java:2201) ~[?:?]
        at com.google.common.cache.LocalCache.get(LocalCache.java:3937) ~[?:?]
        at com.google.common.cache.LocalCache$LocalManualCache.get(LocalCache.java:4739) ~[?:?]
        at org.eclipse.xtext.xbase.ide.types.ClasspathScanner.getDescriptors(ClasspathScanner.java:85) ~[?:?]
        at org.eclipse.xtext.xbase.ide.types.ClasspathScanner.lambda$getBootClasspathDescriptors$2(ClasspathScanner.java:99) ~[?:?]
        at org.eclipse.xtext.xbase.lib.internal.FunctionDelegate.apply(FunctionDelegate.java:42) ~[?:?]
        at com.google.common.collect.Iterators$8.transform(Iterators.java:799) ~[?:?]
        at com.google.common.collect.TransformedIterator.next(TransformedIterator.java:48) ~[?:?]
        at com.google.common.collect.TransformedIterator.next(TransformedIterator.java:48) ~[?:?]
        at com.google.common.collect.Iterators$5.hasNext(Iterators.java:548) ~[?:?]
        at com.google.common.collect.Iterators$5.hasNext(Iterators.java:547) ~[?:?]
        at org.eclipse.xtext.xbase.ide.contentassist.ClasspathBasedIdeTypesProposalProvider.createTypeProposals(ClasspathBasedIdeTypesProposalProvider.java:77) ~[?:?]
        at org.eclipse.xtext.xbase.ide.contentassist.XbaseIdeContentProposalProvider.completeJavaTypes(XbaseIdeContentProposalProvider.java:411) ~[?:?]
        at org.eclipse.xtext.xbase.ide.contentassist.XbaseIdeContentProposalProvider.completeJavaTypes(XbaseIdeContentProposalProvider.java:407) ~[?:?]
        at org.eclipse.xtext.xbase.ide.contentassist.XbaseIdeContentProposalProvider._createProposals(XbaseIdeContentProposalProvider.java:204) ~[?:?]
        at org.eclipse.xtext.xbase.ide.contentassist.XbaseIdeContentProposalProvider.createProposals(XbaseIdeContentProposalProvider.java:641) ~[?:?]
        at org.eclipse.xtext.ide.editor.contentassist.IdeContentProposalProvider.createProposals(IdeContentProposalProvider.java:94) ~[?:?]
        at org.eclipse.xtext.ide.server.contentassist.ContentAssistService.createProposals(ContentAssistService.java:108) ~[?:?]
        at org.eclipse.xtext.ide.server.contentassist.ContentAssistService.createCompletionList(ContentAssistService.java:73) ~[?:?]
        at org.eclipse.xtext.ide.server.LanguageServerImpl.lambda$completion$14(LanguageServerImpl.java:425) ~[?:?]
        at org.eclipse.xtext.ide.server.WorkspaceManager.doRead(WorkspaceManager.java:234) ~[?:?]
        at org.eclipse.xtext.ide.server.LanguageServerImpl.completion(LanguageServerImpl.java:427) ~[?:?]
        at org.eclipse.xtext.ide.server.LanguageServerImpl.lambda$completion$13(LanguageServerImpl.java:406) ~[?:?]
        at org.eclipse.xtext.ide.server.concurrent.RequestManager.lambda$runRead$2(RequestManager.java:116) ~[?:?]
        at java.util.concurrent.CompletableFuture.uniApply(CompletableFuture.java:602) ~[?:?]
        ... 5 more
Caused by: java.lang.NoClassDefFoundError: org/objectweb/asm/ClassReader
        at org.eclipse.xtext.xbase.ide.types.ClasspathTypeDescriptor.forJarEntry(ClasspathTypeDescriptor.java:150) ~[?:?]
        at org.eclipse.xtext.xbase.ide.types.ClasspathScanner.loadJarDescriptors(ClasspathScanner.java:229) ~[?:?]
        at org.eclipse.xtext.xbase.ide.types.ClasspathScanner.loadDescriptors(ClasspathScanner.java:154) ~[?:?]
        at org.eclipse.xtext.xbase.ide.types.ClasspathScanner.lambda$getDescriptors$1(ClasspathScanner.java:83) ~[?:?]
        at com.google.common.cache.LocalCache$LocalManualCache$1.load(LocalCache.java:4742) ~[?:?]
        at com.google.common.cache.LocalCache$LoadingValueReference.loadFuture(LocalCache.java:3527) ~[?:?]
        at com.google.common.cache.LocalCache$Segment.loadSync(LocalCache.java:2319) ~[?:?]
        at com.google.common.cache.LocalCache$Segment.lockedGetOrLoad(LocalCache.java:2282) ~[?:?]
        at com.google.common.cache.LocalCache$Segment.get(LocalCache.java:2197) ~[?:?]
        at com.google.common.cache.LocalCache.get(LocalCache.java:3937) ~[?:?]
        at com.google.common.cache.LocalCache$LocalManualCache.get(LocalCache.java:4739) ~[?:?]
        at org.eclipse.xtext.xbase.ide.types.ClasspathScanner.getDescriptors(ClasspathScanner.java:85) ~[?:?]
        at org.eclipse.xtext.xbase.ide.types.ClasspathScanner.lambda$getBootClasspathDescriptors$2(ClasspathScanner.java:99) ~[?:?]
        at org.eclipse.xtext.xbase.lib.internal.FunctionDelegate.apply(FunctionDelegate.java:42) ~[?:?]
        at com.google.common.collect.Iterators$8.transform(Iterators.java:799) ~[?:?]
        at com.google.common.collect.TransformedIterator.next(TransformedIterator.java:48) ~[?:?]
        at com.google.common.collect.TransformedIterator.next(TransformedIterator.java:48) ~[?:?]
        at com.google.common.collect.Iterators$5.hasNext(Iterators.java:548) ~[?:?]
        at com.google.common.collect.Iterators$5.hasNext(Iterators.java:547) ~[?:?]
        at org.eclipse.xtext.xbase.ide.contentassist.ClasspathBasedIdeTypesProposalProvider.createTypeProposals(ClasspathBasedIdeTypesProposalProvider.java:77) ~[?:?]
        at org.eclipse.xtext.xbase.ide.contentassist.XbaseIdeContentProposalProvider.completeJavaTypes(XbaseIdeContentProposalProvider.java:411) ~[?:?]
        at org.eclipse.xtext.xbase.ide.contentassist.XbaseIdeContentProposalProvider.completeJavaTypes(XbaseIdeContentProposalProvider.java:407) ~[?:?]
        at org.eclipse.xtext.xbase.ide.contentassist.XbaseIdeContentProposalProvider._createProposals(XbaseIdeContentProposalProvider.java:204) ~[?:?]
        at org.eclipse.xtext.xbase.ide.contentassist.XbaseIdeContentProposalProvider.createProposals(XbaseIdeContentProposalProvider.java:641) ~[?:?]
        at org.eclipse.xtext.ide.editor.contentassist.IdeContentProposalProvider.createProposals(IdeContentProposalProvider.java:94) ~[?:?]
        at org.eclipse.xtext.ide.server.contentassist.ContentAssistService.createProposals(ContentAssistService.java:108) ~[?:?]
        at org.eclipse.xtext.ide.server.contentassist.ContentAssistService.createCompletionList(ContentAssistService.java:73) ~[?:?]
        at org.eclipse.xtext.ide.server.LanguageServerImpl.lambda$completion$14(LanguageServerImpl.java:425) ~[?:?]
        at org.eclipse.xtext.ide.server.WorkspaceManager.doRead(WorkspaceManager.java:234) ~[?:?]
        at org.eclipse.xtext.ide.server.LanguageServerImpl.completion(LanguageServerImpl.java:427) ~[?:?]
        at org.eclipse.xtext.ide.server.LanguageServerImpl.lambda$completion$13(LanguageServerImpl.java:406) ~[?:?]
        at org.eclipse.xtext.ide.server.concurrent.RequestManager.lambda$runRead$2(RequestManager.java:116) ~[?:?]
        at java.util.concurrent.CompletableFuture.uniApply(CompletableFuture.java:602) ~[?:?]
        ... 5 more
Caused by: java.lang.ClassNotFoundException: org.objectweb.asm.ClassReader cannot be found by org.eclipse.xtext.xbase.ide_2.12.0.v20170519-0752
        at org.eclipse.osgi.internal.loader.BundleLoader.findClassInternal(BundleLoader.java:461) ~[?:?]
        at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:372) ~[?:?]
        at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:364) ~[?:?]
        at org.eclipse.osgi.internal.loader.ModuleClassLoader.loadClass(ModuleClassLoader.java:161) ~[?:?]
        at java.lang.ClassLoader.loadClass(ClassLoader.java:357) ~[?:?]
        at org.eclipse.xtext.xbase.ide.types.ClasspathTypeDescriptor.forJarEntry(ClasspathTypeDescriptor.java:150) ~[?:?]
        at org.eclipse.xtext.xbase.ide.types.ClasspathScanner.loadJarDescriptors(ClasspathScanner.java:229) ~[?:?]
        at org.eclipse.xtext.xbase.ide.types.ClasspathScanner.loadDescriptors(ClasspathScanner.java:154) ~[?:?]
        at org.eclipse.xtext.xbase.ide.types.ClasspathScanner.lambda$getDescriptors$1(ClasspathScanner.java:83) ~[?:?]
        at com.google.common.cache.LocalCache$LocalManualCache$1.load(LocalCache.java:4742) ~[?:?]
        at com.google.common.cache.LocalCache$LoadingValueReference.loadFuture(LocalCache.java:3527) ~[?:?]
        at com.google.common.cache.LocalCache$Segment.loadSync(LocalCache.java:2319) ~[?:?]
        at com.google.common.cache.LocalCache$Segment.lockedGetOrLoad(LocalCache.java:2282) ~[?:?]
        at com.google.common.cache.LocalCache$Segment.get(LocalCache.java:2197) ~[?:?]
        at com.google.common.cache.LocalCache.get(LocalCache.java:3937) ~[?:?]
        at com.google.common.cache.LocalCache$LocalManualCache.get(LocalCache.java:4739) ~[?:?]
        at org.eclipse.xtext.xbase.ide.types.ClasspathScanner.getDescriptors(ClasspathScanner.java:85) ~[?:?]
        at org.eclipse.xtext.xbase.ide.types.ClasspathScanner.lambda$getBootClasspathDescriptors$2(ClasspathScanner.java:99) ~[?:?]
        at org.eclipse.xtext.xbase.lib.internal.FunctionDelegate.apply(FunctionDelegate.java:42) ~[?:?]
        at com.google.common.collect.Iterators$8.transform(Iterators.java:799) ~[?:?]
        at com.google.common.collect.TransformedIterator.next(TransformedIterator.java:48) ~[?:?]
        at com.google.common.collect.TransformedIterator.next(TransformedIterator.java:48) ~[?:?]
        at com.google.common.collect.Iterators$5.hasNext(Iterators.java:548) ~[?:?]
        at com.google.common.collect.Iterators$5.hasNext(Iterators.java:547) ~[?:?]
        at org.eclipse.xtext.xbase.ide.contentassist.ClasspathBasedIdeTypesProposalProvider.createTypeProposals(ClasspathBasedIdeTypesProposalProvider.java:77) ~[?:?]
        at org.eclipse.xtext.xbase.ide.contentassist.XbaseIdeContentProposalProvider.completeJavaTypes(XbaseIdeContentProposalProvider.java:411) ~[?:?]
        at org.eclipse.xtext.xbase.ide.contentassist.XbaseIdeContentProposalProvider.completeJavaTypes(XbaseIdeContentProposalProvider.java:407) ~[?:?]
        at org.eclipse.xtext.xbase.ide.contentassist.XbaseIdeContentProposalProvider._createProposals(XbaseIdeContentProposalProvider.java:204) ~[?:?]
        at org.eclipse.xtext.xbase.ide.contentassist.XbaseIdeContentProposalProvider.createProposals(XbaseIdeContentProposalProvider.java:641) ~[?:?]
        at org.eclipse.xtext.ide.editor.contentassist.IdeContentProposalProvider.createProposals(IdeContentProposalProvider.java:94) ~[?:?]
        at org.eclipse.xtext.ide.server.contentassist.ContentAssistService.createProposals(ContentAssistService.java:108) ~[?:?]
        at org.eclipse.xtext.ide.server.contentassist.ContentAssistService.createCompletionList(ContentAssistService.java:73) ~[?:?]
        at org.eclipse.xtext.ide.server.LanguageServerImpl.lambda$completion$14(LanguageServerImpl.java:425) ~[?:?]
        at org.eclipse.xtext.ide.server.WorkspaceManager.doRead(WorkspaceManager.java:234) ~[?:?]
        at org.eclipse.xtext.ide.server.LanguageServerImpl.completion(LanguageServerImpl.java:427) ~[?:?]
        at org.eclipse.xtext.ide.server.LanguageServerImpl.lambda$completion$13(LanguageServerImpl.java:406) ~[?:?]
        at org.eclipse.xtext.ide.server.concurrent.RequestManager.lambda$runRead$2(RequestManager.java:116) ~[?:?]
        at java.util.concurrent.CompletableFuture.uniApply(CompletableFuture.java:602) ~[?:?]
        ... 5 more

And this one whenever I close vscode.

2017-11-24 22:10:54.900 [ERROR] [nrpc.json.ConcurrentMessageProcessor] - java.net.SocketException: Connection reset
java.lang.RuntimeException: java.net.SocketException: Connection reset
        at org.eclipse.lsp4j.jsonrpc.json.StreamMessageProducer.listen(StreamMessageProducer.java:103) [106:org.eclipse.lsp4j.jsonrpc:0.2.1.v20170706-0855]
        at org.eclipse.lsp4j.jsonrpc.json.ConcurrentMessageProcessor.run(ConcurrentMessageProcessor.java:84) [106:org.eclipse.lsp4j.jsonrpc:0.2.1.v20170706-0855]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
        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) [?:?]
Caused by: java.net.SocketException: Connection reset
        at java.net.SocketInputStream.read(SocketInputStream.java:210) ~[?:?]
        at java.net.SocketInputStream.read(SocketInputStream.java:141) ~[?:?]
        at java.net.SocketInputStream.read(SocketInputStream.java:224) ~[?:?]
        at org.eclipse.lsp4j.jsonrpc.json.StreamMessageProducer.listen(StreamMessageProducer.java:61) ~[?:?]
        ... 6 more

More concerning is that all my squeezebox, globalcache, and bigassfan things came up uninitialized. The bindings appear to be installed and running.

openhab> bundle:list -s | grep squeeze
226 │ Active   │  80 │ 2.2.0.201711242225     │ org.openhab.binding.squeezebox
openhab> bundle:list -s | grep global
223 │ Active   │  80 │ 2.2.0.201711242225     │ org.openhab.binding.globalcache
openhab> bundle:list -s | grep bigassfan
221 │ Active   │  80 │ 2.2.0.201711242225     │ org.openhab.binding.bigassfan

As this is my prod system, I’m restoring the backup from the previous build I was on (1081).

Dim · November 25, 2017, 7:46am

My experience from today’s upgrade was a smooth one (no issues to report)
From: openHAB2 2.2.0 Snapshot Build #1082 (2.2.0~20171116035510) based on Karaf 4.1.2
To: openHAB2 2.2.0 Snapshot Build #1096 (2.2.0~20171125002051) based on Karaf 4.1.3

All tested and working fine (knx, mqtt, astro, mail, pushover, mapdb, influxdb, homekit, weather, nuts)
I will check the Language Server stuff (LSP with VSCode) and report back.
So far, so good… Logs are clean and system is fully functional