From 6329a0df900ca13c2599634db5be967c0a513d2b Mon Sep 17 00:00:00 2001 From: Sheetal Nandi Date: Thu, 27 May 2021 11:14:12 -0700 Subject: [PATCH] Add traces for module resolution reuse (#44282) --- src/compiler/diagnosticMessages.json | 44 +++++++++++++- src/compiler/program.ts | 10 +++- src/compiler/resolutionCache.ts | 48 +++++++++++++++ .../unittests/reuseProgramStructure.ts | 20 +++---- .../unittests/tsserver/resolutionCache.ts | 60 ++++++++++++++----- 5 files changed, 154 insertions(+), 28 deletions(-) diff --git a/src/compiler/diagnosticMessages.json b/src/compiler/diagnosticMessages.json index e8d52eadb6..c71967b2ea 100644 --- a/src/compiler/diagnosticMessages.json +++ b/src/compiler/diagnosticMessages.json @@ -4637,11 +4637,11 @@ "category": "Message", "code": 6182 }, - "Reusing resolution of module '{0}' to file '{1}' from old program.": { + "Reusing resolution of module '{0}' from '{1}' of old program, it was successfully resolved to '{2}'.": { "category": "Message", "code": 6183 }, - "Reusing module resolutions originating in '{0}' since resolutions are unchanged from old program.": { + "Reusing resolution of module '{0}' from '{1}' of old program, it was successfully resolved to '{2}' with Package ID '{3}'.": { "category": "Message", "code": 6184 }, @@ -5073,6 +5073,46 @@ "category": "Message", "code": 6388 }, + "Reusing resolution of module '{0}' from '{1}' of old program, it was not resolved.": { + "category": "Message", + "code": 6389 + }, + "Reusing resolution of type reference directive '{0}' from '{1}' of old program, it was successfully resolved to '{2}'.": { + "category": "Message", + "code": 6390 + }, + "Reusing resolution of type reference directive '{0}' from '{1}' of old program, it was successfully resolved to '{2}' with Package ID '{3}'.": { + "category": "Message", + "code": 6391 + }, + "Reusing resolution of type reference directive '{0}' from '{1}' of old program, it was not resolved.": { + "category": "Message", + "code": 6392 + }, + "Reusing resolution of module '{0}' from '{1}' found in cache from location '{2}', it was successfully resolved to '{3}'.": { + "category": "Message", + "code": 6393 + }, + "Reusing resolution of module '{0}' from '{1}' found in cache from location '{2}', it was successfully resolved to '{3}' with Package ID '{4}'.": { + "category": "Message", + "code": 6394 + }, + "Reusing resolution of module '{0}' from '{1}' found in cache from location '{2}', it was not resolved.": { + "category": "Message", + "code": 6395 + }, + "Reusing resolution of type reference directive '{0}' from '{1}' found in cache from location '{2}', it was successfully resolved to '{3}'.": { + "category": "Message", + "code": 6396 + }, + "Reusing resolution of type reference directive '{0}' from '{1}' found in cache from location '{2}', it was successfully resolved to '{3}' with Package ID '{4}'.": { + "category": "Message", + "code": 6397 + }, + "Reusing resolution of type reference directive '{0}' from '{1}' found in cache from location '{2}', it was not resolved.": { + "category": "Message", + "code": 6398 + }, "The expected type comes from property '{0}' which is declared here on type '{1}'": { "category": "Message", diff --git a/src/compiler/program.ts b/src/compiler/program.ts index 82b8b209f8..ad71fe075d 100644 --- a/src/compiler/program.ts +++ b/src/compiler/program.ts @@ -1288,7 +1288,15 @@ namespace ts { const oldResolvedModule = getResolvedModule(oldSourceFile, moduleName); if (oldResolvedModule) { if (isTraceEnabled(options, host)) { - trace(host, Diagnostics.Reusing_resolution_of_module_0_to_file_1_from_old_program, moduleName, getNormalizedAbsolutePath(file.originalFileName, currentDirectory)); + trace(host, + oldResolvedModule.packageId ? + Diagnostics.Reusing_resolution_of_module_0_from_1_of_old_program_it_was_successfully_resolved_to_2_with_Package_ID_3 : + Diagnostics.Reusing_resolution_of_module_0_from_1_of_old_program_it_was_successfully_resolved_to_2, + moduleName, + getNormalizedAbsolutePath(file.originalFileName, currentDirectory), + oldResolvedModule.resolvedFileName, + oldResolvedModule.packageId && packageIdToString(oldResolvedModule.packageId) + ); } (result || (result = new Array(moduleNames.length)))[i] = oldResolvedModule; (reusedNames || (reusedNames = [])).push(moduleName); diff --git a/src/compiler/resolutionCache.ts b/src/compiler/resolutionCache.ts index 617fb795ee..bccb5af9b5 100644 --- a/src/compiler/resolutionCache.ts +++ b/src/compiler/resolutionCache.ts @@ -38,6 +38,7 @@ namespace ts { interface ResolutionWithResolvedFileName { resolvedFileName: string | undefined; + packagetId?: PackageId; } interface CachedResolvedModuleWithFailedLookupLocations extends ResolvedModuleWithFailedLookupLocations, ResolutionWithFailedLookupLocations { @@ -396,6 +397,29 @@ namespace ts { const resolutionInDirectory = perDirectoryResolution.get(name); if (resolutionInDirectory) { resolution = resolutionInDirectory; + const host = resolutionHost.getCompilerHost?.() || resolutionHost; + if (isTraceEnabled(compilerOptions, host)) { + const resolved = getResolutionWithResolvedFileName(resolution); + trace( + host, + loader === resolveModuleName as unknown ? + resolved?.resolvedFileName ? + resolved.packagetId ? + Diagnostics.Reusing_resolution_of_module_0_from_1_found_in_cache_from_location_2_it_was_successfully_resolved_to_3_with_Package_ID_4: + Diagnostics.Reusing_resolution_of_module_0_from_1_found_in_cache_from_location_2_it_was_successfully_resolved_to_3: + Diagnostics.Reusing_resolution_of_module_0_from_1_found_in_cache_from_location_2_it_was_not_resolved : + resolved?.resolvedFileName ? + resolved.packagetId ? + Diagnostics.Reusing_resolution_of_type_reference_directive_0_from_1_found_in_cache_from_location_2_it_was_successfully_resolved_to_3_with_Package_ID_4 : + Diagnostics.Reusing_resolution_of_type_reference_directive_0_from_1_found_in_cache_from_location_2_it_was_successfully_resolved_to_3 : + Diagnostics.Reusing_resolution_of_type_reference_directive_0_from_1_found_in_cache_from_location_2_it_was_not_resolved, + name, + containingFile, + getDirectoryPath(containingFile), + resolved?.resolvedFileName, + resolved?.packagetId && packageIdToString(resolved.packagetId) + ); + } } else { resolution = loader(name, containingFile, compilerOptions, resolutionHost.getCompilerHost?.() || resolutionHost, redirectedReference); @@ -413,6 +437,30 @@ namespace ts { logChanges = false; } } + else { + const host = resolutionHost.getCompilerHost?.() || resolutionHost; + if (isTraceEnabled(compilerOptions, host) && !seenNamesInFile.has(name)) { + const resolved = getResolutionWithResolvedFileName(resolution); + trace( + host, + loader === resolveModuleName as unknown ? + resolved?.resolvedFileName ? + resolved.packagetId ? + Diagnostics.Reusing_resolution_of_module_0_from_1_of_old_program_it_was_successfully_resolved_to_2_with_Package_ID_3 : + Diagnostics.Reusing_resolution_of_module_0_from_1_of_old_program_it_was_successfully_resolved_to_2 : + Diagnostics.Reusing_resolution_of_module_0_from_1_of_old_program_it_was_not_resolved : + resolved?.resolvedFileName ? + resolved.packagetId ? + Diagnostics.Reusing_resolution_of_type_reference_directive_0_from_1_of_old_program_it_was_successfully_resolved_to_2_with_Package_ID_3 : + Diagnostics.Reusing_resolution_of_type_reference_directive_0_from_1_of_old_program_it_was_successfully_resolved_to_2 : + Diagnostics.Reusing_resolution_of_type_reference_directive_0_from_1_of_old_program_it_was_not_resolved, + name, + containingFile, + resolved?.resolvedFileName, + resolved?.packagetId && packageIdToString(resolved.packagetId) + ); + } + } Debug.assert(resolution !== undefined && !resolution.isInvalidated); seenNamesInFile.set(name, true); resolvedModules.push(getResolutionWithResolvedFileName(resolution)); diff --git a/src/testRunner/unittests/reuseProgramStructure.ts b/src/testRunner/unittests/reuseProgramStructure.ts index 41192ac962..2face82e2d 100644 --- a/src/testRunner/unittests/reuseProgramStructure.ts +++ b/src/testRunner/unittests/reuseProgramStructure.ts @@ -677,8 +677,8 @@ namespace ts { "File 'node_modules/@types/typerefs2/package.json' does not exist.", "File 'node_modules/@types/typerefs2/index.d.ts' exist - use it as a name resolution result.", "======== Type reference directive 'typerefs2' was successfully resolved to 'node_modules/@types/typerefs2/index.d.ts', primary: true. ========", - "Reusing resolution of module './b2' to file 'f2.ts' from old program.", - "Reusing resolution of module './f1' to file 'f2.ts' from old program." + "Reusing resolution of module './b2' from 'f2.ts' of old program, it was successfully resolved to 'b2.ts'.", + "Reusing resolution of module './f1' from 'f2.ts' of old program, it was successfully resolved to 'f1.ts'." ], "program2: reuse module resolutions in f2 since it is unchanged"); } @@ -701,8 +701,8 @@ namespace ts { "File 'node_modules/@types/typerefs2/package.json' does not exist.", "File 'node_modules/@types/typerefs2/index.d.ts' exist - use it as a name resolution result.", "======== Type reference directive 'typerefs2' was successfully resolved to 'node_modules/@types/typerefs2/index.d.ts', primary: true. ========", - "Reusing resolution of module './b2' to file 'f2.ts' from old program.", - "Reusing resolution of module './f1' to file 'f2.ts' from old program." + "Reusing resolution of module './b2' from 'f2.ts' of old program, it was successfully resolved to 'b2.ts'.", + "Reusing resolution of module './f1' from 'f2.ts' of old program, it was successfully resolved to 'f1.ts'." ], "program3: reuse module resolutions in f2 since it is unchanged"); } @@ -726,8 +726,8 @@ namespace ts { "File 'node_modules/@types/typerefs2/package.json' does not exist.", "File 'node_modules/@types/typerefs2/index.d.ts' exist - use it as a name resolution result.", "======== Type reference directive 'typerefs2' was successfully resolved to 'node_modules/@types/typerefs2/index.d.ts', primary: true. ========", - "Reusing resolution of module './b2' to file 'f2.ts' from old program.", - "Reusing resolution of module './f1' to file 'f2.ts' from old program." + "Reusing resolution of module './b2' from 'f2.ts' of old program, it was successfully resolved to 'b2.ts'.", + "Reusing resolution of module './f1' from 'f2.ts' of old program, it was successfully resolved to 'f1.ts'.", ], "program_4: reuse module resolutions in f2 since it is unchanged"); } @@ -767,8 +767,8 @@ namespace ts { "File 'node_modules/@types/typerefs2/package.json' does not exist.", "File 'node_modules/@types/typerefs2/index.d.ts' exist - use it as a name resolution result.", "======== Type reference directive 'typerefs2' was successfully resolved to 'node_modules/@types/typerefs2/index.d.ts', primary: true. ========", - "Reusing resolution of module './b2' to file 'f2.ts' from old program.", - "Reusing resolution of module './f1' to file 'f2.ts' from old program." + "Reusing resolution of module './b2' from 'f2.ts' of old program, it was successfully resolved to 'b2.ts'.", + "Reusing resolution of module './f1' from 'f2.ts' of old program, it was successfully resolved to 'f1.ts'.", ], "program_6: reuse module resolutions in f2 since it is unchanged"); } @@ -787,8 +787,8 @@ namespace ts { "File 'node_modules/@types/typerefs2/package.json' does not exist.", "File 'node_modules/@types/typerefs2/index.d.ts' exist - use it as a name resolution result.", "======== Type reference directive 'typerefs2' was successfully resolved to 'node_modules/@types/typerefs2/index.d.ts', primary: true. ========", - "Reusing resolution of module './b2' to file 'f2.ts' from old program.", - "Reusing resolution of module './f1' to file 'f2.ts' from old program." + "Reusing resolution of module './b2' from 'f2.ts' of old program, it was successfully resolved to 'b2.ts'.", + "Reusing resolution of module './f1' from 'f2.ts' of old program, it was successfully resolved to 'f1.ts'.", ], "program_7 should reuse module resolutions in f2 since it is unchanged"); } }); diff --git a/src/testRunner/unittests/tsserver/resolutionCache.ts b/src/testRunner/unittests/tsserver/resolutionCache.ts index d3d4ff1361..2506acfdcb 100644 --- a/src/testRunner/unittests/tsserver/resolutionCache.ts +++ b/src/testRunner/unittests/tsserver/resolutionCache.ts @@ -515,6 +515,10 @@ namespace ts.projectSystem { expectedTrace.push(`======== Module name '${moduleName}' was successfully resolved to '${module.path}'. ========`); } + function getExpectedModuleResolutionFromCacheTrace(containingFile: File, module: File, moduleName: string, cacheLocation: string): string { + return `Reusing resolution of module '${moduleName}' from '${containingFile.path}' found in cache from location '${cacheLocation}', it was successfully resolved to '${module.path}'.`; + } + function getExpectedRelativeModuleResolutionTrace(host: TestServerHost, file: File, module: File, moduleName: string, expectedTrace: string[] = []) { getExpectedResolutionTraceHeader(expectedTrace, file, moduleName); expectedTrace.push(`Loading module as file / folder, candidate module location '${removeFileExtension(module.path)}', target file type 'TypeScript'.`); @@ -540,8 +544,8 @@ namespace ts.projectSystem { return expectedTrace; } - function getExpectedReusingResolutionFromOldProgram(file: File, moduleName: string) { - return `Reusing resolution of module '${moduleName}' to file '${file.path}' from old program.`; + function getExpectedReusingResolutionFromOldProgram(file: File, moduleFile: File, moduleName: string) { + return `Reusing resolution of module '${moduleName}' from '${file.path}' of old program, it was successfully resolved to '${moduleFile.path}'.`; } function verifyWatchesWithConfigFile(host: TestServerHost, files: File[], openFile: File, extraExpectedDirectories?: readonly string[]) { @@ -587,6 +591,8 @@ namespace ts.projectSystem { service.openClientFile(file1.path); const expectedTrace = getExpectedRelativeModuleResolutionTrace(host, file1, module1, module1Name); getExpectedRelativeModuleResolutionTrace(host, file1, module2, module2Name, expectedTrace); + expectedTrace.push(getExpectedModuleResolutionFromCacheTrace(file2, module1, module1Name, `${tscWatch.projectRoot}/src`)); + expectedTrace.push(getExpectedModuleResolutionFromCacheTrace(file2, module2, module2Name, `${tscWatch.projectRoot}/src`)); verifyTrace(resolutionTrace, expectedTrace); verifyWatchesWithConfigFile(host, files, file1); @@ -594,8 +600,10 @@ namespace ts.projectSystem { host.writeFile(file2.path, file2.content + fileContent); host.runQueuedTimeoutCallbacks(); verifyTrace(resolutionTrace, [ - getExpectedReusingResolutionFromOldProgram(file1, module1Name), - getExpectedReusingResolutionFromOldProgram(file1, module2Name) + getExpectedReusingResolutionFromOldProgram(file1, module1, module1Name), + getExpectedReusingResolutionFromOldProgram(file1, module2, module2Name), + getExpectedReusingResolutionFromOldProgram(file2, module1, module1Name), + getExpectedReusingResolutionFromOldProgram(file2, module2, module2Name), ]); verifyWatchesWithConfigFile(host, files, file1); }); @@ -614,6 +622,8 @@ namespace ts.projectSystem { service.openClientFile(file1.path); const expectedTrace = getExpectedNonRelativeModuleResolutionTrace(host, file1, module1, module1Name); getExpectedNonRelativeModuleResolutionTrace(host, file1, module2, module2Name, expectedTrace); + expectedTrace.push(getExpectedModuleResolutionFromCacheTrace(file2, module1, module1Name, `${tscWatch.projectRoot}/src`)); + expectedTrace.push(getExpectedModuleResolutionFromCacheTrace(file2, module2, module2Name, `${tscWatch.projectRoot}/src`)); verifyTrace(resolutionTrace, expectedTrace); verifyWatchesWithConfigFile(host, files, file1, expectedNonRelativeDirectories); @@ -621,8 +631,10 @@ namespace ts.projectSystem { host.writeFile(file2.path, file2.content + fileContent); host.runQueuedTimeoutCallbacks(); verifyTrace(resolutionTrace, [ - getExpectedReusingResolutionFromOldProgram(file1, module1Name), - getExpectedReusingResolutionFromOldProgram(file1, module2Name) + getExpectedReusingResolutionFromOldProgram(file1, module1, module1Name), + getExpectedReusingResolutionFromOldProgram(file1, module2, module2Name), + getExpectedReusingResolutionFromOldProgram(file2, module1, module1Name), + getExpectedReusingResolutionFromOldProgram(file2, module2, module2Name), ]); verifyWatchesWithConfigFile(host, files, file1, expectedNonRelativeDirectories); }); @@ -685,8 +697,14 @@ namespace ts.projectSystem { host.runQueuedTimeoutCallbacks(); verifyTrace(resolutionTrace, [ - getExpectedReusingResolutionFromOldProgram(file1, module1Name), - getExpectedReusingResolutionFromOldProgram(file1, module2Name) + getExpectedReusingResolutionFromOldProgram(file1, module1, module1Name), + getExpectedReusingResolutionFromOldProgram(file1, module2, module2Name), + getExpectedReusingResolutionFromOldProgram(file2, module1, module3Name), + getExpectedReusingResolutionFromOldProgram(file2, module2, module4Name), + getExpectedReusingResolutionFromOldProgram(file4, module1, module6Name), + getExpectedReusingResolutionFromOldProgram(file4, module2, module2Name), + getExpectedReusingResolutionFromOldProgram(file3, module1, module5Name), + getExpectedReusingResolutionFromOldProgram(file3, module2, module4Name), ]); verifyWatchesWithConfigFile(host, files, file1); }); @@ -721,8 +739,14 @@ namespace ts.projectSystem { host.runQueuedTimeoutCallbacks(); verifyTrace(resolutionTrace, [ - getExpectedReusingResolutionFromOldProgram(file1, module1Name), - getExpectedReusingResolutionFromOldProgram(file1, module2Name) + getExpectedReusingResolutionFromOldProgram(file1, module1, module1Name), + getExpectedReusingResolutionFromOldProgram(file1, module2, module2Name), + getExpectedReusingResolutionFromOldProgram(file2, module1, module1Name), + getExpectedReusingResolutionFromOldProgram(file2, module2, module2Name), + getExpectedReusingResolutionFromOldProgram(file4, module1, module1Name), + getExpectedReusingResolutionFromOldProgram(file4, module2, module2Name), + getExpectedReusingResolutionFromOldProgram(file3, module1, module1Name), + getExpectedReusingResolutionFromOldProgram(file3, module2, module2Name), ]); verifyWatchesWithConfigFile(host, files, file1, expectedNonRelativeDirectories); }); @@ -772,11 +796,17 @@ namespace ts.projectSystem { host.runQueuedTimeoutCallbacks(); verifyTrace(resolutionTrace, [ - getExpectedReusingResolutionFromOldProgram(file1, file2Name), - getExpectedReusingResolutionFromOldProgram(file1, file4Name), - getExpectedReusingResolutionFromOldProgram(file1, file3Name), - getExpectedReusingResolutionFromOldProgram(file1, module1Name), - getExpectedReusingResolutionFromOldProgram(file1, module2Name) + getExpectedReusingResolutionFromOldProgram(file1, file2, file2Name), + getExpectedReusingResolutionFromOldProgram(file1, file4, file4Name), + getExpectedReusingResolutionFromOldProgram(file1, file3, file3Name), + getExpectedReusingResolutionFromOldProgram(file1, module1, module1Name), + getExpectedReusingResolutionFromOldProgram(file1, module2, module2Name), + getExpectedReusingResolutionFromOldProgram(file2, module1, module1Name), + getExpectedReusingResolutionFromOldProgram(file2, module2, module2Name), + getExpectedReusingResolutionFromOldProgram(file4, module1, module1Name), + getExpectedReusingResolutionFromOldProgram(file4, module2, module2Name), + getExpectedReusingResolutionFromOldProgram(file3, module1, module1Name), + getExpectedReusingResolutionFromOldProgram(file3, module2, module2Name), ]); checkWatches();