org.eclipse.lsp4j.jsonrpc.RemoteEndpoint handleCancellation

[D0zee]

Hello everyone! I write a language server for kotlin build scripts. I've started get warnings from lsp4j as I understand on client side.

The example of a such warning is below: 2023 7:17:07 PM org.eclipse.lsp4j.jsonrpc.RemoteEndpoint handleCancellation WARNING: Unmatched cancel notification for request id 7

What does this warning mean? And how to fix it? My lsp4j version on server side is 0.15.0, on client side as I suspect is latest, because I use lsp4j as a dependency in eclipse plugin. I've already tried to increase the version of lsp4j on server side, but nothing helps.

[jonahgraham]

What does this warning mean?

I think it means that the client is sending a cancel to the server for a message that it never to the server in the first place, or perhaps client sent a cancel after the server already replied. If it is the former, that sounds like a client bug, if it is the latter that is probably a race condition.

And how to fix it?

I don't think updating the server to latest will make much of difference as I don't think LSP4J has made changes recently, have a look at the changelog.

If the client is LSP4E perhaps some of the relatively new cancellation support isn't lining up with the server expectation.

Can you share a more complete log of the messages?

[D0zee]

These two lines are full log message. This warning appears when on any edits of file. I thought that maybe error from my end, but I went to older commits and the warning appears there also, althought I didn't see this warning in my log before.

[jonahgraham]

These two lines are full log message

Sorry, too many meanings for log around :) I meant the full log of the communication between client and server, the json-rpc contents.

[D0zee]

https://pastebin.com/TvWKji3C It's full log of communication between server and client. But there are strange logs - it's just for debugging. The test project is a simple application from gradle init. After full initialization (I noted the end of it), I typed one character at a time and looked at the logs

[jonahgraham]

Sorry that is still the workspace log, I am talking about the log showing all the JSON-RPC objects back and forth. You can turn that on in LSP4E in this preference pace:

and then in the Console (or file you logged to) you will see all the JSON-RPC back and forth:

In that log you can track down what is happening by finding the messages with the matching IDs, e.g. {"jsonrpc":"2.0","id":"7"

[jonahgraham]

PS LSP4E is being improved all the time and there is some initiatives to provide better logging UIs. See for example https://github.com/eclipse/lsp4e/issues/745

[D0zee]

Hello, I return with logs. These logs are printed on one change in text file. I still don't understand why client send requests to cancel.

[t=1692356789408] LSP4E to org.eclipse.buildship.kotlinDSL.provider.server:
Content-Length: 346

[t=1692356789410] LSP4E to org.eclipse.buildship.kotlinDSL.provider.server:
{"jsonrpc":"2.0","method":"textDocument/didChange","params":{"textDocument":{"version":13,"uri":"file:///Users/kolavladimirov/Downloads/sample_composite_builds_basics-kotlin-dsl-2/my-utils/string-utils/build.gradle.kts"},"contentChanges":[{"range":{"start":{"line":16,"character":1},"end":{"line":16,"character":1}},"rangeLength":0,"text":"f"}]}}

[t=1692356789675] org.eclipse.buildship.kotlinDSL.provider.server to LSP4E:
{"jsonrpc":"2.0","method":"window/logMessage","params":{"type":3,"message":"debounce0 Linting .../string-utils/build.gradle.kts"}}

[t=1692356789685] org.eclipse.buildship.kotlinDSL.provider.server to LSP4E:
{"jsonrpc":"2.0","method":"window/logMessage","params":{"type":2,"message":"compiling [KtFile: /Users/kolavladimirov/Downloads/sample_composite_builds_basics-kotlin-dsl-2/my-utils/string-utils/build.gradle.kts] with BUILD_SCRIPT"}}

[t=1692356789902] LSP4E to org.eclipse.buildship.kotlinDSL.provider.server:
Content-Length: 65

[t=1692356789902] LSP4E to org.eclipse.buildship.kotlinDSL.provider.server:
{"jsonrpc":"2.0","method":"$/cancelRequest","params":{"id":"29"}}

[t=1692356789902] LSP4E to org.eclipse.buildship.kotlinDSL.provider.server:
Content-Length: 224

[t=1692356789902] LSP4E to org.eclipse.buildship.kotlinDSL.provider.server:
{"jsonrpc":"2.0","id":"31","method":"textDocument/documentSymbol","params":{"textDocument":{"uri":"file:///Users/kolavladimirov/Downloads/sample_composite_builds_basics-kotlin-dsl-2/my-utils/string-utils/build.gradle.kts"}}}

[t=1692356789908] org.eclipse.buildship.kotlinDSL.provider.server to LSP4E:
{"jsonrpc":"2.0","method":"window/logMessage","params":{"type":2,"message":"client    Unmatched cancel notification for request id 29"}}

[t=1692356789909] org.eclipse.buildship.kotlinDSL.provider.server to LSP4E:
{"jsonrpc":"2.0","method":"window/logMessage","params":{"type":3,"message":"async2    Find symbols in .../string-utils/build.gradle.kts"}}

[t=1692356789910] org.eclipse.buildship.kotlinDSL.provider.server to LSP4E:
{"jsonrpc":"2.0","method":"window/logMessage","params":{"type":3,"message":"async2    Finished in 1 ms"}}

[t=1692356789911] org.eclipse.buildship.kotlinDSL.provider.server to LSP4E:
{"jsonrpc":"2.0","id":"31","result":[]}

[t=1692356789977] LSP4E to org.eclipse.buildship.kotlinDSL.provider.server:
Content-Length: 264

[t=1692356789977] LSP4E to org.eclipse.buildship.kotlinDSL.provider.server:
{"jsonrpc":"2.0","id":"32","method":"textDocument/documentHighlight","params":{"textDocument":{"uri":"file:///Users/kolavladimirov/Downloads/sample_composite_builds_basics-kotlin-dsl-2/my-utils/string-utils/build.gradle.kts"},"position":{"line":16,"character":2}}}

[t=1692356789982] org.eclipse.buildship.kotlinDSL.provider.server to LSP4E:
{"jsonrpc":"2.0","method":"window/logMessage","params":{"type":3,"message":"async2    Re-parsing build.gradle.kts 0:1-19:1"}}

[t=1692356790060] org.eclipse.buildship.kotlinDSL.provider.server to LSP4E:
{"jsonrpc":"2.0","method":"textDocument/publishDiagnostics","params":{"uri":"file:///Users/kolavladimirov/Downloads/sample_composite_builds_basics-kotlin-dsl-2/my-utils/string-utils/build.gradle.kts","diagnostics":[]}}

[t=1692356790077] org.eclipse.buildship.kotlinDSL.provider.server to LSP4E:
{"jsonrpc":"2.0","method":"textDocument/publishDiagnostics","params":{"uri":"file:///Users/kolavladimirov/Downloads/sample_composite_builds_basics-kotlin-dsl-2/my-utils/string-utils/build.gradle.kts","diagnostics":[{"range":{"start":{"line":16,"character":0},"end":{"line":16,"character":2}},"severity":1,"code":"UNRESOLVED_REFERENCE","source":"kotlin","message":"Unresolved reference: ff","tags":[]}]}}

[t=1692356790082] org.eclipse.buildship.kotlinDSL.provider.server to LSP4E:
{"jsonrpc":"2.0","method":"window/logMessage","params":{"type":3,"message":"debounce0 Reported 1 diagnostics in .../string-utils/build.gradle.kts"}}

[t=1692356790083] org.eclipse.buildship.kotlinDSL.provider.server to LSP4E:
{"jsonrpc":"2.0","method":"window/logMessage","params":{"type":3,"message":"async2    Hovering BLOCK"}}

[t=1692356790083] org.eclipse.buildship.kotlinDSL.provider.server to LSP4E:
{"jsonrpc":"2.0","id":"32","result":[]}

[jonahgraham]

Higher up the log is there a request with ID 29 (the ID that the cancel was for)? Is there a response from that request?

[D0zee]

I think that this request doesn't get a response, because It doesn't influence on something, just appears

[D0zee]

You are right, it was method that worked wrongly. I turned off it and warnings disappeared.

[jonahgraham]

I am glad to know you have managed to figure it out. Thanks for reporting back and closing the issue.