Tests are running much slower in 7.0.0-alpha.1 with --no-cache

[Ludevik]

My setup:
babel-preset-env: 1.7.0,
jest: 23.6.0,
jest-preset-angular: 7.0.0-alpha.1,
jest-sonar-reporter: 2.0.0,

I am using babel-jest to process *.js files.

I am trying to upgrade from 6.0.0 -> 7.0.0-alpha.1. I am running jest with:
npm run jest -- --no-cache and observing that the time required to finish tests goes up from ~120s to around 950s. When i enable the cache, then the first run is slow, but consecutive run is much faster (same as in version 6.0.0) - around 30s.

Anyone else experiencing same behavior?
What could be the cause for this, where should i look?

[thymikee]

Please don't run Jest with no-cache, otherwise there's no point in using it.

In v7.0.0 we changed the transformer (a thing that lets Jest understand TypeScript and Angular code) from simple regex (fast but inaccurate) to TypeScript AST transformer (slow but accurate).
It's expected for the first run to be slow, but every subsequent one should be much faster (as you experienced).

Closing, as this is not the issue. In fact, your tests are running faster now, possibly because of other optimisations made by ts-jest team

[Ludevik]

@thymikee --no-cache just exaggerates the time needed to run tests. I use that only to see how long it takes the first time. Even single test runs too long when the cache could not be used for some reason.

I think there is some problem, probably something wrong with my setup regarding ts-jest. I've put some console logs into InlineHtmlStripStylesTransformer, specifically into visitor to measure how long it takes to visit a node. Node visit was quite fast and wasn't the thing clogging the process and it didn't seem that the switch to astTransformer alone was responsible for added 800s to tests run. I added logs into transfromDecoratorForJest as well and i have found out that transfromDecoratorForJest is called multiple times for same component:

    var assignments = getPropertyAssignmentsToTransform(mutable);
    assignments.forEach(function (assignment) {
        **console.log('Assignment initializer', assignment.initializer.text);
        console.log('Assignment', assignment.name.text);**
        switch (assignment.name.text) {
            case TEMPLATE_URL: 

results in:

    Assignment initializer ./alert.component.html
    Assignment templateUrl
    Assignment initializer ./alert.component.html
    Assignment templateUrl
    ... 7 times

Is that expected behavior?

I also played with jest.config.js. I have one library and one app in my workspace and i am using moduleNameMapper:

    moduleNameMapper: {
         'app/(.*)': '<rootDir>/src/app/$1',
         'mocks/(.*)': '<rootDir>/src/mocks/$1',
         'shared': '<rootDir>/src/shared',
         'environments/(.*)': '<rootDir>/src/environments/$1'
    }

app is the application, shared is the library. When i changed library mapping to:
'shared': '<rootDir>/dist/shared', where dist is the directory where the library is built, the time to run tests without cache went down to 600s and each component was visited only once. Still it seems too much time, there is still something going between visits.
I will investigate more and post the results here.

[thymikee]

Cc @wtho

[wtho]

Interesting, I will have a look at how many times the transform gets called.
Indeed it is expensive to make a node mutable and change properties, but we try to make sure we only do it when necessary.

The implementation of the transformer changed since the last release (modifies assignments instead of decorators), so I will just check the newer implementation.

@Ludevik Maybe you can measure the performance another time with the current master? Would be awesome!

[thymikee]

Released latest changes to jest-preset-angular@next, it's tagged v7.0.0-alpha.2

[wtho]

@Ludevik so I checked the example app and it seems to work just fine with the current implementation, every assignment is modified a single time.

Just a guess: If jest loads the component several times (e. g. from different test files) and caching is turned off, the file gets processed several times. Maybe you add another log just inside createVisitor where you can log the path of the file being processed (_.path) to see if the same visitor instance changed the same assignments (which should clearly not happen) or it is different visitors.

Otherwise it can be ts-jest itself. ts-jest 23.10 is a complete rewrite and they handle things very differently now, so there might be unknown performance issues. We added the transformer to make Angular work with it, but we are not aware of performance issues with ts-jest 23.10 so far.

Thanks for sharing and trying out the alpha! Hopefully we get more feedback and can identify the origin of the slowdown.

[Ludevik]

@wtho @thymikee thanks.
I have tested with alpha.2 and it is a bit faster. I'm currently at ~500s with --no-cache and 300s on the first run after --clearCache. I've put log into create visitor function and it is called multiple times for some .ts files, it depends on the situation. Jest spawns 7 threads on my machine to run the tests and each of that thread transforms .ts and .js files on its own, so some of the files are transformed multiple times, up to 7 times.
I understand now why each of my file in library is transformed 7 times when i change the mapping from dist to src. It is because when i tell jest to use dist folder it doesn't need to transform my library as it is already compiled to .js. When i ran my tests with src then i got 7 hits in createVisitor for my library's index.ts files which in turn transforms 7 times every exported library file.

I will write a question to ts-jest directly as jest-preset-angular just uses that and it seems that the astTransformer is quite fast.

[ahnpnl]

FYI, this might be one of the causes of performance

[AndriiShpak]

Also tried upgrade to alpha version and timing difference was impossible to work with, so I had to revert the change. Let's hope that it is going to be fixed inside ts-jest lib.
Anyway I would recommend to reopen the issue just for people to find it easily (had to dig a little to get here)