Closed Bug 1493365 Opened 6 years ago Closed 6 years ago

Intermittent PLDHashTableTest.GrowToMaxCapacity | Value of: false

Categories

(Core :: XPCOM, defect, P5)

Product:
Core
Component:
XPCOM
Type:
defect

Tracking

()

Status:
RESOLVED FIXED
Milestone:
mozilla64
Tracking Flags:
Tracking Status
firefox64 --- fixed

People

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

Details

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

Attachments

(1 file)

Bug 1493365 - Reduce the amount of memory consumed when reading symbol files
46 bytes, text/x-phabricator-request
ted
: review+
Details | Review
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
status-firefox64: --- → fixed
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

Creator:
Created:
Updated:
Size: