NPM Install fails when tsconfig is present in VSCode workspace

[mjbvz]

TypeScript Version: 2.3.4
NPM version: 5.0.4

Repo

1. In vscode, create a workspace:

app.ts:

import _ from 'lodash'

tsconfig.json

{
 "compilerOptions": { }
}

package.json:

{
 "name": "test",
 "version": "1.0.0",
 "description": "",
 "main": "index.js",
 "dependencies": {
 "lodash": "^4.16.4",
 "rxjs": "^5.4.2"
 },
 "devDependencies": {
 "@types/lodash": "^4.14.68",
 "typescript": "^2.4.1"
 },
 "scripts": {
 "test": "echo \"Error: no test specified\" && exit 1"
 },
 "keywords": [],
 "author": "",
 "license": "ISC"
}

2. With code open, open the ts file.

3. In the a terminal for the current workspace, run npm install

Bug

PS C:\source\test> npm i
npm WARN test@1.0.0 No description
npm WARN test@1.0.0 No repository field.

npm ERR! path C:\source\test\node_modules\@types\lodash
npm ERR! code ENOENT
npm ERR! errno -4058
npm ERR! syscall rename
npm ERR! enoent ENOENT: no such file or directory, rename 'C:\source\test\node_modules\@types\lodash' -> 'C:\source\test\node_modules\@types\.lodash.DELETE'
npm ERR! enoent This is related to npm not being able to find a file.
npm ERR! enoent

npm ERR! A complete log of this run can be found in:
npm ERR! C:\Users\matb.REDMOND\AppData\Roaming\npm-cache\_logs\2017-07-05T20_55_16_461Z-debug.log

Here are the file handles:

> C:\Users\matb.REDMOND\Downloads\Handle\handle.exe lodash
Code.exe pid: 21136 type: File 534: C:\source\test\node_modules\.staging\@types\lodash-4e92de43\tem plate
Code.exe pid: 21136 type: File 5E0: C:\source\test\node_modules\.staging\@types\lodash-4e92de43

and the process info for pid 21136:

"C:\Program Files (x86)\Microsoft VS Code\Code.exe" "c:\Program Files (x86)\Microsoft VS Code\resources\app\extensions\typescript\out\utils\electronForkStart" "c:\Program Files (x86)\Microsoft VS Code\resources\app\extensions\node_modules\typescript\lib\tsserver.js" --useSingleInferredProject --enableTelemetry --cancellationPipeName \\.\pipe\vscode-tscancellation-70cad40d58dfe783e0f8-sock*

Seems that the tsserver is holding onto these files, breaking npm install

[mjbvz]

Here's the start of the tsserver log in these cases:

Info 0 Binding...
Info 1 request: {"seq":0,"type":"request","command":"configure","arguments":{"hostInfo":"vscode"}}
Info 2 Host information vscode
Info 3 response: {"seq":0,"type":"response","command":"configure","request_seq":0,"success":true}
Perf 4 0::configure: async elapsed time (in milliseconds) 1.6751
Info 5 request: {"seq":1,"type":"request","command":"compilerOptionsForInferredProjects","arguments":{"options":{"module":"CommonJS","target":"ES6","allowSyntheticDefaultImports":true,"allowNonTsExtensions":true,"allowJs":true,"jsx":"Preserve"}}}
Perf 6 1::compilerOptionsForInferredProjects: elapsed time (in milliseconds) 0.6952
Info 7 response: {"seq":0,"type":"response","command":"compilerOptionsForInferredProjects","request_seq":1,"success":true,"body":true}
Info 8 request: {"seq":2,"type":"request","command":"open","arguments":{"file":"c:/source/test/y.ts","fileContent":"\nimport _ from 'lodash'\n\n_.","scriptKindName":"TS"}}
Info 9 Search path: c:/source/test
Info 10 Config file name: c:/source/test/tsconfig.json
Info 11 No plugins exist
Info 12 Add recursive watcher for: c:/source/test
Info 13 c for path c:/source/test not found in cache...
Info 14 Starting C:\Program Files (x86)\Microsoft VS Code\Code.exe with args ["C:\\Users\\matb.REDMOND\\AppData\\Roaming\\npm\\node_modules\\typescript\\lib/watchGuard.js","c:/source/test"]
Info 15 WatchGuard for path c:/source/test returned: OK
Info 16 Opened configuration file c:/source/test/tsconfig.json
Info 17 Project 'c:/source/test/tsconfig.json' (Configured) 0
C:/Users/matb.REDMOND/AppData/Roaming/npm/node_modules/typescript/lib/lib.d.ts
c:/source/test/y.ts

-----------------------------------------------
Open files: 
c:/source/test/y.ts
Info 18 event: {"seq":0,"type":"event","event":"configFileDiag","body":{"triggerFile":"c:/source/test/y.ts","configFile":"c:/source/test/tsconfig.json","diagnostics":[]}}
Perf 19 2::open: async elapsed time (in milliseconds) 878.9492
Info 20 request: {"seq":3,"type":"request","command":"getSupportedCodeFixes","arguments":null}
Perf 21 3::getSupportedCodeFixes: elapsed time (in milliseconds) 0.3511
Info 22 response: {"seq":0,"type":"response","command":"getSupportedCodeFixes","request_seq":3,"success":true,"body":["2304","2339","2377","2420","2503","2515","2653","2663","2686","2689","6133","6138","17009"]}
Info 23 request: {"seq":4,"type":"request","command":"geterr","arguments":{"delay":0,"files":["c:/source/test/y.ts"]}}
Perf 24 4::geterr: async elapsed time (in milliseconds) 2.2478
Info 25 event: {"seq":0,"type":"event","event":"syntaxDiag","body":{"file":"c:/source/test/y.ts","diagnostics":[{"start":{"line":4,"offset":3},"end":{"line":4,"offset":3},"text":"Identifier expected.","code":1003}]}}
Info 26 event: {"seq":0,"type":"event","event":"semanticDiag","body":{"file":"c:/source/test/y.ts","diagnostics":[{"start":{"line":2,"offset":15},"end":{"line":2,"offset":23},"text":"Cannot find module 'lodash'.","code":2307}]}}
Info 27 event: {"seq":0,"type":"event","event":"requestCompleted","body":{"request_seq":4}}
Info 28 Detected source file changes: c:/source/test/node_modules/.staging/symbol-observable-5f792886/index.d.ts
Info 29 Detected source file changes: c:/source/test/node_modules/.staging/@types/lodash-4e92de43/add/index.d.ts
Info 30 Detected source file changes: c:/source/test/node_modules/.staging/@types/lodash-4e92de43/assign/index.d.ts
Info 31 Detected source file changes: c:/source/test/node_modules/.staging/@types/lodash-4e92de43/assignIn/index.d.ts
Info 32 Detected source file changes: c:/source/test/node_modules/.staging/@types/lodash-4e92de43/at/index.d.ts
Info 33 Detected source file changes: c:/source/test/node_modules/.staging/@types/lodash-4e92de43/attempt/index.d.ts
Info 34 Detected source file changes: c:/source/test/node_modules/.staging/@types/lodash-4e92de43/before/index.d.ts
Info 35 Detected source file changes: c:/source/test/node_modules/.staging/rxjs-7f819787/Operator.d.ts
Info 36 Detected source file changes: c:/source/test/node_modules/.staging/@types/lodash-4e92de43/bind/index.d.ts
Info 37 Detected source file changes: c:/source/test/node_modules/.staging/rxjs-7f819787/InnerSubscriber.d.ts
Info 38 Detected source file changes: c:/source/test/node_modules/.staging/@types/lodash-4e92de43/camelCase/index.d.ts
...
Info 279 event: {"seq":0,"type":"event","event":"configFileDiag","body":{"triggerFile":"c:/source/test/node_modules/.staging/rxjs-7f819787/observable/IteratorObservable.d.ts","configFile":"c:/source/test/tsconfig.json","diagnostics":[]}}
Info 280 request: {"seq":5,"type":"request","command":"open","arguments":{"file":"c:/source/test/node_modules/.staging/rxjs-7f819787/observable/IteratorObservable.d.ts","fileContent":"import { IScheduler } from '../Scheduler';\nimport { Observable } from '../Observable';\nimport { TeardownLogic } from '../Subscription';\nimport { Subscriber } from '../Subscriber';\n/**\n * We need this JSDoc comment for affecting ESDoc.\n * @extends {Ignored}\n * @hide true\n */\nexport declare class IteratorObservable<T> extends Observable<T> {\n private scheduler;\n private iterator;\n static create<T>(iterator: any, scheduler?: IScheduler): IteratorObservable<T>;\n static dispatch(state: any): void;\n constructor(iterator: any, scheduler?: IScheduler);\n protected _subscribe(subscriber: Subscriber<T>): TeardownLogic;\n}\n","scriptKindName":"TS"}}
Info 281 Search path: c:/source/test/node_modules/.staging/rxjs-7f819787/observable
Info 282 Config file name: c:/source/test/tsconfig.json
Info 283 Add watcher for: c:/source/test/node_modules/.staging/rxjs-7f819787/observable
Info 284 watchDirectory for c:/source/test/node_modules/.staging/rxjs-7f819787/observable uses cached drive information.
Info 285 Add watcher for: c:/source/test/node_modules/.staging/rxjs-7f819787
Info 286 watchDirectory for c:/source/test/node_modules/.staging/rxjs-7f819787 uses cached drive information.
Info 287 Add watcher for: c:/source/test/node_modules/.staging
Info 288 watchDirectory for c:/source/test/node_modules/.staging uses cached drive information.
Info 289 Add watcher for: c:/source/test/node_modules
Info 290 watchDirectory for c:/source/test/node_modules uses cached drive information.
Info 291 Add watcher for: c:/source/test
Info 292 watchDirectory for c:/source/test uses cached drive information.
Info 293 Add watcher for: c:/source
Info 294 watchDirectory for c:/source uses cached drive information.
Info 295 Scheduling throttled operation: {"projectName":"/dev/null/inferredProject1*","fileNames":["C:/Users/matb.REDMOND/AppData/Roaming/npm/node_modules/typescript/lib/lib.es6.d.ts","c:/source/test/node_modules/.staging/rxjs-7f819787/Subscription.d.ts","c:/source/test/node_modules/.staging/rxjs-7f819787/Scheduler.d.ts","c:/source/test/node_modules/.staging/rxjs-7f819787/Observer.d.ts","c:/source/test/node_modules/.staging/rxjs-7f819787/Subscriber.d.ts","c:/source/test/node_modules/.staging/rxjs-7f819787/Operator.d.ts","c:/source/test/node_modules/.staging/rxjs-7f819787/observable/IfObservable.d.ts","c:/source/test/node_modules/.staging/rxjs-7f819787/observable/ErrorObservable.d.ts","c:/source/test/node_modules/.staging/rxjs-7f819787/Observable.d.ts","c:/source/test/node_modules/.staging/rxjs-7f819787/observable/IteratorObservable.d.ts"],"compilerOptions":{"module":1,"target":2,"allowSyntheticDefaultImports":true,"allowNonTsExtensions":true,"allowJs":true,"jsx":1,"noEmitForJsFiles":true},"typeAcquisition":{"enable":true,"include":[],"exclude":[]},"unresolvedImports":[],"projectRootPath":"","kind":"discover"}
Info 296 Project 'c:/source/test/tsconfig.json' (Configured) 0
C:/Users/matb.REDMOND/AppData/

[mjbvz]

Ron Buckton (@rbuckton) / Andy (Andrewkraft) (@Andy-MS) can you please take a look at this issue. I believe the root cause is a change we made in VSCode 1.13 that opens triggerFile. I find it odd that the server is watching the staging directory and sending events about it though

We're seeing fair number of people report this problem: microsoft/vscode#28593 I'll see if I can get a workaround in for vscode 1.14

[sheetalkamat]

This is because the configaFileDiagnostics is sent irrespective of what we decide to do with the file. Which ends up sending event to vscode about the that's in the staged directory)(that file may or may not end up being part of the project).. Look at https://github.com/Microsoft/TypeScript/blob/master/src/server/editorServices.ts#L649

Since vscode opens the trigger file, it would end up opening that file and that means we will watch the whole ancestor chain for addition of the tsconfig file.

There are two issues here:

1. The event shouldn't have been sent.
2. The watch for tsconfig file doesn't need to watch the whole directory just the file.

This would be updated with the changes I am making of which first batch will go out this Monday.

[BurtHarris]

Sheetal Nandi (@sheetalkamat): Any update on this? I'm still having trouble with VSCode 1.14.2. NPM works OK before I start VSCode, but gets hosed after. Shutting down VSCode doesn't fix the problem, but logging out does.