Closed Bug 1388998 Opened 2 years ago Closed 2 years ago

Crash in memcpy | nsTArray_base<T>::ShiftData<T> | nsTArray_Impl<T>::RemoveElementsAt | mozilla::storage::Service::unregisterConnection

Categories

(Toolkit :: Storage, defect, critical)

All
Windows
defect
Not set
critical

Tracking

()

RESOLVED FIXED
mozilla58
Tracking Status
firefox-esr52 --- unaffected
firefox55 --- unaffected
firefox56 + wontfix
firefox57 --- wontfix
firefox58 --- fixed

People

(Reporter: kanru, Assigned: asuth)

References

Details

(Keywords: crash, regression)

Crash Data

Attachments

(1 file, 1 obsolete file)

This bug was filed from the Socorro interface and is 
report bp-5e2362b7-08cb-4689-bb4d-5378b0170808.
=============================================================

This is #17 top crash for build 20170807113452 and I also find 167 similar crashes in the past tree months. 

It looks like the first build id of this kind of signature is 20170630150342

Ben, do you have any idea?
Flags: needinfo?(bkelly)
Keywords: regression
OS: Windows 10 → Windows
Hardware: Unspecified → All
Assignee: nobody → bugmail
Status: NEW → ASSIGNED
Flags: needinfo?(bkelly)
Preliminary investigation suggests that we're doing:  memmove(dest=memory we own, src=memory we don't own that crosses a 4k page boundary into unmapped address space, size=0 so we assume it's harmless but the memmove does a speculative read and CRASH)

I need to look at the disassembly to be sure the size is actually 0; memmove is jumbling the registers and I may need the minidump if they've been spilled to stack.  Pursuing that now.
I tested on my profile and that crash is happening when I have the roomy bookamrks addon enabled https://addons.mozilla.org/es/firefox/addon/roomy-bookmarks-toolbar/

Here is my about support https://hastebin.com/dekokihaqe.swift

Hope this info helps.

Let me know if you need any more info.
(In reply to Andrew Sutherland [:asuth] from comment #1)
> Preliminary investigation suggests that we're doing:  memmove(dest=memory we
> own, src=memory we don't own that crosses a 4k page boundary into unmapped
> address space, size=0 so we assume it's harmless but the memmove does a
> speculative read and CRASH)
> 
> I need to look at the disassembly to be sure the size is actually 0; memmove
> is jumbling the registers and I may need the minidump if they've been
> spilled to stack.  Pursuing that now.

I looked at a minidump, the size is indeed zero.

0:000> .frame 0b
0b 00cae404 0e571f3e VCRUNTIME140!memmove+0x4e [f:\dd\vctools\crt\vcruntime\src\string\i386\MEMCPY.ASM @ 194]
0:000> dv
            dst = 0x0000000b "--- memory read error at address 0x0000000b ---"
            src = 0xffffffff "--- memory read error at address 0xffffffff ---"
          count = 0

0:000> .frame 0d
0d 00cae424 0e883f63 xul!nsTArray_base<nsTArrayInfallibleAllocator,nsTArray_CopyWithMemutils>::ShiftData<nsTArrayInfallibleAllocator>+0x9d [z:\build\build\src\obj-firefox\dist\include\nstarray-inl.h @ 272]
0:000> dv
           this = 0x2f5edffc
         aStart = 0xb
        aOldLen = <value unavailable>
        aNewLen = 0
      aElemSize = 4
     aElemAlign = 4
            num = 0xffffffff
       baseAddr = <value unavailable>
(In reply to Kan-Ru Chen [:kanru] (UTC+8) from comment #3)
> I looked at a minidump, the size is indeed zero.

Thanks!

> 0:000> .frame 0b
> 0b 00cae404 0e571f3e VCRUNTIME140!memmove+0x4e
> [f:\dd\vctools\crt\vcruntime\src\string\i386\MEMCPY.ASM @ 194]
> 0:000> dv
>             dst = 0x0000000b "--- memory read error at address 0x0000000b
> ---"
>             src = 0xffffffff "--- memory read error at address 0xffffffff
> ---"
>           count = 0

dst and src certainly look wrong, but that makes sense because I wouldn't expect the debugger to have debug information about hand-written assembly and the x86 calling convention places the first 2 args in registers and the disassembly shows ecx/edx do get overwritten pretty early.  But maybe count is right, because it was the 3rd arg and would have been passed via stack?
 
> 0:000> .frame 0d
> 0d 00cae424 0e883f63
> xul!nsTArray_base<nsTArrayInfallibleAllocator,nsTArray_CopyWithMemutils>::
> ShiftData<nsTArrayInfallibleAllocator>+0x9d
> [z:\build\build\src\obj-firefox\dist\include\nstarray-inl.h @ 272]
> 0:000> dv
>            this = 0x2f5edffc
>          aStart = 0xb
>         aOldLen = <value unavailable>
>         aNewLen = 0
>       aElemSize = 4
>      aElemAlign = 4
>             num = 0xffffffff
>        baseAddr = <value unavailable>

And I assume we trust this more because it was compiled code and should have the correct debug information?

If you'd like to steal this bug, please do feel free.  I'm still in the process of setting up my new windows machine, and I expect to spend tomorrow focusing on a places bug.  (And I'm about to sign off for the night now.)
:kanru, any chance you could take over this bug or find someone else to continue pursuing it?  I thought I would be able to get back to it, but another potential Firefox 55 regression has cropped up and that may delay me more than a little on pursuing this further.
Assignee: bugmail → nobody
Status: ASSIGNED → NEW
Flags: needinfo?(kchen)
[Tracking Requested - why for this release]:
this is the #1 non-shutdown crash on win64 builds in 56.0b
Track 56+ as topcrash.
The volume of crashes in 56 seems low right now. Given we are only 1 week from RC, mark 56 won't fix.
Correlations for Firefox Release
(100.0% in signature vs 02.12% overall) Addon "Roomy Bookmarks Toolbar" = true
"Roomy Bookmarks Toolbar" is a legacy add-on that won't be compatible with Firefox 57 WebExtensions and, indeed, there are no [@ memmove | ...] crashes in 57 or 58. However, there are still a couple instances of the [@ memcpy | ...] crash signature in 57.0b3 and 58.0a1, so there is either another way to trigger the crash or these users are somehow re-enabling the Roomy Bookmarks add-on. I checked some of the 57.0b3 and 58.0a1 crash reports and they do have the Roomy Bookmarks add-on ("ALone-alive@ya.ru") installed.

https://addons.mozilla.org/en-US/firefox/addon/roomy-bookmarks-toolbar/
those 57(devedition)&58 crashes show "extensions.legacy.enabled" set to true in about:config. since that won't work anymore on beta/release i think we can stop caring about those versions...
not sure if there's anything left to do for 56.0 (0.03% of release users have Roomy Bookmarks installed) - i wasn't able to reproduce the crash with just installing the addon.
Looking at the extension source, it uses the same idiom in overlay.js in setColor() and in colorMenu.js in the helper db() function used by multiple other functions in the file:
- mozIStorageService::openDatabase(), save it into a function scope variable.
- mozIStorageConnection::createStatement()
- mozIStatement::executeAsync()
- never call close or finalize on anything

And here we have a great crash stack that I think shows how the above cascades into trouble right here in river city:
https://crash-stats.mozilla.com/report/index/bee675af-c55f-4675-9ebf-437d80170929 that looks like:
* nsTArray_base<nsTArrayInfallibleAllocator, nsTArray_CopyWithMemutils>::ShiftData<nsTArrayInfallibleAllocator>(unsigned __int64, unsigned __int64, unsigned __int64, unsigned __int64, unsigned __int64)
* nsTArray_Impl<RefPtr<mozilla::storage::Connection>, nsTArrayInfallibleAllocator>::RemoveElementsAt(unsigned __int64, unsigned __int64)
* mozilla::storage::Service::unregisterConnection(mozilla::storage::Connection*)
* mozilla::storage::Connection::Release()
* detail::ProxyReleaseEvent<nsISupports>::Run()
* nsThread::ProcessNextEvent(bool, bool*)
* NS_ProcessNextEvent(nsIThread*, bool)
* mozilla::storage::Connection::SpinningSynchronousClose()
* mozilla::storage::Connection::Close()
* mozilla::storage::Connection::~Connection()
* mozilla::storage::Connection::Release()
* RefPtr<mozilla::image::Image>::~RefPtr<mozilla::image::Image>()
* detail::ProxyRelease<nsISupports>(char const*, nsIEventTarget*, already_AddRefed<nsISupports>, bool)
* detail::ProxyReleaseChooser<1>::ProxyReleaseISupports(char const*, nsIEventTarget*, nsISupports*, bool)
* mozilla::storage::Service::unregisterConnection(mozilla::storage::Connection*)
* mozilla::storage::Connection::Release()
* detail::ProxyReleaseEvent<nsISupports>::Run()
* nsThread::ProcessNextEvent(bool, bool*)
* mozilla::ipc::MessagePump::Run(base::MessagePump::Delegate*)

In particular, Service::unregisterConnection invokes NS_ProxyRelease and takes the default of aAlwaysProxy=false... which means that when we're already on the right thread, we Release the object down to 0 right then and there.  Which works fine with well-behaved code that properly closed its connection, because then when invoke Close() nothing happens.  But especially in 56 where we added it in bug 1355561, we will do our SpinningSynchronousClose() invocation.

Looking at the implementation of RemoveElementsAt and its use of ShiftData, there are assertions, but there's no runtime guards.  So the nested event loop means we can try and delete an element beyond the end of the array because we can end up with a stale index (because we invoke RemoveElementAt after we do the proxy release), which means we can try and mess with memory we don't own.  Checkmate/bingo/etc.

I'll prepare the fix now.
Assignee: nobody → bugmail
Status: NEW → ASSIGNED
Flags: needinfo?(kchen)
NS_ProxyRelease will immediately release the provided reference if already on
the right thread unless aAlwaysRelease=true (the default is false).  We need to
set it to be true to avoid Close() and its potential to, out of desperation
when faced with misuse, spin a nested event loop.
Attachment #8913916 - Flags: review?(mak77)
I ran tests locally for storage and places.  One places xpcshell test "test_localtab_matches_override" seemed to be upset about not being able to connect to my X server on :99 (this is on linux under xvfb-run), I'm assuming that's unrelated to my change and more an artifact of changes on trunk related to graphics or something accidentally attempting to talk to the X server.
Comment on attachment 8913916 [details] [diff] [review]
mozStorageService connection unregistering should defer final Release()

Review of attachment 8913916 [details] [diff] [review]:
-----------------------------------------------------------------

LGTM, thank you for figuring this out and patching it.
Attachment #8913916 - Flags: review?(mak77) → review+
https://hg.mozilla.org/integration/mozilla-inbound/rev/0a5a34ef66d11be4c0b64e873e05d84896f3a994
Bug 1388998 - mozStorageService connection unregistering should defer final Release(). r=mak
Backed out for mass test failures during shutdown:

https://hg.mozilla.org/integration/mozilla-inbound/rev/ff5340cbaef07b5e3fa8b53e386467dd7f044145

Push with failures: https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&revision=0a5a34ef66d11be4c0b64e873e05d84896f3a994&filter-resultStatus=testfailed&filter-resultStatus=busted&filter-resultStatus=exception&filter-resultStatus=retry&filter-resultStatus=usercancel&filter-resultStatus=runnable
Failure log example: https://treeherder.mozilla.org/logviewer.html#?job_id=134413324&repo=mozilla-inbound

[task 2017-10-02T15:11:57.399Z] 15:11:57     INFO - TEST-START | devtools/client/netmonitor/test/browser_net_waterfall-click.js
[task 2017-10-02T15:11:59.950Z] 15:11:59     INFO - GECKO(1137) | JavaScript error: resource://devtools/shared/base-loader.js -> resource://devtools/client/netmonitor/src/connector/firefox-connector.js, line 74: TypeError: this.tabTarget is null
[task 2017-10-02T15:11:59.959Z] 15:11:59     INFO - GECKO(1137) | MEMORY STAT | vsize 2633MB | residentFast 429MB | heapAllocated 185MB
[task 2017-10-02T15:11:59.960Z] 15:11:59     INFO - TEST-OK | devtools/client/netmonitor/test/browser_net_waterfall-click.js | took 2567ms
[task 2017-10-02T15:12:00.005Z] 15:12:00     INFO - checking window state
[task 2017-10-02T15:12:02.233Z] 15:12:02     INFO - GECKO(1137) | Completed ShutdownLeaks collections in process 1265
[task 2017-10-02T15:12:02.281Z] 15:12:02     INFO - GECKO(1137) | Completed ShutdownLeaks collections in process 1299
[task 2017-10-02T15:12:02.282Z] 15:12:02     INFO - GECKO(1137) | Completed ShutdownLeaks collections in process 1188
[task 2017-10-02T15:12:02.339Z] 15:12:02     INFO - GECKO(1137) | Completed ShutdownLeaks collections in process 1239
[task 2017-10-02T15:12:02.990Z] 15:12:02     INFO - GECKO(1137) | Completed ShutdownLeaks collections in process 1137
[task 2017-10-02T15:12:02.990Z] 15:12:02     INFO - TEST-START | Shutdown
[task 2017-10-02T15:12:02.990Z] 15:12:02     INFO - Browser Chrome Test Summary
[task 2017-10-02T15:12:02.990Z] 15:12:02     INFO - Passed:  19086
[task 2017-10-02T15:12:02.990Z] 15:12:02     INFO - Failed:  0
[task 2017-10-02T15:12:02.990Z] 15:12:02     INFO - Todo:    0
[task 2017-10-02T15:12:02.991Z] 15:12:02     INFO - Mode:    e10s
[task 2017-10-02T15:12:02.993Z] 15:12:02     INFO - *** End BrowserChrome Test Results ***
[task 2017-10-02T15:13:07.077Z] 15:13:07     INFO - GECKO(1137) | ExceptionHandler::GenerateDump cloned child ExceptionHandler::WaitForContinueSignal waiting for continue signal...
[task 2017-10-02T15:13:07.078Z] 15:13:07     INFO - GECKO(1137) | 1467
[task 2017-10-02T15:13:07.078Z] 15:13:07     INFO - GECKO(1137) | ExceptionHandler::SendContinueSignalToChild sent continue signal to child
[task 2017-10-02T15:13:07.214Z] 15:13:07     INFO - TEST-INFO | Main app process: exit 11
[task 2017-10-02T15:13:07.216Z] 15:13:07     INFO - Buffered messages finished
[task 2017-10-02T15:13:07.218Z] 15:13:07    ERROR - TEST-UNEXPECTED-FAIL | devtools/client/netmonitor/test/browser_net_waterfall-click.js | application terminated with exit code 11
[task 2017-10-02T15:13:07.220Z] 15:13:07     INFO - runtests.py | Application ran for: 0:06:26.667891
[task 2017-10-02T15:13:07.222Z] 15:13:07     INFO - zombiecheck | Reading PID log: /tmp/tmpsKod3fpidlog
[task 2017-10-02T15:13:07.223Z] 15:13:07     INFO - ==> process 1137 launched child process 1161
[task 2017-10-02T15:13:07.224Z] 15:13:07     INFO - ==> process 1137 launched child process 1188
[task 2017-10-02T15:13:07.224Z] 15:13:07     INFO - ==> process 1137 launched child process 1239
[task 2017-10-02T15:13:07.225Z] 15:13:07     INFO - ==> process 1137 launched child process 1265
[task 2017-10-02T15:13:07.225Z] 15:13:07     INFO - ==> process 1137 launched child process 1299
[task 2017-10-02T15:13:07.226Z] 15:13:07     INFO - zombiecheck | Checking for orphan process with PID: 1161
[task 2017-10-02T15:13:07.227Z] 15:13:07     INFO - zombiecheck | Checking for orphan process with PID: 1188
[task 2017-10-02T15:13:07.228Z] 15:13:07     INFO - zombiecheck | Checking for orphan process with PID: 1239
[task 2017-10-02T15:13:07.229Z] 15:13:07     INFO - zombiecheck | Checking for orphan process with PID: 1265
[task 2017-10-02T15:13:07.229Z] 15:13:07     INFO - zombiecheck | Checking for orphan process with PID: 1299
[task 2017-10-02T15:13:07.230Z] 15:13:07     INFO - mozcrash Downloading symbols from: https://queue.taskcluster.net/v1/task/KK0sTG4TTnquDT3NSYbzbw/artifacts/public/build/target.crashreporter-symbols.zip
[task 2017-10-02T15:13:14.176Z] 15:13:14     INFO - mozcrash Copy/paste: /usr/local/bin/linux64-minidump_stackwalk /tmp/tmps4rnes.mozrunner/minidumps/1d46f15f-0357-a7be-28a4-583abc71db34.dmp /tmp/tmpW4ouxB
[task 2017-10-02T15:13:22.421Z] 15:13:22     INFO - mozcrash Saved minidump as /builds/worker/workspace/build/blobber_upload_dir/1d46f15f-0357-a7be-28a4-583abc71db34.dmp
[task 2017-10-02T15:13:22.422Z] 15:13:22     INFO - mozcrash Saved app info as /builds/worker/workspace/build/blobber_upload_dir/1d46f15f-0357-a7be-28a4-583abc71db34.extra
[task 2017-10-02T15:13:22.473Z] 15:13:22     INFO - PROCESS-CRASH | devtools/client/netmonitor/test/browser_net_waterfall-click.js | application crashed [@ RunWatchdog]
[task 2017-10-02T15:13:22.474Z] 15:13:22     INFO - Crash dump filename: /tmp/tmps4rnes.mozrunner/minidumps/1d46f15f-0357-a7be-28a4-583abc71db34.dmp
[task 2017-10-02T15:13:22.475Z] 15:13:22     INFO - Operating system: Linux
[task 2017-10-02T15:13:22.475Z] 15:13:22     INFO -                   0.0.0 Linux 3.13.0-112-generic #159-Ubuntu SMP Fri Mar 3 15:26:07 UTC 2017 x86_64
[task 2017-10-02T15:13:22.476Z] 15:13:22     INFO - CPU: amd64
[task 2017-10-02T15:13:22.477Z] 15:13:22     INFO -      family 6 model 62 stepping 4
[task 2017-10-02T15:13:22.477Z] 15:13:22     INFO -      2 CPUs
[task 2017-10-02T15:13:22.478Z] 15:13:22     INFO - 
[task 2017-10-02T15:13:22.478Z] 15:13:22     INFO - GPU: UNKNOWN
[task 2017-10-02T15:13:22.479Z] 15:13:22     INFO - 
[task 2017-10-02T15:13:22.479Z] 15:13:22     INFO - Crash reason:  SIGSEGV
[task 2017-10-02T15:13:22.480Z] 15:13:22     INFO - Crash address: 0x0
[task 2017-10-02T15:13:22.481Z] 15:13:22     INFO - Process uptime: not available
[task 2017-10-02T15:13:22.481Z] 15:13:22     INFO - 
[task 2017-10-02T15:13:22.482Z] 15:13:22     INFO - Thread 45 (crashed)
[task 2017-10-02T15:13:22.483Z] 15:13:22     INFO -  0  libxul.so!RunWatchdog [nsTerminator.cpp:0a5a34ef66d1 : 160 + 0x0]
[task 2017-10-02T15:13:22.483Z] 15:13:22     INFO -     rax = 0x0000000000636d20   rdx = 0x00007f73bcaa7050
[task 2017-10-02T15:13:22.484Z] 15:13:22     INFO -     rcx = 0x00007f73c8d6730d   rbx = 0x000000000000003f
[task 2017-10-02T15:13:22.485Z] 15:13:22     INFO -     rsi = 0x0000000000000000   rdi = 0x0000000000000000
[task 2017-10-02T15:13:22.485Z] 15:13:22     INFO -     rbp = 0x00007f73645ebec0   rsp = 0x00007f73645ebeb0
[task 2017-10-02T15:13:22.486Z] 15:13:22     INFO -      r8 = 0x0000000000000000    r9 = 0x00007f73c8b000e0
[task 2017-10-02T15:13:22.487Z] 15:13:22     INFO -     r10 = 0x000000000000060c   r11 = 0x0000000000000000
[task 2017-10-02T15:13:22.487Z] 15:13:22     INFO -     r12 = 0x00007f736cc300a0   r13 = 0x0000000000000001
[task 2017-10-02T15:13:22.488Z] 15:13:22     INFO -     r14 = 0x00007f73645ec700   r15 = 0x00007f73645ec670
[task 2017-10-02T15:13:22.489Z] 15:13:22     INFO -     rip = 0x00007f73bb7c58e4
[task 2017-10-02T15:13:22.489Z] 15:13:22     INFO -     Found by: given as instruction pointer in context
[task 2017-10-02T15:13:22.490Z] 15:13:22     INFO -  1  libnspr4.so!_pt_root [ptthread.c:0a5a34ef66d1 : 216 + 0x7]
[task 2017-10-02T15:13:22.490Z] 15:13:22     INFO -     rbx = 0x00007f736e77e340   rbp = 0x00007f73645ebf10
[task 2017-10-02T15:13:22.491Z] 15:13:22     INFO -     rsp = 0x00007f73645ebed0   r12 = 0x00000000000005b7
[task 2017-10-02T15:13:22.492Z] 15:13:22     INFO -     r13 = 0x0000000000000001   r14 = 0x00007f73645ec700
[task 2017-10-02T15:13:22.492Z] 15:13:22     INFO -     r15 = 0x00007f73645ec670   rip = 0x00007f73c85cb4a1
[task 2017-10-02T15:13:22.493Z] 15:13:22     INFO -     Found by: call frame info
[task 2017-10-02T15:13:22.494Z] 15:13:22     INFO -  2  libpthread-2.23.so + 0x76ba
[task 2017-10-02T15:13:22.494Z] 15:13:22     INFO -     rbx = 0x0000000000000000   rbp = 0x0000000000000000
[task 2017-10-02T15:13:22.495Z] 15:13:22     INFO -     rsp = 0x00007f73645ebf20   r12 = 0x0000000000000000
[task 2017-10-02T15:13:22.496Z] 15:13:22     INFO -     r13 = 0x00007fff4f35a61f   r14 = 0x0000000000800000
[task 2017-10-02T15:13:22.496Z] 15:13:22     INFO -     r15 = 0x00007f7381f7dc90   rip = 0x00007f73c9d196ba
[task 2017-10-02T15:13:22.497Z] 15:13:22     INFO -     Found by: call frame info
[task 2017-10-02T15:13:22.498Z] 15:13:22     INFO -  3  libc-2.23.so + 0x1073dd
[task 2017-10-02T15:13:22.498Z] 15:13:22     INFO -     rsp = 0x00007f73645ebfc0   rip = 0x00007f73c8da23dd
[task 2017-10-02T15:13:22.499Z] 15:13:22     INFO -     Found by: stack scanning
[task 2017-10-02T15:13:22.500Z] 15:13:22     INFO - 
[task 2017-10-02T15:13:22.500Z] 15:13:22     INFO - Thread 0
[task 2017-10-02T15:13:22.501Z] 15:13:22     INFO -  0  libpthread-2.23.so + 0xd360
[task 2017-10-02T15:13:22.501Z] 15:13:22     INFO -     rax = 0xfffffffffffffe00   rdx = 0x0000000000000183
[task 2017-10-02T15:13:22.502Z] 15:13:22     INFO -     rcx = 0xffffffffffffffff   rbx = 0x00007f73c8a49760
[task 2017-10-02T15:13:22.503Z] 15:13:22     INFO -     rsi = 0x0000000000000080   rdi = 0x00007f73c8a49764
[task 2017-10-02T15:13:22.503Z] 15:13:22     INFO -     rbp = 0x00007fff4f35ca50   rsp = 0x00007fff4f35ca10
[task 2017-10-02T15:13:22.504Z] 15:13:22     INFO -      r8 = 0x00007f73c8a49700    r9 = 0x00000000000000c1
[task 2017-10-02T15:13:22.505Z] 15:13:22     INFO -     r10 = 0x0000000000000000   r11 = 0x0000000000000246
[task 2017-10-02T15:13:22.505Z] 15:13:22     INFO -     r12 = 0x0000000000000001   r13 = 0x00007f73c8a49760
[task 2017-10-02T15:13:22.506Z] 15:13:22     INFO -     r14 = 0x00007fff4f35ca78   r15 = 0x00007fff4f35caec
[task 2017-10-02T15:13:22.506Z] 15:13:22     INFO -     rip = 0x00007f73c9d1f360
[task 2017-10-02T15:13:22.507Z] 15:13:22     INFO -     Found by: given as instruction pointer in context
[task 2017-10-02T15:13:22.508Z] 15:13:22     INFO -  1  libxul.so!mozilla::ThreadEventQueue<mozilla::PrioritizedEventQueue<mozilla::EventQueue> >::GetEvent [CondVar.h:0a5a34ef66d1 : 68 + 0xc]
[task 2017-10-02T15:13:22.508Z] 15:13:22     INFO -     rbp = 0x00007fff4f35cab0   rsp = 0x00007fff4f35ca60
[task 2017-10-02T15:13:22.509Z] 15:13:22     INFO -     rip = 0x00007f73b86407c2
[task 2017-10-02T15:13:22.510Z] 15:13:22     INFO -     Found by: previous frame's frame pointer
[task 2017-10-02T15:13:22.511Z] 15:13:22     INFO -  2  libxul.so!nsThread::ProcessNextEvent [nsThread.cpp:0a5a34ef66d1 : 967 + 0x17]
[task 2017-10-02T15:13:22.511Z] 15:13:22     INFO -     rbx = 0x00007f73c8ad1a00   rbp = 0x00007fff4f35d020
[task 2017-10-02T15:13:22.512Z] 15:13:22     INFO -     rsp = 0x00007fff4f35cac0   r12 = 0x00007f73c8ad1a00
[task 2017-10-02T15:13:22.513Z] 15:13:22     INFO -     r13 = 0x0000000000000001   r14 = 0x00007f73af4cbc88
[task 2017-10-02T15:13:22.513Z] 15:13:22     INFO -     r15 = 0x00007fff4f35d04f   rip = 0x00007f73b864bc22
[task 2017-10-02T15:13:22.514Z] 15:13:22     INFO -     Found by: call frame info
[task 2017-10-02T15:13:22.515Z] 15:13:22     INFO -  3  libxul.so!NS_ProcessNextEvent [nsThreadUtils.cpp:0a5a34ef66d1 : 524 + 0xe]
[task 2017-10-02T15:13:22.515Z] 15:13:22     INFO -     rbx = 0x00007f73af41de80   rbp = 0x00007fff4f35d050
[task 2017-10-02T15:13:22.516Z] 15:13:22     INFO -     rsp = 0x00007fff4f35d030   r12 = 0x00007f73c8ad1a00
[task 2017-10-02T15:13:22.517Z] 15:13:22     INFO -     r13 = 0x00007f736cd4bca0   r14 = 0x00007f73b8640110
[task 2017-10-02T15:13:22.517Z] 15:13:22     INFO -     r15 = 0x00007f73bcaaa2a0   rip = 0x00007f73b864d47b
[task 2017-10-02T15:13:22.518Z] 15:13:22     INFO -     Found by: call frame info
[task 2017-10-02T15:13:22.518Z] 15:13:22     INFO -  4  libxul.so!mozilla::dom::StorageObserver::Observe [nsThreadUtils.h:0a5a34ef66d1 : 323 + 0xd]
[task 2017-10-02T15:13:22.519Z] 15:13:22     INFO -     rbx = 0x00007f73af41de80   rbp = 0x00007fff4f35d2f0
[task 2017-10-02T15:13:22.520Z] 15:13:22     INFO -     rsp = 0x00007fff4f35d060   r12 = 0x00007f73c8ad1a00
[task 2017-10-02T15:13:22.520Z] 15:13:22     INFO -     r13 = 0x00007f736cd4bca0   r14 = 0x00007f73b8640110
[task 2017-10-02T15:13:22.521Z] 15:13:22     INFO -     r15 = 0x00007f73bcaaa2a0   rip = 0x00007f73ba1c441d
[task 2017-10-02T15:13:22.522Z] 15:13:22     INFO -     Found by: call frame info
[task 2017-10-02T15:13:22.522Z] 15:13:22     INFO -  5  libxul.so!nsObserverList::NotifyObservers [nsObserverList.cpp:0a5a34ef66d1 : 112 + 0xf]
[task 2017-10-02T15:13:22.523Z] 15:13:22     INFO -     rbx = 0x0000000000000023   rbp = 0x00007fff4f35d340
[task 2017-10-02T15:13:22.524Z] 15:13:22     INFO -     rsp = 0x00007fff4f35d300   r12 = 0x00007f73bcaaa2a0
[task 2017-10-02T15:13:22.524Z] 15:13:22     INFO -     r13 = 0x00007f73bc5d8c3b   r14 = 0x0000000000000000
[task 2017-10-02T15:13:22.525Z] 15:13:22     INFO -     r15 = 0x00007fff4f35d308   rip = 0x00007f73b86008ce
[task 2017-10-02T15:13:22.526Z] 15:13:22     INFO -     Found by: call frame info
[task 2017-10-02T15:13:22.526Z] 15:13:22     INFO -  6  libxul.so!nsObserverService::NotifyObservers [nsObserverService.cpp:0a5a34ef66d1 : 296 + 0x11]
[task 2017-10-02T15:13:22.527Z] 15:13:22     INFO -     rbx = 0x00007f73b5fc7920   rbp = 0x00007fff4f35d3a0
[task 2017-10-02T15:13:22.528Z] 15:13:22     INFO -     rsp = 0x00007fff4f35d350   r12 = 0x00007f73bc5d8c3b
[task 2017-10-02T15:13:22.528Z] 15:13:22     INFO -     r13 = 0x0000000000000000   r14 = 0x00007f73bcaaa2a0
[task 2017-10-02T15:13:22.529Z] 15:13:22     INFO -     r15 = 0x0000164a3c09a5ea   rip = 0x00007f73b8600a61
[task 2017-10-02T15:13:22.530Z] 15:13:22     INFO -     Found by: call frame info
[task 2017-10-02T15:13:22.532Z] 15:13:22     INFO -  7  libxul.so!nsXREDirProvider::DoShutdown [nsXREDirProvider.cpp:0a5a34ef66d1 : 1113 + 0x19]
[task 2017-10-02T15:13:22.533Z] 15:13:22     INFO -     rbx = 0x00007f73b5fc7900   rbp = 0x00007fff4f35d3d0
[task 2017-10-02T15:13:22.534Z] 15:13:22     INFO -     rsp = 0x00007fff4f35d3b0   r12 = 0x00007fff4f35d500
[task 2017-10-02T15:13:22.535Z] 15:13:22     INFO -     r13 = 0x0000000000000000   r14 = 0x00007f73c8ab7780
[task 2017-10-02T15:13:22.536Z] 15:13:22     INFO -     r15 = 0x00007f73c8a7ac00   rip = 0x00007f73bb7e42d9
[task 2017-10-02T15:13:22.537Z] 15:13:22     INFO -     Found by: call frame info
[task 2017-10-02T15:13:22.538Z] 15:13:22     INFO -  8  libxul.so!ScopedXPCOMStartup::~ScopedXPCOMStartup [nsAppRunner.cpp:0a5a34ef66d1 : 1522 + 0xc]
[task 2017-10-02T15:13:22.540Z] 15:13:22     INFO -     rbx = 0x00007f73c8ab7780   rbp = 0x00007fff4f35d400
[task 2017-10-02T15:13:22.541Z] 15:13:22     INFO -     rsp = 0x00007fff4f35d3e0   r12 = 0x00007fff4f35d480
[task 2017-10-02T15:13:22.542Z] 15:13:22     INFO -     r13 = 0x0000000000000000   r14 = 0x00007f73c8ab7780
[task 2017-10-02T15:13:22.544Z] 15:13:22     INFO -     r15 = 0x00007f73c8a7ac00   rip = 0x00007f73bb7d8049
[task 2017-10-02T15:13:22.545Z] 15:13:22     INFO -     Found by: call frame info
[task 2017-10-02T15:13:22.546Z] 15:13:22     INFO -  9  libxul.so!XREMain::XRE_main [UniquePtr.h:0a5a34ef66d1 : 528 + 0x8]
[task 2017-10-02T15:13:22.547Z] 15:13:22     INFO -     rbx = 0x0000000000000000   rbp = 0x00007fff4f35d470
[task 2017-10-02T15:13:22.548Z] 15:13:22     INFO -     rsp = 0x00007fff4f35d410   r12 = 0x00007fff4f35d480
[task 2017-10-02T15:13:22.548Z] 15:13:22     INFO -     r13 = 0x0000000000000000   r14 = 0x00007f73c8ab7780
[task 2017-10-02T15:13:22.549Z] 15:13:22     INFO -     r15 = 0x00007f73c8a7ac00   rip = 0x00007f73bb7de30e
[task 2017-10-02T15:13:22.550Z] 15:13:22     INFO -     Found by: call frame info
[task 2017-10-02T15:13:22.551Z] 15:13:22     INFO - 10  libxul.so!XRE_main [nsAppRunner.cpp:0a5a34ef66d1 : 4960 + 0x5]
[task 2017-10-02T15:13:22.552Z] 15:13:22     INFO -     rbx = 0x0000000000000005   rbp = 0x00007fff4f35d640
[task 2017-10-02T15:13:22.553Z] 15:13:22     INFO -     rsp = 0x00007fff4f35d480   r12 = 0x00007fff4f35d480
[task 2017-10-02T15:13:22.554Z] 15:13:22     INFO -     r13 = 0x00007fff4f35e7a8   r14 = 0x00007fff4f35d660
[task 2017-10-02T15:13:22.555Z] 15:13:22     INFO -     r15 = 0x00007fff4f35d660   rip = 0x00007f73bb7de6f8
[task 2017-10-02T15:13:22.555Z] 15:13:22     INFO -     Found by: call frame info
[task 2017-10-02T15:13:22.556Z] 15:13:22     INFO - 11  firefox!do_main [nsBrowserApp.cpp:0a5a34ef66d1 : 231 + 0xf]
[task 2017-10-02T15:13:22.557Z] 15:13:22     INFO -     rbx = 0x00007fff4f35e7a8   rbp = 0x00007fff4f35e690
[task 2017-10-02T15:13:22.558Z] 15:13:22     INFO -     rsp = 0x00007fff4f35d650   r12 = 0x0000000000000005
[task 2017-10-02T15:13:22.559Z] 15:13:22     INFO -     r13 = 0x00007fff4f35e7d8   r14 = 0x0000000000000000
[task 2017-10-02T15:13:22.560Z] 15:13:22     INFO -     r15 = 0x00007fff4f35d660   rip = 0x00000000004074c9
[task 2017-10-02T15:13:22.561Z] 15:13:22     INFO -     Found by: call frame info
[task 2017-10-02T15:13:22.562Z] 15:13:22     INFO - 12  firefox!main [nsBrowserApp.cpp:0a5a34ef66d1 : 304 + 0xe]
[task 2017-10-02T15:13:22.563Z] 15:13:22     INFO -     rbx = 0x00007fff4f35e7a8   rbp = 0x00007fff4f35e6c0
[task 2017-10-02T15:13:22.564Z] 15:13:22     INFO -     rsp = 0x00007fff4f35e6a0   r12 = 0x0000000000000005
[task 2017-10-02T15:13:22.566Z] 15:13:22     INFO -     r13 = 0x00007fff4f35e7d8   r14 = 0x000015ff21bdd60b
[task 2017-10-02T15:13:22.567Z] 15:13:22     INFO -     r15 = 0x0000000000000000   rip = 0x0000000000406bd0
[task 2017-10-02T15:13:22.568Z] 15:13:22     INFO -     Found by: call frame info
[task 2017-10-02T15:13:22.569Z] 15:13:22     INFO - 13  libc-2.23.so + 0x20830
[task 2017-10-02T15:13:22.570Z] 15:13:22     INFO -     rbx = 0x0000000000000000   rbp = 0x000000000042dc70
[task 2017-10-02T15:13:22.570Z] 15:13:22     INFO -     rsp = 0x00007fff4f35e6d0   r12 = 0x0000000000406e8c
[task 2017-10-02T15:13:22.572Z] 15:13:22     INFO -     r13 = 0x00007fff4f35e7a0   r14 = 0x0000000000000000
[task 2017-10-02T15:13:22.572Z] 15:13:22     INFO -     r15 = 0x0000000000000000   rip = 0x00007f73c8cbb830
[task 2017-10-02T15:13:22.574Z] 15:13:22     INFO -     Found by: call frame info
[task 2017-10-02T15:13:22.575Z] 15:13:22     INFO - 14  firefox + 0x6b60
[task 2017-10-02T15:13:22.576Z] 15:13:22     INFO -     rsp = 0x00007fff4f35e6f0   rip = 0x0000000000406b60
[task 2017-10-02T15:13:22.577Z] 15:13:22     INFO -     Found by: stack scanning
[task 2017-10-02T15:13:22.578Z] 15:13:22     INFO - 15  firefox + 0x6e8c
[task 2017-10-02T15:13:22.580Z] 15:13:22     INFO -     rsp = 0x00007fff4f35e708   rip = 0x0000000000406e8c
[task 2017-10-02T15:13:22.581Z] 15:13:22     INFO -     Found by: stack scanning
[task 2017-10-02T15:13:22.582Z] 15:13:22     INFO - 16  firefox + 0x2dc60
[task 2017-10-02T15:13:22.583Z] 15:13:22     INFO -     rsp = 0x00007fff4f35e750   rip = 0x000000000042dc60
[task 2017-10-02T15:13:22.586Z] 15:13:22     INFO -     Found by: stack scanning
[task 2017-10-02T15:13:22.588Z] 15:13:22     INFO - 17  ld-2.23.so + 0x10ab0
[task 2017-10-02T15:13:22.589Z] 15:13:22     INFO -     rsp = 0x00007fff4f35e758   rip = 0x00007f73c9f3fab0
[task 2017-10-02T15:13:22.590Z] 15:13:22     INFO -     Found by: stack scanning
[task 2017-10-02T15:13:22.591Z] 15:13:22     INFO - 18  ld-2.23.so + 0x107cb
[task 2017-10-02T15:13:22.592Z] 15:13:22     INFO -     rsp = 0x00007fff4f35e760   rip = 0x00007f73c9f3f7cb
[task 2017-10-02T15:13:22.593Z] 15:13:22     INFO -     Found by: stack scanning
[task 2017-10-02T15:13:22.594Z] 15:13:22     INFO - 19  firefox + 0x6e8c
[task 2017-10-02T15:13:22.596Z] 15:13:22     INFO -     rsp = 0x00007fff4f35e778   rip = 0x0000000000406e8c
[task 2017-10-02T15:13:22.597Z] 15:13:22     INFO -     Found by: stack scanning
[task 2017-10-02T15:13:22.598Z] 15:13:22     INFO - 20  firefox!_start + 0x29
[task 2017-10-02T15:13:22.599Z] 15:13:22     INFO -     rsp = 0x00007fff4f35e790   rip = 0x0000000000406eb5
[task 2017-10-02T15:13:22.600Z] 15:13:22     INFO -     Found by: stack scanning
Flags: needinfo?(bugmail)
This appears to be complicated mutex re-entrancy fallout from LocalStorage's ThreadObserver infrastructure added in bug 1010717.  Also, I shall once more use the try-server with abandon.  I felt like I should lean on mozilla-inbound a little more given the recent threads about the try server being overloaded, but... whoops.
The call-stacks illustrate things pretty well, but I need to explain it to myself at least.  Here's what's going on:

- LocalStorage's StorageDBThread has its own event loop, as we may remember from bug 1010717 where :mak upgraded it from "sketchy hand-rolled PRThread" to "sketchy hand-rolled PRThread that uses an nsIThreadObserver to better pretend it's a normal nsIThread" (no judgement; hard/ugly problem, reasonable and impressive fix).  Happily, :janv is overhauling LocalStorage, so this ugliness will go away.
- The thread is coordinated by the ThreadObserver's non-reentrant Monitor.  There is also a ReentrantMonitor 
- Because of the sketchy threading situation, dispatching a runnable to the StorageDBThread invokes ThreadObserver::OnDispatchedEvent, which acquires the monitor so that it can wake-up the thread and tell it to spin the normal nsIThread event-loop.
- StorageDBThread::ShutdownDatabase() is invoked with the monitor held.
- ShutdownDatabase() drops the sole strong refcount to the Connection() which causes its refcount to go to 1 and unregister itself.  Which, with the change in my patch, introduces a dispatch to the storage thread, which invokes OnDispatchEvent and attempts to reentrantly acquire the mutex, which deadlocks.
  - On opt builds, this results in nsTerminator.cpp's RunWatchdog triggering a timeout crash.
  - On debug builds, the deadlock detector asserts.
- If we didn't deadlock, it looks like the release runnable will never run, and it will only drop its refcount when nsThreadManager::Shutdown is invoked.   Specifically, looking at nsThread::ThreadFunc, it calls `nsThreadManager::get().UnregisterCurrentThread(*self);` on the way out, which causes the thread manager to drop its RefPtr to the nsThread.  When that doesn't happen, we expect the nsThread and its event queue to live until nsThreadManager::Shutdown's `threads` array goes out of scope.  It won't wait on the thread and potentially crash, however, because ShutdownRequired() will return false because nsThread::InitCurrentThread() doesn't set it.
  - I'm treating the underlying failure to register as not a big deal given that StorageDBThread sticks around until normal shutdown anyways, and again, :janv is fixing LocalStorage.


I've got a new patch that changes Service::unregisterConnection to drop the final reference:
- using aAlwaysDispatch=false as exists in tree, but this time explicitly with a comment.  In retrospect, I should have known the deferred release was trouble, but I was trying to stick to the eternal wisdom of "if you're going to be bad and spin a nested event loop, spin it with as little on the stack as possible".  However, since we no longer have out-of-tree consumers of mozStorage, we really should never spin a nested event loop now, so it's better to err on the side of not complicating shutdown or violating caller expectations about refcounts.
- outside the loop, to avoid reentrancy issues with mutation
- outside the mutex being held, to avoid reentrancy issues with the mutex
Flags: needinfo?(bugmail)
Attachment #8913916 - Attachment is obsolete: true
Comment on attachment 8914608 [details] [diff] [review]
Drop final Connection reference after finishing guarded connection list mutation

Review of attachment 8914608 [details] [diff] [review]:
-----------------------------------------------------------------

::: storage/mozStorageService.cpp
@@ +318,2 @@
>  
> +  MOZ_ASSERT(forgettingRef);

Could you please retain the previous unreachable message as the MOZ_ASSERT message (or something similar)
Attachment #8914608 - Flags: review?(mak77) → review+
(In reply to [:philipp] from comment #11)
> those 57(devedition)&58 crashes show "extensions.legacy.enabled" set to true
> in about:config. since that won't work anymore on beta/release i think we
> can stop caring about those versions...

I disagree. We should avoid startup crashes regardless of whether the pref is valid or not. Will leave it to RelMan to decide whether this should be considered a dot release ride-along candidate or not.
What is the status here?
Flags: needinfo?(bugmail)
https://hg.mozilla.org/integration/mozilla-inbound/rev/2f78917dbcfdfab5ef0470557c8ca98003cb5f09
Bug 1388998 - Drop final Connection reference after finishing guarded connection list mutation. r=mak
(In reply to Marco Castelluccio [:marco] from comment #24)
> What is the status here?

Thanks for the ping!  I've landed the patch now with :mak's requested change.  I had pushed re-landing this down in priority a bit for risk reasons related to other shutdown related patches that were landing around when the r+ happened and since the underlying issue was mooted[1].

1: Because the root cause of the crash reports was a badly behaved legacy extension, something possible in 56, but not possible in 57 or 58.  And around that time it became clear that there was no chance of this getting uplifted to 56, which is the only place there would be a win versus added risk.
Flags: needinfo?(bugmail)
https://hg.mozilla.org/mozilla-central/rev/2f78917dbcfd
Status: ASSIGNED → RESOLVED
Closed: 2 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla58
There's over 1000 reports from 56 in the last week across the 3 signatures in this bug. Did we want to consider this for 56.0.2 ride-along status?
Flags: needinfo?(lhenry)
I think this can wait for 57.
Flags: needinfo?(lhenry)
If we want the crashes to go away on 56, maybe we can contact the addon developer and/or blacklist the current version or something?  Because the specific extension's behavior is what is triggering this.
(In reply to Andrew Sutherland [:asuth] from comment #30)
> If we want the crashes to go away on 56, maybe we can contact the addon
> developer and/or blacklist the current version or something?  Because the
> specific extension's behavior is what is triggering this.

Is that the only addon that causes this crash? Given the crash volume, there might be more than one.
Philipp or Andrew, could you look at the addons that are present in the crash reports with these signatures? (otherwise, I'll take a look on Friday)
Flags: needinfo?(madperson)
Flags: needinfo?(bugmail)
ALone-live@ya.ru:1.4.14 (Roomy Bookmarks Toolbar) is the most common factor and present in 90% of those crashers.
another one i could spot is vocabhighlighter@name.domain:0.73.1-signed.1-signed (Vocabulary Highlighter) - apparently responsible for another remaining 7% of this signature.
Flags: needinfo?(madperson)
...and identfavicon@david.hanak.hu:0.3.4.7.1-signed.1-signed (IdentFavIcon) may be the last 3%
(In reply to [:philipp] from comment #32)
> ALone-live@ya.ru:1.4.14 (Roomy Bookmarks Toolbar) is the most common factor
> and present in 90% of those crashers.

(As discussed previously in comment 12, this extension opens the database multiple times, uses executeAsync, and never cleans up the database itself.)

> vocabhighlighter@name.domain:0.73.1-signed.1-signed (Vocabulary Highlighter)
> - apparently responsible for another remaining 7% of this signature.

This extension also likes to open the database multiple times, never saving it off, uses executeAsync, and never cleans up the database via close or asyncClose.

(In reply to [:philipp] from comment #33)
> ...and identfavicon@david.hanak.hu:0.3.4.7.1-signed.1-signed (IdentFavIcon)
> may be the last 3%

This seems to not use mozStorage directly, but does use nsINavHistoryService and nsIFaviconService in its prefs UI.  The prefs UI has a "clearIcons" mechanism that seems to use unconstrained QUERY_TYPE_HISTORY and QUERY_TYPE_BOOKMARKS that will (synchronously) return the entirety of history.  Given that it's all sync, this would not directly trigger the problem as understood on this bug.  However, by dominating the main thread for an extended period of time, it's conceivable the resulting massive event-loop backup could contribute to other code triggering the problem.  (Tidbit: The clearing process calls nsIFaviconService.getFaviconForPage() and nsIFaviconService.setAndLoadFaviconForPage(), both of which haven't existed since Firefox 22.  However, they are called in an error-eating try block, so I guess no one noticed that all that history churning is for naught.)
Flags: needinfo?(bugmail)
Thanks for the quick analysis. Should we block the addons responsible for 90% and 7% of the crashes?
That's a good question.  It seems perhaps rude to the authors and users to just blacklist them, and looking at Roomy Bookmarks' ADU's, they're at ~44k, which is higher than the number of crashes my graph webextension is showing here, but I also don't understand if there's decimation involved in sampling for these crashes.

:Fallen, I know we NI'd you on bug 1354324 for a similar "add-on misbehavior is causing problems for users", do you have guidance here?  Ideally I suppose we'd reach out to the add-on authors and see if they're willing to update their extensions to cache their databases once created and add a profile-before-change shutdown observer that will trigger asyncClose of the database, or failing that, if they're willing for us to push a similar update of the extensions (if that's something we allow ourselves to do).  (Alternately, calling asyncClose at all the call-sites that get the database once they're done with it would work as well, but is a lot more code and would be much jankier for users).  I can help prepare the changes.

The extensions we're talking about are:
- https://addons.mozilla.org/en-US/firefox/addon/roomy-bookmarks-toolbar/
- https://addons.mozilla.org/en-Us/firefox/addon/vocabulary-highlighter/
Flags: needinfo?(philipp)
btw, these legacy add-ons will stop working in just three weeks when 57.0 is released. So there is a trade-off: do we block the add-ons three weeks early to fix a crash (56.0 top browser crash ~#30) or give those users three more weeks of using their add-ons?
We're explicitly expecting a large number of people to downgrade back to 56, however, hence bug 1404344.
I've reached out to the authors and made them aware of this bug. I will get back to you if they reply via email.
Flags: needinfo?(philipp)
Should we wontfix this for 57? And FWIW, I'd vote for blocklisting extensions we know are causing this.
Flags: needinfo?(bugmail)
The author of Roomy Bookmarks Toolbar has replied and uploaded a fix in a beta version. They are waiting for feedback. Andrew, can you check if version 1.4.15beta7 fixes the issue and let me know? I'll get back to the author so he can push a new version. We do have the possibility to blocklist specific versions, given the author is responsive I would allow them to publish a new version first though.
(In reply to Philipp Kewisch [:Fallen] from comment #41)
> The author of Roomy Bookmarks Toolbar has replied and uploaded a fix in a
> beta version. They are waiting for feedback. Andrew, can you check if
> version 1.4.15beta7 fixes the issue and let me know? I'll get back to the
> author so he can push a new version. We do have the possibility to blocklist
> specific versions, given the author is responsive I would allow them to
> publish a new version first though.

According to meld which did a recursive directory diff, a lot of things have changed between the most recent public version and this one, so I just looked at the database usages.  The changes should address the database connection leakage that result in crashes (and potentially resource exhaustion).  However, one more change is needed:

- In the colorMenu.js db() "getData" handler, the asyncClose() call is inside the handleResult() callback instead of the handleCompletion() callback like it is in other places.  handleResult() may be invoked 0 times if there are no result rows, or multiple times if there are enough rows to result in batching.  It's the 0th case we're really worried about, because asyncClose() can handle being called multiple times, although it will throw on subsequent invocations.

  The asyncClose() can most simply be moved outside the callbacks to immediately follow the "statement.executeAsync" invocation; this will work because the close gets queued up behind the completion of the executeAsync invocation.  It can also be moved inside the handleCompletion callback and be correct.

  Aside: Note that in the "saveData" case, the asyncClose does still need to happen in the handleCompletion callbacks as it currently does because a new statement is created and executeAsync()ed in there.  These calls will throw once asyncClose() is invoked.
Flags: needinfo?(bugmail)
I've approved version 1.4.17 of Roomy Bookmarks Toolbar with the changes as suggested.
Thank you very much for driving that, :Fallen!

So I think the idea is that if we follow https://addons.mozilla.org/en-US/firefox/addon/roomy-bookmarks-toolbar/statistics/usage/versions/?last=30 we can see 1.4.17 replace 1.4.14 and we should see a corresponding drop-off in crashes (for 90% of the crashes attributed to Roomy Bookmarks).
It sounds like the general consensus is that we're not backporting this patch to Beta. Setting the status accordingly, but feel free to set it back and nominate it for approval if you feel strongly otherwise.
Depends on: 1413501
You need to log in before you can comment on or make changes to this bug.