Update paths on move misses update when moving file back and forth

[mjbvz]

microsoft/vscode#50811

TypeScript Version: 2.9.1

Search Terms:

• Update paths on move
• getEditsForFileRename

Code

1. For a project

jsconfig.json

{
    "compilerOptions": {
        "module": "commonjs",
        "target": "es2016",
        "jsx": "preserve"
    },
    "exclude": [
        "node_modules",
        "**/node_modules/*"
    ]
}

a.js:

export const a = 123;

b.js:

import { a } from './sub/a';

export const b = 123;

console.log(a, b) 

1. Move a.js into a sub folder. Select to update paths.
2. Move a.js back into top level folder

Bug:
Sometimes you do not get prompted to update paths. This happens when getEditsForFileRename returns no edits

Here are the logs:

tsserver.log

It looks like sometimes a.js ends up in the inferred project instead of the jsconfig.json project:

Info 527  [16:17:48.76] Project '/Users/matb/projects/san/jsconfig.json' (Configured) 0
Info 527  [16:17:48.76] 	Files (15)
	/Users/matb/projects/san/node_modules/typescript/lib/lib.es2016.full.d.ts
	/Users/matb/projects/san/node_modules/typescript/lib/lib.es2016.array.include.d.ts
	/Users/matb/projects/san/node_modules/typescript/lib/lib.es2015.d.ts
	/Users/matb/projects/san/node_modules/typescript/lib/lib.es5.d.ts
	/Users/matb/projects/san/node_modules/typescript/lib/lib.es2015.symbol.wellknown.d.ts
	/Users/matb/projects/san/node_modules/typescript/lib/lib.es2015.reflect.d.ts
	/Users/matb/projects/san/node_modules/typescript/lib/lib.es2015.proxy.d.ts
	/Users/matb/projects/san/node_modules/typescript/lib/lib.es2015.iterable.d.ts
	/Users/matb/projects/san/node_modules/typescript/lib/lib.es2015.symbol.d.ts
	/Users/matb/projects/san/node_modules/typescript/lib/lib.es2015.promise.d.ts
	/Users/matb/projects/san/node_modules/typescript/lib/lib.es2015.generator.d.ts
	/Users/matb/projects/san/node_modules/typescript/lib/lib.es2015.collection.d.ts
	/Users/matb/projects/san/node_modules/typescript/lib/lib.es2015.core.d.ts
	/Users/matb/projects/san/b.js
	/Users/matb/projects/san/node_modules/typescript/lib/typescript.d.ts

Info 527  [16:17:48.76] -----------------------------------------------
Info 527  [16:17:48.76] Project '/dev/null/inferredProject1*' (Inferred) 1
Info 527  [16:17:48.76] 	Files (14)
	/Users/matb/projects/san/node_modules/typescript/lib/lib.es2016.full.d.ts
	/Users/matb/projects/san/node_modules/typescript/lib/lib.es2016.array.include.d.ts
	/Users/matb/projects/san/node_modules/typescript/lib/lib.es2015.d.ts
	/Users/matb/projects/san/node_modules/typescript/lib/lib.es5.d.ts
	/Users/matb/projects/san/node_modules/typescript/lib/lib.es2015.symbol.wellknown.d.ts
	/Users/matb/projects/san/node_modules/typescript/lib/lib.es2015.reflect.d.ts
	/Users/matb/projects/san/node_modules/typescript/lib/lib.es2015.proxy.d.ts
	/Users/matb/projects/san/node_modules/typescript/lib/lib.es2015.iterable.d.ts
	/Users/matb/projects/san/node_modules/typescript/lib/lib.es2015.symbol.d.ts
	/Users/matb/projects/san/node_modules/typescript/lib/lib.es2015.promise.d.ts
	/Users/matb/projects/san/node_modules/typescript/lib/lib.es2015.generator.d.ts
	/Users/matb/projects/san/node_modules/typescript/lib/lib.es2015.collection.d.ts
	/Users/matb/projects/san/node_modules/typescript/lib/lib.es2015.core.d.ts
	/Users/matb/projects/san/a.js

Info 527  [16:17:48.76] -----------------------------------------------
Info 527  [16:17:48.76] Open files: 
Info 527  [16:17:48.76] 	FileName: /Users/matb/projects/san/b.js ProjectRootPath: /Users/matb/projects/san
Info 527  [16:17:48.76] 		Projects: /Users/matb/projects/san/jsconfig.json
Info 527  [16:17:48.77] 	FileName: /Users/matb/projects/san/a.js ProjectRootPath: /Users/matb/projects/san
Info 527  [16:17:48.77] 		Projects: /dev/null/inferredProject1*
Perf 527  [16:17:48.77] 55::open: async elapsed time (in milliseconds) 16.8510
Info 528  [16:17:48.77] request:
    {"seq":56,"type":"request","command":"getEditsForFileRename","arguments":{"file":"/Users/matb/projects/san/a.js","oldFilePath":"/Users/matb/projects/san/sub/a.js","newFilePath":"/Users/matb/projects/san/a.js"}}
Info 529  [16:17:48.77] Starting updateGraphWorker: Project: /dev/null/inferredProject1*
Info 530  [16:17:48.77] Finishing updateGraphWorker: Project: /dev/null/inferredProject1* Version: 1 structureChanged: false Elapsed: 0ms
Perf 531  [16:17:48.77] 56::getEditsForFileRename: elapsed time (in milliseconds) 0.6543
Info 532  [16:17:48.78] response:
    {"seq":0,"type":"response","command":"getEditsForFileRename","request_seq":56,"success":true,"body":[]}

I can't reproduce the error if I open a.js and move it while it's still open.

I can reproduce this if I don't open any files but do move a.js. In that case I don't even see an option to view the tsserver log -- it probably wasn't started, since the file is moved but not actually opened.

I suspect the reproducability of this bug has to do with what files are open at the time of the move. Could you write down exactly what files are open when do the move? For me, b.js opens as soon as there's an edit in it, and I wasn't closing it, so it continued to be updated when I kept moving a.js.

[mhegazy]

@mjbvz the editor needs to make sure a file is open before it is moved. there are cases where we have no way of knowing the context of the file, e.g. if it was never opened.

[mjbvz]

@Andy-MS Try closing a.js and moving it back and forth a few times. Here's a complete log where the last getEditsForFileRename request fails: tsserver.log

We currently do this on rename:

• close the old file
• open the new file
• Call getEditsForFileRename

I've confirmed in the logs that the old file was opened before the rename started. Should we be firing the close? I confirmed in the logs that for the failed request, the file is correctly opened immediately before we start the rename

@sheetalkamat If everything's working correctly, there should never be an inferred project at all because jsconfig.json is present, right? It looks like we are correctly adding to the configured project most of the time, but there is an error in the log at Info 735 where we create an inferred project for some reason, even though a few lines above in the log it shows that we found the config file. Might have something to do with the order of the watcher seeing the file creation vs. the editor sending a message to us. I can't reproduce this on my computer.