FileSystemWatcher fires events to extensions before text documents are updated

[Colengms]

Version: 1.33.1 (user setup)
Commit: 51b0b28
Date: 2019-04-11T08:27:14.102Z
Electron: 3.1.6
Chrome: 66.0.3359.181
Node.js: 10.2.0
V8: 6.6.346.32
OS: Windows_NT x64 10.0.17763

I can repro this debugging the C/C++ extension ( https://github.com/Microsoft/vscode-cpptools ).

In the handling of an onDidChange event from a FileSystemWatcher, we are loading the contents of that file (using vscode.workspace.openTextDocument), but the contents that are returned are outdated (prior to the change).

This repro's for me regardless of whether the file is currently open for edit. If open, I see updated content in the UI. Even if I wait to step over openTextDocument until after the change is apparent in the UI, I still get the old contents.

[jrieken]

Please add a small sample extension and steps that allow us to reproduce this.

[Colengms]

It's pretty clearly loading the contents from a cache in openTextDocument, in extHostDocuments.ensureDocumentData.

	const cached = this._documentsAndEditors.getDocument(uri);
	if (cached) {
		return Promise.resolve(cached);
	}

Perhaps clear it from the cache before triggering the file watcher event?

[Colengms]

I created an extension using the following how-to: https://code.visualstudio.com/api/get-started/your-first-extension

I added the following code to the activate function:

const uri = vscode.window.activeTextEditor!.document.uri;
fileWatcher = vscode.workspace.createFileSystemWatcher(new vscode.RelativePattern(
	vscode.workspace.getWorkspaceFolder(uri)!,
	'**/*'
), false, false, false);
fileWatcher.onDidChange(() => {
	vscode.workspace.openTextDocument(vscode.window.activeTextEditor!.document.uri).then((document: vscode.TextDocument) => {
		let curText: string = document.getText();
		vscode.window.showInformationMessage(curText);
	});
});

Run this extension, and opening a test text file. Run the Hello World command to activate the extension. Then edit the file. You will see it correctly displays an information message with the new contents.

Now, try editing the file outside of vscode. You will see it displays the prior contents of the file, not the new contents of the file. Expected: it should have read the new/current contents of the file, not used what was in the cache.

[Colengms]

We are also seeing issues with files that have been deleted then successfully opening (from cache) using openTextDocument, than failing to save (vscode.TextDocument.save) due to a (incorrect?) error message about needing to replace the file...

[sean-mcmanus]

The bug I'm seeing can be reproed with our shipped 0.23.0-insiders via:

1. Edit Configurations (JSON).
2. Close c_cpp_properties.json.
3. Edit Configurations (JSON).
4. Delete c_cpp_properties.json.
5. Edit Configurations (JSON).
   Result:
   @bobbrown @michelleangela This is blocking our release. The effect is made more severe by another issue in the config UI that is causing this code path to be hit in an never ending loop as it repeatedly tries to create a new c_cpp_properties.json and fails.
   

[bpasero]

Reproduces since the beginning we have this API, as such marking as feature request and not bug. The flow is as follows:

• file gets updated
• we correctly get a file change event on the renderer
• we start to update the model by reading from disk
• the MainThreadFileSystemEventService starts to fire events to the extension host
• the extension host is faster dispatching the event than the model loading from disk

Maybe a better solution would be to introduce a new event on text documents when they change on disk as opposed to artificially halting file system events (which are pretty low level) until all models are synced.

Changing the flow by halting events might also have consequences for existing extensions that rely on the current behaviour.

[jrieken]

Yeah, we should definitely not pause events. If the document changes then we should emit a document change event, e.g. onDidChangeTextDocument and then I'd argue that this isn't an issue at all, e.g once a document is opened you should listen its context change events and not (just) to file change events

[Colengms]

We can work around the scenario in which the file is changed externally, by ignoring the watcher's onDidChange if the file can be found in textDocuments, and handling it via onDidChangeTextDocument instead.

Is there a workaround for the scenario in which the file is deleted? There is no onDidDeleteTextDocument. We are using openTextDocument to create the file, which results in the scenario Sean described above.

I've tried creating the file using fs.writeFile() before calling openTextDocument. However, the call to openTextDocument then throws due to 'file already exists on disk'. Perhaps we can defer that work until we've also received an onDidCreate for the file (assuming there is not a similar race condition with onDidCreate as well). That's gets a bit messy.

[jrieken]

Is there a workaround for the scenario in which the file is deleted? There is no onDidDeleteTextDocument.

And that's unlikely to happen, there is onDidOpen and onDidClose and that should be used. For instance, when a file is deleted on disk but still open in an editor we don't close the document but keep it open - with a UX hint that the underlying file on disk has been deleted

I've tried creating the file using fs.writeFile() before calling openTextDocument. However, the call to openTextDocument then throws due to 'file already exists on disk'.

That doesn't make sense unless you call openTextDocument so that it creates the document, e.g untitled scheme. Otherwise, if you use the URI that represents the file on disk than no creation will happen. Also not sure why you need onDidCreate as fs.writeFile invokes a callback once the file is on disk

[Colengms]

Opening the file in the editor is not necessary to repro the 'replace file dialog' problem. We can repro only opening the file programmatically. The issue occurs when saving a previously deleted document. Repro steps:

• the document is present in textDocuments (whether opened in UI, or by a call to openTextDocument)
• delete that document from disk
• open the file using openTextDocument, which returns the cached version
• call save on the TextDocument

This leads to a replace file dialog. However, since the file is not present on disk, perhaps the user should not be prompted with a 'replace' file dialog?

[Colengms]

That doesn't make sense unless you call openTextDocument so that it creates the document, e.g untitled scheme. Otherwise, if you use the URI that represents the file on disk than no creation will happen. Also not sure why you need onDidCreate as fs.writeFile invokes a callback once the file is on disk

By 'doesn't make sense' are you confirming that this is a bug, or asking for clarification of the repro?

Creating the file before trying to open it is an attempt to workaround the issue (or one of the issues) we are reporting here, in which vscode does not create the file when we call openTextDocument (rather, it returns a cached copy of the deleted file). I assume that if I create a file using fs.writeFile, a call to openTextDocument should succeed (as the file does indeed exist), and not fail in the way it currently is; with a "file already exists on disk" error, as it should not be trying to create it... Based on the successfully workaround above (waiting for onDidDeleteTextDocument), I was suggesting that perhaps I need to wait for vscode to process certain file system events before my newly created file is properly handled by openTextDocument. .. We still need a workaround here, so we can create this file on disk, and put contents in it, without triggering a Replace dialog.

Is there a way to tell vscode to stop caching a textDocument, so that our next attempt to open it will create it instead of returning what's still in cache?

[Colengms]

I can work around the behavior we're reporting associated with deleting a file and trying to use openTextDocument/save, by avoiding use of openTextDocument and creating/writing the file using only fs.writeFile. I assume that as long as we don't try to open this file using openTextDocument until after vscode has had the opportunity to process the related file system events, things will work fine.

[jrieken]

By 'doesn't make sense' are you confirming that this is a bug, or asking for clarification of the repro?

YEah, that would be a bug. I hacked something up following the steps you mention but couldn't reproduce. Do you mind gives us a sample extension that shows this?

[Colengms]

We use some async, and bpasero mentioned (above) that timing may be a factor. So, I'm having difficulty repro'ing in an isolated example. However, I seem to have an isolated repro for an issue with the Replace dialog that may be related.

Replace extension.ts from a Hello World project created using: https://code.visualstudio.com/api/get-started/your-first-extension
with:

let fileWatcher: vscode.FileSystemWatcher;

async function ensureFile(uri: vscode.Uri): Promise<void> {
	let fileUri: vscode.Uri = vscode.Uri.file(uri.fsPath).with({ scheme: "untitled" });
	let document: vscode.TextDocument = await vscode.workspace.openTextDocument(fileUri);
	let curText: string = document.getText();
	if (curText.length > 0) {
		vscode.window.showInformationMessage("Deleted document opened with old content!");
	}

	let edit: vscode.WorkspaceEdit = new vscode.WorkspaceEdit();
	edit.insert(document.uri, new vscode.Position(0, 0), "new content");
	await vscode.workspace.applyEdit(edit);
	await document.save();
}

export function activate(context: vscode.ExtensionContext) {

	const uri = vscode.window.activeTextEditor!.document.uri;
	fileWatcher = vscode.workspace.createFileSystemWatcher(new vscode.RelativePattern(
		vscode.workspace.getWorkspaceFolder(uri)!,
		'**/*'
	), false, false, false);
	fileWatcher.onDidDelete((uri) => {
		ensureFile(uri);
	});

	let disposable = vscode.commands.registerCommand('extension.helloWorld', () => {
		vscode.workspace.openTextDocument(vscode.window.activeTextEditor!.document.uri).then((document: vscode.TextDocument) => {
			vscode.window.showInformationMessage(document.getText());
		});

	});

	context.subscriptions.push(disposable);
}

export function deactivate() {}

• Create 2 files in the same directory.
• Open file A
• Run the Hello World command to initialize the extension
• Delete file B
• At this point, you should see the correct behavior. The file is replaced with a new file of the same name.
• Delete file B again
• This time, the Replace dialog is displayed. Click "Replace"
• The file is not actually written to disk.
• Expected: The replace dialog should not have been displayed, as there was no file to replace
• Expected: If clicking "Replace" the file should have been written.

If you do the equivalent with file B open in the editor, you will see the Replace dialog displayed on the first attempt, and clicking "Replace" will updated the opened copy of the file, but it will not write the file to disk.

[GitMensch]

Friendly ping after 18 months: is there any update for that? @Colengms does the cpp-extension now completely work around that (possibly by using only low-leve fs routines)?

[sean-mcmanus]

@GitMensch Colen is OOF till January. Looks like the workaround was implemented in https://github.com/microsoft/vscode-cpptools/pull/3545/files .