1372823 - Extend BaseThreadInitThunk gatekeeping to support Windows 64-bit

Status: RESOLVED FIXED

(Core :: General, defect, P3)

Description

[Carl Corcoran [:ccorcoran]]

Bug 1322554 adds a hook to BaseThreadInitThunk which checks the thread start address. This is currently only done on 32-bit Windows, but should be extended to 64-bit.

Comment 1

[Selena Deckelmann :selenamarie :selena]

Consulted aklotz and put at P3 due to lack of resources.

Comment 2

[(Away)]

We may need to do this anyway for bug 1397301 comment 12.

Comment 4

[Bob Owen (:bobowen)]

I'm hoping this is as straight forward as removing the |#ifdef _M_IX86|s.
Seems to work fine locally, including the test.

Here's a full 64-bit try push (we get a lot of oranges anyway on these at the moment):
https://treeherder.mozilla.org/#/jobs?repo=try&revision=3485c786c06cf17111051ab6255be5d336fd33ae

Comment 5

[(Away)]

(In reply to Bob Owen (:bobowen) from comment #4)
> I'm hoping this is as straight forward as removing the |#ifdef _M_IX86|s.
> Seems to work fine locally, including the test.

If TestDllInterceptor.exe passes on Win7SP1 (the OS where essentially all of bug 1397301's crashes are) then that should be enough to land this.

In general we should run TestDllInterceptor on all supported Windows, but in this case any failures can be dealt with in a followup IMO.

Comment 6

[Marco Castelluccio [:marco]]

IIRC philipp, you were able to reproduce one of the crashes with the BaseThreadInitThunk signature on a 64-bit build. Could you verify that this is preventing the crash?

Comment 7

[[:philipp]]

yes, running robosizer on win10 causes reproducible crashes during startup on win64 nightly (like bp-268a24d4-5c16-4ccb-aa72-46d930170920) - bug 1369188.
the try build from comment #4 launches without an issue.

Comment 8

[Bob Owen (:bobowen)]

Attachment: Extend BaseThreadInitThunk thread start address verification to 64-bit

Try push looking good and confirmation that it prevents crashes, thanks. :-)

Comment 9

[(Away)]

Comment on attachment 8910386 [details] [diff] [review]
Extend BaseThreadInitThunk thread start address verification to 64-bit

No problem for 57.

I'd prefer not to uplift this to 56 so late, but if we absolutely must, then we really need to watch for regressions on at least one beta or a very limited release population, before opening the floodgates.

Comment 10

[Bob Owen (:bobowen)]

Thanks dmajor.

(In reply to David Major [:dmajor] from comment #5)
...
> In general we should run TestDllInterceptor on all supported Windows, but in
> this case any failures can be dealt with in a followup IMO.

I've run the 64-bit TestDllInterceptor on Win7(SP1), Win8, Win8.1 and Win10 and the detour for BaseThreadInitThunk was fine.

Comment 11

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/4dab43248f15
Extend BaseThreadInitThunk thread start address verification to 64-bit. r=dmajor

Comment 12

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

https://hg.mozilla.org/mozilla-central/rev/4dab43248f15

Comment 13

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

Backed out for crashing GTest on Windows 10 x64 debug:

https://hg.mozilla.org/mozilla-central/rev/b14c75b83d0226333b1240466ea9f07cfb206ff3

Push with failures: https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&revision=4dab43248f156f9c864b6dbd6d8b6c134e302ca1
Failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=132493171&repo=mozilla-inbound

15:20:26     INFO -  TEST-START | VsyncTester.CompositorGetVsyncNotifications
15:20:26     INFO -  Unable to read VR Path Registry from C:\Users\GenericWorker\AppData\Local\openvr\openvrpaths.vrpath
15:20:26     INFO -  [1088, Main Thread] ###!!! ASSERTION: IsMainProcess() called before indexedDB has been initialized!: 'gDBManager', file z:/build/build/src/dom/indexedDB/IndexedDatabaseManager.cpp, line 688
15:20:39     INFO -  #01: mozilla::dom::IndexedDatabaseManager::NoteLiveQuotaManager(mozilla::dom::quota::QuotaManager *) [dom/indexedDB/IndexedDatabaseManager.cpp:832]
15:20:39     INFO -  #02: mozilla::dom::IndexedDatabaseManager::Init() [dom/indexedDB/IndexedDatabaseManager.cpp:398]
15:20:39     INFO -  #03: mozilla::dom::IndexedDatabaseManager::GetOrCreate() [dom/indexedDB/IndexedDatabaseManager.cpp:355]
15:20:39     INFO -  #04: mozilla::dom::indexedDB::`anonymous namespace'::Maintenance::CreateIndexedDatabaseManager [dom/indexedDB/ActorsParent.cpp:18354]
15:20:39     INFO -  #05: mozilla::dom::indexedDB::`anonymous namespace'::Maintenance::Run [dom/indexedDB/ActorsParent.cpp:18828]
15:20:39     INFO -  #06: nsThread::ProcessNextEvent(bool,bool *) [xpcom/threads/nsThread.cpp:1040]
15:20:39     INFO -  #07: FlushMainThreadLoop [gfx/tests/gtest/TestVsync.cpp:107]
15:20:39     INFO -  #08: VsyncTester_CompositorGetVsyncNotifications_Test::TestBody() [gfx/tests/gtest/TestVsync.cpp:137]
15:20:39     INFO -  #09: testing::internal::HandleSehExceptionsInMethodIfSupported<testing::Test,void>(testing::Test *,void ( testing::Test::*)(void),char const *) [testing/gtest/gtest/src/gtest.cc:2387]
15:20:39     INFO -  #10: testing::internal::HandleExceptionsInMethodIfSupported<testing::Test,void>(testing::Test *,void ( testing::Test::*)(void),char const *) [testing/gtest/gtest/src/gtest.cc:2455]
15:20:39     INFO -  #11: testing::Test::Run() [testing/gtest/gtest/src/gtest.cc:2481]
15:20:39     INFO -  #12: testing::TestInfo::Run() [testing/gtest/gtest/src/gtest.cc:2660]
15:20:39     INFO -  #13: testing::TestCase::Run() [testing/gtest/gtest/src/gtest.cc:2773]
15:20:39     INFO -  #14: testing::internal::UnitTestImpl::RunAllTests() [testing/gtest/gtest/src/gtest.cc:4647]
15:20:39     INFO -  #15: testing::internal::HandleSehExceptionsInMethodIfSupported<testing::internal::UnitTestImpl,bool>(testing::internal::UnitTestImpl *,bool ( testing::internal::UnitTestImpl::*)(void),char const *) [testing/gtest/gtest/src/gtest.cc:2387]
15:20:39     INFO -  #16: testing::internal::HandleExceptionsInMethodIfSupported<testing::internal::UnitTestImpl,bool>(testing::internal::UnitTestImpl *,bool ( testing::internal::UnitTestImpl::*)(void),char const *) [testing/gtest/gtest/src/gtest.cc:2455]
15:20:39     INFO -  #17: testing::UnitTest::Run() [testing/gtest/gtest/src/gtest.cc:4257]
15:20:39     INFO -  #18: mozilla::RunGTestFunc(int *,char * *) [testing/gtest/mozilla/GTestRunner.cpp:117]
15:20:39     INFO -  #19: XREMain::XRE_mainStartup(bool *) [toolkit/xre/nsAppRunner.cpp:3928]
15:20:39     INFO -  #20: XREMain::XRE_main(int,char * * const,mozilla::BootstrapConfig const &) [toolkit/xre/nsAppRunner.cpp:4850]
15:20:39     INFO -  #21: XRE_main(int,char * * const,mozilla::BootstrapConfig const &) [toolkit/xre/nsAppRunner.cpp:4960]
15:20:39     INFO -  #22: do_main [browser/app/nsBrowserApp.cpp:237]
15:20:39     INFO -  #23: NS_internal_main(int,char * *,char * *) [browser/app/nsBrowserApp.cpp:311]
15:20:39     INFO -  #24: wmain [toolkit/xre/nsWindowsWMain.cpp:118]
15:20:39     INFO -  #25: __scrt_common_main_seh [f:/dd/vctools/crt/vcstartup/src/startup/exe_common.inl:253]
15:20:39     INFO -  #26: KERNEL32.DLL + 0x12774
15:20:39     INFO -  #27: ntdll.dll + 0x70d61
15:20:39     INFO -  [1088, Main Thread] ###!!! ASSERTION: IsMainProcess() called before indexedDB has been initialized!: 'gDBManager', file z:/build/build/src/dom/indexedDB/IndexedDatabaseManager.cpp, line 688
15:20:39     INFO -  Hit MOZ_CRASH() at z:/build/build/src/memory/mozalloc/mozalloc_abort.cpp:33
15:20:39     INFO -  mozcrash INFO | Copy/paste: Z:\task_1506006677\build\win32-minidump_stackwalk.exe Z:\task_1506006677\build\tests\gtest\8ad6321b-ad50-410d-a944-e7a50b4827e5.dmp Z:\task_1506006677\build\symbols
15:20:51     INFO -  mozcrash INFO | Saved minidump as Z:\task_1506006677\build\blobber_upload_dir\8ad6321b-ad50-410d-a944-e7a50b4827e5.dmp
15:20:51     INFO -  mozcrash INFO | Saved app info as Z:\task_1506006677\build\blobber_upload_dir\8ad6321b-ad50-410d-a944-e7a50b4827e5.extra
15:20:51  WARNING -  PROCESS-CRASH | gtest | application crashed [@ mozalloc_abort(char const * const)]
15:20:51     INFO -  Crash dump filename: Z:\task_1506006677\build\tests\gtest\8ad6321b-ad50-410d-a944-e7a50b4827e5.dmp
15:20:51     INFO -  Operating system: Windows NT
15:20:51     INFO -                    10.0.15063
15:20:51     INFO -  CPU: amd64
15:20:51     INFO -       family 6 model 63 stepping 2
15:20:51     INFO -       8 CPUs
15:20:51     INFO -  GPU: UNKNOWN
15:20:51     INFO -  Crash reason:  EXCEPTION_BREAKPOINT
15:20:51     INFO -  Crash address: 0x7ff9ea5c3f56
15:20:51     INFO -  Process uptime: 379 seconds
15:20:51     INFO -  Thread 0 (crashed)
15:20:51     INFO -   0  mozglue.dll!mozalloc_abort(char const * const) [mozalloc_abort.cpp:4dab43248f15 : 33 + 0x1b]
15:20:51     INFO -      rax = 0x0000000000000000   rdx = 0x0000000000000000
15:20:51     INFO -      rcx = 0x00000000ffffffff   rbx = 0x0000000000000021
15:20:51     INFO -      rsi = 0x0000000000000000   rdi = 0xffffffffffffffff
15:20:51     INFO -      rbp = 0x00000049e5ffe560   rsp = 0x00000049e5ffe430
15:20:51     INFO -       r8 = 0x00000049e5ffcd18    r9 = 0x0000000000000000
15:20:51     INFO -      r10 = 0x0000000000000000   r11 = 0x00000049e5ffe2b0
15:20:51     INFO -      r12 = 0x0000000000000001   r13 = 0x0000000000000000
15:20:51     INFO -      r14 = 0x0000000000000002   r15 = 0x000001da01b56c00
15:20:51     INFO -      rip = 0x00007ff9ea5c3f56
15:20:51     INFO -      Found by: given as instruction pointer in context
15:20:51     INFO -   1  xul.dll!NS_DebugBreak [nsDebugImpl.cpp:4dab43248f15 : 448 + 0xd]
15:20:51     INFO -      rbx = 0x0000000000000021   rbp = 0x00000049e5ffe560
15:20:51     INFO -      rsp = 0x00000049e5ffe460   r12 = 0x0000000000000001
15:20:51     INFO -      r13 = 0x0000000000000000   r14 = 0x0000000000000002
15:20:51     INFO -      r15 = 0x000001da01b56c00   rip = 0x00007ff9b505da3b
15:20:51     INFO -      Found by: call frame info
15:20:51     INFO -   2  xul.dll!mozilla::dom::IndexedDatabaseManager::IsMainProcess() [IndexedDatabaseManager.cpp:4dab43248f15 : 687 + 0x31]
15:20:51     INFO -      rbx = 0x0000000000000021   rbp = 0x00000049e5ffe560
15:20:51     INFO -      rsp = 0x00000049e5ffe920   r12 = 0x0000000000000001
15:20:51     INFO -      r13 = 0x0000000000000000   r14 = 0x0000000000000002
15:20:51     INFO -      r15 = 0x000001da01b56c00   rip = 0x00007ff9b77cacd5
15:20:51     INFO -      Found by: call frame info
15:20:51     INFO -   3  xul.dll!mozilla::dom::IndexedDatabaseManager::NoteLiveQuotaManager(mozilla::dom::quota::QuotaManager *) [IndexedDatabaseManager.cpp:4dab43248f15 : 832 + 0x5]
15:20:51     INFO -      rbx = 0x0000000000000021   rbp = 0x00000049e5ffe560
15:20:51     INFO -      rsp = 0x00000049e5ffe960   r12 = 0x0000000000000001
15:20:51     INFO -      r13 = 0x0000000000000000   r14 = 0x0000000000000002
15:20:51     INFO -      r15 = 0x000001da01b56c00   rip = 0x00007ff9b77cb099
15:20:51     INFO -      Found by: call frame info
15:20:51     INFO -   4  xul.dll!mozilla::dom::IndexedDatabaseManager::Init() [IndexedDatabaseManager.cpp:4dab43248f15 : 396 + 0xb]
15:20:51     INFO -      rbx = 0x0000000000000021   rbp = 0x00000049e5ffe560
15:20:51     INFO -      rsp = 0x00000049e5ffe990   r12 = 0x0000000000000001
15:20:51     INFO -      r13 = 0x0000000000000000   r14 = 0x0000000000000002
15:20:51     INFO -      r15 = 0x000001da01b56c00   rip = 0x00007ff9b77ca261
15:20:51     INFO -      Found by: call frame info
15:20:51     INFO -   5  xul.dll!mozilla::dom::IndexedDatabaseManager::GetOrCreate() [IndexedDatabaseManager.cpp:4dab43248f15 : 354 + 0x8]
15:20:51     INFO -      rbx = 0x0000000000000021   rbp = 0x00000049e5ffe560
15:20:51     INFO -      rsp = 0x00000049e5ffebf0   r12 = 0x0000000000000001
15:20:51     INFO -      r13 = 0x0000000000000000   r14 = 0x0000000000000002
15:20:51     INFO -      r15 = 0x000001da01b56c00   rip = 0x00007ff9b77c9ef7
15:20:51     INFO -      Found by: call frame info
15:20:51     INFO -   6  xul.dll!mozilla::dom::indexedDB::`anonymous namespace'::Maintenance::CreateIndexedDatabaseManager [ActorsParent.cpp:4dab43248f15 : 18353 + 0x5]
15:20:51     INFO -      rbx = 0x0000000000000021   rbp = 0x00000049e5ffe560
15:20:51     INFO -      rsp = 0x00000049e5ffec50   r12 = 0x0000000000000001
15:20:51     INFO -      r13 = 0x0000000000000000   r14 = 0x0000000000000002
15:20:51     INFO -      r15 = 0x000001da01b56c00   rip = 0x00007ff9b77342d1
15:20:51     INFO -      Found by: call frame info
15:20:51     INFO -   7  xul.dll!mozilla::dom::indexedDB::`anonymous namespace'::Maintenance::Run [ActorsParent.cpp:4dab43248f15 : 18827 + 0x5]
15:20:51     INFO -      rbx = 0x0000000000000021   rbp = 0x00000049e5ffe560
15:20:51     INFO -      rsp = 0x00000049e5ffec90   r12 = 0x0000000000000001
15:20:51     INFO -      r13 = 0x0000000000000000   r14 = 0x0000000000000002
15:20:51     INFO -      r15 = 0x000001da01b56c00   rip = 0x00007ff9b7772884
15:20:51     INFO -      Found by: call frame info
15:20:51     INFO -   8  xul.dll!nsThread::ProcessNextEvent(bool,bool *) [nsThread.cpp:4dab43248f15 : 1039 + 0x14]
15:20:51     INFO -      rbx = 0x0000000000000021   rbp = 0x00000049e5ffe560
15:20:51     INFO -      rsp = 0x00000049e5ffecd0   r12 = 0x0000000000000001
15:20:51     INFO -      r13 = 0x0000000000000000   r14 = 0x0000000000000002
15:20:51     INFO -      r15 = 0x000001da01b56c00   rip = 0x00007ff9b510e74d
15:20:51     INFO -      Found by: call frame info
15:20:51     INFO -   9  xul.dll!FlushMainThreadLoop [TestVsync.cpp:4dab43248f15 : 107 + 0x19]
15:20:51     INFO -      rbx = 0x0000000000000021   rbp = 0x00000049e5ffe560
15:20:51     INFO -      rsp = 0x00000049e5fff360   r12 = 0x0000000000000001
15:20:51     INFO -      r13 = 0x0000000000000000   r14 = 0x0000000000000002
15:20:51     INFO -      r15 = 0x000001da01b56c00   rip = 0x00007ff9b96d2a90
15:20:51     INFO -      Found by: call frame info
15:20:51     INFO -  10  xul.dll!VsyncTester_CompositorGetVsyncNotifications_Test::TestBody() [TestVsync.cpp:4dab43248f15 : 136 + 0x5]
15:20:51     INFO -      rbx = 0x0000000000000021   rbp = 0x00000049e5ffe560
15:20:51     INFO -      rsp = 0x00000049e5fff400   r12 = 0x0000000000000001
15:20:51     INFO -      r13 = 0x0000000000000000   r14 = 0x0000000000000002
15:20:51     INFO -      r15 = 0x000001da01b56c00   rip = 0x00007ff9b96b1279
15:20:51     INFO -      Found by: call frame info
15:20:51     INFO -  11  xul.dll!testing::internal::HandleSehExceptionsInMethodIfSupported<testing::Test,void>(testing::Test *,void ( testing::Test::*)(void),char const *) [gtest.cc:4dab43248f15 : 2387 + 0x2]
15:20:51     INFO -      rbx = 0x0000000000000021   rbp = 0x00000049e5ffe560
15:20:51     INFO -      rsp = 0x00000049e5fff4a0   r12 = 0x0000000000000001
15:20:51     INFO -      r13 = 0x0000000000000000   r14 = 0x0000000000000002
15:20:51     INFO -      r15 = 0x000001da01b56c00   rip = 0x00007ff9b9607138
15:20:51     INFO -      Found by: call frame info
15:20:51     INFO -  12  xul.dll!testing::internal::HandleExceptionsInMethodIfSupported<testing::Test,void>(testing::Test *,void ( testing::Test::*)(void),char const *) [gtest.cc:4dab43248f15 : 2455 + 0x1c]
15:20:51     INFO -      rbx = 0x0000000000000021   rbp = 0x00000049e5ffe560
15:20:51     INFO -      rsp = 0x00000049e5fff4d0   r12 = 0x0000000000000001
15:20:51     INFO -      r13 = 0x0000000000000000   r14 = 0x0000000000000002
15:20:51     INFO -      r15 = 0x000001da01b56c00   rip = 0x00007ff9b9607025
15:20:51     INFO -      Found by: call frame info
15:20:51     INFO -  13  xul.dll!testing::Test::Run() [gtest.cc:4dab43248f15 : 2474 + 0x16]
15:20:51     INFO -      rbx = 0x0000000000000021   rbp = 0x00000049e5ffe560
15:20:51     INFO -      rsp = 0x00000049e5fff500   r12 = 0x0000000000000001
15:20:51     INFO -      r13 = 0x0000000000000000   r14 = 0x0000000000000002
15:20:51     INFO -      r15 = 0x000001da01b56c00   rip = 0x00007ff9b961c3fa
15:20:51     INFO -      Found by: call frame info
15:20:51     INFO -  14  xul.dll!testing::TestInfo::Run() [gtest.cc:4dab43248f15 : 2656 + 0x8]
15:20:51     INFO -      rbx = 0x0000000000000021   rbp = 0x00000049e5ffe560
15:20:51     INFO -      rsp = 0x00000049e5fff530   r12 = 0x0000000000000001
15:20:51     INFO -      r13 = 0x0000000000000000   r14 = 0x0000000000000002
15:20:51     INFO -      r15 = 0x000001da01b56c00   rip = 0x00007ff9b961c5e9
15:20:51     INFO -      Found by: call frame info
15:20:51     INFO -  15  xul.dll!testing::TestCase::Run() [gtest.cc:4dab43248f15 : 2774 + 0x12]
15:20:51     INFO -      rbx = 0x0000000000000021   rbp = 0x00000049e5ffe560
15:20:51     INFO -      rsp = 0x00000049e5fff560   r12 = 0x0000000000000001
15:20:51     INFO -      r13 = 0x0000000000000000   r14 = 0x0000000000000002
15:20:51     INFO -      r15 = 0x000001da01b56c00   rip = 0x00007ff9b961c4d1
15:20:51     INFO -      Found by: call frame info
15:20:51     INFO -  16  xul.dll!testing::internal::UnitTestImpl::RunAllTests() [gtest.cc:4dab43248f15 : 4649 + 0x3e]
15:20:51     INFO -      rbx = 0x0000000000000021   rbp = 0x00000049e5ffe560
15:20:51     INFO -      rsp = 0x00000049e5fff590   r12 = 0x0000000000000001
15:20:51     INFO -      r13 = 0x0000000000000000   r14 = 0x0000000000000002
15:20:51     INFO -      r15 = 0x000001da01b56c00   rip = 0x00007ff9b961c992
15:20:51     INFO -      Found by: call frame info
15:20:51     INFO -  17  xul.dll!testing::internal::HandleSehExceptionsInMethodIfSupported<testing::internal::UnitTestImpl,bool>(testing::internal::UnitTestImpl *,bool ( testing::internal::UnitTestImpl::*)(void),char const *) [gtest.cc:4dab43248f15 : 2387 + 0x2]
15:20:51     INFO -      rbx = 0x0000000000000021   rbp = 0x00000049e5ffe560
15:20:51     INFO -      rsp = 0x00000049e5fff600   r12 = 0x0000000000000001
15:20:52     INFO -      r13 = 0x0000000000000000   r14 = 0x0000000000000002
15:20:52     INFO -      r15 = 0x000001da01b56c00   rip = 0x00007ff9b9607210
15:20:52     INFO -      Found by: call frame info
15:20:52     INFO -  18  xul.dll!testing::internal::HandleExceptionsInMethodIfSupported<testing::internal::UnitTestImpl,bool>(testing::internal::UnitTestImpl *,bool ( testing::internal::UnitTestImpl::*)(void),char const *) [gtest.cc:4dab43248f15 : 2455 + 0x1c]
15:20:52     INFO -      rbx = 0x0000000000000021   rbp = 0x00000049e5ffe560
15:20:52     INFO -      rsp = 0x00000049e5fff630   r12 = 0x0000000000000001
15:20:52     INFO -      r13 = 0x0000000000000000   r14 = 0x0000000000000002
15:20:52     INFO -      r15 = 0x000001da01b56c00   rip = 0x00007ff9b9607115
15:20:52     INFO -      Found by: call frame info
15:20:52     INFO -  19  xul.dll!testing::UnitTest::Run() [gtest.cc:4dab43248f15 : 4257 + 0x17]
15:20:52     INFO -      rbx = 0x0000000000000021   rbp = 0x00000049e5ffe560
15:20:52     INFO -      rsp = 0x00000049e5fff660   r12 = 0x0000000000000001
15:20:52     INFO -      r13 = 0x0000000000000000   r14 = 0x0000000000000002
15:20:52     INFO -      r15 = 0x000001da01b56c00   rip = 0x00007ff9b961c72f
15:20:52     INFO -      Found by: call frame info
15:20:52     INFO -  20  xul.dll!mozilla::RunGTestFunc(int *,char * *) [GTestRunner.cpp:4dab43248f15 : 117 + 0xd]
15:20:52     INFO -      rbx = 0x0000000000000021   rbp = 0x00000049e5ffe560
15:20:52     INFO -      rsp = 0x00000049e5fff690   r12 = 0x0000000000000001
15:20:52     INFO -      r13 = 0x0000000000000000   r14 = 0x0000000000000002
15:20:52     INFO -      r15 = 0x000001da01b56c00   rip = 0x00007ff9b9623d02
15:20:52     INFO -      Found by: call frame info
15:20:52     INFO -  21  xul.dll!XREMain::XRE_mainStartup(bool *) [nsAppRunner.cpp:4dab43248f15 : 3928 + 0x17]
15:20:52     INFO -      rbx = 0x0000000000000021   rbp = 0x00000049e5ffe560
15:20:52     INFO -      rsp = 0x00000049e5fff720   r12 = 0x0000000000000001
15:20:52     INFO -      r13 = 0x0000000000000000   r14 = 0x0000000000000002
15:20:52     INFO -      r15 = 0x000001da01b56c00   rip = 0x00007ff9b915cb02
15:20:52     INFO -      Found by: call frame info
15:20:52     INFO -  22  xul.dll!XREMain::XRE_main(int,char * * const,mozilla::BootstrapConfig const &) [nsAppRunner.cpp:4dab43248f15 : 4850 + 0xc]
15:20:52     INFO -      rbx = 0x0000000000000021   rbp = 0x00000049e5ffe560
15:20:52     INFO -      rsp = 0x00000049e5fff860   r12 = 0x0000000000000001
15:20:52     INFO -      r13 = 0x0000000000000000   r14 = 0x0000000000000002
15:20:52     INFO -      r15 = 0x000001da01b56c00   rip = 0x00007ff9b9158dd6
15:20:52     INFO -      Found by: call frame info
15:20:52     INFO -  23  xul.dll!XRE_main(int,char * * const,mozilla::BootstrapConfig const &) [nsAppRunner.cpp:4dab43248f15 : 4960 + 0x12]
15:20:52     INFO -      rbx = 0x0000000000000021   rbp = 0x00000049e5ffe560
15:20:52     INFO -      rsp = 0x00000049e5fff930   r12 = 0x0000000000000001
15:20:52     INFO -      r13 = 0x0000000000000000   r14 = 0x0000000000000002
15:20:52     INFO -      r15 = 0x000001da01b56c00   rip = 0x00007ff9b91586cc
15:20:52     INFO -      Found by: call frame info
15:20:52     INFO -  24  firefox.exe!do_main [nsBrowserApp.cpp:4dab43248f15 : 236 + 0x15]
15:20:52     INFO -      rbx = 0x0000000000000021   rbp = 0x00000049e5ffe560
15:20:52     INFO -      rsp = 0x00000049e5fffad0   r12 = 0x0000000000000001
15:20:52     INFO -      r13 = 0x0000000000000000   r14 = 0x0000000000000002
15:20:52     INFO -      r15 = 0x000001da01b56c00   rip = 0x00007ff6fc3619d6
15:20:52     INFO -      Found by: call frame info
15:20:52     INFO -  25  firefox.exe!NS_internal_main(int,char * *,char * *) [nsBrowserApp.cpp:4dab43248f15 : 309 + 0xd]
15:20:52     INFO -      rbx = 0x0000000000000021   rbp = 0x00000049e5ffe560
15:20:52     INFO -      rsp = 0x00000049e5fffc90   r12 = 0x0000000000000001
15:20:52     INFO -      r13 = 0x0000000000000000   r14 = 0x0000000000000002
15:20:52     INFO -      r15 = 0x000001da01b56c00   rip = 0x00007ff6fc36145f
15:20:52     INFO -      Found by: call frame info
15:20:52     INFO -  26  firefox.exe!wmain [nsWindowsWMain.cpp:4dab43248f15 : 115 + 0x14]
15:20:52     INFO -      rbx = 0x0000000000000021   rbp = 0x00000049e5ffe560
15:20:52     INFO -      rsp = 0x00000049e5fffd00   r12 = 0x0000000000000001
15:20:52     INFO -      r13 = 0x0000000000000000   r14 = 0x0000000000000002
15:20:52     INFO -      r15 = 0x000001da01b56c00   rip = 0x00007ff6fc361d9b
15:20:52     INFO -      Found by: call frame info
15:20:52     INFO -  27  firefox.exe!__scrt_common_main_seh [exe_common.inl : 253 + 0x22]
15:20:52     INFO -      rbx = 0x0000000000000021   rbp = 0x00000049e5ffe560
15:20:52     INFO -      rsp = 0x00000049e5fffd60   r12 = 0x0000000000000001
15:20:52     INFO -      r13 = 0x0000000000000000   r14 = 0x0000000000000002
15:20:52     INFO -      r15 = 0x000001da01b56c00   rip = 0x00007ff6fc3a6f29
15:20:52     INFO -      Found by: call frame info
15:20:52     INFO -  28  kernel32.dll!BaseThreadInitThunk + 0x14
15:20:52     INFO -      rbx = 0x0000000000000021   rbp = 0x00000049e5ffe560
15:20:52     INFO -      rsp = 0x00000049e5fffda0   r12 = 0x0000000000000001
15:20:52     INFO -      r13 = 0x0000000000000000   r14 = 0x0000000000000002
15:20:52     INFO -      r15 = 0x000001da01b56c00   rip = 0x00007ff9ed4d2774
15:20:52     INFO -      Found by: call frame info
15:20:52     INFO -  29  ntdll.dll!SdbpCheckMatchingRegistryEntry + 0x29d
15:20:52     INFO -      rbx = 0x0000000000000021   rbp = 0x00000049e5ffe560
15:20:52     INFO -      rsp = 0x00000049e5fffdd0   r12 = 0x0000000000000001
15:20:52     INFO -      r13 = 0x0000000000000000   r14 = 0x0000000000000002
15:20:52     INFO -      r15 = 0x000001da01b56c00   rip = 0x00007ff9efd90d61
15:20:52     INFO -      Found by: call frame info
15:20:52     INFO -  30  KERNELBASE.dll + 0x67c0
15:20:52     INFO -      rsp = 0x00000049e5fffe00   rip = 0x00007ff9ec2467c0
15:20:52     INFO -      Found by: stack scanning

Comment 14

[Ryan VanderMeulen [:RyanVM]]

Pushed to Beta57 also.
https://hg.mozilla.org/releases/mozilla-beta/rev/c23b7af37eaf

Comment 15

[Liz Henry (:lizzard) (relman/hg->git project)]

Do we also need this on 56 release?

Comment 16

[Bob Owen (:bobowen)]

Got back to this and spent some time trying to work out why we end up losing this race permanently, but couldn't figure anything out.

So, I fixed what is a theoretically incorrect assertion, but I seem to have swapped that for a permanent time-out problem :-(
https://treeherder.mozilla.org/#/jobs?repo=try&revision=cbc4e5009afbc7634ad9e0f57cf8bb120a642803

The time-out is right at the end, so I suspect this is a shutdown hang.

Comment 17

[Bob Owen (:bobowen)]

I think I've reproduced this hang locally, where it is waiting on this spinner [1].

[1] https://hg.mozilla.org/mozilla-central/file/613f64109bde/toolkit/components/places/tests/gtest/places_test_harness.h#l384

Comment 18

[Bob Owen (:bobowen)]

OK I've found and fixed the shutdown hang, another race where we were waiting on the places-connection-closed notification during the profile-before-change notification in the places test harness.
Problem is that places-connection-closed is sent by something that also happens because of profile-before-change, so if they get in the wrong order you hang.

I've just changed it to wait in the following shutdown phase ... and now I have a shutdown crash, probably a race again. :-)

Comment 19

[Bob Owen (:bobowen)]

Final (hopefully) issue was down to the idle-daily observer for satchel being in the manifest.
This change for some reason means that sometimes idle-daily gets notified and that causes the form history database to be created even though profile-after-change hasn't happened.

Normally profile-after-change causes a call to FormHistoryStartup.init, which sets up the shutdown observers.
As that doesn't happen the database connection doesn't get closed and we crash:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=40553fe50dd718d4982b20862d3a334a0b986905

Comment 20

[Bob Owen (:bobowen)]

Attachment: Part 1: Fix assertion in IndexedDatabaseManager::NoteLiveQuotaManager

Comment 21

[Bob Owen (:bobowen)]

Attachment: Part 2: In places test harness, wait for places-connection-closed in profile-before-change-qm not profile-before-change

Comment 22

[Bob Owen (:bobowen)]

Attachment: Part 3: Annotate crash with database name when storage connection not closed

Comment 23

[Bob Owen (:bobowen)]

Attachment: Part 4: Set-up observer for idle-daily in FormHistoryStartup.init not manifest

This is so that we don't open a database connection without any of the machinery in place to close it.

Comment 24

[Bob Owen (:bobowen)]

Attachment: Part 5: Extend BaseThreadInitThunk thread start address verification to 64-bit

Comment 25

[Bob Owen (:bobowen)]

Comment on attachment 8919232 [details] [diff] [review]
Part 5: Extend BaseThreadInitThunk thread start address verification to 64-bit

Carrying r+ from dmajor in comment 9.

Comment 26

[Marco Bonardo [:mak]]

Comment on attachment 8919231 [details] [diff] [review]
Part 4: Set-up observer for idle-daily in FormHistoryStartup.init not manifest

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

Since it's also part of the profile-after-change category, the change makes sense. Otherwise, this would have changed the component behavior, that I assume was to be able to do idle work even if nothing inited the service yet. since the service is inited with the profile, we don't need the idle-daily category startup.

Comment 27

[Marco Bonardo [:mak]]

Comment on attachment 8919229 [details] [diff] [review]
Part 3: Annotate crash with database name when storage connection not closed

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

Awesome, this would solve bug 1384036!

::: storage/mozStorageService.cpp
@@ +29,5 @@
> +#ifdef MOZ_CRASHREPORTER
> +#include "nsExceptionHandler.h"
> +#endif
> +
> +#ifdef XP_WIN

the change from SQLITE_OS_WIN to XP_WIN doesn't seem strictly necessary. They differ slightly, and it's Sqlite that dominates here since it's including libraries internally. Provided this compiles on our tinderboxes this is not a big deal in practice.

@@ +829,5 @@
>        for (uint32_t i = 0, n = connections.Length(); i < n; i++) {
>          if (!connections[i]->isClosed()) {
> +#ifdef MOZ_CRASHREPORTER
> +          // getFilename is only the leaf name for the database file,
> +          // so it shouldn't contain privacy-sensitive information.

potentially this may disclose informations about a couple things:
1. indexedDB database ids. In the past we used telemetryFilename to avoid exposing information. But now I see indexedDB seems to use an hash, I just don't know if that's randomized and non-invertible.
2. legacy add-ons installed. Though, we don't officially support those anymore, so I guess it's ok.

Regardless, this code only runs when SCM_CRASH is set, that is basically only on DEBUG builds and when an ENV var is set. Not a big deal in general, but I'll still forward this to Jan to tell if there's any privacy hit for indexedDB yet.

Comment 28

[Jan Varga [:janv]]

Comment on attachment 8919229 [details] [diff] [review]
Part 3: Annotate crash with database name when storage connection not closed

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

::: storage/mozStorageService.cpp
@@ +832,5 @@
> +          // getFilename is only the leaf name for the database file,
> +          // so it shouldn't contain privacy-sensitive information.
> +          CrashReporter::AnnotateCrashReport(
> +            NS_LITERAL_CSTRING("StorageConnectionNotClosed"),
> +            connections[i]->getFilename());

MOZ_LOG and telemetry both use mTelemetryFilename in this source file, so I guess we should be in sync with that. I would prefer mTelemetryFilename here if you are ok with that.

Comment 29

[Bob Owen (:bobowen)]

(In reply to Jan Varga [:janv] from comment #28)
...
> MOZ_LOG and telemetry both use mTelemetryFilename in this source file, so I
> guess we should be in sync with that. I would prefer mTelemetryFilename here
> if you are ok with that.

mTelemetryFilename is from mozStorageConnection.cpp not this file.

Also thinking about it the crash annotation isn't so useful in the DEBUG case so maybe I should add something like the following as well:

#ifdef DEBUG
          printf_stderr("Storage connection not closed: %s",
                        connections[i]->getFilename().get());
#endif

Comment 30

[Jan Varga [:janv]]

(In reply to Bob Owen (:bobowen) from comment #29)
> (In reply to Jan Varga [:janv] from comment #28)
> ...
> > MOZ_LOG and telemetry both use mTelemetryFilename in this source file, so I
> > guess we should be in sync with that. I would prefer mTelemetryFilename here
> > if you are ok with that.
> 
> mTelemetryFilename is from mozStorageConnection.cpp not this file.

I meant that |connections[i]->getFilename()| could be replaced with something that uses mTelemetryFilename

> 
> Also thinking about it the crash annotation isn't so useful in the DEBUG
> case so maybe I should add something like the following as well:
> 
> #ifdef DEBUG
>           printf_stderr("Storage connection not closed: %s",
>                         connections[i]->getFilename().get());
> #endif

That's fine by me.

Comment 31

[Marco Bonardo [:mak]]

note: in debug mode _OR_ if a specific ENV var is set. Not that I think anyone would set that on purpose apart from ourselves, so the problem is minor.

Comment 32

[Jan Varga [:janv]]

Ok, I don't insist on using mTelemetryFilename, I just thought that it would be nice to be in sync with existing code which uses it even for MOZ_LOG.

Comment 33

[Bob Owen (:bobowen)]

OK thanks both, I'll keep it as it is then and add in the printf_stderr, which will be particularly helpful on try push failures.

Comment 34

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/b22ccf242a36
Part 1: Fix assertion in IndexedDatabaseManager::NoteLiveQuotaManager. r=janv
https://hg.mozilla.org/integration/mozilla-inbound/rev/31091526aa5e
Part 2: In places test harness, wait for places-connection-closed in profile-before-change-qm not profile-before-change. r=mak
https://hg.mozilla.org/integration/mozilla-inbound/rev/b2f92ccf6938
Part 3: Annotate crash with database name when storage connection not closed. r=janv
https://hg.mozilla.org/integration/mozilla-inbound/rev/f8094e7cb515
Part 4: Set-up observer for idle-daily in FormHistoryStartup.init not manifest. r=mak
https://hg.mozilla.org/integration/mozilla-inbound/rev/13bd66ee725e
Part 5: Extend BaseThreadInitThunk thread start address verification to 64-bit. r=dmajor

Comment 35

[Stefan Hindli [:stefan_hindli]]

https://hg.mozilla.org/mozilla-central/rev/b22ccf242a36
https://hg.mozilla.org/mozilla-central/rev/31091526aa5e
https://hg.mozilla.org/mozilla-central/rev/b2f92ccf6938
https://hg.mozilla.org/mozilla-central/rev/f8094e7cb515
https://hg.mozilla.org/mozilla-central/rev/13bd66ee725e

Comment 36

[(Away)]

I know that it's annoying when unrelated issues get in the way, but I think this bug was a really good result for our codebase in cleaning out these latent problems. Thank you bug-watchers for your patience and thank you Bob for your tenacity!