41GB tsserver.log file filled with "Cannot read property 'close' of undefined"

[fkleuver]

I wanted to share with you something interesting that happened today. Whether this can really be considered a bug, I'll leave up to you, but here goes.
So I was wondering how my C drive suddenly got so full today out of nowhere, ran a scan and found this:

It starts with this:

Info 5602 [10:50:10.787] DirectoryWatcher:: Triggered with d:/projects/cherow/bench/node_modules/lodash/fp/isSymbol.js :: WatchInfo: d:/projects/cherow/bench/node_modules 1 Project: WatchType: node_modules for closed script infos in them Info 5603 [10:50:10.787] Elapsed:: 0ms DirectoryWatcher:: Triggered with d:/projects/cherow/bench/node_modules/lodash/fp/isSymbol.js :: WatchInfo: d:/projects/cherow/bench/node_modules 1 Project: WatchType: node_modules for closed script infos in them Info 5604 [10:50:10.787] DirectoryWatcher:: Triggered with d:/projects/cherow/bench/node_modules/lodash/fp/ISTYPE~1.JS :: WatchInfo: d:/projects/cherow/bench/node_modules 1 Project: WatchType: node_modules for closed script infos in them Info 5605 [10:50:10.787] Elapsed:: 0ms DirectoryWatcher:: Triggered with d:/projects/cherow/bench/node_modules/lodash/fp/ISTYPE~1.JS :: WatchInfo: d:/projects/cherow/bench/node_modules 1 Project: WatchType: node_modules for closed script infos in them Info 5606 [10:50:10.787] DirectoryWatcher:: Triggered with d:/projects/cherow/bench/node_modules/lodash/fp/ISUNDE~1.JS :: WatchInfo: d:/projects/cherow/bench/node_modules 1 Project: WatchType: node_modules for closed script infos in them Info 5607 [10:50:10.787] Elapsed:: 0ms DirectoryWatcher:: Triggered with d:/projects/cherow/bench/node_modules/lodash/fp/ISUNDE~1.JS :: WatchInfo: d:/projects/cherow/bench/node_modules 1 Project: WatchType: node_modules for closed script infos in them Info 5608 [10:50:10.787] DirectoryWatcher:: Triggered with d:/projects/cherow/bench/node_modules/lodash/fp/ISWEAK~1.JS :: WatchInfo: d:/projects/cherow/bench/node_modules 1 Project: WatchType: node_modules for closed script infos in them Info 5609 [10:50:10.787] Elapsed:: 0ms DirectoryWatcher:: Triggered with d:/projects/cherow/bench/node_modules/lodash/fp/ISWEAK~1.JS :: WatchInfo: d:/projects/cherow/bench/node_modules 1 Project: WatchType: node_modules for closed script infos in them Info 5610 [10:50:10.787] DirectoryWatcher:: Triggered with d:/projects/cherow/bench/node_modules/lodash/fp/ISWEAK~2.JS :: WatchInfo: d:/projects/cherow/bench/node_modules 1 Project: WatchType: node_modules for closed script infos in them Info 5611 [10:50:10.787] Elapsed:: 0ms DirectoryWatcher:: Triggered with d:/projects/cherow/bench/node_modules/lodash/fp/ISWEAK~2.JS :: WatchInfo: d:/projects/cherow/bench/node_modules 1 Project: WatchType: node_modules for closed script infos in them Info 5612 [10:50:10.787] DirectoryWatcher:: Triggered with d:/projects/cherow/bench/node_modules/lodash/fp/iteratee.js :: WatchInfo: d:/projects/cherow/bench/node_modules 1 Project: WatchType: node_modules for closed script infos in them Info 5613 [10:50:10.787] Elapsed:: 0ms DirectoryWatcher:: Triggered with d:/projects/cherow/bench/node_modules/lodash/fp/iteratee.js :: WatchInfo: d:/projects/cherow/bench/node_modules 1 Project: WatchType: node_modules for closed script infos in them Info 5614 [10:50:10.787] DirectoryWatcher:: Triggered with d:/projects/cherow/bench/node_modules/lodash/fp/join.js :: WatchInfo: d:/projects/cherow/bench/node_modules 1 Project: WatchType: node_modules for closed script infos in them Info 5615 [10:50:10.788] Elapsed:: 0ms DirectoryWatcher:: Triggered with d:/projects/cherow/bench/node_modules/lodash/fp/join.js :: WatchInfo: d:/projects/cherow/bench/node_modules 1 Project: WatchType: node_modules for closed script infos in them Info 5616 [10:50:10.788] DirectoryWatcher:: Triggered with d:/projects/cherow/bench/node_modules/lodash/fp/juxt.js :: WatchInfo: d:/projects/cherow/bench/node_modules 1 Project: WatchType: node_modules for closed script infos in them Info 5617 [10:50:10.788] Elapsed:: 0ms DirectoryWatcher:: Triggered with d:/projects/cherow/bench/node_modules/lodash/fp/juxt.js :: WatchInfo: d:/projects/cherow/bench/node_modules 1 Project: WatchType: node_modules for closed script infos in them Info 5618 [10:50:10.788] DirectoryWatcher:: Triggered with d:/projects/cherow/bench/node_modules/lodash/fp/KEBABC~1.JS :: WatchInfo: d:/projects/cherow/bench/node_modules 1 Project: WatchType: node_modules for closed script infos in them Info 5619 [10:50:10.788] Elapsed:: 0ms DirectoryWatcher:: Triggered with d:/projects/cherow/bench/node_modules/lodash/fp/KEBABC~1.JS :: WatchInfo: d:/projects/cherow/bench/node_modules 1 Project: WatchType: node_modules for closed script infos in them Info 5620 [10:50:10.789] Starting updateGraphWorker: Project: d:/Projects/cherow/bench/tsconfig.json Info 5621 [10:50:10.798] Finishing updateGraphWorker: Project: d:/Projects/cherow/bench/tsconfig.json Version: 122 structureChanged: false Elapsed: 9ms Info 5622 [10:50:10.798] Structure before ensureProjectForOpenFiles: Info 5623 [10:50:10.798] Project 'd:/Projects/cherow/bench/tsconfig.json' (Configured) 0 Info 5623 [10:50:10.798] Files (81)

Info 5623 [10:50:10.798] -----------------------------------------------
Info 5623 [10:50:10.798] Project '/dev/null/inferredProject1*' (Inferred) 1
Info 5623 [10:50:10.798] Files (278)

Info 5623 [10:50:10.798] -----------------------------------------------
Info 5623 [10:50:10.798] Open files:
Info 5623 [10:50:10.798] FileName: d:/Projects/cherow/bench/bench.ts ProjectRootPath: d:/Projects/cherow
Info 5623 [10:50:10.798] FileName: d:/Projects/cherow/bench/src/cherow/index.ts ProjectRootPath: d:/Projects/cherow
Info 5623 [10:50:10.798] FileName: d:/Projects/cherow/bench/src/cherow/latest.ts ProjectRootPath: d:/Projects/cherow
Info 5623 [10:50:10.798] FileName: d:/Projects/cherow/bench/src/cherow/local.ts ProjectRootPath: d:/Projects/cherow
Info 5623 [10:50:10.798] FileName: d:/Projects/cherow/bench/src/parse.ts ProjectRootPath: d:/Projects/cherow
Info 5623 [10:50:10.798] Starting updateGraphWorker: Project: /dev/null/inferredProject1*
Info 5624 [10:50:13.362] Finishing updateGraphWorker: Project: /dev/null/inferredProject1* Version: 14 structureChanged: true Elapsed: 2564ms
Info 5625 [10:50:13.364] Structure after ensureProjectForOpenFiles:
Info 5626 [10:50:13.364] Project 'd:/Projects/cherow/bench/tsconfig.json' (Configured) 0
Info 5626 [10:50:13.365] Files (81)

Info 5626 [10:50:13.365] -----------------------------------------------
Info 5626 [10:50:13.365] Project '/dev/null/inferredProject1*' (Inferred) 1
Info 5626 [10:50:13.365] Files (248)

Info 5626 [10:50:13.365] -----------------------------------------------
Info 5626 [10:50:13.365] Open files:
Info 5626 [10:50:13.365] FileName: d:/Projects/cherow/bench/bench.ts ProjectRootPath: d:/Projects/cherow
Info 5626 [10:50:13.365] FileName: d:/Projects/cherow/bench/src/cherow/index.ts ProjectRootPath: d:/Projects/cherow
Info 5626 [10:50:13.365] FileName: d:/Projects/cherow/bench/src/cherow/latest.ts ProjectRootPath: d:/Projects/cherow
Info 5626 [10:50:13.365] FileName: d:/Projects/cherow/bench/src/cherow/local.ts ProjectRootPath: d:/Projects/cherow
Info 5626 [10:50:13.365] FileName: d:/Projects/cherow/bench/src/parse.ts ProjectRootPath: d:/Projects/cherow
Info 5626 [10:50:13.365] got projects updated in background, updating diagnostics for d:/Projects/cherow/bench/bench.ts,d:/Projects/cherow/bench/src/cherow/index.ts,d:/Projects/cherow/bench/src/cherow/latest.ts,d:/Projects/cherow/bench/src/cherow/local.ts,d:/Projects/cherow/bench/src/parse.ts
Err 5627 [10:50:13.367] Exception on executing command unknown:

Cannot read property 'close' of undefined

TypeError: Cannot read property 'close' of undefined
    at FSEvent.FSWatcher._handle.onchange (fs.js:1385:22)

And then proceeds to log this error another 180 million times in the 3 hours that follow:

Err 5628  [10:50:13.368] Exception on executing command unknown:

    Cannot read property 'close' of undefined

    TypeError: Cannot read property 'close' of undefined
        at FSEvent.FSWatcher._handle.onchange (fs.js:1385:22)

Indeed, that's 16.699 errors (100.196 lines of text ~4MB) logged per second, without interruption, for 3 hours straight until Windows warned me that my SSD drive started getting full.

The reason these numbers are so large, I soon realized, is most likely because I forgot to add node_modules under a new subfolder to .gitignore (and/or to some other ignore settings). I can't actually reproduce this now.

Now this is largely a problem between chair and keyboard, but shouldn't there be some kind of limit on how much log can be produced? I'm not entirely sure what one can be expected to expect in this situation. It's no big deal, but I just wanted to inform you guys that this sort of thing can apparently happen if node_modules somehow ends up getting analyzed by TypeScript 😆

[sheetalkamat]

This sounds similar to as when trying out repro for #29856 as mentioned in microsoft/vscode#68576 (comment), I was able to repro this issue.

[sheetalkamat]

Closing this as this is duplicate of #29407 which is result of gulp build deleting the folder we are watching and we not getting notified or node going in bad state.

[fkleuver]

@sheetalkamat Thanks for clarifying. That makes sense. In that case, I think it was because I used git clean -xfd to clean the working folder state. I do that quite often. I might have still had a mocha watch task running in some console with ts-node
Is there any way to limit the amount of log that can be produced though?