Closed Bug 1274390 Opened 4 years ago Closed 3 years ago
Restoring all tabs from previous session fails because of "org
.json .JSONException: No value for is Private"
485.53 KB, text/x-log
MozReview Request: Bug 1274390 - Include isPrivate and desktopMode in the session store data used for initialising new tabs. r=sebastian
58 bytes, text/x-review-board-request
Recently I had Firefox crash on my Android device. Sadface (although I can't complain because I really asked for it by running a Nightly). After it restarted, I was shown the Awesomescreen "Recent Tabs" view. Since I'm rather attached to my tabs, I scrolled to the bottom of the "tabs from last time" list and hit "Open all". This opened the first six tabs, and didn't do anything about the rest of the 100-200 tabs I have open. Additionally, tapping on the individual tabs in the list doesn't do anything unless I tap on one which was opened by "Open all". `adb logcat` reveals the following (I'll attach a full log too): 05-19 12:58:58.191 9759 10002 D GeckoTabs: handleMessage: Tab:Added 05-19 12:58:58.200 9759 10002 W GeckoTabs: handleMessage threw for Tab:Added 05-19 12:58:58.200 9759 10002 W GeckoTabs: org.json.JSONException: No value for isPrivate 05-19 12:58:58.200 9759 10002 W GeckoTabs: at org.json.JSONObject.get(JSONObject.java:389) 05-19 12:58:58.200 9759 10002 W GeckoTabs: at org.json.JSONObject.getBoolean(JSONObject.java:410) 05-19 12:58:58.200 9759 10002 W GeckoTabs: at org.mozilla.gecko.Tabs.handleMessage(Tabs.java:461) 05-19 12:58:58.200 9759 10002 W GeckoTabs: at org.mozilla.gecko.EventDispatcher.dispatchEvent(EventDispatcher.java:325) 05-19 12:58:58.200 9759 10002 W GeckoTabs: at org.mozilla.gecko.EventDispatcher.dispatchEvent(EventDispatcher.java:248) 05-19 12:58:58.200 9759 10002 W GeckoTabs: at org.mozilla.gecko.GeckoAppShell.handleGeckoMessage(GeckoAppShell.java:1911) 05-19 12:58:58.200 9759 10002 W GeckoTabs: at org.mozilla.gecko.mozglue.GeckoLoader.nativeRun(Native Method) 05-19 12:58:58.200 9759 10002 W GeckoTabs: at org.mozilla.gecko.GeckoThread.run(GeckoThread.java:509) 05-19 12:58:58.204 9759 10002 D GeckoTabs: handleMessage: Content:StateChange 05-19 12:58:58.210 9759 9759 D GeckoNetworkManager: Incoming event enableNotifications for state OnNoListeners -> OnWithListeners 05-19 12:58:58.211 9759 9759 D GeckoNetworkManager: New network state: UP, WIFI, WIFI 05-19 12:58:58.213 9759 9759 D GeckoNetworkManager: Incoming event receivedUpdate for state OnWithListeners -> OnWithListeners 05-19 12:58:58.214 9759 9759 D GeckoNetworkManager: New network state: UP, WIFI, WIFI 05-19 12:58:58.216 9759 10002 D GeckoTabs: handleMessage: Content:StateChange 05-19 12:58:58.227 9759 10002 D GeckoTabs: handleMessage: Content:StateChange It's worth noting that from the `GeckoConsole` messages I get further down, it seems that the tabs _are_ actually loading - they're just not showing in the UI. Also, the attached log is me sitting on the homescreen for a bit, tapping the Nightly icon, scrolling (way) down to the "Open all" button, hitting it, and sitting in Firefox for a little bit. I'm on Firefox Nightly, built 2016/05/18, running on CyanogenMod 13.0-20160516-NIGHTLY-angler (which is based on Android 6.0.1). I own a Nexus 6P.
I have a suspicion what might have gone wrong - over in bug 1229259, I've changed tab initialisation to always include a basic amount of session store data. Previously, there was a small window of time between tab creation and DOMTitleChanged where a tab wouldn't have any session store data and therefore wouldn't get saved to disc. Now that tabs are always initialised with that basic amount of session store data, it seems possible that they might get saved to disk in that state if a session save is triggered before the full tab data is collected by the session store. This doesn't seem to be a problem for the session restore on startup, because the Java session parser there treats isPrivate as optional , however the Recent Tabs panel works in a slightly different manner. Any click on a tab (or the Open All button) ends up here , which means that if isPrivate is not present in the session store data, we end up calling BrowserApp.addTab() with params.isPrivate explicitely set to "undefined", which coincidentally defeats browser.js's default value logic . So in the end, Java receives a Tab:Added message with isPrivate undefined, which means things will fall apart when we want to access that value  while trying to actually create a new tab on the Java UI side.  https://dxr.mozilla.org/mozilla-central/rev/f1f2644d34440fe38c098e323bf570e09197e51a/mobile/android/base/java/org/mozilla/gecko/GeckoApp.java#1670  https://dxr.mozilla.org/mozilla-central/rev/f1f2644d34440fe38c098e323bf570e09197e51a/mobile/android/components/SessionStore.js#1089  https://dxr.mozilla.org/mozilla-central/rev/f1f2644d34440fe38c098e323bf570e09197e51a/mobile/android/chrome/content/browser.js#3431  https://dxr.mozilla.org/mozilla-central/rev/f1f2644d34440fe38c098e323bf570e09197e51a/mobile/android/base/java/org/mozilla/gecko/Tabs.java#464
STR: 1. Turn session store logging on (browser.sessionstore.debug_logging to true and restart). 2. Turn tab restoring off ("never"). 3. Watch logcat for GeckoSessionStore and launch Firefox. 4. Open any page with a link to a large page which will take a while to load (e.g. for me https://dxr.mozilla.org/mozilla-central/search?q=path%3Amobile+path%3Abrowser.js&redirect=false) 5. Open the link (e.g. the link to browser.js) in a new tab and then immediately hit the home button. You want to time this to happen after the session store has processed the TabOpen event, so the new tab with its basic session store data gets written to storage on backgrounding. 6. Once the session store has finished writing (watch logcat for _writeFile() _write() returned), kill Firefox. Either use the stop button in Android Studio, or keep a terminal with |adb shell am force-stop org.mozilla.fennec| ready. You must do this before the session store starts writing the updated full tab data to disk after receiving the DOMTitleChanged event for the new tab (that's why you should pick a page which is slow to load). 7. Relaunch Firefox and try restoring the new tab from the "Tabs from last time", which should give you the symptoms described by Alex (Gecko starts loading the tab, however it doesn't appear in the UI, instead you get errors in the logcat from GeckoTabs).
Restoring a tab from the Recent Tabs panel, which goes via the session store's _restoreTabs() function and ultimately via BrowserApp.addTab() and a Tab:Added message back to the Java UI requires the value for isPrivate to be present in the session store data for the respective tab - if it isn't, we end up sending isPrivate as "undefined", which breaks the process of adding the new tab in our UI. When the session store collects the full tab data for a browser, it always includes the values for isPrivate and desktopMode, therefore we now include those values in the basic session store data we use in initialising a new tab object, too. Review commit: https://reviewboard.mozilla.org/r/54424/diff/#index_header See other reviews: https://reviewboard.mozilla.org/r/54424/
Attachment #8755138 - Flags: review?(s.kaspari)
Comment on attachment 8755138 [details] MozReview Request: Bug 1274390 - Include isPrivate and desktopMode in the session store data used for initialising new tabs. r=sebastian https://reviewboard.mozilla.org/r/54424/#review51146
Attachment #8755138 - Flags: review?(s.kaspari) → review+
Comment on attachment 8755138 [details] MozReview Request: Bug 1274390 - Include isPrivate and desktopMode in the session store data used for initialising new tabs. r=sebastian Approval Request Comment [Feature/regressing bug #]: Mobile session store, bug 1229259 [User impact if declined]: Occasionally, restoring tabs from the Recent Tabs panel will fail. [Describe test coverage new/current, TreeHerder]: manual (see STR in comment 2). [Risks and why]: Low: Session store data for new tabs is basically initialised in two steps - preliminary data is added during tab creation and the full data after the DOMTitleChangedEvent during page load. This patch ensures that certain properties which are expected to be always present in the data are initialised during tab creation. [String/UUID change made/needed]: none
I should mention that my tabs actually _did_ end up opening, but only after several hours. (Note also that I have several hundred tabs.) I assume that doesn't change the outcome of this bug? In any case, looks like *something* got fixed, so that's nice. \o/
Hmm, that sounds most weird and to be honest I don't really have an explanation for what caused *that* behaviour (although it's nice that you didn't loose your open tabs in the end). But comment 2 still seems the most likely explanation for how we got to "org.json.JSONException: No value for isPrivate" and the tab initialisation needed fixing in any case.
Whoops, I meant to say comment 1 above.
Comment on attachment 8755138 [details] MozReview Request: Bug 1274390 - Include isPrivate and desktopMode in the session store data used for initialising new tabs. r=sebastian Recent regression in session restore. Beta47+, Aurora48+
Hi Andrei, could you please plan some focused testing around session restore for 47.0b9? Thanks!
Hmm, okay. Is it possible that the tabs got opened (but not displayed in the Java UI), then Firefox got killed and when it was reopened, the "open" tabs were properly restored? I have the browser set to restore tabs, FWIW.
That seems plausible. It is possible/probable that session restoring got turned off temporarily if you've crashed at least twice in a row (see bug 1263110). Since the only thing that was broken here was opening the tabs in the UI, the session store was still keeping track of those invisible tabs. Once you manage a background - foreground - background cycle without crashing, session restoring is turned back on, so your tabs will be restored normally the next time you launch Firefox.
Sounds correct! Thanks for the speedy response.
(In reply to Ritu Kothari (:ritu) from comment #11) > Hi Andrei, could you please plan some focused testing around session restore > for 47.0b9? Thanks! I believe this is Android only, forwarding this ni? to Ioana.
Flags: needinfo?(andrei.vaida) → needinfo?(ioana.chiorean)
We have covered this with a test and I did not reproduce it. I will try to keep a big profiles ( hundreds of tabs to see if in the future will happen again)
You need to log in before you can comment on or make changes to this bug.