intermittent assertion failure: NS_GetCurrentThread() == mOwningThread (Wrong thread!) / mOwningEventTarget->IsOnCurrentThread() caused by storage::Service::minimizeMemory()

NEW
Unassigned
(NeedInfo from)

Status

()

Toolkit
Storage
P3
normal
2 years ago
a month ago

People

(Reporter: Away for a while, Unassigned, NeedInfo)

Tracking

({intermittent-failure})

Firefox Tracking Flags

(Not tracked)

Details

(crash signature)

(Reporter)

Description

2 years ago
<http://archive.mozilla.org/pub/firefox/try-builds/eakhgari@mozilla.com-12fb5862dfc8110cae035ac55c32231fb4cb893f/try-linux64-debug/try_ubuntu64_vm-debug_test-mochitest-e10s-browser-chrome-2-bm114-tests1-linux64-build658.txt.gz>

00:31:38     INFO -  Assertion failure: NS_GetCurrentThread() == mOwningThread (Wrong thread!), at /builds/slave/try-l64-d-00000000000000000000/build/src/xpcom/threads/LazyIdleThread.cpp:530
00:32:06     INFO -  #01: nsThread::PutEvent(already_AddRefed<nsIRunnable>&&, nsThread::nsNestedEventTarget*) [xpcom/threads/nsThread.cpp:594]
00:32:06     INFO -  #02: nsThread::DispatchInternal(already_AddRefed<nsIRunnable>&&, unsigned int, nsThread::nsNestedEventTarget*) [xpcom/threads/nsThread.cpp:652]
00:32:06     INFO -  #03: nsIEventTarget::Dispatch(nsIRunnable*, unsigned int) [mfbt/AlreadyAddRefed.h:101]
00:32:06     INFO -  #04: mozilla::storage::Service::minimizeMemory() [storage/mozStorageService.cpp:389]
00:32:06     INFO -  #05: mozilla::storage::Service::Observe(nsISupports*, char const*, char16_t const*) [storage/mozStorageService.cpp:936]
00:32:06     INFO -  #06: nsObserverList::NotifyObservers(nsISupports*, char const*, char16_t const*) [xpcom/glue/nsTArray.h:367]
00:32:06     INFO -  #07: nsObserverService::NotifyObservers(nsISupports*, char const*, char16_t const*) [xpcom/glue/nsTHashtable.h:134]
00:32:06     INFO -  #08: NS_InvokeByIndex [xpcom/reflect/xptcall/md/unix/xptcinvoke_x86_64_unix.cpp:176]
00:32:06     INFO -  #09: CallMethodHelper::Call() [js/xpconnect/src/xpcprivate.h:857]
00:32:06     INFO -  #10: XPCWrappedNative::CallMethod(XPCCallContext&, XPCWrappedNative::CallMode) [js/xpconnect/src/XPCWrappedNative.cpp:1381]
00:32:06     INFO -  #11: XPC_WN_CallMethod(JSContext*, unsigned int, JS::Value*) [js/xpconnect/src/XPCWrappedNativeJSOps.cpp:1115]
00:32:06     INFO -  #12: js::CallJSNative(JSContext*, bool (*)(JSContext*, unsigned int, JS::Value*), JS::CallArgs const&) [js/src/jscntxtinlines.h:236]
00:32:06     INFO -  #13: js::Invoke(JSContext*, JS::CallArgs const&, js::MaybeConstruct) [js/src/vm/Interpreter.cpp:479]
00:32:06     INFO -  #14: Interpret [js/src/vm/Interpreter.cpp:2803]
00:32:06     INFO -  #15: js::RunScript(JSContext*, js::RunState&) [js/src/vm/Interpreter.cpp:426]
00:32:06     INFO -  #16: js::Invoke(JSContext*, JS::CallArgs const&, js::MaybeConstruct) [js/src/vm/Interpreter.cpp:497]
00:32:06     INFO -  #17: js::Invoke(JSContext*, JS::Value const&, JS::Value const&, unsigned int, JS::Value const*, JS::MutableHandle<JS::Value>) [js/src/vm/Interpreter.cpp:531]
00:32:06     INFO -  #18: js::DirectProxyHandler::call(JSContext*, JS::Handle<JSObject*>, JS::CallArgs const&) const [js/public/RootingAPI.h:719]
00:32:06     INFO -  #19: js::CrossCompartmentWrapper::call(JSContext*, JS::Handle<JSObject*>, JS::CallArgs const&) const [js/src/proxy/CrossCompartmentWrapper.cpp:289]
00:32:06     INFO -  #20: js::Proxy::call(JSContext*, JS::Handle<JSObject*>, JS::CallArgs const&) [js/src/proxy/Proxy.cpp:391]
00:32:06     INFO -  #21: js::proxy_Call(JSContext*, unsigned int, JS::Value*) [js/public/RootingAPI.h:719]
00:32:06     INFO -  #22: js::CallJSNative(JSContext*, bool (*)(JSContext*, unsigned int, JS::Value*), JS::CallArgs const&) [js/src/jscntxtinlines.h:236]
00:32:06     INFO -  #23: js::Invoke(JSContext*, JS::CallArgs const&, js::MaybeConstruct) [js/src/vm/Interpreter.cpp:467]
00:32:06     INFO -  #24: js::Invoke(JSContext*, JS::Value const&, JS::Value const&, unsigned int, JS::Value const*, JS::MutableHandle<JS::Value>) [js/src/vm/Interpreter.cpp:531]
00:32:06     INFO -  #25: JS::Call(JSContext*, JS::Handle<JS::Value>, JS::Handle<JS::Value>, JS::HandleValueArray const&, JS::MutableHandle<JS::Value>) [js/src/jsapi.cpp:2864]
00:32:06     INFO -  #26: mozilla::dom::AnyCallback::Call(JSContext*, JS::Handle<JS::Value>, JS::Handle<JS::Value>, JS::MutableHandle<JS::Value>, mozilla::ErrorResult&) [obj-firefox/dom/bindings/PromiseBinding.cpp:78]
00:32:06     INFO -  #27: mozilla::dom::AnyCallback::Call(JS::Handle<JS::Value>, JS::MutableHandle<JS::Value>, mozilla::ErrorResult&, char const*, mozilla::dom::CallbackObject::ExceptionHandling, JSCompartment*) [obj-firefox/dist/include/mozilla/dom/PromiseBinding.h:149]
00:32:06     INFO -  #28: mozilla::dom::WrapperPromiseCallback::Call(JSContext*, JS::Handle<JS::Value>) [dom/promise/PromiseCallback.cpp:341]
00:32:06     INFO -  #29: mozilla::dom::PromiseReactionJob::Run() [mfbt/Maybe.h:372]
00:32:06     INFO -  #30: mozilla::dom::Promise::PerformMicroTaskCheckpoint() [xpcom/glue/nsDebug.h:40]
00:32:06     INFO -  #31: mozilla::CycleCollectedJSRuntime::AfterProcessTask(unsigned int) [xpcom/base/CycleCollectedJSRuntime.cpp:1161]
00:32:06     INFO -  #32: XPCJSRuntime::AfterProcessTask(unsigned int) [js/xpconnect/src/XPCJSRuntime.cpp:3651]
00:32:06     INFO -  #33: nsThread::ProcessNextEvent(bool, bool*) [xpcom/threads/nsThread.cpp:1007]
00:32:06     INFO -  #34: NS_ProcessNextEvent(nsIThread*, bool) [xpcom/glue/nsThreadUtils.cpp:297]
00:32:06     INFO -  #35: mozilla::ipc::MessagePump::Run(base::MessagePump::Delegate*) [ipc/glue/MessagePump.cpp:96]
00:32:06     INFO -  #36: MessageLoop::RunInternal() [ipc/chromium/src/base/message_loop.cc:235]
00:32:06     INFO -  #37: MessageLoop::Run() [ipc/chromium/src/base/message_loop.cc:520]
00:32:06     INFO -  #38: nsBaseAppShell::Run() [widget/nsBaseAppShell.cpp:158]
00:32:06     INFO -  #39: nsAppStartup::Run() [toolkit/components/startup/nsAppStartup.cpp:282]
00:32:06     INFO -  #40: XREMain::XRE_mainRun() [toolkit/xre/nsAppRunner.cpp:4327]
00:32:06     INFO -  #41: XREMain::XRE_main(int, char**, nsXREAppData const*) [toolkit/xre/nsAppRunner.cpp:4423]
00:32:06     INFO -  #42: XRE_main [toolkit/xre/nsAppRunner.cpp:4526]
00:32:06     INFO -  #43: do_main [browser/app/nsBrowserApp.cpp:212]
00:32:06     INFO -  #44: main [browser/app/nsBrowserApp.cpp:354]
00:32:06     INFO -  #45: libc.so.6 + 0x2176d
00:32:06     INFO -  #46: _start
00:32:06     INFO -  Assertion failure: mPendingEventCount (Mismatched calls to observer methods!), at /builds/slave/try-l64-d-00000000000000000000/build/src/xpcom/threads/LazyIdleThread.cpp:550
00:32:06     INFO -  #01: nsThread::ProcessNextEvent(bool, bool*) [xpcom/threads/nsThread.cpp:1003]
00:32:06     INFO -  #02: NS_ProcessNextEvent(nsIThread*, bool) [xpcom/glue/nsThreadUtils.cpp:297]
00:32:06     INFO -  #03: mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) [ipc/glue/MessagePump.cpp:327]
00:32:06     INFO -  #04: MessageLoop::RunInternal() [ipc/chromium/src/base/message_loop.cc:235]
00:32:06     INFO -  #05: MessageLoop::Run() [ipc/chromium/src/base/message_loop.cc:520]
00:32:06     INFO -  #06: nsThread::ThreadFunc(void*) [xpcom/threads/nsThread.cpp:403]
00:32:06     INFO -  #07: _pt_root [nsprpub/pr/src/pthreads/ptthread.c:215]
00:32:06     INFO -  #08: libpthread.so.0 + 0x7e9a
00:32:06     INFO -  #09: libc.so.6 + 0xf42ed
00:32:06     INFO -  [Child 3065] ###!!! ABORT: Aborting on channel error.: file /builds/slave/try-l64-d-00000000000000000000/build/src/ipc/glue/MessageChannel.cpp, line 1762
00:32:06     INFO -  #01: mozilla::ipc::ProcessLink::OnChannelError() [ipc/glue/MessageLink.cpp:429]
00:32:06     INFO -  #02: IPC::Channel::ChannelImpl::OnFileCanReadWithoutBlocking(int) [ipc/chromium/src/chrome/common/ipc_channel_posix.cc:881]
00:32:06     INFO -  #03: event_base_loop [ipc/chromium/src/third_party/libevent/event.c:1355]
00:32:06     INFO -  #04: base::MessagePumpLibevent::Run(base::MessagePump::Delegate*) [ipc/chromium/src/base/message_pump_libevent.cc:370]
00:32:06     INFO -  #05: MessageLoop::RunInternal() [ipc/chromium/src/base/message_loop.cc:235]
00:32:06     INFO -  #06: MessageLoop::Run() [ipc/chromium/src/base/message_loop.cc:520]
00:32:06     INFO -  #07: base::Thread::ThreadMain() [ipc/chromium/src/base/thread.cc:175]
00:32:06     INFO -  #08: ThreadFunc [ipc/chromium/src/base/platform_thread_posix.cc:38]
00:32:06     INFO -  #09: libpthread.so.0 + 0x7e9a
00:32:06     INFO -  #10: libc.so.6 + 0xf42ed
00:32:06     INFO -  [Child 3065] ###!!! ABORT: Aborting on channel error.: file /builds/slave/try-l64-d-00000000000000000000/build/src/ipc/glue/MessageChannel.cpp, line 1762
00:32:06     INFO -  Hit MOZ_CRASH() at /builds/slave/try-l64-d-00000000000000000000/build/src/memory/mozalloc/mozalloc_abort.cpp:33
(Reporter)

Updated

2 years ago
Blocks: 998330
This looks like a serious LazyIdleThread semantics problem.  Whatever we are dispatching to is a LazyIdleThread that demands that only its owner dispatches to it.

So I think the scenario is this:
- Someone is a LazyIdleThread
- The LazyIdleThread opens a synchronous mozStorage connection
- DOOM! DOOM DOOM DOOM!

This seems like mozStorage can either blame the consumer or LazyIdleThread for having dubious semantics.  LazyIdleThread.h for one doesn't seem to justify why only its creator can use it.

Comment 2

a year ago
Bulk assigning P3 to all open intermittent bugs without a priority set in Firefox components per bug 1298978.
Priority: -- → P3

Updated

9 months ago
Duplicate of this bug: 1351764
Duplicate of this bug: 1357554
Looking into this more (because of bug 1357554 showing this is still a thing that happens and can waste the valuable time of those who file bugs on assertions they encounter), it seems:
- It's QuotaManager's IOThread that is a LazyIdleThread and the root cause.
- The connections in question aren't QuotaManager's, but its clients dom/indexedDB, dom/cache, and dom/asmjscache.  (QuotaManager does use a SQLite database for tracking the status of <profile>/storage, but that's new and is a very short-lived connection.  The usage did not exist when this intermittent was first reported.)
- mozStorage's use of do_GetCurrentThread() is indeed not seeing the LazyIdleThread (as touched on in bug 722181), but instead the underlying backing thread that can go away.  The assertion is happening because LazyIdleThread registers itself as an observer for the underlying nsThread and enforces its assertion in the OnDispatched notification.

Looking at https://bugzilla.mozilla.org/buglist.cgi?quicksearch=lazyidlethread I see a number of other intermittent failures involving LazyIdleThread.  The only other LazyIdleThread consumers seem to be nsHttpNegotiateAuth and ipc/glue/CrashReporterHost.

Given how important QuotaManager is to the system and that arguably adding thread startup overhead to our latency for ServiceWorkers' use of dom/cache is bad, maybe it would be a good short-term fix to just have QuotaManager use a permanent thread.  :janv, what are your thoughts on that?

We could maintain the balance by addressing bug 722181 and having mozStorage's async threads not be dedicated threads.  (There's also some new possibilities for addressing that that I'll post there.)
Flags: needinfo?(jvarga)

Updated

6 months ago
Duplicate of this bug: 1376542
Crash Signature: [@ mozilla::LazyIdleThread::OnDispatchedEvent(nsIThreadInternal *) ]
Duplicate of this bug: 1376543
Duplicate of this bug: 1371862
Duplicate of this bug: 1358660
Summary: intermittent assertion failure: NS_GetCurrentThread() == mOwningThread (Wrong thread!) caused by storage::Service::minimizeMemory() → intermittent assertion failure: NS_GetCurrentThread() == mOwningThread (Wrong thread!) / mOwningEventTarget->IsOnCurrentThread() caused by storage::Service::minimizeMemory()

Comment 10

5 months ago
1 failures in 718 pushes (0.001 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* autoland: 1

Platform breakdown:
* windows8-64: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1239794&startday=2017-06-26&endday=2017-07-02&tree=all

Comment 11

5 months ago
1 failures in 656 pushes (0.002 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* mozilla-central: 1

Platform breakdown:
* windows8-64: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1239794&startday=2017-07-03&endday=2017-07-09&tree=all

Comment 12

4 months ago
1 failures in 949 pushes (0.001 failures/push) were associated with this bug in the last 7 days.   

Repository breakdown:
* mozilla-beta: 1

Platform breakdown:
* windows7-32: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1239794&startday=2017-08-14&endday=2017-08-20&tree=all

Comment 13

a month ago
1 failures in 857 pushes (0.001 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* autoland: 1

Platform breakdown:
* windows7-32: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1239794&startday=2017-10-30&endday=2017-11-05&tree=all
You need to log in before you can comment on or make changes to this bug.