Code Validation not working with LSP (InvocationTargetException), using VS Code Extension

[c--r]

Current Behaviour

Code Validation in VS Code does not work (errors are not marked or explained), when clicking on other code lines, I get the following error message in the "Output" ("Ausgabe") area in VS Code:

[Error - 23:25:47] Request textDocument/documentHighlight failed.
  Message: Internal error, please look at the server's logs.
  Code: -32603 
[Error - 23:25:48] Request textDocument/hover failed.
  Message: Internal error, please look at the server's logs.
  Code: -32603 

This happens even when creating e.g. a new rules file.

This is a follow-up to this discussion, in which another user reported the same problem; and a copy of this issue.

My environment

VS Studio Code (running on Win7 PC): Version 1.19.1 Commit 0759f77bb8d86658bc935a10a64f6182c5a1eeba Datum 2017-12-19T09:46:23.884Z Shell 1.7.9 Renderer 58.0.3029.110 Node 7.9.0 Architektur x64

using openHAB VS Code Extension 0.3.5

connecting to a openhab-2.2.0 distribution (latest stable release downloaded from openhab.org, no snapshot) running on Raspian Stretch on a Raspberry Pi 3

Log Details

When opening a file in VS Code

(there is nothing logged in the "Output" Section or so in VS Code )

By default, there is no output in the openhab.log related to the Language Server probably due to this change: filter out known exceptions from the log #606 After setting log4j2.logger.lsp4j.level = INFO in userdata/etc/org.ops4j.pax.logging.cfg there is the following output:

 2017-12-28 23:05:07.667 [WARN ] [eclipse.lsp4j.jsonrpc.RemoteEndpoint] - Notification threw an exception: {
  "jsonrpc": "2.0",
  "method": "textDocument/didOpen",
  "params": {
    "textDocument": {
      "uri": "file:///d%3A/openHAB/openhab-2.2.0-rpi2/conf/rules/new.rules",
      "languageId": "openhab",
      "version": 1,
      "text": "rule \"rule name\"\r\nwhen\r\n    Item BL_AZ changed\r\nthen\r\n    logDebug(\"openhab\", \"message\")\r\nend\r\n"
    }
  }
}
java.lang.RuntimeException: java.lang.reflect.InvocationTargetException
        at org.eclipse.lsp4j.jsonrpc.services.GenericEndpoint.lambda$null$0(GenericEndpoint.java:53) ~[102:org.eclipse.lsp4j.jsonrpc:0.2.1.v20170706-0855]
        at org.eclipse.lsp4j.jsonrpc.services.GenericEndpoint.notify(GenericEndpoint.java:126) [102:org.eclipse.lsp4j.jsonrpc:0.2.1.v20170706-0855]
        at org.eclipse.lsp4j.jsonrpc.RemoteEndpoint.handleNotification(RemoteEndpoint.java:165) [102:org.eclipse.lsp4j.jsonrpc:0.2.1.v20170706-0855]
        at org.eclipse.lsp4j.jsonrpc.RemoteEndpoint.consume(RemoteEndpoint.java:136) [102:org.eclipse.lsp4j.jsonrpc:0.2.1.v20170706-0855]
        at org.eclipse.lsp4j.jsonrpc.json.StreamMessageProducer.handleMessage(StreamMessageProducer.java:149) [102:org.eclipse.lsp4j.jsonrpc:0.2.1.v20170706-0855]
        at org.eclipse.lsp4j.jsonrpc.json.StreamMessageProducer.listen(StreamMessageProducer.java:77) [102:org.eclipse.lsp4j.jsonrpc:0.2.1.v20170706-0855]
        at org.eclipse.lsp4j.jsonrpc.json.ConcurrentMessageProcessor.run(ConcurrentMessageProcessor.java:84) [102: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.lang.reflect.InvocationTargetException
        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.lsp4j.jsonrpc.services.GenericEndpoint.lambda$null$0(GenericEndpoint.java:51) ~[?:?]
        ... 11 more
Caused by: java.lang.NullPointerException
        at org.eclipse.xtext.ide.server.WorkspaceManager.getProjectManager(WorkspaceManager.java:173) ~[?:?]
        at org.eclipse.xtext.ide.server.BuildManager.internalBuild(BuildManager.java:150) ~[?:?]
        at org.eclipse.xtext.ide.server.BuildManager.doBuild(BuildManager.java:125) ~[?:?]
        at org.eclipse.xtext.ide.server.WorkspaceManager.doBuild(WorkspaceManager.java:153) ~[?:?]
        at org.eclipse.xtext.ide.server.WorkspaceManager.didOpen(WorkspaceManager.java:202) ~[?:?]
        at org.eclipse.xtext.ide.server.LanguageServerImpl.lambda$didOpen$4(LanguageServerImpl.java:263) ~[?:?]
        at org.eclipse.xtext.ide.server.concurrent.RequestManager.runWrite(RequestManager.java:71) ~[?:?]
        at org.eclipse.xtext.ide.server.LanguageServerImpl.didOpen(LanguageServerImpl.java:266) ~[?:?]
        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.lsp4j.jsonrpc.services.GenericEndpoint.lambda$null$0(GenericEndpoint.java:51) ~[?:?]
        ... 11 more

Here is the payload sniffed on port 5007 using Wireshark:

Content-Length: 1275
{"jsonrpc":"2.0","id":0,"method":"initialize","params":{"processId":8888,"rootPath":"d:\\openHAB\\openhab-2.2.0-rpi2","rootUri":"file:///d%3A/openHAB/openhab-2.2.0-rpi2","capabilities":{"workspace":{"applyEdit":true,"didChangeConfiguration":{"dynamicRegistration":true},"didChangeWatchedFiles":{"dynamicRegistration":true},"symbol":{"dynamicRegistration":true},"executeCommand":{"dynamicRegistration":true}},"textDocument":{"synchronization":{"dynamicRegistration":true,"willSave":true,"willSaveWaitUntil":true,"didSave":true},"completion":{"dynamicRegistration":true,"completionItem":{"snippetSupport":true,"commitCharactersSupport":true}},"hover":{"dynamicRegistration":true},"signatureHelp":{"dynamicRegistration":true},"definition":{"dynamicRegistration":true},"references":{"dynamicRegistration":true},"documentHighlight":{"dynamicRegistration":true},"documentSymbol":{"dynamicRegistration":true},"codeAction":{"dynamicRegistration":true},"codeLens":{"dynamicRegistration":true},"formatting":{"dynamicRegistration":true},"rangeFormatting":{"dynamicRegistration":true},"onTypeFormatting":{"dynamicRegistration":true},"rename":{"dynamicRegistration":true},"documentLink":{"dynamicRegistration":true}}},"trace":"off"}}

Content-Length: 444
{"jsonrpc":"2.0","id":"0","result":{"capabilities":{"textDocumentSync":2,"hoverProvider":true,"completionProvider":{"resolveProvider":false,"triggerCharacters":["."]},"signatureHelpProvider":{"triggerCharacters":["(",","]},"definitionProvider":true,"referencesProvider":true,"documentHighlightProvider":true,"documentSymbolProvider":true,"workspaceSymbolProvider":true,"documentFormattingProvider":true,"documentRangeFormattingProvider":true}}}

Content-Length: 52
{"jsonrpc":"2.0","method":"initialized","params":{}}

Content-Length: 101
{"jsonrpc":"2.0","method":"workspace/didChangeConfiguration","params":{"settings":{"openhabLSP":{}}}}

Content-Length: 330
{"jsonrpc":"2.0","method":"textDocument/didOpen","params":{"textDocument":{"uri":"file:///d%3A/openHAB/openhab-2.2.0-rpi2/conf/rules/new.rules","languageId":"openhab","version":1,"text":"rule \"rule name\"\r\nwhen\r\n    Item BL_AZ changed\r\nthen\r\n    logDebug(\"openhab\", \"message\")\r\nend\r\n"}}}

When clicking on code lines in VS Code:

(there is no log output in openhab.log)

VS Code shows:

[Error - 23:25:47] Request textDocument/documentHighlight failed.
  Message: Internal error, please look at the server's logs.
  Code: -32603 
[Error - 23:25:48] Request textDocument/hover failed.
  Message: Internal error, please look at the server's logs.
  Code: -32603 

network payload:

Content-Length: 216
{"jsonrpc":"2.0","id":1,"method":"textDocument/hover","params":{"textDocument":{"uri":"file:///d%3A/openHAB/openhab-2.2.0-rpi2/conf/rules/test.rules"},"position":{"line":157,"character":3}}}

Content-Length: 117
{"jsonrpc":"2.0","id":"1","error":{"code":-32603,"message":"Internal error, please look at the server\u0027s logs."}}

Content-Length: 228
{"jsonrpc":"2.0","id":2,"method":"textDocument/documentHighlight","params":{"textDocument":{"uri":"file:///d%3A/openHAB/openhab-2.2.0-rpi2/conf/rules/test.rules"},"position":{"line":157,"character":3}}}

Content-Length: 117
{"jsonrpc":"2.0","id":"2","error":{"code":-32603,"message":"Internal error, please look at the server\u0027s logs."}}

[sjsf]

Wow, that's what I'd call a detailed problem description. Thanks for that effort!

I'll have a look and try reproducing it at home with a Windows PC.

[liquidshock]

I can confirm that the problem is the same on MacOS using VSCode 1.19.1 using stable openHAB 2.2.0 with openHAB VS Code Extension 0.3.5.

[ulfwin]

I have the same issue on Linux Mint (LMDE 2 Cinnamon 64-bit) using VSCode 1.19.2 and openHAB 2.2.0

[Tech4Ever]

I am getting the same error message

[Error - 16:43:06] Request textDocument/hover failed. Message: Internal error, please look at the server's logs. Code: -32603

[neoneomaxim]

Hi I am getting the same error when i hover or highlight the text.

[Error - 12:03:56 AM] Request textDocument/hover failed. Message: Internal error, please look at the server's logs. Code: -32603 [Error - 12:03:57 AM] Request textDocument/documentHighlight failed. Message: Internal error, please look at the server's logs. Code: -32603

OPENHAB version 2.2 release

Visual code studio version 1.21.1

[DutchTaurus]

Hi,

Just my two cents.

For me the code validation was not working at all and even crashing openHAB2.3 (latest snapshot) on my Raspberry Pi 3 just after a couple of minutes with a 'heap stack out of memory' error.

I have a lot of rules in a lot of rule files and decided to remove a bunch of them temporarily. That actually helped, code validation now worked! When adding more and more rules back in I noticed the 'Request textDocument/hover failed' and other errors started popping up.

So I tried to assign a bigger chunk of memory to the JVM for openHAB and that seemed to have done the trick for me. Code validation is now running and openHAB is stable again, CV might just be too memory hungry for a limited device like the Raspberry Pi with default memory settings.

HTH.

[sjsf]

I remember having seen the same happening in good, old designer (R.I.P.) too. So it indeed might not be related to the language server but to the actual validation...

IIRC it was the holiday.script which let it go berserk pretty quickly. But I never found the time to nail it down to the root cause, but it might be a candidate for a starting point for an analysis.

[c--r]

Interesting. Unfortunately, this does not solve the problem in my case, since my rule file only consists of a few lines (<10) of code.

[dschmidt]

Any progress on this?

[c--r]

After 1 year I gave it another try and code validation now works for me. Unfortunately, I cannot really tell exactly the root cause, but I thought I'll share some thoughts, maybe it is useful for someone.

This time I used:

• openhab 2.4.0
• Raspian Stretch on a Raspberry Pi 3
• VS Studio Code Version 1.30.2
• Openhab Extension 0.4.1

This is my Workspace setting (nothing special about it really):

{
	"settings": {
		"files.eol": "\n",
		"editor.fontSize": 13,
		"openhab.lspEnabled": true,
		"openhab.host": "192.168.1.44",	
		"openhab.sitemapPreviewUI": "classicui"
	},
	"folders": [
		{
			"path": "."
		}
	]
}

What I also observed as potential source of problems is that:

• make sure that you don't set your config in the User setting and have a conflicting (wrong) config in the workspace setting. Workspace overrides User Settings. Changing configs is sometimes a bit confusing in VS Studio Code when you start from the "Settings" menu.
• when you restart Openhab, code validation stops working until you re-open the file you are editing or even restart VS Studio Code.

After VS Studio Code has connected to the LSP Server, you should see the following log line:

2019-01-20 00:15:12.461 [DEBUG] [thome.model.lsp.internal.ModelServer] - Going to wait for a client to connect
2019-01-20 00:15:12.465 [DEBUG] [thome.model.lsp.internal.ModelServer] - Client /192.168.1.1:65156 connected

[Goliath23]

Opening the config folder from a mapped network drive instead of a UNC path fixed it for me. Also read that solution in another thread I can't find again right now..