741116 - Nightly hangs and shows "Nightly is not responding" dialogs

Status: RESOLVED DUPLICATE of bug 736237

(Firefox for Android Graveyard :: General, defect)

Description

[Doug Turner (:dougt)]

I am seeing lots of hangs when browsing on a Google Nexus.  These are frequent enough to make nightly unusable for dogfooding.


tail of logcat:

D/dalvikvm( 8101): GC_FOR_ALLOC freed 0K, 11% free 21248K/23815K, paused 21ms
I/ActivityManager(  198): START {cmp=org.mozilla.fennec/org.mozilla.gecko.TabsTray} from pid 8101
I/ActivityManager(  198): START {cmp=org.mozilla.fennec/org.mozilla.gecko.TabsTray} from pid 8101
W/ActivityManager(  198): Activity pause timeout for ActivityRecord{41864f08 org.mozilla.fennec/.App}
D/OpenGLRenderer(17704): Flushing caches (mode 1)
I/InputDispatcher(  198): Application is not responding: Window{41cdc160 org.mozilla.fennec/org.mozilla.fennec.App paused=false}.  8019.7ms since event, 5000.4ms since wait started
I/WindowManager(  198): Input event dispatching timed out sending to org.mozilla.fennec/org.mozilla.fennec.App
I/Process (  198): Sending signal. PID: 8101 SIG: 3
I/dalvikvm( 8101): threadid=3: reacting to signal 3
I/dalvikvm( 8101): Wrote stack traces to '/data/anr/traces.txt'
I/Process (  198): Sending signal. PID: 198 SIG: 3
I/dalvikvm(  198): threadid=3: reacting to signal 3
I/dalvikvm(  198): Wrote stack traces to '/data/anr/traces.txt'
I/Process (  198): Sending signal. PID: 270 SIG: 3
I/dalvikvm(  270): threadid=3: reacting to signal 3
I/dalvikvm(  270): Wrote stack traces to '/data/anr/traces.txt'
I/Process (  198): Sending signal. PID: 384 SIG: 3
I/dalvikvm(  384): threadid=3: reacting to signal 3
I/dalvikvm(  384): Wrote stack traces to '/data/anr/traces.txt'
I/Process (  198): Sending signal. PID: 394 SIG: 3
I/dalvikvm(  394): threadid=3: reacting to signal 3
I/dalvikvm(  394): Wrote stack traces to '/data/anr/traces.txt'
D/dalvikvm(  198): GC_CONCURRENT freed 1846K, 18% free 28048K/34119K, paused 3ms+7ms
D/dalvikvm(  198): GC_EXPLICIT freed 384K, 18% free 28124K/34119K, paused 3ms+6ms
E/ActivityManager(  198): ANR in org.mozilla.fennec (org.mozilla.fennec/org.mozilla.gecko.TabsTray)
E/ActivityManager(  198): Reason: keyDispatchingTimedOut
E/ActivityManager(  198): Parent: org.mozilla.fennec/.App
E/ActivityManager(  198): Load: 1.05 / 1.9 / 1.48
E/ActivityManager(  198): CPU usage from 5704ms to 0ms ago:
E/ActivityManager(  198):   113% 8101/org.mozilla.fennec: 110% user + 3.3% kernel / faults: 7 minor
E/ActivityManager(  198):   1.7% 198/system_server: 0.5% user + 1.2% kernel / faults: 37 minor 1 major
E/ActivityManager(  198):   1% 120/mediaserver: 0.8% user + 0.1% kernel / faults: 17 minor
E/ActivityManager(  198):   0% 105/irq/206-mms_ts: 0% user + 0% kernel
E/ActivityManager(  198):   0.1% 117/surfaceflinger: 0.1% user + 0% kernel
E/ActivityManager(  198):   0.1% 4464/kworker/u:1: 0% user + 0.1% kernel
E/ActivityManager(  198): 58% TOTAL: 56% user + 2.7% kernel
E/ActivityManager(  198): CPU usage from 507ms to 1024ms later:
E/ActivityManager(  198):   109% 8101/org.mozilla.fennec: 101% user + 7.6% kernel
E/ActivityManager(  198):     94% 8101/.mozilla.fennec: 88% user + 5.7% kernel
E/ActivityManager(  198):     13% 8137/Thread-1029: 11% user + 1.9% kernel
E/ActivityManager(  198):     1.9% 9510/er$SensorThread: 1.9% user + 0% kernel
E/ActivityManager(  198):   5.7% 198/system_server: 1.9% user + 3.8% kernel
E/ActivityManager(  198):     1.9% 229/InputDispatcher: 0% user + 1.9% kernel
E/ActivityManager(  198):     1.9% 251/WifiService: 0% user + 1.9% kernel
E/ActivityManager(  198):   1.2% 4464/kworker/u:1: 0% user + 1.2% kernel
E/ActivityManager(  198): 60% TOTAL: 53% user + 6.7% kernel
I/WindowManager(  198): createSurface Window{41854c38  paused=false}: DRAW NOW PENDING
I/ActivityManager(  198): START {cmp=org.mozilla.fennec/org.mozilla.gecko.TabsTray} from pid 8101
I/GeckoApp( 8101): pause
I/GeckoViewsFactory( 8101): Creating custom Gecko view: TabsTray$TabsListContainer
I/GeckoViewsFactory( 8101): Creating custom Gecko view: LinkTextView
I/Gecko   ( 8101): Compositor: Composite took 35 ms.
I/ActivityManager(  198): START {cmp=org.mozilla.fennec/org.mozilla.gecko.TabsTray} from pid 8101
I/WindowManager(  198): createSurface Window{41aa2798 org.mozilla.fennec/org.mozilla.gecko.TabsTray paused=false}: DRAW NOW PENDING
I/Gecko   ( 8101): Compositor: Composite took 48 ms.
I/ActivityManager(  198): Displayed org.mozilla.fennec/org.mozilla.gecko.TabsTray: +8s283ms
W/ActivityManager(  198): Launch timeout has expired, giving up wake lock!
W/ActivityManager(  198): Activity idle timeout for ActivityRecord{41e1c4d0 org.mozilla.fennec/org.mozilla.gecko.TabsTray}

Comment 1

[Doug Turner (:dougt)]

Attachment: /data/anr/traces.txt

Maybe this is org.mozilla.gecko.AboutHomeContent$TopSitesCursorAdapter taking too much time?

Comment 2

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

Is it possible that you have a XUL profile migration happening? Gian-Carlo was making a patch in a different bug that makes AboutHome ignore cursor changes.

  at android.widget.CursorAdapter.getCount(CursorAdapter.java:196)
  at org.mozilla.gecko.AboutHomeContent$TopSitesCursorAdapter.getCount(AboutHomeContent.java:731)
  at android.widget.AdapterView$AdapterDataSetObserver.onChanged(AdapterView.java:789)
  at android.widget.AbsListView$AdapterDataSetObserver.onChanged(AbsListView.java:5592)

His patch would make this completely go away. I'm not sure what bug that patch was attached to though. Gian-Carlo?

Comment 3

[Doug Turner (:dougt)]

No migration happening that I am aware of.  I see this when browsing around.

Comment 4

[Gian-Carlo Pascutto [:gcp]]

Attachment: Patch. Avoid about:home updates

The bug I found affects *everything* that accesses the history/bookmarks DB, including simple browsing. Profile Migration was just hit worse because it does a lot of it. Attached is the patch that disables homepage updates.

Doug, do you have sync enabled? Large amount of bookmarks/history Does the patch fix this for you?

Comment 5

[Doug Turner (:dougt)]

gcp, i had sync enabled.  I disabled sync from the Settings application and I am still seeing the ANRs.

I cleared my profile and history from the in-app preferences.   I haven't seen an ANR yet.

Comment 6

[Aaron Train [:aaronmt]]

Attachment: Nightly (04/02) logcat

I get this accessing the AwesomeScreen immediately following a cold-start (Nightly 04/02)

Comment 8

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

(In reply to Gian-Carlo Pascutto (:gcp) from comment #4)
> Created attachment 611351 [details] [diff] [review]
> Patch. Avoid about:home updates
> 
> The bug I found affects *everything* that accesses the history/bookmarks DB,
> including simple browsing. Profile Migration was just hit worse because it
> does a lot of it. Attached is the patch that disables homepage updates.
> 
> Doug, do you have sync enabled? Large amount of bookmarks/history Does the
> patch fix this for you?

This patch is in bug 736237