gfxPlatformFontList::Init() is taking 4.75% of startup time on the MainThread on Fenix:
https://irccloud.mozilla.com/file/pwTR5BG0/report.html
(Select FlameGraph, top thread, about in the middle of the graph)
Mostly in FT_New_Face()

Is Fenix using multiple processes, such that this cost is paid by each of them when they launch, or is it just once at browser startup?

Is this an issue on every startup, or are you looking specifically at the first startup after installation (or after clearing all cached data, etc)? At one point for Fennec, we were caching font information in the startupCache, so that only the first startup was expensive, and subsequent startups were a lot faster. So I'm wondering if that mechanism is working in Fenix?

(In reply to Jonathan Kew (:jfkthame) from comment #1)

Is Fenix using multiple processes, such that this cost is paid by each of them when they launch, or is it just once at browser startup?

Multiple processes (1 content process currently); I suspect it's paid by each but my profile only can capture the Main process startup.

Is this an issue on every startup, or are you looking specifically at the first startup after installation (or after clearing all cached data, etc)? At one point for Fennec, we were caching font information in the startupCache, so that only the first startup was expensive, and subsequent startups were a lot faster. So I'm wondering if that mechanism is working in Fenix?

Because when I do a new test I typically push a new version of the app (and uninstall the old one), this may look like a first-install case; I didn't take this capture so it could be either. I'll retest with a second-run of the same build. Hopefully this is being cached.

2nd run, I still see significant time in ::Init loading fonts

In the profile exported to Gecko Profiler shows it's taking circa 220ms (ignore the Running Time; that doesn't include waits on files/etc); you can drag-select the area with hits in the Gecko track at the top to see; if you zoom in too close though it loses the samples).

gfxPlatform

Forgot to NI

the HTML simpleperf profile is here: (mozilla-only sorry): https://drive.google.com/file/d/1w4R0F27HzL4OUxUg83cQHc4d0hhAI4VI/view?usp=sharing

OK, that profile suggests the FontNameCache (see gfxFT2FontList.cpp) is not successfully saving the font list loaded on first run, because if that were working, gfxFT2FontList::AppendFacesFromFontFile should use the cached data and take an early return, without needing to create an FT_Face from each file.

Can you determine whether a FontNameCache is being used at all? It looks like it may be possible to enable logging for the fontInfoLog module, and get some info that way.

Yeah, that looks like a browser that doesn't have a cached list. So that's what I would expect on first run, but subsequent startups should be quite different: instead of "reading font info via FreeType for ..." you ought to see "using cached font info for ...". (I assume this was not a first-run?)

If you're able to run under a debugger, maybe you can confirm whether a FontNameCache is in fact getting created; whether it's getting a valid pointer from mozilla::scache::StartupCache::GetSingleton() in its constructor; whether it finds the "font.cached-list" key in its Init() method; whether its CacheFileInfo() method gets called to store things in it; and whether its destructor actually puts stuff into the cache via mCache->PutBuffer. Something in there isn't working...

(I suppose it could be that within gfxFT2FontList, the FontNameCache is working as expected, but the underlying StartupCache is broken, and so even though we try to cache the font details, they don't get successfully stored. Then each subsequent launch would still have to start from scratch, which is what the above log indicates.)

It was not first run. I can't easily run in a debugger, but I'll add some log messages

Patch I used to follow

If you want to try this with geckoview_example, use:
adb shell "am start -n org.mozilla.geckoview_example/org.mozilla.geckoview_example.GeckoViewActivity --es env0 MOZ_LOG=fontInfoLog:5"

Fenix (untested):
adb shell "am start -n org.mozilla.fenix.debug/org.mozilla.fenix.HomeActivity --es env0 MOZ_LOG=fontInfoLog:5"

Install geckoview_example after doing a fennec build (or after downloading the right artifact from a m-c/etc build):
adb install ./obj-opt/gradle/build/mobile/android/geckoview_example/outputs/apk/withGeckoBinaries/debug/geckoview_example-withGeckoBinaries-debug.apk

I don't see any sign of WillShutdown() in your log, which makes me suspect that although gfxFT2FontList is attempting to store its info in the cache, it's never getting written out.

How does the app quit? Are we doing an orderly shutdown, with XPCOM notifications like "xpcom-will-shutdown" being sent to observers and handled before the platform is finally torn down, or are we short-circuiting all that in the interests of a fast shutdown?

Orderly shutdown on android is... rare if ever I think. The OS unceremoniously kills you

Confirmed with android people - you never/virtually-never get xpcom-will-shutdown/etc

jfkthame - this appears to be saving the data on a 5s timer, but can't read it back. Not sure why.

8040:05-24 21:35:51.807 20165 20187 I Gecko : [Child 20165: Main Thread]: D/fontInfoLog got font list from chrome process: 183 faces in 122 families
8280:05-24 21:35:55.795 20143 20160 I Gecko : [Parent 20143: Main Thread]: D/fontInfoLog Writing FontNameCache:
8281:05-24 21:35:55.796 20143 20160 I Gecko : [Parent 20143: Main Thread]: D/fontInfoLog putting FontNameCache to font.cached-list, length 23092
8282:05-24 21:35:55.796 20143 20160 I Gecko : [Parent 20143: Main Thread]: D/fontInfoLog done
8283:05-24 21:35:55.796 20143 20160 I Gecko : [Parent 20143: Main Thread]: D/fontInfoLog Done with writecache
...
9692:05-24 21:36:20.283 20378 20395 D GeckoThread: env var: MOZ_LOG=fontInfoLog:5
9769:05-24 21:36:21.647 20378 20395 I Gecko : [(null) 20378: Main Thread]: D/fontInfoLog Created FontNameCache
9770:05-24 21:36:21.648 20378 20395 I Gecko : [(null) 20378: Main Thread]: D/fontInfoLog no cache of font.cached-list
9771:05-24 21:36:21.648 20378 20395 I Gecko : [(null) 20378: Main Thread]: D/fontInfoLog reading font info via FreeType for /system/fonts/AndroidClock.ttf

I'm done for now; this patch is kinda hacky, but works. Better would be to find real idle time (not just an mainthread IdleCallback), and save the data from there. OTOH how often will we need to write the data?

I moved the Jar stuff too, since anything on shutdown isn't happening

snorp mentioned we may be purging caches on startup:
https://searchfox.org/mozilla-central/source/mobile/android/geckoview_example/src/main/java/org/mozilla/geckoview_example/GeckoViewActivity.java#131
"it causes problems during development"
I disabled that line, but still it didn't work.

Note that the startupcache has it's own 60s timeout before writing.

Here's a patch to allow logging of StartupCache actions

jonathan - to get it to write, it has to be idle for 60s continuously (or more). I did get it to write finally, and then it didn't find a cache on restart even with purgecaches removed.
Passing the ball to someone.... looks like a startup cache issue. NI to the last few people to land real patches against it.

(In reply to Randell Jesup [:jesup] (needinfo me) from comment #21)

jonathan - to get it to write, it has to be idle for 60s continuously (or more). I did get it to write finally, and then it didn't find a cache on restart even with purgecaches removed.
Passing the ball to someone.... looks like a startup cache issue. NI to the last few people to land real patches against it.

It's not clear what information you are looking for here.

(In reply to Randell Jesup [:jesup] (needinfo me) from comment #18)

OTOH how often will we need to write the data?

Very rarely: we'd expect to write it once after the first startup, and then we only ever need to write it again if the device's set of installed fonts changes, which may happen on an OS upgrade. Aside from that, it's probably almost unheard-of that people modify their installed fonts on an Android device, I guess.

So the code checks on subsequent startups to confirm if the set of files has changed compared to the cached data; if so, we'd need to re-write the data, but in practice this hardly ever happens. (At least, that would be the case if the cache were actually working.)

Given that we don't get the opportunity to write on shutdown, as the code was originally designed to do, maybe we should just take the "safe" option of writing the cache record as soon as we've collected the font list during first launch. That would maximize the chance of actually getting the data written; if we have to wait until we've been idle for 60 seconds, or something like that, we may just get killed instead and lose the data.

Ok, the WIP patch does seem to work to ensure the fonts get written to the cache... it's just that it can take a LONG time for the cache to get written, and if Gecko is killed that won't happen. When it is written, the fonts are loaded from the cache. I haven't verified yet what the impact is, but it should be good.

Probably since the Startup Cache has it's own dirty-data timeout we should simply aggressively write the buffer, or at worst bundle any updates found in one pass and write them. If we really think it's going to cause too much CPU/thrashing, use a much shorter timeout here (1s or les).

My patch pushes dirty data to the StartupCache at the end of font scanning, since the StartupCache has it's own 60s write timer - there's no need to duplicate that here, just avoid thrashing it on every font we find. The destruction-time write check doesn't hurt and is very unlikely/impossible that it will find dirty data, though if it does currently the StartupCache won't flush dirty buffers before the browser exit anyways (that might change)

I tweaked on of the debugs which was problematical. Using the logs I have proof that (if you wait long enough, and aren't using unmodified local (debug) geckoview_example*) it does write the cache, and successfully reads it at startup.

• gve by default in Debug form does --purgecaches

Backed out for build bustages.

Push with failure: https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&resultStatus=testfailed%2Cbusted%2Cexception&classifiedState=unclassified&revision=023c03347e6aa71229914754486b0be2c5db751b&selectedJob=249394408

Failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=249394408&repo=mozilla-inbound&lineNumber=29056

[task 2019-05-31T15:25:09.146Z] 15:25:09 INFO - make[4]: Entering directory '/builds/worker/workspace/build/src/obj-firefox/gfx/thebes'
[task 2019-05-31T15:25:09.152Z] 15:25:09 INFO - /builds/worker/workspace/build/src/sccache/sccache /builds/worker/workspace/build/src/clang/bin/clang++ --target=aarch64-linux-android -o gfxFT2FontList.o -c -flto=thin -I/builds/worker/workspace/build/src/obj-firefox/dist/stl_wrappers -I/builds/worker/workspace/build/src/obj-firefox/dist/system_wrappers -include /builds/worker/workspace/build/src/config/gcc_hidden.h -DNDEBUG=1 -DTRIMMED=1 -DOS_POSIX=1 -DOS_LINUX=1 -DMOZ_ENABLE_FREETYPE -DGRAPHITE2_STATIC -DSTATIC_EXPORTABLE_JS_API -DMOZ_HAS_MOZGLUE -DMOZILLA_INTERNAL_API -DIMPL_LIBXUL -I/builds/worker/workspace/build/src/gfx/thebes -I/builds/worker/workspace/build/src/obj-firefox/gfx/thebes -I/builds/worker/workspace/build/src/obj-firefox/ipc/ipdl/ipdlheaders -I/builds/worker/workspace/build/src/ipc/chromium/src -I/builds/worker/workspace/build/src/ipc/glue -I/builds/worker/workspace/build/src/dom/base -I/builds/worker/workspace/build/src/dom/xml -I/builds/worker/workspace/build/src/gfx/skia -I/builds/worker/workspace/build/src/gfx/skia/skia/include/config -I/builds/worker/workspace/build/src/gfx/skia/skia/include/core -I/builds/worker/workspace/build/src/gfx/skia/skia/include/docs -I/builds/worker/workspace/build/src/gfx/skia/skia/include/gpu -I/builds/worker/workspace/build/src/gfx/skia/skia/include/utils -I/builds/worker/workspace/build/src/obj-firefox/dist/include -I/builds/worker/workspace/build/src/obj-firefox/dist/include/nspr -I/builds/worker/workspace/build/src/obj-firefox/dist/include/nss -fPIC -DMOZILLA_CLIENT -include /builds/worker/workspace/build/src/obj-firefox/mozilla-config.h -Qunused-arguments -isystem /builds/worker/workspace/build/src/android-ndk/sysroot/usr/include/aarch64-linux-android -isystem /builds/worker/workspace/build/src/android-ndk/sysroot/usr/include -gcc-toolchain /builds/worker/workspace/build/src/android-ndk/toolchains/aarch64-linux-android-4.9/prebuilt/linux-x86_64 -D__ANDROID_API_=21 -fstack-protector-strong -Qunused-arguments -Wall -Wbitfield-enum-conversion -Wempty-body -Wignored-qualifiers -Woverloaded-virtual -Wpointer-arith -Wshadow-field-in-constructor-modified -Wsign-compare -Wtype-limits -Wunreachable-code -Wunreachable-code-return -Wwrite-strings -Wno-invalid-offsetof -Wclass-varargs -Wfloat-overflow-conversion -Wfloat-zero-conversion -Wloop-analysis -Wc++1z-compat -Wc++2a-compat -Wcomma -Wimplicit-fallthrough -Werror=non-literal-null-conversion -Wstring-conversion -Wtautological-overlap-compare -Wtautological-unsigned-enum-zero-compare -Wtautological-unsigned-zero-compare -Wno-inline-new-delete -Wno-error=deprecated-declarations -Wno-error=array-bounds -Wno-error=backend-plugin -Wno-error=return-std-move -Wno-error=atomic-alignment -Wformat -Wformat-security -Wno-gnu-zero-variadic-macro-arguments -Wno-unknown-warning-option -Wno-return-type-c-linkage -fno-sized-deallocation -fno-short-enums -fno-exceptions -stdlib=libstdc++ -I/builds/worker/workspace/build/src/android-ndk/sources/cxx-stl/llvm-libc++/include -I/builds/worker/workspace/build/src/android-ndk/sources/android/support/include -I/builds/worker/workspace/build/src/android-ndk/sources/cxx-stl/llvm-libc++abi/include -fstack-protector-strong -fno-exceptions -fno-strict-aliasing -fno-rtti -ffunction-sections -fdata-sections -fno-exceptions -fno-math-errno -pipe -g -Xclang -load -Xclang /builds/worker/workspace/build/src/obj-firefox/build/clang-plugin/libclang-plugin.so -Xclang -add-plugin -Xclang moz-check -Oz -fno-omit-frame-pointer -funwind-tables -Werror -I/builds/worker/workspace/build/src/obj-firefox/dist/include/cairo -I/builds/worker/workspace/build/src/obj-firefox/dist/include/cairo -I/builds/worker/workspace/build/src/modules/freetype2/include -MD -MP -MF .deps/gfxFT2FontList.o.pp /builds/worker/workspace/build/src/gfx/thebes/gfxFT2FontList.cpp
[task 2019-05-31T15:25:09.153Z] 15:25:09 ERROR - /builds/worker/workspace/build/src/gfx/thebes/gfxFT2FontList.cpp:1363:48: error: format specifies type 'unsigned int' but the argument has type 'size_t' (aka 'unsigned long') [-Werror,-Wformat]
[task 2019-05-31T15:25:09.153Z] 15:25:09 INFO - LOG(("WriteCache: putting Jar, length %u", bufSize));
[task 2019-05-31T15:25:09.153Z] 15:25:09 INFO - ~~ ^~~~~~~
[task 2019-05-31T15:25:09.153Z] 15:25:09 INFO - %zu
[task 2019-05-31T15:25:09.154Z] 15:25:09 INFO - /builds/worker/workspace/build/src/gfx/thebes/gfxFT2FontList.cpp:62:67: note: expanded from macro 'LOG'
[task 2019-05-31T15:25:09.154Z] 15:25:09 INFO - #define LOG(args) MOZ_LOG(sFontInfoLog, mozilla::LogLevel::Debug, args)
[task 2019-05-31T15:25:09.154Z] 15:25:09 INFO - ^~~~
[task 2019-05-31T15:25:09.154Z] 15:25:09 INFO - /builds/worker/workspace/build/src/obj-firefox/dist/include/mozilla/Logging.h:267:56: note: expanded from macro 'MOZ_LOG'
[task 2019-05-31T15:25:09.155Z] 15:25:09 INFO - MOZ_LOG_EXPAND_ARGS args);
[task 2019-05-31T15:25:09.155Z] 15:25:09 INFO - ^~~~~
[task 2019-05-31T15:25:09.155Z] 15:25:09 INFO - /builds/worker/workspace/build/src/obj-firefox/dist/include/mozilla/Logging.h:209:34: note: expanded from macro 'MOZ_LOG_EXPAND_ARGS'
[task 2019-05-31T15:25:09.155Z] 15:25:09 INFO - #define MOZ_LOG_EXPAND_ARGS(...) VA_ARGS
[task 2019-05-31T15:25:09.155Z] 15:25:09 INFO - ^~~~~~~~~~~
[task 2019-05-31T15:25:09.155Z] 15:25:09 INFO - 1 error generated.
[task 2019-05-31T15:25:09.155Z] 15:25:09 INFO - /builds/worker/workspace/build/src/config/rules.mk:810: recipe for target 'gfxFT2FontList.o' failed
[task 2019-05-31T15:25:09.155Z] 15:25:09 ERROR - make[4]: *** [gfxFT2FontList.o] Error 1
[task 2019-05-31T15:25:09.155Z] 15:25:09 INFO - make[4]: Leaving directory '/builds/worker/workspace/build/src/obj-firefox/gfx/thebes'
[task 2019-05-31T15:25:09.156Z] 15:25:09 INFO - /builds/worker/workspace/build/src/config/recurse.mk:74: recipe for target 'gfx/thebes/target' failed
[task 2019-05-31T15:25:09.156Z] 15:25:09 ERROR - make[3]: *** [gfx/thebes/target] Error 2
[task 2019-05-31T15:25:09.156Z] 15:25:09 INFO - make[3]: *** Waiting for unfinished jobs....
[task 2019-05-31T15:25:09.172Z] 15:25:09 INFO - make[4]: Entering directory '/builds/worker/workspace/build/src/obj-firefox/dom/canvas'
[task 2019-05-31T15:25:09.173Z] 15:25:09 INFO - dom/canvas/MurmurHash3.o
[task 2019-05-31T15:25:09.173Z] 15:25:09 INFO - make[4]: Leaving directory '/builds/worker/workspace/build/src/obj-firefox/dom/canvas'
[task 2019-05-31T15:25:09.394Z] 15:25:09 INFO - make[4]: Entering directory '/builds/worker/workspace/build/src/obj-firefox/dom/canvas'
[task 2019-05-31T15:25:09.394Z] 15:25:09 INFO - /builds/worker/workspace/build/src/sccache/sccache /builds/worker/workspace/build/src/clang/bin/clang++ --target=aarch64-linux-android -o MurmurHash3.o -c -flto=thin -I/builds/worker/workspace/build/src/obj-firefox/dist/stl_wrappers -I/builds/worker/workspace/build/src/obj-firefox/dist/system_wrappers -include /builds/worker/workspace/build/src/config/gcc_hidden.h -DNDEBUG=1 -DTRIMMED=1 -DOS_POSIX=1 -DOS_LINUX=1 -DSTATIC_EXPORTABLE_JS_API -DMOZ_HAS_MOZGLUE -DMOZILLA_INTERNAL_API -DIMPL_LIBXUL -I/builds/worker/workspace/build/src/dom/canvas -I/builds/worker/workspace/build/src/obj-firefox/dom/canvas -I/builds/worker/workspace/build/src/js/xpconnect/wrappers -I/builds/worker/workspace/build/src/obj-firefox/ipc/ipdl/ipdlheaders -I/builds/worker/workspace/build/src/ipc/chromium/src -I/builds/worker/workspace/build/src/ipc/glue -I/builds/worker/workspace/build/src/dom/base -I/builds/worker/workspace/build/src/dom/html -I/builds/worker/workspace/build/src/dom/svg -I/builds/worker/workspace/build/src/dom/workers -I/builds/worker/workspace/build/src/dom/xul -I/builds/worker/workspace/build/src/gfx/angle/checkout/include -I/builds/worker/workspace/build/src/gfx/gl -I/builds/worker/workspace/build/src/image -I/builds/worker/workspace/build/src/js/xpconnect/src -I/builds/worker/workspace/build/src/layout/generic -I/builds/worker/workspace/build/src/layout/style -I/builds/worker/workspace/build/src/layout/xul -I/builds/worker/workspace/build/src/media/libyuv/libyuv/include -I/builds/worker/workspace/build/src/gfx/skia -I/builds/worker/workspace/build/src/gfx/skia/skia/include/config -I/builds/worker/workspace/build/src/gfx/skia/skia/include/core -I/builds/worker/workspace/build/src/gfx/skia/skia/include/docs -I/builds/worker/workspace/build/src/gfx/skia/skia/include/gpu -I/builds/worker/workspace/build/src/gfx/skia/skia/include/utils -I/builds/worker/workspace/build/src/obj-firefox/dist/include -I/builds/worker/workspace/build/src/obj-firefox/dist/include/nspr -I/builds/worker/workspace/build/src/obj-firefox/dist/include/nss -fPIC -DMOZILLA_CLIENT -include /builds/worker/workspace/build/src/obj-firefox/mozilla-config.h -Qunused-arguments -isystem /builds/worker/workspace/build/src/android-ndk/sysroot/usr/include/aarch64-linux-android -isystem /builds/worker/workspace/build/src/android-ndk/sysroot/usr/include -gcc-toolchain /builds/worker/workspace/build/src/android-ndk/toolchains/aarch64-linux-android-4.9/prebuilt/linux-x86_64 -D__ANDROID_API=21 -fstack-protector-strong -Qunused-arguments -Wall -Wbitfield-enum-conversion -Wempty-body -Wignored-qualifiers -Woverloaded-virtual -Wpointer-arith -Wshadow-field-in-constructor-modified -Wsign-compare -Wtype-limits -Wunreachable-code -Wunreachable-code-return -Wwrite-strings -Wno-invalid-offsetof -Wclass-varargs -Wfloat-overflow-conversion -Wfloat-zero-conversion -Wloop-analysis -Wc++1z-compat -Wc++2a-compat -Wcomma -Wimplicit-fallthrough -Werror=non-literal-null-conversion -Wstring-conversion -Wtautological-overlap-compare -Wtautological-unsigned-enum-zero-compare -Wtautological-unsigned-zero-compare -Wno-inline-new-delete -Wno-error=deprecated-declarations -Wno-error=array-bounds -Wno-error=backend-plugin -Wno-error=return-std-move -Wno-error=atomic-alignment -Wformat -Wformat-security -Wno-gnu-zero-variadic-macro-arguments -Wno-unknown-warning-option -Wno-return-type-c-linkage -fno-sized-deallocation -fno-short-enums -fno-exceptions -stdlib=libstdc++ -I/builds/worker/workspace/build/src/android-ndk/sources/cxx-stl/llvm-libc++/include -I/builds/worker/workspace/build/src/android-ndk/sources/android/support/include -I/builds/worker/workspace/build/src/android-ndk/sources/cxx-stl/llvm-libc++abi/include -fstack-protector-strong -fno-exceptions -fno-strict-aliasing -fno-rtti -ffunction-sections -fdata-sections -fno-exceptions -fno-math-errno -pipe -g -Xclang -load -Xclang /builds/worker/workspace/build/src/obj-firefox/build/clang-plugin/libclang-plugin.so -Xclang -add-plugin -Xclang moz-check -Oz -fno-omit-frame-pointer -funwind-tables -Werror -I/builds/worker/workspace/build/src/obj-firefox/dist/include/cairo -I/builds/worker/workspace/build/src/obj-firefox/dist/include/cairo -Wno-error=shadow -Wno-missing-braces -Werror=implicit-int-conversion -MD -MP -MF .deps/MurmurHash3.o.pp -Wno-implicit-fallthrough /builds/worker/workspace/build/src/dom/canvas/MurmurHash3.cpp
[task 2019-05-31T15:25:09.394Z] 15:25:09 INFO - make[4]: Leaving directory '/builds/worker/workspace/build/src/obj-firefox/dom/canvas'
[task 2019-05-31T15:25:09.397Z] 15:25:09 INFO - make[4]: Entering directory '/builds/worker/workspace/build/src/obj-firefox/dom/canvas'
[task 2019-05-31T15:25:09.397Z] 15:25:09 INFO - dom/canvas/Unified_cpp_dom_canvas0.o
[task 2019-05-31T15:25:09.397Z] 15:25:09 INFO - make[4]: Leaving directory '/builds/worker/workspace/build/src/obj-firefox/dom/canvas'
[task 2019-05-31T15:25:09.676Z] 15:25:09 INFO - make[4]: Entering directory '/builds/worker/workspace/build/src/obj-firefox/dom/canvas'
[task 2019-05-31T15:25:09.680Z] 15:25:09 INFO - /builds/worker/workspace/build/src/sccache/sccache /builds/worker/workspace/build/src/clang/bin/clang++ --target=aarch64-linux-android -o ImageUtils.o -c -flto=thin -I/builds/worker/workspace/build/src/obj-firefox/dist/stl_wrappers -I/builds/worker/workspace/build/src/obj-firefox/dist/system_wrappers -include /builds/worker/workspace/build/src/config/gcc_hidden.h -DNDEBUG=1 -DTRIMMED=1 -DOS_POSIX=1 -DOS_LINUX=1 -DSTATIC_EXPORTABLE_JS_API -DMOZ_HAS_MOZGLUE -DMOZILLA_INTERNAL_API -DIMPL_LIBXUL -I/builds/worker/workspace/build/src/dom/canvas -I/builds/worker/workspace/build/src/obj-firefox/dom/canvas -I/builds/worker/workspace/build/src/js/xpconnect/wrappers -I/builds/worker/workspace/build/src/obj-firefox/ipc/ipdl/ipdlheaders -I/builds/worker/workspace/build/src/ipc/chromium/src -I/builds/worker/workspace/build/src/ipc/glue -I/builds/worker/workspace/build/src/dom/base -I/builds/worker/workspace/build/src/dom/html -I/builds/worker/workspace/build/src/dom/svg -I/builds/worker/workspace/build/src/dom/workers -I/builds/worker/workspace/build/src/dom/xul -I/builds/worker/workspace/build/src/gfx/angle/checkout/include -I/builds/worker/workspace/build/src/gfx/gl -I/builds/worker/workspace/build/src/image -I/builds/worker/workspace/build/src/js/xpconnect/src -I/builds/worker/workspace/build/src/layout/generic -I/builds/worker/workspace/build/src/layout/style -I/builds/worker/workspace/build/src/layout/xul -I/builds/worker/workspace/build/src/media/libyuv/libyuv/include -I/builds/worker/workspace/build/src/gfx/skia -I/builds/worker/workspace/build/src/gfx/skia/skia/include/config -I/builds/worker/workspace/build/src/gfx/skia/skia/include/core -I/builds/worker/workspace/build/src/gfx/skia/skia/include/docs -I/builds/worker/workspace/build/src/gfx/skia/skia/include/gpu -I/builds/worker/workspace/build/src/gfx/skia/skia/include/utils -I/builds/worker/workspace/build/src/obj-firefox/dist/include -I/builds/worker/workspace/build/src/obj-firefox/dist/include/nspr -I/builds/worker/workspace/build/src/obj-firefox/dist/include/nss -fPIC -DMOZILLA_CLIENT -include /builds/worker/workspace/build/src/obj-firefox/mozilla-config.h -Qunused-arguments -isystem /builds/worker/workspace/build/src/android-ndk/sysroot/usr/include/aarch64-linux-android -isystem /builds/worker/workspace/build/src/android-ndk/sysroot/usr/include -gcc-toolchain /builds/worker/workspace/build/src/android-ndk/toolchains/aarch64-linux-android-4.9/prebuilt/linux-x86_64 -D__ANDROID_API_=21 -fstack-protector-strong -Qunused-arguments -Wall -Wbitfield-enum-conversion -Wempty-body -Wignored-qualifiers -Woverloaded-virtual -Wpointer-arith -Wshadow-field-in-constructor-modified -Wsign-compare -Wtype-limits -Wunreachable-code -Wunreachable-code-return -Wwrite-strings -Wno-invalid-offsetof -Wclass-varargs -Wfloat-overflow-conversion -Wfloat-zero-conversion -Wloop-analysis -Wc++1z-compat -Wc++2a-compat -Wcomma -Wimplicit-fallthrough -Werror=non-literal-null-conversion -Wstring-conversion -Wtautological-overlap-compare -Wtautological-unsigned-enum-zero-compare -Wtautological-unsigned-zero-compare -Wno-inline-new-delete -Wno-error=deprecated-declarations -Wno-error=array-bounds -Wno-error=backend-plugin -Wno-error=return-std-move -Wno-error=atomic-alignment -Wformat -Wformat-security -Wno-gnu-zero-variadic-macro-arguments -Wno-unknown-warning-option -Wno-return-type-c-linkage -fno-sized-deallocation -fno-short-enums -fno-exceptions -stdlib=libstdc++ -I/builds/worker/workspace/build/src/android-ndk/sources/cxx-stl/llvm-libc++/include -I/builds/worker/workspace/build/src/android-ndk/sources/android/support/include -I/builds/worker/workspace/build/src/android-ndk/sources/cxx-stl/llvm-libc++abi/include -fstack-protector-strong -fno-exceptions -fno-strict-aliasing -fno-rtti -ffunction-sections -fdata-sections -fno-exceptions -fno-math-errno -pipe -g -Xclang -load -Xclang /builds/worker/workspace/build/src/obj-firefox/build/clang-plugin/libclang-plugin.so -Xclang -add-plugin -Xclang moz-check -Oz -fno-omit-frame-pointer -funwind-tables -Werror -I/builds/worker/workspace/build/src/obj-firefox/dist/include/cairo -I/builds/worker/workspace/build/src/obj-firefox/dist/include/cairo -Wno-error=shadow -Wno-missing-braces -Werror=implicit-int-conversion -MD -MP -MF .deps/ImageUtils.o.pp /builds/worker/workspace/build/src/dom/canvas/ImageUtils.cpp
[task 2019-05-31T15:25:09.680Z] 15:25:09 INFO - make[4]: Leaving directory '/builds/worker/workspace/build/src/obj-firefox/dom/canvas'
[task 2019-05-31T15:25:09.681Z] 15:25:09 INFO - make[4]: Entering directory '/builds/worker/workspace/build/src/obj-firefox/dom/canvas'
[task 2019-05-31T15:25:09.681Z] 15:25:09 INFO - dom/canvas/Unified_cpp_dom_canvas1.o
[task 2019-05-31T15:25:09.681Z] 15:25:09 INFO - make[4]: Leaving directory '/builds/worker/workspace/build/src/obj-firefox/dom/canvas'
[task 2019-05-31T15:25:10.405Z] 15:25:10 INFO - make[4]: Entering directory '/builds/worker/workspace/build/src/obj-firefox/mfbt/tests'

Backout: https://hg.mozilla.org/integration/mozilla-inbound/rev/068c41e639db5d9d2adfd095c11db924893da876

https://hg.mozilla.org/mozilla-central/rev/798777922fe7

68=wontfix because it's getting a little late in the 68 Beta cycle to uplift perf optimizations. Fenix MVP will ship GV 68 Beta, but will quickly move to GV 69 (where this bug is fixed).

Does this fix benefit Fennec, which doesn't use e10s? Fennec 68 will be maintained in the ESR 68 channel until mid-2020.

I believe this is broken in fennec (I'll have to do another build to verify), and that this patch should fix it in fennec.
This would advocate for uplifting to 68 (once verified)

(In reply to Randell Jesup [:jesup] (needinfo me) from comment #33)

I believe this is broken in fennec (I'll have to do another build to verify), and that this patch should fix it in fennec.
This would advocate for uplifting to 68 (once verified)

Thanks for the heads up! I didn't realize this fixed a bug in Fennec and was more than just an optimization. We will move all Fennec users to the ESR 68 channel, so we need to uplift all Fennec fixes to 68.

Ok, I tried fennec with the landed patches - fonts get cached and loaded from cache. Fennec with logs added, but without the write-cache changes: it appears the fonts never get written to cache - as I'd expect, as it would only happen on xpcom shutdown, and the startupcache code doesn't flush on shutdown (and has a 60s timer after data is changed before writing). and Fennec likely never sees an xpcom shutdown.

Comment on attachment 9068898 [details]
Bug 1554183: Save font data to startup cache immediately r=jfkthame

Beta/Release Uplift Approval Request

• User impact if declined: Slower startup in geckoview/fenix and fennec
• Is this code covered by automated tests?: No
• Has the fix been verified in Nightly?: Yes
• Needs manual test from QE?: No
• If yes, steps to reproduce:
• List of other uplifts needed: None
• Risk to taking this patch: Low
• Why is the change risky/not risky? (and alternatives if risky): Adds logs, only changes when font data is submitted to the StartupCache - the data itself isn't changed. The only risk would be that the code for reading in (and deciding on the validity of) the font cache may not have been tested in a long time.
• String changes made/needed: none

I'm wary of taking this mid beta cycle since it sounds like this isn't a regression.

Note: we may still want it for 68ESR for fennec, though that can probably wait some and uplift after we have some time with it in Fenix/GVE. Can't mark 68ESR-affected yet.

Randell, did you want to nominate this for ESR68 uplift? FWIW, I'm still on the fence about actually accepting it :)

Comment on attachment 9068898 [details]
Bug 1554183: Save font data to startup cache immediately r=jfkthame

ESR Uplift Approval Request

• If this is not a sec:{high,crit} bug, please state case for ESR consideration: Significant 200-400ms startup performance improvement
• User impact if declined: Slow startup for the rest of the life of Fennec
• Fix Landed on Version:
• Risk to taking this patch: Low
• Why is the change risky/not risky? (and alternatives if risky): Simple-ish change; in use by GV. Fixes something that must have worked at some point. Adds logs, only changes when font data is submitted to the StartupCache - the data itself isn't changed. The only risk would be that the code for reading in (and deciding on the validity of) the font cache may not have been tested in a long time; however it has now been in GV for almost 2 months.
• String or UUID changes made by this patch: none

Comment on attachment 9068898 [details]
Bug 1554183: Save font data to startup cache immediately r=jfkthame

Fun fact, GV69 hasn't shipped to anything of note at this point and effectively hasn't gotten any real world testing to date. I don't think we want to take this for Fennec 68.1 at this point since we're already halfway through the cycle. Maybe we can revisit at the start of the 68.2 cycle when it'll have more time to bake.

This is fixed for geckoview. fennec has lived with this bug so far, I think it can end its life with it.