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

parallel/test-tick-processor-unknown failures #8725

Closed
mhdawson opened this issue Sep 22, 2016 · 43 comments
Closed

parallel/test-tick-processor-unknown failures #8725

mhdawson opened this issue Sep 22, 2016 · 43 comments
Labels
test Issues and PRs related to the tests. v8 engine Issues and PRs related to the V8 dependency.

Comments

@mhdawson
Copy link
Member

mhdawson commented Sep 22, 2016

  • Version: master
  • Platform: smartos [EDIT by Trott: Windows, Raspberry Pi, probably others too]
  • Subsystem:test
not ok 1166 parallel/test-tick-processor-unknown
# TIMEOUT
  ---

In my last run to test a unrelated test change.

smartos - https://ci.nodejs.org/job/node-test-commit-smartos/nodes=smartos14-32/4379/console

also seemed to fail in next run that was launched as well.

@targos
Copy link
Member

targos commented Sep 22, 2016

@jbergstroem
Copy link
Member

jbergstroem commented Sep 22, 2016

ping @nodejs/platform-solaris (time to rename?) @geek

@mscdex mscdex added v8 engine Issues and PRs related to the V8 dependency. test Issues and PRs related to the tests. smartos Issues and PRs related to the SmartOS platform. labels Sep 22, 2016
@geek
Copy link
Member

geek commented Sep 22, 2016

@jbergstroem agreed on the rename

not ok 1166 parallel/test-tick-processor-unknown
# TIMEOUT
  ---
  duration_ms: 60.140

Is 60ms just too low for a timeout?

@addaleax
Copy link
Member

addaleax commented Sep 22, 2016

Is 60ms just too low for a timeout?

It’s a terrible name but afaik duration_ms is given in seconds, and we can’t really change that name.

@imyller
Copy link
Member

imyller commented Sep 22, 2016

This is not limited to SmartOS:

not ok 237 parallel/test-tick-processor-unknown
# TIMEOUT
  ---
  duration_ms: 62.541

https://ci.nodejs.org/job/node-test-binary-windows/3975/RUN_SUBSET=1,VS_VERSION=vs2015,label=win2012r2/console

Could this be related to V8 5.4 beta now in master?

@Trott
Copy link
Member

Trott commented Sep 23, 2016

It’s a terrible name but afaik duration_ms is given in seconds

Yes, and we don't change the name from duration_ms because IIRC it's actually specified that way in TAP, believe it or not.

@Trott
Copy link
Member

Trott commented Sep 23, 2016

Could this be related to V8 5.4 beta now in master?

Anything's possible, but test-tick-processor (now three different test-tick-processor-* tests) is non-deterministic and has been flaky across pretty much every platform at one time or another.

/cc @matthewloring @indutny

@targos
Copy link
Member

targos commented Sep 23, 2016

The stress test failed with 43/100 runs. I think all of them are because of the timeout but it's interesting to see that sometimes there is additional output:

OOM error

not ok 1 parallel/test-tick-processor-unknown
# TIMEOUT
# FATAL ERROR: invalid array length Allocation failed - JavaScript heap out of memory
#  1: node::Abort() [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
#  2: node::OnFatalError(char const*, char const*) [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
#  3: v8::Utils::ReportOOMFailure(char const*, bool) [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
#  4: v8::internal::V8::FatalProcessOutOfMemory(char const*, bool) [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
#  5: v8::internal::Heap::AllocateUninitializedFixedArray(int) [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
#  6: v8::internal::Factory::NewUninitializedFixedArray(int) [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
#  7: v8::internal::(anonymous namespace)::ElementsAccessorBase<v8::internal::(anonymous namespace)::FastPackedSmiElementsAccessor, v8::internal::(anonymous namespace)::ElementsKindTraits<(v8::internal::ElementsKind)0> >::GrowCapacityAndConvertImpl(v8::internal::Handle<v8::internal::JSObject>, unsigned int) [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
#  8: v8::internal::Runtime_GrowArrayElements(int, v8::internal::Object**, v8::internal::Isolate*) [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
#  9: ad80a23e
# 10: 8c74511b
# 11: 8c75f591
# 12: 8c73d3bc
# 13: 8c73d0c4
# 14: 8c73cf9f
# 15: 8c74d8eb
# 16: 8c737fa4
# 17: 8c737a8e
# 18: 8c7378ae
# 19: 8c718902
# 20: 8c7189ff
# 21: ad80b6b6
# 22: 8c71496f
# 23: ad80b6b6
# 24: ad86537d
# 25: ad864baf
# 26: ad863e0e
# 27: ad86198a
# 28: ad83e83e
# 29: ad827878
# 30: v8::internal::Execution::Call(v8::internal::Isolate*, v8::internal::Handle<v8::internal::Object>, v8::internal::Handle<v8::internal::Object>, int, v8::internal::Handle<v8::internal::Object>*) [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
# 31: v8::Function::Call(v8::Local<v8::Context>, v8::Local<v8::Value>, int, v8::Local<v8::Value>*) [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
# 32: v8::Function::Call(v8::Local<v8::Value>, int, v8::Local<v8::Value>*) [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
# 33: node::LoadEnvironment(node::Environment*) [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
# 34: node::StartNodeInstance(void*) [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
# 35: node::Start(int, char**) [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
# 36: main [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
# 37: _start [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
# FATAL ERROR: invalid array length Allocation failed - JavaScript heap out of memory
#  1: node::Abort() [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
#  2: node::OnFatalError(char const*, char const*) [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
#  3: v8::Utils::ReportOOMFailure(char const*, bool) [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
#  4: v8::internal::V8::FatalProcessOutOfMemory(char const*, bool) [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
#  5: v8::internal::Heap::AllocateUninitializedFixedArray(int) [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
#  6: v8::internal::Factory::NewUninitializedFixedArray(int) [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
#  7: v8::internal::(anonymous namespace)::ElementsAccessorBase<v8::internal::(anonymous namespace)::FastPackedSmiElementsAccessor, v8::internal::(anonymous namespace)::ElementsKindTraits<(v8::internal::ElementsKind)0> >::GrowCapacityAndConvertImpl(v8::internal::Handle<v8::internal::JSObject>, unsigned int) [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
#  8: v8::internal::Runtime_GrowArrayElements(int, v8::internal::Object**, v8::internal::Isolate*) [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
#  9: 8260a23e
# 10: 92b426db
# 11: 92b5f9d1
# 12: 92b3d3bc
# 13: 92b3d0c4
# 14: 92b3cf9f
# 15: 92b4c58b
# 16: 92b37fa4
# 17: 92b37a8e
# 18: 92b378ae
# 19: 92b18902
# 20: 92b189ff
# 21: 8260b6b6
# 22: 92b1496f
# 23: 8260b6b6
# 24: 8266537d
# 25: 82664baf
# 26: 82663e0e
# 27: 8266198a
# 28: 8263e83e
# 29: 82627878
# 30: v8::internal::Execution::Call(v8::internal::Isolate*, v8::internal::Handle<v8::internal::Object>, v8::internal::Handle<v8::internal::Object>, int, v8::internal::Handle<v8::internal::Object>*) [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
# 31: v8::Function::Call(v8::Local<v8::Context>, v8::Local<v8::Value>, int, v8::Local<v8::Value>*) [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
# 32: v8::Function::Call(v8::Local<v8::Value>, int, v8::Local<v8::Value>*) [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
# 33: node::LoadEnvironment(node::Environment*) [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
# 34: node::StartNodeInstance(void*) [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
# 35: node::Start(int, char**) [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
# 36: main [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
# 37: _start [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
  ---
  duration_ms: 60.140
  ...

firstLine.split is not a function

not ok 1 parallel/test-tick-processor-unknown
# TIMEOUT
# undefined:92
#   firstLine = firstLine.split(',');
#                         ^
# 
# TypeError: firstLine.split is not a function
#     at versionCheck (eval at <anonymous> (internal/v8_prof_processor.js:32:1), <anonymous>:92:25)
#     at eval (eval at <anonymous> (internal/v8_prof_processor.js:32:1), <anonymous>:69:1)
#     at eval (eval at <anonymous> (internal/v8_prof_processor.js:32:1), <anonymous>:3574:3)
#     at internal/v8_prof_processor.js:32:1
#     at NativeModule.compile (bootstrap_node.js:485:7)
#     at Function.NativeModule.require (bootstrap_node.js:426:18)
#     at startup (bootstrap_node.js:86:20)
#     at bootstrap_node.js:497:3
  ---
  duration_ms: 60.174
  ...

List of times:

  duration_ms: 60.93
  duration_ms: 60.89
  duration_ms: 60.140
  duration_ms: 2.362
  duration_ms: 2.366
  duration_ms: 60.82
  duration_ms: 60.107
  duration_ms: 60.128
  duration_ms: 9.515
  duration_ms: 60.110
  duration_ms: 9.749
  duration_ms: 9.189
  duration_ms: 9.402
  duration_ms: 8.893
  duration_ms: 60.166
  duration_ms: 60.85
  duration_ms: 13.922
  duration_ms: 10.655
  duration_ms: 13.224
  duration_ms: 13.917
  duration_ms: 60.87
  duration_ms: 10.628
  duration_ms: 11.395
  duration_ms: 60.190
  duration_ms: 28.31
  duration_ms: 10.219
  duration_ms: 60.177
  duration_ms: 60.123
  duration_ms: 12.298
  duration_ms: 15.384
  duration_ms: 60.115
  duration_ms: 60.136
  duration_ms: 19.151
  duration_ms: 34.309
  duration_ms: 60.117
  duration_ms: 60.140
  duration_ms: 60.158
  duration_ms: 26.923
  duration_ms: 60.104
  duration_ms: 60.170
  duration_ms: 15.433
  duration_ms: 15.343
  duration_ms: 60.112
  duration_ms: 60.165
  duration_ms: 26.553
  duration_ms: 26.11
  duration_ms: 17.701
  duration_ms: 21.575
  duration_ms: 12.34
  duration_ms: 15.664
  duration_ms: 18.818
  duration_ms: 10.372
  duration_ms: 60.116
  duration_ms: 43.494
  duration_ms: 25.313
  duration_ms: 60.97
  duration_ms: 60.135
  duration_ms: 10.229
  duration_ms: 10.75
  duration_ms: 16.998
  duration_ms: 16.586
  duration_ms: 33.236
  duration_ms: 60.158
  duration_ms: 25.110
  duration_ms: 60.119
  duration_ms: 9.868
  duration_ms: 60.172
  duration_ms: 60.113
  duration_ms: 23.27
  duration_ms: 60.108
  duration_ms: 60.147
  duration_ms: 60.142
  duration_ms: 60.171
  duration_ms: 15.103
  duration_ms: 17.712
  duration_ms: 17.618
  duration_ms: 60.165
  duration_ms: 9.793
  duration_ms: 14.5
  duration_ms: 20.811
  duration_ms: 60.101
  duration_ms: 17.34
  duration_ms: 60.98
  duration_ms: 41.845
  duration_ms: 28.982
  duration_ms: 60.124
  duration_ms: 60.151
  duration_ms: 60.94
  duration_ms: 60.131
  duration_ms: 17.684
  duration_ms: 39.495
  duration_ms: 23.895
  duration_ms: 11.651
  duration_ms: 20.881
  duration_ms: 60.168
  duration_ms: 27.426
  duration_ms: 60.166
  duration_ms: 36.347
  duration_ms: 60.174
  duration_ms: 22.403

@Trott
Copy link
Member

Trott commented Sep 23, 2016

Another failure on Windows too: https://ci.nodejs.org/job/node-test-binary-windows/3983/RUN_SUBSET=1,VS_VERSION=vs2015,label=win2012r2/console:

not ok 237 parallel/test-tick-processor-unknown
# TIMEOUT

Any objection to removing the SmartOS/Solaris specificity on this issue? Or would people prefer we have a separate issue for Windows? I could go either way, as there might or might not be a common cause for the failures on the different platforms.
¯_(ツ)_/¯

@Trott
Copy link
Member

Trott commented Sep 23, 2016

Any chance that we're only seeing these timeouts on single-processor machines?

EDIT: Answer: Nope.

@geek
Copy link
Member

geek commented Sep 23, 2016

@Trott go for updating the title

test.py supports overriding the timeout. Should we adjust the timeout for our 32-bit builds?

Current:

/opt/local/bin/python2.7 tools/test.py -j 4 -p tap --logfile test.tap \
    --mode=release --flaky-tests=dontcare \
     addons doctool inspector known_issues message parallel pseudo-tty sequential

Suggested:

/opt/local/bin/python2.7 tools/test.py -j 4 -p tap --logfile test.tap \
    --timeout=120 \
    --mode=release --flaky-tests=dontcare \
     addons doctool inspector known_issues message parallel pseudo-tty sequential

@Trott
Copy link
Member

Trott commented Sep 23, 2016

@geek There's a timeout multiplier in test.py that we could use too. I actually tried that to solve the test-tick-processor-* timeouts on Raspberry Pi 1 and it did not work. Of course, Raspberry Pi is not SmartOS or Windows, so YMMV...

@Trott
Copy link
Member

Trott commented Sep 23, 2016

I have a PR open (#8652) to skip the test-tick-processor-* tests on machines with a single CPU that is slower than 1000 MHz. That can be tweaked but I guess the question is about the approach: Are we comfortable with "The V8 tick processor cannot be reliably tested on slow single processor machines, and that's OK." Or is that not OK? (That PR skips it on Raspberry Pi 1, but runs the tests on Pi 2 and Pi 3 machines.)

@Trott
Copy link
Member

Trott commented Sep 23, 2016

@geek Currently the test-tick-processor-unknown takes 10-15 seconds to complete on Raspberry Pi 2 and Raspberry Pi 3 devices. I strongly suspect that SmartOS issue is that the test will never complete, not that the timeout isn't long enough. But let's try it. I'll switch the timeout to 10 minutes or something and run a stress test...

@Trott Trott removed the smartos Issues and PRs related to the SmartOS platform. label Sep 23, 2016
@Trott
Copy link
Member

Trott commented Sep 23, 2016

Failure on Raspberry Pi 2 of test-tick-processor-builtin likely related:

https://ci.nodejs.org/job/node-test-binary-arm/3978/RUN_SUBSET=4,label=pi2-raspbian-wheezy/console

not ok 135 parallel/test-tick-processor-builtin
# TIMEOUT

Might it also help to move these tests to sequential? Probably worth a shot.

@Trott
Copy link
Member

Trott commented Sep 23, 2016

Stress test with 10-minute timeout instead of 1-minute timeout: https://ci.nodejs.org/job/node-stress-single-test/957/nodes=smartos14-32/console

When it succeeds, it takes less than 2 seconds. When it times out, it times out over ten minutes. Something about the test causes it to deadlock, it seems. @matthewloring @indutny

@matthewloring
Copy link

test-tick-processor-unknown is looking for JS symbols which should be working on all platforms. The majority of the flakiness I have seen has been on the tests that check for C++ symbols but these should not be running on smartos. I can get access to a smartos machine and see if I can get more information.

@matthewloring
Copy link

If tick processor output from one of the timeout runs on smartos can be recovered that will also speed up diagnosis.

@imyller
Copy link
Member

imyller commented Sep 23, 2016

Any objection to removing the SmartOS/Solaris specificity on this issue

@Trott I think the issue topic should be updated.

@Trott Trott changed the title smartos - parallel/test-tick-processor-unkonwn failures parallel/test-tick-processor-unkonwn failures Sep 23, 2016
@matthewloring
Copy link

I am referring to the profile generated by the test that it searches for particular symbols (produced here: https://github.com/nodejs/node/blob/master/test/fixtures/tick-processor-base.js#L33).

@imyller imyller changed the title parallel/test-tick-processor-unkonwn failures parallel/test-tick-processor-unknown failures Sep 24, 2016
@geek
Copy link
Member

geek commented Sep 24, 2016

I am unable to reproduce when I run the test directly.

# git log
commit 4dd044b5dc60668e47a0f0a7714b9ed1d91dec9c

Which is mhdawson@4dd044b

Machine details:

# uname -a
SunOS base-32 5.11 joyent_20160721T174127Z i86pc i386 i86pc Solaris
# sm-summary
...
Image               base-32-lts 14.4.2
...

Running the test with the runner

tools/test.py -p tap parallel/test-tick-processor-unknown
1..1
ok 1 parallel/test-tick-processor-unknown
  ---
  duration_ms: 3.745
  ...

Running the test with the build directly

# out/Release/node test/parallel/test-tick-processor-unknown.js
# echo $?
0

@Trott
Copy link
Member

Trott commented Sep 27, 2016

@geek Interesting. How many times did you run it? Can you run it in a loop 50 times or something? Also, I believe this test fails more frequently with slow CPU, so maybe run it on the slowest host you have?

@geek
Copy link
Member

geek commented Sep 27, 2016

@Trott this is on a host with only 42% of a core and 512mb of memory.

I ran it in a loop until it failed, it never failed after 112 iterations

@Trott
Copy link
Member

Trott commented Sep 28, 2016

@geek @imyller I got test-tick-processor-unknown to fail from the command line on test-joyent-smartos14-x86-2.

# git log
commit 40866377e8cec5cd4fdb9726b593a6e112ed54cc
# uname -a
SunOS ea49e343-6d4c-4f55-b3bd-9876db4cad0f 5.11 joyent_20160303T211841Z i86pc i386 i86pc Solaris
# sm-summary
... 
Image               base-32-lts 14.4.2
...

Output here!

# tools/test.py --repeat=5 parallel/test-tick-processor-unknown
=== release test-tick-processor-unknown ===                    
Path: parallel/test-tick-processor-unknown
FATAL ERROR: invalid array length Allocation failed - JavaScript heap out of memory
 1: node::Abort() [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
 2: node::OnFatalError(char const*, char const*) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
 3: v8::Utils::ReportOOMFailure(char const*, bool) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
 4: v8::internal::V8::FatalProcessOutOfMemory(char const*, bool) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
 5: v8::internal::Heap::AllocateUninitializedFixedArray(int) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
 6: v8::internal::Factory::NewUninitializedFixedArray(int) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
 7: v8::internal::(anonymous namespace)::ElementsAccessorBase<v8::internal::(anonymous namespace)::FastPackedSmiElementsAccessor, v8::internal::(anonymous namespace)::ElementsKindTraits<(v8::internal::ElementsKind)0> >::GrowCapacityAndConvertImpl(v8::internal::Handle<v8::internal::JSObject>, unsigned int) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
 8: v8::internal::Runtime_GrowArrayElements(int, v8::internal::Object**, v8::internal::Isolate*) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
 9: 8730a23e
10: 98843c7b
11: 9885867b
12: 9883c2fc
13: 9883c004
14: 9883bedf
15: 9884c54b
16: 98836ee4
17: 988369ce
18: 988367ee
19: 98818962
20: 98818a5f
21: 8730b6b6
22: 988149cf
23: 8730b6b6
24: 8736537d
25: 87364baf
26: 87363e0e
27: 8736198a
28: 8733e83e
29: 87327878
30: v8::internal::Execution::Call(v8::internal::Isolate*, v8::internal::Handle<v8::internal::Object>, v8::internal::Handle<v8::internal::Object>, int, v8::internal::Handle<v8::internal::Object>*) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
31: v8::Function::Call(v8::Local<v8::Context>, v8::Local<v8::Value>, int, v8::Local<v8::Value>*) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
32: v8::Function::Call(v8::Local<v8::Value>, int, v8::Local<v8::Value>*) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
33: node::LoadEnvironment(node::Environment*) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
34: node::StartNodeInstance(void*) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
35: node::Start(int, char**) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
36: main [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
37: _start [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
FATAL ERROR: invalid array length Allocation failed - JavaScript heap out of memory
 1: node::Abort() [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
 2: node::OnFatalError(char const*, char const*) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
 3: v8::Utils::ReportOOMFailure(char const*, bool) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
 4: v8::internal::V8::FatalProcessOutOfMemory(char const*, bool) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
 5: v8::internal::Heap::AllocateUninitializedFixedArray(int) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
 6: v8::internal::Factory::NewUninitializedFixedArray(int) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
 7: v8::internal::(anonymous namespace)::ElementsAccessorBase<v8::internal::(anonymous namespace)::FastPackedSmiElementsAccessor, v8::internal::(anonymous namespace)::ElementsKindTraits<(v8::internal::ElementsKind)0> >::GrowCapacityAndConvertImpl(v8::internal::Handle<v8::internal::JSObject>, unsigned int) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
 8: v8::internal::Runtime_GrowArrayElements(int, v8::internal::Object**, v8::internal::Isolate*) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
 9: 9190a23e
10: ad7437bb
11: ad75961b
12: ad73c2fc
13: ad73c004
14: ad73bedf
15: ad74dc4b
16: ad736ee4
17: ad7369ce
18: ad7367ee
19: ad718962
20: ad718a5f
21: 9190b6b6
22: ad7149cf
23: 9190b6b6
24: 9196537d
25: 91964baf
26: 91963e0e
27: 9196198a
28: 9193e83e
29: 91927878
30: v8::internal::Execution::Call(v8::internal::Isolate*, v8::internal::Handle<v8::internal::Object>, v8::internal::Handle<v8::internal::Object>, int, v8::internal::Handle<v8::internal::Object>*) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
31: v8::Function::Call(v8::Local<v8::Context>, v8::Local<v8::Value>, int, v8::Local<v8::Value>*) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
32: v8::Function::Call(v8::Local<v8::Value>, int, v8::Local<v8::Value>*) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
33: node::LoadEnvironment(node::Environment*) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
34: node::StartNodeInstance(void*) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
35: node::Start(int, char**) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
36: main [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
37: _start [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
FATAL ERROR: invalid array length Allocation failed - JavaScript heap out of memory
 1: node::Abort() [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
 2: node::OnFatalError(char const*, char const*) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
 3: v8::Utils::ReportOOMFailure(char const*, bool) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
 4: v8::internal::V8::FatalProcessOutOfMemory(char const*, bool) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
 5: v8::internal::Heap::AllocateUninitializedFixedArray(int) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
 6: v8::internal::Factory::NewUninitializedFixedArray(int) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
 7: v8::internal::(anonymous namespace)::ElementsAccessorBase<v8::internal::(anonymous namespace)::FastPackedSmiElementsAccessor, v8::internal::(anonymous namespace)::ElementsKindTraits<(v8::internal::ElementsKind)0> >::GrowCapacityAndConvertImpl(v8::internal::Handle<v8::internal::JSObject>, unsigned int) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
 8: v8::internal::Runtime_GrowArrayElements(int, v8::internal::Object**, v8::internal::Isolate*) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
 9: fe40a23e
10: a504541b
11: a5056c7b
12: a503c2fc
13: a503c004
14: a503bedf
15: a504c54b
16: a5036ee4
17: a50369ce
18: a50367ee
19: a5018962
20: a5018a5f
21: fe40b6b6
22: a50149cf
23: fe40b6b6
24: fe46537d
25: fe464baf
26: fe463e0e
27: fe46198a
28: fe43e83e
29: fe427878
30: v8::internal::Execution::Call(v8::internal::Isolate*, v8::internal::Handle<v8::internal::Object>, v8::internal::Handle<v8::internal::Object>, int, v8::internal::Handle<v8::internal::Object>*) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
31: v8::Function::Call(v8::Local<v8::Context>, v8::Local<v8::Value>, int, v8::Local<v8::Value>*) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
32: v8::Function::Call(v8::Local<v8::Value>, int, v8::Local<v8::Value>*) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
33: node::LoadEnvironment(node::Environment*) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
34: node::StartNodeInstance(void*) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
35: node::Start(int, char**) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
36: main [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
37: _start [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
FATAL ERROR: invalid array length Allocation failed - JavaScript heap out of memory
 1: node::Abort() [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
 2: node::OnFatalError(char const*, char const*) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
 3: v8::Utils::ReportOOMFailure(char const*, bool) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
 4: v8::internal::V8::FatalProcessOutOfMemory(char const*, bool) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
 5: v8::internal::Heap::AllocateUninitializedFixedArray(int) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
 6: v8::internal::Factory::NewUninitializedFixedArray(int) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
 7: v8::internal::(anonymous namespace)::ElementsAccessorBase<v8::internal::(anonymous namespace)::FastPackedSmiElementsAccessor, v8::internal::(anonymous namespace)::ElementsKindTraits<(v8::internal::ElementsKind)0> >::GrowCapacityAndConvertImpl(v8::internal::Handle<v8::internal::JSObject>, unsigned int) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
 8: v8::internal::Runtime_GrowArrayElements(int, v8::internal::Object**, v8::internal::Isolate*) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
 9: 86b0a23e
10: b78437bb
11: b785735b
12: b783c2fc
13: b783c004
14: b783bedf
15: b784dd6b
16: b7836ee4
17: b78369ce
18: b78367ee
19: b7818962
20: b7818a5f
21: 86b0b6b6
22: b78149cf
23: 86b0b6b6
24: 86b6537d
25: 86b64baf
26: 86b63e0e
27: 86b6198a
28: 86b3e83e
29: 86b27878
30: v8::internal::Execution::Call(v8::internal::Isolate*, v8::internal::Handle<v8::internal::Object>, v8::internal::Handle<v8::internal::Object>, int, v8::internal::Handle<v8::internal::Object>*) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
31: v8::Function::Call(v8::Local<v8::Context>, v8::Local<v8::Value>, int, v8::Local<v8::Value>*) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
32: v8::Function::Call(v8::Local<v8::Value>, int, v8::Local<v8::Value>*) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
33: node::LoadEnvironment(node::Environment*) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
34: node::StartNodeInstance(void*) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
35: node::Start(int, char**) [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
36: main [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
37: _start [/home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/out/Release/node]
Command: out/Release/node /home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-32/test/parallel/test-tick-processor-unknown.js
--- TIMEOUT ---

I pressed control-c after that.

@matthewloring
Copy link

Do you have any information on how long this test ran before producing the error above? tick-processor-base.js will aggregate all vm ticks by repeatedly concatenating them into a string which could grow to many MB in size. If this is a low memory machine, it may hit system memory limits.

@rvagg
Copy link
Member

rvagg commented Sep 28, 2016

Just experienced on master, both Windows and SmartOS https://ci.nodejs.org/job/node-test-commit/5345/

SmartOS machine has a hanging test:

iojs     97388  1.5  0.0 59504 38008 ?        O 01:52:11 60:53 /home/iojs/build/workspace/node-test-commit-smartos/nodes/smartos14-64/out/Release/node --call-graph-size=10 /home/iojs/node-tmp/tmp.1/tick-processor.log /home/iojs/node-tmp/tmp.1/tick-processor.log

@nodejs/platform-solaris is someone around that might be able to hop in to this machine and inspect the process with some dtrace magic to see where it's up to? Ping me on IRC if you get this in the next little while, I'll leave it running.

@rvagg
Copy link
Member

rvagg commented Sep 28, 2016

The windows machine in this run doesn't seem to have a hung process, not sure if that says anything tho.

@imyller
Copy link
Member

imyller commented Sep 28, 2016

So to summarize:

It halts with:

FATAL ERROR: invalid array length Allocation failed - JavaScript heap out of memory

From:

 4: v8::internal::V8::FatalProcessOutOfMemory(char const*, bool) 
 5: v8::internal::Heap::AllocateUninitializedFixedArray(int) 
 6: v8::internal::Factory::NewUninitializedFixedArray(int) 
 7: v8::internal::(anonymous namespace)::ElementsAccessorBase<v8::internal::(anonymous namespace)::FastPackedSmiElementsAccessor, v8::internal::(anonymous namespace)::ElementsKindTraits<(v8::internal::ElementsKind)0> >::GrowCapacityAndConvertImpl(v8::internal::Handle<v8::internal::JSObject>, unsigned int) 
 8: v8::internal::Runtime_GrowArrayElements(int, v8::internal::Object**, v8::internal::Isolate*) 

with code, which is setImmediate -powered infinite loop, started in child process node through -pe flag and profiler log file enabled and it's stdout logged to a variable:

         function f() {
           for (var i = 0; i < 1000000; i++) {
             i++;
           }
           setImmediate(function() { f(); });
         };
         f();

And then that child process happily runs this infinite loop until eventually falling with out of heap memory.

Meanwhile the parent process (the actual test code) starts every 750 milliseconds a new node child process which is started as --prof-process to process the v8 profiler log file created by infinite-loop runner's --prof. The processed stdout output is then searched for predefined pattern:

/LazyCompile.*\[eval\]:1|.*%  UNKNOWN/

If this pattern is found, SIGTERM is sent to the infinite-loop process and test concludes successfully. If pattern is not found, new profiler processing child process is again started every 750 millisecond until eternity - even if the infinite-loop process has meanwhile failed in out of heap memory condition or something else.

Correct?

(alternate path is that @Trott log out of heap memory comes from parent test process because stdout chunk var grows too large as pattern is never found, but it's still a variation of the same theme)

@imyller
Copy link
Member

imyller commented Sep 28, 2016

Also something to note: it very much looks like all parallel test-tick-processor tests possibly share the same common.tmpDir + 'tick_processor.log' because tmpDir is unique to TEST_THREAD_ID coming from tools/test.py. (?)

This could easily lead to very mixed file to parse for --prof-process, and not finding the matching pattern - and leaving the infinite-loop process run until heap mem starvation.

edit: haven't actually logged/tested this yet, but wanted to list here as one possible cause of failure

@Trott
Copy link
Member

Trott commented Sep 28, 2016

@matthewloring asked:

Do you have any information on how long this test ran before producing the error above?

The timeout in the test runner was 60 seconds.

@Trott
Copy link
Member

Trott commented Sep 28, 2016

@imyller wrote:

Also something to note: it very much looks like all parallel test-tick-processor tests possibly share the same common.tmpDir + 'tick_processor.log'

They will not share the same tmpDir unless they run one after the other, in which case, tmpDir is unlinked by the test itself (well, in this case, by the fixture file, using common.refreshTmpDir()) before using.

So, unless I'm misunderstanding, there shouldn't be mixed up files or anything like that.

@Trott
Copy link
Member

Trott commented Sep 28, 2016

@imyller wrote a detailed observation of how the test is failing, then asked:

Correct?

I think what you wrote in that comment is correct. @matthewloring @indutny @geek or others can hopefully provide a more informed evaluation than mine, though.

@matthewloring
Copy link

This description matches my understanding.

@geek
Copy link
Member

geek commented Sep 28, 2016

@Trott, running it with --repeat=5 did result in a timeout. Dropping the RETRY_TIMEOUT in the test to 200ms (5a17139#diff-b1d2dd5b403a2e96c6a17506dd505f5bR10) corrected that.

To confirm the results I tried again with --repeat=10 and found a bug in

firstLine = firstLine.split(',');
<-- which is not always a string (
function readline() {
while (true) {
const lineBreak = line.indexOf('\n');
if (lineBreak !== -1) {
const res = line.slice(0, lineBreak);
line = line.slice(lineBreak + 1);
return res;
}
const bytes = fs.readSync(fd, buf, 0, buf.length);
line += dec.write(buf.slice(0, bytes));
if (line.length === 0) {
return false;
}
}
)

@Trott
Copy link
Member

Trott commented Sep 30, 2016

@geek I see you opened a PR to fix the tests. Woo hoo and thanks! Do you also intend to open a PR to fix the issue in v8_prof_polyfill.js? /cc @matthewloring

@matthewloring
Copy link

I agree that firstLine may not always be a string but that is only the case if the file does not include the \n character. If the tick profile output does not have any new lines then things are in a bad state (though better handling of this error case would be good). Are you encountering failures on the split call or did you find this from reading the code?

@mhdawson
Copy link
Member Author

mhdawson commented Oct 5, 2016

Also test-tick-processor-builtin failure on PPC BE similar to one mentioned for raspberry pi: https://ci.nodejs.org/job/node-test-commit-plinux/nodes=ppcle-ubuntu1404/4608/console

@MylesBorins
Copy link
Contributor

@Trott
Copy link
Member

Trott commented Nov 1, 2016

I modified the test to always print the output from the process that consumes the tick log file. On smartos14-32 (where we seem to see failures the most), when it blows up with this after about 20 seconds:

not ok 1 parallel/test-tick-processor-unknown
# FATAL ERROR: invalid array length Allocation failed - JavaScript heap out of memory
#  1: node::Abort() [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
#  2: node::OnFatalError(char const*, char const*) [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
#  3: v8::Utils::ReportOOMFailure(char const*, bool) [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
#  4: v8::internal::V8::FatalProcessOutOfMemory(char const*, bool) [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
#  5: v8::internal::Heap::AllocateUninitializedFixedArray(int) [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
#  6: v8::internal::Factory::NewUninitializedFixedArray(int) [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
#  7: v8::internal::(anonymous namespace)::ElementsAccessorBase<v8::internal::(anonymous namespace)::FastPackedSmiElementsAccessor, v8::internal::(anonymous namespace)::ElementsKindTraits<(v8::internal::ElementsKind)0> >::GrowCapacityAndConvertImpl(v8::internal::Handle<v8::internal::JSObject>, unsigned int) [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
#  8: v8::internal::Runtime_GrowArrayElements(int, v8::internal::Object**, v8::internal::Isolate*) [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
#  9: a150a23e
# 10: 87646d3b
# 11: 87664536
# 12: 8763f03c
# 13: 8764cf82
# 14: 8763ebc6
# 15: 8764f1eb
# 16: 87639c24
# 17: 8763970e
# 18: 8763952e
# 19: 876197a2
# 20: 8761989f
# 21: a150b6b6
# 22: 8761580f
# 23: a150b6b6
# 24: a15653dd
# 25: a1564c0f
# 26: a1563e6d
# 27: a15619b7
# 28: a153e83e
# 29: a1527878
# 30: v8::internal::Execution::Call(v8::internal::Isolate*, v8::internal::Handle<v8::internal::Object>, v8::internal::Handle<v8::internal::Object>, int, v8::internal::Handle<v8::internal::Object>*) [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
# 31: v8::Function::Call(v8::Local<v8::Context>, v8::Local<v8::Value>, int, v8::Local<v8::Value>*) [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
# 32: v8::Function::Call(v8::Local<v8::Value>, int, v8::Local<v8::Value>*) [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
# 33: node::LoadEnvironment(node::Environment*) [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
# 34: node::Start(uv_loop_s*, int, char const* const*, int, char const* const*) [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
# 35: node::Start(int, char**) [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
# 36: main [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]
# 37: _start [/home/iojs/build/workspace/node-stress-single-test/nodes/smartos14-32/out/Release/node]

...this is the contents of the output from the process that consumes the log file:

# line 965: Key not found: 99
# line 966: Key not found: 99
# line 967: Key not found: 99
# line 970: Key not found: 99
# line 971: Key not found: 99
# line 972: Key not found: 99
# line 973: Key not found: 99
# line 975: Key not found: 99
# line 976: Key not found: 99
# line 977: Key not found: 99
# line 979: Key not found: 99
# line 980: Key not found: 99
# line 982: Key not found: 99
# line 983: Key not found: 99
# line 984: Key not found: 99
# line 985: Key not found: 99
# line 986: Key not found: 99
# line 987: Key not found: 99
# line 988: Key not found: 99
# line 989: Key not found: 99
# line 990: Key not found: 99
# line 991: Key not found: 99
# line 993: Key not found: 99
# line 994: Key not found: 99
# line 996: Key not found: 99
# line 997: Key not found: 99
# line 998: Key not found: 99
# line 999: Key not found: 99
# line 1000: Key not found: 99
# line 1001: Key not found: 99
# line 1002: Key not found: 99
# line 1003: Key not found: 99
# line 1004: Key not found: 99
# line 1005: Key not found: 99
# line 1006: Key not found: 99
# line 1007: Key not found: 99
# line 1008: Key not found: 99
# line 1009: Key not found: 99
# line 1010: Key not found: 99
# line 1012: Key not found: 99
# line 1014: Key not found: 99
# line 1016: Key not found: 99
# line 1017: Key not found: 99
# line 1018: Key not found: 99
# line 1020: Key not found: 99
# line 1021: Key not found: 99
# line 1022: Key not found: 99
# line 1023: Key not found: 99
# line 1025: Key not found: 99
# line 1026: Key not found: 99
# line 1027: Key not found: 99
# line 1028: Key not found: 99
# line 1029: Key not found: 99
# line 1030: Key not found: 99
# line 1032: Key not found: 99
# line 1033: Key not found: 99
# line 1034: Key not found: 99
# line 1035: Key not found: 99
# line 1036: Key not found: 99
# line 1037: Key not found: 99
# line 1038: Key not found: 99
# line 1039: Key not found: 99
# line 1041: Key not found: 99
# line 1042: Key not found: 99
# line 1043: Key not found: 99
# line 1044: Key not found: 99
# line 1045: Key not found: 99
# line 1046: Key not found: 99
# line 1047: Key not found: 99
# line 1048: Key not found: 99
# line 1049: Key not found: 99
# line 1050: Key not found: 99
# line 1051: Key not found: 99
# line 1052: Key not found: 99
# line 1053: Key not found: 99
# line 1054: Key not found: 99
# line 1055: Key not found: 99
# line 1057: Key not found: 99
# line 1058: Key not found: 99
# line 1063: Key not found: 99
# line 1064: Key not found: 99
# line 1065: Key not found: 99
# line 1066: Key not found: 99
# line 1071: Key not found: 99
# line 1072: Key not found: 99
# line 1074: Key not found: 99
# line 1076: Key not found: 99
# line 1077: Key not found: 99
# line 1078: Key not found: 99
# line 1079: Key not found: 99
# line 1080: Key not found: 99
# line 1081: Key not found: 99
# line 1082: Key not found: 99
# line 1083: Key not found: 99
# line 1084: Key not found: 99
# line 1085: Key not found: 99
# line 1086: Key not found: 99
# line 1088: Key not found: 99
# line 1089: Key not found: 99
# line 1090: Key not found: 99
# line 1091: Key not found: 99
# line 1093: Key not found: 99
# line 1095: Key not found: 99
# line 1096: Key not found: 99
# line 1097: Key not found: 99
# line 1098: Key not found: 99
# line 1099: Key not found: 99
# line 1101: Key not found: 99
# line 1102: Key not found: 99
# line 1103: Key not found: 99
# line 1104: Key not found: 99
# line 1105: Key not found: 99
# line 1107: Key not found: 99
# line 1108: Key not found: 99
# line 1109: Key not found: 99
# line 1110: Key not found: 99
# line 1111: Key not found: 99
# line 1112: Key not found: 99
# line 1113: Key not found: 99
# line 1114: Key not found: 99
# line 1115: Key not found: 99
# line 1116: Key not found: 99
# line 1117: Key not found: 99
# line 1118: Key not found: 99
# line 1120: Key not found: 99
# line 1121: Key not found: 99
# line 1122: Key not found: 99
# line 1123: Key not found: 99
# line 1124: Key not found: 99
# line 1125: Key not found: 99
# line 1126: Key not found: 99
# line 1130: Key not found: 99
# line 1132: Key not found: 99
# line 1133: Key not found: 99
# line 1134: Key not found: 99
# line 1135: Key not found: 99
# line 1136: Key not found: 99
# line 1138: Key not found: 99
# line 1139: Key not found: 99
# 
# <--- Last few GCs --->
# 
# [88793:a184008]    20498 ms: Scavenge 403.6 (409.1) -> 401.7 (409.1) MB, 0.0 / 0.0 ms  allocation failure 
# [88793:a184008]    20501 ms: Scavenge 403.6 (409.1) -> 401.7 (409.1) MB, 0.0 / 0.0 ms  allocation failure 
# [88793:a184008]    20504 ms: Scavenge 403.6 (409.1) -> 401.7 (409.1) MB, 0.0 / 0.0 ms  allocation failure 
# [88793:a184008]    20506 ms: Scavenge 403.6 (409.1) -> 401.7 (409.1) MB, 0.0 / 0.0 ms  allocation failure 
# 
# 
# <--- JS stacktrace --->
# 
# ==== JS stack trace =========================================
# 
# Security context: 0xb62739dd <JS Object>
#     2: deleteAllCoveredNodes_ [0xb62081a1 <undefined>:~612] [pc=87664536](this=0xa4508fcd <a CodeMap with map 9c21501d>,tree=0xa4518fcd <a SplayTree with map 9c215729>,start=8,end=0xa456e965 <Number: 1696>)
#     3: addCode [0xb62081a1 <undefined>:543] [pc=8763f03c](this=0xa4508fcd <a CodeMap with map 9c21501d>,start=8,codeEntry=0xa456e971 <JS Object>)
#     4: addFuncCode [0xb62081a1 <undefined>:1110]...
# 
# 

Is this at all useful for determining what's going wrong? @matthewloring @indutny @misterdjules

@matthewloring
Copy link

Hmm, that's interesting, that error likely comes from the splay tree implementation used by the tick processor inside V8. I can take a look.

@Trott
Copy link
Member

Trott commented Jul 15, 2017

I haven't seen this issue in a very long time. Probably #9506 mitigated it sufficiently that it doesn't happen anymore (or happens with such infrequency as to be indistinguishable from not happening anymore). Feel free to comment (or re-open) if you disagree, but I'm going to close this.

@Trott Trott closed this as completed Jul 15, 2017
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
test Issues and PRs related to the tests. v8 engine Issues and PRs related to the V8 dependency.
Projects
None yet
Development

No branches or pull requests