"Unable to edit document because the file was not previously opened" when using "dart.onlyAnalyzeProjectsWithOpenFiles":true (and plugins)

[DanTup]

Splitting this from #4740 since it's not the same as the original issue and I'm not yet certain that it's plugin-related at all.

To reproduce:

• Create a simple empty project that references an analyzer plugin (like custom_lint)
  I'm not sure the plugin is relevant yet, but it seems to repro pretty reliably with and I couldn't repro without
• Ensure "dart.onlyAnalyzeProjectsWithOpenFiles":true is set for the workspace and that no files are open
• Run the Developer: Reload Window command to get a clean analyzer with no open files
• Open analysis_options.yaml and press Save
• Close analysis_options.yaml
  Modifying analysis_options may or may not be relevant
• Open a .dart file
• Make some changes to the file

This open results in an error like:

Opening the file triggers rebuilding of analysis roots, but it also seems to remove the overlay:

1701185971585:Req:{"jsonrpc"::"2.0","method"::"textDocument/didOpen","params"::{"textDocument"::{"uri"::"file::///C%3A/Dev/Test%20Projects/dartcode_4740_repro/lib/dartcode_4740_repro.dart","languageId"::"dart","version"::1,"text"::"int calculate() {\n  return 6 * 7;\n}\n"}},"clientRequestTime"::1701185971583}
1701185971585:Info:Setting overlay for C::\Dev\Test Projects\dartcode_4740_repro\lib\dartcode_4740_repro.dart
1701185971587:Info:Setting roots
1701185971588:Info:Done setting roots
1701185971588:Info:Done setting roots
1701185971588:Info:Removing overlay for C::\Dev\Test Projects\dartcode_4740_repro\lib\dartcode_4740_repro.dart
1701185972690:Req:{"jsonrpc"::"2.0","method"::"textDocument/didChange","params"::{"textDocument"::{"uri"::"file::///C%3A/Dev/Test%20Projects/dartcode_4740_repro/lib/dartcode_4740_repro.dart","version"::2},"contentChanges"::[{"range"::{"start"::{"line"::3,"character"::0},"end"::{"line"::3,"character"::0}},"rangeLength"::0,"text"::"d"}]},"clientRequestTime"::1701185972204}
1701185972690:Res:{"jsonrpc"::"2.0","method"::"window/showMessage","params"::{"message"::"Unable to edit document because the file was not previously opened:: C::\\Dev\\Test Projects\\dartcode_4740_repro\\lib\\dartcode_4740_repro.dart","type"::1}}
1701185972690:Res:{"jsonrpc"::"2.0","method"::"window/logMessage","params"::{"message"::"An unrecoverable error occurred.\n\nUnable to edit document because the file was not previously opened:: C::\\Dev\\Test Projects\\dartcode_4740_repro\\lib\\dartcode_4740_repro.dart\n\n-32099\n\nnull","type"::1}}

We always verify we have an overlay before processing a textDocument/didChange event so this results in us throwing.

[DanTup]

This looks like a race condition and it may be caused by plugins.

When there are changes to plugins, we end up re-computing our capabilities and call client/unregisterCapability and client/registerCapability. It appears that this causes VS Code to tell us that the open files have been closed and then re-opened:

1701186529088:Res:{"id"::5,"jsonrpc"::"2.0","method"::"client/unregisterCapability","params"::{"unregisterations"::[{"id"::"181","method"::"textDocument/codeAction"},{"id"::"184","method"::"textDocument/definition"},{"id"::"187","method"::"textDocument/formatting"},{"id"::"188","method"::"textDocument/implementation"},{"id"::"189","method"::"textDocument/references"},{"id"::"190","method"::"textDocument/rename"},{"id"::"192","method"::"textDocument/signatureHelp"},{"id"::"193","method"::"textDocument/didOpen"},{"id"::"194","method"::"textDocument/didClose"},{"id"::"195","method"::"textDocument/didChange"}]}}
1701186529089:Res:{"id"::6,"jsonrpc"::"2.0","method"::"client/registerCapability","params"::{"registrations"::[{"id"::"221","method"::"textDocument/codeAction","registerOptions"::{"codeActionKinds"::["source","source.organizeImports","source.fixAll","source.sortMembers","quickfix","refactor"],"documentSelector"::[{"language"::"dart","scheme"::"file"}]}},{"id"::"224","method"::"textDocument/definition","registerOptions"::{"documentSelector"::[{"language"::"dart","scheme"::"file"}]}},{"id"::"227","method"::"textDocument/formatting","registerOptions"::{"documentSelector"::[{"language"::"dart","scheme"::"file"}]}},{"id"::"228","method"::"textDocument/implementation","registerOptions"::{"documentSelector"::[{"language"::"dart","scheme"::"file"}]}},{"id"::"229","method"::"textDocument/references","registerOptions"::{"documentSelector"::[{"language"::"dart","scheme"::"file"}]}},{"id"::"230","method"::"textDocument/rename","registerOptions"::{"documentSelector"::[{"language"::"dart","scheme"::"file"}],"prepareProvider"::true}},{"id"::"232","method"::"textDocument/signatureHelp","registerOptions"::{"documentSelector"::[{"language"::"dart","scheme"::"file"}],"retriggerCharacters"::[","],"triggerCharacters"::["("]}},{"id"::"233","method"::"textDocument/didOpen","registerOptions"::{"documentSelector"::[{"language"::"dart","scheme"::"file"},{"language"::"yaml","pattern"::"**/pubspec.yaml","scheme"::"file"},{"language"::"yaml","pattern"::"**/analysis_options.yaml","scheme"::"file"},{"language"::"yaml","pattern"::"**/lib/{fix_data.yaml,fix_data/**.yaml}","scheme"::"file"}]}},{"id"::"234","method"::"textDocument/didClose","registerOptions"::{"documentSelector"::[{"language"::"dart","scheme"::"file"},{"language"::"yaml","pattern"::"**/pubspec.yaml","scheme"::"file"},{"language"::"yaml","pattern"::"**/analysis_options.yaml","scheme"::"file"},{"language"::"yaml","pattern"::"**/lib/{fix_data.yaml,fix_data/**.yaml}","scheme"::"file"}]}},{"id"::"235","method"::"textDocument/didChange","registerOptions"::{"documentSelector"::[{"language"::"dart","scheme"::"file"},{"language"::"yaml","pattern"::"**/pubspec.yaml","scheme"::"file"},{"language"::"yaml","pattern"::"**/analysis_options.yaml","scheme"::"file"},{"language"::"yaml","pattern"::"**/lib/{fix_data.yaml,fix_data/**.yaml}","scheme"::"file"}],"syncKind"::2}}]}}
1701186530038:Req:{"jsonrpc"::"2.0","method"::"textDocument/didClose","params"::{"textDocument"::{"uri"::"file::///C%3A/Dev/Test%20Projects/dartcode_4740_repro/lib/dartcode_4740_repro.dart"}},"clientRequestTime"::1701186530034}
1701186530042:Req:{"jsonrpc"::"2.0","method"::"textDocument/didOpen","params"::{"textDocument"::{"uri"::"file::///C%3A/Dev/Test%20Projects/dartcode_4740_repro/lib/dartcode_4740_repro.dart","languageId"::"dart","version"::2,"text"::"int calculate() {\n  return 6 * 7;\n}\nd"}},"clientRequestTime"::1701186530038}

But it appears that we process the close/open in the wrong order, so we first update the overlay and then remove it:

CLOSE    -> 1701186530038:Req:{"jsonrpc"::"2.0","method"::"textDocument/didClose","params"::{"textDocument"::{"uri"::"file::///C%3A/Dev/Test%20Projects/dartcode_4740_repro/lib/dartcode_4740_repro.dart"}},"clientRequestTime"::1701186530034}
            1701186530039:Info:Setting roots
            1701186530039:Req:{"jsonrpc"::"2.0","method"::"$/cancelRequest","params"::{"id"::6},"clientRequestTime"::1701186530035}
            1701186530042:Req:{"jsonrpc"::"2.0","id"::6,"result"::null,"clientRequestTime"::1701186530038}
OPEN     -> 1701186530042:Req:{"jsonrpc"::"2.0","method"::"textDocument/didOpen","params"::{"textDocument"::{"uri"::"file::///C%3A/Dev/Test%20Projects/dartcode_4740_repro/lib/dartcode_4740_repro.dart","languageId"::"dart","version"::2,"text"::"int calculate() {\n  return 6 * 7;\n}\nd"}},"clientRequestTime"::1701186530038}
+OVERLAY -> 1701186530042:Info:Setting overlay for C::\Dev\Test Projects\dartcode_4740_repro\lib\dartcode_4740_repro.dart
            1701186530044:Info:Setting roots
            1701186530045:Req:{"jsonrpc"::"2.0","id"::8,"method"::"textDocument/codeAction","params"::{"textDocument"::{"uri"::"file::///C%3A/Dev/Test%20Projects/dartcode_4740_repro/lib/dartcode_4740_repro.dart"},"range"::{"start"::{"line"::3,"character"::1},"end"::{"line"::3,"character"::1}},"context"::{"diagnostics"::[],"triggerKind"::2}},"clientRequestTime"::1701186530039}
            1701186530046:Res:{"id"::8,"jsonrpc"::"2.0","error"::{"code"::-32801,"message"::"Document was modified before operation completed"}}
            1701186530046:Info:Done setting roots
-OVERLAY -> 1701186530046:Info:Removing overlay for C::\Dev\Test Projects\dartcode_4740_repro\lib\dartcode_4740_repro.dart

So it appears that there is a bug in the processing of closed files - they must be applied immediately and synchronously.

#0      OverlayResourceProvider.removeOverlay (package::analyzer/file_system/overlay_file_system.dart::68::62)
#1      LspAnalysisServer.onOverlayDestroyed (package::analysis_server/src/lsp/lsp_analysis_server.dart::603::22)
#2      TextDocumentCloseHandler.handle.<anonymous closure> (package::analysis_server/src/lsp/handlers/handler_text_document_changes.dart::76::14)
<asynchronous suspension>
#3      LspAnalysisServer._handleNotificationMessage (package::analysis_server/src/lsp/lsp_analysis_server.dart::991::20)
<asynchronous suspension>
#4      LspAnalysisServer.handleMessage.<anonymous closure>.<anonymous closure> (package::analysis_server/src/lsp/lsp_analysis_server.dart::458::15)
<asynchronous suspension>
#5      OperationPerformanceImpl.runAsync (package::analyzer/src/util/performance/operation_performance.dart::172::14)
<asynchronous suspension>
#6      LspAnalysisServer.handleMessage.<anonymous closure> (package::analysis_server/src/lsp/lsp_analysis_server.dart::439::11)
<asynchronous suspension>

[DanTup]

The issue is a bug in handling of closed files. There is an await that meant if a client closed and re-opened a file very close together, the close could be processed after the open, leaving the file in a "closed" state (which produces this error on the next change).

It isn't directly related to plugins or onlyAnalyzeProjectsWithOpenFiles, however using plugins can result in us re-registering capabilities with the client when analysis roots change (which results in VS Code's LSP client closing and re-opening all files since those events are tied to the capabilities) and using onlyAnalyzeProjectsWithOpenFiles causes additional work when files are opening/closing which makes it more likely for the bad await to cause the work to be re-ordered.

I have a fix open at https://dart-review.googlesource.com/c/sdk/+/338660 but since it'll only ship in a future SDK release my recommendation is to disable onlyAnalyzeProjectsWithOpenFiles as a workaround (I'd generally recommend not using that at all, but if you do feel you need it for some projects, set it only on those projects rather than in your global user settings).

[DanTup]

Fixed by dart-lang/sdk@4f0dc3b