Closed Bug 1439624 Opened 4 years ago Closed 2 years ago

Intermittent tools/profiler/tests/chrome/test_profile_worker.html,test_profile_worker_bug_1428076.html | application crashed [@ mozilla::dom::WorkerPrivate::ScheduleDeletion]

Categories

(Core :: Gecko Profiler, defect, P3)

defect

Tracking

()

RESOLVED WORKSFORME

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: crash, intermittent-failure)

Crash Data

Filed by: apavel [at] mozilla.com

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

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

[task 2018-02-20T14:27:59.594Z] 14:27:59     INFO -  INFO | automation.py | Application ran for: 0:02:29.105361
[task 2018-02-20T14:27:59.595Z] 14:27:59     INFO -  INFO | zombiecheck | Reading PID log: /tmp/tmpZOd6f8pidlog
[task 2018-02-20T14:28:00.930Z] 14:28:00     INFO -  mozcrash Copy/paste: /usr/local/bin/linux64-minidump_stackwalk /tmp/tmpj0LD3N/37e16e6d-4092-72ed-4357-f05856e05014.dmp /builds/worker/workspace/build/symbols
[task 2018-02-20T14:28:10.981Z] 14:28:10     INFO -  mozcrash Saved minidump as /builds/worker/workspace/build/blobber_upload_dir/37e16e6d-4092-72ed-4357-f05856e05014.dmp
[task 2018-02-20T14:28:10.982Z] 14:28:10     INFO -  mozcrash Saved app info as /builds/worker/workspace/build/blobber_upload_dir/37e16e6d-4092-72ed-4357-f05856e05014.extra
[task 2018-02-20T14:28:10.985Z] 14:28:10  WARNING -  PROCESS-CRASH | tools/profiler/tests/chrome/test_profile_worker.html | application crashed [@ mozilla::dom::WorkerPrivate::ScheduleDeletion]
[task 2018-02-20T14:28:10.985Z] 14:28:10     INFO -  Crash dump filename: /tmp/tmpj0LD3N/37e16e6d-4092-72ed-4357-f05856e05014.dmp
[task 2018-02-20T14:28:10.991Z] 14:28:10     INFO -  Operating system: Android
[task 2018-02-20T14:28:10.991Z] 14:28:10     INFO -                    0.0.0 Linux 2.6.29-gea477bb #1 Wed Sep 26 11:04:45 PDT 2012 armv7l
[task 2018-02-20T14:28:10.992Z] 14:28:10     INFO -  CPU: arm
[task 2018-02-20T14:28:10.992Z] 14:28:10     INFO -       ARMv7 ARM Cortex-A8 features: swp,half,thumb,fastmult,vfpv2,edsp,neon,vfpv3
[task 2018-02-20T14:28:10.992Z] 14:28:10     INFO -       1 CPU
[task 2018-02-20T14:28:10.992Z] 14:28:10     INFO -  GPU: UNKNOWN
[task 2018-02-20T14:28:10.992Z] 14:28:10     INFO -  Crash reason:  SIGSEGV
[task 2018-02-20T14:28:10.992Z] 14:28:10     INFO -  Crash address: 0x0
[task 2018-02-20T14:28:10.992Z] 14:28:10     INFO -  Process uptime: not available
[task 2018-02-20T14:28:10.992Z] 14:28:10     INFO -  Thread 53 (crashed)
[task 2018-02-20T14:28:10.992Z] 14:28:10     INFO -   0  libxul.so!mozilla::dom::WorkerPrivate::ScheduleDeletion [WorkerPrivate.cpp:6496c32d75a24e7994572785eccedfa2da38cf92 : 0 + 0x6]
[task 2018-02-20T14:28:10.992Z] 14:28:10     INFO -       r0 = 0x00000000    r1 = 0x4693aef2    r2 = 0x56d34bcc    r3 = 0x00000e41
[task 2018-02-20T14:28:10.993Z] 14:28:10     INFO -       r4 = 0x00000e41    r5 = 0x00000001    r6 = 0x80004005    r7 = 0x6b0ff668
[task 2018-02-20T14:28:10.993Z] 14:28:10     INFO -       r8 = 0x00000000    r9 = 0x64aead30   r10 = 0x692d3ee0   r12 = 0x00000003
[task 2018-02-20T14:28:10.993Z] 14:28:10     INFO -       fp = 0x65a47c00    sp = 0x6b0ff650    lr = 0x5333bff5    pc = 0x54933472
[task 2018-02-20T14:28:10.993Z] 14:28:10     INFO -      Found by: given as instruction pointer in context
[task 2018-02-20T14:28:10.993Z] 14:28:10     INFO -   1  libxul.so!WorkerThreadPrimaryRunnable::Run [RuntimeService.cpp:6496c32d75a24e7994572785eccedfa2da38cf92 : 2776 + 0x5]
[task 2018-02-20T14:28:10.993Z] 14:28:10     INFO -       r4 = 0x00000000    r5 = 0x00000001    r6 = 0x80004005    r7 = 0x6b0ff8e8
[task 2018-02-20T14:28:10.993Z] 14:28:10     INFO -       r8 = 0x00000000    r9 = 0x64aead30   r10 = 0x692d3ee0    fp = 0x65a47c00
[task 2018-02-20T14:28:10.993Z] 14:28:10     INFO -       sp = 0x6b0ff670    lr = 0x54929433    pc = 0x54929433
[task 2018-02-20T14:28:10.994Z] 14:28:10     INFO -      Found by: call frame info
[task 2018-02-20T14:28:10.994Z] 14:28:10     INFO -   2  libxul.so!nsThread::ProcessNextEvent [nsThread.cpp:6496c32d75a24e7994572785eccedfa2da38cf92 : 1040 + 0x5]
[task 2018-02-20T14:28:10.994Z] 14:28:10     INFO -       r4 = 0x00000000    r5 = 0x533c31b3    r6 = 0x6b0ff91d    r7 = 0x6b0ffe08
[task 2018-02-20T14:28:10.994Z] 14:28:10     INFO -       r8 = 0x00000000    r9 = 0x6b0ff920   r10 = 0x6b0ffe17    fp = 0x65b8e0e0
[task 2018-02-20T14:28:10.994Z] 14:28:10     INFO -       sp = 0x6b0ff8f0    lr = 0x533c973b    pc = 0x533c973b
[task 2018-02-20T14:28:10.994Z] 14:28:10     INFO -      Found by: call frame info
[task 2018-02-20T14:28:10.994Z] 14:28:10     INFO -   3  libxul.so!NS_ProcessNextEvent [nsThreadUtils.cpp:6496c32d75a24e7994572785eccedfa2da38cf92 : 517 + 0xd]
[task 2018-02-20T14:28:10.994Z] 14:28:10     INFO -       r4 = 0x00000000    r5 = 0x65b8e0e0    r6 = 0x00000001    r7 = 0x6b0ffe28
[task 2018-02-20T14:28:10.994Z] 14:28:10     INFO -       r8 = 0x692d4a7c    r9 = 0x65b8e0e0   r10 = 0x692d4a70    fp = 0x2a291678
[task 2018-02-20T14:28:10.995Z] 14:28:10     INFO -       sp = 0x6b0ffe10    lr = 0x533d1385    pc = 0x533d1385
[task 2018-02-20T14:28:10.995Z] 14:28:10     INFO -      Found by: call frame info
[task 2018-02-20T14:28:10.995Z] 14:28:10     INFO -   4  libxul.so!mozilla::ipc::MessagePumpForNonMainThreads::Run [MessagePump.cpp:6496c32d75a24e7994572785eccedfa2da38cf92 : 334 + 0x7]
[task 2018-02-20T14:28:10.995Z] 14:28:10     INFO -       r4 = 0x692d4a60    r5 = 0x65b8e190    r6 = 0x00000001    r7 = 0x6b0ffe50
[task 2018-02-20T14:28:10.995Z] 14:28:10     INFO -       r8 = 0x692d4a7c    r9 = 0x65b8e0e0   r10 = 0x692d4a70    fp = 0x2a291678
[task 2018-02-20T14:28:10.995Z] 14:28:10     INFO -       sp = 0x6b0ffe30    lr = 0x537441dd    pc = 0x537441dd
[task 2018-02-20T14:28:10.995Z] 14:28:10     INFO -      Found by: call frame info
[task 2018-02-20T14:28:10.995Z] 14:28:10     INFO -   5  libxul.so!MessageLoop::RunInternal [message_loop.cc:6496c32d75a24e7994572785eccedfa2da38cf92 : 326 + 0x7]
[task 2018-02-20T14:28:10.995Z] 14:28:10     INFO -       r4 = 0x65b8e190    r5 = 0x65b8e0f4    r6 = 0x6b0ffea4    r7 = 0x6b0ffe70
[task 2018-02-20T14:28:10.996Z] 14:28:10     INFO -       r8 = 0x00000000    r9 = 0x6b0ffe9c   r10 = 0x6b0fff00    fp = 0x2a291678
[task 2018-02-20T14:28:10.996Z] 14:28:10     INFO -       sp = 0x6b0ffe58    lr = 0x536fc745    pc = 0x536fc745
[task 2018-02-20T14:28:10.996Z] 14:28:10     INFO -      Found by: call frame info
[task 2018-02-20T14:28:10.996Z] 14:28:10     INFO -   6  libxul.so!MessageLoop::Run [message_loop.cc:6496c32d75a24e7994572785eccedfa2da38cf92 : 319 + 0x5]
[task 2018-02-20T14:28:10.996Z] 14:28:10     INFO -       r0 = 0x65b8e190    r1 = 0x00000000    r2 = 0x00000001    r3 = 0x00000001
[task 2018-02-20T14:28:10.996Z] 14:28:10     INFO -       r4 = 0x65b8e190    r5 = 0x65b8e0f4    r6 = 0x6b0ffea4    r7 = 0x6b0ffe90
[task 2018-02-20T14:28:10.996Z] 14:28:10     INFO -       r8 = 0x00000000    r9 = 0x6b0ffe9c   r10 = 0x6b0fff00    fp = 0x2a291678
[task 2018-02-20T14:28:10.996Z] 14:28:10     INFO -       sp = 0x6b0ffe78    lr = 0x536fc6f3    pc = 0x536fc6f3
[task 2018-02-20T14:28:10.996Z] 14:28:10     INFO -      Found by: call frame info
[task 2018-02-20T14:28:10.996Z] 14:28:10     INFO -   7  libxul.so!nsThread::ThreadFunc [nsThread.cpp:6496c32d75a24e7994572785eccedfa2da38cf92 : 423 + 0x3]
[task 2018-02-20T14:28:10.997Z] 14:28:10     INFO -       r0 = 0x00000001    r1 = 0x692d4a00    r2 = 0x65b8e190    r3 = 0x00000000
[task 2018-02-20T14:28:10.997Z] 14:28:10     INFO -       r4 = 0x65b8e0e0    r5 = 0x65b8e0f4    r6 = 0x6b0ffea4    r7 = 0x6b0ffec0
[task 2018-02-20T14:28:10.997Z] 14:28:10     INFO -       r8 = 0x00000000    r9 = 0x6b0ffe9c   r10 = 0x6b0fff00    fp = 0x2a291678
[task 2018-02-20T14:28:10.997Z] 14:28:10     INFO -       sp = 0x6b0ffe98    lr = 0x533c8263    pc = 0x533c8263
[task 2018-02-20T14:28:10.997Z] 14:28:10     INFO -      Found by: call frame info
[task 2018-02-20T14:28:10.997Z] 14:28:10     INFO -   8  libnss3.so!_pt_root [ptthread.c:6496c32d75a24e7994572785eccedfa2da38cf92 : 201 + 0x1]
[task 2018-02-20T14:28:10.997Z] 14:28:10     INFO -       r4 = 0x697cb880    r5 = 0x52da7dd0    r6 = 0x00000000    r7 = 0x6b0ffee0
[task 2018-02-20T14:28:10.997Z] 14:28:10     INFO -       r8 = 0x2a291678    r9 = 0x00000002   r10 = 0x6b0fff00    fp = 0x2a291678
[task 2018-02-20T14:28:10.997Z] 14:28:10     INFO -       sp = 0x6b0ffec8    lr = 0x52cc6b35    pc = 0x52cc6b35
[task 2018-02-20T14:28:10.998Z] 14:28:10     INFO -      Found by: call frame info
[task 2018-02-20T14:28:10.998Z] 14:28:10     INFO -   9  libc.so + 0xca5a
[task 2018-02-20T14:28:10.998Z] 14:28:10     INFO -       r4 = 0x6b0fff00    r5 = 0x2a291678    r6 = 0x52cc6a59    r7 = 0x697cb880
[task 2018-02-20T14:28:10.998Z] 14:28:10     INFO -       r8 = 0x529e14c8    r9 = 0x6b000000   r10 = 0x6b0fff00    fp = 0x2a291678
[task 2018-02-20T14:28:10.998Z] 14:28:10     INFO -       sp = 0x6b0ffee8    lr = 0x40033a5c    pc = 0x40033a5c
[task 2018-02-20T14:28:10.999Z] 14:28:10     INFO -      Found by: call frame info
[task 2018-02-20T14:28:11.000Z] 14:28:10     INFO -  10  libc.so + 0xcbd6
[task 2018-02-20T14:28:11.000Z] 14:28:10     INFO -       sp = 0x6b0fff00    pc = 0x40033bd8
[task 2018-02-20T14:28:11.000Z] 14:28:10     INFO -      Found by: stack scanning
[task 2018-02-20T14:28:11.000Z] 14:28:11     INFO -  11  dalvik-heap (deleted) + 0x5485ef0
[task 2018-02-20T14:28:11.000Z] 14:28:11     INFO -       sp = 0x6b0fff18    pc = 0x4693aef2
[task 2018-02-20T14:28:11.001Z] 14:28:11     INFO -      Found by: stack scanning
From the log:

[task 2018-03-09T21:07:55.997Z] 21:07:55     INFO -  03-09 13:07:02.837 I/GeckoDump( 6016): ⰲ겿{"action":"log","time":1520629622770,"thread":null,"pid":null,"source":"mochitest","level":"INFO","message":"Profiler has started","js_source":"TestRunner.js"}ⰲ겿
[task 2018-03-09T21:07:55.998Z] 21:07:55     INFO -  03-09 13:07:03.018 I/GeckoDump( 6016): ⰲ겿{"action":"log","time":1520629622980,"thread":null,"pid":null,"source":"mochitest","level":"INFO","message":"Starting the worker...","js_source":"TestRunner.js"}ⰲ겿
[task 2018-03-09T21:07:55.998Z] 21:07:55     INFO -  03-09 13:07:11.478 I/Gecko   ( 6016): console.log: "hello world"
[task 2018-03-09T21:07:55.998Z] 21:07:55     INFO -  03-09 13:07:11.807 I/GeckoConsole( 6016): hello world
[task 2018-03-09T21:07:55.999Z] 21:07:55     INFO -  03-09 13:07:12.828 I/GeckoDump( 6016): ⰲ겿{"action":"log","time":1520629632716,"thread":null,"pid":null,"source":"mochitest","level":"INFO","message":"Got a message, terminating the worker.","js_source":"TestRunner.js"}ⰲ겿
[task 2018-03-09T21:07:55.999Z] 21:07:55     INFO -  03-09 13:07:14.018 F/MOZ_Assert( 6016): Assertion failure: !NS_HasPendingEvents(currentThread), at /builds/worker/workspace/build/src/dom/workers/WorkerPrivate.cpp:3656

So it's failing this assertion:

> void
> WorkerPrivate::ScheduleDeletion(WorkerRanOrNot aRanOrNot)
> {
>   AssertIsOnWorkerThread();
>   MOZ_ASSERT(mChildWorkers.IsEmpty());
>   MOZ_ASSERT(mSyncLoopStack.IsEmpty());
>   MOZ_ASSERT(!mPendingEventQueueClearing);
> 
>   ClearMainEventQueue(aRanOrNot);
> #ifdef DEBUG
>   if (WorkerRan == aRanOrNot) {
>     nsIThread* currentThread = NS_GetCurrentThread();
>     MOZ_ASSERT(currentThread);
>     MOZ_ASSERT(!NS_HasPendingEvents(currentThread));   // <----------- !!!
>   }
> #endif

So somehow ClearMainEventQueue is leaving an event in the queue.

Or maybe the profilers "responsiveness" instrumentation is adding an event to this thread's queue between the call to ClearMainEventQueue and the check.
Duplicate of this bug: 1450838
Summary: Intermittent tools/profiler/tests/chrome/test_profile_worker.html | application crashed [@ mozilla::dom::WorkerPrivate::ScheduleDeletion] → Intermittent tools/profiler/tests/chrome/test_profile_worker.html,test_profile_worker_bug_1428076.html | application crashed [@ mozilla::dom::WorkerPrivate::ScheduleDeletion]
This is probably a regression from bug 1431755, see comment 4.
Blocks: 1431755
Crash Signature: [@ mozilla::dom::WorkerPrivate::ScheduleDeletion] → [@ mozilla::dom::WorkerPrivate::ScheduleDeletion] [@ arena_t::MallocSmall(unsigned int, bool)]

Moving these bugs (intermittent test failures with crashes) out of P5.

Priority: P5 → --
Priority: -- → P3

This seems to not occure any more (at least under this signature).

Status: NEW → RESOLVED
Closed: 2 years ago
Resolution: --- → WORKSFORME
You need to log in before you can comment on or make changes to this bug.