Editing a document opened via "Go To Definition" results in `didChange` before `didOpen`, and mysterious `didClose`

[scztt]

Does this issue occur when all extensions are disabled?: Yes

• VS Code Version: 1.75.1
• OS Version: MacOS 12.4

Steps to Reproduce:

1. (Using the SuperCollider language server https://github.com/scztt/LanguageServer.quark)
2. Open a file
3. Option+Click a symbol / "Go To Definition" to open the file containing the definition of that symbol
4. Modify the opened document

Result:
The language server receives an didChange event for the edit before it has received a didOpen (an explicit requirement of the LSP protocol). In some cases, I observe a mysterious didClose for the document at the place I would expect a didOpen (e.g. when it is opened in vscode). An example sequence of requests from vscode to the language server showing the problem:

LSP communication for "Go To Definition":

>>> {"jsonrpc":"2.0","id":6,"method":"textDocument/definition","params":{"textDocument":{"uri":"file:///Users/chrysanth/Desktop/F%20O%20R%20E%20S%20T%20R%20Y/FELT/FELT-control.scd"},"position":{"line":10,"character":28}}}
<<< {"id": "6","result": [{"range": {"end": {"character": 0,"line": 39},"start": {"character": 0,"line": 39}},"uri": "file:///Users/Shared/_code/SuperCollider/cmake-build-RelWithDebInfo/Install/SuperCollider/SuperCollider.app/Contents/Resources/SCClassLibrary/Common/Control/Spec.sc"}]}

// document was not opened, but already a foldingRange/codeLens request? This already seems suspicious - but maybe this is allowed?
>>> {"jsonrpc":"2.0","id":7,"method":"textDocument/foldingRange","params":{"textDocument":{"uri":"file:///Users/Shared/_code/SuperCollider/cmake-build-RelWithDebInfo/Install/SuperCollider/SuperCollider.app/Contents/Resources/SCClassLibrary/Common/Control/Spec.sc"}}}

>>> {"jsonrpc":"2.0","id":8,"method":"textDocument/codeLens","params":{"textDocument":{"uri":"file:///Users/Shared/_code/SuperCollider/cmake-build-RelWithDebInfo/Install/SuperCollider/SuperCollider.app/Contents/Resources/SCClassLibrary/Common/Control/Spec.sc"}}}

// perform edit on Spec.sc...

>>> {"jsonrpc":"2.0","method":"textDocument/didChange","params":{"textDocument":{"uri":"file:///Users/Shared/_code/SuperCollider/cmake-build-RelWithDebInfo/Install/SuperCollider/SuperCollider.app/Contents/Resources/SCClassLibrary/Common/Control/Spec.sc","version":2},"contentChanges":[{"range":{"start":{"line":38,"character":0},"end":{"line":38,"character":0}},"rangeLength":0,"text":"\n"}]}}

LSP communication for Option+click:

>>> {"jsonrpc":"2.0","id":5,"method":"textDocument/definition","params":{"textDocument":{"uri":"file:///Users/chrysanth/Desktop/F%20O%20R%20E%20S%20T%20R%20Y/FELT/FELT-control.scd"},"position":{"line":10,"character":26}}}
<<< {"id": "5","result": [{"range": {"end": {"character": 0,"line": 39},"start": {"character": 0,"line": 39}},"uri": "file:///Users/Shared/_code/SuperCollider/cmake-build-RelWithDebInfo/Install/SuperCollider/SuperCollider.app/Contents/Resources/SCClassLibrary/Common/Control/Spec.sc"}]}

// This is strange, because we have no didOpen and no previous reference to this file since the server was started.
>>> {"jsonrpc":"2.0","method":"textDocument/didClose","params":{"textDocument":{"uri":"file:///Users/Shared/_code/SuperCollider/cmake-build-RelWithDebInfo/Install/SuperCollider/SuperCollider.app/Contents/Resources/SCClassLibrary/Common/Control/Spec.sc"}}}

>>> {"jsonrpc":"2.0","id":6,"method":"textDocument/definition","params":{"textDocument":{"uri":"file:///Users/chrysanth/Desktop/F%20O%20R%20E%20S%20T%20R%20Y/FELT/FELT-control.scd"},"position":{"line":10,"character":26}}}
<<< {"id": "6","result": [{"range": {"end": {"character": 0,"line": 39},"start": {"character": 0,"line": 39}},"uri": "file:///Users/Shared/_code/SuperCollider/cmake-build-RelWithDebInfo/Install/SuperCollider/SuperCollider.app/Contents/Resources/SCClassLibrary/Common/Control/Spec.sc"}]}

>>> {"jsonrpc":"2.0","id":7,"method":"textDocument/foldingRange","params":{"textDocument":{"uri":"file:///Users/Shared/_code/SuperCollider/cmake-build-RelWithDebInfo/Install/SuperCollider/SuperCollider.app/Contents/Resources/SCClassLibrary/Common/Control/Spec.sc"}}}
>>> {"jsonrpc":"2.0","id":8,"method":"textDocument/codeLens","params":{"textDocument":{"uri":"file:///Users/Shared/_code/SuperCollider/cmake-build-RelWithDebInfo/Install/SuperCollider/SuperCollider.app/Contents/Resources/SCClassLibrary/Common/Control/Spec.sc"}}}

// perform edit on Spec.sc...

>>> {"jsonrpc":"2.0","method":"textDocument/didChange","params":{"textDocument":{"uri":"file:///Users/Shared/_code/SuperCollider/cmake-build-RelWithDebInfo/Install/SuperCollider/SuperCollider.app/Contents/Resources/SCClassLibrary/Common/Control/Spec.sc","version":2},"contentChanges":[{"range":{"start":{"line":38,"character":0},"end":{"line":38,"character":0}},"rangeLength":0,"text":"\n"}]}}

Expected:
At minimum, the LSP spec specifies a textDocument/didOpen before a textDocument/didChange. I'm not clear on whether the spec requires a didOpen before other textDocument requests, but this would also make sense to me.

Notes:

• didOpen messages work normally for other kinds of file open operations, e.g. clicking in the Explorer tree.
• didClose messages are issues for documents opened via "Go To Definition" when they are closed in VSCode.
• In most repro cases, we are opening a file that is NOT in the current workspace (e.g. in the currently opened folder) (this is an artifact of the programming language, where compiled libraries for which symbols are indexed are generally apart from user code). For cases where the file containing the definition IS in the current workspace, I observe SOME cases where there is a correct didOpen and some cases where there is still a missing didOpen. I don't see any obvious differences between cases that work correctly vs don't.

[vscodenpa]

Thanks for creating this issue! It looks like you may be using an old version of VS Code, the latest stable release is 1.75.1. Please try upgrading to the latest version and checking whether this issue remains.

Happy Coding!

[scztt]

Thanks for creating this issue! It looks like you may be using an old version of VS Code, the latest stable release is 1.75.1. Please try upgrading to the latest version and checking whether this issue remains.

Tested with 1.75.1, the problem still occurs.

[jrieken]

didOpen messages work normally for other kinds of file open operations, e.g. clicking in the Explorer tree.

That's a misunderstanding - the open/close events will fire any time a document is created/loaded. It does usually correspond to open an editor but must not

[jrieken]

Leaving the apparent out of order event to @dbaeumer

[scztt]

That's a misunderstanding - the open/close events will fire any time a document is created/loaded. It does usually correspond to open an editor but must not

Got it. I only mentioned this to note that - didOpen/didClose events are working correctly in all other workflows that I have observed, it's only this one particular workflow where things are incorrect.

[dbaeumer]

This was a known issue in the LSP libraries when using full document sync (instead of the preferred increment sync). It got fixed in the 8.1.0 version of the libs that shipped last week. Could you please ensure that you use the latest version.

If you still see the issue with latest could you please provide me with a GitHub repository I can clone that demos what you are seeing.

[scztt]

This was a known issue in the LSP libraries when using full document sync (instead of the preferred increment sync). It got fixed in the 8.1.0 version of the libs that shipped last week. Could you please ensure that you use the latest version.

I'm familiar with this bug - my server is using incremental sync now, so I didn't think it would apply. However, I'll try the 8.1.0 library to see if the behavior changes and report back.

[dbaeumer]

I tried to reproduce this with the latest 8.1.0 version using my ESLint server and I was not able to do so. Here is the trace I get:

[Trace - 11:38:12 AM] Sending notification 'textDocument/didOpen'.
[Trace - 11:38:12 AM] Sending notification 'textDocument/didClose'.
[Trace - 11:38:12 AM] Received request 'workspace/configuration - (4)'.
[Trace - 11:38:12 AM] Sending response 'workspace/configuration - (4)'. Processing request took 3ms
[Trace - 11:38:17 AM] Sending notification 'textDocument/didOpen'.
[Trace - 11:38:17 AM] Received request 'workspace/configuration - (5)'.
[Trace - 11:38:17 AM] Sending response 'workspace/configuration - (5)'. Processing request took 4ms
[Trace - 11:38:17 AM] Received request 'client/registerCapability - (6)'.
[Trace - 11:38:17 AM] Sending response 'client/registerCapability - (6)'. Processing request took 1ms
[Trace - 11:38:17 AM] Received notification 'textDocument/publishDiagnostics'.
[Trace - 11:38:17 AM] Received notification 'eslint/status'.
[Trace - 11:38:27 AM] Sending notification 'textDocument/didChange'.
[Trace - 11:38:27 AM] Received notification 'textDocument/publishDiagnostics'.
[Trace - 11:38:27 AM] Received notification 'eslint/status'.

[scztt]

I attempted to reproduce this bug with 8.1.0. I still saw the issue, but I dug deeper and discovered a cause of the problem in my own code. Once I resolved this on my size, everything looks fine regarding message order. Closing this bug.

[scztt]

If it's helpful for anyone finding this in the future:

The bug on my side was triggered by overrunning an internal buffer when transmitting a very large JSON-RPC message, causing that message to be dropped. The only messages that are commonly large enough to trigger this case are didOpen messages on very large documents, since the entirety of the document is included in the text field of that request.

This explains the intermittent nature of the bug (prior to this, I simply didn't have any documents large enough to trigger the problem), and the fact that it only affected didOpen message and no others (since there are very few other requests that could contain the entire text of a document).