Repository navigation
getEditsForFileRename can take a long time on large project #29031
Copy link
Copy link
Closed
Labels
BugA bug in TypeScriptA bug in TypeScriptDomain: LS: TSServerIssues related to the TSServerIssues related to the TSServerDomain: PerformanceReports of unusually slow behaviorReports of unusually slow behaviorFixedA PR has been merged for this issueA PR has been merged for this issue
Milestone
Description
TypeScript Version: 3.2.2
Search Terms:
- getEditsForFileRename
- update imports on rename
Repo
- Using VS Code
- With
"typescript.updateImportsOnFileMove.enabled": "prompt"set - Open VS Code codebase
- Open
src/vs/base/common/paging.ts - Wait for js/ts intellisense to load
- Rename the file
Bug:
It takes a long time before the update imports prompt is shown. I've attached to tsserver log (the name name was newPaging): tsserver.log.zip
Looks like there are two long running ops. Handling the project structure change:
Info 2083 [13:54:12.450] DirectoryWatcher:: Triggered with /Users/matb/projects/vscode/src/vs/base/common/paging.ts :: WatchInfo: /Users/matb/projects/vscode/src/vs 1 Project: /Users/matb/projects/vscode/src/tsconfig.json WatchType: Wild card directory
Info 2084 [13:54:12.452] Scheduled: /Users/matb/projects/vscode/src/tsconfig.json, Cancelled earlier one
Info 2085 [13:54:12.452] Scheduled: *ensureProjectForOpenFiles*, Cancelled earlier one
Info 2086 [13:54:12.452] Elapsed:: 2ms DirectoryWatcher:: Triggered with /Users/matb/projects/vscode/src/vs/base/common/paging.ts :: WatchInfo: /Users/matb/projects/vscode/src/vs 1 Project: /Users/matb/projects/vscode/src/tsconfig.json WatchType: Wild card directory
Info 2087 [13:54:12.452] DirectoryWatcher:: Triggered with /Users/matb/projects/vscode/src/vs/base/common/newPaging.ts :: WatchInfo: /Users/matb/projects/vscode/src/vs 1 Project: /Users/matb/projects/vscode/src/tsconfig.json WatchType: Wild card directory
Info 2088 [13:54:12.452] Scheduled: /Users/matb/projects/vscode/src/tsconfig.json, Cancelled earlier one
Info 2089 [13:54:12.453] Scheduled: *ensureProjectForOpenFiles*, Cancelled earlier one
Info 2090 [13:54:12.453] Elapsed:: 1ms DirectoryWatcher:: Triggered with /Users/matb/projects/vscode/src/vs/base/common/newPaging.ts :: WatchInfo: /Users/matb/projects/vscode/src/vs 1 Project: /Users/matb/projects/vscode/src/tsconfig.json WatchType: Wild card directory
Info 2091 [13:54:12.453] DirectoryWatcher:: Triggered with /Users/matb/projects/vscode/src/vs/base/common/paging.ts :: WatchInfo: /Users/matb/projects/vscode/src/vs 1 Project: /Users/matb/projects/vscode/src/tsconfig.json WatchType: Directory of Failed lookup locations in module resolution
Info 2092 [13:54:12.453] Elapsed:: 0ms DirectoryWatcher:: Triggered with /Users/matb/projects/vscode/src/vs/base/common/paging.ts :: WatchInfo: /Users/matb/projects/vscode/src/vs 1 Project: /Users/matb/projects/vscode/src/tsconfig.json WatchType: Directory of Failed lookup locations in module resolution
Info 2093 [13:54:12.453] DirectoryWatcher:: Triggered with /Users/matb/projects/vscode/src/vs/base/common/newPaging.ts :: WatchInfo: /Users/matb/projects/vscode/src/vs 1 Project: /Users/matb/projects/vscode/src/tsconfig.json WatchType: Directory of Failed lookup locations in module resolution
Info 2094 [13:54:12.453] Elapsed:: 0ms DirectoryWatcher:: Triggered with /Users/matb/projects/vscode/src/vs/base/common/newPaging.ts :: WatchInfo: /Users/matb/projects/vscode/src/vs 1 Project: /Users/matb/projects/vscode/src/tsconfig.json WatchType: Directory of Failed lookup locations in module resolution
Info 2095 [13:54:12.503] request:
{"seq":41,"type":"request","command":"open","arguments":{"file":"/Users/matb/projects/vscode/src/vs/base/common/newPaging.ts","fileContent":"/*---------------------------------------------------------------------------------------------\n * Copyright (c) Microsoft Corporation. All rights reserved.\n * Licensed under the MIT License. See License.txt in the project root for license information.\n *--------------------------------------------------------------------------------------------*/\n\nimport { isArray } from 'vs/base/common/types';\nimport { CancellationToken, CancellationTokenSource } from 'vs/base/common/cancellation';\nimport { canceled } from 'vs/base/common/errors';\nimport { range } from 'vs/base/common/arrays';\n\n/**\n * A Pager is a stateless abstraction over a paged collection.\n */\nexport interface IPager<T> {\n\tfirstPage: T[];\n\ttotal: number;\n\tpageSize: number;\n\tgetPage(pageIndex: number, cancellationToken: CancellationToken): Promise<T[]>;\n}\n\ninterface IPage<T> {\n\tisResolved: boolean;\n\tpromise: Promise<void> | null;\n\tcts: CancellationTokenSource | null;\n\tpromiseIndexes: Set<number>;\n\telements: T[];\n}\n\nfunction createPage<T>(elements?: T[]): IPage<T> {\n\treturn {\n\t\tisResolved: !!elements,\n\t\tpromise: null,\n\t\tcts: null,\n\t\tpromiseIndexes: new Set<number>(),\n\t\telements: elements || []\n\t};\n}\n\n/**\n * A PagedModel is a stateful model over an abstracted paged collection.\n */\nexport interface IPagedModel<T> {\n\tlength: number;\n\tisResolved(index: number): boolean;\n\tget(index: number): T;\n\tresolve(index: number, cancellationToken: CancellationToken): Promise<T>;\n}\n\nexport function singlePagePager<T>(elements: T[]): IPager<T> {\n\treturn {\n\t\tfirstPage: elements,\n\t\ttotal: elements.length,\n\t\tpageSize: elements.length,\n\t\tgetPage: (pageIndex: number, cancellationToken: CancellationToken): Promise<T[]> => {\n\t\t\treturn Promise.resolve(elements);\n\t\t}\n\t};\n}\n\nexport class PagedModel<T> implements IPagedModel<T> {\n\n\tprivate pager: IPager<T>;\n\tprivate pages: IPage<T>[] = [];\n\n\tget length(): number { return this.pager.total; }\n\n\tconstructor(arg: IPager<T> | T[]) {\n\t\tthis.pager = isArray(arg) ? singlePagePager<T>(arg) : arg;\n\n\t\tconst totalPages = Math.ceil(this.pager.total / this.pager.pageSize);\n\n\t\tthis.pages = [\n\t\t\tcreatePage(this.pager.firstPage.slice()),\n\t\t\t...range(totalPages - 1).map(() => createPage<T>())\n\t\t];\n\t}\n\n\tisResolved(index: number): boolean {\n\t\tconst pageIndex = Math.floor(index / this.pager.pageSize);\n\t\tconst page = this.pages[pageIndex];\n\n\t\treturn !!page.isResolved;\n\t}\n\n\tget(index: number): T {\n\t\tconst pageIndex = Math.floor(index / this.pager.pageSize);\n\t\tconst indexInPage = index % this.pager.pageSize;\n\t\tconst page = this.pages[pageIndex];\n\n\t\treturn page.elements[indexInPage];\n\t}\n\n\tresolve(index: number, cancellationToken: CancellationToken): Promise<T> {\n\t\tif (cancellationToken.isCancellationRequested) {\n\t\t\treturn Promise.reject(canceled());\n\t\t}\n\n\t\tconst pageIndex = Math.floor(index / this.pager.pageSize);\n\t\tconst indexInPage = index % this.pager.pageSize;\n\t\tconst page = this.pages[pageIndex];\n\n\t\tif (page.isResolved) {\n\t\t\treturn Promise.resolve(page.elements[indexInPage]);\n\t\t}\n\n\t\tif (!page.promise) {\n\t\t\tpage.cts = new CancellationTokenSource();\n\t\t\tpage.promise = this.pager.getPage(pageIndex, page.cts.token)\n\t\t\t\t.then(elements => {\n\t\t\t\t\tpage.elements = elements;\n\t\t\t\t\tpage.isResolved = true;\n\t\t\t\t\tpage.promise = null;\n\t\t\t\t\tpage.cts = null;\n\t\t\t\t}, err => {\n\t\t\t\t\tpage.isResolved = false;\n\t\t\t\t\tpage.promise = null;\n\t\t\t\t\tpage.cts = null;\n\t\t\t\t\treturn Promise.reject(err);\n\t\t\t\t});\n\t\t}\n\n\t\tcancellationToken.onCancellationRequested(() => {\n\t\t\tif (!page.cts) {\n\t\t\t\treturn;\n\t\t\t}\n\n\t\t\tpage.promiseIndexes.delete(index);\n\n\t\t\tif (page.promiseIndexes.size === 0) {\n\t\t\t\tpage.cts.cancel();\n\t\t\t}\n\t\t});\n\n\t\tpage.promiseIndexes.add(index);\n\n\t\treturn page.promise.then(() => page.elements[indexInPage]);\n\t}\n}\n\nexport class DelayedPagedModel<T> implements IPagedModel<T> {\n\n\tget length(): number { return this.model.length; }\n\n\tconstructor(private model: IPagedModel<T>, private timeout: number = 500) { }\n\n\tisResolved(index: number): boolean {\n\t\treturn this.model.isResolved(index);\n\t}\n\n\tget(index: number): T {\n\t\treturn this.model.get(index);\n\t}\n\n\tresolve(index: number, cancellationToken: CancellationToken): Promise<T> {\n\t\treturn new Promise((c, e) => {\n\t\t\tif (cancellationToken.isCancellationRequested) {\n\t\t\t\treturn e(canceled());\n\t\t\t}\n\n\t\t\tconst timer = setTimeout(() => {\n\t\t\t\tif (cancellationToken.isCancellationRequested) {\n\t\t\t\t\treturn e(canceled());\n\t\t\t\t}\n\n\t\t\t\ttimeoutCancellation.dispose();\n\t\t\t\tthis.model.resolve(index, cancellationToken).then(c, e);\n\t\t\t}, this.timeout);\n\n\t\t\tconst timeoutCancellation = cancellationToken.onCancellationRequested(() => {\n\t\t\t\tclearTimeout(timer);\n\t\t\t\ttimeoutCancellation.dispose();\n\t\t\t\te(canceled());\n\t\t\t});\n\t\t});\n\t}\n}\n\n/**\n * Similar to array.map, `mapPager` lets you map the elements of an\n * abstract paged collection to another type.\n */\nexport function mapPager<T, R>(pager: IPager<T>, fn: (t: T) => R): IPager<R> {\n\treturn {\n\t\tfirstPage: pager.firstPage.map(fn),\n\t\ttotal: pager.total,\n\t\tpageSize: pager.pageSize,\n\t\tgetPage: (pageIndex, token) => pager.getPage(pageIndex, token).then(r => r.map(fn))\n\t};\n}\n\n/**\n * Merges two pagers.\n */\nexport function mergePagers<T>(one: IPager<T>, other: IPager<T>): IPager<T> {\n\treturn {\n\t\tfirstPage: [...one.firstPage, ...other.firstPage],\n\t\ttotal: one.total + other.total,\n\t\tpageSize: one.pageSize + other.pageSize,\n\t\tgetPage(pageIndex: number, token): Promise<T[]> {\n\t\t\treturn Promise.all([one.getPage(pageIndex, token), other.getPage(pageIndex, token)])\n\t\t\t\t.then(([onePage, otherPage]) => [...onePage, ...otherPage]);\n\t\t}\n\t};\n}","scriptKindName":"TS","projectRootPath":"/Users/matb/projects/vscode"}}
Info 2096 [13:54:12.503] Search path: /Users/matb/projects/vscode/src/vs/base/common
Info 2097 [13:54:12.504] ConfigFilePresence:: Current Watches: :: File: /Users/matb/projects/vscode/src/vs/base/common/tsconfig.json Currently impacted open files: RootsOfInferredProjects: OtherOpenFiles: /Users/matb/projects/vscode/src/vs/base/common/newPaging.ts Status: File added to open files impacted by this config file
Info 2098 [13:54:12.504] ConfigFilePresence:: Current Watches: :: File: /Users/matb/projects/vscode/src/vs/base/common/jsconfig.json Currently impacted open files: RootsOfInferredProjects: OtherOpenFiles: /Users/matb/projects/vscode/src/vs/base/common/newPaging.ts Status: File added to open files impacted by this config file
Info 2099 [13:54:12.508] ConfigFilePresence:: Current Watches: :: File: /Users/matb/projects/vscode/src/vs/base/tsconfig.json Currently impacted open files: RootsOfInferredProjects: OtherOpenFiles: /Users/matb/projects/vscode/src/vs/base/common/newPaging.ts Status: File added to open files impacted by this config file
Info 2100 [13:54:12.508] ConfigFilePresence:: Current Watches: :: File: /Users/matb/projects/vscode/src/vs/base/jsconfig.json Currently impacted open files: RootsOfInferredProjects: OtherOpenFiles: /Users/matb/projects/vscode/src/vs/base/common/newPaging.ts Status: File added to open files impacted by this config file
Info 2101 [13:54:12.508] ConfigFilePresence:: Current Watches: :: File: /Users/matb/projects/vscode/src/vs/tsconfig.json Currently impacted open files: RootsOfInferredProjects: OtherOpenFiles: /Users/matb/projects/vscode/src/vs/editor/contrib/codeAction/lightBulbWidget.ts,/Users/matb/projects/vscode/src/vs/editor/contrib/codeAction/codeActionCommands.ts,/Users/matb/projects/vscode/src/vs/editor/contrib/codeAction/test/codeActionModel.test.ts,/Users/matb/projects/vscode/src/vs/base/common/newPaging.ts Status: File added to open files impacted by this config file
Info 2102 [13:54:12.508] ConfigFilePresence:: Current Watches: :: File: /Users/matb/projects/vscode/src/vs/jsconfig.json Currently impacted open files: RootsOfInferredProjects: OtherOpenFiles: /Users/matb/projects/vscode/src/vs/editor/contrib/codeAction/lightBulbWidget.ts,/Users/matb/projects/vscode/src/vs/editor/contrib/codeAction/codeActionCommands.ts,/Users/matb/projects/vscode/src/vs/editor/contrib/codeAction/test/codeActionModel.test.ts,/Users/matb/projects/vscode/src/vs/base/common/newPaging.ts Status: File added to open files impacted by this config file
Info 2103 [13:54:12.509] ConfigFilePresence:: Current Watches: Config file for the program:: File: /Users/matb/projects/vscode/src/tsconfig.json Currently impacted open files: RootsOfInferredProjects: OtherOpenFiles: /Users/matb/projects/vscode/src/vs/editor/contrib/codeAction/lightBulbWidget.ts,/Users/matb/projects/vscode/src/vs/editor/contrib/codeAction/codeActionCommands.ts,/Users/matb/projects/vscode/src/vs/editor/contrib/codeAction/test/codeActionModel.test.ts,/Users/matb/projects/vscode/src/vs/base/common/newPaging.ts Status: File added to open files impacted by this config file
Info 2104 [13:54:12.509] For info: /Users/matb/projects/vscode/src/vs/base/common/newPaging.ts :: Config file name: /Users/matb/projects/vscode/src/tsconfig.json
Info 2105 [13:54:12.645] Starting updateGraphWorker: Project: /Users/matb/projects/vscode/src/tsconfig.json
Info 2106 [13:54:18.532] Finishing updateGraphWorker: Project: /Users/matb/projects/vscode/src/tsconfig.json Version: 5 structureChanged: true Elapsed: 5887ms
Info 2107 [13:54:18.536] Project '/Users/matb/projects/vscode/src/tsconfig.json' (Configured) 0
Info 2107 [13:54:18.537] Files (1772)
And the getEditsForFileRename call:
{"seq":43,"type":"request","command":"getEditsForFileRename","arguments":{"file":"/Users/matb/projects/vscode/src/vs/base/common/newPaging.ts","oldFilePath":"/Users/matb/projects/vscode/src/vs/base/common/paging.ts","newFilePath":"/Users/matb/projects/vscode/src/vs/base/common/newPaging.ts"}}
Perf 2118 [13:54:24.595] 43::getEditsForFileRename: elapsed time (in milliseconds) 6049.1891
Info 2119 [13:54:24.595] response:
{"seq":0,"type":"response","command":"getEditsForFileRename","request_seq":43,"success":true,"body":[{"fileName":"/Users/matb/projects/vscode/src/vs/base/browser/ui/list/listPaging.ts","textChanges":[{"start":{"line":11,"offset":30},"end":{"line":11,"offset":51},"newText":"vs/base/common/newPaging"}]},{"fileName":"/Users/matb/projects/vscode/src/vs/base/test/common/paging.test.ts","textChanges":[{"start":{"line":7,"offset":37},"end":{"line":7,"offset":58},"newText":"vs/base/common/newPaging"}]},{"fileName":"/Users/matb/projects/vscode/src/vs/platform/extensionManagement/common/extensionManagement.ts","textChanges":[{"start":{"line":8,"offset":25},"end":{"line":8,"offset":46},"newText":"vs/base/common/newPaging"}]},{"fileName":"/Users/matb/projects/vscode/src/vs/platform/extensionManagement/node/extensionGalleryService.ts","textChanges":[{"start":{"line":15,"offset":25},"end":{"line":15,"offset":46},"newText":"vs/base/common/newPaging"}]},{"fileName":"/Users/matb/projects/vscode/src/vs/workbench/parts/extensions/common/extensions.ts","textChanges":[{"start":{"line":9,"offset":25},"end":{"line":9,"offset":46},"newText":"vs/base/common/newPaging"}]},{"fileName":"/Users/matb/projects/vscode/src/vs/workbench/parts/extensions/electron-browser/extensionsActions.ts","textChanges":[{"start":{"line":39,"offset":29},"end":{"line":39,"offset":50},"newText":"vs/base/common/newPaging"}]},{"fileName":"/Users/matb/projects/vscode/src/vs/workbench/parts/extensions/node/extensionsWorkbenchService.ts","textChanges":[{"start":{"line":14,"offset":52},"end":{"line":14,"offset":73},"newText":"vs/base/common/newPaging"}]},{"fileName":"/Users/matb/projects/vscode/src/vs/workbench/parts/extensions/electron-browser/extensionsViews.ts","textChanges":[{"start":{"line":11,"offset":69},"end":{"line":11,"offset":90},"newText":"vs/base/common/newPaging"}]},{"fileName":"/Users/matb/projects/vscode/src/vs/workbench/parts/extensions/test/electron-browser/extensionsActions.test.ts","textChanges":[{"start":{"line":24,"offset":25},"end":{"line":24,"offset":46},"newText":"vs/base/common/newPaging"}]},{"fileName":"/Users/matb/projects/vscode/src/vs/workbench/parts/extensions/test/electron-browser/extensionsTipsService.test.ts","textChanges":[{"start":{"line":33,"offset":25},"end":{"line":33,"offset":46},"newText":"vs/base/common/newPaging"}]},{"fileName":"/Users/matb/projects/vscode/src/vs/workbench/parts/extensions/test/electron-browser/extensionsViews.test.ts","textChanges":[{"start":{"line":24,"offset":25},"end":{"line":24,"offset":46},"newText":"vs/base/common/newPaging"}]},{"fileName":"/Users/matb/projects/vscode/src/vs/workbench/parts/extensions/test/electron-browser/extensionsWorkbenchService.test.ts","textChanges":[{"start":{"line":25,"offset":25},"end":{"line":25,"offset":46},"newText":"vs/base/common/newPaging"}]}]}
Reactions are currently unavailable
Metadata
Metadata
Assignees
Labels
BugA bug in TypeScriptA bug in TypeScriptDomain: LS: TSServerIssues related to the TSServerIssues related to the TSServerDomain: PerformanceReports of unusually slow behaviorReports of unusually slow behaviorFixedA PR has been merged for this issueA PR has been merged for this issue
Activity
mjbvz commentedon Dec 14, 2018
Quick API usage question: do we (VS Code) need to actually open the new file (
newPaging.tsin this case) on TypeScript before we callgetEditsForFileRename? Not sure if that would fix the issue but I want to double check this[-]getEditsForFileRename[/-][+]getEditsForFileRename can take a long time on large project[/+]mjbvz commentedon Jan 7, 2019
Daniel Rosenwasser (@DanielRosenwasser) Can we investigate this for TS 3.3.5 or for 3.4? The delay currently causes a poor user experience, especially in large projects like VS Code
sheetalkamat commentedon Jan 8, 2019
Matt Bierner (@mjbvz) The quick look at the log shows that the
newPaging.tswas open before callinggetEditsForFileRename. I also noticed you had two configured projects open instead of just thepaging.tsone.getEditsForFileRenamewill go through all projects to find if it needs any edits.On my machine with just paging.ts open doing rename was about 2s and with all the files that you had open, (with 2 config projects open) it took 3s so the other project definitely changes the numbers as expected.
I haven't look at the code in detail for this so now looking to see how things can be improved.
sheetalkamat commentedon Jan 8, 2019
https://github.com/Microsoft/TypeScript/blob/master/src/services/getEditsForFileRename.ts#L216 this seems to be the culprit with 4727ms of 5671ms spent to check if file exists on old file.
There is no need to check for file presence when trying to rename imp…
2 remaining items
DanielRosenwasser commentedon Jan 9, 2019
Matt Bierner (@mjbvz) would VS Code adopt 3.2.5?
mjbvz commentedon Jan 9, 2019
Sure, depending on when 3.2.5 would ship we could either pick it up by the end of January for VS Code 1.31 or in February for VS Code 1.32
mjbvz commentedon Jan 9, 2019
Never mind, misread the version as 3.3.5. No, we do not plan to pick up any more TS 3.2.x releases.
DanielRosenwasser commentedon Jan 9, 2019
Then nope, no porting necessary.
DanielRosenwasser commentedon Jan 9, 2019
Awesome work Sheetal!
Merge remote-tracking branch 'origin/master' into debug-messages
OliverJAsh commentedon Mar 20, 2019
Coming here from microsoft/vscode#65112 via microsoft/vscode#64986. Running TS 3.3.333, this still seems to be an issue. Unfortunately I can't easily share a repro because it's a large project…
Niaro commentedon Apr 27, 2020
Matt Bierner (@mjbvz) Yeap, this is still an issue. In a monorepo it takes a huge amount of time to update affected files.
mjbvz commentedon Apr 27, 2020
George Evstigneev (@Niaro) See #30535
If you still see this issue when using TypeScript 3.9+ in your workspace (install this extension to quickly test) please file a new issue with more information about your project