Stryker: Ran out of memory with large angular application

Created on 6 Nov 2018  ·  14Comments  ·  Source: stryker-mutator/stryker

Summary

When running stryker in a large angular application (Found 2 of 1615 file(s) to be mutated) with jest I'm getting errors. Before I increased the timeout I only got a timeout error. After increasing a out of memory error is displayed:

18:14:47 (53635) TRACE ChildProcessProxy
<--- Last few GCs --->

[53637:0x102802a00]   135067 ms: Scavenge 1292.2 (1440.0) -> 1281.0 (1442.5) MB, 9.0 / 0.0 ms  (average mu = 0.252, current mu = 0.226) allocation failure
[53637:0x102802a00]   136011 ms: Mark-sweep 1293.8 (1442.5) -> 1278.1 (1439.0) MB, 864.3 / 0.0 ms  (average mu = 0.222, current mu = 0.190) allocation failure scavenge might not succeed
[53637:0x102802a00]   136113 ms: Scavenge 1294.4 (1439.0) -> 1284.4 (1441.0) MB, 9.4 / 0.0 ms  (average mu = 0.222, current mu = 0.190) allocation failure


<--- JS stacktrace --->

==== JS stack trace =========================================

    0: ExitFrame [pc: 0x1b245195c01d]
Security context: 0x06613861e681 <JSObject>
    1: eventTargetPatch(aka eventTargetPatch) [0x661062e07f1] [/Users/---/development/control-panel/node_modules/zone.js/dist/zone.js:~2713] [pc=0x1b24554b0ec2](this=0x0661e58026f1 <undefined>,_global=0x0661062e08f9 <JSGlobal Object>,api=0x0661062e0889 <Object map = 0x66194d6e681>)
    2: /* anonymous */(aka /* anonymous */) [0x661062e0919] [/U...


18:14:47 (53635) TRACE ChildProcessProxy FATAL ERROR: Ineffective mark-compacts near heap limit Allocation failed - JavaScript heap out of memory
 1: 0x100039dbf node::Abort() [/usr/local/bin/node]
 2: 0x100039fc9 node::OnFatalError(char const*, char const*) [/usr/local/bin/node]

18:14:47 (53635) TRACE ChildProcessProxy  3: 0x1001d1375 v8::internal::V8::FatalProcessOutOfMemory(v8::internal::Isolate*, char const*, bool) [/usr/local/bin/node]

18:14:47 (53635) TRACE ChildProcessProxy  4: 0x10059c572 v8::internal::Heap::FatalProcessOutOfMemory(char const*) [/usr/local/bin/node]

18:14:47 (53635) TRACE ChildProcessProxy  5: 0x10059f045 v8::internal::Heap::CheckIneffectiveMarkCompact(unsigned long, double) [/usr/local/bin/node]

18:14:47 (53635) TRACE ChildProcessProxy  6: 0x10059aeef v8::internal::Heap::PerformGarbageCollection(v8::internal::GarbageCollector, v8::GCCallbackFlags) [/usr/local/bin/node]

18:14:47 (53635) TRACE ChildProcessProxy  7: 0x1005990c4 v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollectionReason, v8::GCCallbackFlags) [/usr/local/bin/node]

18:14:47 (53635) TRACE ChildProcessProxy  8: 0x1005a594c v8::internal::Heap::AllocateRawWithLigthRetry(int, v8::internal::AllocationSpace, v8::internal::AllocationAlignment) [/usr/local/bin/node]

18:14:47 (53635) TRACE ChildProcessProxy  9: 0x1005a59cf v8::internal::Heap::AllocateRawWithRetryOrFail(int, v8::internal::AllocationSpace, v8::internal::AllocationAlignment) [/usr/local/bin/node]

18:14:47 (53635) TRACE ChildProcessProxy 10: 0x100574da6 v8::internal::Factory::NewFixedArrayWithFiller(v8::internal::Heap::RootListIndex, int, v8::internal::Object*, v8::internal::PretenureFlag) [/usr/local/bin/node]

18:14:47 (53635) TRACE ChildProcessProxy 11: 0x1006eca76 v8::internal::HashTable<v8::internal::NameDictionary, v8::internal::NameDictionaryShape>::EnsureCapacity(v8::internal::Handle<v8::internal::NameDictionary>, int, v8::internal::PretenureFlag) [/usr/local/bin/node]
12: 0x1006e6190 v8::internal::Dictionary<v8::internal::NameDictionary, v8::internal::NameDictionaryShape>::Add(v8::internal::Handle<v8::internal::NameDictionary>, v8::internal::Handle<v8::internal::Name>, v8::internal::Handle<v8::internal::Object>, v8::internal::PropertyDetails, int*) [/usr/local/bin/node]
13: 0x10081a141 v8::internal::Runtime_AddDictionaryProperty(int, v8::internal::Object**, v8::internal::Isolate*) [/usr/local/bin/node]
14: 0x1b245195c01d

18:14:47 (53635) WARN ChildProcessProxy Child process [pid 53637] ran out of memory. Stdout and stderr are logged on debug level.
18:14:47 (53635) DEBUG ChildProcessProxy Last part of stdout and stderr was:
    FATAL ERROR: Ineffective mark-compacts near heap limit Allocation failed - JavaScript heap out of memory
     1: 0x100039dbf node::Abort() [/usr/local/bin/node]
     2: 0x100039fc9 node::OnFatalError(char const*, char const*) [/usr/local/bin/node]

     3: 0x1001d1375 v8::internal::V8::FatalProcessOutOfMemory(v8::internal::Isolate*, char const*, bool) [/usr/local/bin/node]

     4: 0x10059c572 v8::internal::Heap::FatalProcessOutOfMemory(char const*) [/usr/local/bin/node]

     5: 0x10059f045 v8::internal::Heap::CheckIneffectiveMarkCompact(unsigned long, double) [/usr/local/bin/node]

     6: 0x10059aeef v8::internal::Heap::PerformGarbageCollection(v8::internal::GarbageCollector, v8::GCCallbackFlags) [/usr/local/bin/node]

     7: 0x1005990c4 v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollectionReason, v8::GCCallbackFlags) [/usr/local/bin/node]

     8: 0x1005a594c v8::internal::Heap::AllocateRawWithLigthRetry(int, v8::internal::AllocationSpace, v8::internal::AllocationAlignment) [/usr/local/bin/node]

     9: 0x1005a59cf v8::internal::Heap::AllocateRawWithRetryOrFail(int, v8::internal::AllocationSpace, v8::internal::AllocationAlignment) [/usr/local/bin/node]

    10: 0x100574da6 v8::internal::Factory::NewFixedArrayWithFiller(v8::internal::Heap::RootListIndex, int, v8::internal::Object*, v8::internal::PretenureFlag) [/usr/local/bin/node]

    11: 0x1006eca76 v8::internal::HashTable<v8::internal::NameDictionary, v8::internal::NameDictionaryShape>::EnsureCapacity(v8::internal::Handle<v8::internal::NameDictionary>, int, v8::internal::PretenureFlag) [/usr/local/bin/node]
    12: 0x1006e6190 v8::internal::Dictionary<v8::internal::NameDictionary, v8::internal::NameDictionaryShape>::Add(v8::internal::Handle<v8::internal::NameDictionary>, v8::internal::Handle<v8::internal::Name>, v8::internal::Handle<v8::internal::Object>, v8::internal::PropertyDetails, int*) [/usr/local/bin/node]
    13: 0x10081a141 v8::internal::Runtime_AddDictionaryProperty(int, v8::internal::Object**, v8::internal::Isolate*) [/usr/local/bin/node]
    14: 0x1b245195c01d

18:14:47 (53635) INFO RetryDecorator Test runner process [53637] ran out of memory. You probably have a memory leak in your tests. Don't worry, Stryker will restart the process, but you might want to investigate this later, because this decreases performance.

//...

17:39:06 (52147) ERROR InitialTestExecutor One or more tests resulted in an error:
    Test runner crashed. Tried twice to restart it without any luck. Last time the error message was: Error: Process
Error: Process

With the same setup, but when everything except one dummy component is removed, stryker works fine.

Already tried to increase the memory limit with --max-old-space-size=8192 --optimize-for-size --max_old_space_size=8192 --optimize_for_size

Stryker config

module.exports = function(config) {
    config.set({
        mutator: 'typescript',
        packageManager: 'yarn',
        reporters: ['clear-text', 'progress'],
        testRunner: 'jest',
        transpilers: [],
        coverageAnalysis: 'off',
        tsconfigFile: 'tsconfig.test.json',
        mutate: [
            'src/test/**/*.ts',
            '!src/**/*.spec.ts',
            '!src/**/*.mock.ts',
            '!**/*.d.ts',
            '!**/*.snap',
            '!**/*.module.ts'
        ],
        logLevel: 'trace',
        timeoutFactor: 15.0,
        timeoutMS: 6000000,
        jest: {
            project: 'default',
            config: require(__dirname + '/jest.config.js')
        },
    });
};

Jest config

module.exports = {
    "preset": "jest-preset-angular",
    "coverageDirectory": "build/coverage/jest",
    "setupTestFrameworkScriptFile": "<rootDir>/src/setupJest.ts",
    "testMatch": [
        "**/+(*.)+(spec).+(ts)?(x)"
    ],
    "transformIgnorePatterns": [
        "node_modules/(?!@ngrx|ngx-cookie-service|@novnc|@angular/common/locales)"
    ],
    "transform": {
        "^.+\\.(ts|html)$": "<rootDir>/node_modules/jest-preset-angular/preprocessor.js",
        "^.+\\.js$": "babel-jest"
    }
};

Stryker environment

├─┬ [email protected]
│ ├── @stryker-mutator/[email protected]
├─┬ [email protected]
├─┬ [email protected]
│ ├── @stryker-mutator/[email protected] deduped
├─┬ [email protected]
├─┬ [email protected]

│   │ ├─┬ [email protected]
│   │ │ └─┬ [email protected]
│   │ │   ├── [email protected]
│   │ ├── [email protected] deduped
│   │ ├─┬ [email protected]
│   │ │ ├── [email protected] deduped
│   │ │ └── [email protected] deduped
│   │ ├── [email protected] deduped
│   │ ├─┬ [email protected]
│   │ │ │ ├── [email protected] deduped
│   │ │ │ ├── [email protected] deduped
│   │ │ │ ├── [email protected] deduped
│   │ │ │ ├── [email protected] deduped
│   │ │ │ └── [email protected] deduped
│   │ │ ├── [email protected] deduped
│   │ │ ├─┬ [email protected]
│   │ │ ├── [email protected] deduped
│   │ │ ├── [email protected] deduped
│   │ │ ├── [email protected] deduped
│   │ │ ├── [email protected] deduped
│   │ ├── [email protected] deduped
│   │ ├─┬ [email protected]
│   │ ├── [email protected] deduped
│   │ ├── [email protected] deduped
│   ├─┬ [email protected]
│   │ ├── [email protected]
│   │ ├── [email protected] deduped
│   ├── [email protected]
│   ├─┬ [email protected]
│   │ ├─┬ [email protected]
│   │ ├── [email protected]
│   │ ├── [email protected] deduped
│   ├─┬ [email protected]
│   ├── [email protected]
│   ├─┬ [email protected]
│   │ ├── [email protected] deduped
│   │ └── [email protected] deduped
│   ├─┬ [email protected]
│   │ ├── [email protected] deduped
│   │ ├── [email protected] deduped
│   │ ├── [email protected] deduped
│   │ ├── [email protected] deduped
│   │ ├─┬ [email protected]
│   │ ├── [email protected] deduped
│   │ ├── [email protected] deduped
│   │ ├── [email protected] deduped
│   │ ├── [email protected] deduped
│   ├─┬ [email protected]
│   │ ├── [email protected] deduped
│   │ ├── [email protected] deduped
│   │ ├── [email protected] deduped
│   │ ├── [email protected] deduped
│   │ ├── [email protected] deduped
│   │ ├── [email protected] deduped
│   │ ├── [email protected] deduped
│   │ ├── [email protected] deduped
│   ├─┬ [email protected]
│   │ ├─┬ [email protected]
│   │ │ ├── [email protected] deduped
│   │ ├─┬ [email protected]
│   │ │ ├── [email protected] deduped
│   │ ├── [email protected] deduped
│   │ ├── [email protected] deduped
│   ├─┬ [email protected]
│   │ ├── [email protected] deduped
│   ├─┬ [email protected]
│   │ ├── [email protected] deduped
│   ├─┬ [email protected]
│   ├─┬ [email protected]
├─┬ [email protected]
│ ├── @types/[email protected]
│ ├── [email protected]
│ └─┬ [email protected]

Your Environment

| software | version(s)
| ---------------- | -------
| node | 10.10.0
| yarn | 1.12.1
| Operating System | macOS High Sierra

Add stryker.log

stryker.log

Created with 

$ node --max-old-space-size=8192 --optimize-for-size --max_old_space_size=8192 --optimize_for_size node_modules/.bin/stryker run --fileLogLevel trace
⁉ Question 🛠 In progress
Source
picture wachri
👍2

Most helpful comment

I am experiencing the same issue with a NestJS application + Jest

picture jmtelljohann on 20 Aug 2019
👍4

All 14 comments

Thanks for opening this detailed issue! It looks like Stryker crashes during the initial test run. I haven't seen this before. I'll take a more thorough look at your config and logging tomorrow 👍

simondel picture simondel on 6 Nov 2018

Thank you. If I can help feel free to add instructions :)

wachri picture wachri on 7 Nov 2018

@wachri this is an interesting setup. You're using jest to test an angular project. This is new for us.

Could you try to open the sandbox directory after a failed run and run jest from there like you normally would in your main repository? This is to rule out any out of memory errors resulting from jest or one of it's plugins.

nicojs picture nicojs on 9 Nov 2018

@nicojs using jest has really speed up our tests, especially in the development environment. Already tried this and the jest tests are running fine.

Test Suites: 308 passed, 308 total
Tests:       3 skipped, 4464 passed, 4467 total
Snapshots:   163 passed, 163 total
wachri picture wachri on 9 Nov 2018

It looks like that --max-old-space-size is ignored in the child process. When I have a look into my system monitor the process never reaches this. Had tried it on a machine with 32GB RAM and --max-old-space-size=20000. The process it self has reached around 5GB and then it crashes with out of memory.

bildschirmfoto 2018-11-12 um 14 48 43

bildschirmfoto 2018-11-12 um 14 54 59

wachri picture wachri on 12 Nov 2018

@nicojs Any progress on this, or any thing I can do to help debugging? I would really like to use stryker in this project :)

wachri picture wachri on 3 Dec 2018

@wachri Could you try this with the latest version of Stryker? We've made some changes yesterday that may fix this.

We've released v1 today. If you want we could help you migrate to that version as well. As of right now, it contains no new features compared to the latest 0.x release.

simondel picture simondel on 13 Feb 2019

PS sorry for being so slow to respond :( 🐌

simondel picture simondel on 13 Feb 2019

@simondel thank you for you response :).
I tried it out with the same result. Please see the attached file log file:
stryker.log
If i can do more please let me know :).

module.exports = function(config) {
    config.set({
        mutator: 'typescript',
        packageManager: 'yarn',
        reporters: ['clear-text', 'progress'],
        testRunner: 'jest',
        transpilers: [],
        logLevel: 'trace',
        coverageAnalysis: 'off',
        mutate: [
            'src/app/*.ts',
            '!src/**/*.spec.ts',
            '!src/**/*.mock.ts',
            '!**/*.d.ts',
            '!**/*.snap',
            '!**/*.module.ts'
        ],
    });
};

and 

─┬ @stryker-mutator/[email protected]
│ ├─┬ @stryker-mutator/[email protected]
│ ├── @stryker-mutator/[email protected]
├─┬ @stryker-mutator/[email protected]
│ ├── @stryker-mutator/[email protected] deduped
├─┬ @stryker-mutator/[email protected]
│ ├── @stryker-mutator/[email protected] deduped
│ ├── @stryker-mutator/[email protected] deduped
wachri picture wachri on 13 Feb 2019

Thanks for testing this! Would it be possible for you to share the code or create a reproduction app?

Also, what happens after the memory leak errors? Does Stryker continue and report it for every mutant?

simondel picture simondel on 13 Feb 2019

Working to reproduce the behavior in https://github.com/wachri/stryker-out-of-memory. It currently not looking that it depends (only) on the amount of components. I was't able to reproduce the exactly same error but a similar one. With a combination of a large count of components and some complexity in the component I get an out of memory error after the initial run:

16:55:51 (51310) DEBUG ChildProcessProxy Disposing of worker process 51312
16:55:51 (51310) DEBUG ChildProcessProxy Kill 51312
16:55:51 (51310) INFO InitialTestExecutor Initial test run succeeded. Ran 403 tests in 1 minute 6 seconds (net 8022 ms, overhead 48179 ms).
16:55:59 (51310) INFO MutatorFacade 390115 Mutant(s) generated

<--- Last few GCs --->

[51310:0x103800000]   192182 ms: Scavenge 8029.7 (8330.9) -> 8029.7 (8330.9) MB, 12.5 / 0.0 ms  (average mu = 0.338, current mu = 0.269) allocation failure
[51310:0x103800000]   192196 ms: Scavenge 8029.7 (8330.9) -> 8029.7 (8330.9) MB, 12.3 / 0.0 ms  (average mu = 0.338, current mu = 0.269) allocation failure
[51310:0x103800000]   192210 ms: Scavenge 8029.7 (8330.9) -> 8029.7 (8330.9) MB, 13.2 / 0.0 ms  (average mu = 0.338, current mu = 0.269) allocation failure


<--- JS stacktrace --->
Cannot get stack trace in GC.
FATAL ERROR: Scavenger: semi-space copy Allocation failed - JavaScript heap out of memory

Writing Node.js report to file: report.20190220.165756.51310.001.json
Node.js report completed
 1: 0x10006313d node::Abort() [/usr/local/bin/node]
 2: 0x100063894 node::OnFatalError(char const*, char const*) [/usr/local/bin/node]
 3: 0x1001a5ca7 v8::Utils::ReportOOMFailure(v8::internal::Isolate*, char const*, bool) [/usr/local/bin/node]
 4: 0x1001a5c44 v8::internal::V8::FatalProcessOutOfMemory(v8::internal::Isolate*, char const*, bool) [/usr/local/bin/node]
 5: 0x1005aada2 v8::internal::Heap::FatalProcessOutOfMemory(char const*) [/usr/local/bin/node]
 6: 0x100600a03 v8::internal::Scavenger::Process(v8::internal::OneshotBarrier*) [/usr/local/bin/node]
 7: 0x1005bbb43 v8::internal::ScavengingTask::RunInParallel() [/usr/local/bin/node]
 8: 0x1005cecff v8::internal::ItemParallelJob::Task::RunInternal() [/usr/local/bin/node]
 9: 0x1005cf30d v8::internal::ItemParallelJob::Run(std::__1::shared_ptr<v8::internal::Counters>) [/usr/local/bin/node]
10: 0x1005ac37b v8::internal::Heap::Scavenge() [/usr/local/bin/node]
11: 0x1005a90c6 v8::internal::Heap::PerformGarbageCollection(v8::internal::GarbageCollector, v8::GCCallbackFlags) [/usr/local/bin/node]
12: 0x1005a79c5 v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollectionReason, v8::GCCallbackFlags) [/usr/local/bin/node]
13: 0x1005b426c v8::internal::Heap::AllocateRawWithLightRetry(int, v8::internal::AllocationSpace, v8::internal::AllocationAlignment) [/usr/local/bin/node]
14: 0x1005b42ef v8::internal::Heap::AllocateRawWithRetryOrFail(int, v8::internal::AllocationSpace, v8::internal::AllocationAlignment) [/usr/local/bin/node]
15: 0x1005834e4 v8::internal::Factory::NewFillerObject(int, bool, v8::internal::AllocationSpace) [/usr/local/bin/node]
16: 0x100835a04 v8::internal::Runtime_AllocateInNewSpace(int, v8::internal::Object**, v8::internal::Isolate*) [/usr/local/bin/node]
17: 0x336f69f4fc7d
18: 0x336f6a25f8f0
/var/folders/d6/8cg8ppqs2tl0w72pxn80pq480000gn/T/yarn--1550678083806-0.9782673415647616/node: line 3: 51310 Abort trap: 6           "/usr/local/bin/node" "$@"
error Command failed with exit code 134.
info Visit https://yarnpkg.com/en/docs/cli/run for documentation about this command.

report.20190220.165756.51310.001.json.zip

stryker-log.txt

You can find the example in the branche out-of-memory-after-initial-test

Learnings:

  • When I only generate a lot of default components (generated over 2k) everything is working
  • With some complexity in the components it works, too
  • Only after adding a lot more complexity to the components I got the error

Maybe this helps already a bit?

wachri picture wachri on 20 Feb 2019

Hello guys, how is it going? I came across this issue using a standard create-react-app + jest application.

Screenshot 2019-08-20 at 09 33 56
Screenshot 2019-08-20 at 09 33 50

One thing I noticed is: it doesn't matter if I choose the entire suite (350 tests) or part of that (10 for example).

marabesi picture marabesi on 20 Aug 2019

I am experiencing the same issue with a NestJS application + Jest

jmtelljohann picture jmtelljohann on 20 Aug 2019
👍4

Hi! This should be fixed with version 2.2.1: https://github.com/stryker-mutator/stryker/blob/master/packages/core/CHANGELOG.md

simondel picture simondel on 13 Nov 2019
Was this page helpful?
0 / 5 - 0 ratings

Related issues

Lakitna picture Lakitna  ·  42Comments
kmdrGroch picture kmdrGroch  ·  19Comments
trollepierre picture trollepierre  ·  18Comments
simondel picture simondel  ·  25Comments
wolf-off picture wolf-off  ·  18Comments