Newman: Running 200000 Instances of a single POST call causes JS exception

[jbnok]

_Version and environment information:_

1. Newman Version (can be found via newman -v): _3.4.3_
2. OS details (type, version, and architecture): _RHEL - Red Hat Enterprise Linux_
3. Are you using Newman as a library, or via the CLI? _CLI_
4. Did you encounter this recently, or has this bug always been there: _Presumably always there. Ran into this recently_
5. Expected behaviour: _There be better garbage collection/cleanup and I am able to run all 200K instances_
6. Command / script used to run Newman: _(From Jenkins Job): /usr/local/lib/node_modules/newman/bin/newman.js run ${COLLECTION_NAME} -e ${ENVIRONMENT_NAME} -d serverInfo.csv -n ${COUNT} -r html,cli,json,junit --insecure
   _
7. Sample collection, and auxilliary files (minus the sensitive details): _N/A_
8. Screenshots (if applicable): _No Screen shots but exception below_
   Exception:

Iteration 144112/200000

→ Start A Workflow

<--- Last few GCs --->

[8724:0x3ea00d0] 294323968 ms: Mark-sweep 1213.5 (1553.3) -> 1213.3 (1553.3) MB, 1790.0 / 0.0 ms  allocation failure GC in old space requested
[8724:0x3ea00d0] 294325847 ms: Mark-sweep 1213.3 (1553.3) -> 1213.2 (1513.3) MB, 1841.3 / 0.0 ms  last resort gc 
[8724:0x3ea00d0] 294327659 ms: Mark-sweep 1213.2 (1513.3) -> 1213.2 (1506.3) MB, 1812.1 / 0.0 ms  last resort gc 


<--- JS stacktrace --->

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

Security context: 0x123a3f9c0d31 <JS Object>
    1: /* anonymous */ [/usr/local/lib/node_modules/newman/node_modules/postman-collection/lib/collection/property-list.js:359] [pc=0xa7418cac6e4](this=0x84092ea5e21 <JS Global Object>,accumulator=0x187d00a26dc9 <an Object with map 0x7ce66607011>,value=0x2d0ef3df7ce1 <a PostmanPropertyDescription with map 0x26850f316d69>,key=0x84092e69769 <String[11]: description>)
    2: arguments adaptor fram...

FATAL ERROR: CALL_AND_RETRY_LAST Allocation failed - JavaScript heap out of memory
 1: node::Abort() [node]
 2: 0x126492c [node]
 3: v8::Utils::ReportOOMFailure(char const*, bool) [node]
 4: v8::internal::V8::FatalProcessOutOfMemory(char const*, bool) [node]
 5: v8::internal::Factory::NewTransitionArray(int) [node]
 6: v8::internal::TransitionArray::Insert(v8::internal::Handle<v8::internal::Map>, v8::internal::Handle<v8::internal::Name>, v8::internal::Handle<v8::internal::Map>, v8::internal::SimpleTransitionFlag) [node]
 7: v8::internal::Map::CopyReplaceDescriptors(v8::internal::Handle<v8::internal::Map>, v8::internal::Handle<v8::internal::DescriptorArray>, v8::internal::Handle<v8::internal::LayoutDescriptor>, v8::internal::TransitionFlag, v8::internal::MaybeHandle<v8::internal::Name>, char const*, v8::internal::SimpleTransitionFlag) [node]
 8: v8::internal::Map::CopyAddDescriptor(v8::internal::Handle<v8::internal::Map>, v8::internal::Descriptor*, v8::internal::TransitionFlag) [node]
 9: v8::internal::Map::CopyWithField(v8::internal::Handle<v8::internal::Map>, v8::internal::Handle<v8::internal::Name>, v8::internal::Handle<v8::internal::FieldType>, v8::internal::PropertyAttributes, v8::internal::Representation, v8::internal::TransitionFlag) [node]
10: v8::internal::Map::TransitionToDataProperty(v8::internal::Handle<v8::internal::Map>, v8::internal::Handle<v8::internal::Name>, v8::internal::Handle<v8::internal::Object>, v8::internal::PropertyAttributes, v8::internal::Object::StoreFromKeyed) [node]
11: v8::internal::LookupIterator::PrepareTransitionToDataProperty(v8::internal::Handle<v8::internal::JSObject>, v8::internal::Handle<v8::internal::Object>, v8::internal::PropertyAttributes, v8::internal::Object::StoreFromKeyed) [node]
12: v8::internal::Object::AddDataProperty(v8::internal::LookupIterator*, v8::internal::Handle<v8::internal::Object>, v8::internal::PropertyAttributes, v8::internal::Object::ShouldThrow, v8::internal::Object::StoreFromKeyed) [node]
13: v8::internal::Object::SetProperty(v8::internal::LookupIterator*, v8::internal::Handle<v8::internal::Object>, v8::internal::LanguageMode, v8::internal::Object::StoreFromKeyed) [node]
14: v8::internal::StoreIC::Store(v8::internal::Handle<v8::internal::Object>, v8::internal::Handle<v8::internal::Name>, v8::internal::Handle<v8::internal::Object>, v8::internal::Object::StoreFromKeyed) [node]
15: v8::internal::KeyedStoreIC::Store(v8::internal::Handle<v8::internal::Object>, v8::internal::Handle<v8::internal::Object>, v8::internal::Handle<v8::internal::Object>) [node]
16: v8::internal::Runtime_KeyedStoreIC_Miss(int, v8::internal::Object**, v8::internal::Isolate*) [node]
17: 0xa74174063a7
/tmp/hudson5071886919626673712.sh: line 9:  8724 Aborted                 /usr/local/lib/node_modules/newman/bin/newman.js run ${COLLECTION_NAME} -e ${ENVIRONMENT_NAME} -d serverInfo.csv -n ${COUNT} -r html,cli,json,junit --insecure

_Steps to reproduce the problem:_

1. Run newman with 200K instances of a single call.

[jbnok]

Before I get the "newman isn't designed for load testing" reply I would just like to make it clear that that is well known from another issue I have previously raised. However I will state again that this is a design oversight that should be addressed. Anyone testing load/scalability/performance of their APIs will need this functionality.

[czardoz]

@jbnok Thanks for reporting this, I agree, it's a separate issue (the other one #935 is specific to reporters, whereas this is not).

[jiarensuo]

same issue here. Is there any solution? Can I set npm --max-old-space-size to solve?

[shamasis]

@kunagpal @kamalaknn we need to build a newman core summary object flag that does not retain / accumulate stuff at all.

Else, we need to check if turning off all reporters (including CLI) ensures a light operation. If that is done, then we can write an article on turning off the reporters and maybe using a light reporter to run many many requests.

[chara-art]

Hello @DannyDainton as #2483 marked duplicate with this is issue, may I kindly request whether there is a roadmap plan for resolving issue #941?

[DannyDainton]

I believe @codenirvana would be better placed to answer questions with regards to the Newman roadmap.

[shamasis]

We need to decouple the "accumulator" summary object for reporters in Newman. It will disable some statistics feature, but it should open up this use case.

@codenirvana how about we do a workaround as an interim that when no reporter is loaded, we don't build summary object?

Then we can schedule a reporter API change for next major newman version or back the summary object with a disk buffer?

We would also need to do something about the extractRunnables array that flattens a collection and instead use a DSL like approach to programmatically track outcome for large collections. But, I'm guessing that for single request and large iteration use case, even this will not be a blocker.

[Wintereise]

We need to decouple the "accumulator" summary object for reporters in Newman. It will disable some statistics feature, but it should open up this use case.

It may be good enough to just dump the summary to disk periodically instead of holding on to it all, assuming of course the summary is the root cause.

We're seeing this with a toJSON call when testing endpoints that return large volumes of data with only 50~ iterations (at around the 1000~ requests mark).

This was with the old space size bumped to 4G already.

<--- Last few GCs --->

[4219:0x439a500]   661632 ms: Mark-sweep 3901.1 (4134.8) -> 3889.7 (4137.3) MB, 472.3 / 0.0 ms  (average mu = 0.125, current mu = 0.060) allocation failure scavenge might not succeed
[4219:0x439a500]   662124 ms: Mark-sweep 3903.4 (4137.3) -> 3891.9 (4139.6) MB, 449.2 / 0.0 ms  (average mu = 0.106, current mu = 0.088) allocation failure scavenge might not succeed


<--- JS stacktrace --->

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

    0: ExitFrame [pc: 0x1457299]
Security context: 0x1c702fa008d1 <JSObject>
    1: /* anonymous */ [0x8a084cc55b9] [/c/Users/reise/wcode/pixart/backend/cloud-run/newman/node_modules/postman-collection/lib/collection/property-list.js:~613] [pc=0x377b820eb190](this=0x3e209b884961 <JSGlobal Object>,0x1a26588311c1 <PostmanResponse map = 0x327d40cc8c9>)
    2: arguments adaptor frame: 3->1
    3: toJSON [0x3966630b8419] [/c/Users/reise/wcode/...

FATAL ERROR: Ineffective mark-compacts near heap limit Allocation failed - JavaScript heap out of memory
 1: 0xa9e290 node::Abort() [/home/reisender/.nvm/versions/node/v12.16.0/bin/node]
 2: 0xaa04b2 node::OnFatalError(char const*, char const*) [/home/reisender/.nvm/versions/node/v12.16.0/bin/node]
 3: 0xc0db6e v8::Utils::ReportOOMFailure(v8::internal::Isolate*, char const*, bool) [/home/reisender/.nvm/versions/node/v12.16.0/bin/node]
 4: 0xc0dee9 v8::internal::V8::FatalProcessOutOfMemory(v8::internal::Isolate*, char const*, bool) [/home/reisender/.nvm/versions/node/v12.16.0/bin/node]
 5: 0xdba835  [/home/reisender/.nvm/versions/node/v12.16.0/bin/node]
 6: 0xdbaec6 v8::internal::Heap::RecomputeLimits(v8::internal::GarbageCollector) [/home/reisender/.nvm/versions/node/v12.16.0/bin/node]
 7: 0xdc76da v8::internal::Heap::PerformGarbageCollection(v8::internal::GarbageCollector, v8::GCCallbackFlags) [/home/reisender/.nvm/versions/node/v12.16.0/bin/node]
 8: 0xdc85e5 v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollectionReason, v8::GCCallbackFlags) [/home/reisender/.nvm/versions/node/v12.16.0/bin/node]
 9: 0xdcb09c v8::internal::Heap::AllocateRawWithRetryOrFail(int, v8::internal::AllocationType, v8::internal::AllocationOrigin, v8::internal::AllocationAlignment) [/home/reisender/.nvm/versions/node/v12.16.0/bin/node]
10: 0xd91dfd v8::internal::Factory::NewFixedArrayWithFiller(v8::internal::RootIndex, int, v8::internal::Object, v8::internal::AllocationType) [/home/reisender/.nvm/versions/node/v12.16.0/bin/node]
11: 0xd91ef0 v8::internal::Handle<v8::internal::FixedArray> v8::internal::Factory::NewFixedArrayWithMap<v8::internal::FixedArray>(v8::internal::RootIndex, int, v8::internal::AllocationType) [/home/reisender/.nvm/versions/node/v12.16.0/bin/node]
12: 0xfbf92d v8::internal::OrderedHashTable<v8::internal::OrderedHashSet, 1>::Allocate(v8::internal::Isolate*, int, v8::internal::AllocationType) [/home/reisender/.nvm/versions/node/v12.16.0/bin/node]
13: 0xfbf9df v8::internal::OrderedHashTable<v8::internal::OrderedHashSet, 1>::Rehash(v8::internal::Isolate*, v8::internal::Handle<v8::internal::OrderedHashSet>, int) [/home/reisender/.nvm/versions/node/v12.16.0/bin/node]
14: 0xfbffbb v8::internal::OrderedHashTable<v8::internal::OrderedHashSet, 1>::EnsureGrowable(v8::internal::Isolate*, v8::internal::Handle<v8::internal::OrderedHashSet>) [/home/reisender/.nvm/versions/node/v12.16.0/bin/node]
15: 0xfc00ab v8::internal::OrderedHashSet::Add(v8::internal::Isolate*, v8::internal::Handle<v8::internal::OrderedHashSet>, v8::internal::Handle<v8::internal::Object>) [/home/reisender/.nvm/versions/node/v12.16.0/bin/node]
16: 0xf79576 v8::internal::KeyAccumulator::AddKeys(v8::internal::Handle<v8::internal::FixedArray>, v8::internal::AddKeyConversion) [/home/reisender/.nvm/versions/node/v12.16.0/bin/node]
17: 0xf7addd v8::internal::KeyAccumulator::CollectOwnPropertyNames(v8::internal::Handle<v8::internal::JSReceiver>, v8::internal::Handle<v8::internal::JSObject>) [/home/reisender/.nvm/versions/node/v12.16.0/bin/node]
18: 0xf7b36e v8::internal::KeyAccumulator::CollectOwnKeys(v8::internal::Handle<v8::internal::JSReceiver>, v8::internal::Handle<v8::internal::JSObject>) [/home/reisender/.nvm/versions/node/v12.16.0/bin/node]
19: 0xf7bf6e v8::internal::KeyAccumulator::CollectKeys(v8::internal::Handle<v8::internal::JSReceiver>, v8::internal::Handle<v8::internal::JSReceiver>) [/home/reisender/.nvm/versions/node/v12.16.0/bin/node]
20: 0xf7c397 v8::internal::FastKeyAccumulator::GetKeys(v8::internal::GetKeysConversion) [/home/reisender/.nvm/versions/node/v12.16.0/bin/node]
21: 0x10c6c81 v8::internal::Runtime_ForInEnumerate(int, unsigned long*, v8::internal::Isolate*) [/home/reisender/.nvm/versions/node/v12.16.0/bin/node]
22: 0x1457299  [/home/reisender/.nvm/versions/node/v12.16.0/bin/node]

[shamasis]

Yeah. That's right.

But it's not straightforward since the summary is a deep object. With hindsight, we should have made this an accumulative array. 🤦🏼‍♂️ The reporter APIs also expect a full object.

Maybe we can completely use a separate accumulation method and use getters to emulate summary.

It is also not prudent to build the root functionality with disk backing since disk failure or lack of file access permission will cause an unwanted hindrance in failure cases. Hence it has to also function without disk backing or optionally opt in to disk buffered mode.

[shamasis]

By the way, let's deep dive the heap issue, it could also be other factors while we speculate summary alone. 😂😂

[dcmeglio]

@shamasis Is there the possibility of setting certain requests to be excluded from the summary? I have a loop that goes through an SQS queue, reads a message, sets a variable depending on what the message was, deletes the message, and loops until the queue is empty. Could be 10 entries on the queue, could be 10,000. I then have a request at the end that looks at the variables and makes assertions based on the variables should be set. I don't need either my Poll SQS or my Delete SQS in the summary, I just need the request at the end that checks to see if the variables I'm expecting to be true/false to be part of the summary. Is there any way I can set certain requests as an exclude from the summary? I suspect that would solve my out of mem error.

[svarshney2311]

@DannyDainton ,

as per your comment "Thanks for reporting this issue, this is happening because Newman internally accumulates all the iteration data to generate a report."
so If we are splitting our collection into two and running newman command twice in the same instance, would that issue be resolved?
After creating first report , would newman will release all the iteration data and memory will be available for next run?

[ulyssesb]

By the way, let's deep dive the heap issue, it could also be other factors while we speculate summary alone.

Did some testing considering summary as culprit of memory consumption that I think it worth sharing, but you should take it with grain of salt. I'm running datasets and scripts that if removed might decrease memory consumption.

Testing summary

Completely removing usage of RunSummary from run.js/emmiter seems to have no effect on memory consumption.

Changes
run.js : 155

>  emitter.summary = new RunSummary(emitter, options);
<  emitter.summary = {} //new RunSummary(emitter, options);

_Sample size: 2048 entries_

Control Test

Result: +/- 3500mb

Without summary

Result: +/-3500mb

Testing newman

Maybe the problem is not in newman but rather somewhere in postman-runtime.

Changes
run.js : 192

setImmediate(function () {
    run.start(callbacks);
});

return 

_Sample size: 256_

Control Test

Runtime: 54s
Memory 1024mb

Without newman

Runtime: 54s
Memory 958mb

Looking at the results seems that the problem might not be with newman but rather somewhere on postman. But is also possible that code changes were made in the wrong place.

Trying to create a memory heapdump results in segmentation fault every single time.

Hope this helps