Closed Bug 1639131 Opened 5 years ago Closed 5 years ago

Intermittent services,toolkit test | application crashed [@ mozilla::BlockingResourceBase::CheckAcquire()]

Categories

(Core :: Graphics: Layers, defect)

defect
Not set
normal

Tracking

()

RESOLVED DUPLICATE of bug 1644254

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: crash, intermittent-failure)

Crash Data

Filed by: btara [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=302866725&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/Mkk9xOozQc27pgq0bOLodQ/runs/0/artifacts/public/logs/live_backing.log


[task 2020-05-19T08:12:43.341Z] 08:12:43     INFO -  TEST-START | toolkit/profile/xpcshell/test_steal_inuse.js
[task 2020-05-19T08:12:43.520Z] 08:12:43     INFO -  mozcrash Saved minidump as /builds/worker/workspace/build/blobber_upload_dir/7aeb5fe7-4f54-ab22-11b3-3d2d92d1fb2e.dmp
[task 2020-05-19T08:12:43.521Z] 08:12:43  WARNING -  PROCESS-CRASH | toolkit/components/telemetry/tests/unit/test_TelemetrySession.js | application crashed [@ mozilla::BlockingResourceBase::CheckAcquire()]
[task 2020-05-19T08:12:43.522Z] 08:12:43     INFO -  Crash dump filename: /tmp/xpc-other-dGpqcR/7aeb5fe7-4f54-ab22-11b3-3d2d92d1fb2e.dmp
[task 2020-05-19T08:12:43.523Z] 08:12:43     INFO -  Operating system: Linux
[task 2020-05-19T08:12:43.524Z] 08:12:43     INFO -                    0.0.0 Linux 4.4.0-1014-aws #14taskcluster1-Ubuntu SMP Tue Apr 3 10:27:00 UTC 2018 x86_64
[task 2020-05-19T08:12:43.525Z] 08:12:43     INFO -  CPU: amd64
[task 2020-05-19T08:12:43.526Z] 08:12:43     INFO -       family 6 model 85 stepping 4
[task 2020-05-19T08:12:43.527Z] 08:12:43     INFO -       2 CPUs
[task 2020-05-19T08:12:43.527Z] 08:12:43     INFO -  GPU: UNKNOWN
[task 2020-05-19T08:12:43.528Z] 08:12:43     INFO -  Crash reason:  SIGSEGV /SEGV_MAPERR
[task 2020-05-19T08:12:43.529Z] 08:12:43     INFO -  Crash address: 0x38
[task 2020-05-19T08:12:43.530Z] 08:12:43     INFO -  Process uptime: not available
[task 2020-05-19T08:12:43.531Z] 08:12:43     INFO -  Thread 2 (crashed)
[task 2020-05-19T08:12:43.531Z] 08:12:43     INFO -   0  libxul.so!mozilla::BlockingResourceBase::CheckAcquire() [BlockingResourceBase.cpp:800142bdea708f819ee11fadcf08f6cf3170eb32 : 216 + 0x0]
[task 2020-05-19T08:12:43.532Z] 08:12:43     INFO -      rax = 0xa65a224362258c00   rdx = 0x00007f370dbffa30
[task 2020-05-19T08:12:43.533Z] 08:12:43     INFO -      rcx = 0x00007f370e6b5800   rbx = 0x0000000000000000
[task 2020-05-19T08:12:43.534Z] 08:12:43     INFO -      rsi = 0x0000000000000001   rdi = 0x0000000000000028
[task 2020-05-19T08:12:43.534Z] 08:12:43     INFO -      rbp = 0x00007f370dbfd420   rsp = 0x00007f370dbfd370
[task 2020-05-19T08:12:43.535Z] 08:12:43     INFO -       r8 = 0x0000000000000000    r9 = 0x0000000000000003
[task 2020-05-19T08:12:43.536Z] 08:12:43     INFO -      r10 = 0x001015bcd78ef34f   r11 = 0x00000000ffffffff
[task 2020-05-19T08:12:43.536Z] 08:12:43     INFO -      r12 = 0x00007f370e66f748   r13 = 0x00007f370dbfd580
[task 2020-05-19T08:12:43.537Z] 08:12:43     INFO -      r14 = 0x0000000000000028   r15 = 0x00007f370dbfd4d0
[task 2020-05-19T08:12:43.538Z] 08:12:43     INFO -      rip = 0x00007f371a5de3d3
[task 2020-05-19T08:12:43.539Z] 08:12:43     INFO -      Found by: given as instruction pointer in context
[task 2020-05-19T08:12:43.544Z] 08:12:43     INFO -   1  libxul.so!mozilla::OffTheBooksMutex::Lock() [BlockingResourceBase.cpp:800142bdea708f819ee11fadcf08f6cf3170eb32 : 317 + 0xc]
[task 2020-05-19T08:12:43.545Z] 08:12:43     INFO -      rbx = 0x0000000000000000   rbp = 0x00007f370dbfd440
[task 2020-05-19T08:12:43.546Z] 08:12:43     INFO -      rsp = 0x00007f370dbfd430   r12 = 0x00007f370e66f748
[task 2020-05-19T08:12:43.547Z] 08:12:43     INFO -      r13 = 0x00007f370dbfd580   r14 = 0x0000000000000028
[task 2020-05-19T08:12:43.547Z] 08:12:43     INFO -      r15 = 0x00007f370dbfd4d0   rip = 0x00007f371a5deb9e
[task 2020-05-19T08:12:43.548Z] 08:12:43     INFO -      Found by: call frame info
[task 2020-05-19T08:12:43.548Z] 08:12:43     INFO -   2  libxul.so!mozilla::layers::ImageBridgeParent::ShutdownInternal() [ImageBridgeParent.cpp:800142bdea708f819ee11fadcf08f6cf3170eb32 : 119 + 0xf]
[task 2020-05-19T08:12:43.549Z] 08:12:43     INFO -      rbx = 0x00000222f076d65c   rbp = 0x00007f370dbfd480
[task 2020-05-19T08:12:43.549Z] 08:12:43     INFO -      rsp = 0x00007f370dbfd450   r12 = 0x00007f370e66f748
[task 2020-05-19T08:12:43.550Z] 08:12:43     INFO -      r13 = 0x00007f370dbfd580   r14 = 0x0000000000000000
[task 2020-05-19T08:12:43.550Z] 08:12:43     INFO -      r15 = 0x00007f370dbfd4d0   rip = 0x00007f371b56a09a
[task 2020-05-19T08:12:43.550Z] 08:12:43     INFO -      Found by: call frame info
[task 2020-05-19T08:12:43.550Z] 08:12:43     INFO -   3  libxul.so!mozilla::detail::RunnableFunction<mozilla::layers::ImageBridgeParent::Shutdown()::$_21>::Run() [nsThreadUtils.h:800142bdea708f819ee11fadcf08f6cf3170eb32 : 574 + 0x5]
[task 2020-05-19T08:12:43.550Z] 08:12:43     INFO -      rbx = 0x00000222f076d65c   rbp = 0x00007f370dbfd490
[task 2020-05-19T08:12:43.550Z] 08:12:43     INFO -      rsp = 0x00007f370dbfd490   r12 = 0x00007f370e66f748
[task 2020-05-19T08:12:43.550Z] 08:12:43     INFO -      r13 = 0x00007f370dbfd580   r14 = 0x00007f370e66f680
[task 2020-05-19T08:12:43.550Z] 08:12:43     INFO -      r15 = 0x00007f370dbfd4d0   rip = 0x00007f371b5775ef
[task 2020-05-19T08:12:43.550Z] 08:12:43     INFO -      Found by: call frame info
[task 2020-05-19T08:12:43.550Z] 08:12:43     INFO -   4  libxul.so!nsThread::ProcessNextEvent(bool, bool*) [nsThread.cpp:800142bdea708f819ee11fadcf08f6cf3170eb32 : 1211 + 0x11]
[task 2020-05-19T08:12:43.550Z] 08:12:43     INFO -      rbx = 0x00000222f076d65c   rbp = 0x00007f370dbfda00
[task 2020-05-19T08:12:43.550Z] 08:12:43     INFO -      rsp = 0x00007f370dbfd4a0   r12 = 0x00007f370e66f748
[task 2020-05-19T08:12:43.550Z] 08:12:43     INFO -      r13 = 0x00007f370dbfd580   r14 = 0x00007f370e66f680
[task 2020-05-19T08:12:43.550Z] 08:12:43     INFO -      r15 = 0x00007f370dbfd4d0   rip = 0x00007f371a5fc4e8
[task 2020-05-19T08:12:43.551Z] 08:12:43     INFO -      Found by: call frame info
[task 2020-05-19T08:12:43.551Z] 08:12:43     INFO -   5  libxul.so!NS_ProcessNextEvent(nsIThread*, bool) [nsThreadUtils.cpp:800142bdea708f819ee11fadcf08f6cf3170eb32 : 501 + 0xc]
[task 2020-05-19T08:12:43.551Z] 08:12:43     INFO -      rbx = 0x0000000000000000   rbp = 0x00007f370dbfda30
[task 2020-05-19T08:12:43.551Z] 08:12:43     INFO -      rsp = 0x00007f370dbfda10   r12 = 0x0000000000000000
[task 2020-05-19T08:12:43.551Z] 08:12:43     INFO -      r13 = 0x00007f370dc04f60   r14 = 0x00007f370dbfda17
[task 2020-05-19T08:12:43.551Z] 08:12:43     INFO -      r15 = 0x00007f370e66f680   rip = 0x00007f371a60017b
[task 2020-05-19T08:12:43.551Z] 08:12:43     INFO -      Found by: call frame info
[task 2020-05-19T08:12:43.551Z] 08:12:43     INFO -   6  libxul.so!mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) [MessagePump.cpp:800142bdea708f819ee11fadcf08f6cf3170eb32 : 302 + 0xa]
[task 2020-05-19T08:12:43.551Z] 08:12:43     INFO -      rbx = 0x00007f370dbfdb28   rbp = 0x00007f370dbfda80
[task 2020-05-19T08:12:43.551Z] 08:12:43     INFO -      rsp = 0x00007f370dbfda40   r12 = 0x0000000000000000
[task 2020-05-19T08:12:43.551Z] 08:12:43     INFO -      r13 = 0x00007f370dc04f60   r14 = 0x00007f370dc04f40
[task 2020-05-19T08:12:43.551Z] 08:12:43     INFO -      r15 = 0x00007f370e66f680   rip = 0x00007f371ac0cf19
[task 2020-05-19T08:12:43.551Z] 08:12:43     INFO -      Found by: call frame info
[task 2020-05-19T08:12:43.551Z] 08:12:43     INFO -   7  libxul.so!MessageLoop::RunInternal() [message_loop.cc:800142bdea708f819ee11fadcf08f6cf3170eb32 : 315 + 0x17]
[task 2020-05-19T08:12:43.551Z] 08:12:43     INFO -      rbx = 0x00007f370dbfdb28   rbp = 0x00007f370dbfdac0
[task 2020-05-19T08:12:43.551Z] 08:12:43     INFO -      rsp = 0x00007f370dbfda90   r12 = 0x00007f370dbfdb28
[task 2020-05-19T08:12:43.551Z] 08:12:43     INFO -      r13 = 0x00007f370dbfdb20   r14 = 0x00007f370dbfdad0
[task 2020-05-19T08:12:43.551Z] 08:12:43     INFO -      r15 = 0x00007f370e66f6c0   rip = 0x00007f371abb8429
[task 2020-05-19T08:12:43.551Z] 08:12:43     INFO -      Found by: call frame info
[task 2020-05-19T08:12:43.552Z] 08:12:43     INFO -   8  libxul.so!MessageLoop::Run() [message_loop.cc:800142bdea708f819ee11fadcf08f6cf3170eb32 : 290 + 0x8]
[task 2020-05-19T08:12:43.552Z] 08:12:43     INFO -      rbx = 0x00007f370dbfdb28   rbp = 0x00007f370dbfdb00
[task 2020-05-19T08:12:43.552Z] 08:12:43     INFO -      rsp = 0x00007f370dbfdad0   r12 = 0x00007f370dbfdb28
[task 2020-05-19T08:12:43.552Z] 08:12:43     INFO -      r13 = 0x00007f370dbfdb20   r14 = 0x00007f370dbfdad0
[task 2020-05-19T08:12:43.552Z] 08:12:43     INFO -      r15 = 0x00007f370e66f6c0   rip = 0x00007f371abb8383
[task 2020-05-19T08:12:43.552Z] 08:12:43     INFO -      Found by: call frame info
[task 2020-05-19T08:12:43.552Z] 08:12:43     INFO -   9  libxul.so!nsThread::ThreadFunc(void*) [nsThread.cpp:800142bdea708f819ee11fadcf08f6cf3170eb32 : 444 + 0x8]
[task 2020-05-19T08:12:43.552Z] 08:12:43     INFO -      rbx = 0x00007f37237a4478   rbp = 0x00007f370dbfdd20
[task 2020-05-19T08:12:43.552Z] 08:12:43     INFO -      rsp = 0x00007f370dbfdb10   r12 = 0x00007f370dbfdb28
[task 2020-05-19T08:12:43.552Z] 08:12:43     INFO -      r13 = 0x00007f370dbfdb20   r14 = 0x00007f370e66f680
[task 2020-05-19T08:12:43.552Z] 08:12:43     INFO -      r15 = 0x00007f370e66f6c0   rip = 0x00007f371a5f9aa9
[task 2020-05-19T08:12:43.552Z] 08:12:43     INFO -      Found by: call frame info
[task 2020-05-19T08:12:43.552Z] 08:12:43     INFO -  10  libnspr4.so!_pt_root [ptthread.c:800142bdea708f819ee11fadcf08f6cf3170eb32 : 201 + 0x7]
[task 2020-05-19T08:12:43.552Z] 08:12:43     INFO -      rbx = 0x00007f370e66e280   rbp = 0x00007f370dbfdd70
[task 2020-05-19T08:12:43.552Z] 08:12:43     INFO -      rsp = 0x00007f370dbfdd30   r12 = 0x00007f370dbfe840
[task 2020-05-19T08:12:43.552Z] 08:12:43     INFO -      r13 = 0x0000000000000000   r14 = 0x00000000000042a0
[task 2020-05-19T08:12:43.552Z] 08:12:43     INFO -      r15 = 0x00007f370dbff700   rip = 0x00007f37241eabd9
[task 2020-05-19T08:12:43.552Z] 08:12:43     INFO -      Found by: call frame info
[task 2020-05-19T08:12:43.553Z] 08:12:43     INFO -  11  libpthread.so.0 + 0x76db
[task 2020-05-19T08:12:43.553Z] 08:12:43     INFO -      rbx = 0x0000000000000000   rbp = 0x0000000000000000
[task 2020-05-19T08:12:43.553Z] 08:12:43     INFO -      rsp = 0x00007f370dbfdd80   r12 = 0x00007f370dbfde40
[task 2020-05-19T08:12:43.553Z] 08:12:43     INFO -      r13 = 0x0000000000000000   r14 = 0x00007f370e66e280
[task 2020-05-19T08:12:43.553Z] 08:12:43     INFO -      r15 = 0x00007ffc30b08fa0   rip = 0x00007f3723ddf6db
[task 2020-05-19T08:12:43.553Z] 08:12:43     INFO -      Found by: call frame info
[task 2020-05-19T08:12:43.553Z] 08:12:43     INFO -  12  libc.so.6 + 0x12188f
[task 2020-05-19T08:12:43.553Z] 08:12:43     INFO -      rsp = 0x00007f370dbfde40   rip = 0x00007f37186d188f
[task 2020-05-19T08:12:43.553Z] 08:12:43     INFO -      Found by: stack scanning
...
...

Happened exactly once only on autoland and doesn't appear to have anything to do with Telemetry code other than it happening during a Telemetry test.

Status: NEW → RESOLVED
Closed: 5 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Component: Telemetry → Graphics: Layers
Product: Toolkit → Core
Resolution: INCOMPLETE → ---
Summary: Intermittent toolkit/components/telemetry/tests/unit/test_TelemetrySession.js | application crashed [@ mozilla::BlockingResourceBase::CheckAcquire()] → Intermittent services,toolkit test | application crashed [@ mozilla::BlockingResourceBase::CheckAcquire()]

The stack mentions libxul.so!mozilla::layers::ImageBridgeParent::ShutdownInternal(). The failures only occur for toolkit or sync tests so far. Any idea what's happening here?

Flags: needinfo?(kats)

I'm not sure. On the face of it the crash looks as though the sImagesBridgeLock monitor gets destroyed somewhere between dereferencing the StaticAutoPtr here and when the MutexAutoLock actually does the lock. That seems like a pretty narrow window of opportunity. And the only thing that destroys the monitor is the ClearOnShutdown which doesn't run until later. I verified in a local build that for both the GPU process and main process, the ImageBridgeParent::ShutdownInternal code runs on the compositor thread while the main thread is blocked here, and that all happens before we even get to the first of the XPCOM shutdown phases here, let alone the ShutdownFinal phase which clears the monitor.

So I don't really know what might be causing this. Now that you've duped bugs to this one, and presumably future occurrences will get starred to this bug, we can see how frequent it is. If it's annoyingly frequent I can try and devote more time to digging into it more.

Flags: needinfo?(kats)

dupe of 1644254

Status: REOPENED → RESOLVED
Closed: 5 years ago5 years ago
Resolution: --- → DUPLICATE
You need to log in before you can comment on or make changes to this bug.