Massive performance degradation in getCacheKey()

[Trainmaster]

🐛 Bug Report

The getCacheKey() function seems to degradate as the amount of files increases. I observed this in a project with a few thousands of files when upgrading from Jest 26 to 27.

To Reproduce

A few hundreds of files which have to be transformed.

Expected behavior

Performance remains constant.

Link to repo (highly encouraged)

Unfortunately I can't share the repo. But I added some logging to that function.

jest@27.0.5 ts-jest@27.0.3

# node_modules/ts-jest/dist/ts-jest-transformer.js

var i = 0;
// ...
TsJestTransformer.prototype.getCacheKey = function (fileContent, filePath, transformOptions) {
    var start = new Date().getTime();
    var _a;
    var configs = this._configsFor(transformOptions);
    this._logger.debug({ fileName: filePath, transformOptions: transformOptions }, 'computing cache key for', filePath);
    var _b = transformOptions.instrument, instrument = _b === void 0 ? false : _b;
    var constructingCacheKeyElements = [
        this._transformCfgStr,
        exports.CACHE_KEY_EL_SEPARATOR,
        configs.rootDir,
        exports.CACHE_KEY_EL_SEPARATOR,
        "instrument:" + (instrument ? 'on' : 'off'),
        exports.CACHE_KEY_EL_SEPARATOR,
        fileContent,
        exports.CACHE_KEY_EL_SEPARATOR,
        filePath,
    ];
    if (!configs.isolatedModules && this._tsResolvedModulesCachePath) {
        var resolvedModuleNames = void 0;
        if (((_a = this._depGraphs.get(filePath)) === null || _a === void 0 ? void 0 : _a.fileContent) === fileContent) {
            this._logger.debug({ fileName: filePath, transformOptions: transformOptions }, 'getting resolved modules from disk caching or memory caching for', filePath);
            resolvedModuleNames = this._depGraphs
                .get(filePath)
                .resolvedModuleNames.filter(function (moduleName) { return fs_1.existsSync(moduleName); });
        }
        else {
            this._logger.debug({ fileName: filePath, transformOptions: transformOptions }, 'getting resolved modules from TypeScript API for', filePath);
            resolvedModuleNames = this._compiler.getResolvedModules(fileContent, filePath, transformOptions.cacheFS);
            this._depGraphs.set(filePath, {
                fileContent: fileContent,
                resolvedModuleNames: resolvedModuleNames,
            });
            fs_1.writeFileSync(this._tsResolvedModulesCachePath, json_1.stringify(__spreadArray([], __read(this._depGraphs))));
        }
        resolvedModuleNames.forEach(function (moduleName) {
            constructingCacheKeyElements.push(exports.CACHE_KEY_EL_SEPARATOR, moduleName, exports.CACHE_KEY_EL_SEPARATOR, fs_1.statSync(moduleName).mtimeMs.toString());
        });
    }
    var end = new Date().getTime();
    console.error('_getCacheKey #' + i + ' ' + (end - start));
    i++
    return sha1_1.sha1.apply(void 0, __spreadArray([], __read(constructingCacheKeyElements)));
};

# Start
_getCacheKey #0 5503
_getCacheKey #1 0
_getCacheKey #2 12
_getCacheKey #3 9
_getCacheKey #4 42

# It's getting worse
_getCacheKey #500 18
_getCacheKey #501 21
_getCacheKey #502 18
_getCacheKey #503 19
_getCacheKey #504 18

# And worse (until all memory is used and system freezes)
_getCacheKey #1000 39
_getCacheKey #1001 39
_getCacheKey #1002 39
_getCacheKey #1003 42
_getCacheKey #1004 45

With Jest 26 everything is fine:

jest@26.6.3 ts-jest@26.5.6

# node_modules/ts-jest/dist/ts-jest-transformer.js

var i = 0;
// ...
TsJestTransformer.prototype.getCacheKey = function (fileContent, filePath, _jestConfigStr, transformOptions) {
    var start = new Date().getTime();
    var configs = this.configsFor(transformOptions.config);
    this.logger.debug({ fileName: filePath, transformOptions: transformOptions }, 'computing cache key for', filePath);
    var _a = transformOptions.instrument, instrument = _a === void 0 ? false : _a, _b = transformOptions.rootDir, rootDir = _b === void 0 ? configs.rootDir : _b;
    var end = new Date().getTime();
    console.error('_getCacheKey #' + i + ' ' + (end - start));
    i++
    return sha1_1.sha1(this._transformCfgStr, '\x00', rootDir, '\x00', "instrument:" + (instrument ? 'on' : 'off'), '\x00', fileContent, '\x00', filePath);
};

# Start
_getCacheKey #0 104
_getCacheKey #1 0
_getCacheKey #2 0
_getCacheKey #3 0
_getCacheKey #4 0

# Still fast
_getCacheKey #500 0
_getCacheKey #501 0
_getCacheKey #502 0
_getCacheKey #503 0
_getCacheKey #504 0

# No degradation after 1000 files
_getCacheKey #1000 0
_getCacheKey #1001 0
_getCacheKey #1002 0
_getCacheKey #1003 0
_getCacheKey #1004 0

envinfo

System:
    OS: Ubuntu 18.04.1
    Node version: v14.15.5

Npm packages:
    jest: 27.0.5
    ts-jest: 27.0.3
    typescript: 4.2.4
    babel(optional): 7.14.6

[ahnpnl]

in v27, we did a fix for watch mode as well as normal mode to fix issues with type checking not perform correctly. The solution requires to add processing file's related files into cache key to inform Jest later that if any related files change, Jest needs to reprocess. For example:

• File A has 2 related files B,C
• Key cache is then created by combination of A, B, C
• Later B is changed, which will lead to A needs to be re type checked if A is processed again by ts-jest.

v26 doesn't have this solution which explained your observation. The solution was came up because ts-jest only performs type check in process function instead of getCacheKey.

[Xaz16]

If I right understand the problem all my test runs start to use most of available memory and in some cases like CI (bitbucket pipelines) where you have memory limits it starts fail. On jest 26 packages everything is ok.

[ahnpnl]

This is related to design choice. To fix this, the design needs to be changed which will be related to #2707 and all #2707 related issues.

[anton-gorbikov]

Experiencing the same issue. We have 300+ Angular tests and I can't even run them locally after migration. ts-jest consumes 60 GB of memory (16 RAM + 45 swap) and my macOS just crashes. Rollback to jest@26 fixes the issue.

[Xaz16]

In our case, we are suffering from this "design choice" and just put "--no-cache" to command that runs tests and see 2-3x performance "boost" due to ts-jest have no cache and have no performance degradation

One angular project that tests by 6m now runs by 2m40s

[gms1]

In our case, having a cold jest-cache takes 4 times longer than running jest with --no-cache.

But in our multi-project nx-workspace, using the nx-cli, the jest-cache cannot be properly deactivated, so we would have to run jest directly and therefore would also lose the advantage of the nx-cache.

So for us, enabling the "isolatedModules" options seems to be the only usable workaround, which is even 26% faster than running with --no-cache

[CSchulz]

Wouldn't it be a solution for CI environments to restore the old getCacheKey implementation?
CI have their fixed types and it won't change on the fly like on a developer machine.

[drrnkin]

This is related to design choice. To fix this, the design needs to be changed which will be related to #2707 and all #2707 related issues.

I logged #2707 and closely-related #1747. In the first, I added a comment that I had eventually implemented a workaround for that bug. Maybe this design change should be rolled back for the sake of performance in the short term. It's a choice of which bug is worse.