[3.7.2] Debug failure: Dynamic files must always have current directory context

[mjbvz]

Extracted from microsoft/vscode#84618 (comment)

TypeScript Version: 3.7.2

Search Terms

• Update Open
• updateOpen
• untitled
• VS Code

Problem
@MLoughry is reporting TS Server errors in VS Code for loose JS files (untitled files). Here are the relevant parts of the logs:

Info 0    [16:30:41.124] Starting TS Server
Info 1    [16:30:41.128] Version: 3.7.2
Info 2    [16:30:41.128] Arguments: C:\Program Files\Microsoft VS Code\Code.exe e:\VSO\client-web\node_modules\typescript\lib\tsserver.js --syntaxOnly --useInferredProjectPerProjectRoot --disableAutomaticTypingAcquisition --cancellationPipeName C:\Users\Michael\AppData\Local\Temp\vscode-typescript\6b5bad2d31e523852b49\tscancellation-0a9a8159919f74576a36.tmp* --logVerbosity verbose --logFile c:\Users\Michael\AppData\Roaming\Code\logs\20191109T200605\exthost3\vscode.typescript-language-features\tsserver-log-BSEZoJ\tsserver.log --locale en --noGetErrOnBackgroundUpdate --validateDefaultNpmLocation
Info 3    [16:30:41.128] Platform: win32 NodeVersion: 12 CaseSensitive: false
Info 4    [16:30:41.136] request:
    {"seq":0,"type":"request","command":"updateOpen","arguments":{"changedFiles":[],"closedFiles":[],"openFiles":[{"file":"untitled:/e:/VSO/client-web/fooScript.js","fileContent":"cons","projectRootPath":"e:\\VSO\\client-web","scriptKindName":"JS"}]}}
Info 5    [16:30:41.141] Starting updateGraphWorker: Project: /dev/null/inferredProject1*
Info 6    [16:30:41.141] Finishing updateGraphWorker: Project: /dev/null/inferredProject1* Version: 1 structureChanged: undefined Elapsed: 0ms
Info 7    [16:30:41.141] Project '/dev/null/inferredProject1*' (Inferred) 
Info 8    [16:30:41.141] 	Files (0)

Info 9    [16:30:41.141] -----------------------------------------------
Info 10   [16:30:41.141] Project '/dev/null/inferredProject1*' (Inferred) 0
Info 10   [16:30:41.141] 	Files (0)

Info 10   [16:30:41.141] -----------------------------------------------
Info 10   [16:30:41.141] Open files: 
Info 10   [16:30:41.141] 	FileName: untitled:/e:/VSO/client-web/fooScript.js ProjectRootPath: e:/VSO/client-web
Info 10   [16:30:41.141] 		Projects: /dev/null/inferredProject1*
Perf 10   [16:30:41.142] 0::updateOpen: elapsed time (in milliseconds) 5.8480
Info 11   [16:30:41.142] response:
    {"seq":0,"type":"response","command":"updateOpen","request_seq":0,"success":true,"body":true}
Info 12   [16:30:41.143] request:
    {"seq":1,"type":"request","command":"configure","arguments":{"hostInfo":"vscode","preferences":{"providePrefixAndSuffixTextForRename":true,"allowRenameOfImportPath":true}}}
Info 13   [16:30:41.143] Host information vscode
Info 14   [16:30:41.143] response:
    {"seq":0,"type":"response","command":"configure","request_seq":1,"success":true}
Perf 15   [16:30:41.143] 1::configure: async elapsed time (in milliseconds) 0.3943
Info 16   [16:30:41.143] request:
    {"seq":2,"type":"request","command":"updateOpen","arguments":{"changedFiles":[],"closedFiles":[],"openFiles":[{"file":"e:/VSO/client-web/packages/mail/packages/attachments/orchestration/owa-attachment-multi-menu-actions/lib/test.ts","fileContent":"import { AttachmentMenuInfo } from '.';\n","projectRootPath":"e:\\VSO\\client-web","scriptKindName":"TS"},{"file":"e:/VSO/client-web/packages/mail/packages/attachments/orchestration/owa-attachment-multi-menu-actions/lib/index.ts","fileContent":"export {\r\n    default as AttachmentMenuInfo,\r\n    GetCreateAttachmentHandlerFunc,\r\n} from './types/AttachmentMenuInfo';\r\nexport { default as AttachmentMultiMenuEntry } from './types/AttachmentMultiMenuEntry';\r\nexport { CreateAttachmentsFunc } from './types/CreateAttachmentsFunc';\r\n\r\nexport { default as attachmentMultiMenuEntry } from './utils/attachmentMultiMenuEntry';\r\n","projectRootPath":"e:\\VSO\\client-web","scriptKindName":"TS"},{"file":"untitled:/e:/VSO/client-web/^fooScript.js","fileContent":"cons","projectRootPath":"e:\\VSO\\client-web","scriptKindName":"JS"}]}}
Err 17    [16:30:41.160] Exception on executing command {"seq":2,"type":"request","command":"updateOpen","arguments":{"changedFiles":[],"closedFiles":[],"openFiles":[{"file":"e:/VSO/client-web/packages/mail/packages/attachments/orchestration/owa-attachment-multi-menu-actions/lib/test.ts","fileContent":"import { AttachmentMenuInfo } from '.';\n","projectRootPath":"e:\\VSO\\client-web","scriptKindName":"TS"},{"file":"e:/VSO/client-web/packages/mail/packages/attachments/orchestration/owa-attachment-multi-menu-actions/lib/index.ts","fileContent":"export {\r\n    default as AttachmentMenuInfo,\r\n    GetCreateAttachmentHandlerFunc,\r\n} from './types/AttachmentMenuInfo';\r\nexport { default as AttachmentMultiMenuEntry } from './types/AttachmentMultiMenuEntry';\r\nexport { CreateAttachmentsFunc } from './types/CreateAttachmentsFunc';\r\n\r\nexport { default as attachmentMultiMenuEntry } from './utils/attachmentMultiMenuEntry';\r\n","projectRootPath":"e:\\VSO\\client-web","scriptKindName":"TS"},{"file":"untitled:/e:/VSO/client-web/^fooScript.js","fileContent":"cons","projectRootPath":"e:\\VSO\\client-web","scriptKindName":"JS"}]}}:

    Debug Failure. False expression: 
    Verbose Debug Information: {"fileName":"untitled:/e:/VSO/client-web/^fooScript.js","currentDirectory":"e:/VSO/client-web","hostCurrentDirectory":"C:/Program Files/Microsoft VS Code","openKeys":["untitled:/e:/vso/client-web/fooscript.js"]}
    Dynamic files must always have current directory context since containing external project name will always match the script info name.

    Error: Debug Failure. False expression: 
    Verbose Debug Information: {"fileName":"untitled:/e:/VSO/client-web/^fooScript.js","currentDirectory":"e:/VSO/client-web","hostCurrentDirectory":"C:/Program Files/Microsoft VS Code","openKeys":["untitled:/e:/vso/client-web/fooscript.js"]}
    Dynamic files must always have current directory context since containing external project name will always match the script info name.
        at ProjectService.getOrCreateScriptInfoWorker (e:\VSO\client-web\node_modules\typescript\lib\tsserver.js:137724:30)
        at ProjectService.getOrCreateScriptInfoOpenedByClientForNormalizedPath (e:\VSO\client-web\node_modules\typescript\lib\tsserver.js:137710:29)
        at ProjectService.getOrCreateOpenScriptInfo (e:\VSO\client-web\node_modules\typescript\lib\tsserver.js:138113:33)
        at ProjectService.applyChangesInOpenFiles (e:\VSO\client-web\node_modules\typescript\lib\tsserver.js:138332:41)
        at Session.handlers.ts.createMapFromTemplate._a.<computed> (e:\VSO\client-web\node_modules\typescript\lib\tsserver.js:139212:46)
        at e:\VSO\client-web\node_modules\typescript\lib\tsserver.js:140870:88
        at IOSession.Session.executeWithRequestId (e:\VSO\client-web\node_modules\typescript\lib\tsserver.js:140861:28)
        at IOSession.Session.executeCommand (e:\VSO\client-web\node_modules\typescript\lib\tsserver.js:140870:33)
        at IOSession.Session.onMessage (e:\VSO\client-web\node_modules\typescript\lib\tsserver.js:140893:35)
        at Interface.<anonymous> (e:\VSO\client-web\node_modules\typescript\lib\tsserver.js:142208:27)
        at Interface.emit (events.js:200:13)
        at Interface._onLine (readline.js:314:10)
        at Interface._normalWrite (readline.js:459:12)
        at Socket.ondata (readline.js:170:10)
        at Socket.emit (events.js:200:13)
        at addChunk (_stream_readable.js:294:12)
        at readableAddChunk (_stream_readable.js:275:11)
        at Socket.Readable.push (_stream_readable.js:210:10)
        at Pipe.onStreamRead (internal/stream_base_commons.js:166:17)

The crash has similar repo steps but has a different error stack from #35091

[DanielRosenwasser]

@amcasey is looking into this, but @sheetalkamat is likely familiar with the domain.

[mjbvz]

The file name being used is: "untitled:/e:/VSO/client-web/fooScript.js That's very odd because:

• In memory files (untitled) should have a ^ prefix on the filename
• I don't know how you can (easily) get into the state of having a real file path in a untitled file in VS Code. If you just create a file using cmd+n, the files have paths such as untitled:^Untitled-2

@MLoughry How exactly did you open fooScript.js?

[mjbvz]

Also, was this the log from first time the TS Server crashed? And do you still see the errors using the current VS Code insiders builds?

I fixed a few bugs related to how we recover from server restarts. microsoft/vscode@6118d27 in particular could explain why in this log we see updateOpen happening even before configure (and potentially why we create an untitled file without a ^ prefix). However that fix is only relevant if the TS Server has already crashed and is restarting...

[MLoughry]

From the integrated terminal, “code fooScript.js” - Michael

…

________________________________ From: Matt Bierner <[email protected]> Sent: Thursday, November 14, 2019 12:07:09 AM To: microsoft/TypeScript <[email protected]> Cc: Michael Loughry <[email protected]>; Mention <[email protected]> Subject: [EXTERNAL] Re: [microsoft/TypeScript] [3.7.2] Debug failure: Dynamic files must always have current directory context (#35094) The file name being used is: "file":"untitled:/e:/VSO/client-web/fooScript.js" That's very odd because: * In memory files (untitled) should have a ^ prefix on the filename * I don't know how you can (easily) get into the state of having a real file path in a untitled file in VS Code. If you just create a file using cmd+n, the files have paths such as untitled:^Untitled-2 @MLoughry<https://nam06.safelinks.protection.outlook.com/?url=https%3A%2F%2Fgithub.com%2FMLoughry&data=02%7C01%7Cmiclo%40microsoft.com%7C576abb99031e44ac78db08d768d9a680%7C72f988bf86f141af91ab2d7cd011db47%7C1%7C0%7C637093156321060291&sdata=%2BGWc8v%2B%2Bx6I%2Fe7KNGfpS%2FTF2UXVxfkgT6Omoon0XVKw%3D&reserved=0> How exactly did you open fooScript.js? — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub<https://nam06.safelinks.protection.outlook.com/?url=https%3A%2F%2Fgithub.com%2Fmicrosoft%2FTypeScript%2Fissues%2F35094%3Femail_source%3Dnotifications%26email_token%3DAE633KLDKPIGU3UMNJEILGDQTUBK3A5CNFSM4JND3Z72YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOEEA6OUQ%23issuecomment-553772882&data=02%7C01%7Cmiclo%40microsoft.com%7C576abb99031e44ac78db08d768d9a680%7C72f988bf86f141af91ab2d7cd011db47%7C1%7C0%7C637093156321060291&sdata=B5pNeMDY8ZB%2BPNQRo%2BTfDkYNzin1tK9X6St33LxqZG4%3D&reserved=0>, or unsubscribe<https://nam06.safelinks.protection.outlook.com/?url=https%3A%2F%2Fgithub.com%2Fnotifications%2Funsubscribe-auth%2FAE633KJ2MFB7NUHO6WIPMBDQTUBK3ANCNFSM4JND3Z7Q&data=02%7C01%7Cmiclo%40microsoft.com%7C576abb99031e44ac78db08d768d9a680%7C72f988bf86f141af91ab2d7cd011db47%7C1%7C0%7C637093156321070285&sdata=1scZdQezwDj3BMGnAy13G42x4AdGMBx1W0yjJ5r9Ki4%3D&reserved=0>.

[MLoughry]

This issue persists with the latest Insiders build. I've copied all the tsserver logs from the repro with the Insiders build into a single zip below (though some of the tsserver log folders were actually empty).

Version: 1.41.0-insider (user setup)
Commit: eccf417b72fc0a632ec2cbd7855a681cdb8c81fa
Date: 2019-11-14T09:50:04.822Z
Electron: 6.1.4
Chrome: 76.0.3809.146
Node.js: 12.4.0
V8: 7.6.303.31-electron.0
OS: Windows_NT x64 10.0.18362

crashed_tsserver_logs.zip

[mjbvz]

Thanks. I can repo using code-insiders newFileName.ts to create an untitled file. This is on mac so it's not windows specific

[mjbvz]

@sheetalkamat In memory resources are expected to have a ^ on just the file name, correct? Would a file with a name such as untitled:/Users/mat/^fooScript.js cause problems for TS Server?

[sheetalkamat]

@mjbvz the file name seems ok..

We also have test... https://github.com/microsoft/TypeScript/blob/master/src/testRunner/unittests/tsserver/projects.ts#L1079

Looking into what's going on..

[sheetalkamat]

Seems like we don't expect the projectRootPath for dynamic files and that's the assert that fails in this

[sheetalkamat]

Working on fix but @mjbvz we never supported this.. This code has not been changed for a while now.

[amcasey]

Maybe it's never worked and we're just now catching it because the failure has been made "fatal"?

[mjbvz]

Thank you for looking into this @sheetalkamat. The VS code logic for untitled files has also not changed recently so I agree with @amcasey's suggestion: this was likely a long standing bug that the new VS Code error handling logic revealed. It's unfortunate it was revealed in a way that impacted users