Closed
Bug 1444557
Opened 6 years ago
Closed 6 years ago
Intermittent tools/profiler/tests/chrome/test_profile_worker.html, test_profile_worker_bug_1428076.html | application crashed [@ arena_t::MallocSmall]
Categories
(Core :: Gecko Profiler, defect, P5)
Core
Gecko Profiler
Tracking
()
RESOLVED
INCOMPLETE
People
(Reporter: intermittent-bug-filer, Unassigned)
Details
(Keywords: crash, intermittent-failure)
Crash Data
Filed by: btara [at] mozilla.com https://treeherder.mozilla.org/logviewer.html#?job_id=167048652&repo=autoland https://queue.taskcluster.net/v1/task/FJmtr1znTcCoI3UDNorD3w/runs/0/artifacts/public/logs/live_backing.log [task 2018-03-09T21:05:14.509Z] 21:05:14 INFO - 170 INFO TEST-START | tools/profiler/tests/chrome/test_profile_worker.html [task 2018-03-09T21:08:41.179Z] 21:08:41 INFO - INFO | automation.py | Application ran for: 0:05:13.178601 [task 2018-03-09T21:08:41.179Z] 21:08:41 INFO - INFO | zombiecheck | Reading PID log: /tmp/tmpT5b71Kpidlog [task 2018-03-09T21:08:42.429Z] 21:08:42 INFO - mozcrash Copy/paste: /usr/local/bin/linux64-minidump_stackwalk /tmp/tmpor7Xl0/3160dabb-e4fe-f01f-f0d7-847e0d33f609.dmp /builds/worker/workspace/build/symbols [task 2018-03-09T21:08:52.591Z] 21:08:52 INFO - mozcrash Saved minidump as /builds/worker/workspace/build/blobber_upload_dir/3160dabb-e4fe-f01f-f0d7-847e0d33f609.dmp [task 2018-03-09T21:08:52.591Z] 21:08:52 INFO - mozcrash Saved app info as /builds/worker/workspace/build/blobber_upload_dir/3160dabb-e4fe-f01f-f0d7-847e0d33f609.extra [task 2018-03-09T21:08:52.593Z] 21:08:52 WARNING - PROCESS-CRASH | tools/profiler/tests/chrome/test_profile_worker.html | application crashed [@ arena_t::MallocSmall] [task 2018-03-09T21:08:52.594Z] 21:08:52 INFO - Crash dump filename: /tmp/tmpor7Xl0/3160dabb-e4fe-f01f-f0d7-847e0d33f609.dmp [task 2018-03-09T21:08:52.594Z] 21:08:52 INFO - Operating system: Android [task 2018-03-09T21:08:52.594Z] 21:08:52 INFO - 0.0.0 Linux 2.6.29-gea477bb #1 Wed Sep 26 11:04:45 PDT 2012 armv7l [task 2018-03-09T21:08:52.594Z] 21:08:52 INFO - CPU: arm [task 2018-03-09T21:08:52.599Z] 21:08:52 INFO - ARMv7 ARM Cortex-A8 features: swp,half,thumb,fastmult,vfpv2,edsp,neon,vfpv3 [task 2018-03-09T21:08:52.599Z] 21:08:52 INFO - 1 CPU [task 2018-03-09T21:08:52.599Z] 21:08:52 INFO - GPU: UNKNOWN [task 2018-03-09T21:08:52.599Z] 21:08:52 INFO - Crash reason: SIGSEGV [task 2018-03-09T21:08:52.599Z] 21:08:52 INFO - Crash address: 0x384adf93 [task 2018-03-09T21:08:52.599Z] 21:08:52 INFO - Process uptime: not available [task 2018-03-09T21:08:52.599Z] 21:08:52 INFO - Thread 11 (crashed) [task 2018-03-09T21:08:52.599Z] 21:08:52 INFO - 0 libmozglue.so!arena_t::MallocSmall [mozjemalloc.cpp:6df9c07fd8382b748366335218af39616493c6d2 : 2217 + 0x0] [task 2018-03-09T21:08:52.600Z] 21:08:52 INFO - r0 = 0xfffffe08 r1 = 0x00000003 r2 = 0x00000060 r3 = 0x5de98040 [task 2018-03-09T21:08:52.600Z] 21:08:52 INFO - r4 = 0x384adf93 r5 = 0x5de98000 r6 = 0xfffffe00 r7 = 0x52cfdc00 [task 2018-03-09T21:08:52.600Z] 21:08:52 INFO - r8 = 0x00000000 r9 = 0x00000000 r10 = 0x00000060 r12 = 0x00000001 [task 2018-03-09T21:08:52.600Z] 21:08:52 INFO - fp = 0x52a045e0 sp = 0x52cfdbc0 lr = 0x528542a9 pc = 0x528542c8 [task 2018-03-09T21:08:52.600Z] 21:08:52 INFO - Found by: given as instruction pointer in context [task 2018-03-09T21:08:52.601Z] 21:08:52 INFO - 1 libmozglue.so!BaseAllocator::malloc [mozjemalloc.cpp:6df9c07fd8382b748366335218af39616493c6d2 : 4137 + 0x7] [task 2018-03-09T21:08:52.601Z] 21:08:52 INFO - r4 = 0x00000054 r5 = 0x52cfdc1c r6 = 0x00000000 r7 = 0x52cfdc10 [task 2018-03-09T21:08:52.601Z] 21:08:52 INFO - r8 = 0x52cfdc60 r9 = 0x52cfdc7c r10 = 0x00000001 fp = 0x5f44a146 [task 2018-03-09T21:08:52.602Z] 21:08:52 INFO - sp = 0x52cfdc08 lr = 0x5285579d pc = 0x5285579d [task 2018-03-09T21:08:52.602Z] 21:08:52 INFO - Found by: call frame info [task 2018-03-09T21:08:52.603Z] 21:08:52 INFO - 2 libmozglue.so!Allocator<MozJemallocBase>::moz_arena_malloc [malloc_decls.h:6df9c07fd8382b748366335218af39616493c6d2 : 37 + 0x5] [task 2018-03-09T21:08:52.603Z] 21:08:52 INFO - r4 = 0x00000054 r5 = 0x5aa13800 r6 = 0x00000000 r7 = 0x52cfdc28 [task 2018-03-09T21:08:52.603Z] 21:08:52 INFO - r8 = 0x52cfdc60 r9 = 0x52cfdc7c r10 = 0x00000001 fp = 0x5f44a146 [task 2018-03-09T21:08:52.603Z] 21:08:52 INFO - sp = 0x52cfdc18 lr = 0x528556c3 pc = 0x528556c3 [task 2018-03-09T21:08:52.604Z] 21:08:52 INFO - Found by: call frame info [task 2018-03-09T21:08:52.604Z] 21:08:52 INFO - 3 libxul.so!js::MallocProvider<JSContext>::pod_malloc<char> [Utility.h:6df9c07fd8382b748366335218af39616493c6d2 : 388 + 0x3] [task 2018-03-09T21:08:52.604Z] 21:08:52 INFO - r2 = 0x528556a5 r3 = 0x52a044c0 r4 = 0x00000054 r5 = 0x5aa13800 [task 2018-03-09T21:08:52.604Z] 21:08:52 INFO - r6 = 0x00000000 r7 = 0x52cfdc48 r8 = 0x52cfdc60 r9 = 0x52cfdc7c [task 2018-03-09T21:08:52.605Z] 21:08:52 INFO - r10 = 0x00000001 fp = 0x5f44a146 sp = 0x52cfdc30 lr = 0x557b77c5 [task 2018-03-09T21:08:52.605Z] 21:08:52 INFO - pc = 0x557b77c5 [task 2018-03-09T21:08:52.605Z] 21:08:52 INFO - Found by: call frame info [task 2018-03-09T21:08:52.605Z] 21:08:52 INFO - 4 libxul.so!js::ObjectGroup::allocationSiteGroup [MallocProvider.h:6df9c07fd8382b748366335218af39616493c6d2 : 187 + 0x7] [task 2018-03-09T21:08:52.605Z] 21:08:52 INFO - r4 = 0x5f7548e0 r5 = 0x00000000 r6 = 0x5aa28000 r7 = 0x52cfdd28 [task 2018-03-09T21:08:52.605Z] 21:08:52 INFO - r8 = 0x52cfdc60 r9 = 0x52cfdc7c r10 = 0x00000001 fp = 0x5f44a146 [task 2018-03-09T21:08:52.605Z] 21:08:52 INFO - sp = 0x52cfdc50 lr = 0x55d060b9 pc = 0x55d060b9 [task 2018-03-09T21:08:52.606Z] 21:08:52 INFO - Found by: call frame info [task 2018-03-09T21:08:52.606Z] 21:08:52 INFO - 5 libxul.so!js::NewObjectOperation [Interpreter.cpp:6df9c07fd8382b748366335218af39616493c6d2 : 4950 + 0xb] [task 2018-03-09T21:08:52.606Z] 21:08:52 INFO - r4 = 0x00000001 r5 = 0x0003fff0 r6 = 0x5f44a145 r7 = 0x52cfdd78 [task 2018-03-09T21:08:52.606Z] 21:08:52 INFO - r8 = 0x00000000 r9 = 0x00000000 r10 = 0x52cfe004 fp = 0x5aa13800 [task 2018-03-09T21:08:52.606Z] 21:08:52 INFO - sp = 0x52cfdd30 lr = 0x557f5b09 pc = 0x557f5b09 [task 2018-03-09T21:08:52.606Z] 21:08:52 INFO - Found by: call frame info [task 2018-03-09T21:08:52.606Z] 21:08:52 INFO - 6 libxul.so!Interpret [Interpreter.cpp:6df9c07fd8382b748366335218af39616493c6d2 : 3769 + 0x9] [task 2018-03-09T21:08:52.607Z] 21:08:52 INFO - r4 = 0x5c77b130 r5 = 0x000000e7 r6 = 0x00000201 r7 = 0x52cfe130 [task 2018-03-09T21:08:52.607Z] 21:08:52 INFO - r8 = 0x0003fff8 r9 = 0x52cfe054 r10 = 0x5aa13800 fp = 0xffffff83 [task 2018-03-09T21:08:52.607Z] 21:08:52 INFO - sp = 0x52cfdd80 lr = 0x557e9a09 pc = 0x557e9a09 [task 2018-03-09T21:08:52.607Z] 21:08:52 INFO - Found by: call frame info [task 2018-03-09T21:08:52.607Z] 21:08:52 INFO - 7 libxul.so!js::RunScript [Interpreter.cpp:6df9c07fd8382b748366335218af39616493c6d2 : 418 + 0x7] [task 2018-03-09T21:08:52.607Z] 21:08:52 INFO - r4 = 0x52cfe174 r5 = 0x5aa13800 r6 = 0x5bd9fcc0 r7 = 0x52cfe158 [task 2018-03-09T21:08:52.607Z] 21:08:52 INFO - r8 = 0x00000000 r9 = 0x52cfe174 r10 = 0x52cfe18c fp = 0x52cfe260 [task 2018-03-09T21:08:52.608Z] 21:08:52 INFO - sp = 0x52cfe138 lr = 0x557de273 pc = 0x557de273 [task 2018-03-09T21:08:52.608Z] 21:08:52 INFO - Found by: call frame info [task 2018-03-09T21:08:52.608Z] 21:08:52 INFO - 8 libxul.so!js::InternalCallOrConstruct [Interpreter.cpp:6df9c07fd8382b748366335218af39616493c6d2 : 490 + 0x5] [task 2018-03-09T21:08:52.608Z] 21:08:52 INFO - r4 = 0x5aa13800 r5 = 0x52cfe208 r6 = 0xffffff86 r7 = 0x52cfe1b0 [task 2018-03-09T21:08:52.608Z] 21:08:52 INFO - r8 = 0x00000000 r9 = 0x52cfe174 r10 = 0x52cfe18c fp = 0x52cfe260 [task 2018-03-09T21:08:52.608Z] 21:08:52 INFO - sp = 0x52cfe160 lr = 0x557ecfd5 pc = 0x557ecfd5 [task 2018-03-09T21:08:52.609Z] 21:08:52 INFO - Found by: call frame info [task 2018-03-09T21:08:52.609Z] 21:08:52 INFO - 9 libxul.so!InternalCall [Interpreter.cpp:6df9c07fd8382b748366335218af39616493c6d2 : 517 + 0x9] [task 2018-03-09T21:08:52.609Z] 21:08:52 INFO - r4 = 0x52cfe208 r5 = 0x5aa13800 r6 = 0xffffff86 r7 = 0x52cfe1d8 [task 2018-03-09T21:08:52.610Z] 21:08:52 INFO - r8 = 0x52cfe258 r9 = 0xffffff83 r10 = 0x52cfe2b0 fp = 0x52cfe260 [task 2018-03-09T21:08:52.610Z] 21:08:52 INFO - sp = 0x52cfe1b8 lr = 0x557ed8e9 pc = 0x557ed8e9 [task 2018-03-09T21:08:52.610Z] 21:08:52 INFO - Found by: call frame info [task 2018-03-09T21:08:52.611Z] 21:08:52 INFO - 10 libxul.so!<name omitted> [Interpreter.cpp:6df9c07fd8382b748366335218af39616493c6d2 : 536 + 0x5] [task 2018-03-09T21:08:52.611Z] 21:08:52 INFO - r4 = 0x00000000 r5 = 0x52cfe208 r6 = 0xffffff86 r7 = 0x52cfe1f0 [task 2018-03-09T21:08:52.611Z] 21:08:52 INFO - r8 = 0x52cfe258 r9 = 0xffffff83 r10 = 0x52cfe2b0 fp = 0x52cfe260 [task 2018-03-09T21:08:52.611Z] 21:08:52 INFO - sp = 0x52cfe1e0 lr = 0x557ed975 pc = 0x557ed975 [task 2018-03-09T21:08:52.612Z] 21:08:52 INFO - Found by: call frame info [task 2018-03-09T21:08:52.612Z] 21:08:52 INFO - 11 libxul.so!js::jit::InterpretResume [VMFunctions.cpp:6df9c07fd8382b748366335218af39616493c6d2 : 957 + 0x7] [task 2018-03-09T21:08:52.612Z] 21:08:52 INFO - r4 = 0x5aa13800 r5 = 0x52cfe208 r6 = 0xffffff86 r7 = 0x52cfe288 [task 2018-03-09T21:08:52.613Z] 21:08:52 INFO - r8 = 0x52cfe258 r9 = 0xffffff83 r10 = 0x52cfe2b0 fp = 0x52cfe260 [task 2018-03-09T21:08:52.613Z] 21:08:52 INFO - sp = 0x52cfe1f8 lr = 0x55b0008d pc = 0x55b0008d [task 2018-03-09T21:08:52.613Z] 21:08:52 INFO - Found by: call frame info [task 2018-03-09T21:08:52.613Z] 21:08:52 INFO - 12 0x372dfe1a [task 2018-03-09T21:08:52.614Z] 21:08:52 INFO - r4 = 0x52cfe298 r5 = 0x52cfe2ac r6 = 0x574f30e8 r7 = 0xffffff83 [task 2018-03-09T21:08:52.614Z] 21:08:52 INFO - r8 = 0x00002043 r9 = 0x5d39e5b8 r10 = 0x00000001 fp = 0x52cfe304 [task 2018-03-09T21:08:52.614Z] 21:08:52 INFO - sp = 0x52cfe290 lr = 0x372dfe1c pc = 0x372dfe1c [task 2018-03-09T21:08:52.614Z] 21:08:52 INFO - Found by: call frame info [task 2018-03-09T21:08:52.615Z] 21:08:52 INFO - 13 libxul.so!wcsrtombs + 0x1abb61d [task 2018-03-09T21:08:52.615Z] 21:08:52 INFO - sp = 0x52cfe2a4 pc = 0x580aba00 [task 2018-03-09T21:08:52.615Z] 21:08:52 INFO - Found by: stack scanning [task 2018-03-09T21:08:52.615Z] 21:08:52 INFO - Thread 0 [task 2018-03-09T21:08:52.616Z] 21:08:52 INFO - 0 libc.so + 0x1c3dc [task 2018-03-09T21:08:52.616Z] 21:08:52 INFO - r0 = 0xfffffffc r1 = 0xbeafa4a8 r2 = 0x00000010 r3 = 0xffffffff [task 2018-03-09T21:08:52.616Z] 21:08:52 INFO - r4 = 0x2a040c00 r5 = 0x00000000 r6 = 0x2a040c14 r7 = 0x000000fc [task 2018-03-09T21:08:52.616Z] 21:08:52 INFO - r8 = 0x2a040c48 r9 = 0x00000014 r10 = 0x2a00d0a0 r12 = 0xbeafa4a8 [task 2018-03-09T21:08:52.617Z] 21:08:52 INFO - fp = 0xbeafa61c sp = 0xbeafa488 lr = 0x400b1fb5 pc = 0x400433dc [task 2018-03-09T21:08:52.617Z] 21:08:52 INFO - Found by: given as instruction pointer in context [task 2018-03-09T21:08:52.617Z] 21:08:52 INFO - 1 libutils.so + 0x1785c [task 2018-03-09T21:08:52.617Z] 21:08:52 INFO - sp = 0xbeafa4a0 pc = 0x400b485e [task 2018-03-09T21:08:52.618Z] 21:08:52 INFO - Found by: stack scanning [task 2018-03-09T21:08:52.618Z] 21:08:52 INFO - 2 libbinder.so + 0x1bc2d [task 2018-03-09T21:08:52.618Z] 21:08:52 INFO - sp = 0xbeafa4d8 pc = 0x400f7c2f [task 2018-03-09T21:08:52.618Z] 21:08:52 INFO - Found by: stack scanning [task 2018-03-09T21:08:52.619Z] 21:08:52 INFO - 3 libbinder.so + 0x18603 [task 2018-03-09T21:08:52.619Z] 21:08:52 INFO - sp = 0xbeafa4f8 pc = 0x400f4605 [task 2018-03-09T21:08:52.619Z] 21:08:52 INFO - Found by: stack scanning [task 2018-03-09T21:08:52.619Z] 21:08:52 INFO - 4 libbinder.so + 0x2032d [task 2018-03-09T21:08:52.620Z] 21:08:52 INFO - sp = 0xbeafa500 pc = 0x400fc32f [task 2018-03-09T21:08:52.620Z] 21:08:52 INFO - Found by: stack scanning [task 2018-03-09T21:08:52.620Z] 21:08:52 INFO - 5 libc.so + 0x109e9 [task 2018-03-09T21:08:52.620Z] 21:08:52 INFO - sp = 0xbeafa518 pc = 0x400379eb [task 2018-03-09T21:08:52.621Z] 21:08:52 INFO - Found by: stack scanning [task 2018-03-09T21:08:52.621Z] 21:08:52 INFO - 6 libc.so + 0xd9bf [task 2018-03-09T21:08:52.621Z] 21:08:52 INFO - sp = 0xbeafa530 pc = 0x400349c1 [task 2018-03-09T21:08:52.621Z] 21:08:52 INFO - Found by: stack scanning [task 2018-03-09T21:08:52.622Z] 21:08:52 INFO - 7 libbinder.so + 0x1e561 [task 2018-03-09T21:08:52.622Z] 21:08:52 INFO - sp = 0xbeafa538 pc = 0x400fa563 [task 2018-03-09T21:08:52.622Z] 21:08:52 INFO - Found by: stack scanning [task 2018-03-09T21:08:52.622Z] 21:08:52 INFO - 8 libbinder.so + 0x1e5cf [task 2018-03-09T21:08:52.623Z] 21:08:52 INFO - sp = 0xbeafa550 pc = 0x400fa5d1 [task 2018-03-09T21:08:52.623Z] 21:08:52 INFO - Found by: stack scanning [task 2018-03-09T21:08:52.623Z] 21:08:52 INFO - 9 libbinder.so + 0x18469 [task 2018-03-09T21:08:52.623Z] 21:08:52 INFO - sp = 0xbeafa554 pc = 0x400f446b [task 2018-03-09T21:08:52.624Z] 21:08:52 INFO - Found by: stack scanning [task 2018-03-09T21:08:52.624Z] 21:08:52 INFO - 10 libgui.so + 0x2186d [task 2018-03-09T21:08:52.624Z] 21:08:52 INFO - sp = 0xbeafa558 pc = 0x4057786f [task 2018-03-09T21:08:52.624Z] 21:08:52 INFO - Found by: stack scanning [task 2018-03-09T21:08:52.625Z] 21:08:52 INFO - 11 libc.so + 0x3b072 [task 2018-03-09T21:08:52.625Z] 21:08:52 INFO - sp = 0xbeafa5a8 pc = 0x40062074 [task 2018-03-09T21:08:52.625Z] 21:08:52 INFO - Found by: stack scanning [task 2018-03-09T21:08:52.625Z] 21:08:52 INFO - 12 icudt50l.dat + 0x877511 [task 2018-03-09T21:08:52.626Z] 21:08:52 INFO - sp = 0xbeafa5ac pc = 0x508cc513 [task 2018-03-09T21:08:52.626Z] 21:08:52 INFO - Found by: stack scanning [task 2018-03-09T21:08:52.626Z] 21:08:52 INFO - 13 libutils.so + 0x151d7 [task 2018-03-09T21:08:52.626Z] 21:08:52 INFO - sp = 0xbeafa5d0 pc = 0x400b21d9 [task 2018-03-09T21:08:52.627Z] 21:08:52 INFO - Found by: stack scanning [task 2018-03-09T21:08:52.627Z] 21:08:52 INFO - 14 libandroid_runtime.so + 0x67b6b [task 2018-03-09T21:08:52.627Z] 21:08:52 INFO - sp = 0xbeafa5f0 pc = 0x4016db6d [task 2018-03-09T21:08:52.627Z] 21:08:52 INFO - Found by: stack scanning
Updated•6 years ago
|
Summary: Intermittent tools/profiler/tests/chrome/test_profile_worker.html | application crashed [@ arena_t::MallocSmall] → Intermittent tools/profiler/tests/chrome/test_profile_worker.html, test_profile_worker_bug_1428076.html | application crashed [@ arena_t::MallocSmall]
Comment hidden (Intermittent Failures Robot) |
Comment 2•6 years ago
|
||
The crash happens when we run out of memory to allocate a string, which happens during console.log. Console::MaybeExecuteDumpFunction calls JS_ValueToSource which recursively stringifies an object. consoleBinding::log -> Console::Log -> Console::Method -> Console::MethodInternal -> Console::MaybeExecuteDumpFunction It looks like we allocate too many "hello world!" strings in the worker which don't get GC'ed before we run out of memory. Which is strange. This might be a GC bug or a JS_ValueToSource leak. Or maybe it's somewhat expected and we should work around it by calling something other than console.log as fast as we can in a loop.
Comment 3•6 years ago
|
||
I think that by calling "console.log" repeatedly, we actually append to the console buffer, so it's normal that it doesn't get GC. Shouldn't we clear some of the console data when we get close to an OOM? Or maybe we do it with an hardcoded value but the threshold is too high for some ARM devices?
Comment 4•6 years ago
|
||
> It looks like we allocate too many "hello world!" strings in the worker which don't get GC'ed before we run out of memory. Which is strange. Actually we don't loop in this worker, see the code in [1]. So it's even stranger, please disregard my comment 2. [1] https://searchfox.org/mozilla-central/source/tools/profiler/tests/chrome/test_profile_worker.html#29-32
Comment hidden (Intermittent Failures Robot) |
Updated•6 years ago
|
Crash Signature: [@ arena_t::MallocSmall] → [@ arena_t::MallocSmall][@ arena_t::DallocSmall]
Comment hidden (Intermittent Failures Robot) |
Updated•6 years ago
|
Crash Signature: [@ arena_t::MallocSmall][@ arena_t::DallocSmall] → [@ arena_t::MallocSmall]
[@ arena_t::DallocSmall]
[@ arena_t::DallocRun]
Comment 7•6 years ago
|
||
[@ arena_t::DallocRun] failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=171361859&repo=mozilla-inbound&lineNumber=2363
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 16•6 years ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → INCOMPLETE
You need to log in
before you can comment on or make changes to this bug.
Description
•