test_caches.html fails on Linux x64 debug with --run-by-dir enabled.

RESOLVED FIXED in Firefox 42

Status

()

Core
DOM
RESOLVED FIXED
3 years ago
3 years ago

People

(Reporter: Kaustabh Datta Choudhury, Assigned: bkelly)

Tracking

42 Branch
mozilla42
Points:
---

Firefox Tracking Flags

(firefox42 fixed)

Details

Attachments

(1 attachment)

(Reporter)

Description

3 years ago
We are trying to get --run-by-dir run more reliably but this test is producing oranges :
Here's the try results : https://treeherder.mozilla.org/#/jobs?repo=try&revision=351ba2066462&filter-resultStatus=testfailed&filter-resultStatus=busted&filter-resultStatus=exception&filter-resultStatus=retry&filter-resultStatus=usercancel&filter-resultStatus=running&filter-resultStatus=pending&exclusion_profile=false&filter-platform=linux%20x64%20debug&filter-searchStr=e10s

Here's an excerpt from the logs :
 
14:01:31     INFO -  1319 INFO TEST-START | dom/cache/test/mochitest/test_caches.html
14:01:31     INFO -  [Child 4177] WARNING: NS_ENSURE_SUCCESS(rv, true) failed with result 0x80570030: file /builds/slave/try-l64-d-00000000000000000000/build/src/docshell/base/nsDocShell.cpp, line 11759
14:01:31     INFO -  ++DOMWINDOW == 12 (0x7f6159e96000) [pid = 4177] [serial = 123] [outer = 0x7f615e6c3000]
14:01:31     INFO -  ++DOCSHELL 0x7f615d1ed800 == 4 [pid = 4177] [id = 44]
14:01:31     INFO -  ++DOMWINDOW == 13 (0x7f615a2b3400) [pid = 4177] [serial = 124] [outer = (nil)]
14:01:31     INFO -  ++DOMWINDOW == 14 (0x7f615a2b6400) [pid = 4177] [serial = 125] [outer = 0x7f615a2b3400]
14:01:32     INFO -  http://mochi.test:8888/tests/dom/cache/test/mochitest/worker_wrapper.js
14:01:32     INFO -  [Child 4177] WARNING: '!info', file /builds/slave/try-l64-d-00000000000000000000/build/src/dom/workers/ServiceWorkerManager.cpp, line 3275
14:01:32     INFO -  ++DOCSHELL 0x7f615d1d5800 == 5 [pid = 4177] [id = 45]
14:01:32     INFO -  ++DOMWINDOW == 15 (0x7f6159e90800) [pid = 4177] [serial = 126] [outer = (nil)]
14:01:32     INFO -  ++DOMWINDOW == 16 (0x7f6159e90c00) [pid = 4177] [serial = 127] [outer = 0x7f6159e90800]
14:01:32     INFO -  [Child 4177] WARNING: NS_ENSURE_SUCCESS(rv, true) failed with result 0x80570030: file /builds/slave/try-l64-d-00000000000000000000/build/src/docshell/base/nsDocShell.cpp, line 11759
14:01:33     INFO -  --DOCSHELL 0x7f615bb41000 == 4 [pid = 4177] [id = 43]
14:01:33     INFO -  ++DOCSHELL 0x7f615d1e0000 == 5 [pid = 4177] [id = 46]
14:01:33     INFO -  ++DOMWINDOW == 17 (0x7f615a2c1c00) [pid = 4177] [serial = 128] [outer = (nil)]
14:01:33     INFO -  ++DOMWINDOW == 18 (0x7f615a36b400) [pid = 4177] [serial = 129] [outer = 0x7f615a2c1c00]
14:01:33     INFO -  [Child 4177] WARNING: NS_ENSURE_SUCCESS(rv, true) failed with result 0x80570030: file /builds/slave/try-l64-d-00000000000000000000/build/src/docshell/base/nsDocShell.cpp, line 11759
14:01:33     INFO -  [Child 4177] WARNING: Called close() before start()!: 'mStarted', file /builds/slave/try-l64-d-00000000000000000000/build/src/dom/workers/MessagePort.cpp, line 216
14:01:33     INFO -  --DOMWINDOW == 17 (0x7f615ac04000) [pid = 4177] [serial = 116] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/cache/test/mochitest/empty.html]
14:01:33     INFO -  --DOMWINDOW == 16 (0x7f6159e8f000) [pid = 4177] [serial = 120] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/cache/test/mochitest/empty.html]
14:01:34     INFO -  MEMORY STAT | vsize 496MB | residentFast 94MB | heapAllocated 18MB
14:01:34     INFO -  1320 INFO TEST-OK | dom/cache/test/mochitest/test_caches.html | took 2482ms
14:01:34     INFO -  [Child 4177] WARNING: NS_ENSURE_SUCCESS(rv, true) failed with result 0x80570030: file /builds/slave/try-l64-d-00000000000000000000/build/src/docshell/base/nsDocShell.cpp, line 11759
14:01:34     INFO -  ++DOMWINDOW == 17 (0x7f615ac04400) [pid = 4177] [serial = 130] [outer = 0x7f615e6c3000]
14:01:34     INFO -  [Child 4177] WARNING: Called close() before start()!: 'mStarted', file /builds/slave/try-l64-d-00000000000000000000/build/src/dom/workers/MessagePort.cpp, line 216
14:01:34     INFO -  [Parent 4122] WARNING: NS_ENSURE_SUCCESS(EnsureScriptEnvironment(), nullptr) failed with result 0x80040111: file /builds/slave/try-l64-d-00000000000000000000/build/src/docshell/base/nsDocShell.cpp, line 4588
14:01:34     INFO -  --DOCSHELL 0x7f76bc08a800 == 5 [pid = 4122] [id = 6]
14:01:34     INFO -  ###!!! [Parent][OnMaybeDequeueOne] Error: Channel closing: too late to send/recv, messages will be lost
14:01:34     INFO -  [Parent 4122] WARNING: NS_ENSURE_SUCCESS(EnsureScriptEnvironment(), nullptr) failed with result 0x80040111: file /builds/slave/try-l64-d-00000000000000000000/build/src/docshell/base/nsDocShell.cpp, line 4588
14:01:34     INFO -  ++DOMWINDOW == 18 (0x7f6159dd8400) [pid = 4177] [serial = 131] [outer = 0x7f615e6c3000]
14:01:34     INFO -  --DOCSHELL 0x7f76d42d6000 == 4 [pid = 4122] [id = 1]
14:01:35     INFO -  --DOCSHELL 0x7f76bc098800 == 3 [pid = 4122] [id = 7]
14:01:35     INFO -  --DOCSHELL 0x7f76c5495800 == 2 [pid = 4122] [id = 3]
14:01:35     INFO -  --DOCSHELL 0x7f76c5496000 == 1 [pid = 4122] [id = 4]
14:01:35     INFO -  [Child 4177] WARNING: NS_ENSURE_TRUE(mDocShell) failed: file /builds/slave/try-l64-d-00000000000000000000/build/src/embedding/browser/nsWebBrowser.cpp, line 363
14:01:35     INFO -  [Child 4177] WARNING: NS_ENSURE_TRUE(domWindow) failed: file /builds/slave/try-l64-d-00000000000000000000/build/src/embedding/browser/nsDocShellTreeOwner.cpp, line 83
14:01:35     INFO -  [Child 4177] WARNING: NS_ENSURE_SUCCESS(EnsureScriptEnvironment(), nullptr) failed with result 0x80040111: file /builds/slave/try-l64-d-00000000000000000000/build/src/docshell/base/nsDocShell.cpp, line 4588
14:01:35     INFO -  [Child 4177] WARNING: NS_ENSURE_SUCCESS(EnsureScriptEnvironment(), nullptr) failed with result 0x80040111: file /builds/slave/try-l64-d-00000000000000000000/build/src/docshell/base/nsDocShell.cpp, line 4588
14:01:35     INFO -  Assertion failure: mTarget == NS_GetCurrentThread(), at /builds/slave/try-l64-d-00000000000000000000/build/src/dom/cache/Context.cpp:120
14:01:59     INFO -  #01: mozilla::dom::cache::Context::QuotaInitRunnable::~QuotaInitRunnable() [dom/cache/Context.cpp:214]
14:01:59     INFO -  #02: mozilla::dom::cache::Context::QuotaInitRunnable::Release() [memory/mozalloc/mozalloc.h:210]
14:01:59     INFO -  #03: nsThread::ProcessNextEvent(bool, bool*) [xpcom/glue/nsTArray.h:361]
14:01:59     INFO -  #04: NS_ProcessNextEvent(nsIThread*, bool) [xpcom/glue/nsThreadUtils.cpp:265]
14:01:59     INFO -  #05: mozilla::dom::cache::Manager::ShutdownAllOnMainThread() [dom/cache/Manager.cpp:1478]
14:01:59     INFO -  #06: mozilla::dom::quota::QuotaManager::Observe(nsISupports*, char const*, char16_t const*) [dom/quota/QuotaManager.cpp:2994]
14:01:59     INFO -  #07: nsObserverList::NotifyObservers(nsISupports*, char const*, char16_t const*) [xpcom/glue/nsTArray.h:361]
14:01:59     INFO -  #08: nsObserverService::NotifyObservers(nsISupports*, char const*, char16_t const*) [xpcom/glue/nsTHashtable.h:128]
14:01:59     INFO -  #09: nsXREDirProvider::DoShutdown() [toolkit/xre/nsXREDirProvider.cpp:902]
14:01:59     INFO -  #10: ScopedXPCOMStartup::~ScopedXPCOMStartup() [toolkit/xre/nsAppRunner.cpp:1491]
14:01:59     INFO -  #11: mozilla::UniquePtr<ScopedXPCOMStartup, mozilla::DefaultDelete<ScopedXPCOMStartup> >::reset(ScopedXPCOMStartup*) [memory/mozalloc/mozalloc.h:210]
14:01:59     INFO -  #12: XREMain::XRE_main(int, char**, nsXREAppData const*) [mfbt/UniquePtr.h:278]
14:01:59     INFO -  #13: XRE_main [toolkit/xre/nsAppRunner.cpp:4449]
14:01:59     INFO -  #14: do_main [browser/app/nsBrowserApp.cpp:214]
14:01:59     INFO -  #15: main [browser/app/nsBrowserApp.cpp:480]
14:01:59     INFO -  #16: libc.so.6 + 0x2176d
14:01:59     INFO -  #17: _start
14:01:59     INFO -  --DOCSHELL 0x7f615d1e0000 == 4 [pid = 4177] [id = 46]
14:01:59     INFO -  --DOCSHELL 0x7f615d1ed800 == 3 [pid = 4177] [id = 44]
14:01:59     INFO -  --DOCSHELL 0x7f615d1d5800 == 2 [pid = 4177] [id = 45]
14:01:59     INFO -  --DOMWINDOW == 17 (0x7f6159ddc000) [pid = 4177] [serial = 117] [outer = (nil)] [url = about:blank]
14:01:59     INFO -  --DOMWINDOW == 16 (0x7f6159dde000) [pid = 4177] [serial = 118] [outer = (nil)] [url = http://mochi.test:8888/tests/SimpleTest/iframe-between-tests.html]
14:01:59     INFO -  --DOMWINDOW == 15 (0x7f6159e90000) [pid = 4177] [serial = 121] [outer = (nil)] [url = http://mochi.test:8888/tests/dom/cache/test/mochitest/empty.html]
14:01:59     INFO -  --DOMWINDOW == 14 (0x7f6159e95000) [pid = 4177] [serial = 122] [outer = (nil)] [url = http://mochi.test:8888/tests/SimpleTest/iframe-between-tests.html]
14:01:59     INFO -  [Child 4177] ###!!! ABORT: Aborting on channel error.: file /builds/slave/try-l64-d-00000000000000000000/build/src/ipc/glue/MessageChannel.cpp, line 1662
14:01:59     INFO -  #01: mozilla::ipc::ProcessLink::OnChannelError() [ipc/glue/MessageLink.cpp:407]
14:01:59     INFO -  #02: IPC::Channel::ChannelImpl::OnFileCanReadWithoutBlocking(int) [ipc/chromium/src/chrome/common/ipc_channel_posix.cc:881]
14:01:59     INFO -  #03: event_base_loop [ipc/chromium/src/third_party/libevent/event.c:1355]
14:01:59     INFO -  #04: base::MessagePumpLibevent::Run(base::MessagePump::Delegate*) [ipc/chromium/src/base/message_pump_libevent.cc:357]
14:01:59     INFO -  #05: MessageLoop::RunInternal() [ipc/chromium/src/base/message_loop.cc:235]
14:01:59     INFO -  #06: MessageLoop::Run() [ipc/chromium/src/base/message_loop.cc:520]
14:01:59     INFO -  #07: base::Thread::ThreadMain() [ipc/chromium/src/base/thread.cc:173]
14:01:59     INFO -  #08: ThreadFunc [ipc/chromium/src/base/platform_thread_posix.cc:41]
14:01:59     INFO -  #09: libpthread.so.0 + 0x7e9a
14:01:59     INFO -  #10: libc.so.6 + 0xf42ed
14:01:59     INFO -  [Child 4177] ###!!! ABORT: Aborting on channel error.: file /builds/slave/try-l64-d-00000000000000000000/build/src/ipc/glue/MessageChannel.cpp, line 1662
14:01:59     INFO -  Hit MOZ_CRASH() at /builds/slave/try-l64-d-00000000000000000000/build/src/memory/mozalloc/mozalloc_abort.cpp:33
14:01:59     INFO -  TEST-INFO | Main app process: killed by SIGSEGV
14:01:59     INFO -  1321 INFO TEST-START | Shutdown
14:01:59     INFO -  1322 INFO Passed:  3235
14:01:59     INFO -  1323 INFO Failed:  0
14:01:59     INFO -  1324 INFO Todo:    0
14:01:59     INFO -  1325 INFO Slowest: 7067ms - /tests/dom/cache/test/mochitest/test_cache_match_vary.html
14:01:59     INFO -  1326 INFO SimpleTest FINISHED
14:01:59     INFO -  1327 INFO TEST-INFO | Ran 1 Loops
14:01:59     INFO -  1328 INFO SimpleTest FINISHED
14:01:59  WARNING -  TEST-UNEXPECTED-FAIL | dom/cache/test/mochitest/test_caches.html | application terminated with exit code 11
(Reporter)

Updated

3 years ago
Blocks: 1162003
(Reporter)

Updated

3 years ago
Flags: needinfo?(ehsan)
(Assignee)

Updated

3 years ago
Assignee: nobody → bkelly
Status: NEW → ASSIGNED
Flags: needinfo?(ehsan)
(Assignee)

Comment 1

3 years ago
The QuotaInitRunnable can be destroyed on the original thread if the Context is canceled in the PREINIT state.  Either we need to drop the assertion or delay the creation of the QuotaInitRunnable.
:bkelly, cool!  Let me or Kaustabh know if you need any help testing a fix for this.
(Assignee)

Comment 3

3 years ago
Created attachment 8631603 [details] [diff] [review]
Delay creation of QuotaInitRunnable until Cache Context actually started. r=ehsan

I believe this should fix the problem, but I can't reproduce locally.

Kaustabh, can you verify this fixes the issue in your test?

Try build with current automation settings:

   https://treeherder.mozilla.org/#/jobs?repo=try&revision=f332674969ba
Attachment #8631603 - Flags: review?(ehsan)
Attachment #8631603 - Flags: feedback?(kaustabh93)

Updated

3 years ago
Attachment #8631603 - Flags: review?(ehsan) → review+
(Reporter)

Comment 4

3 years ago
(In reply to Ben Kelly [:bkelly] from comment #3)
> Created attachment 8631603 [details] [diff] [review]
> Delay creation of QuotaInitRunnable until Cache Context actually started.
> r=ehsan
> 
> I believe this should fix the problem, but I can't reproduce locally.
> 
> Kaustabh, can you verify this fixes the issue in your test?
> 
> Try build with current automation settings:
> 
>    https://treeherder.mozilla.org/#/jobs?repo=try&revision=f332674969ba

Thanks a lot for looking into this. The patch works great : https://treeherder.mozilla.org/#/jobs?repo=try&revision=ca2e8f4f0d89
(Assignee)

Comment 5

3 years ago
Comment on attachment 8631603 [details] [diff] [review]
Delay creation of QuotaInitRunnable until Cache Context actually started. r=ehsan

Thanks for testing.
Attachment #8631603 - Flags: feedback?(kaustabh93)
https://hg.mozilla.org/mozilla-central/rev/04683ab91303
Status: ASSIGNED → RESOLVED
Last Resolved: 3 years ago
status-firefox42: affected → fixed
Resolution: --- → FIXED
Target Milestone: --- → mozilla42
(Assignee)

Comment 9

3 years ago
Kaustabh, it seems your try build is based on this rev:

  https://hg.mozilla.org/try/rev/cef11c3e86c3

Which is from July 6.  This patch landed on July 9.

Can you update your tree and try again?
Flags: needinfo?(bkelly) → needinfo?(kaustabh93)
(Reporter)

Comment 10

3 years ago
(In reply to Ben Kelly [:bkelly] from comment #9)
> Kaustabh, it seems your try build is based on this rev:
> 
>   https://hg.mozilla.org/try/rev/cef11c3e86c3
> 
> Which is from July 6.  This patch landed on July 9.
> 
> Can you update your tree and try again?


thanks for pointing it out. It works fine : https://treeherder.mozilla.org/#/jobs?repo=try&revision=eed3cdf4829a
Status: REOPENED → RESOLVED
Last Resolved: 3 years ago3 years ago
Flags: needinfo?(kaustabh93)
Resolution: --- → FIXED
You need to log in before you can comment on or make changes to this bug.