diagnostics shown are those for stale file contents when typing quickly in a large file

[TysonAndre]

• Did you upgrade to latest plugin version? yes
• Did you upgrade to/compile latest binary? Run shell command bin/languageclient --version to get its version number. yes
• (Neovim users only) Did you check output of :checkhealth LanguageClient?
• Did you check troubleshooting? yes

Describe the bug

When typing quickly in a large file, the language server's diagnostics are for a stale version of the file (e.g. 1-3 keystrokes behind). Typing slower, this issue doesn't happen.

One issue seems to be that publishDiagnostics doesn't seem to be locked properly. The language server receives two didChange events in short succession, and then this language client processes the didChange event concurrently (should there be locking added to LanguageClient-neovim for modifying diagnostics?)

• So I'm seeing the older publishDiagnostics call (with errors) rendered in the diagnostics+gutter, despite a newer publishDiagnostics call (with no errors) being emitted shortly afterwards. The language server emits output in the correct order.

Also concerning is that didChange start and end overlaps. I don't know if this is causing bugs in other use cases

11:58:46 INFO unnamed src/language_server_protocol.rs:1893 End textDocument/didChange
11:58:46 INFO unnamed src/language_server_protocol.rs:2311 End languageClient/handleTextChanged
11:58:46 INFO unnamed src/language_server_protocol.rs:1893 End textDocument/didChange
11:58:46 INFO unnamed src/language_server_protocol.rs:2311 End languageClient/handleTextChanged

...omitted
Message: {"jsonrpc":"2.0","method":"textDocument/publishDiagnostics","params":{"diagnostics":[{"code":null,"message":"PhanUndeclaredTypeReturnType Return type of parseCodeAsPHPAST() is undeclared type \\ast\\no","range":{"end":{"character":0,"line":189},"start":{"character":0,"line":188}},"severity":2,"source":"Phan"},{"code":null,"message":"PhanTypeMismatchReturn Returning type \\ast\\Node but parseCodeAsPHPAST() is declared to return \\ast\\no","range":{"end":{"character":0,"line":196},"start":{"character":0,"line":195}},"severity":2,"source":"Phan"}],"uri":"file:///path/to/phan/src/Phan/AST/TolerantASTConverter/TolerantASTConverter.php"}}

Error: ErrorMessage { msg: "Error: Failure { jsonrpc: Some(V2), error: Error { code: InternalError, message: \"\\\'Vim(let):E28: No such highlight group name: ALEWarning\\\'\", data: None }, id: Num(60) }" }
11:58:46 INFO reader-Some("php") src/rpcclient.rs:83 <= Some("php") {"method":"textDocument\/publishDiagnostics","params":{"uri":"file:\/\/\/path\/to\/phan\/src\/Phan\/AST\/TolerantASTConverter\/TolerantASTConverter.php","diagnostics":[{"range":{"start":{"line":188,"character":0},"end":{"line":189,"character":0}},"severity":2,"code":null,"source":"Phan","message":"PhanUndeclaredTypeReturnType Return type of parseCodeAsPHPAST() is undeclared type \\ast\\no"},{"range":{"start":{"line":195,"character":0},"end":{"line":196,"character":0}},"severity":2,"code":null,"source":"Phan","message":"PhanTypeMismatchReturn Returning type \\ast\\Node but parseCodeAsPHPAST() is declared to return \\ast\\no"}]},"jsonrpc":"2.0"}
11:58:46 INFO reader-Some("php") src/rpcclient.rs:83 <= Some("php") {"method":"textDocument\/publishDiagnostics","params":{"uri":"file:\/\/\/path\/to\/phan\/src\/Phan\/AST\/TolerantASTConverter\/TolerantASTConverter.php","diagnostics":[]},"jsonrpc":"2.0"}
11:58:46 INFO unnamed src/language_server_protocol.rs:1936 Begin textDocument/publishDiagnostics
11:58:46 INFO unnamed src/language_server_protocol.rs:1936 Begin textDocument/publishDiagnostics
11:58:46 DEBUG unnamed src/language_client.rs:41 state.diagnostics./path/to/phan/src/Phan/AST/TolerantASTConverter/TolerantASTConverter.php: [{"message":"PhanUndeclaredTypeReturnType Return type of parseCodeAsPHPAST() is undeclared type \\ast\\no","range":{"end":{"character":0,"line":189},"start":{"character":0,"line":188}},"severity":2,"source":"Phan"},{"message":"PhanTypeMismatchReturn Returning type \\ast\\Node but parseCodeAsPHPAST() is declared to return \\ast\\no","range":{"end":{"character":0,"line":196},"start":{"character":0,"line":195}},"severity":2,"source":"Phan"}] ==> []
11:58:46 INFO unnamed src/vim.rs:101 Begin setqflist
11:58:46 INFO unnamed src/rpcclient.rs:137 => None {"jsonrpc":"2.0","method":"setqflist","params":[[],"r"]}
11:58:46 INFO unnamed src/rpcclient.rs:137 => None {"jsonrpc":"2.0","method":"setqflist","params":[[],"a",{"title":"[LC]: diagnostics"}]}
11:58:46 DEBUG unnamed src/language_client.rs:41 state.diagnostics./path/to/phan/src/Phan/AST/TolerantASTConverter/TolerantASTConverter.php: [] ==> [{"message":"PhanUndeclaredTypeReturnType Return type of parseCodeAsPHPAST() is undeclared type \\ast\\no","range":{"end":{"character":0,"line":189},"start":{"character":0,"line":188}},"severity":2,"source":"Phan"},{"message":"PhanTypeMismatchReturn Returning type \\ast\\Node but parseCodeAsPHPAST() is declared to return \\ast\\no","range":{"end":{"character":0,"line":196},"start":{"character":0,"line":195}},"severity":2,"source":"Phan"}]
11:58:46 INFO unnamed src/vim.rs:101 Begin setqflist
11:58:46 INFO unnamed src/rpcclient.rs:137 => None {"jsonrpc":"2.0","method":"eval","params":["LSP#filename()"],"id":61}
11:58:46 INFO unnamed src/rpcclient.rs:137 => None {"jsonrpc":"2.0","method":"setqflist","params":[[{"col":1,"filename":"/path/to/phan/src/Phan/AST/TolerantASTConverter/TolerantASTConverter.php","lnum":189,"nr":null,"text":"PhanUndeclaredTypeReturnType Return type of parseCodeAsPHPAST() is undeclared type \\ast\\no","type":"W"},{"col":1,"filename":"/path/to/phan/src/Phan/AST/TolerantASTConverter/TolerantASTConverter.php","lnum":196,"nr":null,"text":"PhanTypeMismatchReturn Returning type \\ast\\Node but parseCodeAsPHPAST() is declared to return \\ast\\no","type":"W"}],"r"]}
11:58:46 INFO unnamed src/rpcclient.rs:137 => None {"jsonrpc":"2.0","method":"setqflist","params":[[],"a",{"title":"[LC]: diagnostics"}]}
11:58:46 INFO unnamed src/rpcclient.rs:137 => None {"jsonrpc":"2.0","method":"eval","params":["LSP#filename()"],"id":62}
11:58:46 INFO reader-None src/rpcclient.rs:83 <= None {"id":61,"jsonrpc":"2.0","result":"/path/to/phan/src/Phan/AST/TolerantASTConverter/TolerantASTConverter.php"}

Environment

• neovim/vim version (nvim --version or vim --version): (Various versions of vim, including 8.1 1-932 and 8.1.0677, so I don't think it's that)
• This plugin version (git rev-parse --short HEAD): (various versions, including 3ae32eb76b3ecc16f7d6d3169559b3be6591b4e9)
• This plugin's binary version (bin/languageclient --version): (0.1.140 - I also have this issue with 0.1.138, so I don't think it's new)
• Minimal vimrc content (A minimal vimrc is the smallest vimrc that could reproduce the issue. Refer to an example here): (TODO)
• Language server link and version: https://github.com/TysonAndre/LanguageServer-phan-neovim (latest master branch)

To Reproduce

see description

Current behavior

Seeing diagnostics for a slightly out of date version of the document (Seeing an error for @return ast\No when the most recent document contents are @return ast\Node

Expected behavior

It should prefer the publishDiagnostics that is more recently emitted by the server, i.e. the one with no errors. (i.e. {"uri":"file:\/\/\/path\/to\/phan\/src\/Phan\/AST\/TolerantASTConverter\/TolerantASTConverter.php","diagnostics":[]},"jsonrpc":"2.0"})

That might be possible if you add the time in nanoseconds when the client unserialized the message from the JSON bytes, or by adding locking to ensure that earlier requests finish before later requests?

Screenshots

Additional context

Add any other context about the problem here.

[TysonAndre]

It looks like this isn't going to affect a large number of users, just developers of language servers. EDIT: never mind, it happens even with debug statements turned off

This only happens when I'm using let g:LanguageClient_serverStderr=1

[teto]

I haven't investigated but I regularly see these symptoms.

[TysonAndre]

I'm having some luck with https://github.com/TysonAndre/LanguageClient-neovim/commit/76c49a80f67fc6fc6b6189a91edda0b89b87b9a0 - I still see the issue in debug builds with verbose logging in the client but not in release(optimized) builds.

• I'm completely new to rust and I'm still reading the getting started guide, so there's probably many ways that could be improved

It's not getting Instant::now() early enough, but I think the approach would work (not 100% sure if the extra lock could cause deadlock, but I don't think it would). I should instead be adding the instant when the notification is unserialized. (rpcclient would unserialize A then B, but would sometimes call processDiagnostics in the order B then A because it's asynchronous)

Manually adding a 10ms sleep after processing each notification from the language server is a crude way to work around that race condition - better ways exist but I'm not familiar at all with rust.

[TysonAndre]

I'm still using that branch with a release build - I encountered problems when trying to rebase that commit against the latest version of the next branch. https://github.com/TysonAndre/LanguageClient-neovim/tree/race-condition-workaround and couldn't solve them

[martskins]

@TysonAndre I believe this should have been solved by #1126

[TysonAndre]

I believe this should have been solved by 1126

The issue I'm describing is referring to the diagnostics (error messages) shown in the copen gutter at the bottom, not the signs shown to the top left, if I understood the PR summary

[martskins]

Ah yeah sorry I misread the issue. I'll see if I can replicate and try and find a way to solve it 👍