Closed Bug 746946 Opened 9 years ago Closed 9 years ago

Fennec crashes repeatedly after opening the bookmarks or history section with a clean profile

Categories

(Firefox for Android :: General, defect)

ARM
Android
defect
Not set
critical

Tracking

()

VERIFIED FIXED
Firefox 15
Tracking Status
firefox14 --- verified
blocking-fennec1.0 --- beta+

People

(Reporter: paul.feher, Assigned: Margaret)

References

Details

(Keywords: crash, reproducible, topcrash, Whiteboard: [native-crash])

Crash Data

Attachments

(2 files)

Attached file Log file
Nightly Fennec 14.0a1 (2012-04-19)
Device: HTC Desire Z
OS: Android 2.3.3

Steps to reproduce:
1. Start fennec with a clean profile
2. Tap on the Bookmarks section in awesome menu

Fennec crashes repeatedly after accessing the bookmark section for the first time.I can't access the crash report in about:crashes.

NOTE: Please see the attached log file.

04-19 15:09:37.481: E/GeckoAppShell(16870): >>> REPORTING UNCAUGHT EXCEPTION FROM THREAD 10 ("GeckoBackgroundThread")
04-19 15:09:37.481: E/GeckoAppShell(16870): android.view.ViewRoot$CalledFromWrongThreadException: Only the original thread that created a view hierarchy can touch its views.
04-19 15:09:37.481: E/GeckoAppShell(16870): 	at android.view.ViewRoot.checkThread(ViewRoot.java:3094)
04-19 15:09:37.481: E/GeckoAppShell(16870): 	at android.view.ViewRoot.requestLayout(ViewRoot.java:646)
04-19 15:09:37.481: E/GeckoAppShell(16870): 	at android.view.View.requestLayout(View.java:8464)
04-19 15:09:37.481: E/GeckoAppShell(16870): 	at android.view.View.requestLayout(View.java:8464)
04-19 15:09:37.481: E/GeckoAppShell(16870): 	at android.view.View.requestLayout(View.java:8464)
04-19 15:09:37.481: E/GeckoAppShell(16870): 	at android.view.View.requestLayout(View.java:8464)
04-19 15:09:37.481: E/GeckoAppShell(16870): 	at android.view.View.requestLayout(View.java:8464)
04-19 15:09:37.481: E/GeckoAppShell(16870): 	at android.view.View.requestLayout(View.java:8464)
04-19 15:09:37.481: E/GeckoAppShell(16870): 	at android.view.View.requestLayout(View.java:8464)
04-19 15:09:37.481: E/GeckoAppShell(16870): 	at android.widget.AbsListView.requestLayout(AbsListView.java:1102)
04-19 15:09:37.481: E/GeckoAppShell(16870): 	at android.widget.ListView.setAdapter(ListView.java:497)
04-19 15:09:37.481: E/GeckoAppShell(16870): 	at org.mozilla.gecko.AwesomeBarTabs$BookmarksQueryTask.onPostExecute(AwesomeBarTabs.java:368)
04-19 15:09:37.481: E/GeckoAppShell(16870): 	at org.mozilla.gecko.AwesomeBarTabs$BookmarksQueryTask.onPostExecute(AwesomeBarTabs.java:339)
04-19 15:09:37.481: E/GeckoAppShell(16870): 	at android.os.AsyncTask.finish(AsyncTask.java:417)
04-19 15:09:37.481: E/GeckoAppShell(16870): 	at android.os.AsyncTask.access$300(AsyncTask.java:127)
04-19 15:09:37.481: E/GeckoAppShell(16870): 	at android.os.AsyncTask$InternalHandler.handleMessage(AsyncTask.java:429)
04-19 15:09:37.481: E/GeckoAppShell(16870): 	at android.os.Handler.dispatchMessage(Handler.java:99)
04-19 15:09:37.481: E/GeckoAppShell(16870): 	at android.os.Looper.loop(Looper.java:143)
04-19 15:09:37.481: E/GeckoAppShell(16870): 	at org.mozilla.gecko.GeckoBackgroundThread.run(GeckoBackgroundThread.java:31)
Crash Signature: [@ android.view.ViewRoot$CalledFromWrongThreadException: Only the original thread that created a view hierarchy can touch its views. at android.view.ViewRoot.checkThread(ViewRoot.java)]
Keywords: crash
Whiteboard: [native-crash]
I believe that the deletions of the bookmarks are slow and causing an issue when you clear history.  I still saw it when I immediately went to the awesome page after deleting.  At first I thought it wasn't deleting properly.  It turns out that it does delete, but it takes a bit of time to do so.
Keywords: reproducible
blocking-fennec1.0: --- → ?
Assignee: nobody → margaret.leibovic
blocking-fennec1.0: ? → +
Paul, did you previously have a version of Fennec installed on your device? The logs attached show a crash stack that goes through profile migration code.

(In reply to Naoki Hirata :nhirata from comment #2)
> I believe that the deletions of the bookmarks are slow and causing an issue
> when you clear history.  I still saw it when I immediately went to the
> awesome page after deleting.  At first I thought it wasn't deleting
> properly.  It turns out that it does delete, but it takes a bit of time to
> do so.

I'm confused - what deletions of bookmarks are you talking about? Paul's initial bug description made it sound like this was happening to him during a first-run experience.
>The logs attached show a crash stack that goes through profile migration code.

It's a StrictMode violation warning, not a crash (bug 746365). 

The crash is earlier up in his log:

04-19 15:09:37.481: E/GeckoAppShell(16870): 	at org.mozilla.gecko.AwesomeBarTabs$BookmarksQueryTask.onPostExecute(AwesomeBarTabs.java:368)
04-19 15:09:37.481: E/GeckoAppShell(16870): 	at org.mozilla.gecko.AwesomeBarTabs$BookmarksQueryTask.onPostExecute(AwesomeBarTabs.java:339)
0
Ok I can reproduce this on the Galaxy II -- create a new profile, start Nightly, immediately hit the awesome-screen and tap the bookmarks tab ...
Pasting the crash stack so that it's easier to see.
https://crash-stats.mozilla.com/report/index/bp-60973948-c47f-4f97-b804-fdd1c2120419

android.view.ViewRoot$CalledFromWrongThreadException: Only the original thread that created a view hierarchy can touch its views.
	at android.view.ViewRoot.checkThread(ViewRoot.java:2802)
	at android.view.ViewRoot.requestLayout(ViewRoot.java:594)
	at android.view.View.requestLayout(View.java:8125)
	at android.view.View.requestLayout(View.java:8125)
	at android.view.View.requestLayout(View.java:8125)
	at android.view.View.requestLayout(View.java:8125)
	at android.view.View.requestLayout(View.java:8125)
	at android.view.View.requestLayout(View.java:8125)
	at android.view.View.requestLayout(View.java:8125)
	at android.widget.AbsListView.requestLayout(AbsListView.java:993)
	at android.widget.ListView.setAdapter(ListView.java:479)
	at org.mozilla.gecko.AwesomeBarTabs$BookmarksQueryTask.onPostExecute(AwesomeBarTabs.java:368)
	at org.mozilla.gecko.AwesomeBarTabs$BookmarksQueryTask.onPostExecute(AwesomeBarTabs.java:339)
	at android.os.AsyncTask.finish(AsyncTask.java:417)
	at android.os.AsyncTask.access$300(AsyncTask.java:127)
	at android.os.AsyncTask$InternalHandler.handleMessage(AsyncTask.java:429)
	at android.os.Handler.dispatchMessage(Handler.java:99)
	at android.os.Looper.loop(Looper.java:123)
	at org.mozilla.gecko.GeckoBackgroundThread.run(GeckoBackgroundThread.java:31)
I can crash just as Paul does, hitting the clear history after doing some navigation.
bug 747109?
Naoki, this is a new profile and immediately *with swift haste!* going to the Bookmark Tab while Gecko is churning  - Galaxy Nexus too fast, hitting this on the SII and the Xperia Play
I did the same crash in Comment 6 by clearing my history in the settings and then going to immediately to the history in the awesome page.  I didn't need to create a new profile.
(In reply to Naoki Hirata :nhirata from comment #9)
> I did the same crash in Comment 6 by clearing my history in the settings and
> then going to immediately to the history in the awesome page.  I didn't need
> to create a new profile.

same crash == same stack ?
Same stack, yes.  comment 6 is my crash stack from socorro in response to comment 3 and comment 4.
(In reply to Margaret Leibovic [:margaret] from comment #3)
> Paul, did you previously have a version of Fennec installed on your device?
> The logs attached show a crash stack that goes through profile migration
> code.
> 
> (In reply to Naoki Hirata :nhirata from comment #2)
> > I believe that the deletions of the bookmarks are slow and causing an issue
> > when you clear history.  I still saw it when I immediately went to the
> > awesome page after deleting.  At first I thought it wasn't deleting
> > properly.  It turns out that it does delete, but it takes a bit of time to
> > do so.
> 
> I'm confused - what deletions of bookmarks are you talking about? Paul's
> initial bug description made it sound like this was happening to him during
> a first-run experience.

This is happening on a first-run but also if you make a fennec update, like it was in my case. I have noticed that, in some cases, it appears if the application is not used for a few minutes.
There are about 20 crashes per build with this signature.
Keywords: topcrash
This is 100% reproducible on a Galaxy S Captivate after creating a new profile.
i keep hitting this on HTC Incredible S, 4-24-2012, Android 2.3.4.

STR is same as comment 0, launch awesomescreen and tap on bookmarks

https://crash-stats.mozilla.com/report/index/bp-a3528839-9525-410b-b027-b42082120424
I was able to reproduce on a Nexus S. The problem is that we seem to be creating BookmarksQueryTask (or HistoryQueryTask in the case of bug 747447) on a background thread, causing the onPostExecute to run on the background thread as well.

Forcing the contents of onPostExecute to run on the main thread fixes the crash, but I'd like to find out how we're creating these tasks on the wrong thread in the first place (and why it only happens sometimes).
Duplicate of this bug: 747447
Updating the summary to reflect the symptom that was also reported in bug 747447.
Summary: Fennec crashes repeatedly after opening the bookmarks section with a clean profile → Fennec crashes repeatedly after opening the bookmarks or history section with a clean profile
for reference on my HTC Incredible S.

04-26 13:27:57.321: INFO/Gecko(15687): Compositor: Composite took 34 ms.
04-26 13:27:57.381: ERROR/GeckoCrashReporter(15687): exception while closing progress dialog: 
04-26 13:27:57.381: ERROR/GeckoCrashReporter(15687): java.lang.IllegalArgumentException: View not attached to window manager
04-26 13:27:57.381: ERROR/GeckoCrashReporter(15687):     at android.view.WindowManagerImpl.findViewLocked(WindowManagerImpl.java:391)
04-26 13:27:57.381: ERROR/GeckoCrashReporter(15687):     at android.view.WindowManagerImpl.removeView(WindowManagerImpl.java:236)
04-26 13:27:57.381: ERROR/GeckoCrashReporter(15687):     at android.view.Window$LocalWindowManager.removeView(Window.java:441)
04-26 13:27:57.381: ERROR/GeckoCrashReporter(15687):     at android.app.Dialog.dismissDialog(Dialog.java:306)
04-26 13:27:57.381: ERROR/GeckoCrashReporter(15687):     at android.app.Dialog.access$000(Dialog.java:89)
04-26 13:27:57.381: ERROR/GeckoCrashReporter(15687):     at android.app.Dialog$1.run(Dialog.java:132)
04-26 13:27:57.381: ERROR/GeckoCrashReporter(15687):     at android.app.Dialog.dismiss(Dialog.java:296)
04-26 13:27:57.381: ERROR/GeckoCrashReporter(15687):     at org.mozilla.fennec.CrashReporter.finish(CrashReporter.java:126)
04-26 13:27:57.381: ERROR/GeckoCrashReporter(15687):     at org.mozilla.fennec.CrashReporter$1.run(CrashReporter.java:116)
04-26 13:27:57.381: ERROR/GeckoCrashReporter(15687):     at android.os.Handler.handleCallback(Handler.java:587)
04-26 13:27:57.381: ERROR/GeckoCrashReporter(15687):     at android.os.Handler.dispatchMessage(Handler.java:92)
04-26 13:27:57.381: ERROR/GeckoCrashReporter(15687):     at android.os.Looper.loop(Looper.java:150)
04-26 13:27:57.381: ERROR/GeckoCrashReporter(15687):     at android.app.ActivityThread.main(ActivityThread.java:4293)
04-26 13:27:57.381: ERROR/GeckoCrashReporter(15687):     at java.lang.reflect.Method.invokeNative(Native Method)
04-26 13:27:57.381: ERROR/GeckoCrashReporter(15687):     at java.lang.reflect.Method.invoke(Method.java:507)
04-26 13:27:57.381: ERROR/GeckoCrashReporter(15687):     at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:839)
04-26 13:27:57.381: ERROR/GeckoCrashReporter(15687):     at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:597)
04-26 13:27:57.381: ERROR/GeckoCrashReporter(15687):     at dalvik.system.NativeStart.main(Native Method)
(In reply to Tony Chung [:tchung] from comment #19)
> for reference on my HTC Incredible S.
> 
> 04-26 13:27:57.321: INFO/Gecko(15687): Compositor: Composite took 34 ms.
> 04-26 13:27:57.381: ERROR/GeckoCrashReporter(15687): exception while closing
> progress dialog: 
> 04-26 13:27:57.381: ERROR/GeckoCrashReporter(15687):
> java.lang.IllegalArgumentException: View not attached to window manager
> 04-26 13:27:57.381: ERROR/GeckoCrashReporter(15687):     at
> android.view.WindowManagerImpl.findViewLocked(WindowManagerImpl.java:391)
> 04-26 13:27:57.381: ERROR/GeckoCrashReporter(15687):     at
> android.view.WindowManagerImpl.removeView(WindowManagerImpl.java:236)
> 04-26 13:27:57.381: ERROR/GeckoCrashReporter(15687):     at
> android.view.Window$LocalWindowManager.removeView(Window.java:441)
> 04-26 13:27:57.381: ERROR/GeckoCrashReporter(15687):     at
> android.app.Dialog.dismissDialog(Dialog.java:306)
> 04-26 13:27:57.381: ERROR/GeckoCrashReporter(15687):     at
> android.app.Dialog.access$000(Dialog.java:89)
> 04-26 13:27:57.381: ERROR/GeckoCrashReporter(15687):     at
> android.app.Dialog$1.run(Dialog.java:132)
> 04-26 13:27:57.381: ERROR/GeckoCrashReporter(15687):     at
> android.app.Dialog.dismiss(Dialog.java:296)
> 04-26 13:27:57.381: ERROR/GeckoCrashReporter(15687):     at
> org.mozilla.fennec.CrashReporter.finish(CrashReporter.java:126)
> 04-26 13:27:57.381: ERROR/GeckoCrashReporter(15687):     at
> org.mozilla.fennec.CrashReporter$1.run(CrashReporter.java:116)
> 04-26 13:27:57.381: ERROR/GeckoCrashReporter(15687):     at
> android.os.Handler.handleCallback(Handler.java:587)
> 04-26 13:27:57.381: ERROR/GeckoCrashReporter(15687):     at
> android.os.Handler.dispatchMessage(Handler.java:92)
> 04-26 13:27:57.381: ERROR/GeckoCrashReporter(15687):     at
> android.os.Looper.loop(Looper.java:150)
> 04-26 13:27:57.381: ERROR/GeckoCrashReporter(15687):     at
> android.app.ActivityThread.main(ActivityThread.java:4293)
> 04-26 13:27:57.381: ERROR/GeckoCrashReporter(15687):     at
> java.lang.reflect.Method.invokeNative(Native Method)
> 04-26 13:27:57.381: ERROR/GeckoCrashReporter(15687):     at
> java.lang.reflect.Method.invoke(Method.java:507)
> 04-26 13:27:57.381: ERROR/GeckoCrashReporter(15687):     at
> com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:
> 839)
> 04-26 13:27:57.381: ERROR/GeckoCrashReporter(15687):     at
> com.android.internal.os.ZygoteInit.main(ZygoteInit.java:597)
> 04-26 13:27:57.381: ERROR/GeckoCrashReporter(15687):     at
> dalvik.system.NativeStart.main(Native Method)

Clearing data will also do the trick.
i'm clearing previous release+ nom, and asking for this again.   This is a really annoying experience on first launch.  If we give this to aurora users, they will see this right away.   Certainly will drive up crash reports.

1) install aurora
2) click awesomebar, and tap on bookmarks
3) crash with stack above.

Tested on the aurora candidate build that blassey put out to the mobile team.

Can we reassess this for beta blocking?
blocking-fennec1.0: + → ---
(I think Tony meant to flip the blocking flag to ?)
blocking-fennec1.0: --- → ?
Attached patch band-aid patchSplinter Review
If this bug is deemed really important, this patch will make the crash go away, but we should really look into a better solution.

The problem I've found is actually that onPostExecute is sometimes executing in the GeckoBackgroundThread, even though the AsyncTask docs say it should always execute on the main thread, especially since I checked that we're always creating the AsyncTasks on the main thread.

The AsyncTask implementation probably doesn't account for the fact that the app itself may have more than one thread, so it's messing up finding the main thread, but I need to look more into the implementation to verify that assumption.

An alternate fix we could explore is to use GeckoAsyncTask instead of AsyncTask, but we'd have to implement the cancel method for it.
Attachment #618782 - Flags: review?(mark.finkle)
blocking-fennec1.0: ? → beta+
Attachment #618782 - Flags: review?(mark.finkle) → review+
Comment on attachment 618782 [details] [diff] [review]
band-aid patch

[Approval Request Comment]
needed to stop a crash
Attachment #618782 - Flags: approval-mozilla-aurora?
http://hg.mozilla.org/mozilla-central/rev/77a097275ffa

Leaving open since it's not clear that what landed is the final fix for this bug. Please resolve if it is.
Flags: in-testsuite?
Comment on attachment 618782 [details] [diff] [review]
band-aid patch

[Triage Comment]
Mobile-only, beta blocker. Approved for Aurora 14.
Attachment #618782 - Flags: approval-mozilla-aurora? → approval-mozilla-aurora+
Depends on: 750358
Landed on aurora:
https://hg.mozilla.org/releases/mozilla-aurora/rev/68854a10e0cb

(In reply to Ryan VanderMeulen from comment #26)
> http://hg.mozilla.org/mozilla-central/rev/77a097275ffa
> 
> Leaving open since it's not clear that what landed is the final fix for this
> bug. Please resolve if it is.

To keep matters straight, let's close this bug. I filed bug 750358 to investigate the underlying (and potentially more widespread) problem.
Status: NEW → RESOLVED
Closed: 9 years ago
Resolution: --- → FIXED
(In reply to Margaret Leibovic [:margaret] from comment #23)

> The AsyncTask implementation probably doesn't account for the fact that the
> app itself may have more than one thread, so it's messing up finding the
> main thread, but I need to look more into the implementation to verify that
> assumption.

This is especially true if a Sync is running when you launch the Fennec browser activity…
Verified fixed on Aurora  14.0a2 (2012-05-14)
                  Nightly 15.0a1 (2012-05-14)
Dev: Samsung Galaxy SII (2.3.4)
Status: RESOLVED → VERIFIED
You need to log in before you can comment on or make changes to this bug.