Closed Bug 1493365 Opened 6 years ago Closed 6 years ago

Intermittent PLDHashTableTest.GrowToMaxCapacity | Value of: false

Categories

(Core :: XPCOM, defect, P5)

defect

Tracking

()

RESOLVED FIXED
mozilla64
Tracking Status
firefox64 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: gsvelto)

Details

(Keywords: intermittent-failure, Whiteboard: [retriggered])

Attachments

(1 file)

Filed by: apavel [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=200905462&repo=autoland

https://queue.taskcluster.net/v1/task/W3_nTPAmQjKT1aeEt0NSDw/runs/0/artifacts/public/logs/live_backing.log

[task 2018-09-22T00:25:47.946Z] 00:25:47     INFO -  TestCrashyOperation: The following crash is expected. Do not panic.
[task 2018-09-22T00:25:47.947Z] 00:25:47     INFO -  Hit MOZ_CRASH(Entry size is too large) at /builds/worker/workspace/build/src/xpcom/ds/PLDHashTable.cpp:216
[task 2018-09-22T00:25:47.947Z] 00:25:47     INFO -  #01: InitCapacityOk_EntrySizeTooBig() [xpcom/tests/gtest/TestPLDHash.cpp:111]
[task 2018-09-22T00:25:47.947Z] 00:25:47     INFO -  #02: TestCrashyOperation(void (*)()) [xpcom/tests/gtest/TestPLDHash.cpp:58]
[task 2018-09-22T00:25:47.947Z] 00:25:47     INFO -  #03: PLDHashTableTest_InitCapacityOk_Test::TestBody() [xpcom/tests/gtest/TestPLDHash.cpp:142]
[task 2018-09-22T00:25:47.947Z] 00:25:47     INFO -  #04: testing::Test::Run() [testing/gtest/gtest/src/gtest.cc:4921]
[task 2018-09-22T00:25:47.947Z] 00:25:47     INFO -  #05: testing::TestInfo::Run() [testing/gtest/gtest/src/gtest.cc:4921]
[task 2018-09-22T00:25:47.947Z] 00:25:47     INFO -  #06: testing::TestCase::Run() [testing/gtest/gtest/src/gtest.cc:2775]
[task 2018-09-22T00:25:47.947Z] 00:25:47     INFO -  #07: testing::internal::UnitTestImpl::RunAllTests() [testing/gtest/gtest/src/gtest.cc:4650]
[task 2018-09-22T00:25:47.947Z] 00:25:47     INFO -  #08: testing::UnitTest::Run() [testing/gtest/gtest/src/gtest.cc:4259]
[task 2018-09-22T00:25:47.947Z] 00:25:47     INFO -  #09: mozilla::RunGTestFunc(int*, char**) [testing/gtest/gtest/include/gtest/gtest.h:2233]
[task 2018-09-22T00:25:47.947Z] 00:25:47     INFO -  #10: XREMain::XRE_mainStartup(bool*) [toolkit/xre/nsAppRunner.cpp:4014]
[task 2018-09-22T00:25:47.948Z] 00:25:47     INFO -  #11: XREMain::XRE_main(int, char**, mozilla::BootstrapConfig const&) [toolkit/xre/nsAppRunner.cpp:4953]
[task 2018-09-22T00:25:47.950Z] 00:25:47     INFO -  #12: XRE_main(int, char**, mozilla::BootstrapConfig const&) [toolkit/xre/nsAppRunner.cpp:5060]
[task 2018-09-22T00:25:47.950Z] 00:25:47     INFO -  #13: _fini
[task 2018-09-22T00:25:47.950Z] 00:25:47     INFO -  #14: libc.so.6 + 0x20830
[task 2018-09-22T00:25:47.951Z] 00:25:47     INFO -  #15: _fini
[task 2018-09-22T00:25:47.951Z] 00:25:47     INFO -  Program /builds/worker/workspace/build/application/firefox/firefox (pid = 1219) received signal 11.
[task 2018-09-22T00:25:47.951Z] 00:25:47     INFO -  Stack:
[task 2018-09-22T00:25:47.951Z] 00:25:47     INFO -  #01: <name omitted> [xpcom/ds/PLDHashTable.cpp:216]
[task 2018-09-22T00:25:47.951Z] 00:25:47     INFO -  #02: InitCapacityOk_EntrySizeTooBig() [xpcom/tests/gtest/TestPLDHash.cpp:111]
[task 2018-09-22T00:25:47.951Z] 00:25:47     INFO -  #03: TestCrashyOperation(void (*)()) [xpcom/tests/gtest/TestPLDHash.cpp:58]
[task 2018-09-22T00:25:47.951Z] 00:25:47     INFO -  #04: PLDHashTableTest_InitCapacityOk_Test::TestBody() [xpcom/tests/gtest/TestPLDHash.cpp:142]
[task 2018-09-22T00:25:47.951Z] 00:25:47     INFO -  #05: testing::Test::Run() [testing/gtest/gtest/src/gtest.cc:4921]
[task 2018-09-22T00:25:47.951Z] 00:25:47     INFO -  #06: testing::TestInfo::Run() [testing/gtest/gtest/src/gtest.cc:4921]
[task 2018-09-22T00:25:47.951Z] 00:25:47     INFO -  #07: testing::TestCase::Run() [testing/gtest/gtest/src/gtest.cc:2775]
[task 2018-09-22T00:25:47.951Z] 00:25:47     INFO -  #08: testing::internal::UnitTestImpl::RunAllTests() [testing/gtest/gtest/src/gtest.cc:4650]
[task 2018-09-22T00:25:47.952Z] 00:25:47     INFO -  #09: testing::UnitTest::Run() [testing/gtest/gtest/src/gtest.cc:4259]
[task 2018-09-22T00:25:47.952Z] 00:25:47     INFO -  #10: mozilla::RunGTestFunc(int*, char**) [testing/gtest/gtest/include/gtest/gtest.h:2233]
[task 2018-09-22T00:25:47.952Z] 00:25:47     INFO -  #11: XREMain::XRE_mainStartup(bool*) [toolkit/xre/nsAppRunner.cpp:4014]
[task 2018-09-22T00:25:47.952Z] 00:25:47     INFO -  #12: XREMain::XRE_main(int, char**, mozilla::BootstrapConfig const&) [toolkit/xre/nsAppRunner.cpp:4953]
[task 2018-09-22T00:25:47.953Z] 00:25:47     INFO -  #13: XRE_main(int, char**, mozilla::BootstrapConfig const&) [toolkit/xre/nsAppRunner.cpp:5060]
[task 2018-09-22T00:25:47.953Z] 00:25:47     INFO -  #14: _fini
[task 2018-09-22T00:25:47.953Z] 00:25:47     INFO -  #15: libc.so.6 + 0x20830
[task 2018-09-22T00:25:47.957Z] 00:25:47     INFO -  #16: _fini
[task 2018-09-22T00:25:47.957Z] 00:25:47     INFO -  Sleeping for 0 seconds.
[task 2018-09-22T00:25:47.957Z] 00:25:47     INFO -  Type 'gdb /builds/worker/workspace/build/application/firefox/firefox 1219' to attach your debugger to this thread.
[task 2018-09-22T00:25:47.957Z] 00:25:47     INFO -  Done sleeping...
[task 2018-09-22T00:25:47.957Z] 00:25:47     INFO -  TEST-PASS | PLDHashTableTest.InitCapacityOk | test completed (time: 15ms)
[task 2018-09-22T00:25:47.957Z] 00:25:47     INFO -  TEST-START | PLDHashTableTest.LazyStorage
[task 2018-09-22T00:25:47.957Z] 00:25:47     INFO -  TEST-PASS | PLDHashTableTest.LazyStorage | test completed (time: 0ms)
[task 2018-09-22T00:25:47.957Z] 00:25:47     INFO -  TEST-START | PLDHashTableTest.MoveSemantics
[task 2018-09-22T00:25:47.957Z] 00:25:47     INFO -  TEST-PASS | PLDHashTableTest.MoveSemantics | test completed (time: 0ms)
[task 2018-09-22T00:25:47.957Z] 00:25:47     INFO -  TEST-START | PLDHashTableTest.Clear
[task 2018-09-22T00:25:47.957Z] 00:25:47     INFO -  TEST-PASS | PLDHashTableTest.Clear | test completed (time: 0ms)
[task 2018-09-22T00:25:47.957Z] 00:25:47     INFO -  TEST-START | PLDHashTableTest.Iterator
[task 2018-09-22T00:25:47.957Z] 00:25:47     INFO -  TEST-PASS | PLDHashTableTest.Iterator | test completed (time: 0ms)
[task 2018-09-22T00:25:47.957Z] 00:25:47     INFO -  TEST-START | PLDHashTableTest.GrowToMaxCapacity
[task 2018-09-22T00:25:57.591Z] 00:25:57  WARNING -  TEST-UNEXPECTED-FAIL | PLDHashTableTest.GrowToMaxCapacity | Value of: false
[task 2018-09-22T00:25:57.591Z] 00:25:57     INFO -    Actual: false
[task 2018-09-22T00:25:57.592Z] 00:25:57     INFO -  Expected: true @ /builds/worker/workspace/build/src/xpcom/tests/gtest/TestPLDHash.cpp:377
[task 2018-09-22T00:25:57.592Z] 00:25:57  WARNING -  TEST-UNEXPECTED-FAIL | PLDHashTableTest.GrowToMaxCapacity | test completed (time: 17849ms)
[task 2018-09-22T00:25:57.593Z] 00:25:57     INFO -  TEST-START | Pipes.ChainedPipes
[task 2018-09-22T00:25:57.762Z] 00:25:57     INFO -  EOF count = 33333
[task 2018-09-22T00:25:57.762Z] 00:25:57     INFO -  read  33333 bytes, time = 168ms
[task 2018-09-22T00:25:57.763Z] 00:25:57     INFO -  TEST-PASS | Pipes.ChainedPipes | test completed (time: 171ms)
[task 2018-09-22T00:25:57.763Z] 00:25:57     INFO -  TEST-START | Pipes.Main
[task 2018-09-22T00:26:01.064Z] 00:26:01     INFO -  read  1222211 bytes, time = 3298ms
[task 2018-09-22T00:26:01.064Z] 00:26:01     INFO -  wrote 1222211 bytes, time = 3298ms
[task 2018-09-22T00:26:01.773Z] 00:26:01     INFO -  read  16308 bytes
[task 2018-09-22T00:26:01.773Z] 00:26:01     INFO -  wrote 16308 bytes
[task 2018-09-22T00:26:01.915Z] 00:26:01     INFO -  read  1222211 bytes, time = 138ms
[task 2018-09-22T00:26:01.915Z] 00:26:01     INFO -  wrote 1222211 bytes, time = 138ms
[task 2018-09-22T00:26:02.684Z] 00:26:02     INFO -  read  16371 bytes
[task 2018-09-22T00:26:02.685Z] 00:26:02     INFO -  wrote 16371 bytes
[task 2018-09-22T00:26:02.685Z] 00:26:02     INFO -  TEST-PASS | Pipes.Main | test completed (time: 4926ms)

[task 2018-09-22T00:26:09.170Z] 00:26:09     INFO -  TEST-START | Strings.huge_capacity
[task 2018-09-22T00:26:09.172Z] 00:26:09  WARNING -  TEST-UNEXPECTED-FAIL | Strings.huge_capacity | Value of: i.SetCapacity(nsString::size_type(-1)/4 - 1000, fallible)
[task 2018-09-22T00:26:09.172Z] 00:26:09     INFO -    Actual: false
[task 2018-09-22T00:26:09.173Z] 00:26:09     INFO -  Expected: true @ /builds/worker/workspace/build/src/xpcom/tests/gtest/TestStrings.cpp:1430
[task 2018-09-22T00:26:09.174Z] 00:26:09  WARNING -  TEST-UNEXPECTED-FAIL | Strings.huge_capacity | Value of: j.SetCapacity(nsString::size_type(-1)/4 - 1000, fallible)
[task 2018-09-22T00:26:09.174Z] 00:26:09     INFO -    Actual: false
[task 2018-09-22T00:26:09.174Z] 00:26:09     INFO -  Expected: true @ /builds/worker/workspace/build/src/xpcom/tests/gtest/TestStrings.cpp:1434
[task 2018-09-22T00:26:10.311Z] 00:26:10  WARNING -  TEST-UNEXPECTED-FAIL | Strings.huge_capacity | Value of: k.SetCapacity(nsString::size_type(-1)/4 - 1001, fallible)
[task 2018-09-22T00:26:10.311Z] 00:26:10     INFO -    Actual: false
[task 2018-09-22T00:26:10.311Z] 00:26:10     INFO -  Expected: true @ /builds/worker/workspace/build/src/xpcom/tests/gtest/TestStrings.cpp:1439
[task 2018-09-22T00:26:10.312Z] 00:26:10  WARNING -  TEST-UNEXPECTED-FAIL | Strings.huge_capacity | Value of: k.SetCapacity(nsString::size_type(-1)/4 - 998, fallible)
[task 2018-09-22T00:26:10.312Z] 00:26:10     INFO -    Actual: false
[task 2018-09-22T00:26:10.312Z] 00:26:10     INFO -  Expected: true @ /builds/worker/workspace/build/src/xpcom/tests/gtest/TestStrings.cpp:1440
[task 2018-09-22T00:26:12.174Z] 00:26:12  WARNING -  TEST-UNEXPECTED-FAIL | Strings.huge_capacity | Value of: n.SetCapacity((nsString::size_type(-1)/2 - sizeof(nsStringBuffer)) / 2 - 2, fallible)
[task 2018-09-22T00:26:12.174Z] 00:26:12     INFO -    Actual: false
[task 2018-09-22T00:26:12.175Z] 00:26:12     INFO -  Expected: true @ /builds/worker/workspace/build/src/xpcom/tests/gtest/TestStrings.cpp:1458
[task 2018-09-22T00:26:12.175Z] 00:26:12  WARNING -  TEST-UNEXPECTED-FAIL | Strings.huge_capacity | Value of: n1.SetCapacity((nsCString::size_type(-1)/2 - sizeof(nsStringBuffer)) / 1 - 2, fallible)
[task 2018-09-22T00:26:12.176Z] 00:26:12     INFO -    Actual: false
[task 2018-09-22T00:26:12.176Z] 00:26:12     INFO -  Expected: true @ /builds/worker/workspace/build/src/xpcom/tests/gtest/TestStrings.cpp:1463
[task 2018-09-22T00:26:12.176Z] 00:26:12  WARNING -  TEST-UNEXPECTED-FAIL | Strings.huge_capacity | test completed (time: 3002ms)
[task 2018-09-22T00:26:12.177Z] 00:26:12     INFO -  TEST-START | Strings.tofloat
[task 2018-09-22T00:26:12.178Z] 00:26:12     INFO -  TEST-PASS | Strings.tofloat | test completed (time: 3ms)
Component: General → XPCOM
Product: Testing → Core
Version: Version 3 → unspecified
First occurrence based on retriggers appears to be from Bug 1470223. This occurs only on Linux x64 debug:

https://tinyurl.com/y8wv659g

Gabriele can you please provide some input here? This is rather frequent.
Flags: needinfo?(gsvelto)
Bug 1470223 cannot have caused this, but it changed how the output of such intermittents is processed so this might be another intermittent with a new stack trace. I'll double-check to see if it's an issue with bug 1470223 or it's the expected output.
It took me a while to figure out how a change to a Python script that processes the output of the tests could have affected the outcome of a C++ unit-test but I think I've figured out what's happening: the test in question allocates a *lot* of memory and my changes to the fix_stack_using_bpsyms.py should also have increased the script's memory usage quite a bit. So it's possibly that the C++ unit-test is failing because it's going out-of-memory, that would explain why it's happening sometimes but not always. I've modified the script to use a more efficient data-structure and pushed it to try:

https://treeherder.mozilla.org/#/jobs?repo=try&revision=91ecf775e0801bd2076de708137fe3bacfa7f243

I'll re-trigger the tests a bunch of times, if they don't fail then we can confirm that excessive memory usage was the issue.
Flags: needinfo?(gsvelto)
Assignee: nobody → gsvelto
Status: NEW → ASSIGNED
When reworking the script each entry holding a function name was replaced by a
dictionary holding both the function name and its size. This significantly
increased memory consumption as using a full-fledged dictionary for only two
fields is very space inefficient. This patch uses a named tuple instead of a
dictionary for every entry, reducing memory consumption by almost four times.
Comment on attachment 9011360 [details]
Bug 1493365 - Reduce the amount of memory consumed when reading symbol files

Ted Mielczarek [:ted] [:ted.mielczarek] has approved the revision.
Attachment #9011360 - Flags: review+
Pushed by gsvelto@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/9c255bb965ab
Reduce the amount of memory consumed when reading symbol files r=ted
https://hg.mozilla.org/mozilla-central/rev/9c255bb965ab
Status: ASSIGNED → RESOLVED
Closed: 6 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla64
Thanks for fixing this Gabriele!
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: