Investigate flaky test-http-same-map on debug builds #22775

Trott · 2018-09-09T16:08:55Z

Version: 11.0.0-pre (master)
Platform: ubuntu1604_sharedlibs_debug_x64
Subsystem: test http

https://ci.nodejs.org/job/node-test-commit-linux-containered/6927/nodes=ubuntu1604_sharedlibs_debug_x64/console

00:41:54 not ok 895 parallel/test-http-same-map
00:41:54   ---
00:41:54   duration_ms: 3.139
00:41:54   severity: crashed
00:41:54   exitcode: -6
00:41:54   stack: |-
00:41:54     DebugPrint: 0x1e193d7108e9: [JS_OBJECT_TYPE]
00:41:54      - map: 0x1660a466d2e9 <Map(HOLEY_ELEMENTS)> [FastProperties]
00:41:54      - prototype: 0x1e193d724231 <Object map = 0x1660a466aa01>
00:41:54      - elements: 0x371eea8023b1 <FixedArray[0]> [HOLEY_ELEMENTS]
00:41:54      - properties: 0x371eea8023b1 <FixedArray[0]> {
00:41:54         #_readableState: 0x1e193d7109c9 <ReadableState map = 0x1660a4667bf1> (data field 0)
00:41:54         #readable: 0x371eea8029a1 <false> (data field 1)
00:41:54         #_events: 0x1e193d710b59 <Object map = 0x1660a4603a69> (data field 2)
00:41:54         #_eventsCount: 0 (data field 3)
00:41:54         #_maxListeners: 0x371eea8026f1 <undefined> (data field 4)
00:41:54         #socket: 0x1e193d70fb01 <Socket map = 0x1660a466c9f9> (data field 5)
00:41:54         #connection: 0x1e193d70fb01 <Socket map = 0x1660a466c9f9> (data field 6)
00:41:54         #httpVersionMajor: 1 (data field 7)
00:41:54         #httpVersionMinor: 1 (data field 8)
00:41:54         #httpVersion: 0x1e193d710c01 <String[3]: 1.1> (data field 9)
00:41:54         #complete: 0x371eea8028c9 <true> (data field 10)
00:41:54         #headers: 0x1e193d710b71 <Object map = 0x1660a466bdf1> (data field 11)
00:41:54         #rawHeaders: 0x1e193d710781 <JSArray[4]> (data field 12)
00:41:54         #trailers: 0x1e193d710ba9 <Object map = 0x1660a4602571> (data field 13)
00:41:54         #rawTrailers: 0x1e193d710be1 <JSArray[0]> (data field 14)
00:41:54         #aborted: 0x371eea8029a1 <false> (data field 15)
00:41:54         #upgrade: 0x371eea8029a1 <false> (data field 16)
00:41:54         #url: 0x0e10b9685229 <String[1]: /> (data field 17)
00:41:54         #method: 0x1e193d720509 <String[3]: GET> (data field 18)
00:41:54         #statusCode: 0x371eea8022b1 <null> (data field 19)
00:41:54         #statusMessage: 0x371eea8022b1 <null> (data field 20)
00:41:54         #client: 0x1e193d70fb01 <Socket map = 0x1660a466c9f9> (data field 21)
00:41:54         #_consuming: 0x371eea8029a1 <false> (data field 22)
00:41:54         #_dumped: 0x371eea8028c9 <true> (data field 23)
00:41:54      }
00:41:54     0x1660a466d2e9: [Map]
00:41:54      - type: JS_OBJECT_TYPE
00:41:54      - instance size: 224
00:41:54      - inobject properties: 25
00:41:54      - elements kind: HOLEY_ELEMENTS
00:41:54      - unused property fields: 1
00:41:54      - enum length: invalid
00:41:54      - back pointer: 0x1660a466d449 <Map(HOLEY_ELEMENTS)>
00:41:54      - prototype_validity cell: 0x282397537901 <Cell value= 0>
00:41:54      - instance descriptors #24: 0x1e193d70d791 <DescriptorArray[92]>
00:41:54      - layout descriptor: 0
00:41:54      - transitions #1: 0x1660a466d4a1 <Map(HOLEY_ELEMENTS)>
00:41:54          #req: (transition to (data field, attrs: [WEC]) @ FATAL ERROR: v8::HandleScope::CreateHandle() Cannot create a handle without a HandleScope
00:41:54      1: 0x1a14311 node::DumpBacktrace(_IO_FILE*) [out/Debug/node]
00:41:54      2: 0x1a5162d node::Abort() [out/Debug/node]
00:41:54      3: 0x1a522ce node::FatalError(char const*, char const*) [out/Debug/node]
00:41:54      4: 0x1df62ce v8::Utils::ReportApiFailure(char const*, char const*) [out/Debug/node]
00:41:54      5: 0x1de3251 v8::Utils::ApiCheck(bool, char const*, char const*) [out/Debug/node]
00:41:54      6: 0x24daff2 v8::internal::HandleScope::Extend(v8::internal::Isolate*) [out/Debug/node]
00:41:54      7: 0x1dcce0a v8::internal::HandleScope::CreateHandle(v8::internal::Isolate*, v8::internal::Object*) [out/Debug/node]
00:41:54      8: 0x1dccede v8::internal::HandleScope::GetHandle(v8::internal::Isolate*, v8::internal::Object*) [out/Debug/node]
00:41:54      9: 0x1dccb27 v8::internal::HandleBase::HandleBase(v8::internal::Object*, v8::internal::Isolate*) [out/Debug/node]
00:41:54     10: 0x1ddedc1 v8::internal::Handle<v8::internal::Map>::Handle(v8::internal::Map*, v8::internal::Isolate*) [out/Debug/node]
00:41:54     11: 0x1efa18a v8::internal::Handle<v8::internal::Map> v8::internal::handle<v8::internal::Map>(v8::internal::Map*, v8::internal::Isolate*) [out/Debug/node]
00:41:54     12: 0x24c0cbe v8::internal::FieldType::AsClass() [out/Debug/node]
00:41:54     13: 0x24c0f01 v8::internal::FieldType::PrintTo(std::ostream&) [out/Debug/node]
00:41:54     14: 0x2704384 v8::internal::DescriptorArray::PrintDescriptorDetails(std::ostream&, int, v8::internal::PropertyDetails::PrintMode) [out/Debug/node]
00:41:54     15: 0x2704726 v8::internal::TransitionsAccessor::PrintOneTransition(std::ostream&, v8::internal::Name*, v8::internal::Map*) [out/Debug/node]
00:41:54     16: 0x27048c4 v8::internal::TransitionsAccessor::PrintTransitions(std::ostream&) [out/Debug/node]
00:41:54     17: 0x26fbcf8 v8::internal::Map::MapPrint(std::ostream&) [out/Debug/node]
00:41:54     18: 0x26f8d48 v8::internal::HeapObject::HeapObjectPrint(std::ostream&) [out/Debug/node]
00:41:54     19: 0x26f8b3f v8::internal::Object::Print(std::ostream&) [out/Debug/node]
00:41:54     20: 0x29a32fb  [out/Debug/node]
00:41:54     21: 0x29a2f9d v8::internal::Runtime_DebugPrint(int, v8::internal::Object**, v8::internal::Isolate*) [out/Debug/node]
00:41:54     22: 0x39d65831695f 
00:41:54   ...

Trott · 2018-09-13T17:23:49Z

Again today:

https://ci.nodejs.org/job/node-test-commit-linux-containered/7018/nodes=ubuntu1604_sharedlibs_debug_x64/console

00:39:11 not ok 895 parallel/test-http-same-map
00:39:11   ---
00:39:11   duration_ms: 3.241
00:39:11   severity: crashed
00:39:11   exitcode: -6
00:39:11   stack: |-
00:39:11     DebugPrint: 0x3661c5a8add1: [JS_OBJECT_TYPE]
00:39:11      - map: 0x0af4cf36c689 <Map(HOLEY_ELEMENTS)> [FastProperties]
00:39:11      - prototype: 0x3661c5a958c1 <Object map = 0xaf4cf369da1>
00:39:11      - elements: 0x2fe31d3023b1 <FixedArray[0]> [HOLEY_ELEMENTS]
00:39:11      - properties: 0x2fe31d3023b1 <FixedArray[0]> {
00:39:11         #_readableState: 0x3661c5a8aeb1 <ReadableState map = 0xaf4cf366f91> (data field 0)
00:39:12         #readable: 0x2fe31d3029a1 <false> (data field 1)
00:39:12         #_events: 0x3661c5a8b041 <Object map = 0xaf4cf303a69> (data field 2)
00:39:12         #_eventsCount: 0 (data field 3)
00:39:12         #_maxListeners: 0x2fe31d3026f1 <undefined> (data field 4)
00:39:12         #socket: 0x3661c5a89fe9 <Socket map = 0xaf4cf36bd99> (data field 5)
00:39:12         #connection: 0x3661c5a89fe9 <Socket map = 0xaf4cf36bd99> (data field 6)
00:39:12         #httpVersionMajor: 1 (data field 7)
00:39:12         #httpVersionMinor: 1 (data field 8)
00:39:12         #httpVersion: 0x3661c5a8b0e9 <String[3]: 1.1> (data field 9)
00:39:12         #complete: 0x2fe31d3028c9 <true> (data field 10)
00:39:12         #headers: 0x3661c5a8b059 <Object map = 0xaf4cf36b191> (data field 11)
00:39:12         #rawHeaders: 0x3661c5a8ac69 <JSArray[4]> (data field 12)
00:39:12         #trailers: 0x3661c5a8b091 <Object map = 0xaf4cf302571> (data field 13)
00:39:12         #rawTrailers: 0x3661c5a8b0c9 <JSArray[0]> (data field 14)
00:39:12         #aborted: 0x2fe31d3029a1 <false> (data field 15)
00:39:12         #upgrade: 0x2fe31d3029a1 <false> (data field 16)
00:39:12         #url: 0x13d0c9484e11 <String[1]: /> (data field 17)
00:39:12         #method: 0x0865fa0c58b9 <String[3]: GET> (data field 18)
00:39:12         #statusCode: 0x2fe31d3022b1 <null> (data field 19)
00:39:12         #statusMessage: 0x2fe31d3022b1 <null> (data field 20)
00:39:12         #client: 0x3661c5a89fe9 <Socket map = 0xaf4cf36bd99> (data field 21)
00:39:12         #_consuming: 0x2fe31d3029a1 <false> (data field 22)
00:39:12         #_dumped: 0x2fe31d3028c9 <true> (data field 23)
00:39:12      }
00:39:12     0xaf4cf36c689: [Map]
00:39:12      - type: JS_OBJECT_TYPE
00:39:12      - instance size: 224
00:39:12      - inobject properties: 25
00:39:12      - elements kind: HOLEY_ELEMENTS
00:39:12      - unused property fields: 1
00:39:12      - enum length: invalid
00:39:12      - back pointer: 0x0af4cf36c7e9 <Map(HOLEY_ELEMENTS)>
00:39:12      - prototype_validity cell: 0x0da2858bbbd9 <Cell value= 0>
00:39:12      - instance descriptors #24: 0x3661c5a87c79 <DescriptorArray[92]>
00:39:12      - layout descriptor: 0
00:39:12      - transitions #1: 0x0af4cf36c841 <Map(HOLEY_ELEMENTS)>
00:39:12          #req: (transition to (data field, attrs: [WEC]) @ FATAL ERROR: v8::HandleScope::CreateHandle() Cannot create a handle without a HandleScope
00:39:12      1: 0x1a151c7 node::DumpBacktrace(_IO_FILE*) [out/Debug/node]
00:39:12      2: 0x1a523d5 node::Abort() [out/Debug/node]
00:39:12      3: 0x1a53076 node::FatalError(char const*, char const*) [out/Debug/node]
00:39:12      4: 0x1df57d4 v8::Utils::ReportApiFailure(char const*, char const*) [out/Debug/node]
00:39:12      5: 0x1de2757 v8::Utils::ApiCheck(bool, char const*, char const*) [out/Debug/node]
00:39:12      6: 0x24da4f8 v8::internal::HandleScope::Extend(v8::internal::Isolate*) [out/Debug/node]
00:39:12      7: 0x1dcc310 v8::internal::HandleScope::CreateHandle(v8::internal::Isolate*, v8::internal::Object*) [out/Debug/node]
00:39:12      8: 0x1dcc3e4 v8::internal::HandleScope::GetHandle(v8::internal::Isolate*, v8::internal::Object*) [out/Debug/node]
00:39:12      9: 0x1dcc02d v8::internal::HandleBase::HandleBase(v8::internal::Object*, v8::internal::Isolate*) [out/Debug/node]
00:39:12     10: 0x1dde2c7 v8::internal::Handle<v8::internal::Map>::Handle(v8::internal::Map*, v8::internal::Isolate*) [out/Debug/node]
00:39:12     11: 0x1ef9690 v8::internal::Handle<v8::internal::Map> v8::internal::handle<v8::internal::Map>(v8::internal::Map*, v8::internal::Isolate*) [out/Debug/node]
00:39:12     12: 0x24c01c4 v8::internal::FieldType::AsClass() [out/Debug/node]
00:39:12     13: 0x24c0407 v8::internal::FieldType::PrintTo(std::ostream&) [out/Debug/node]
00:39:12     14: 0x270388a v8::internal::DescriptorArray::PrintDescriptorDetails(std::ostream&, int, v8::internal::PropertyDetails::PrintMode) [out/Debug/node]
00:39:12     15: 0x2703c2c v8::internal::TransitionsAccessor::PrintOneTransition(std::ostream&, v8::internal::Name*, v8::internal::Map*) [out/Debug/node]
00:39:12     16: 0x2703dca v8::internal::TransitionsAccessor::PrintTransitions(std::ostream&) [out/Debug/node]
00:39:12     17: 0x26fb1fe v8::internal::Map::MapPrint(std::ostream&) [out/Debug/node]
00:39:12     18: 0x26f824e v8::internal::HeapObject::HeapObjectPrint(std::ostream&) [out/Debug/node]
00:39:12     19: 0x26f8045 v8::internal::Object::Print(std::ostream&) [out/Debug/node]
00:39:12     20: 0x29a2801  [out/Debug/node]
00:39:12     21: 0x29a24a3 v8::internal::Runtime_DebugPrint(int, v8::internal::Object**, v8::internal::Isolate*) [out/Debug/node]
00:39:12     22: 0x36335599695f 
00:39:12   ...

Trott · 2018-09-13T17:24:32Z

/ping @targos since I think he does stuff with debug builds a lot (although I think it's not containered and that may be important to the equation here?)

refack · 2018-09-13T22:42:10Z

I bisected it to V8 6.9 (#21983). It's perma-failing since then.

Trott · 2018-09-14T05:04:31Z

@nodejs/v8 Not sure if this is a V8 issue, or if it's just a change in V8 exposing a problem elsewhere, but I don't know who else to loop in, so I'm going with V8 folks...

addaleax · 2018-09-14T18:36:27Z

It seems like it exposes some kind of V8 bug, even though we’re doing things we’re not really supposed to in the test.

It’s not obvious why this started failing, and whether the fix is straightforward (adding a handle scope somewhere) or not (if creating handles is actually not okay). So, I’ll try to check canary to figure out whether this has been fixed upstream and/or bisect V8 to figure out which commit introduced this.

addaleax · 2018-09-14T19:12:36Z

It looks like this is fixed on canary.

Trott · 2018-09-15T11:25:45Z

It looks like this is fixed on canary.

How long before the canary build ends up in our master branch? Should we do a bisect to try to identify the commit that fixes it and see if we can float that as a patch?

targos · 2018-09-15T11:39:30Z

@Trott Between 2 and 3 months. It might already be fixed in V8 7.0. I have a local debug build with this version. How can I test it?

Trott · 2018-09-15T11:44:49Z

How can I test it?

@targos If there's a branch on GitHub that we can point the CI host at, we can build from that and test on that host. Otherwise, I guess the first step is to try to make a debug version fail the test locally for you. However, I'm not sure the problem will show up on debug builds in all environments.

@refack Did you do your bisect by running the test on the Jenkins host or did you do that locally?

targos · 2018-09-15T11:50:21Z

That's the branch: https://github.com/targos/node/commits/v8-7.0

refack · 2018-09-15T15:15:11Z

@refack Did you do your bisect by running the test on the Jenkins host or did you do that locally?

I did it on the Jenkins host. I'll run it against our canary-base. Else we could flag this test to skip on debug builds (then I'll change the debug job to fail instead just being unstable)

refack · 2018-09-15T15:23:13Z

🤦‍♂️ build blocked because:

../deps/v8/src/builtins/builtins-definitions.h:8:56: fatal error: builtins-generated/bytecodes-builtins-list.h: No such file or directory

Which is on me nodejs/node-v8#75
So need a few more hours

Trott · 2018-09-15T16:19:39Z

Running against the branch @targos specified which has V8 7.0: https://ci.nodejs.org/job/node-test-commit-linux-containered/7076/

Trott · 2018-09-15T16:22:58Z

(I don't see an easy way to do stress testing against ubuntu1604_sharedlibs_debug_x64 but this errors out so consistently that one test run followed by two or three rebuilds will tell us what we need to know, probably.)

refack · 2018-09-15T23:13:19Z

I don't see an easy way to do stress testing

In my experience it's 100% reproducible, you could simply checkout that branch locally, ./configure --debug and stress.

* test-http-same-map.js Refs: nodejs#22775

Trott · 2018-09-15T23:55:47Z

It's green against the targos V8 7.0 branch. 🎉

Trott · 2018-09-17T01:58:41Z

When can we expect V8 7.0 can land in master? Does it make sense to try to find the commit that fixes this and backport it to our version on master? Or does it make sense to wait for V8 7.0 to land in master instead?

hashseed · 2018-09-17T05:27:06Z

Just looks like a missing HandleScope. I'll create a PR to fix.

hashseed · 2018-09-17T05:37:59Z

FWIW, this refactoring was the fix. I'm going to fix it more locally.

Refs: nodejs#22775

hashseed · 2018-09-17T05:48:20Z

The fix is here: #22890

Refs: #22775 PR-URL: #22890 Reviewed-By: Ruben Bridgewater <ruben@bridgewater.de> Reviewed-By: Anna Henningsen <anna@addaleax.net> Reviewed-By: Refael Ackermann <refack@gmail.com>

It is not required with V8 7.0 as per nodejs/node#22775

addaleax added the v8 engine Issues and PRs related to the V8 dependency. label Sep 14, 2018

refack added a commit to refack/node that referenced this issue Sep 15, 2018

test: expect test to fail in debug builds

71fcdd7

* test-http-same-map.js Refs: nodejs#22775

refack mentioned this issue Sep 15, 2018

test: expect test to fail in debug builds #22881

Closed

4 tasks

hashseed added a commit to hashseed/node that referenced this issue Sep 17, 2018

deps: add missing HandleScope in FieldType::PrintTo

4e596b2

Refs: nodejs#22775

addaleax mentioned this issue Sep 17, 2018

deps: add missing HandleScope in FieldType::PrintTo #22890

Closed

1 task

addaleax closed this as completed Sep 18, 2018

deepak1556 added a commit to electron/electron that referenced this issue Oct 25, 2018

fix: remove deps_add_missing_handlescope_in_fieldtype_printto.patch

414f0aa

It is not required with V8 7.0 as per nodejs/node#22775

MarshallOfSound pushed a commit to electron/electron that referenced this issue Oct 26, 2018

fix: remove deps_add_missing_handlescope_in_fieldtype_printto.patch

bc8c909

It is not required with V8 7.0 as per nodejs/node#22775

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Investigate flaky test-http-same-map on debug builds #22775

Investigate flaky test-http-same-map on debug builds #22775

Trott commented Sep 9, 2018

Trott commented Sep 13, 2018

Trott commented Sep 13, 2018

refack commented Sep 13, 2018

Trott commented Sep 14, 2018

addaleax commented Sep 14, 2018

addaleax commented Sep 14, 2018

Trott commented Sep 15, 2018

targos commented Sep 15, 2018

Trott commented Sep 15, 2018

targos commented Sep 15, 2018

refack commented Sep 15, 2018

refack commented Sep 15, 2018

Trott commented Sep 15, 2018

Trott commented Sep 15, 2018

refack commented Sep 15, 2018

Trott commented Sep 15, 2018

Trott commented Sep 17, 2018

hashseed commented Sep 17, 2018

hashseed commented Sep 17, 2018

hashseed commented Sep 17, 2018

Investigate flaky test-http-same-map on debug builds #22775

Investigate flaky test-http-same-map on debug builds #22775

Comments

Trott commented Sep 9, 2018

Trott commented Sep 13, 2018

Trott commented Sep 13, 2018

refack commented Sep 13, 2018

Trott commented Sep 14, 2018

addaleax commented Sep 14, 2018

addaleax commented Sep 14, 2018

Trott commented Sep 15, 2018

targos commented Sep 15, 2018

Trott commented Sep 15, 2018

targos commented Sep 15, 2018

refack commented Sep 15, 2018

refack commented Sep 15, 2018

Trott commented Sep 15, 2018

Trott commented Sep 15, 2018

refack commented Sep 15, 2018

Trott commented Sep 15, 2018

Trott commented Sep 17, 2018

hashseed commented Sep 17, 2018

hashseed commented Sep 17, 2018

hashseed commented Sep 17, 2018