Repository navigation
getEditsForFileRename taking long time #30535
Description
Activity
Matt Bierner (@mjbvz) I don't seem to see this either with vscode or insiders build from latest typescript build from master.
With vscode:Info 8843 [15:43:2.305] request: {"seq":25,"type":"request","command":"getEditsForFileRename","arguments":{"file":"c:/github/vscode/src/vs/editor/contrib/codeAction/codeActionRename.ts","oldFilePath":"c:/github/vscode/src/vs/editor/contrib/codeAction/codeAction.ts","newFilePath":"c:/github/vscode/src/vs/editor/contrib/codeAction/codeActionRename.ts"}} Perf 8844 [15:43:2.673] 25::getEditsForFileRename: elapsed time (in milliseconds) 367.1587With insiders:
Info 8851 [15:46:54.377] request: {"seq":30,"type":"request","command":"getEditsForFileRename","arguments":{"oldFilePath":"c:/github/vscode/src/vs/editor/contrib/codeAction/codeAction.ts","newFilePath":"c:/github/vscode/src/vs/editor/contrib/codeAction/codeActionRenamed.ts"}} Perf 8852 [15:46:54.706] 30::getEditsForFileRename: elapsed time (in milliseconds) 329.2082I still see this using TS 3.4.1 but I think the long running request is actually the
configurerequest we send before requestinggetEditsForFileRename. Here's the VS Code timing of that request beforegetEditsForFileRename:[Trace - 10:53:31 AM] Sending request: configure (42). Response expected: yes. Current queue length: 3 Arguments: { "formatOptions": { "tabSize": 4, "indentSize": 4, "convertTabsToSpaces": false, "newLineCharacter": "\n", "insertSpaceAfterCommaDelimiter": true, "insertSpaceAfterConstructor": false, "insertSpaceAfterSemicolonInForStatements": true, "insertSpaceBeforeAndAfterBinaryOperators": true, "insertSpaceAfterKeywordsInControlFlowStatements": true, "insertSpaceAfterFunctionKeywordForAnonymousFunctions": true, "insertSpaceBeforeFunctionParenthesis": false, "insertSpaceAfterOpeningAndBeforeClosingNonemptyParenthesis": false, "insertSpaceAfterOpeningAndBeforeClosingNonemptyBrackets": false, "insertSpaceAfterOpeningAndBeforeClosingNonemptyBraces": true, "insertSpaceAfterOpeningAndBeforeClosingTemplateStringBraces": false, "insertSpaceAfterOpeningAndBeforeClosingJsxExpressionBraces": false, "insertSpaceAfterTypeAssertion": false, "placeOpenBraceOnNewLineForFunctions": false, "placeOpenBraceOnNewLineForControlBlocks": false }, "preferences": { "quotePreference": "single", "importModuleSpecifierPreference": "non-relative", "allowTextChangesInNewFiles": true, "providePrefixAndSuffixTextForRename": true, "allowRenameOfImportPath": true } } [Trace - 10:53:31 AM] Response received: configure (42). Request took 6795 ms. Success: trueWe make a global
configurerequest to ensure that any edited files have the expected configuration for settings like quotes (as we do not know which files are going to be touched before hand).You should see the file rename dialog taking a long time to show up in VS Code. I don't know where this delay actually shows up on the tsserver as the logs show that the
configurerequest itself is pretty quick.Looked a little bit into this. From tsserver point of view neither
configurenorgetEditsForRenametake long..Perf 2120 [12:2:0.935] 33::configure: async elapsed time (in milliseconds) 0.4259 Perf 2122 [12:2:1.439] 34::getEditsForFileRename: elapsed time (in milliseconds) 502.5104Its the updateOpen request before this that needs to process opening and closing of the file that's renamed (It is done only once but it does take some time since its a big project)
Info 2101 [12:1:53.912] Starting updateGraphWorker: Project: c:/github/vscode/src/tsconfig.json Info 2102 [12:2:0.916] Finishing updateGraphWorker: Project: c:/github/vscode/src/tsconfig.json Version: 2 structureChanged: true Elapsed: 7004msI think we could add another array to updateOpen for rename where we can reuse the parsed source file at least if texts are same? I will experiment with that and post back if that has better results.
Investigating this further seems like most time is gone in module resolution.. The interesting fact is that the number of files in program (2172) > the limit of files(256) for which we will iterate through each resolution and invalidate the only changed resolution..
For initial program:: Info 4430 [14:37:51.152] ResolveModule time: 5.76s For program with rename on FS for codeActionRenamed:: Info 6754 [14:38:15.17] ResolveModule time: 4.53s Complete time information for rename:: Info 6742 [14:38:15.17] Files: 2172 Info 6743 [14:38:15.17] Lines: 688383 Info 6744 [14:38:15.17] Nodes: 3395193 Info 6745 [14:38:15.17] Identifiers: 1152337 Info 6746 [14:38:15.17] Symbols: 401143 Info 6747 [14:38:15.17] Types: 76 Info 6748 [14:38:15.17] Memory used: 742979K Info 6749 [14:38:15.17] Assignability cache size: 0 Info 6750 [14:38:15.17] Identity cache size: 0 Info 6751 [14:38:15.17] Subtype cache size: 0 Info 6752 [14:38:15.17] Strict subtype cache size: 0 Info 6753 [14:38:15.17] ResolveTypeReference time: 0.10s Info 6754 [14:38:15.17] ResolveModule time: 4.53s Info 6755 [14:38:15.17] Parse time: 0.00s Info 6756 [14:38:15.17] Parse c:/github/vscode/src/vs/editor/contrib/codeAction/codeActionRenamed.ts time: 0.00s Info 6757 [14:38:15.17] Program time: 5.18s Info 6758 [14:38:15.17] Bind time: 0.00s Info 6759 [14:38:15.17] Total time: 5.18sLooking into how we can optimize resolveModules when program contains large number of files in it.
While the root cause is discovered, it would need few prototypes to see how best we can handle.
- Try create as many resuse of resolutions as possible so its easier to invalidate. I think this could make life significantly efficient..
- keep track of moduleName folders timestamp to invalidate when number of files are large.. (would work well for
node_modulesbut not so much for classic resolution.. If we could do this we wouldn't need to discard resolutions between two creations..
TypeScript Version: 3.4.0-rc
Search Terms:
Repo
src/vs/editor/contrib/codeAction/codeAction.tscodeActionRenamedBug
This triggers a
getEditsForFileRenamerequest that takes between 5 and 10 seconds to resolve. Here's the tsserver.log.