1345534 - Open tabs disappearing

Status: RESOLVED WORKSFORME

(Firefox for Android Graveyard :: General, defect, P2)

Description

[Aaron Griffin]

User Agent: Mozilla/5.0 (Android 6.0.1; Mobile; rv:51.0) Gecko/51.0 Firefox/51.0
Build ID: 20170208135532

Steps to reproduce:

Switch to a running Firefox instance with at least one tab in the tab queue.


Actual results:

Periodically, since the last week or so (currently on 51.0.3), the browser will open with a new tab and the last queued tab. Old open tabs are completely missing and are not in recently closed tabs. I generally have 4-7 tabs open at any time and keep them for long periods.


Expected results:

Tabs should not be lost, or at least should be listed in recently closed tabs.

Comment 1

[Jan Henning [:JanH]]

Is Firefox really already running when you switch to it, or has it been killed in the background by Android and has to start up again actually?

Also, could you please turn on full logging by enabling "consoleservice.logcat" and "browser.sessionstore.debug_logging" in about:config (needs a restart to become effective) and then get a log as soon as you encounter this again?

You can either connect your phone to a computer and use ADB (https://developer.android.com/studio/releases/platform-tools.html) with the following command line:

Windows
> adb logcat -dv threadtime | findstr Gecko > log.txt

Linux/Mac
> adb logcat -dv threadtime | grep Gecko > log.txt

or you can try using the Log View add-on (https://addons.mozilla.org/android/addon/logview/).

Comment 2

[Aaron Griffin]

Firefox still remains in the running list of apps - I rarely switch to it with the icon, usually with the program menu (forgive me, I can't recall the android term for the square button). I don't know if it would remain there if killed or not.

I've turned on those two things and installed the logview addon.

Will report back the next time it happens.

Comment 3

[Aaron Griffin]

Just happened to me. I had at least two other tabs open and one tab pending in the tab queue. I believe FF sat in the background for around two hours.

This is the best I can do for the logs right now https://pastebin.mozilla.org/8981603 but that was using the "pastebin" button from the add-on. There's lots of stuff missing. Notably, this looks interesting to me:

GeckoSessionStore
    saveStateDelayed() timer delay = 9586, incrementing _pendingWrite to 1
GeckoSessionStore
    application-background
GeckoSessionStore
    flushPendingState(), _pendingWrite = 1
GeckoSessionStore
    _saveState(aAsync = false)
GeckoSessionStore
    _saveState() killed queued timer
GeckoSessionStore
    _saveState() current state collected
GeckoSessionStore
    _saveState() writing normal data, 5 tabs in window[0]
GeckoSessionStore
    _writeFile(aAsync = false), _pendingWrite = 1
GeckoSessionStore
    _write() writing synchronously

But that all appears to be nice and successful. Definitely don't have 5 tabs, though.

Comment 4

[Jan Henning [:JanH]]

Yes, unfortunately the Pastebin log only shows a tab completing it's loading, but nothing directly useful.

A long shot, but can you possibly remember whether the log extract you've included above was from before Firefox was backgrounded for two hours, or after it had started up again? (Given the appearance of "application-background", I assume the former, i.e. the write as Firefox was backgrounded).

Also, there wasn't any entry with something like "_writeFile() _write() returned, _pendingWrite = ..." immediately afterwards? It could be possible that we've been killed at that point, but "_write() writing synchronously" appears only *after* we've synchronously written the temp file and moved it to the actual file name (https://dxr.mozilla.org/mozilla-release/rev/4aa6b651f543fc61434508bfd4f9e245eddee2e4/mobile/android/components/SessionStore.js#1115), so I'm not sure how us getting killed afterwards could affect the file integrity. There also wasn't any possible earlier async write interfering, since _pendingWrite was only incremented from 0 to 1 by the preceding saveStateDelayed() call.

We also didn't touch the backup file during this write, so whatever happened to that I wonder?

Thanks for taking the time, though and fingers crossed for getting a complete log the next time.

Comment 5

[Paul [pwd]]

I've had this happen a couple of times in the past couple months. Lost around 30 tabs each time. I thought it was a corrupted profile but oddly my add-ons are still installed so it's definitely something different.

Comment 6

[Paul [pwd]]

Oh I should add, on both occasions before I lost the tabs permanently, I could swipe Firefox from memory and after a few times of doing that, the tabs would come back only to be lost again.

Comment 7

[Paul [pwd]]

This happened again this morning. I've now cleared data to check if it persists. 

The tab was opened via the tab queue via a custom tab.

Comment 8

[Paul [pwd]]

Attachment: 2017-04-18-08-16-13.txt

Logcat 1

Comment 9

[Paul [pwd]]

Attachment: 2017-04-18-08-19-37.txt

Logcat 2

Comment 10

[Paul [pwd]]

Attachment: 2017-04-18-08-19-49.txt

Logcat 3

Comment 11

[Paul [pwd]]

Attachment: 2017-04-18-08-53-55.txt

Logcat 4

Comment 12

[Paul [pwd]]

Attachment: 2017-04-18-10-27-51.txt

Logcat 5

Comment 13

[Paul [pwd]]

I'm not sure if these logcats adequately demonstrate the issue but I've certainly tried to get enough to at least cover it with a scatter-gun approach. Hopefully they also show an issue where by sometimes a page won't load upon my return to Fennec but will load fine if I copy and paste the address into a new tab.

Comment 14

[Sebastian Kaspari (:sebastian; :pocmo)]

Thanks for the logs, Paul! I'll flag this for triage.

Comment 15

[Jan Henning [:JanH]]

(In reply to Paul [pwd] from comment #13)
> Hopefully they also show an issue where by sometimes a page won't
> load upon my return to Fennec but will load fine if I copy and paste the
> address into a new tab.

Completely broken tabs that don't react to anything (except closing them in the UI) sounds like bug 1356563. I'll look at the logs to try and see whether I can find anything interesting.

Comment 16

[Jan Henning [:JanH]]

So the logs are showing clear symptoms of bug 1356563 - all instances of JS errors where the window is mysteriously undefined or otherwise doesn't exist are this bug.

Depending on how you interact with your tabs, this could definitively cause tab loss - when bug 1356563 happens, all previous tabs basically exist only in the UI, but not in Gecko. So if you open any new tabs within the same session afterwards (which will now successfully open a tab in Gecko as well), this'll overwrite the session store data with the new session, so the next startup will restore only the newly opened tabs, but nothing older. Not sure if that bug alone can explain all of your problems, though.

(In reply to Paul [pwd] from comment #6)
> Oh I should add, on both occasions before I lost the tabs permanently, I
> could swipe Firefox from memory and after a few times of doing that, the
> tabs would come back only to be lost again.

So did you do that (swiping Firefox away and restarting it frequently) for these logs as well? Just wondering, as in some logs I see Firefox starting up a few times in succession without any obvious crashes inbetween.

I also see some instances of missing session store files (An error occurred during restore, switching to backup file), although  without session store debug logging I probably can't say much about that.

I'm also not that familiar with tab queues, so for now maybe somebody else can say something more about that...

... the "Unable to parse URL from tab queue array" seem suspicious at first, but on closer inspection it turns out that our way of parsing the stored tab queue data (https://dxr.mozilla.org/mozilla-central/rev/a374c35469935a874fefe64d3e07003fc5bc8884/mobile/android/base/java/org/mozilla/gecko/tabqueue/TabQueueHelper.java#201) is rather silly, so just a false alarm.

Comment 17

[Paul [pwd]]

Thanks Jan. I've just had the same thing happen on my tablet and I don't open that as often at all. In fact I'd not opened that in hours and just went in to do a search to find all of my previous tabs missing. Not sure if that information helps you to confirm this as bug 1356563 or not.

(In reply to Jan Henning [:JanH] from comment #16)
> So did you do that (swiping Firefox away and restarting it frequently) for
> these logs as well? Just wondering, as in some logs I see Firefox starting
> up a few times in succession without any obvious crashes inbetween.
I did indeed, I was hoping to be able to show you something magical like the tabs restored. It never worked though.

Comment 18

[Jan Henning [:JanH]]

Actually thinking about it some more, tabs disappearing, mysteriously reappearing and then disappearing for good could in theory be a side effect of session store backups.

It's not very probable, because normally, the previous backup is replaced with a copy of the new session store file quite soon after starting Firefox, but it could happen, especially if you immediately swipe Firefox away.

So the sequence could be something like:
- Tabs are lost from main session store file, but not from the backup
- You start up and kill Firefox a few times in quick succession and eventually end up with a damaged session store file
- The next startup restores from the backup, which will still have all your tabs
- Because of bug 1356563 the tabs aren't really restored, though and this time you keep Firefox open long enough/open new tabs to overwrite both copies of the session store file.

Comment 19

[Wesley Huang [:wesley_huang] (EPM) (NI me)]

From the symptom we should put this into tracking+.
But seems not very easy to reproduce so i'm leaving it P2.

Hi Ioana,
Could you or your team do a branch check on 52, 53, 54, 55?

Comment 20

[Al Tsai [:atsai]]

echo Comment 19 to bring it to surface.

Comment 21

[Sorina Florean [:sflorean]]

Can't reproduce with Asus ZenPad 8 (Android 6.0.1) and Huawei Honor (Android 5.1.1) on builds 56.0a1, 55.0b5 and 54.0.1 following the steps:
1. Open 4-5 tabs in Firefox with always restore ON;
2. Leave Firefox in background;
3. Open one tab in tab queue;
4. Wait 2-3 hours and open Firefox again. Also open after 1-2 min. Close again and reopen. 
All the tabs was opened, including the ones from step 1. Did I missed something?

Comment 22

[Ioana Chiorean]

As Sorina mentioned in Comment #21, we were not able to reproduce it. 
Aaron Griffin and Paul, did we miss any steps? Are you still able to reproduce it ?

Comment 23

[Paul [pwd]]

Ioana, as per comment #17, I believe this was down to another bug. When that got fixed, this problem went away.

Comment 24

[Ioana Chiorean]

Oke then, Marking this as Worksforme then as it is ok now.