1420641 - fennec release 57&58 loads first page after launch very slowly

Status: VERIFIED FIXED

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

Description

[Ben Kelly [:bkelly, not reviewing]]

I've been running firefox 57 to work around bug 1414536 lately.  I've noticed that the first load after launching firefox always seems to take a long time.  Its like it the first network connection is stuck on DNS or something.  Repeated loads of the same site are then fast.

I'm basically just trying to load SUMO articles from my top sites.

Comment 1

[alan.n.davies]

There is also bug 1295117 in which similar behaviour has been reported.  However, that bug was initially about a different problem, so this is probably a better place discuss it.  I'll repost and expand on what I said in that bug...

There seem to be numerous reports around the web of firefox taking ages to load the first page after it starts up.  It typically takes about 1 minute to open the first page.  This is unacceptably slow.  After that first page has loaded, the browser seems to revert to normal loading speeds.

I connected my Android phone via the USB debugging tools, and it seems to spend most of it's time in "Non-incremental GC" and "Minor GC".  I have attached a performance log of opening the eurogamer.net site.

I tried reinstalling firefox on my phone and that fixed the issue for a while, but it eventually came back again.  It seemed to be pretty much 48 hours after I reinstalled that the problem resurfaced.

Comment 2

[alan.n.davies]

Attachment: FirefoxAndroidSlowLoad.json

Performance log of slow load of eurogamer.net

Comment 3

[Ben Kelly [:bkelly, not reviewing]]

James, do you have any thoughts here?  Is the profile in comment 2 helpful or can you help Alan use the perf-html.io addon on fennec?  (I've still never managed to use it.)

Comment 4

[alan.n.davies]

I managed to load the profile into perf-html.io, but its all pretty meaningless to me.  It does seem to be spending 49 seconds (67% of the time)  in nsAppShell::ProcessNextNativeEvent:wait though.

Comment 5

[Ben Kelly [:bkelly, not reviewing]]

(In reply to alan.n.davies from comment #4)
> I managed to load the profile into perf-html.io, but its all pretty
> meaningless to me.  It does seem to be spending 49 seconds (67% of the time)
> in nsAppShell::ProcessNextNativeEvent:wait though.

Can you click the green share button to get a perma-link and paste here?

Comment 6

[alan.n.davies]

https://perfht.ml/2Aa5HSS

Comment 7

[Ben Kelly [:bkelly, not reviewing]]

Thanks.  Nothing in there is jumping out to me as the problem.

It feels to me like the gecko/android interface is stalling for some reason during the network request.  I wish I was at the all-hands meeting this week so I could show James my device with the problem.

Comment 8

[alan.n.davies]

Damn.  Unfortunately I don't know enough about the firefox internals, or android to help out.  This seems like a major bug to me though.  Users will turn away in droves if they have to wait 1 minute for a website to appear.

Another thing I noticed is that the problem goes away if you start a guest session.

Comment 10

[sqweek]

The interface isn't stalling for me, and it doesn't look like it is in Alan's log either. There's a lot of time in ProcessNextNativeEvent::Wait, but that's a _good_ thing. It means Firefox is ready and waiting to process the next system event (eg. user touch/gesture). It means the UI is responsive.

There's an interesting marker "Non-blank paint after 76196ms", which I think is indicative of how long the page takes to load. But I'm struggling to discern the reason it takes so long; these event loop stacks seem to make it very hard to follow what is actually happening as someone totally unfamiliar with the codebase.

Alan, how did you acquire the performance log? Are you able to take another log with firefox behaving well?

Comment 11

[alan.n.davies]

The interface is not stalled.  The progress bar gets about 1/10th of the way across and stays there for about 15-20 seconds.  During this time I can swipe the new tab page between "Top Sites", "Bookmarks" and "History" with no lag.

Yes, the page does take ~76 seconds to load!  That is a crazily long time.

I acquired the logs by connecting my phone to my PC via USB, and using the WebIDE in the Windows version of firefox to capture the performance.  I have created 4 more logs...

Initial slow load of eurogamer.net
https://perfht.ml/2Cxhkot

Closed tab, then re-loaded eurogamer.net.  Now loads at normal speed
https://perfht.ml/2CDZtMU

Closed firefox, then re-loaded eurogamer.net (slow again)
https://perfht.ml/2CBCMJ2

Closed tab, then re-loaded eurogamer.net.  Now loads at normal speed
https://perfht.ml/2CCsgB8

Comment 12

[sqweek]

Yeah, that's the same symptoms I see - the progress bar 1/10th of the way.

Thanks for the additional logs. The most striking difference I can see is when you filter the Stack Chart on "http". In the fast case (3 second load), there's regular http related stacks across the timeline. But in the slow case, there's basically _nothing_ http related until near the very end. So, keeping in mind I'm very new at analysing firefox performance dumps, that makes me think the problem lies with whatever is doing the network communication. Which is presumably happening in a separate thread (or via async i/o) so isn't captured by the perfomance log :/

Does the WebIDE provide options for capturing other threads? I had a quick look at it but it's not immediately obvious how to use it to capture my own logs so I'll have to try and find some time to learn how it works.

Comment 13

[alan.n.davies]

Is there any update on this?  You only have to look on Reddit, or the Google play store reviews to see that there are a lot of unhappy people.

Some examples...

https://www.reddit.com/r/firefox/comments/7l0hdh/mozilla_please_fix_firefox_on_android/

https://www.reddit.com/r/firefox/comments/7kz2ze/firefox_for_android_is_still_super_slow/

https://www.reddit.com/r/firefox/comments/7ih7we/firefox_load_times_on_android_are_very_slow/
(This one claims to be "solved" by clearing data.  I did a complete re-install which did fix the issue but it came back 2 days later)

https://play.google.com/store/apps/details?id=org.mozilla.firefox&reviewId=Z3A6QU9xcFRPSFYyT0N6QVRMOTkwdWxlcDVCQjdQRGJ5cDJjUXIyVHNJRE03OXhDb3VRcE9SOV9vbGdtWU96bHB0blE4QWxwWlhNenhodV9xY2prVnZ6SFE

https://play.google.com/store/apps/details?id=org.mozilla.firefox&reviewId=Z3A6QU9xcFRPRmQzcXdUbFNPTGtsV056UTFvTFBLS2djWDI0VzBySnR6bmdwSFZhYlBsaExkU0xxYlgwOW9vQWI4Y0tqR0NGTzZyU01hZGNBVFBSbWNyMmc

Comment 14

[Ben Kelly [:bkelly, not reviewing]]

Attachment: logcat.tmp

Here is a logcat from my device.  To make this I:

1. Launched firefox
2. Typed example.com in the URL bar, but did not push enter
3. Started logcat | grep Gecko
4. hit enter on URL bar
5. Waited for page to load
6. Stopped logcat

You can see there is a 17 second pause:

12-21 08:35:21.665 30652 30678 I GeckoConsole: [6.643] Rpc response updates
12-21 08:35:38.564 31357 31357 I GeckoApplication: zerdatime 3177833662 - application start

Also, there are some messages from GeckoNetworkManager leading up to that which might be relevant:

12-21 08:35:16.218 30652 30652 D GeckoNetworkManager: Incoming event enableNotifications for state OnWithListeners -> null
12-21 08:35:16.219 30652 30652 W GeckoNetworkManager: Invalid event enableNotifications for state OnWithListeners

12-21 08:35:20.744 30652 30652 D GeckoNetworkManager: Incoming event stop for state OnWithListeners -> OffWithListeners

12-21 08:35:21.642 30652 30652 D GeckoNetworkManager: Incoming event stop for state OffWithListeners -> null
12-21 08:35:21.642 30652 30652 W GeckoNetworkManager: Invalid event stop for state OffWithListeners

Comment 15

[Ben Kelly [:bkelly, not reviewing]]

(In reply to Ben Kelly [:bkelly] from comment #14)
> 12-21 08:35:38.564 31357 31357 I GeckoApplication: zerdatime 3177833662 -
> application start

Oh, this was for a push message for nightly.

Comment 16

[Ben Kelly [:bkelly, not reviewing]]

Comment on attachment 8938339 [details]
logcat.tmp

I think this logcat is bogus because of other gecko running.

Comment 17

[Ben Kelly [:bkelly, not reviewing]]

Here is a snippet of logcat for doing the same thing for mozilla.org:

12-21 08:45:28.505 32591 32591 D GeckoToolbar: onTabChanged: SECURITY_CHANGE
12-21 08:45:28.506 32591 32591 D GeckoBrowserApp: BrowserApp.onTabChanged: 0: SECURITY_CHANGE
12-21 08:45:28.556 32591 32591 I GeckoTabs: zerdatime 3178423654 - page load start
12-21 08:45:28.556 32591 32591 D GeckoToolbar: onTabChanged: START
12-21 08:45:28.557 32591 32591 D GeckoBrowserApp: BrowserApp.onTabChanged: 0: START
12-21 08:45:28.564 32591 32609 D GeckoIdleService: Setting timer a day from now
12-21 08:45:28.615 32591 32591 D GeckoLayerClient: Window-size changed to (1080,1536)
12-21 08:45:58.936 32591 32591 D GeckoNetworkManager: Incoming event stop for state OnWithListeners -> OffWithListeners
12-21 08:45:58.937 32591 32607 D GeckoBrowserProvider: Expiring history.
12-21 08:45:59.156 32591 32607 D GeckoBrowserProvider: Expiring highlights blocklist.
12-21 08:45:59.157 32591 32607 D GeckoBrowserProvider: Expiring thumbnails.
12-21 08:45:59.857 32591 32591 D GeckoToolbar: onTabChanged: TITLE

I didn't pipe this into a file so I could see when it unpaused with page load.  This line occurred when the page load got unstuck:

12-21 08:45:58.936 32591 32591 D GeckoNetworkManager: Incoming event stop for state OnWithListeners -> OffWithListeners

Comment 18

[Ben Kelly [:bkelly, not reviewing]]

BTW, I've tried a couple things to see if they work around the problem.  None of them worked:

1. Disable network throttling in about:config.
2. Try to restore tabs via session restore

Beta and nightly on this same device do not have any problem.  I've considered wiping my release profile and starting over, but then I would lose the ability to help debug here.

Comment 19

[Ben Kelly [:bkelly, not reviewing]]

Just before the bit in comment 17 the logcat has:

12-21 08:45:25.375 32591 32591 D GeckoNetworkManager: Incoming event enableNotifications for state O
nWithListeners -> null
12-21 08:45:25.375 32591 32591 W GeckoNetworkManager: Invalid event enableNotifications for state On
WithListeners

Comment 20

[James Willcox (:snorp) ([e-mail]) (he/him)]

It looks like we should only get the 'stop' event if we are shutting down the GeckoNetworkManager[0] or the app was put into the background[1]. The network events are handled in Gecko here[2], which simply does NotifyObservers with NS_NETWORK_LINK_TYPE_TOPIC, which...apparently has no listeners anymore (sigh). I think the GeckoNetworkManager message may be a red herring.

57 is working fine here, I can't reproduce at all. It smells like a similar problem we had with mDNS, though, where it would wedge the Gecko thread for like 30s at a time. Ben are you on wifi when you are able to repro this? Does it still happen on LTE?


[0] https://dxr.mozilla.org/mozilla-release/source/mobile/android/geckoview/src/main/java/org/mozilla/gecko/GeckoNetworkManager.java?q=file%3AGeckoNetworkManager.java&redirect_type=single#101
[1] https://dxr.mozilla.org/mozilla-release/source/mobile/android/geckoview/src/main/java/org/mozilla/gecko/GeckoNetworkManager.java?q=file%3AGeckoNetworkManager.java&redirect_type=single#136
[2] https://dxr.mozilla.org/mozilla-release/source/widget/android/GeckoNetworkManager.h#33

Comment 21

[Ben Kelly [:bkelly, not reviewing]]

(In reply to James Willcox (:snorp) ([e-mail]) from comment #20)
> 57 is working fine here, I can't reproduce at all. It smells like a similar
> problem we had with mDNS, though, where it would wedge the Gecko thread for
> like 30s at a time. Ben are you on wifi when you are able to repro this?
> Does it still happen on LTE?

It actually happens even in airplane mode.   There is even a delay showing the "disconnected from network" page.

Comment 22

[Ben Kelly [:bkelly, not reviewing]]

Attachment: 2017-12-20 16.21.48.png

Here is a screenshot of where the delay is.

Comment 23

[Ben Kelly [:bkelly, not reviewing]]

Alan, Sqweek, does clearing the app data or uninstalling/re-installing firefox help at all?

We're trying to isolate if this is a corrupt profile issue or something that always happens independent of the profile state.  I'm hesitant to do it myself since I haven't found a way to backup/restore my firefox data yet.  So if this works then I've lost the ability to help debug the problem.

Comment 24

[James Willcox (:snorp) ([e-mail]) (he/him)]

+jchen for elite debugging skillz

Comment 25

[alan.n.davies]

(In reply to Ben Kelly [:bkelly] from comment #23)
> Alan, Sqweek, does clearing the app data or uninstalling/re-installing
> firefox help at all?
> 
> We're trying to isolate if this is a corrupt profile issue or something that
> always happens independent of the profile state.  I'm hesitant to do it
> myself since I haven't found a way to backup/restore my firefox data yet. 
> So if this works then I've lost the ability to help debug the problem.

I have previously re-installed the app and it fixed the problem for 2 days and it then came back again.  It was pretty much 48 hours on the dot that it resurfaced, though may have been coincidence.

I just tried clearing the data and it fixed it again.  I'll let you know if it comes back in 2 days time.

Comment 26

[Ben Kelly [:bkelly, not reviewing]]

Thank you Alan.  Do you have Firefox account sync enabled?

Comment 27

[alan.n.davies]

(In reply to Ben Kelly [:bkelly] from comment #26)
> Thank you Alan.  Do you have Firefox account sync enabled?

Yes I do.

Comment 28

[Ben Kelly [:bkelly, not reviewing]]

It would be interesting to try a wipe without setting up sync at some point.  Or maybe an initial stnc and then disconnect your account so sync stops.  Maybe sync is doing something bad.

Comment 29

[sqweek]

I've only recently switched to Firefox (on desktop and mobile, after reading about Quantum); I've never had a functional mobile firefox. But the first thing I did was set up a firefox account and setup sync on mobile.

Just tried the following test with ff mobile:

1. Disconnect from firefox account to stop syncing
2. Open link => SLOW
3. Close tab, Open different tab => SLOW
4. Close app, Open link => SLOW
5. Close app, Open link => SLOW
6. Clear data
7. Open firefox; search for "cars" in url bar => SLOW
8. Prompted to "Choose what data to share"
9. Close app, search for "cats" in url bar => FAST
10. Close app, Open link via twitter => FAST
11. Open link via twitter => FAST

So in my case it seemed disconnecting the sync account didn't make a difference, but clearing data has helped. The first SLOW load (step 7) could easily be attributed to initial setup when firefox runs the first time?

Comment 30

[Jan Henning [:JanH]]

On the first start after installation, an update [1], or clearing data/the cache, we need to extract the current copy of libxul.so from the APK, which can take a few seconds as it's a multi-megabyte file. For subsequent starts this shouldn't matter, though.


[1] I seem to remember that we should have some code that does this automatically in background post-update, but I've got no idea if it's really working (and of course it doesn't help if you launch Firefox immediately after an update).

Comment 31

[bull500]

just want to chime in as a user.  
Its not sync.  
I dont have a FF sync account and it happens on Fennec. 
The only solution is to have two tabs already open. That way FF somehow keeps things in memory and the pages load pretty fine.

Comment 32

[James Willcox (:snorp) ([e-mail]) (he/him)]

Hmmm, Ben and others with the problem: are you low on disk space? We unpack libxul into the app's cache directory, which Android could remove at any time. I wonder if those files are frequently getting removed?

Comment 33

[alan.n.davies]

I have 5GB free on the internal storage, and about 60GB free on an SD card.

Anyway, there is no delay immediately after clearing the data, so I don't think the unzipping is the problem.

Comment 34

[bull500]

:snorp  

In my case kinda yes:

internal:
13.52GB(Used)/14.56GB

external:
4.15GB(Used)/7.39GB

1GB RAM  
Max used by Fennec is 248MB; Avg mem use: 96MB ;Running Frequency: 61%

Comment 35

[Ben Kelly [:bkelly, not reviewing]]

I'm at 19GB used of 32GB.  So I don't think its storage size.

Also, android nuking storage would effect my beta and nightly profiles as well, no?

Comment 36

[James Willcox (:snorp) ([e-mail]) (he/him)]

(In reply to Ben Kelly [:bkelly] from comment #35)
> I'm at 19GB used of 32GB.  So I don't think its storage size.
> 

Yeah, that seems like plenty.

> Also, android nuking storage would effect my beta and nightly profiles as
> well, no?

If it decides to nuke caches to free up space, then maybe, yeah.

Comment 37

[sqweek]

I've been running with very little free space for a long time (like every time there's an app update android told me "not enough space to update" and I'd have to delete some caches etc. to get it moving). Suprisingly the rest of the phone seemed to work fine, but a week or two ago I did free up a bunch of space and it didn't change the firefox situation.

Comment 38

[fox4ever]

Here's another "User view" I'm having the same problem with FF57 on Android media boxes. Pages takes forever to load.
-No differences if on WiFi or wired
-At first I thought it was my router since rebooting it was solving the issue for few minutes
-Because sometimes setups does not upgrade well over versions, I decided to uninstall and start fresh. Solved the problem for few days. Then it's back again.

Plenty of meemory and free space on my devices. I have Android Media players from different brands running 4.4.4 5.1.2 and 7.1.2 and they are all affected.

Comment 39

[fox4ever]

(In reply to fox4ever from comment #38)
> Here's another "User view" I'm having the same problem with FF57 on Android
> media boxes.
I forgot to mention, I also tried to disable HW acceleration and it didn't help at all.

Comment 40

[sqweek]

Ok a couple of days ago I started to get "not enough space to update apps" warnings again. Firefox was still performing fine.
However, last night the problem returned and has persisted -- just as I was getting used to good performance xD

Comment 42

[James Willcox (:snorp) ([e-mail]) (he/him)]

This is very hard to diagnose further because production Firefox is not debuggable (in Android terms). I think we need to produce a build of 57 that *is* debuggable, then ask if the effected folks can try that. Jim, can you try that? It might be that we just need to get a Try build of 57.

Comment 43

[Kevin Brosnan [Ex-Mozilla]]

As I recall try builds don't get signed with the release keys so they will get certificate issues when installing the app.

Comment 44

[(inactive) Jim Chen [:jchen] [:darchons]]

Yeah I'll make a 57 Nightly try build.

Comment 45

[(inactive) Jim Chen [:jchen] [:darchons]]

Here's a special debuggable, profiling build of Firefox 57: https://moz.jnchen.com/builds/bug1420641.apk

Can anyone see if they can reproduce the bug with this version?

1. Install the APK. It will show up as "Bug 1420641" and it can coexist with regular Firefox.
2. Grant the app "Storage" permission, and try to reproduce the bug.
3. To generate a profile, force close the app and reopen it. After the bug appears and after the page finally loads, use the "Quit" menu to quit the app.
4. There should now be a file named "bug1420641-profile.json" in your storage directory (under "/sdcard").
5. Upload the profile. Note that the profile contains URLs you visited during the run, but you can upload it as a private attachment.

Comment 46

[bull500]

(In reply to Jim Chen [:jchen] [:darchons] from comment #45)
> Here's a special debuggable, profiling build of Firefox 57:
> https://moz.jnchen.com/builds/bug1420641.apk
> 
> Can anyone see if they can reproduce the bug with this version?
> 
> 1. Install the APK. It will show up as "Bug 1420641" and it can coexist with
> regular Firefox.
> 2. Grant the app "Storage" permission, and try to reproduce the bug.
> 3. To generate a profile, force close the app and reopen it. After the bug
> appears and after the page finally loads, use the "Quit" menu to quit the
> app.
> 4. There should now be a file named "bug1420641-profile.json" in your
> storage directory (under "/sdcard").
> 5. Upload the profile. Note that the profile contains URLs you visited
> during the run, but you can upload it as a private attachment.

Hopefully this can help. 
http://www.mediafire.com/?st2yf17gpftrz

Noticed something else.  
Tabs don't get closed instantly. Sometimes after closing FF tabs, clearing it off from memory and loading it back shows the previous tabs.

Comment 47

[bull500]

Does anybody else here use the HTTPS everywhere addon?? It seems to make the load times much worse than before.
Uploaded a profile at the same place with name (perfectcap) that includes the addon enabled.

Comment 48

[apK16V]

mailed apk output. unusable on motog 2014 titan lineageos :) did rate on playstore. rarely star apps

Comment 49

[Jonathan García]

(In reply to bull500 from comment #47)
> Does anybody else here use the HTTPS everywhere addon?? It seems to make the
> load times much worse than before.
> Uploaded a profile at the same place with name (perfectcap) that includes
> the addon enabled.

No, I don't have that addon installed. 

I have other profile this can be download from google drive: https://drive.google.com/open?id=1rtyi8NR4iTq9ZO2JTz8tTaaHjNoC37d-

This is an video uploaded to my twitter account: https://twitter.com/JoGarWeb/status/949736859739049984

Comment 50

[Jonathan García]

(In reply to Jonathan García from comment #49)
> (In reply to bull500 from comment #47)
> > Does anybody else here use the HTTPS everywhere addon?? It seems to make the
> > load times much worse than before.
> > Uploaded a profile at the same place with name (perfectcap) that includes
> > the addon enabled.
> 
> No, I don't have that addon installed. 
> 
> I have other profile this can be download from google drive:
> https://drive.google.com/open?id=1rtyi8NR4iTq9ZO2JTz8tTaaHjNoC37d-
> 
> This is an video uploaded to my twitter account:
> https://twitter.com/JoGarWeb/status/949736859739049984

Google Drive Link: ( https://drive.google.com/open?id=1rtyi8NR4iTq9ZO2JTz8tTaaHjNoC37d- ) https://goo.gl/LJqscy

Comment 51

[Jan Henning [:JanH]]

(In reply to bull500 from comment #47)
> Does anybody else here use the HTTPS everywhere addon?? It seems to make the
> load times much worse than before.
> Uploaded a profile at the same place with name (perfectcap) that includes
> the addon enabled.

See bug 1428573. As far as I can tell the impact of those add-ons happens rather late during page loading, whereas according to the descriptions we've got so far for this bug, the hang happens much earlier than that.

Comment 52

[sqweek]

No add-ons here. Only change from stock config is to turn off "Remember logins". I've uninstalled firefox and installed "bug 1420641" (which tbh is the greatest app name to ever grace my phone ^_^), but the problem hasn't reappeared yet.

Comment 53

[Ben Kelly [:bkelly, not reviewing]]

I also disable password manager's "remember logins".

Comment 54

[Jonathan García]

I don't think who add-ons is the problem. 

I test "bug 1420641" without add-ons and still happen. 
This is a profile without addons: https://drive.google.com/open?id=1Z8NvqnmtKqdqK9qi3VW8xdGRit44xGNB 
This is a video of test on my twitter account: https://twitter.com/JoGarWeb/status/950095658807111681 


I confirm who this bug is not present in Firefox Nightly for Android. I use that version since last week and the bug is not on that version.

Comment 56

[alan.n.davies]

I can't reporoduce the bug using the "bug 1420641" version.  One thing that did occur to me though... I have not enabled Sync on that version.  I will leave it a few more days and then enable Sync to see if the problem resurfaces.

Is anyone experiencing the long delay *without* Sync enabled?

Comment 57

[alan.n.davies]

Ok it finally happened without enabling Syc, so that rules Sync out as the culprit.  Profile available here...

https://drive.google.com/file/d/1PEHmJkKHWcf9VsbzL7sXYwws3zBJWV9z/view?usp=drivesdk

Comment 58

[(inactive) Jim Chen [:jchen] [:darchons]]

Thanks for all the reports! If you now go to "Settings" > "Clear private data", and clear all data, does that affect the bug on the next startup?

Comment 59

[alan.n.davies]

Firefox settings/Clear private data - makes no difference

Android settings/Clear cache - makes no difference

Android settings/Clear data - back to full speed.

Comment 60

[(inactive) Jim Chen [:jchen] [:darchons]]

I uploaded an updated APK at the same URL (https://moz.jnchen.com/builds/bug1420641.apk) that includes more detailed profiling, if anyone wants to give it a shot. Thanks! You do have to uninstall the previous version before installing this new version.

Comment 62

[Rubén Martín [:Nukeador] ❌ [away till Aug 31st]]

Let me know if there are other tests needed to figure out this problem.

I've been getting reports from a few friends with the exact same issue, sometimes when opening the app the url takes forever to load (blank new tab), making Firefox useless for them.

Cheers.

Comment 63

[(inactive) Jim Chen [:jchen] [:darchons]]

(In reply to Rubén Martín [:Nukeador] from comment #62)
> Let me know if there are other tests needed to figure out this problem.
> 
> I've been getting reports from a few friends with the exact same issue,
> sometimes when opening the app the url takes forever to load (blank new
> tab), making Firefox useless for them.
> 
> Cheers.

Thanks for offering! I think besides using the special build (see comment 45), they can try out Firefox Beta, which apparently doesn't suffer from this bug.

Comment 64

[Michael]

(In reply to Jim Chen [:jchen] [:darchons] from comment #45)
> 
> 4. There should now be a file named "bug1420641-profile.json" in your
> storage directory (under "/sdcard").


Hi Jim,

I've opened Bug 1426551, which is a duplicate of this bug, sorry that I haven't found this bug 1420641 before.

Once informed about the duplicate I've followed this thread with great interest, until now all aspects of my situation is already covered.

Only thing I want to add is about your debug version: Because I'm using a cheap smartphone with not much ram and internal storage, I'm using Android's 6.0 and later option for "Adoptable Storage" (https://source.android.com/devices/storage/adoptable): formatting an sdcard as "internal storage" and extending phone's storage by this.

IMHO unfortunately, maybe there had been good reasons I'm not aware of, Firefox Mobile seems not to use the android:installLocation attribute and therefor does not offer the possibility to be installed or moved to the "external" "internal storage". IMHO unfortunately because cache etc. could get very large, but of course out of scope here.

But in scope is, that because of Google's somewhat strange (or weird :-)) implementation of "Adoptable Storage" the "real" internal storage get's completely invisible and end-user-inaccessible once "Adoptable Storage" is enabled.

That's why users like me have simply no chance to access the mentioned "bug1420641-profile.json" on the invisible part of the phone's file systems.

Comment 65

[Michael]

(In reply to Michael from comment #64)
> I've opened Bug 1426551, which is a duplicate of this bug
> 

... should be Bug 1428625 ....


I've copied #1426551, also my report, because I wanted to add that once Firefox get's OOM-killed, the discussed delay / slowly launch is "triggered" again in my case. Without a restart of Firefox, and even when Firefox was "behind" the initial delay and worked fast as usual for a while. Maybe helpful for you.

Comment 66

[Marco Castelluccio [:marco]]

Almost 9 out of 10 reviews on Google Play are 1-star reviews mentioning this problem, so it seems pretty serious.

Comment 67

[(inactive) Jim Chen [:jchen] [:darchons]]

I was able to reproduce this locally, and looks like it's caused by some abnormal safe-browsing database files. We're spending a long time (> 30 seconds) loading these files on startup, and that prevents us from loading any pages.

In my case, if I delete "goog-phish-shavar.pset" and "goog-phish-shavar.sbstore" files from under profile/safebrowsing, the problem goes away, and if I then put those two files back, the problem comes back as well. Dimi, I uploaded the two problematic files here [1], can you take a look to see if anything looks wrong, and how we could end up in this state? Thanks!

[1] https://moz.jnchen.com/uploads/goog-phish-shavar.pset
    https://moz.jnchen.com/uploads/goog-phish-shavar.sbstore

Comment 68

[Dimi Lee [:dimi]]

(In reply to Jim Chen [:jchen] [:darchons] from comment #67)
> I was able to reproduce this locally, and looks like it's caused by some
> abnormal safe-browsing database files. We're spending a long time (> 30
> seconds) loading these files on startup, and that prevents us from loading
> any pages.

Hi Jim,
Sorry it took me a while to set up the environment for fennec, I haven't had enough time to look more carefully.
At first glance the "goog-phish-shavar.pset" and "goog-phish-shavar.sbstore" look ok, I can't reproduce this bug on my platform.

If possible, could you help me dump the log with the following MOZ_FLAG set:
"UrlClassifierDbService:5,nsChannelClassifier:5,UrlClassifierProtocolParser:5,UrlClassifierStreamUpdater:5,UrlClassifierPrefixSet:5"
Thanks!

I'll see if I can find anything tomorrow.

Comment 69

[u577973]

Hello everyone !

I've found something interesting about the page "about:url-classifier". One of three sources can be updated manually and the others cannot update anymore. (See the attachment "url-classifier_Release_v57.png")

I've reproduce the same step on Nightly and the second source can be updated manually ! (See the attachment "url-classifier_Nightly_v59.png")

I hope these things can will help you :)

Comment 70

[u577973]

Attachment: url-classifier_Release (update problem)

Comment 71

[u577973]

Attachment: url-classifier_Nightly (no update problem)

Comment 72

[(inactive) Jim Chen [:jchen] [:darchons]]

Attachment: slow-safebrowsing.log.gz

Here's a sample log using the slow safebrowsing dbs. You can see several times when a channel is suspended for 10 seconds waiting for the classifier.

Comment 73

[Dimi Lee [:dimi]]

(In reply to Jim Chen [:jchen] [:darchons] from comment #72)
> Created attachment 8943490 [details]
> slow-safebrowsing.log.gz
> 
> Here's a sample log using the slow safebrowsing dbs. You can see several
> times when a channel is suspended for 10 seconds waiting for the classifier.

Hey Jim,
Thank you for helping dump the log, I just checked the log but I think it will still need more time to find the root cause.
I know this bug is very urgent but I am sorry I can't help this now.

Hi francois,
could you help take a look at this when you back from PTO? Thanks!

Comment 74

[Julien Cristau [:jcristau]]

Too late for 57/58, unless we get a low-risk fix soon that could be included in a 58.0.x.

Comment 75

[Lothar Glorius]

Is there a way to completely inhibit this whole safebrowsing stuff from Firefox? Don't want it - don't need it.

Comment 76

[Rubén Martín [:Nukeador] ❌ [away till Aug 31st]]

I don't like to put more pressure over people, but I want to reinforce that this is a huge problem for a lot of people, please check play store comments of users stop using the browser because of this:

https://play.google.com/store/apps/details?id=org.mozilla.firefox

Also I'm surprised about the amount of offline people who are asking me about this problem, I hope we can figure out the problem and have a hotfix soon :-)

Thanks everyone for your work!

Comment 77

[James Willcox (:snorp) ([e-mail]) (he/him)]

Dimi, Ethan, is there a pref to turn all the SB bits off?

Comment 78

[Ritu Kothari (:ritu) (Inactive, please n-i to RyanVM, jcristau, or pascal)]

Hi Ioana, Andrei, can SV please test this scenario and let us know whether this is still a problem in 58? Thanks!

Comment 79

[Ritu Kothari (:ritu) (Inactive, please n-i to RyanVM, jcristau, or pascal)]

Hi Andreas, Snorp, could we get your inputs on this issue which seems to be a regression in 57 as compared to 56? And whether this is an ongoing problem and possibly a severe problem in 58 too. Thanks!

Comment 80

[Dimi Lee [:dimi]]

(In reply to James Willcox (:snorp) ([e-mail]) from comment #77)
> Dimi, Ethan, is there a pref to turn all the SB bits off?

You can set  "browser.safebrowsing.phishing.enabled" and "browser.safebrowsing.phishing.enabled" to false.
And that will disable browsing protection, not include download protection and tracking protection.

Based on what jim had test, I think that will be enough.

Hi Ritu
We could probably check if this bug will happen in release 58 first since release 57 is using SafeBrowsing V2 while release 58 is using SafeBrowsing V4.

Comment 81

[Ben Kelly [:bkelly, not reviewing]]

(In reply to Dimi Lee[:dimi][:dlee] from comment #80)
> (In reply to James Willcox (:snorp) ([e-mail]) from comment #77)
> > Dimi, Ethan, is there a pref to turn all the SB bits off?
> 
> You can set  "browser.safebrowsing.phishing.enabled" and
> "browser.safebrowsing.phishing.enabled" to false.
> And that will disable browsing protection, not include download protection
> and tracking protection.

I set browser.safebrowing.phishing.enabled to false.  (What is the other one?)  Unfortunately I can't get any page to load in this profile any more.

Comment 82

[James Willcox (:snorp) ([e-mail]) (he/him)]

Wennie, are there other people on your team that can help with this?

Comment 83

[James Willcox (:snorp) ([e-mail]) (he/him)]

(In reply to Dimi Lee[:dimi][:dlee] from comment #80)
> (In reply to James Willcox (:snorp) ([e-mail]) from comment #77)
> > Dimi, Ethan, is there a pref to turn all the SB bits off?
> 
> You can set  "browser.safebrowsing.phishing.enabled" and
> "browser.safebrowsing.phishing.enabled" to false.
> And that will disable browsing protection, not include download protection
> and tracking protection.
> 
> Based on what jim had test, I think that will be enough.

I flipped those prefs and still have the bad performance on startup.

Comment 84

[Ioana Chiorean]

Hey Ritu, 
I will check this in the morning on several devices. NI'ing Bogdan from my team too for it.

Comment 85

[Ben Kelly [:bkelly, not reviewing]]

(In reply to Ben Kelly [:bkelly] from comment #81)
> I set browser.safebrowing.phishing.enabled to false.  (What is the other
> one?)  Unfortunately I can't get any page to load in this profile any more.

I think my page loading issue is due to something else and not these prefs.  Perhaps from trying to run an update from about:url-classifier.

Comment 86

[Joel Maher ( :jmaher ) (UTC -8)]

as a note, we track some basic page loads:
https://treeherder.mozilla.org/perf.html#/graphs?timerange=31536000&series=mozilla-inbound,1574442,1,3&series=mozilla-inbound,1567274,1,3&series=mozilla-inbound,1543659,1,3&series=mozilla-inbound,1574450,1,3

that is trunk, there isn't a lot of visible change there except for ~Nov 1, but that is not 57, it would be 58.

Comment 87

[Laurențiu Nicola]

I can't find it any more, but a while ago I was googling around for the browser.safebrowsing.*.enabled keys to see what the new ones do. I remember seeing a file from the Firefox's test runner that configured a profile for the tests. Some of the things it did was to disable these config keys.

Comment 88

[Marco Castelluccio [:marco]]

(In reply to Joel Maher ( :jmaher) (UTC-5) from comment #86)
> as a note, we track some basic page loads:
> https://treeherder.mozilla.org/perf.html#/
> graphs?timerange=31536000&series=mozilla-inbound,1574442,1,3&series=mozilla-
> inbound,1567274,1,3&series=mozilla-inbound,1543659,1,3&series=mozilla-
> inbound,1574450,1,3
> 
> that is trunk, there isn't a lot of visible change there except for ~Nov 1,
> but that is not 57, it would be 58.

Can we restrict the query to "first page loads" (which probably includes the time to start Gecko)? That seems to be what is regressing if I understand correctly.

Comment 89

[Marco Castelluccio [:marco]]

(In reply to Marco Castelluccio [:marco] from comment #88)
> (In reply to Joel Maher ( :jmaher) (UTC-5) from comment #86)
> > as a note, we track some basic page loads:
> > https://treeherder.mozilla.org/perf.html#/
> > graphs?timerange=31536000&series=mozilla-inbound,1574442,1,3&series=mozilla-
> > inbound,1567274,1,3&series=mozilla-inbound,1543659,1,3&series=mozilla-
> > inbound,1574450,1,3
> > 
> > that is trunk, there isn't a lot of visible change there except for ~Nov 1,
> > but that is not 57, it would be 58.
> 
> Can we restrict the query to "first page loads" (which probably includes the
> time to start Gecko)? That seems to be what is regressing if I understand
> correctly.

Ah sorry, I thought this was Telemetry, I hadn't noticed the actual link.
Anyway, the bug might not be visible during talos tests.

Comment 90

[Dimi Lee [:dimi]]

(In reply to James Willcox (:snorp) ([e-mail]) from comment #83)
> I flipped those prefs and still have the bad performance on startup.

The log jim provided indicated that safebrowsing worker thread took a long time while reading "goog-phish-shavar.sbstore" (As he mentioned in Comment 67.
Since we will wait until UrlClassifier returns the classify result, so page loading is stuck.

I was unable to reproduce that with the same "goog-phish-shavar.sbstore" on my platform, so I don't know why it took so long to read that file.

Ben, James,
Could you turn those prefs off and also remove the safebrowsing folder and check it again?
By only flipping off the pref with an existing "goog-phish-shavar.sbstore" will still cause this issue.

Comment 91

[(inactive) Jim Chen [:jchen] [:darchons]]

Good thing is I think 58 probably won't be affected because we switched to safe browsing v4 for 58 (bug 1394017) and this bug seems to affect data from safe browsing v2.

Comment 92

[(inactive) Jim Chen [:jchen] [:darchons]]

However, when we first update from 57 to 58, I think we'd still have the old databases. So until the v4 update runs, I think we might still be slowed down by the old v2 files.

Comment 93

[Andreas Bovens [:abovens]]

(In reply to Jim Chen [:jchen] [:darchons] from comment #92)
> However, when we first update from 57 to 58, I think we'd still have the old
> databases. So until the v4 update runs, I think we might still be slowed
> down by the old v2 files.

That's good and bad news... 

We should verify that it's actually fixed in 58, and then add a note to the release notes.

Comment 94

[Ritu Kothari (:ritu) (Inactive, please n-i to RyanVM, jcristau, or pascal)]

(In reply to Jim Chen [:jchen] [:darchons] from comment #92)
> However, when we first update from 57 to 58, I think we'd still have the old
> databases. So until the v4 update runs, I think we might still be slowed
> down by the old v2 files.

How long can this take?

Comment 95

[James Willcox (:snorp) ([e-mail]) (he/him)]

(In reply to Jim Chen [:jchen] [:darchons] from comment #92)
> However, when we first update from 57 to 58, I think we'd still have the old
> databases. So until the v4 update runs, I think we might still be slowed
> down by the old v2 files.

We should blow away the v2 databases when we upgrade to avoid this.

Comment 96

[Ritu Kothari (:ritu) (Inactive, please n-i to RyanVM, jcristau, or pascal)]

That's a good idea. Would that be a fix that can be whipped up soon to include in Fennec 58 RC build?

Comment 97

[(inactive) Jim Chen [:jchen] [:darchons]]

Attachment: Bug 1420641 - Don't reuse safe-browsing db from 57 for 58 on Android;

This patch, when applied on the 58 branch, temporarily changes the version
number of the safe-browsing databases so that we don't try to reuse any
databases from 57, that were causing the startup slowdown. When 58 regenerates
the databases, it will be using the new v4 source that doesn't have this issue.
On update to 59, the version numbers will revert to before and we will
regenerate the databases again, which I don't think will be too much of a
problem.

Review commit: https://reviewboard.mozilla.org/r/214166/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/214166/

Comment 98

[(inactive) Jim Chen [:jchen] [:darchons]]

Changing the version numbers (on the 58 branch only) seems like a least-risky way to not reuse the 57 databases, but let me know if there's a better way.

Comment 99

[Dimi Lee [:dimi]]

Comment on attachment 8943786 [details]
Bug 1420641 - Don't reuse safe-browsing db from 57 for 58 on Android;

https://reviewboard.mozilla.org/r/214166/#review219912

Thanks for your help jim! This should be the last review for me, if you found any problem, please check with francois, thank you.

Comment 100

[bull500]

Attachment: Fennecstream.png

I just noticed something else that could probably help.

On a wifi connection that is being used for say downloading a large file on a laptop, opening Fennec leads to a slowness.
The white UI loads up fine but everything else takes time. A good portion of my stickied sites are nameless. Some have their icons missing.  

I suspect its not storing on my phone but rather pulling in all the data at launch. If that's the case then i guess locally storing would be much better and update only if new content is available or once per day.   

Pocket is also blank.

Comment 102

[Bogdan Surd, QA [:bsurd, NI]]

Devices:
 - Google Pixel (Android 8.0);
 - Nexus 5 (Android 5.0.1);
 - Samsung Galaxy S8 (Android 7.0);
 - Huawei P10 (Android 7.0);
 - Huawei Honor 5X (Android 5.1.1);
 - Sony Xperia Z5 Premium (Android 6.0.1);
 - Samsung Galaxy S7 (Android 7.0) - personal device (FF installed for several weeks and didn't notice any kind of slowdown so far).
 
Hey everyone,

 I've tried reproducing this with several devices with different pages and steps among those in the comment section (Comment 29,Comment 80), as mentioned in Comment 22 there is a slight to large delay in that state depending on the page that you access from what I've seen, but nothing out of the ordinary.

 Seeing as FF was freshly installed on all of the devices with the latest Nightly, Beta and Release versions as well as the special debuggable from Comment 60 everything worked as expected. Browsed the net for a while, accessing different pages but everything seemed to load normally.

 I will use a couple of phones over the next following days with the same build installed and see if I notice any kind of slowdown since I've seen multiple comments that say the issue started appearing after using FF for a while. Will come back with the results (if any) on Monday or Tuesday or sooner if I notice of find anything.

Comment 103

[Marco Castelluccio [:marco]]

(In reply to Bogdan Surd, QA [:BogdanS, NI] from comment #102)
> Devices:
>  - Google Pixel (Android 8.0);
>  - Nexus 5 (Android 5.0.1);
>  - Samsung Galaxy S8 (Android 7.0);
>  - Huawei P10 (Android 7.0);
>  - Huawei Honor 5X (Android 5.1.1);
>  - Sony Xperia Z5 Premium (Android 6.0.1);
>  - Samsung Galaxy S7 (Android 7.0) - personal device (FF installed for
> several weeks and didn't notice any kind of slowdown so far).
>  
> Hey everyone,
> 
>  I've tried reproducing this with several devices with different pages and
> steps among those in the comment section (Comment 29,Comment 80), as
> mentioned in Comment 22 there is a slight to large delay in that state
> depending on the page that you access from what I've seen, but nothing out
> of the ordinary.
> 
>  Seeing as FF was freshly installed on all of the devices with the latest
> Nightly, Beta and Release versions as well as the special debuggable from
> Comment 60 everything worked as expected. Browsed the net for a while,
> accessing different pages but everything seemed to load normally.
> 
>  I will use a couple of phones over the next following days with the same
> build installed and see if I notice any kind of slowdown since I've seen
> multiple comments that say the issue started appearing after using FF for a
> while. Will come back with the results (if any) on Monday or Tuesday or
> sooner if I notice of find anything.

According to :snorp, this is reproducible if you let Firefox run long enough to
download the updated safebrowsing databases (not sure how long that is).

Comment 104

[(inactive) Jim Chen [:jchen] [:darchons]]

Comment on attachment 8943786 [details]
Bug 1420641 - Don't reuse safe-browsing db from 57 for 58 on Android;

Request for 58 branch. I verified with a try build that with this patch, we don't reuse old safe-browsing databases.

Approval Request Comment
[Feature/Bug causing the regression]: N/A
[User impact if declined]: Possible noticeably slow page load on startup when first updating to 58
[Is this code covered by automated tests?]: No
[Has the fix been verified in Nightly?]: No
[Needs manual test from QE? If yes, steps to reproduce]: No
[List of other uplifts needed for the feature/fix]: None
[Is the change risky?]: No
[Why is the change risky/not risky?]: The actual patch is only a few lines and doesn't introduce any behavior changes; it's designed to have minimal risk.
[String changes made/needed]: None

Comment 105

[Ritu Kothari (:ritu) (Inactive, please n-i to RyanVM, jcristau, or pascal)]

Comment on attachment 8943786 [details]
Bug 1420641 - Don't reuse safe-browsing db from 57 for 58 on Android;

Since 58 is mostly unaffected by this issue, we decided to build RC2 yesterday when this fix was not ready. Let's review this fix when/if we do a 58.x release.

Comment 106

[(inactive) Jim Chen [:jchen] [:darchons]]

Well this patch specifically targets the 57 -> 58 upgrade window, so it will likely not be necessary/useful for a 58.x release.

Comment 107

[Andrei Petcu]

If it is of any help, I have a One Plus 2 phone with Lineage OS 14.1 (based on Android 7.1.2) and pages load slowly on Stable and Beta but they load fast in Nightly. I use Nightly as my daily driver. I use the others mostly for testing stuff.

Comment 108

[Bogdan Surd, QA [:bsurd, NI]]

Devices:
 - Google Pixel (Android 8.0.0);
 - Nexus 5 (Android 6.0.1);
Builds:
 - Nightly (2018-01-18);
 - Beta (58.0b17);
 - Release (58 RC build 2);
 - Bug 1420641 (Comment 60).

During the weekend I tested this using the mentioned devices, there was no noticeable slowdown on the Pixel, but there was one on the "Bug 1420641" debuggable .apk on the Nexus 5. Didn't have any kind of slowdown in any of the other builds tho.
So as per Comment 104 this seems to have been fixed.

Comment 109

[Ritu Kothari (:ritu) (Inactive, please n-i to RyanVM, jcristau, or pascal)]

Hi Jim, since 59 status is marked as affected, does this patch need to land on beta59? Or just 58?

Comment 110

[(inactive) Jim Chen [:jchen] [:darchons]]

I don't think 59 is affected. 58 should only be affected on initial update from 57 to 58.

Comment 111

[Ritu Kothari (:ritu) (Inactive, please n-i to RyanVM, jcristau, or pascal)]

This was added to Fennec 58 release notes.

Comment 112

[James Willcox (:snorp) ([e-mail]) (he/him)]

(In reply to Ritu Kothari (:ritu) from comment #111)
> This was added to Fennec 58 release notes.

Because the patch from this bug was not taken in the 58 release, users are still affected by this until the next safebrowsing database update.

Comment 113

[Sylvestre Ledru [:Sylvestre]]

Comment on attachment 8943786 [details]
Bug 1420641 - Don't reuse safe-browsing db from 57 for 58 on Android;

Let's take it for a potential dot release for android.

Comment 114

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-release/rev/586e26fcca79

Comment 115

[:sdaswani]

Mike, NI'ing you just to let you know that it seems this bug is driving towards resolution. NI me if you disagree - otherwise no action to take.

Comment 116

[Michael Comella (:mcomella) [NI reported issues only: ex-Mozilla]]

Jim, can we close as FIXED?

Comment 117

[Bogdan Surd, QA [:bsurd, NI]]

Hey everyone, verified this with the Nexus 5 where I was able to reproduce the slowdown when testing. Could not reproduce this issue anymore. Marking as verified

Comment 119

[François Marier [:francois]]

Attachment: goog-phish-shavar.pset

Copy of file from comment 67.

Comment 120

[François Marier [:francois]]

Attachment: goog-phish-shavar.sbstore

Copy of file from comment 67.

Comment 121

[Bapf]

Anyone else experiencing this bug again, or is it just me?
(Firefox 68 on OxygenOS running on OnePlus 5T)

Comment 122

[black-z]

(In reply to Bapf from comment #121)

Anyone else experiencing this bug again, or is it just me?
(Firefox 68 on OxygenOS running on OnePlus 5T)

Have this. Nexus 5. Android 6. Firefox 68.

Comment 123

[Dylan]

Seeing this issue as well. OnePlus 6t. Android 9. Firefox 68 and 68.1b3

Comment 124

[Sam Dunham]

Same here. Oxygen OS 9.5.10, OnePlus 7 Pro.