We need to know whether we're loading an external URL much earlier than onWindowFocusChanged. But we still need to know our passed URL and whether it's external in onWindowFocusChanged. So let's try to factor out the computations a little bit so we can share code. I'm not completely happy with how this turned out; I'm open to better ways of structuring this.

Bug 903553 discusses at some length just how bad JSON parsing in Java is. With a session of moderate size, we spend a significant amount of startup time (~200ms) parsing the sessionstore file. I don't think rewriting the session store file format is a good idea, and trying to avoid some of the JSON file parsing and serialization (e.g. not serializing into JSON for sending things into Gecko) would be...ugly. If we can't avoid the work, how about we try to move it out of the critical path by parsing on a background thread? Traces indicate that there's a bunch of free time on the background thread. At the very least, the slow bits of reading the IO can be overlapped with other main thread computation and (on dual-core devices) we can spin doing JSON ops while we're on the main thread too. Performance numbers coming in the next patch, which moves all of this even earlier.

Now that we're parsing on a background thread, why don't we try moving the parsing a bit earlier so that we can try and ensure that we don't collide with other things we were already doing on the background thread? I tested this patch series on a Galaxy Nexus; we easily win several hundred ms of startup time by doing this. I don't have any single core devices to test this on; suggestions for such beasts appreciated.

Chris, if you wanted to benchmark this with your robocop setup, that'd be appreciated. If you don't, then at least you're aware of the bug, so ni?'ing you.

Can we just not read the JSON here? We're just reading this to find a few very specific things about that tabs: http://mxr.mozilla.org/mozilla-central/source/mobile/android/base/GeckoApp.java#1619 We can pretty easily put that into some SharedPrefs that we save in onPause and pull out only when we're restoring session?

(In reply to Nathan Froyd (:froydnj) from comment #4) > Chris, if you wanted to benchmark this with your robocop setup, that'd be > appreciated. If you don't, then at least you're aware of the bug, so > ni?'ing you. Roger. I'll benchmark this and get back to you.

(In reply to Wesley Johnston (:wesj) from comment #5) > Can we just not read the JSON here? We're just reading this to find a few > very specific things about that tabs: > > http://mxr.mozilla.org/mozilla-central/source/mobile/android/base/GeckoApp. > java#1619 > > We can pretty easily put that into some SharedPrefs that we save in onPause > and pull out only when we're restoring session? I'd rather not have data in SharedPrefs (which I hate in general) and the JSON file. One place of truth feels right.

https://www.dropbox.com/s/pnb6fs7bpw5lsxu/FennecStartupLog.trace Here's a startup profile using a single tab with session restore and the patches here. This change hasn't really made it any faster, we just now do it on the backrground thread. (As expected, I suppose). This still sucks very badly for single-core phones.

(In reply to Chris Kitching [:ckitching] from comment #8) > https://www.dropbox.com/s/pnb6fs7bpw5lsxu/FennecStartupLog.trace > > Here's a startup profile using a single tab with session restore and the > patches here. > > This change hasn't really made it any faster, we just now do it on the > backrground thread. (As expected, I suppose). > This still sucks very badly for single-core phones. OK, that is actually consistent with the numbers I was seeing from startup traces. But when I went and benchmarked with the startup numbers in about:telemetry, I was consistently seeing wins. The benchmarking with about:telemetry is tedious (though maybe there's some way to get the numbers from robocop), but I felt much better about the rightness of the universe after looking at the numbers there.

(In reply to Nathan Froyd (:froydnj) from comment #9) > OK, that is actually consistent with the numbers I was seeing from startup > traces. But when I went and benchmarked with the startup numbers in > about:telemetry, I was consistently seeing wins. The benchmarking with > about:telemetry is tedious (though maybe there's some way to get the numbers > from robocop), but I felt much better about the rightness of the universe > after looking at the numbers there. You feel much better about the rightness of the universe by selecting only data which support your hypothesis? :P And yes, this seems about what we expect - some performance improvement on multi-core devices, no real change on single-core devices. Also, no real change in total CPU time - just the concurrency has increased. This is a useful patch, but it's not sufficient to make this problem go away. It mitigates it somewhat on more high-end devices (Where the problem was less present to start with anyway).

(In reply to Chris Kitching [:ckitching] from comment #10) > (In reply to Nathan Froyd (:froydnj) from comment #9) > > OK, that is actually consistent with the numbers I was seeing from startup > > traces. But when I went and benchmarked with the startup numbers in > > about:telemetry, I was consistently seeing wins. The benchmarking with > > about:telemetry is tedious (though maybe there's some way to get the numbers > > from robocop), but I felt much better about the rightness of the universe > > after looking at the numbers there. > > You feel much better about the rightness of the universe by selecting only > data which support your hypothesis? :P Somewhat. :p It's certainly strange that the tracing profiler shows little to no speedup, whereas a different method of measuring time shows significant speedups. Somebody's gotta be wrong... > And yes, this seems about what we expect - some performance improvement on > multi-core devices, no real change on single-core devices. Also, no real > change in total CPU time - just the concurrency has increased. > This is a useful patch, but it's not sufficient to make this problem go > away. It mitigates it somewhat on more high-end devices (Where the problem > was less present to start with anyway). Agreed. I don't, however, see a lot of ways to improve it generally. Restoring the tabs (for a small session of six tabs, with < 2K of session restore data!) takes ~190ms on a Galaxy Nexus: - 87ms to read the session file; - 44ms to parse; - 58ms to stringify JSON. The first part is basically all Java I/O. Can't do much about that. The second part is likewise fairly constrained. More than half of that is allocating JSON objects. The rest of it is spent in Tabs.loadUrl, which is doing more JSON stuff. I tried making Tabs.loadUrl more Javaish yesterday and it didn't seem to help (then again, Tabs.loadUrl takes about 11ms total, so...). The second and third parts could possibly be sped up by using a faster JSON library.

Comment on attachment 790279 [details] [diff] [review] part 2 - move sessionstore loading onto the background thread Review of attachment 790279 [details] [diff] [review]: ----------------------------------------------------------------- ::: mobile/android/base/GeckoApp.java @@ +1297,5 @@ > > + mSessionLoader = new Runnable() { > + @Override > + public void run() { > + synchronized(this) { Just making run() a synchronized method has the same effect. @@ +1455,5 @@ > > initializeChrome(); > > + // Wait for the session loader to finish and send the data to Gecko. > + synchronized(mSessionLoader) { I think there's a race here, albeit an unlikely one. The synchronization in the session loader runnable happens on a separate thread, so there's no guarantee about the execution order, even though the runnable has *probably* run already since it's created in onCreate(). Have you tried adding logging right before this, and at the beginning/end of the runnable? I'm curious to know a) how long the runnable is taking, and b) whether (and how long) this block actually ends up waiting.

(In reply to Nathan Froyd (:froydnj) from comment #11) > The second and third parts could possibly be sped up by using a faster JSON > library. And the only sane way to do that is to go native, as outlined in the other bug. Joy. I'll finish native encode at some point.. I got native decode sort of working, although it broke all the unit tests and it's not clear how to debug segfaults on try which don't happen locally.

(In reply to Brian Nicholson (:bnicholson) from comment #12) > Comment on attachment 790279 [details] [diff] [review] > part 2 - move sessionstore loading onto the background thread > > Review of attachment 790279 [details] [diff] [review]: > ----------------------------------------------------------------- > > ::: mobile/android/base/GeckoApp.java > @@ +1297,5 @@ > > > > + mSessionLoader = new Runnable() { > > + @Override > > + public void run() { > > + synchronized(this) { > > Just making run() a synchronized method has the same effect. Indeed. > @@ +1455,5 @@ > > > > initializeChrome(); > > > > + // Wait for the session loader to finish and send the data to Gecko. > > + synchronized(mSessionLoader) { > > I think there's a race here, albeit an unlikely one. The synchronization in > the session loader runnable happens on a separate thread, so there's no > guarantee about the execution order, even though the runnable has *probably* > run already since it's created in onCreate(). Ooo...good point. That should be fixed, because it would come back to bite us. > Have you tried adding logging right before this, and at the beginning/end of > the runnable? I'm curious to know a) how long the runnable is taking, and b) > whether (and how long) this block actually ends up waiting. The runnable should take ~200ms on a Galaxy Nexus; at least that's about what it was taking before this patch series. I can check to see how long that block winds up waiting. (In reply to Chris Kitching [:ckitching] from comment #13) > (In reply to Nathan Froyd (:froydnj) from comment #11) > > The second and third parts could possibly be sped up by using a faster JSON > > library. > > And the only sane way to do that is to go native, as outlined in the other > bug. After having dealt with JNI, I don't know that I'd call that "sane"... > Joy. I'll finish native encode at some point.. I got native decode sort of > working, although it broke all the unit tests and it's not clear how to > debug segfaults on try which don't happen locally. Usually that means there's some sort of race (not necessarily a bug, just different event handling orders) or you have some uninitialized memory somewhere.

(In reply to Nathan Froyd (:froydnj) from comment #14) > After having dealt with JNI, I don't know that I'd call that "sane"... I LIKE the JNI. Plus, I've spent the last few days working on bug 794981, so I've had lots of recent practice. Plus I once used it to implement an IPC scheme between PHP and Java using POSIX shared memory segments. That's in no way sane. Everyone else seems highly sane after that. :P > Usually that means there's some sort of race (not necessarily a bug, just > different event handling orders) or you have some uninitialized memory > somewhere. I see. That's both useful and unuseful at the same time. :P

Comment on attachment 790280 [details] [diff] [review] part 2b - try starting session restore a little earlier Review of attachment 790280 [details] [diff] [review]: ----------------------------------------------------------------- I'd point to mfinkle for review here, and it looks like he's already redirected to brian

Comment on attachment 790276 [details] [diff] [review] part 1 - factor out computations for determining what URL we were invoked with Review of attachment 790276 [details] [diff] [review]: ----------------------------------------------------------------- r=me, with nits changed ::: mobile/android/base/GeckoApp.java @@ +1372,5 @@ > Tabs.getInstance().loadUrl(url, flags); > } > } > > + private String intentURI() { I'd prefer you pass in the Intent here. @@ +1383,5 @@ > + > + return passedUri; > + } > + > + private boolean invokedWithExternalURL() { and I'd prefer you pass in the passedUri here

Comment on attachment 790276 [details] [diff] [review] part 1 - factor out computations for determining what URL we were invoked with Review of attachment 790276 [details] [diff] [review]: ----------------------------------------------------------------- ::: mobile/android/base/GeckoApp.java @@ +1372,5 @@ > Tabs.getInstance().loadUrl(url, flags); > } > } > > + private String intentURI() { nit: Following Java getter convention, this should be getIntentURI (or getIntentUri).

Comment on attachment 790279 [details] [diff] [review] part 2 - move sessionstore loading onto the background thread Review of attachment 790279 [details] [diff] [review]: ----------------------------------------------------------------- r- for the race mentioned in comment 12.

Comment on attachment 790279 [details] [diff] [review] part 2 - move sessionstore loading onto the background thread >diff --git a/mobile/android/base/GeckoApp.java b/mobile/android/base/GeckoApp.java >+ ThreadUtils.postToBackgroundThread(mSessionLoader); Your comment about doing this earlier to avoid running into other background thread work made me realize something: This could be run on any thread, not "the" background thread. You have no way to know this, so I am just pointing it out. We started using ThreadUtils.xXXBackgroundThread for database related work. We wanted to serialize things coming and going into the databases. We were getting weird corruptions. But I digress! Since this code has no database interactions, you can run it on any background thread. We had talked about adding a ThreadUtils.xXXDatabaseThread, which used only a single thread, and change ThreadUtils.xXXBackgroundThread to use a pool of threads (for non-database related work).

From margaret's comments in bug 1266339, it would be nice to finally move the session restore I/O off the main thread.

Android Studio doesn't recognise our version guards and is consequentially always showing two errors in GeckoApp, which makes it more difficult to spot when you've introduced an actual error. Review commit: https://reviewboard.mozilla.org/r/52930/diff/#index_header See other reviews: https://reviewboard.mozilla.org/r/52930/

For session data parsing, we need to know whether we were invoked with an external URL or not. Since we want to move session data parsing forward to an earlier point in time, but also continue needing that external URL info during initialize() as well, we'll factor out those calculations into their own functions which can then be called from both places. Review commit: https://reviewboard.mozilla.org/r/52932/diff/#index_header See other reviews: https://reviewboard.mozilla.org/r/52932/

Parsing the session store JSON data to restore the last session's tabs is both - computationally relatively expensive - involving disk I/O therefore, we shouldn't be doing it on the main thread. To make sure the session data is actually ready, subsequent code running from a different thread that needs to access it (sending the session restore string to Gecko, the Recent Tabs panel reading the "tabs from last time") waits on a CountDownLatch which is released once the relevant data has been processed. Review commit: https://reviewboard.mozilla.org/r/52934/diff/#index_header See other reviews: https://reviewboard.mozilla.org/r/52934/

Since we're doing this in background now anyway, we might as well start doing it slightly earlier and run in parallel to parts of the layout setup, so we don't bump immediately into the the following, preexisting bit of background initialisation. Review commit: https://reviewboard.mozilla.org/r/52936/diff/#index_header See other reviews: https://reviewboard.mozilla.org/r/52936/

Check the state of the CountDownLatches to see whether they've been already released when calling await(). Review commit: https://reviewboard.mozilla.org/r/52938/diff/#index_header See other reviews: https://reviewboard.mozilla.org/r/52938/

This is basically a resurrected version of Nathan's patches - the major difference is that I've opted for using CountDownLatches to wait for the background thread session data processing to have finished. As it currently stands, this bug depends on bug 1266339, although it's not a hard dependency - it's just that I'd have to rewrite the bits touching GeckoProfile.updateSessionFile() if I wanted to land them in the reverse order.

Best to move review -> Margaret

Comment on attachment 8753018 [details] MozReview Request: Bug 905223 - Part 0 - Add target API annotations to get rid of errors in Android Studio. r=margaret Review request updated; see interdiff: https://reviewboard.mozilla.org/r/52930/diff/1-2/

Comment on attachment 8753019 [details] MozReview Request: Bug 905223 - Part 1 - Factor out external URL calculation. r=margaret Review request updated; see interdiff: https://reviewboard.mozilla.org/r/52932/diff/1-2/

Comment on attachment 8753020 [details] MozReview Request: Bug 905223 - Part 2 - Move session data parsing into a background thread. r=jchen Review request updated; see interdiff: https://reviewboard.mozilla.org/r/52934/diff/1-2/

Comment on attachment 8753021 [details] MozReview Request: Bug 905223 - Part 3 - Move the session parsing in front of the layout initialisation. r=margaret Review request updated; see interdiff: https://reviewboard.mozilla.org/r/52936/diff/1-2/

Comment on attachment 8753022 [details] MozReview Request: Bug 905223 - DON'T LAND - Debug log Review request updated; see interdiff: https://reviewboard.mozilla.org/r/52938/diff/1-2/

Comment on attachment 8753018 [details] MozReview Request: Bug 905223 - Part 0 - Add target API annotations to get rid of errors in Android Studio. r=margaret https://reviewboard.mozilla.org/r/52930/#review49894

Sorry I've been slow to get around to reviewing this. jchen, do you think you could help take a look at these patches? When I see threads I think of you :)

https://reviewboard.mozilla.org/r/52934/#review52236 I took a quick look, but I'm not too knowledgeable about session restore. ::: mobile/android/base/java/org/mozilla/gecko/GeckoApp.java:206 (Diff revision 2) > private final HashMap<String, PowerManager.WakeLock> mWakeLocks = new HashMap<String, PowerManager.WakeLock>(); > > protected boolean mLastSessionCrashed; > protected boolean mShouldRestore; > + private String mRestoreMessage; > + private final CountDownLatch mSessionRestoreParsingFinished = new CountDownLatch(1); See the other comment about using boolean flag and synchronization. ::: mobile/android/base/java/org/mozilla/gecko/GeckoApp.java:1542 (Diff revision 2) > - Log.e(LOGTAG, "An error occurred during restore", e); > - mShouldRestore = false; > - } > - } > + } > - > - GeckoAppShell.notifyObservers("Session:Restore", restoreMessage); > + if (!mIsRestoringActivity) { > + GeckoAppShell.notifyObservers("Session:Restore", mRestoreMessage); You can put this inside the background Runnable, so you shouldn't need to add mRestoreMessage at all. ::: mobile/android/base/java/org/mozilla/gecko/GeckoProfile.java:82 (Diff revision 2) > // Session store > private static final String SESSION_FILE = "sessionstore.js"; > private static final String SESSION_FILE_BACKUP = "sessionstore.bak"; > private static final long MAX_BACKUP_FILE_AGE = 1000 * 3600 * 24; // 24 hours > > + private final CountDownLatch mOldSessionDataProcessed = new CountDownLatch(1); Instead of CountDownLatch, you should use, e.g., a boolean flag with synchronization, ```java private boolean mOldSessionDataProcessed; ``` To signal completion, you would use, ```java synchronized (this) { mOldSessionDataProcessed = true; notifyAll(); } ``` To wait for completion, you would use, ```java synchronized (this) { while (!mOldSessionDataProcessed) { try { wait(); } catch (final InterruptedException e) { // Ignore } } } ```

Comment on attachment 8753019 [details] MozReview Request: Bug 905223 - Part 1 - Factor out external URL calculation. r=margaret https://reviewboard.mozilla.org/r/52932/#review52300 ::: mobile/android/base/java/org/mozilla/gecko/GeckoApp.java:1487 (Diff revision 2) > mWasFirstTabShownAfterActivityUnhidden = true; // Reset since we'll be loading a tab. > > final SafeIntent intent = new SafeIntent(getIntent()); > final String action = intent.getAction(); > > - final String uri = getURIFromIntent(intent); > + final String passedUri = getIntentURI(); Can we pass the intent as a parameter to this method? Otherwise we're creating the same SafeIntent twice.

Comment on attachment 8753021 [details] MozReview Request: Bug 905223 - Part 3 - Move the session parsing in front of the layout initialisation. r=margaret https://reviewboard.mozilla.org/r/52936/#review52304 I'm not convinced this is necessary, and it makes me a bit nervous. This seems like something we could address in a follow-up bug, to measure any performance impact separately.

Comment on attachment 8753018 [details] MozReview Request: Bug 905223 - Part 0 - Add target API annotations to get rid of errors in Android Studio. r=margaret Review request updated; see interdiff: https://reviewboard.mozilla.org/r/52930/diff/2-3/

Comment on attachment 8753019 [details] MozReview Request: Bug 905223 - Part 1 - Factor out external URL calculation. r=margaret Review request updated; see interdiff: https://reviewboard.mozilla.org/r/52932/diff/2-3/

Comment on attachment 8753020 [details] MozReview Request: Bug 905223 - Part 2 - Move session data parsing into a background thread. r=jchen Review request updated; see interdiff: https://reviewboard.mozilla.org/r/52934/diff/2-3/

Comment on attachment 8753019 [details] MozReview Request: Bug 905223 - Part 1 - Factor out external URL calculation. r=margaret Review request updated; see interdiff: https://reviewboard.mozilla.org/r/52932/diff/3-4/

Comment on attachment 8753020 [details] MozReview Request: Bug 905223 - Part 2 - Move session data parsing into a background thread. r=jchen Review request updated; see interdiff: https://reviewboard.mozilla.org/r/52934/diff/3-4/

Comment on attachment 8753020 [details] MozReview Request: Bug 905223 - Part 2 - Move session data parsing into a background thread. r=jchen https://reviewboard.mozilla.org/r/52934/#review52626

https://hg.mozilla.org/integration/fx-team/rev/17386d25f260 https://hg.mozilla.org/integration/fx-team/rev/5fc62e209fc7 https://hg.mozilla.org/integration/fx-team/rev/d4f569803fec

https://hg.mozilla.org/mozilla-central/rev/17386d25f260 https://hg.mozilla.org/mozilla-central/rev/5fc62e209fc7 https://hg.mozilla.org/mozilla-central/rev/d4f569803fec