Bugzilla

Reporter

Updated

•

4 years ago

Blocks: fuzzing-indexeddb

BugBot [:suhaib / :marco/ :calixte]

Comment 2

•

4 years ago

Can't reproduce that locally with current Nightly. Do you happen to have a Pernosco session for that?

Flags: needinfo?(jkratzer)

Updated

•

4 years ago

Crash Signature: [@ mozilla::dom::indexedDB::`anonymous namespace'::QuotaClient::ShutdownWorkThreads::<T>::__invoke]

Reporter

Comment 4

•

4 years ago

It looks like I failed to mention that this testcase must be served via HTTP in order to reproduce (due to XHR). I'll get you a pernosco session for this bug shortly.

Flags: needinfo?(jkratzer)

Comment 5

•

4 years ago

Well, I served in via HTTP, but it still didn't show up. Will be happy to look into the Pernosco session once it's there :)

Reporter

Comment 6

•

4 years ago

Attached file prefs-default-e10s.js — Details

Reporter

Comment 7

•

4 years ago

Unfortunately, I haven't been able to capture this bug in RR. It appears that there's a race between the XHR calls and window close that I'm unable to replicate. Simon, can you try and reproduce using the attached prefs? With these, I'm able to reproduce under gdb.

Steps to Reproduce:

Start local webserver in directory containing the testcase:
python -m SimpleHTTPServer
Install ffpuppet
pip install ffpuppet
Launch target with ffpuppet
python -m ffpuppet -p prefs-default-e10.js --xvfb ~/path/to/build/firefox -u http://localhost:8000/testcase.html

Flags: needinfo?(sgiesecke)

BugBot [:suhaib / :marco/ :calixte]

Comment 8

•

4 years ago

Thanks a lot for the hint towards ffpuppet, that's new for me :) Will try to reproduce it that way.

Comment 9

•

4 years ago

Bugbug thinks this bug is a regression, but please revert this change in case of error.

Keywords: regression

Comment 10

•

4 years ago

(In reply to Jason Kratzer [:jkratzer] from comment #7)

Unfortunately, I haven't been able to capture this bug in RR. It appears that there's a race between the XHR calls and window close that I'm unable to replicate. Simon, can you try and reproduce using the attached prefs? With these, I'm able to reproduce under gdb.

Steps to Reproduce:

Start local webserver in directory containing the testcase:
python -m SimpleHTTPServer

Install ffpuppet
pip install ffpuppet

Launch target with ffpuppet
python -m ffpuppet -p prefs-default-e10.js --xvfb ~/path/to/build/firefox -u http://localhost:8000/testcase.html

Hm, I have some trouble with getting that working, I get:

[simon@sigibln mozilla-unified]$ python -m ffpuppet -p ~/Downloads/prefs-default-e10s.js --xvfb obj-x86_64-pc-linux-gnu/dist/bin/firefox -u http://localhost:8000/1593863.html
[2020-01-28 11:47:03] Launching Firefox...
[2020-01-28 11:47:27] Running Firefox (pid: 13228)...
[2020-01-28 11:48:28] Shutting down...
[2020-01-28 11:48:28] symbols_path not found: '/home/simon/work/mozilla-unified/obj-x86_64-pc-linux-gnu/dist/bin/symbols'
[2020-01-28 11:48:28] Firefox process closed

Not sure what it expects in that symbols_path. Launch the firefox binary regularly works.

Flags: needinfo?(sgiesecke) → needinfo?(jkratzer)

Julien Cristau [:jcristau]

Reporter

Comment 11

•

4 years ago

Hi Simon. You'll need to either make a local build with symbols or, use the builds on taskcluster. You can use fuzzfetch (https://github.com/MozillaSecurity/fuzzfetch) to download the same builds we use for fuzzing.

pip install fuzzfetch
python -m fuzzfetch -a # For ASAN builds

Flags: needinfo?(jkratzer)

Updated

•

4 years ago

status-firefox72: affected → wontfix

status-firefox73: --- → affected

status-firefox74: --- → affected

Updated

•

4 years ago

Flags: needinfo?(sgiesecke)

Comment 12

•

4 years ago

(In reply to Jason Kratzer [:jkratzer] from comment #11)

Hi Simon. You'll need to either make a local build with symbols or, use the builds on taskcluster. You can use fuzzfetch (https://github.com/MozillaSecurity/fuzzfetch) to download the same builds we use for fuzzing.
pip install fuzzfetch
python -m fuzzfetch -a # For ASAN builds

Sorry it took some time to try this again. I now managed to get the toolchain running, thanks!

However, I still couldn't reproduce it, neither with a current asan-opt nor asan-debug build. Will try to run it repeatedly and see if it hits the crash.

Comment hidden (obsolete)

(In reply to Simon Giesecke [:sg] [he/him] from comment #12)

(In reply to Jason Kratzer [:jkratzer] from comment #11)
Hi Simon. You'll need to either make a local build with symbols or, use the builds on taskcluster. You can use fuzzfetch (https://github.com/MozillaSecurity/fuzzfetch) to download the same builds we use for fuzzing.
pip install fuzzfetch
python -m fuzzfetch -a # For ASAN builds
Sorry it took some time to try this again. I now managed to get the toolchain running, thanks!

However, I still couldn't reproduce it, neither with a current asan-opt nor asan-debug build. Will try to run it repeatedly and see if it hits the crash.

One more issue with ffpuppet, I don't know where to direct this otherwise: I tried running python -m ffpuppet --rr -l rr -p ~/Downloads/prefs-default-e10s.js --xvfb m-c-20200205162717-asan-debug/firefox -d -u http://localhost:8000/1593863.html but then there is a timeout:

Traceback (most recent call last):
  File "/usr/lib64/python2.7/runpy.py", line 174, in _run_module_as_main
    "__main__", fname, loader, pkg_name)
  File "/usr/lib64/python2.7/runpy.py", line 72, in _run_code
    exec code in run_globals
  File "/home/simon/.local/lib/python2.7/site-packages/ffpuppet/__main__.py", line 9, in <module>
    main()
  File "/home/simon/.local/lib/python2.7/site-packages/ffpuppet/main.py", line 203, in main
    extension=args.extension)
  File "/home/simon/.local/lib/python2.7/site-packages/ffpuppet/core.py", line 632, in launch
    bootstrapper.wait(self.is_healthy, timeout=launch_timeout, url=location)
  File "/home/simon/.local/lib/python2.7/site-packages/ffpuppet/helpers.py", line 162, in wait
    raise BrowserTimeoutError("Timed out (%ds) waiting for request" % timeout)
ffpuppet.exceptions.BrowserTimeoutError: Timed out (300s) waiting for request

Not sure if this is due to rr slowing things down, however what puzzles me is that the command executed according to the log is:

[ffpuppet] Launch command: rr record --disable-cpuid-features-ext 0xdc230000,0x2c42,0xc /home/simon/work/fuzzy/m-c-20200205162717-asan-debug/firefox -no-remote -profile /tmp/ffprof_hp2bug http://127.0.0.1:45677

The URL here is not the one I specified on the command line. Is this expected? Unfortunately, I don't really know how ffpuppet is supposed to work.

Andrew Sutherland [:asuth] (he/him)

Comment 14

•

4 years ago

I now managed to capture a rr trace at least with an opt build. Will try to get it with a debug build as well. I fear that when submitting to Pernosco I will not have the right source files, maybe I should do a local build with ASAN and symbols. How do I enable the symbols that are required for running ffpuppet?

Flags: needinfo?(sgiesecke) → needinfo?(jkratzer)

Assignee

Comment 15

•

4 years ago

It's my understanding that the pernosco server knows how to get symbols from taskcluster automatically, so I think you should be good to upload the trace. (At the request of the fuzzing team, even :).

Comment 16

•

4 years ago

As I suspected, the Pernosco session has no source files: https://pernos.co/debug/g5vVTbyljXPgxPIIpdN3CQ/index.html

@asuth the problem is that I cannot even run ffpuppet locally without the symbols as mentioned in https://bugzilla.mozilla.org/show_bug.cgi?id=1593863#c10

With a debug build I always get a timeout.

Comment 17

•

4 years ago

Where did the build used for that recording come from?

Flags: needinfo?(sgiesecke)

Comment 18

•

4 years ago

(In reply to Kyle Huey [:khuey] from comment #17)

Where did the build used for that recording come from?

The build came from fuzzfetch. But I guess when uploading to Pernosco, the source paths do not match my local paths, and so the source files don't show up on Pernosco?

Flags: needinfo?(sgiesecke)

Comment 19

•

4 years ago

Right but which branch?

If the build came from taskcluster your local source tree doesn't matter.

Flags: needinfo?(sgiesecke)

Comment 20

•

4 years ago

I now have a Pernosco with a run from a local build, which has sources here: https://pernos.co/debug/fWsgyDsIed8PqD4MmxC8eg/index.html

(In reply to Kyle Huey [:khuey] from comment #19)

Right but which branch?

If the build came from taskcluster your local source tree doesn't matter.

I am not sure what you mean, I got it via python -m fuzzfetch -a as suggested in https://bugzilla.mozilla.org/show_bug.cgi?id=1593863#c12

Flags: needinfo?(sgiesecke)

Comment 21

•

4 years ago

Hm, but this doesn't really help me. I don't see the sanitizer report in the Pernosco session. Locally I got one quite similar to the one reported originally:

=================================================================
==4362==ERROR: AddressSanitizer: SEGV on unknown address 0x000000000000 (pc 0x7f52e887070a bp 0x7f52c13e9ed0 sp 0x7f52c13e9a20 T20)
==4362==The signal is caused by a WRITE memory access.
==4362==Hint: address points to the zero page.
    #0 0x7f52e8870709 in PersistenceTypeToText /home/simon/work/asan/objdir-ff-asan/dist/include/mozilla/dom/quota/PersistenceType.h:47:7
    #1 0x7f52e8870709 in PersistenceTypeString /home/simon/work/asan/objdir-ff-asan/dist/include/mozilla/dom/quota/PersistenceType.h:54:5
    #2 0x7f52e8870709 in Stringify /home/simon/work/asan/dom/indexedDB/ActorsParent.cpp:18251:18
    #3 0x7f52e8870709 in Stringify /home/simon/work/asan/dom/indexedDB/ActorsParent.cpp:17658:22
    #4 0x7f52e8870709 in mozilla::dom::indexedDB::(anonymous namespace)::QuotaClient::ShutdownTimedOut() /home/simon/work/asan/dom/indexedDB/ActorsParent.cpp:17174:26
    #5 0x7f52e886e9e5 in mozilla::dom::indexedDB::(anonymous namespace)::QuotaClient::ShutdownWorkThreads()::$_33::operator()(nsITimer*, void*) const /home/simon/work/asan/dom/indexedDB/ActorsParent.cpp:17070:3
    #6 0x7f52e886e9c5 in mozilla::dom::indexedDB::(anonymous namespace)::QuotaClient::ShutdownWorkThreads()::$_33::__invoke(nsITimer*, void*) /home/simon/work/asan/dom/indexedDB/ActorsParent.cpp:17070:3
    #7 0x7f52e016ef76 in nsTimerImpl::Fire(int) /home/simon/work/asan/xpcom/threads/nsTimerImpl.cpp:562:7
    #8 0x7f52e016e7b9 in nsTimerEvent::Run() /home/simon/work/asan/xpcom/threads/TimerThread.cpp:259:11
    #9 0x7f52e01812b9 in nsThread::ProcessNextEvent(bool, bool*) /home/simon/work/asan/xpcom/threads/nsThread.cpp:1220:14
    #10 0x7f52e0189e71 in NS_ProcessNextEvent(nsIThread*, bool) /home/simon/work/asan/xpcom/threads/nsThreadUtils.cpp:486:10
    #11 0x7f52e88609bc in SpinEventLoopUntil<mozilla::ProcessFailureBehavior::ReportToCaller, (lambda at /home/simon/work/asan/dom/indexedDB/ActorsParent.cpp:17080:3)> /home/simon/work/asan/objdir-ff-asan/dist/
include/nsThreadUtils.h:346:25
    #12 0x7f52e88609bc in mozilla::dom::indexedDB::(anonymous namespace)::QuotaClient::ShutdownWorkThreads() /home/simon/work/asan/dom/indexedDB/ActorsParent.cpp:17080:3
    #13 0x7f52e831daf1 in mozilla::dom::quota::QuotaManager::Shutdown() /home/simon/work/asan/dom/quota/ActorsParent.cpp:3973:21
    #14 0x7f52e830e3fc in mozilla::dom::quota::QuotaManager::ShutdownInstance() /home/simon/work/asan/dom/quota/ActorsParent.cpp:3559:16
    #15 0x7f52e830e358 in mozilla::dom::quota::RecvShutdownQuotaManager() /home/simon/work/asan/dom/quota/ActorsParent.cpp:2732:3
    #16 0x7f52e15b8c06 in mozilla::ipc::BackgroundParentImpl::RecvShutdownQuotaManager() /home/simon/work/asan/ipc/glue/BackgroundParentImpl.cpp:1027:8
    #17 0x7f52e2277163 in mozilla::ipc::PBackgroundParent::OnMessageReceived(IPC::Message const&) /home/simon/work/asan/objdir-ff-asan/ipc/ipdl/PBackgroundParent.cpp:4679:28
    #18 0x7f52e1632c96 in mozilla::ipc::MessageChannel::DispatchAsyncMessage(mozilla::ipc::ActorLifecycleProxy*, IPC::Message const&) /home/simon/work/asan/ipc/glue/MessageChannel.cpp:2215:25
    #19 0x7f52e162eb22 in mozilla::ipc::MessageChannel::DispatchMessage(IPC::Message&&) /home/simon/work/asan/ipc/glue/MessageChannel.cpp:2137:9
    #20 0x7f52e1630859 in mozilla::ipc::MessageChannel::RunMessage(mozilla::ipc::MessageChannel::MessageTask&) /home/simon/work/asan/ipc/glue/MessageChannel.cpp:1976:3
    #21 0x7f52e16311b7 in mozilla::ipc::MessageChannel::MessageTask::Run() /home/simon/work/asan/ipc/glue/MessageChannel.cpp:2007:13
    #22 0x7f52e01812b9 in nsThread::ProcessNextEvent(bool, bool*) /home/simon/work/asan/xpcom/threads/nsThread.cpp:1220:14
    #23 0x7f52e0189e71 in NS_ProcessNextEvent(nsIThread*, bool) /home/simon/work/asan/xpcom/threads/nsThreadUtils.cpp:486:10
    #24 0x7f52e163be53 in mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) /home/simon/work/asan/ipc/glue/MessagePump.cpp:332:5
    #25 0x7f52e14d1b82 in RunInternal /home/simon/work/asan/ipc/chromium/src/base/message_loop.cc:315:10
    #26 0x7f52e14d1b82 in RunHandler /home/simon/work/asan/ipc/chromium/src/base/message_loop.cc:308:3
    #27 0x7f52e14d1b82 in MessageLoop::Run() /home/simon/work/asan/ipc/chromium/src/base/message_loop.cc:290:3
    #28 0x7f52e017a641 in nsThread::ThreadFunc(void*) /home/simon/work/asan/xpcom/threads/nsThread.cpp:464:10

PersistenceType.h:47 contains a MOZ_CRASH (not sure if this is supposed to trigger the sanitizer), which is the switch case when an invalid enum value is passed in. But according to Pernosco, this line is never executed.

Comment 22

•

4 years ago

Ok. Maybe tysmith has some idea of what needs to be done to get it to work, because he has been successfully uploading traces made from taskcluster builds for a while.

Flags: needinfo?(tylsmith)

Comment 23

•

4 years ago

I am still confused that the Pernosco session does not have any local variables. It's an opt build, so quite a lot of them might be optimized away, but there are none at all.

Comment 24

•

4 years ago

Your binaries were probably built without that debug info.

Comment 25

•

4 years ago

(In reply to Kyle Huey [:khuey] from comment #24)

Your binaries were probably built without that debug info.

Yes, seems so. Getting an ASAN build that is usably for this purpose is incredibly complicated. I followed the instructions on https://developer.mozilla.org/en-US/docs/Mozilla/Testing/Firefox_and_Address_Sanitizer, in particular the mozconfig from there. Probably this is due to -gline-tables-only. I didn't dig deep enough into that before. I will try building without that option...

Comment 26

•

4 years ago

Yeah this is why I think you should talk to tysmith, he's been doing this for a while :)

Comment 27

•

4 years ago

I now got a session with variable info at https://pernos.co/debug/u9VmviL7diE94m2GS1Cehg/index.html, but 1. everything useful has been optimized out, and 2. PersistenceType.h:47 is still claimed to be never executed.

Comment 28

•

4 years ago

Can you do an unoptimized build?

Comment 29

•

4 years ago

If I look at PersistenceType.h:34 I see 4 executions. If I look at ActorsParent.cpp:6573 I see 3 executions, and adding persistenceType in the print field does work. The fourth PersistenceTypeToText invocation is some shutdown path.

Debuggers fall down pretty hard on inlined functions like this, primarily because of terrible optimized compiler debug info.

Comment 30

•

4 years ago

Interestingly, with an unoptimized build, it doesn't crash at all. With -Og, it just triggers the MOZ_CRASH at https://searchfox.org/mozilla-central/rev/b1e51ad5613ad3d911cf42e3e525885ce2278915/dom/indexedDB/ActorsParent.cpp#17181. Maybe with further optimizations, this is still just this MOZ_CRASH, and it just appears to be at a different location due to bad debug info.

Still, it should be investigated why we get an IndexedDB shutdown timeout with an optimized build, but not with an unoptimized build.

The -Og Pernosco session is at https://pernos.co/debug/YXs3YOBGNhiCfbyAGUJBvQ/index.html

The crash annotation data shows:

FactoryOperations: 1 (PersistenceType:default|Origin:http://aaaaaaaaa:DDDD|State:DatabaseWorkVersionChange)
LiveDatabases: 1 (DirectoryLock:1|Transactions:1|OtherProcessActor:1|Origin:http://aaaaaaaaa:DDDD|PersistenceType:default|Closed:1|Invalidated:1|ActorWasAlive:1|ActorDestroyed:0)

Ryan VanderMeulen [:RyanVM]

Comment 31

•

4 years ago

There are quite a lot of differences between the failing and non-failing run, including various JavaScript errors, which makes it hard to identify what is causing to IndexedDB timeout in particular. When looking at the IPC messages that are lost due to channel closure, it turns out that only the BAD run has PRemoteWorkerService::Msg___delete__ affected by this. In the BAD run, one RemoterWorkerServiceParent instance is never destroyed. Maybe this holds something that blocks the IndexedDB shutdown?

Updated

•

4 years ago

status-firefox73: affected → wontfix

status-firefox75: --- → affected

status-firefox-esr68: --- → unaffected

Comment 32

•

4 years ago

So the Pernosco sessions I commented on are:

Pascal Chevrel:pascalc (PTO until April 26)

Reporter

Updated

•

4 years ago

Flags: needinfo?(jkratzer)

Updated

•

4 years ago

status-firefox74: affected → fix-optional

Jens Stutte [:jstutte]

Updated

•

4 years ago

Blocks: qm-shutdown-hangs

Jens Stutte [:jstutte]

Updated

•

4 years ago

status-firefox74: fix-optional → wontfix

status-firefox75: affected → fix-optional

status-firefox76: --- → affected

Andrew Sutherland [:asuth] (he/him)

Comment 34

•

4 years ago

Andrew, what do you think about my hypotheses in https://bugzilla.mozilla.org/show_bug.cgi?id=1593863#c31?

In general, if these crashes are due to shutdown timeouts, do you think it is worthwhile to do anything specific on this bug?

Flags: needinfo?(tylsmith) → needinfo?(bugmail)

Assignee

Comment 35

•

4 years ago

It does seem likely that this is a RemoteWorker life-cycle issue and thanks to your pernosco traces in comment 32 I think I can dig into these.

Assignee: nobody → bugmail

Status: NEW → ASSIGNED

Flags: needinfo?(bugmail)

BugBot [:suhaib / :marco/ :calixte]

Updated

•

4 years ago

Crash Signature: [@ mozilla::dom::indexedDB::`anonymous namespace'::QuotaClient::ShutdownWorkThreads::<T>::__invoke] → [@ mozilla::dom::indexedDB::`anonymous namespace'::QuotaClient::ShutdownWorkThreads::<T>::__invoke] [@ mozalloc_abort | abort | g_assertion_message]