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]

@rbuckton / @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]

@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.