1545400 - DevTools blocks all IndexedDB/Dexie transactions

Status: VERIFIED FIXED

(DevTools :: Debugger, defect, P2)

Description

[Rémi B.]

Attachment: firefox-67-idb-bug-repro.tar.bz2

User Agent: Mozilla/5.0 (X11; Linux x86_64; rv:66.0) Gecko/20100101 Firefox/66.0

Steps to reproduce:

In a WebExtension, in Firefox 67, starting a transaction using Dexie (InxededDB? Although we could not create a minimal example without Dexie so far) while dev-tools/console is opened.

Actual results:

The transaction fails because of the following exception:

{
"_e": {},
"name": "InvalidStateError",
"message": "An attempt was made to use an object that is not, or is no longer, usable",
"inner": {},
}

Expected results:

This transaction should succeed. It seems that it does not matter what we do in the transaction as long as one of the table is accessed. It also does not seem to matter which schema the table has.

What's interesting is that the exact same code works fine if the dev-tools are not opened. And it also works fine in versions of Firefox before 67 (so 66, 65, etc.)

This issue prevents us from running transactions in our extension but is not critical because it only happens when dev-tools are open. On the other hand, the same bug could be used to detect if dev-tools are opened from an extension (or a webpage?), which has been used in the past in Chromium browsers by malicious websites to adapt the behavior and conceal things from developers.

We tried to create a minimal example to reproduce this locally and created a GitHub repository out of it with some instructions: https://github.com/remusao/firefox-67-idb-bug-repro

I also attached an archive to this ticket containing the exact same files (firefox-67-idb-bug-repro.tar.bz2)

Some further remarks and observations:

• This issue appears only in Firefox 67, and not in Firefox 66 or below
• This issue appears with both Dexie 2.0.7 as well as 3.0.0 alpha
• This issue appears only when dev tools for the extension are opened
• This issue does not appear when dev tools are closed
• This issue does not appear when browser console is open (only when the extension dev tool console is)
• We could not reproduce with a pure-IndexedDB example
• We did not try to reproduce with a web-page example (only webextension)

Comment 1

[Rémi B.]

The currently minimal WebExtension we used to reproduce is this (background.js):

import Dexie from 'dexie';

setTimeout(() => {
const db = new Dexie('test_db');
db.version(1).stores({ test_table: 'test_key' });
db.transaction('rw', db.test_table, () => db.test_table.toArray().then(console.log).catch(console.error));
}, 8000);

The 8 seconds delay gives a bit of time to open the dev-tools before the transaction starts but the exact value is not important.

Comment 2

[Rémi B.]

We were also able to reproduce this issue in a single web-page. This allows any website to detect if dev-tools are closed or opened. A POC is available here: https://cdn.cliqz.com/browser-f/fun-demo/firefox_devtools.html

Comment 3

[BugBot [:suhaib / :marco/ :calixte]]

The priority flag is not set for this bug.
:pbro, could you have a look please?

For more information, please visit auto_nag documentation.

Comment 4

[Patrick Brosset <:pbro>]

This is an important problem because it allows sites to fingerprint the browser (detect if devtools is opened) which we want to avoid.
I don't know how to investigate this issue and route it to the right component if it needs to be moved. So for now, let me needinfo Mike who might be able to shade some light.

Comment 5

[Mike Ratcliffe [:miker] [:mratcliffe] [:mikeratcliffe]]

Attachment: Bug 1545400 - Commented out initialization code to simplify debugging

Comment 6

[Mike Ratcliffe [:miker] [:mratcliffe] [:mikeratcliffe]]

STR

1. Apply the attached patch using moz-phab patch D32018 --apply-to central.
2. Open the test page.
3. Open the toolbox.

The toolbox is almost empty because my patch disables lots of our stuff. The content page will show that it knows the toolbox is open... it knows this because the DB promise has been rejected.

Seems to be caused by _attachAndResumeThread() as far as I can see.

1. toolbox.js::open() calls:
   • await this._target.attach();
   • this._threadClient = await this._attachAndResumeThread();
2. From that point on all DB communication is blocked.

It seems like as soon as _attachAndResumeThread() is called then all DB transactions are blocked.

This issue was introduced in Firefox 67.

Comment 7

[Logan Smyth [:loganfsmyth]]

Here's the root cause:

* thread #1, queue = 'com.apple.main-thread', stop reason = breakpoint 1.1
  * frame #0: 0x0000000121829204 XUL`mozilla::dom::IDBTransaction::Run(this=0x00000001183d6680) at IDBTransaction.cpp:952
    frame #1: 0x000000011c00baf1 XUL`mozilla::CycleCollectedJSContext::CleanupIDBTransactions(this=0x000000010cbf9000, aRecursionDepth=1) at CycleCollectedJSContext.cpp:453
    frame #2: 0x000000011c00ec8f XUL`mozilla::CycleCollectedJSContext::AfterProcessMicrotasks(this=0x000000010cbf9000) at CycleCollectedJSContext.cpp:507
    frame #3: 0x000000011c00d393 XUL`mozilla::CycleCollectedJSContext::PerformMicroTaskCheckPoint(this=0x000000010cbf9000, aForce=false) at CycleCollectedJSContext.cpp:598
    frame #4: 0x000000011c00d300 XUL`mozilla::CycleCollectedJSContext::runJobs(this=0x000000010cbf9000, aCx=0x000000010f729000) at CycleCollectedJSContext.cpp:291
    frame #5: 0x0000000125089942 XUL`JS::AutoDebuggerJobQueueInterruption::runJobs(this=0x00007ffee39a0d28) at Promise.cpp:5692
    frame #6: 0x0000000125182ab1 XUL`js::ResumeMode js::Debugger::dispatchHook<js::Debugger::slowPathOnNewScript(JSContext*, JS::Handle<JSScript*>)::$_15, js::Debugger::slowPathOnNewScript(JSContext*, JS::Handle<JSScript*>)::$_16>(cx=0x000000010f729000, hookIsEnabled=(anonymous class) @ 0x00007ffee39a0d60, fireHook=(anonymous class) @ 0x00007ffee39a0d50)::$_15, js::Debugger::slowPathOnNewScript(JSContext*, JS::Handle<JSScript*>)::$_16) at Debugger.cpp:2188
    frame #7: 0x00000001251826eb XUL`js::Debugger::slowPathOnNewScript(cx=0x000000010f729000, script=JS::HandleScript @ 0x00007ffee39a0e60) at Debugger.cpp:2198
    frame #8: 0x00000001252bf1e3 XUL`js::Debugger::onNewScript(cx=0x000000010f729000, script=JS::HandleScript @ 0x00007ffee39a0e90) at Debugger.h:2048
    frame #9: 0x000000012534dce0 XUL`js::CloneFunctionAndScript(cx=0x000000010f729000, fun=JS::HandleFunction @ 0x00007ffee39a0fe8, enclosingEnv=JS::HandleObject @ 0x00007ffee39a0fe0, newScope=js::HandleScope @ 0x00007ffee39a0fd8, sourceObject=Handle<js::ScriptSourceObject *> @ 0x00007ffee39a0fd0, allocKind=FUNCTION, proto=JS::HandleObject @ 0x00007ffee39a0fc8) at JSFunction.cpp:2317
    frame #10: 0x0000000124fc3c8b XUL`js::CloneFunctionObjectIfNotSingleton(cx=0x000000010f729000, fun=JS::HandleFunction @ 0x00007ffee39a1190, parent=JS::HandleObject @ 0x00007ffee39a1188, proto=JS::HandleObject @ 0x00007ffee39a1180, newKind=GenericObject) at JSFunction-inl.h:95
    frame #11: 0x0000000124fc5811 XUL`js::Lambda(cx=0x000000010f729000, fun=JS::HandleFunction @ 0x00007ffee39a1210, parent=JS::HandleObject @ 0x00007ffee39a1208) at Interpreter.cpp:4505
    frame #12: 0x0000000124fb8a21 XUL`Interpret(cx=0x000000010f729000, state=0x00007ffee39a44b8) at Interpreter.cpp:3585
    frame #13: 0x0000000124fa901c XUL`js::RunScript(cx=0x000000010f729000, state=0x00007ffee39a44b8) at Interpreter.cpp:423
    frame #14: 0x0000000124fc0bf7 XUL`js::InternalCallOrConstruct(cx=0x000000010f729000, args=0x00007ffee39a4938, construct=NO_CONSTRUCT) at Interpreter.cpp:563
    frame #15: 0x0000000124fc1423 XUL`InternalCall(cx=0x000000010f729000, args=0x00007ffee39a4938) at Interpreter.cpp:590
    frame #16: 0x0000000124fc11fd XUL`js::CallFromStack(cx=0x000000010f729000, args=0x00007ffee39a4938) at Interpreter.cpp:594
    frame #17: 0x0000000125caab6e XUL`js::jit::DoCallFallback(cx=0x000000010f729000, frame=0x00007ffee39a4eb0, stub=0x000000011015c218, argc=2, vp=0x00007ffee39a4e48, res=JS::MutableHandleValue @ 0x00007ffee39a4930) at BaselineIC.cpp:3763

Looks like some of our run-to-completion logic job queue logic ends up running the IndexedDB transaction runnable when this code happens to trigger an onNewScript in the debugger server. This causes the IndexedDB transaction to be committed synchronously instead of when control is yielded back to the task queue. AutoDebuggerJobQueueInterruption is new in https://bugzilla.mozilla.org/show_bug.cgi?id=1145201 which landed in 67.

@jimb Do you have a sense for what might be going wrong to cause this?

Comment 8

[Jim Blandy :jimb]

So, when we entered the scope of adjqi in dispatchHook here:

https://searchfox.org/mozilla-central/rev/6c9f60f8cc064a1005cd8141ecd526578ae9da7a/js/src/vm/Debugger.cpp#2176

the microtask queue was set aside, and a fresh empty one established in its place. So ideally we would not be doing any work that wasn't enqueued during that pause. But what's interesting is, CleanupIDBTransactions is called directly from AfterProcessMicrotasks!

https://searchfox.org/mozilla-central/rev/6c9f60f8cc064a1005cd8141ecd526578ae9da7a/xpcom/base/CycleCollectedJSContext.cpp#507

That is, it's not a queued job, it's something directly required by the HTML spec, as part of the definition of a "microtask checkpoint".

So the serious underlying problem here is that the debugger and other tabs need to be able to perform microtask checkpoints while the debuggee is paused at a breakpoint, and those other checkpoints need to "Cleanup Indexed Database transactions", per spec, but the debuggee's transactions should never be affected.

I suspect the RecursionDepth() argument there has something to do with this story...

Comment 9

[Logan Smyth [:loganfsmyth]]

Attachment: bug-1545400-reproduction.html

With that stack trace, it's now super easy to make a small reproducible example by triggering 'onNewScript' during an IndexedDB transaction. This bug doesn't require 'eval', but it's the easiest way to trigger it.

With devtools closed this page renders green with a success message and with devtools open the page renders reg with an error message.

Comment 10

[Jim Blandy :jimb]

Fantastic!

I think the fix is to make sure that CycleCollectedJSContext::RecursionDepth is incremented during debugger callbacks. This value is used to label IndexedDB transactions, and CycleCollectedJSContext::CleanupIDBTransactions skips transactions for other depths, which is what we want: a callback's IndexedDB activity should not influence the debuggee's activity.

Comment 11

[Jim Blandy :jimb]

It should suffice to have mozilla::CycleCollectedJSContext::SavedMicroTaskQueue increment and decrement the depth in its constructor and destructor.

Comment 12

[Brian Hackett [Laid off!]]

Attachment: Bug 1545400 - Increment recursion depth when debugger has saved a thread's microtasks, r=arai.

Comment 13

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/3f660fc88b99
Increment recursion depth when debugger has saved a thread's microtasks, r=arai,smaug.

Comment 14

[Natalia Csoregi [:nataliaCs]]

https://hg.mozilla.org/mozilla-central/rev/3f660fc88b99

Comment 15

[Julien Cristau [:jcristau]]

Do we need this in 68? Please request beta uplift if so.

Comment 16

[Brian Hackett [Laid off!]]

Comment on attachment 9068161 [details]
Bug 1545400 - Increment recursion depth when debugger has saved a thread's microtasks, r=arai.

Beta/Release Uplift Approval Request

• User impact if declined: When using the debugger, indexed DB operations can behave incorrectly.
• Is this code covered by automated tests?: Yes
• Has the fix been verified in Nightly?: No
• Needs manual test from QE?: Yes
• If yes, steps to reproduce: Bug includes STR. There is an automated test for this fix but it has not been formally verified fixed.
• List of other uplifts needed: None
• Risk to taking this patch: Medium
• Why is the change risky/not risky? (and alternatives if risky): While the patch is small, there are a number of places that use the the recursion depth modified by the patch. Several people have looked into these uses and there shouldn't be any adverse impacts.
• String changes made/needed:

Comment 17

[Julien Cristau [:jcristau]]

Comment on attachment 9068161 [details]
Bug 1545400 - Increment recursion depth when debugger has saved a thread's microtasks, r=arai.

approved for 68.0b10

Comment 18

[Julien Cristau [:jcristau]]

https://hg.mozilla.org/releases/mozilla-beta/rev/9870fe7e0c59

Comment 19

[Rares Doghi, Desktop QA]

Hi guys, can someone help us with some steps on this issue, its still a bit unclear, Is there a Reduced case we can test with for Fx69 and Beta 68 ?

So far we have this URL https://cdn.cliqz.com/browser-f/fun-demo/firefox_devtools.html that shows us when Dev tools is open or not, but in Fx69 and Beta68 it just shows Closed even when its open.

What are the Expected results ? how can we verify this issue on our end ?

Comment 20

[Logan Smyth [:loganfsmyth]]

The test case in https://bugzilla.mozilla.org/show_bug.cgi?id=1545400#c9 should be enough to fully verify this.

Comment 21

[Rares Doghi, Desktop QA]

Hi, I managed to reproduce this issue using the test case from Comment 9, Thanks for the heads up. This issue is Verified as Fixed In Firefox Beta 68.0b10 as well as our latest Nightly build 69.0a1 (2019-06-13). I will mark this issue accordingly.