Intermittent org.mozilla.geckoview.test.ZZAccessibilityTest#testAccessibilityFocus | application crashed [@ mozilla::Logger::~Logger()]
Categories
(Core :: IPC, defect, P2)
Tracking
()
Tracking | Status | |
---|---|---|
firefox-esr68 | --- | unaffected |
firefox71 | --- | unaffected |
firefox72 | --- | unaffected |
firefox73 | --- | fixed |
People
(Reporter: intermittent-bug-filer, Assigned: haik)
References
Details
(Keywords: crash, intermittent-failure)
Attachments
(1 file)
Filed by: malexandru [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=276720168&repo=try
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/D3C14RL8SCyK2lStvao-ag/runs/0/artifacts/public/logs/live_backing.log
[task 2019-11-18T10:58:13.151Z] 10:58:13 INFO - TEST-START | org.mozilla.geckoview.test.ZZAccessibilityTest.testAccessibilityFocus
[task 2019-11-18T10:58:16.556Z] 10:58:16 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_RESULT: shortMsg=Process crashed.
[task 2019-11-18T10:58:16.556Z] 10:58:16 INFO - org.mozilla.geckoview.test | INSTRUMENTATION_CODE: 0
[task 2019-11-18T10:58:16.657Z] 10:58:16 INFO - Passed: 464
[task 2019-11-18T10:58:16.657Z] 10:58:16 INFO - Failed: 0
[task 2019-11-18T10:58:16.657Z] 10:58:16 INFO - Todo: 71
[task 2019-11-18T10:58:16.657Z] 10:58:16 INFO - SUITE-END | took 341s
[task 2019-11-18T10:58:17.395Z] 10:58:17 INFO - mozcrash Copy/paste: /builds/worker/workspace/build/linux64-minidump_stackwalk /tmp/tmpWrfroj/625cc98a-de83-68e1-6d09-6c6322bbf067.dmp /builds/worker/workspace/build/symbols
[task 2019-11-18T10:58:22.132Z] 10:58:22 INFO - mozcrash Saved minidump as /builds/worker/workspace/build/blobber_upload_dir/625cc98a-de83-68e1-6d09-6c6322bbf067.dmp
[task 2019-11-18T10:58:22.132Z] 10:58:22 INFO - mozcrash Saved app info as /builds/worker/workspace/build/blobber_upload_dir/625cc98a-de83-68e1-6d09-6c6322bbf067.extra
[task 2019-11-18T10:58:22.139Z] 10:58:22 WARNING - PROCESS-CRASH | org.mozilla.geckoview.test.ZZAccessibilityTest.testAccessibilityFocus | application crashed [@ mozilla::Logger::~Logger()]
[task 2019-11-18T10:58:22.140Z] 10:58:22 INFO - Crash dump filename: /tmp/tmpWrfroj/625cc98a-de83-68e1-6d09-6c6322bbf067.dmp
[task 2019-11-18T10:58:22.140Z] 10:58:22 INFO - Operating system: Android
[task 2019-11-18T10:58:22.140Z] 10:58:22 INFO - 0.0.0 Linux 3.10.0+ #260 SMP PREEMPT Fri May 19 12:48:14 PDT 2017 x86_64
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - CPU: amd64
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - family 6 model 6 stepping 3
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - 4 CPUs
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - GPU: UNKNOWN
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - Crash reason: SIGSEGV /SEGV_MAPERR
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - Crash address: 0x0
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - Process uptime: not available
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - Thread 15 (crashed)
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - 0 libmozglue.so!mozalloc_abort [mozalloc_abort.cpp:bf9d4014a01474bd7d1b0a314e7b4ae767b54c16 : 33 + 0x16]
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - rax = 0x000076b0c520f3c8 rdx = 0x0000000000000004
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - rcx = 0x000076b0c54b7810 rbx = 0x000076b0d75737e0
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - rsi = 0x000076b0d75730b0 rdi = 0x000000000000001b
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - rbp = 0x000076b0d7573770 rsp = 0x000076b0d7573760
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - r8 = 0x0000000000000000 r9 = 0x000076b0e3a59090
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - r10 = 0x0000000000000022 r11 = 0x0000000000000246
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - r12 = 0x000076b0d75737c0 r13 = 0x0000000000000000
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - r14 = 0x000076b0d75737e0 r15 = 0x000076b0d75739e8
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - rip = 0x000076b0c5137e51
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - Found by: given as instruction pointer in context
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - 1 libxul.so!Abort(char const*) [nsDebugImpl.cpp:bf9d4014a01474bd7d1b0a314e7b4ae767b54c16 : 442 + 0x8]
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - rbp = 0x000076b0d7573790 rsp = 0x000076b0d7573780
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - rip = 0x000076b0bc491907
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - Found by: previous frame's frame pointer
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - 2 libxul.so!NS_DebugBreak [nsTSubstring.h:bf9d4014a01474bd7d1b0a314e7b4ae767b54c16 : 0 + 0x19]
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - rbp = 0x000076b0d7573c10 rsp = 0x000076b0d75737a0
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - rip = 0x000076b0bc4917a5
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - Found by: previous frame's frame pointer
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - 3 libxul.so!mozilla::Logger::~Logger() [logging.cc:bf9d4014a01474bd7d1b0a314e7b4ae767b54c16 : 48 + 0x13]
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - rbp = 0x000076b0d7573c30 rsp = 0x000076b0d7573c20
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - rip = 0x000076b0bc9f0f3b
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - Found by: previous frame's frame pointer
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - 4 libxul.so!IDMap<nsCOMPtr<nsIEventTarget> >::AddWithID(nsCOMPtr<nsIEventTarget> const&, int) [id_map.h:bf9d4014a01474bd7d1b0a314e7b4ae767b54c16 : 53 + 0x36]
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - rbp = 0x000076b0d7573c90 rsp = 0x000076b0d7573c40
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - rip = 0x000076b0bca409df
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - Found by: previous frame's frame pointer
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - 5 libxul.so!mozilla::ipc::IToplevelProtocol::GetMessageEventTarget(IPC::Message const&) [ProtocolUtils.cpp:bf9d4014a01474bd7d1b0a314e7b4ae767b54c16 : 836 + 0xf]
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - rbp = 0x000076b0d7573d40 rsp = 0x000076b0d7573ca0
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - rip = 0x000076b0bca3ac72
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - Found by: previous frame's frame pointer
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - 6 libxul.so!mozilla::ipc::MessageChannel::MessageTask::Post() [MessageChannel.cpp:bf9d4014a01474bd7d1b0a314e7b4ae767b54c16 : 2038 + 0x18]
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - rbp = 0x000076b0d7573d90 rsp = 0x000076b0d7573d50
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - rip = 0x000076b0bca37fd6
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - Found by: previous frame's frame pointer
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - 7 libxul.so!mozilla::ipc::MessageChannel::RepostAllMessages() [MessageChannel.cpp:bf9d4014a01474bd7d1b0a314e7b4ae767b54c16 : 2889 + 0x11]
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - rbp = 0x000076b0d7573e00 rsp = 0x000076b0d7573da0
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - rip = 0x000076b0bca3b6a6
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - Found by: previous frame's frame pointer
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - 8 libxul.so!mozilla::ipc::MessageChannel::OnMessageReceivedFromLink(IPC::Message&&) [MessageChannel.cpp:bf9d4014a01474bd7d1b0a314e7b4ae767b54c16 : 1239 + 0x8]
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - rbp = 0x000076b0d7573e50 rsp = 0x000076b0d7573e10
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - rip = 0x000076b0bca378b5
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - Found by: previous frame's frame pointer
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - 9 libxul.so!mozilla::ipc::ProcessLink::OnMessageReceived(IPC::Message&&) [MessageLink.cpp:bf9d4014a01474bd7d1b0a314e7b4ae767b54c16 : 252 + 0xc]
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - rbp = 0x000076b0d7573e80 rsp = 0x000076b0d7573e60
[task 2019-11-18T10:58:22.144Z] 10:58:22 INFO - rip = 0x000076b0bca3cfa2
[task 2019-11-18T10:58:22.145Z] 10:58:22 INFO - Found by: previous frame's frame pointer
[task 2019-11-18T10:58:22.145Z] 10:58:22 INFO - 10 libxul.so!IPC::Channel::ChannelImpl::ProcessIncomingMessages() [ipc_channel_posix.cc:bf9d4014a01474bd7d1b0a314e7b4ae767b54c16 : 583 + 0x10]
[task 2019-11-18T10:58:22.145Z] 10:58:22 INFO - rbp = 0x000076b0d7573fb0 rsp = 0x000076b0d7573e90
[task 2019-11-18T10:58:22.145Z] 10:58:22 INFO - rip = 0x000076b0bc9ffff8
[task 2019-11-18T10:58:22.145Z] 10:58:22 INFO - Found by: previous frame's frame pointer
[task 2019-11-18T10:58:22.145Z] 10:58:22 INFO - 11 libxul.so!IPC::Channel::ChannelImpl::OnFileCanReadWithoutBlocking(int) [ipc_channel_posix.cc:bf9d4014a01474bd7d1b0a314e7b4ae767b54c16 : 828 + 0x8]
[task 2019-11-18T10:58:22.145Z] 10:58:22 INFO - rbp = 0x000076b0d7573fd0 rsp = 0x000076b0d7573fc0
[task 2019-11-18T10:58:22.145Z] 10:58:22 INFO - rip = 0x000076b0bca00a13
[task 2019-11-18T10:58:22.146Z] 10:58:22 INFO - Found by: previous frame's frame pointer
[task 2019-11-18T10:58:22.146Z] 10:58:22 INFO - 12 libxul.so!event_process_active_single_queue [event.c:bf9d4014a01474bd7d1b0a314e7b4ae767b54c16 : 1639 + 0xea]
[task 2019-11-18T10:58:22.146Z] 10:58:22 INFO - rbp = 0x000076b0d7574070 rsp = 0x000076b0d7573fe0
[task 2019-11-18T10:58:22.146Z] 10:58:22 INFO - rip = 0x000076b0bca08f96
[task 2019-11-18T10:58:22.146Z] 10:58:22 INFO - Found by: previous frame's frame pointer
[task 2019-11-18T10:58:22.146Z] 10:58:22 INFO - 13 libxul.so!event_base_loop [event.c:bf9d4014a01474bd7d1b0a314e7b4ae767b54c16 : 1961 + 0xc5]
[task 2019-11-18T10:58:22.146Z] 10:58:22 INFO - rbp = 0x000076b0d7574100 rsp = 0x000076b0d7574080
[task 2019-11-18T10:58:22.146Z] 10:58:22 INFO - rip = 0x000076b0bca069af
[task 2019-11-18T10:58:22.146Z] 10:58:22 INFO - Found by: previous frame's frame pointer
[task 2019-11-18T10:58:22.147Z] 10:58:22 INFO - 14 libxul.so!base::MessagePumpLibevent::Run(base::MessagePump::Delegate*) [message_pump_libevent.cc:bf9d4014a01474bd7d1b0a314e7b4ae767b54c16 : 0 + 0xc]
[task 2019-11-18T10:58:22.147Z] 10:58:22 INFO - rbp = 0x000076b0d7574170 rsp = 0x000076b0d7574110
[task 2019-11-18T10:58:22.147Z] 10:58:22 INFO - rip = 0x000076b0bc9f3d7b
[task 2019-11-18T10:58:22.147Z] 10:58:22 INFO - Found by: previous frame's frame pointer
[task 2019-11-18T10:58:22.147Z] 10:58:22 INFO - 15 libxul.so!MessageLoop::RunInternal() [message_loop.cc:bf9d4014a01474bd7d1b0a314e7b4ae767b54c16 : 315 + 0x17]
[task 2019-11-18T10:58:22.147Z] 10:58:22 INFO - rbp = 0x000076b0d75741b0 rsp = 0x000076b0d7574180
[task 2019-11-18T10:58:22.147Z] 10:58:22 INFO - rip = 0x000076b0bc9f20e2
[task 2019-11-18T10:58:22.147Z] 10:58:22 INFO - Found by: previous frame's frame pointer
[task 2019-11-18T10:58:22.147Z] 10:58:22 INFO - 16 libxul.so!MessageLoop::Run() [message_loop.cc:bf9d4014a01474bd7d1b0a314e7b4ae767b54c16 : 290 + 0x8]
[task 2019-11-18T10:58:22.148Z] 10:58:22 INFO - rbp = 0x000076b0d75741f0 rsp = 0x000076b0d75741c0
[task 2019-11-18T10:58:22.148Z] 10:58:22 INFO - rip = 0x000076b0bc9f204b
[task 2019-11-18T10:58:22.148Z] 10:58:22 INFO - Found by: previous frame's frame pointer
[task 2019-11-18T10:58:22.148Z] 10:58:22 INFO - 17 libxul.so!base::Thread::ThreadMain() [thread.cc:bf9d4014a01474bd7d1b0a314e7b4ae767b54c16 : 192 + 0x8]
[task 2019-11-18T10:58:22.148Z] 10:58:22 INFO - rbp = 0x000076b0d75743d0 rsp = 0x000076b0d7574200
[task 2019-11-18T10:58:22.148Z] 10:58:22 INFO - rip = 0x000076b0bc9fd673
[task 2019-11-18T10:58:22.148Z] 10:58:22 INFO - Found by: previous frame's frame pointer
[task 2019-11-18T10:58:22.148Z] 10:58:22 INFO - 18 libxul.so!ThreadFunc(void*) [platform_thread_posix.cc:bf9d4014a01474bd7d1b0a314e7b4ae767b54c16 : 40 + 0x6]
[task 2019-11-18T10:58:22.148Z] 10:58:22 INFO - rbp = 0x000076b0d75743e0 rsp = 0x000076b0d75743e0
[task 2019-11-18T10:58:22.149Z] 10:58:22 INFO - rip = 0x000076b0bc9f79e2
[task 2019-11-18T10:58:22.149Z] 10:58:22 INFO - Found by: previous frame's frame pointer
[task 2019-11-18T10:58:22.149Z] 10:58:22 INFO - 19 libc.so + 0x89772
[task 2019-11-18T10:58:22.149Z] 10:58:22 INFO - rsp = 0x000076b0d75743f0 rip = 0x000076b0e2af6772
[task 2019-11-18T10:58:22.149Z] 10:58:22 INFO - Found by: stack scanning
[task 2019-11-18T10:58:22.149Z] 10:58:22 INFO - 20 libxul.so!std::__ndk1::__vector_base<MessageLoop::PendingTask, std::__ndk1::allocator<MessageLoop::PendingTask> >::__destruct_at_end(MessageLoop::PendingTask*) [vector : 429 + 0xb]
[task 2019-11-18T10:58:22.149Z] 10:58:22 INFO - rsp = 0x000076b0d7574428 rip = 0x000076b0bc9f79d8
[task 2019-11-18T10:58:22.149Z] 10:58:22 INFO - Found by: stack scanning
[task 2019-11-18T10:58:22.149Z] 10:58:22 INFO - 21 libc.so + 0x299ec
[task 2019-11-18T10:58:22.150Z] 10:58:22 INFO - rsp = 0x000076b0d7574440 rip = 0x000076b0e2a969ec
[task 2019-11-18T10:58:22.150Z] 10:58:22 INFO - Found by: stack scanning
[task 2019-11-18T10:58:22.150Z] 10:58:22 INFO - 22 libc.so + 0x896c0
[task 2019-11-18T10:58:22.150Z] 10:58:22 INFO - rsp = 0x000076b0d7574448 rip = 0x000076b0e2af66c0
[task 2019-11-18T10:58:22.150Z] 10:58:22 INFO - Found by: stack scanning
[task 2019-11-18T10:58:22.150Z] 10:58:22 INFO - 23 libc.so + 0x1ca66
[task 2019-11-18T10:58:22.150Z] 10:58:22 INFO - rsp = 0x000076b0d7574450 rip = 0x000076b0e2a89a66
[task 2019-11-18T10:58:22.150Z] 10:58:22 INFO - Found by: stack scanning
[task 2019-11-18T10:58:22.151Z] 10:58:22 INFO - 24 libxul.so!std::__ndk1::__vector_base<MessageLoop::PendingTask, std::__ndk1::allocator<MessageLoop::PendingTask> >::__destruct_at_end(MessageLoop::PendingTask*) [vector : 429 + 0xb]
[task 2019-11-18T10:58:22.151Z] 10:58:22 INFO - rsp = 0x000076b0d75744b8 rip = 0x000076b0bc9f79d8
[task 2019-11-18T10:58:22.151Z] 10:58:22 INFO - Found by: stack scanning
[task 2019-11-18T10:58:22.151Z] 10:58:22 INFO - Thread 0
Comment 1•4 years ago
|
||
Not the right signature, and this is a debug assertion so it wouldn't show up on crash-stats anyway. (And there should be an accompanying message, Inserting duplicate item
, but it's not in the log anywhere, so that's also not helping. Are we failing to collect error messages on Android?)
The frame with MessageChannel::RepostAllMessages
may be significant — if we're processing a constructor message twice, that might explain the assertion. But I don't think anyone who's still here knows anything about that code….
Comment hidden (Intermittent Failures Robot) |
Assignee | ||
Updated•4 years ago
|
Assignee | ||
Updated•4 years ago
|
Assignee | ||
Comment 3•4 years ago
|
||
As a side effect of calling MessageChannel::MessageTask::Post() for a constructor message, the top-level protocol mEventTargetMap is populated by the mEventTargetMap.AddWithID(target, handle.mId) call in IToplevelProtocol::GetMessageEventTarget().
When we call EndTimeout() due to receiving a message that was previously timed out, we call RepostAllMessages() which ends up calling Post() and GetMessageEventTarget() again for all messages in MessageChannel::mPending. This results in trying to add the same pair to the target map which causes the crash in DEBUG builds. I am not 100% certain that is what is happening here and there aren’t other scenarios that could leave a mapping in mEventTargetMap, but from the stack and code inspection, this seems likely.
So it looks like we just need to account for this scenario by skipping adding the same (target, handle.mID) pair to the mEventTargetMap. When there’s an event target in the map already, we can ASSERT that it matches the new event target so that we would still crash for instances not caused by RepostAllMessages().
While RepostAllMessages() is definitely hit during try testing, this crash requires a constructor message to be in mPending and already Post()’d when the RepostAllMessages().
Assignee | ||
Comment 4•4 years ago
|
||
Avoid crashing in IToplevelProtocol::GetMessageEventTarget() in DEBUG builds for messages that have been re-posted.
Pushed by haftandilian@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/b97bacb338c9 Intermittent org.mozilla.geckoview.test.ZZAccessibilityTest.testAccessibilityFocus r=jld
Comment 7•4 years ago
|
||
bugherder |
Updated•4 years ago
|
Comment 8•4 years ago
|
||
(In reply to Pulsebot from comment #6)
Pushed by haftandilian@mozilla.com:
https://hg.mozilla.org/integration/autoland/rev/b97bacb338c9
Intermittent org.mozilla.geckoview.test.ZZAccessibilityTest.testAccessibilityFocus r=jld
If Phabricator's UI had made it clear that that was going to be the first line of the commit message I would have asked for it to be changed. Oh well.
Assignee | ||
Comment 9•4 years ago
|
||
(In reply to Jed Davis [:jld] ⟨⏰|UTC-6⟩ ⟦he/him⟧ from comment #8)
Intermittent org.mozilla.geckoview.test.ZZAccessibilityTest.testAccessibilityFocus r=jld
If Phabricator's UI had made it clear that that was going to be the first line of the commit message I would have asked for it to be changed. Oh well.
Sorry about that. I should have updated it. I assume you mean there was no reason to mention the test name because it was a generic IPC issue? And a debug only issue at that.
Comment hidden (Intermittent Failures Robot) |
Comment 11•3 years ago
|
||
6c6f5da9-bf33-4082-a19d-7d99e8083d97 Mass rename intermittents due to Bug 1723034.
Description
•