1587112 - Intermittent startup cache assert on startup: "Assertion failure: mPtr <= mRangeEnd, at $OBJ/dist/include/mozilla/RangedPtr.h:54"

Status: RESOLVED FIXED

(Toolkit :: Startup and Profile System, defect, P3)

Description

[Paul Adenot (:padenot)]

On OSX debug build, randomly (usually once every coupe runs), when starting Firefox:

Assertion failure: mPtr <= mRangeEnd, at /Users/padenot/src/trees/mozilla-unified/obj-x86_64-apple-darwin18.7.0/dist/include/mozilla/RangedPtr.h:54
#01: mozilla::RangedPtr<unsigned char>::checkSanity()[/Users/padenot/src/trees/mozilla-unified/obj-x86_64-apple-darwin18.7.0/dist/NightlyDebug.app/Contents/MacOS/XUL +0x498e40]
#02: mozilla::RangedPtr<unsigned char>::RangedPtr(unsigned char*, unsigned char*, unsigned char*)[/Users/padenot/src/trees/mozilla-unified/obj-x86_64-apple-darwin18.7.0/dist/NightlyDebug.app/Contents/MacOS/XUL +0x498d75]
#03: mozilla::RangedPtr<unsigned char>::RangedPtr(unsigned char*, unsigned char*, unsigned char*)[/Users/padenot/src/trees/mozilla-unified/obj-x86_64-apple-darwin18.7.0/dist/NightlyDebug.app/Contents/MacOS/XUL +0x498cbd]
#04: mozilla::RangedPtr<unsigned char>::create(unsigned char*) const[/Users/padenot/src/trees/mozilla-unified/obj-x86_64-apple-darwin18.7.0/dist/NightlyDebug.app/Contents/MacOS/XUL +0x498b87]
#05: mozilla::RangedPtr<unsigned char>::operator+(unsigned long) const[/Users/padenot/src/trees/mozilla-unified/obj-x86_64-apple-darwin18.7.0/dist/NightlyDebug.app/Contents/MacOS/XUL +0x1cbc56b]
#06: mozilla::scache::StartupCache::LoadArchive()[/Users/padenot/src/trees/mozilla-unified/obj-x86_64-apple-darwin18.7.0/dist/NightlyDebug.app/Contents/MacOS/XUL +0x9c08797]
#07: mozilla::scache::StartupCache::Init()[/Users/padenot/src/trees/mozilla-unified/obj-x86_64-apple-darwin18.7.0/dist/NightlyDebug.app/Contents/MacOS/XUL +0x9c061e7]
#08: mozilla::scache::StartupCache::InitSingleton()[/Users/padenot/src/trees/mozilla-unified/obj-x86_64-apple-darwin18.7.0/dist/NightlyDebug.app/Contents/MacOS/XUL +0x9c057c4]
#09: mozilla::scache::StartupCache::GetSingleton()[/Users/padenot/src/trees/mozilla-unified/obj-x86_64-apple-darwin18.7.0/dist/NightlyDebug.app/Contents/MacOS/XUL +0x9c0572d]
#10: NS_InitXPCOM[/Users/padenot/src/trees/mozilla-unified/obj-x86_64-apple-darwin18.7.0/dist/NightlyDebug.app/Contents/MacOS/XUL +0x360d74]
#11: ScopedXPCOMStartup::Initialize()[/Users/padenot/src/trees/mozilla-unified/obj-x86_64-apple-darwin18.7.0/dist/NightlyDebug.app/Contents/MacOS/XUL +0x9b54429]
#12: XREMain::XRE_main(int, char**, mozilla::BootstrapConfig const&)[/Users/padenot/src/trees/mozilla-unified/obj-x86_64-apple-darwin18.7.0/dist/NightlyDebug.app/Contents/MacOS/XUL +0x9b610bc]
#13: XRE_main(int, char**, mozilla::BootstrapConfig const&)[/Users/padenot/src/trees/mozilla-unified/obj-x86_64-apple-darwin18.7.0/dist/NightlyDebug.app/Contents/MacOS/XUL +0x9b61a0b]
#14: mozilla::BootstrapImpl::XRE_main(int, char**, mozilla::BootstrapConfig const&)[/Users/padenot/src/trees/mozilla-unified/obj-x86_64-apple-darwin18.7.0/dist/NightlyDebug.app/Contents/MacOS/XUL +0x9b7a177]
#15: do_main(int, char**, char**)[/Users/padenot/src/trees/mozilla-unified/obj-x86_64-apple-darwin18.7.0/dist/NightlyDebug.app/Contents/MacOS/firefox +0x18d9]
#16: main[/Users/padenot/src/trees/mozilla-unified/obj-x86_64-apple-darwin18.7.0/dist/NightlyDebug.app/Contents/MacOS/firefox +0x1203]
Process 65571 stopped
* thread #1, queue = 'com.apple.main-thread', stop reason = EXC_BAD_ACCESS (code=1, address=0x0)
    frame #0: 0x0000000110498e4c XUL`mozilla::RangedPtr<unsigned char>::checkSanity(this=0x00007ffeefbfe510) at RangedPtr.h:54:5
   51  	
   52  	  void checkSanity() {
   53  	    MOZ_ASSERT(mRangeStart <= mPtr);
-> 54  	    MOZ_ASSERT(mPtr <= mRangeEnd);
   55  	  }
   56  	
   57  	  /* Creates a new pointer for |aPtr|, restricted to this pointer's range. */
Target 0: (firefox) stopped.

Doug, can you please have a look?

Comment 1

[Paul Adenot (:padenot)]

Sorry I don't have value for mPtr and mRangeEnd.

Comment 2

[Alex Thayer [:alexical] (she/her)]

Unfortunately I can't seem to reproduce this on my end. Immediately after this crashes, what is the size of your <profile>/startupCache/startupCache.8.little file? And can you get the line number in StartupCache::LoadArchive()?

Comment 3

[Alex Thayer [:alexical] (she/her)]

To be clear, if the assertion weren't here, this would still work, as that assertion is firing from code which is using this operator to detect a problem in the file and exit gracefully.

However, it is a problem that the file is in a corrupt state to begin with.

Comment 4

[Paul Adenot (:padenot)]

(In reply to Doug Thayer [:dthayer] from comment #2)

Unfortunately I can't seem to reproduce this on my end. Immediately after this crashes, what is the size of your <profile>/startupCache/startupCache.8.little file? And can you get the line number in StartupCache::LoadArchive()?

I don't have this file, it seems. I also can't seem to repro... I'll comment here if it happens again.

Comment 5

[Alex Thayer [:alexical] (she/her)]

Do you have the startupCache folder? If so, what's in it? If not, make sure you're looking in the "Local Directory" profile dir from about:profiles.

Comment 7

[Alex Thayer [:alexical] (she/her)]

Daniel, in bug 1587567 you mention that this happened as a result of an unrelated crash. Are you certain of the cause of that crash? I just want to make sure I haven't introduced a problem which is causing the startupCache file to be corrupt more often.

Comment 8

[Alex Thayer [:alexical] (she/her)]

I am inclined to say that the observed behavior is actually correct here - crashing on debug builds if the startupCache file is corrupt. This is more likely to surface a problem than if we just fail gracefully. However, I do think it should be more explicit as a MOZ_ASSERT within LoadArchive(). Thoughts?

Comment 9

[Daniel Holbert [:dholbert]]

(In reply to Doug Thayer [:dthayer] from comment #7)

Daniel, in bug 1587567 you mention that this happened as a result of an unrelated crash. Are you certain of the cause of that crash? I just want to make sure I haven't introduced a problem which is causing the startupCache file to be corrupt more often.

Good point -- I was actually wrong, the original crash was startupcache related!! I just hadn't realized, since it happened at a weird intermediate point when I was typing a URL.

Here's the backtrace from that original (mid-run) crash, which left me in a state where I hit this startup crash on the next run:

Program $OBJ/dist/bin/firefox (pid = 1080) received signal 11.
Stack:
#01: js::UnixExceptionHandler(int, siginfo_t*, void*) ($SRC/js/src/ds/MemoryProtectionExceptionHandler.cpp:274)
#02: WasmTrapHandler(int, siginfo_t*, void*) ($SRC/js/src/wasm/WasmSignalHandlers.cpp:963)
#03: __restore_rt (sigaction.c:?)
#04: __memset_avx2_erms (/build/glibc-4WA41p/glibc-2.30/string/../sysdeps/x86_64/multiarch/memset-vec-unaligned-erms.S:151)
#05: LZ4_streamHC_t_alignment ($SRC/mfbt/lz4/lz4hc.c:830)
#06: LZ4_initStreamHC ($SRC/mfbt/lz4/lz4hc.c:917)
#07: LZ4_createStreamHC ($SRC/mfbt/lz4/lz4hc.c:897)
#08: LZ4F_compressBegin_usingCDict ($SRC/mfbt/lz4/lz4frame.c:621)
#09: LZ4F_compressBegin ($SRC/mfbt/lz4/lz4frame.c:715)
#10: mozilla::Compression::LZ4FrameCompressionContext::BeginCompressing(mozilla::Span<char, 18446744073709551615ul>) ($SRC/mfbt/Compression.cpp:126)
#11: mozilla::scache::StartupCache::WriteToDisk() ($SRC/startupcache/StartupCache.cpp:531)
#12: mozilla::scache::StartupCache::ThreadedWrite(void*) ($SRC/startupcache/StartupCache.cpp:654)
#13: _pt_root ($SRC/nsprpub/pr/src/pthreads/ptthread.c:204)
#14: start_thread (/build/glibc-4WA41p/glibc-2.30/nptl/pthread_create.c:480 (discriminator 6))
#15: __GI___clone (/build/glibc-4WA41p/glibc-2.30/misc/../sysdeps/unix/sysv/linux/x86_64/clone.S:97)
#16: ??? (???:???)

Comment 10

[Daniel Holbert [:dholbert]]

However, I do think it should be more explicit as a MOZ_ASSERT within LoadArchive(). Thoughts?

That seems reasonable to me, yeah.

Comment 11

[Daniel Holbert [:dholbert]]

(So it looks like my original crash was a version of bug 1587107.)

Comment 12

[Dave Townsend [:mossop] (PTO until Aug 21st)]

Can you put a priority on this?

Comment 14

[Alex Thayer [:alexical] (she/her)]

Given that the underlying cause was bug 1587107 which is now fixed, I think it's rather low priority, unless anyone has seen this on recent builds. Nevertheless, I'll try to get a patch up for it shortly. If the assertion changes then that may cause anyone who's not speaking up about it now to say something.

Comment 15

[Alex Thayer [:alexical] (she/her)]

Attachment: Bug 1587112 - Make asserts in StartupCache::LoadArchive explicit r?njn

There is no behavior change here - these asserts were previously being hit
inside the operator+ of RangedPtr, but this makes them explicit.

Comment 16

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/a9ac48966ace
Make asserts in StartupCache::LoadArchive explicit r=njn

Comment 17

[Natalia Csoregi [:nataliaCs]]

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

Comment 18

[Ryan VanderMeulen [:RyanVM]]

Is this something we should consider uplifting to Beta or can this ride Fx72 to release?

Comment 19

[Alex Thayer [:alexical] (she/her)]

This can ride 72. It won't make a difference on anything but debug builds, and there the difference will only be the assert message.