Last Comment Bug 712791 - Crash when running Pageload Zippity tests, restoring on cnn.com
: Crash when running Pageload Zippity tests, restoring on cnn.com
Status: VERIFIED FIXED
[native-crash]
: crash, crashreportid, reproducible, topcrash
Product: Firefox for Android
Classification: Client Software
Component: General (show other bugs)
: 12 Branch
: ARM Android
: P2 critical (vote)
: Firefox 12
Assigned To: Chris Peterson [:cpeterson]
:
: Sebastian Kaspari (:sebastian)
Mentors:
: 711977 (view as bug list)
Depends on:
Blocks: 716729
  Show dependency treegraph
 
Reported: 2011-12-21 15:18 PST by John Hammink
Modified: 2016-07-29 14:21 PDT (History)
7 users (show)
See Also:
Crash Signature:
QA Whiteboard:
Iteration: ---
Points: ---
Has Regression Range: ---
Has STR: ---
fixed
fixed
11+


Attachments
logcat crash on session restore (86.96 KB, text/plain)
2011-12-23 08:22 PST, Tony Chung [:tchung]
no flags Details
logcat cpeterson's build (29.27 KB, text/plain)
2011-12-27 14:29 PST, Tony Chung [:tchung]
no flags Details
Crash on CNN load, CPeterson's build (10.66 KB, text/plain)
2011-12-27 15:11 PST, John Hammink
no flags Details
catch-favicon-exception.patch (2.95 KB, patch)
2012-01-05 13:06 PST, Chris Peterson [:cpeterson]
doug.turner: review+
Details | Diff | Splinter Review
catch-favicon-exception-v2.patch (3.00 KB, patch)
2012-01-05 17:21 PST, Chris Peterson [:cpeterson]
cpeterson: review+
akeybl: approval‑mozilla‑aurora+
Details | Diff | Splinter Review
logcat crash on bbc.co.uk loading (27.65 KB, text/plain)
2012-01-06 12:13 PST, Tony Chung [:tchung]
no flags Details

Description John Hammink 2011-12-21 15:18:18 PST
User Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.7; rv:8.0.1) Gecko/20100101 Firefox/8.0.1
Build ID: 20111120135848

Steps to reproduce:

on my Asus Transformer TF101, Zippity Pageload test causes crash (they do not crash on my other devices.


Actual results:

Ran zippity pageload tests.  Apparently just after downloading favicon from www.cnn.com, there is a crash.

Logcat here:  http://pastebin.mozilla.org/1415103

Crash signature is:  bp-97d70d36-c5b3-4b8f-8268-90eee2111221


Expected results:

No crash.
Comment 1 Brad Lassey [:blassey] (use needinfo?) 2011-12-22 11:35:28 PST
#4 top crasher
Comment 2 Chris Peterson [:cpeterson] 2011-12-22 13:23:53 PST
jhopkins reports that he can reproduce this crash by just browsing to cnn.com on his Asus Transformer (running Honeycomb 3.2.1). I can't reproduce the crash on my Galaxy Nexus running ICS.
Comment 3 Tony Chung [:tchung] 2011-12-23 08:22:27 PST
Created attachment 584069 [details]
logcat crash on session restore

i hit this also when trying to session restore fennec with cnn.com in my history.

Using 12-23 build on Galaxy Nexus:

ption to parcel
12-23 08:09:44.262: ERROR/DatabaseUtils(5341): android.database.sqlite.SQLiteConstraintException: error code 19: constraint failed
12-23 08:09:44.262: ERROR/DatabaseUtils(5341):     at android.database.sqlite.SQLiteStatement.native_executeInsert(Native Method)
12-23 08:09:44.262: ERROR/DatabaseUtils(5341):     at android.database.sqlite.SQLiteStatement.executeInsert(SQLiteStatement.java:113)
12-23 08:09:44.262: ERROR/DatabaseUtils(5341):     at android.database.sqlite.SQLiteDatabase.insertWithOnConflict(SQLiteDatabase.java:1745)
12-23 08:09:44.262: ERROR/DatabaseUtils(5341):     at android.database.sqlite.SQLiteDatabase.insertOrThrow(SQLiteDatabase.java:1644)
12-23 08:09:44.262: ERROR/DatabaseUtils(5341):     at com.android.browser.provider.BrowserProvider2.insertInTransaction(BrowserProvider2.java:1438)
12-23 08:09:44.262: ERROR/DatabaseUtils(5341):     at com.android.browser.provider.SQLiteContentProvider.insert(SQLiteContentProvider.java:115)
12-23 08:09:44.262: ERROR/DatabaseUtils(5341):     at android.content.ContentProvider$Transport.insert(ContentProvider.java:189)
12-23 08:09:44.262: ERROR/DatabaseUtils(5341):     at android.content.ContentProviderNative.onTransact(ContentProviderNative.java:152)
12-23 08:09:44.262: ERROR/DatabaseUtils(5341):     at android.os.Binder.execTransact(Binder.java:338)
12-23 08:09:44.262: ERROR/DatabaseUtils(5341):     at dalvik.system.NativeStart.run(Native Method)
12-23 08:09:44.262: WARN/dalvikvm(5503): threadid=15: thread exiting with uncaught exception (group=0x40a671f8)
12-23 08:09:44.277: ERROR/AndroidRuntime(5503): FATAL EXCEPTION: AsyncTask #2
12-23 08:09:44.277: ERROR/AndroidRuntime(5503): java.lang.RuntimeException: An error occured while executing doInBackground()
12-23 08:09:44.277: ERROR/AndroidRuntime(5503):     at android.os.AsyncTask$3.done(AsyncTask.java:278)
12-23 08:09:44.277: ERROR/AndroidRuntime(5503):     at java.util.concurrent.FutureTask$Sync.innerSetException(FutureTask.java:273)
12-23 08:09:44.277: ERROR/AndroidRuntime(5503):     at java.util.concurrent.FutureTask.setException(FutureTask.java:124)
12-23 08:09:44.277: ERROR/AndroidRuntime(5503):     at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:307)
12-23 08:09:44.277: ERROR/AndroidRuntime(5503):     at java.util.concurrent.FutureTask.run(FutureTask.java:137)
12-23 08:09:44.277: ERROR/AndroidRuntime(5503):     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1076)
12-23 08:09:44.277: ERROR/AndroidRuntime(5503):     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:569)
12-23 08:09:44.277: ERROR/AndroidRuntime(5503):     at java.lang.Thread.run(Thread.java:856)
12-23 08:09:44.277: ERROR/AndroidRuntime(5503): Caused by: android.database.sqlite.SQLiteConstraintException: error code 19: constraint failed
12-23 08:09:44.277: ERROR/AndroidRuntime(5503):     at android.database.DatabaseUtils.readExceptionFromParcel(DatabaseUtils.java:171)
12-23 08:09:44.277: ERROR/AndroidRuntime(5503):     at android.database.DatabaseUtils.readExceptionFromParcel(DatabaseUtils.java:135)
12-23 08:09:44.277: ERROR/AndroidRuntime(5503):     at android.content.ContentProviderProxy.insert(ContentProviderNative.java:415)
12-23 08:09:44.277: ERROR/AndroidRuntime(5503):     at android.content.ContentResolver.insert(ContentResolver.java:729)
12-23 08:09:44.277: ERROR/AndroidRuntime(5503):     at org.mozilla.gecko.db.AndroidBrowserDB.updateFaviconForUrl(AndroidBrowserDB.java:288)
12-23 08:09:44.277: ERROR/AndroidRuntime(5503):     at org.mozilla.gecko.db.BrowserDB.updateFaviconForUrl(BrowserDB.java:140)
12-23 08:09:44.277: ERROR/AndroidRuntime(5503):     at org.mozilla.gecko.Favicons$LoadFaviconTask.saveFaviconToDb(Favicons.java:248)
12-23 08:09:44.277: ERROR/AndroidRuntime(5503):     at org.mozilla.gecko.Favicons$LoadFaviconTask.downloadFavicon(Favicons.java:299)
12-23 08:09:44.277: ERROR/AndroidRuntime(5503):     at org.mozilla.gecko.Favicons$LoadFaviconTask.doInBackground(Favicons.java:355)
12-23 08:09:44.277: ERROR/AndroidRuntime(5503):     at org.mozilla.gecko.Favicons$LoadFaviconTask.doInBackground(Favicons.java:215)
12-23 08:09:44.277: ERROR/AndroidRuntime(5503):     at android.os.AsyncTask$2.call(AsyncTask.java:264)
12-23 08:09:44.277: ERROR/AndroidRuntime(5503):     at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:305)
12-23 08:09:44.277: ERROR/AndroidRuntime(5503):     ... 4 more
Comment 4 Chris Peterson [:cpeterson] 2011-12-23 14:10:42 PST
I have not been able to reproduce this crash on my devices, but I suspect this might be a race condition with two LoadFaviconTasks colliding as they are both trying to insert new cnn.com favicons. AsyncTasks may be executed in parallel by a thread pool for Android versions >= DONUT and <= HONEYCOMB. LoadFaviconTask.updateFaviconForUrl() calls ContentResolver.update() and insert() outside of a DB transaction. Perhaps two LoadAsyncTasks try and fail to update() then both try to insert() the same new row.

In the stack traces, you can see that AndroidBrowserDB.updateFaviconForUrl() calls ContentResolver.insert(), not update(). I'm not sure why we are inserting a new favicon because the bookmarks DB should already have a CNN favicon because we are restoring an old session or reloading the same page.

Inserting a row with the same primary key (BookmarksColumns.URL) as an existing row will cause a SQLiteConstraintException. A SQLiteConstraintException could also be thrown for bad column values, but Fennec is presumably trying to save the same valid favicon data it saves every other time someone visit cnn.com. Also, the bookmarks table is created without any column constraints that should be a problem for inserting a favicon:

https://github.com/android/platform_packages_apps_browser/blob/master/src/com/android/browser/provider/BrowserProvider2.java#L392

I think cnn.com triggers this race because the page refreshes its favicon as different frames are loaded. You can clearly see this if you load cnn.com in the Chrome desktop browser.
Comment 5 Tony Chung [:tchung] 2011-12-27 14:29:48 PST
Created attachment 584485 [details]
logcat cpeterson's build

hi chris,

i got this to crash with more logging with your try build you posted at: http://www.cpeterso.com/tmp/fennec-transaction-test.apk.

REpro was startup build, launch cnn.com, before the throbber finishes spinning, Fennec crashes.

logcat attached.
Comment 6 Tony Chung [:tchung] 2011-12-27 14:31:12 PST
(In reply to Tony Chung [:tchung] from comment #5)
> Created attachment 584485 [details]
> logcat cpeterson's build
> 
> hi chris,
> 
> i got this to crash with more logging with your try build you posted at:
> http://www.cpeterso.com/tmp/fennec-transaction-test.apk.
> 
> REpro was startup build, launch cnn.com, before the throbber finishes
> spinning, Fennec crashes.
> 
> logcat attached.

Device: Samsung Galaxy Nexus, Android 4.0.1
Comment 7 John Hammink 2011-12-27 14:45:45 PST
Reproduced with try build available at:

http://pastebin.mozilla.org/1423332

Unfortunately I cannot get a crash in about:crashes
Comment 8 John Hammink 2011-12-27 14:47:13 PST
Device is ASUS Transformer TF101 running Android 3.2.1
Comment 9 John Hammink 2011-12-27 15:11:00 PST
Created attachment 584497 [details]
Crash on CNN load, CPeterson's build
Comment 10 Chris Peterson [:cpeterson] 2012-01-05 13:06:44 PST
Created attachment 586189 [details] [diff] [review]
catch-favicon-exception.patch

insert() mysteriously and intermittently fails with "error code 19: constraint failed" on some Honeycomb and ICS devices. Bookmarks favicons are not a critical feature, so we can ignore the error for now.

This patch should prevent this topcrash, but I would like to open a new bug to investigate the root cause of the SQLite exceptions.
Comment 11 Doug Turner (:dougt) 2012-01-05 16:29:12 PST
Comment on attachment 586189 [details] [diff] [review]
catch-favicon-exception.patch

Review of attachment 586189 [details] [diff] [review]:
-----------------------------------------------------------------

please post another patch so that it's easy to push to m-c, and carry forward the r+

::: mobile/android/base/db/AndroidBrowserDB.java
@@ +296,5 @@
> +                // insert() mysteriously and intermittently fails with "error
> +				// code 19: constraint failed" on some Honeycomb and ICS
> +				// devices. Bookmark favicons are not a critical feature, so
> +				// we can ignore this error for now. bug 711977; bug 712791
> +                Log.e(LOGTAG, String.format(

The formatting of this comment is off -- no tabs, please..
Comment 12 Chris Peterson [:cpeterson] 2012-01-05 17:21:35 PST
Created attachment 586286 [details] [diff] [review]
catch-favicon-exception-v2.patch

patch v2 fixes formatting. r=dougt
Comment 13 Chris Peterson [:cpeterson] 2012-01-05 17:24:58 PST
Comment on attachment 586286 [details] [diff] [review]
catch-favicon-exception-v2.patch

[Approval Request Comment]
Regression caused by (bug #): N/A
User impact if declined: Some users on Honeycomb or ICS devices can get into a state where Fennec will repeatedly crash on the same website.
Testing completed (on m-c, etc.):
Risk to taking this patch (and alternatives if risky): Low. This patch just catches (and ignores) an exception.
Comment 14 Alex Keybl [:akeybl] 2012-01-06 11:01:49 PST
Comment on attachment 586286 [details] [diff] [review]
catch-favicon-exception-v2.patch

[Triage Comment]
Mobile only and a top crash - approved for Aurora.
Comment 15 Tony Chung [:tchung] 2012-01-06 12:13:47 PST
Created attachment 586509 [details]
logcat crash on bbc.co.uk loading

i hit this again on the 1-6 nightly, Galaxy Nexus, 4.0.1.

This time its loading www.bbc.co.uk and watching it crash as the favicon tries to load.  Hopefully its more information if needed.

01-06 12:08:19.277: DEBUG/GeckoFavicons(23149): Creating LoadFaviconTask with URL = http://www.bbc.co.uk/ and favicon URL = http://www.bbc.co.uk/favicon.ico
01-06 12:08:19.285: DEBUG/GeckoFavicons(23149): Calling loadFavicon() with URL = http://www.bbc.co.uk/ and favicon URL = http://www.bbc.co.uk/favicon.ico (1)
01-06 12:08:19.285: DEBUG/GeckoFavicons(23149): Favicon URL is now: http://www.bbc.co.uk/favicon.ico
01-06 12:08:19.285: DEBUG/GeckoFavicons(23149): Calling getFaviconUrlForPageUrl() for http://www.bbc.co.uk/
01-06 12:08:19.301: DEBUG/GeckoFavicons(23149): Downloading favicon for URL = http://www.bbc.co.uk/ with favicon URL = http://www.bbc.co.uk/favicon.ico
01-06 12:08:19.676: DEBUG/GeckoFavicons(23149): Downloaded favicon successfully for URL = http://www.bbc.co.uk/
01-06 12:08:19.676: DEBUG/GeckoFavicons(23149): Saving favicon on browser database for URL = http://www.bbc.co.uk/
01-06 12:08:19.683: ERROR/DatabaseUtils(13672): Writing exception to parcel
01-06 12:08:19.683: ERROR/DatabaseUtils(13672): android.database.sqlite.SQLiteConstraintException: error code 19: constraint failed
01-06 12:08:19.683: ERROR/DatabaseUtils(13672):     at android.database.sqlite.SQLiteStatement.native_executeInsert(Native Method)
01-06 12:08:19.683: ERROR/DatabaseUtils(13672):     at android.database.sqlite.SQLiteStatement.executeInsert(SQLiteStatement.java:113)
01-06 12:08:19.683: ERROR/DatabaseUtils(13672):     at android.database.sqlite.SQLiteDatabase.insertWithOnConflict(SQLiteDatabase.java:1745)
01-06 12:08:19.683: ERROR/DatabaseUtils(13672):     at android.database.sqlite.SQLiteDatabase.insertOrThrow(SQLiteDatabase.java:1644)
01-06 12:08:19.683: ERROR/DatabaseUtils(13672):     at com.android.browser.provider.BrowserProvider2.insertInTransaction(BrowserProvider2.java:1438)
01-06 12:08:19.683: ERROR/DatabaseUtils(13672):     at com.android.browser.provider.SQLiteContentProvider.insert(SQLiteContentProvider.java:115)
01-06 12:08:19.683: ERROR/DatabaseUtils(13672):     at android.content.ContentProvider$Transport.insert(ContentProvider.java:189)
01-06 12:08:19.683: ERROR/DatabaseUtils(13672):     at android.content.ContentProviderNative.onTransact(ContentProviderNative.java:152)
01-06 12:08:19.683: ERROR/DatabaseUtils(13672):     at android.os.Binder.execTransact(Binder.java:338)
01-06 12:08:19.683: ERROR/DatabaseUtils(13672):     at dalvik.system.NativeStart.run(Native Method)
01-06 12:08:19.691: WARN/dalvikvm(23149): threadid=15: thread exiting with uncaught exception (group=0x40a4e1f8)
01-06 12:08:19.699: ERROR/AndroidRuntime(23149): FATAL EXCEPTION: AsyncTask #1
01-06 12:08:19.699: ERROR/AndroidRuntime(23149): java.lang.RuntimeException: An error occured while executing doInBackground()
01-06 12:08:19.699: ERROR/AndroidRuntime(23149):     at android.os.AsyncTask$3.done(AsyncTask.java:278)
01-06 12:08:19.699: ERROR/AndroidRuntime(23149):     at java.util.concurrent.FutureTask$Sync.innerSetException(FutureTask.java:273)
01-06 12:08:19.699: ERROR/AndroidRuntime(23149):     at java.util.concurrent.FutureTask.setException(FutureTask.java:124)
01-06 12:08:19.699: ERROR/AndroidRuntime(23149):     at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:307)
01-06 12:08:19.699: ERROR/AndroidRuntime(23149):     at java.util.concurrent.FutureTask.run(FutureTask.java:137)
01-06 12:08:19.699: ERROR/AndroidRuntime(23149):     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1076)
01-06 12:08:19.699: ERROR/AndroidRuntime(23149):     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:569)
01-06 12:08:19.699: ERROR/AndroidRuntime(23149):     at java.lang.Thread.run(Thread.java:856)
01-06 12:08:19.699: ERROR/AndroidRuntime(23149): Caused by: android.database.sqlite.SQLiteConstraintException: error code 19: constraint failed
01-06 12:08:19.699: ERROR/AndroidRuntime(23149):     at android.database.DatabaseUtils.readExceptionFromParcel(DatabaseUtils.java:171)
01-06 12:08:19.699: ERROR/AndroidRuntime(23149):     at android.database.DatabaseUtils.readExceptionFromParcel(DatabaseUtils.java:135)
01-06 12:08:19.699: ERROR/AndroidRuntime(23149):     at android.content.ContentProviderProxy.insert(ContentProviderNative.java:415)
01-06 12:08:19.699: ERROR/AndroidRuntime(23149):     at android.content.ContentResolver.insert(ContentResolver.java:729)
01-06 12:08:19.699: ERROR/AndroidRuntime(23149):     at org.mozilla.gecko.db.AndroidBrowserDB.updateFaviconForUrl(AndroidBrowserDB.java:288)
01-06 12:08:19.699: ERROR/AndroidRuntime(23149):     at org.mozilla.gecko.db.BrowserDB.updateFaviconForUrl(BrowserDB.java:140)
01-06 12:08:19.699: ERROR/AndroidRuntime(23149):     at org.mozilla.gecko.Favicons$LoadFaviconTask.saveFaviconToDb(Favicons.java:248)
01-06 12:08:19.699: ERROR/AndroidRuntime(23149):     at org.mozilla.gecko.Favicons$LoadFaviconTask.downloadFavicon(Favicons.java:299)
01-06 12:08:19.699: ERROR/AndroidRuntime(23149):     at org.mozilla.gecko.Favicons$LoadFaviconTask.doInBackground(Favicons.java:355)
01-06 12:08:19.699: ERROR/AndroidRuntime(23149):     at org.mozilla.gecko.Favicons$LoadFaviconTask.doInBackground(Favicons.java:215)
01-06 12:08:19.699: ERROR/AndroidRuntime(23149):     at android.os.AsyncTask$2.call(AsyncTask.java:264)
01-06 12:08:19.699: ERROR/AndroidRuntime(23149):     at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:305)
01-06 12:08:19.699: ERROR/AndroidRuntime(23149):     ... 4 more
01-06 12:08:19.707: WARN/ActivityManager(195):   Force finishing activity org.mozilla.fennec/.App
Comment 16 Tony Chung [:tchung] 2012-01-06 12:22:28 PST
repros on aurora also.
Comment 17 Chris Peterson [:cpeterson] 2012-01-09 10:06:10 PST
checkin-needed for mozilla-inbound and mozilla-aurora, please.
Comment 19 Doug Turner (:dougt) 2012-01-09 16:00:44 PST
wait until it lands on m-c before landing on m-a.
Comment 20 Marco Bonardo [::mak] 2012-01-10 01:57:53 PST
https://hg.mozilla.org/mozilla-central/rev/fd89376a7ef2
Comment 21 Camelia Urian 2012-01-11 08:01:33 PST
Verified with:
Nightly 12.0a1 (2012-01-11) 
on following devices: 
- Samsung Nexus S (Android 2.3.6)
- Galaxy Nexus (Android 4.0.1)
- Asus Transformer TF101 (Android 3.2.1)

No crash when loading/browsing on cnn.com and bbc.co.uk
Comment 22 Tony Chung [:tchung] 2012-01-11 11:54:15 PST
also verified on my Galaxy Nexus.  W00T!
Comment 24 Chris Peterson [:cpeterson] 2012-01-14 18:42:40 PST
*** Bug 711977 has been marked as a duplicate of this bug. ***

Note You need to log in before you can comment on or make changes to this bug.