708934 - [viewport] Managed to get Fennec into a state where it just shows blank white pages on all tabs

Status: RESOLVED DUPLICATE of bug 717085

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

Description

[Deb Richardson [:dria] (plz NEEDINFO)]

Not sure how to replicate this one yet, but I'll try once I can figure out how to get out of this state.

What happened was: I opened 11 tabs in Fennec using "Open Link in New Tab", a few picked out of my Awesomebar after creating new tabs, and a couple opened from another app.  Now all of the tabs are just showing a blank white page, including any new tabs I create, and reloading a tab doesn't fix it.

At one point I had one tab showing parts of the Nightly start page, but just the icon and the section titles ("Favourite Sites") -- the grey boxes with the thumbnails weren't showing.

Comment 1

[Deb Richardson [:dria] (plz NEEDINFO)]

Quitting and restarting fixed it, but lost all my tabs (which I think is expected).

Comment 2

[Deb Richardson [:dria] (plz NEEDINFO)]

Ok, I managed to replicate this by clicking a link on a page and switching to another app using the app-switcher button before the page had finished loading.  I couldn't replicate it with only a few tabs open, only when i had 10 or more open.  And you have to switch between apps pretty quickly -- the page load has to be interrupted.

I grabbed a screenshot of the icon-and-titles-only Nightly start page as well, which was what was displayed when I switched back to Fennec while it was in this state.  Will attach.

Comment 3

[Deb Richardson [:dria] (plz NEEDINFO)]

Attachment: weird start page displayed when switched back to broken fennec

Comment 4

[Mark Finkle (:mfinkle) (use needinfo?)]

Things certainly look busted. I think not tried to reproduce this yet, but I wanted to point you at the process of getting "logs" from Android, to help debug some of these kinds of issues. All Android and Gecko error messages show up in something called "logcat", which you can access via the Android SDK using | adb logcat | or by using a device application called aLogCat. See : https://wiki.mozilla.org/Mobile/Fennec/Android#Using_aLogCat

If you could capture the logcat while Fennec is running and failing, it would be a great help.

Comment 5

[Deb Richardson [:dria] (plz NEEDINFO)]

Attachment: Log of faily Fennec

Comment 6

[Deb Richardson [:dria] (plz NEEDINFO)]

I managed to replicate the fail and I think i got a log of it.  I didn't do it by switching apps this time, however, so I'm really not sure what I did.  Log attached.

Will try to replicate it with the app-switching thing again.

Comment 7

[Naoki Hirata :nhirata (please use needinfo instead of cc)]

Not sure, but it looks like fennec might have been partially killed in the background when you came back to it?  I saw this towards the end of the log:

D/OpenGLRenderer( 3759): Flushing caches (mode 1)
I/GeckoApp( 3265): destroy
D/GeckoFavicons( 3265): Closing Favicons database

Comment 8

[Deb Richardson [:dria] (plz NEEDINFO)]

I managed to make this happen again twice tonight, but just when browsing around not when switching apps or anything.  I'm on the latest Fennec Nightly running on a new Galaxy Nexus Prime.

I grabbed the logs & will attach.

Comment 9

[Deb Richardson [:dria] (plz NEEDINFO)]

Attachment: Log of faily Fennec #2 (Dec 13, browsing not switching apps)

Comment 10

[Deb Richardson [:dria] (plz NEEDINFO)]

Attachment: Log #3 (Dec 13, just browsing & possibly hit something in the top UI)

Comment 11

[Naoki Hirata :nhirata (please use needinfo instead of cc)]

I think she's hitting 2 separate bugs.  log 2 shows :
E/StrictMode( 4978): A resource was acquired at attached stack trace but never released. See java.io.Closeable for information on avoiding resource leaks.
E/StrictMode( 4978): java.lang.Throwable: Explicit termination method 'close' not called
E/StrictMode( 4978): at dalvik.system.CloseGuard.open(CloseGuard.java:184)
E/StrictMode( 4978): at java.io.FileInputStream.<init>(FileInputStream.java:80)
E/StrictMode( 4978): at org.mozilla.gecko.AboutHomeContent.getProfileRecommendedAddonsStream(AboutHomeContent.java:162)
E/StrictMode( 4978): at org.mozilla.gecko.AboutHomeContent.getRecommendedAddonsStream(AboutHomeContent.java:170)
E/StrictMode( 4978): at org.mozilla.gecko.AboutHomeContent$4.run(AboutHomeContent.java:184)
E/StrictMode( 4978): at android.os.Handler.handleCallback(Handler.java:605)
E/StrictMode( 4978): at android.os.Handler.dispatchMessage(Handler.java:92)
E/StrictMode( 4978): at android.os.Looper.loop(Looper.java:137)
E/StrictMode( 4978): at org.mozilla.gecko.GeckoAppShell$LooperThread.run(GeckoAppShell.java:153)
D/dalvikvm( 4978): GC_CONCURRENT freed 989K, 17% free 25215K/30343K, paused 2ms+3ms
I/GeckoApp( 4978): stop
E/JavaBinder( 4978): !!! FAILED BINDER TRANSACTION !!!
I/dalvikvm(13451): Turning on JNI app bug workarounds for target SDK version 4...

Log 3 shows: 
I/ActivityManager(  177): Displayed org.mozilla.fennec/org.mozilla.gecko.TabsTray: +363ms
I/GeckoSoftwareLayerClient(20419): Adjusting viewport
E/GeckoViewportMetrics(20419): Error serializing viewportmetrics
E/GeckoViewportMetrics(20419): org.json.JSONException: Forbidden numeric value: NaN
E/GeckoViewportMetrics(20419): at org.json.JSON.checkDouble(JSON.java:25)
E/GeckoViewportMetrics(20419): at org.json.JSONObject.numberToString(JSONObject.java:684)
E/GeckoViewportMetrics(20419): at org.json.JSONStringer.value(JSONStringer.java:284)
E/GeckoViewportMetrics(20419): at org.mozilla.gecko.gfx.ViewportMetrics.toJSON(ViewportMetrics.java:239)
E/GeckoViewportMetrics(20419): at org.mozilla.gecko.gfx.GeckoSoftwareLayerClient.adjustViewport(GeckoSoftwareLayerClient.java:291)
E/GeckoViewportMetrics(20419): at org.mozilla.gecko.gfx.GeckoSoftwareLayerClient.access$600(GeckoSoftwareLayerClient.java:71)
E/GeckoViewportMetrics(20419): at org.mozilla.gecko.gfx.GeckoSoftwareLayerClient$3.run(GeckoSoftwareLayerClient.java:272)
E/GeckoViewportMetrics(20419): at android.os.Handler.handleCallback(Handler.java:605)
E/GeckoViewportMetrics(20419): at android.os.Handler.dispatchMessage(Handler.java:92)
E/GeckoViewportMetrics(20419): at android.os.Looper.loop(Looper.java:137)
E/GeckoViewportMetrics(20419): at org.mozilla.gecko.GeckoApp$26.run(GeckoApp.java:1372)
E/GeckoViewportMetrics(20419): at android.os.Handler.handleCallback(Handler.java:605)
E/GeckoViewportMetrics(20419): at android.os.Handler.dispatchMessage(Handler.java:92)
E/GeckoViewportMetrics(20419): at android.os.Looper.loop(Looper.java:137)
E/GeckoViewportMetrics(20419): at android.app.ActivityThread.main(ActivityThread.java:4340)
E/GeckoViewportMetrics(20419): at java.lang.reflect.Method.invokeNative(Native Method)
E/GeckoViewportMetrics(20419): at java.lang.reflect.Method.invoke(Method.java:511)
E/GeckoViewportMetrics(20419): at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:784)
E/GeckoViewportMetrics(20419): at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:551)
E/GeckoViewportMetrics(20419): at dalvik.system.NativeStart.main(Native Method)
E/GeckoConsole(20419): [JavaScript Error: "JSON.parse: unexpected end of data" {file: "chrome://browser/content/browser.js" line: 613}]
W/ResourceType(  177): Skipping entry 0x7f040001 in package table 0 because it is not complex!

Comment 12

[Kartikaya Gupta (email:[e-mail])]

(In reply to Deb Richardson [:dria] from comment #5)
> Created attachment 580301 [details]
> Log of faily Fennec

This one I believe was fixed in https://hg.mozilla.org/mozilla-central/rev/4850eb9ce32a

(In reply to Deb Richardson [:dria] from comment #10)
> Created attachment 581524 [details]
> Log #3 (Dec 13, just browsing & possibly hit something in the top UI)

But here it appears we still have a problem with generating NaN viewport values somewhere even with the above patch.

Comment 13

[Kartikaya Gupta (email:[e-mail])]

(In reply to Deb Richardson [:dria] from comment #9)
> Created attachment 581523 [details]
> Log of faily Fennec #2 (Dec 13, browsing not switching apps)

I filed bug 710864 for the StrictMode warning in this log.

Comment 14

[Kartikaya Gupta (email:[e-mail])]

If you see in this a newer build please do attach a new log, since the relevant code has changed and the new log will provide more useful information.

Comment 15

[Chris Peterson [:cpeterson]]

I can still reproduce these blank tabs pretty often on my Galaxy Nexus. (I haven't tested much on other devices.)

Comment 16

[Tony Chung [:tchung]]

requesting logs

Comment 17

[Camelia Urian]

Attachment: Logs - browsing and switching apps

Build ID: Mozilla/5.0 (Android; Linux armv7l; rv:12.0a1) Gecko/20120104 Firefox/12.0a1 Fennec/12.0a1
Device: Galaxy Nexus 
OS: Android 4.0.1

I was able to reproduce issue on above environment and take logs.
- I had about 13 tabs open, and kept switching apps.

Comment 18

[Tony Chung [:tchung]]

(In reply to Camelia Urian from comment #17)
> Created attachment 586081 [details]
> Logs - browsing and switching apps
> 
> Build ID: Mozilla/5.0 (Android; Linux armv7l; rv:12.0a1) Gecko/20120104
> Firefox/12.0a1 Fennec/12.0a1
> Device: Galaxy Nexus 
> OS: Android 4.0.1
> 
> I was able to reproduce issue on above environment and take logs.
> - I had about 13 tabs open, and kept switching apps.

Thanks Camelia!  Kats, any help?

Comment 19

[Kartikaya Gupta (email:[e-mail])]

Sorry, been busy with other bugs. But yes, the logs look useful; thanks very much for getting them! I'll analyze this further and put together a patch.

Comment 20

[Brad Lassey [:blassey] (use needinfo?)]

Deb, do you still see this?

Comment 21

[Deb Richardson [:dria] (plz NEEDINFO)]

I haven't seen this in a while and wasn't able to reproduce it just now hammering on nightly for a bit.

Comment 22

[Kartikaya Gupta (email:[e-mail])]

I traced through the log Camelia posted and based on that I believe that the patch from bug 717085 will fix this. Near the end of the log I can see Fennec restarting and the viewport having a zoom of ~0.001, which happens because it tries restoring tabs without knowing what the screen size is, resulting in the viewport badness. I assume the app-switching results in a greater chance of Android killing Fennec and resulting in this condition.

I'll leave this open for now but it should be re-tested once that patch goes in to see if it fixes the problem.

Comment 23

[Kartikaya Gupta (email:[e-mail])]

This should be fixed in today's nightly with the patch from bug 717085. I'm going to mark it as fixed, but please reopen it if you still see it happening. Also, if you see this again please attach new logcat output as well, as it will make it easier to diagnose.

Comment 25

[notuf]

I experience this bug in fennec 39 ARM Android 4.2.2 on Lifetab E10312.