Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Ran out of memory with large angular application #1230

Closed
wachri opened this issue Nov 6, 2018 · 14 comments
Closed

Ran out of memory with large angular application #1230

wachri opened this issue Nov 6, 2018 · 14 comments
Labels
🛠 In progress ⁉ Question Further information is requested

Comments

@wachri
Copy link

wachri commented Nov 6, 2018

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

├─┬ stryker@0.30.1
│ ├── @stryker-mutator/util@0.0.1
├─┬ stryker-api@0.21.4
├─┬ stryker-html-reporter@0.16.5
│ ├── @stryker-mutator/util@0.0.1 deduped
├─┬ stryker-jest-runner@1.2.5
├─┬ stryker-karma-runner@0.20.0
│   │ ├─┬ babel-jest@23.6.0
│   │ │ └─┬ babel-preset-jest@23.2.0
│   │ │   ├── babel-plugin-jest-hoist@23.2.0
│   │ ├── jest-environment-jsdom@23.4.0 deduped
│   │ ├─┬ jest-environment-node@23.4.0
│   │ │ ├── jest-mock@23.2.0 deduped
│   │ │ └── jest-util@23.4.0 deduped
│   │ ├── jest-get-type@22.4.3 deduped
│   │ ├─┬ jest-jasmine2@23.6.0
│   │ │ │ ├── jest-diff@23.6.0 deduped
│   │ │ │ ├── jest-get-type@22.4.3 deduped
│   │ │ │ ├── jest-matcher-utils@23.6.0 deduped
│   │ │ │ ├── jest-message-util@23.4.0 deduped
│   │ │ │ └── jest-regex-util@23.3.0 deduped
│   │ │ ├── jest-diff@23.6.0 deduped
│   │ │ ├─┬ jest-each@23.6.0
│   │ │ ├── jest-matcher-utils@23.6.0 deduped
│   │ │ ├── jest-message-util@23.4.0 deduped
│   │ │ ├── jest-snapshot@23.6.0 deduped
│   │ │ ├── jest-util@23.4.0 deduped
│   │ ├── jest-regex-util@23.3.0 deduped
│   │ ├─┬ jest-resolve@23.6.0
│   │ ├── jest-util@23.4.0 deduped
│   │ ├── jest-validate@23.6.0 deduped
│   ├─┬ jest-environment-jsdom@23.4.0
│   │ ├── jest-mock@23.2.0
│   │ ├── jest-util@23.4.0 deduped
│   ├── jest-get-type@22.4.3
│   ├─┬ jest-haste-map@23.6.0
│   │ ├─┬ jest-docblock@23.2.0
│   │ ├── jest-serializer@23.0.1
│   │ ├── jest-worker@23.2.0 deduped
│   ├─┬ jest-message-util@23.4.0
│   ├── jest-regex-util@23.3.0
│   ├─┬ jest-resolve-dependencies@23.6.0
│   │ ├── jest-regex-util@23.3.0 deduped
│   │ └── jest-snapshot@23.6.0 deduped
│   ├─┬ jest-runner@23.6.0
│   │ ├── jest-config@23.6.0 deduped
│   │ ├── jest-docblock@23.2.0 deduped
│   │ ├── jest-haste-map@23.6.0 deduped
│   │ ├── jest-jasmine2@23.6.0 deduped
│   │ ├─┬ jest-leak-detector@23.6.0
│   │ ├── jest-message-util@23.4.0 deduped
│   │ ├── jest-runtime@23.6.0 deduped
│   │ ├── jest-util@23.4.0 deduped
│   │ ├── jest-worker@23.2.0 deduped
│   ├─┬ jest-runtime@23.6.0
│   │ ├── jest-config@23.6.0 deduped
│   │ ├── jest-haste-map@23.6.0 deduped
│   │ ├── jest-message-util@23.4.0 deduped
│   │ ├── jest-regex-util@23.3.0 deduped
│   │ ├── jest-resolve@23.6.0 deduped
│   │ ├── jest-snapshot@23.6.0 deduped
│   │ ├── jest-util@23.4.0 deduped
│   │ ├── jest-validate@23.6.0 deduped
│   ├─┬ jest-snapshot@23.6.0
│   │ ├─┬ jest-diff@23.6.0
│   │ │ ├── jest-get-type@22.4.3 deduped
│   │ ├─┬ jest-matcher-utils@23.6.0
│   │ │ ├── jest-get-type@22.4.3 deduped
│   │ ├── jest-message-util@23.4.0 deduped
│   │ ├── jest-resolve@23.6.0 deduped
│   ├─┬ jest-util@23.4.0
│   │ ├── jest-message-util@23.4.0 deduped
│   ├─┬ jest-validate@23.6.0
│   │ ├── jest-get-type@22.4.3 deduped
│   ├─┬ jest-watcher@23.4.0
│   ├─┬ jest-worker@23.2.0
├─┬ jest-preset-angular@6.0.1
│ ├── @types/jest@23.3.1
│ ├── jest-zone-patch@0.0.8
│ └─┬ ts-jest@23.1.4

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
@simondel
Copy link
Member

simondel commented Nov 6, 2018

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 👍

@wachri
Copy link
Author

wachri commented Nov 7, 2018

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

@nicojs
Copy link
Member

nicojs commented Nov 9, 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.

@wachri
Copy link
Author

wachri commented Nov 9, 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
Copy link
Author

wachri commented Nov 12, 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
Copy link
Author

wachri commented Dec 3, 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 :)

@simondel
Copy link
Member

@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
Copy link
Member

PS sorry for being so slow to respond :( 🐌

@simondel simondel added ⁉ Question Further information is requested 🛠 In progress labels Feb 13, 2019
@wachri
Copy link
Author

wachri commented Feb 13, 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/core@1.0.1
│ ├─┬ @stryker-mutator/api@1.0.1
│ ├── @stryker-mutator/util@1.0.0
├─┬ @stryker-mutator/jest-runner@1.0.1
│ ├── @stryker-mutator/api@1.0.1 deduped
├─┬ @stryker-mutator/typescript@1.0.1
│ ├── @stryker-mutator/api@1.0.1 deduped
│ ├── @stryker-mutator/util@1.0.0 deduped

@simondel
Copy link
Member

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?

@wachri
Copy link
Author

wachri commented Feb 20, 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?

@marabesi
Copy link

marabesi commented Aug 20, 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).

@jmtelljohann
Copy link

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

@simondel
Copy link
Member

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
🛠 In progress ⁉ Question Further information is requested
Projects
None yet
Development

No branches or pull requests

5 participants