Closed Bug 752287 Opened 13 years ago Closed 6 years ago

android.database.sqlite.SQLiteDatabaseLockedException: error code 5: database is locked: at android.database.sqlite.SQLiteStatement.native_1x1_string(Native Method)

Categories

(Firefox for Android Graveyard :: Data Providers, defect)

16 Branch
All
Android
defect
Not set
critical

Tracking

(firefox16 affected, firefox17 affected)

RESOLVED WONTFIX
Tracking Status
firefox16 --- affected
firefox17 --- affected

People

(Reporter: scoobidiver, Unassigned)

References

Details

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

Crash Data

Attachments

(1 file)

There's one crash after the fix of bug 749493, in 15.0a1/20120505: bp-d4e725b6-5959-4ee2-a974-9b37f2120506. android.database.sqlite.SQLiteDatabaseLockedException: error code 5: database is locked at android.database.sqlite.SQLiteStatement.native_1x1_string(Native Method) at android.database.sqlite.SQLiteStatement.simpleQueryForString(SQLiteStatement.java:161) at android.database.DatabaseUtils.stringForQuery(DatabaseUtils.java:812) at android.database.DatabaseUtils.stringForQuery(DatabaseUtils.java:800) at android.database.sqlite.SQLiteDatabase.setJournalMode(SQLiteDatabase.java:1128) at android.database.sqlite.SQLiteDatabase.openDatabase(SQLiteDatabase.java:1046) at android.database.sqlite.SQLiteDatabase.openOrCreateDatabase(SQLiteDatabase.java:1119) at android.app.ContextImpl.openOrCreateDatabase(ContextImpl.java:1018) at android.content.ContextWrapper.openOrCreateDatabase(ContextWrapper.java:221) at android.database.sqlite.SQLiteOpenHelper.getWritableDatabase(SQLiteOpenHelper.java:157) at org.mozilla.gecko.db.DBUtils.ensureDatabaseIsNotLocked(DBUtils.java:85) at org.mozilla.fennec.db.TabsProvider.getDatabaseHelperForProfile(TabsProvider.java:221) at org.mozilla.fennec.db.TabsProvider.getReadableDatabase(TabsProvider.java:258) at org.mozilla.fennec.db.TabsProvider.query(TabsProvider.java:521) at android.content.ContentProvider$Transport.query(ContentProvider.java:189) at android.content.ContentResolver.query(ContentResolver.java:315) at org.mozilla.gecko.TabsAccessor$2.doInBackground(TabsAccessor.java:120) at org.mozilla.gecko.TabsAccessor$2.doInBackground(TabsAccessor.java:109) at org.mozilla.gecko.GeckoAsyncTask$BackgroundTaskRunnable.run(GeckoAsyncTask.java:61) at android.os.Handler.handleCallback(Handler.java:605) at android.os.Handler.dispatchMessage(Handler.java:92) at android.os.Looper.loop(Looper.java:154) at org.mozilla.gecko.GeckoBackgroundThread.run(GeckoBackgroundThread.java:31) More reports at: https://crash-stats.mozilla.com/report/list?signature=android.database.sqlite.SQLiteDatabaseLockedException%3A+error+code+5%3A+database+is+locked%3A+at+android.database.sqlite.SQLiteStatement.native_1x1_string%28Native+Method%29
I hit this error just now, after doing a sync, and then trying to tap awesomebar to retrieve history items. Not sure how else to reproduce reliably yet. Galaxy Nexus, Firefox 14 Beta 7, android 4.0.4 logcat: 06-21 19:48:24.849: I/GeckoToolbar(28508): zerdatime 41004236 - Throbber stop 06-21 19:48:24.881: D/GeckoFavicons(28508): Loaded favicon from DB successfully for URL = about:home 06-21 19:48:24.920: D/GeckoFavicons(28508): Favicon URL is now: jar:jar:file:///data/app/org.mozilla.firefox_beta-1.apk!/omni.ja!/chrome/chrome/content/branding/favicon32.png 06-21 19:48:24.920: D/GeckoFavicons(28508): Calling getFaviconUrlForPageUrl() for about:home 06-21 19:48:24.920: I/GeckoDisplayPortCalculator(28508): Set strategy VelocityBiasStrategy mult=2.0, threshold=10.240001, reverse=0.2, dangerBaseX=1.0, dangerBaseY=1.0, dangerIncrX=0.0, dangerIncrY=0.0 06-21 19:48:24.920: I/PluginLayer(28508): Using plugin placeholder: false 06-21 19:48:24.920: I/Gecko(28508): Logging GL tracing output to /data/data/org.mozilla.firefox_beta/firefox.trace 06-21 19:48:24.920: I/Gecko(28508): Attempting load of /data/local/egltrace.so 06-21 19:48:24.928: I/Gecko(28508): Attempting load of libEGL.so 06-21 19:48:24.928: D/GeckoFavicons(28508): LoadFaviconTask cancelled for URL = about:home (1) 06-21 19:48:24.928: I/Gecko(28508): Extensions: EGL_KHR_image EGL_KHR_image_base EGL_KHR_image_base EGL_KHR_gl_texture_2D_image EGL_KHR_gl_texture_cubemap_image EGL_KHR_gl_renderbuffer_image EGL_KHR_fence_sync EGL_ANDROID_image_native_buffer EGL_ANDROID_image_native_buffer 0x45 06-21 19:48:24.928: I/Gecko(28508): Extensions length: 226 06-21 19:48:24.928: D/GeckoFavicons(28508): Loading favicon from DB for URL = about:home 06-21 19:48:24.951: I/GeckoApp(28508): stop 06-21 19:48:24.982: D/dalvikvm(28508): GC_CONCURRENT freed 448K, 4% free 14478K/15047K, paused 5ms+3ms 06-21 19:48:24.990: D/GeckoFavicons(28508): Loaded favicon from DB successfully for URL = about:home 06-21 19:48:24.990: D/GeckoFavicons(28508): LoadFaviconTask finished for URL = about:home (2) 06-21 19:48:24.990: I/GeckoApp(28508): Favicon successfully loaded for URL = about:home 06-21 19:48:24.990: I/GeckoApp(28508): Favicon is for current URL = about:home 06-21 19:48:24.990: I/GeckoTab(28508): Updated favicon for tab with id: 1 06-21 19:48:27.935: I/DEBUG(115): debuggerd committing suicide to free the zombie! 06-21 19:48:27.935: I/BootReceiver(193): Copying /data/tombstones/tombstone_02 to DropBox (SYSTEM_TOMBSTONE) 06-21 19:48:27.943: I/DEBUG(28589): debuggerd: Apr 13 2012 21:29:36 06-21 19:48:27.974: I/WindowManager(193): WIN DEATH: Window{41c05f18 SurfaceView paused=false} 06-21 19:48:27.974: I/ActivityManager(193): Process org.mozilla.firefox_beta (pid 28508) has died. 06-21 19:48:27.974: W/ActivityManager(193): Force removing ActivityRecord{416a7f40 org.mozilla.firefox_beta/org.mozilla.gecko.AwesomeBar}: app died, no saved state 06-21 19:48:27.974: I/WindowManager(193): WIN DEATH: Window{419f1c90 org.mozilla.firefox_beta/org.mozilla.firefox_beta.App paused=false} 06-21 19:48:27.982: I/WindowManager(193): WIN DEATH: Window{41d98ab8 org.mozilla.firefox_beta/org.mozilla.gecko.AwesomeBar paused=false} 06-21 19:48:28.006: I/ActivityManager(193): Start proc org.mozilla.firefox_beta for activity org.mozilla.firefox_beta/.App: pid=28590 uid=10072 gids={3003, 1015, 1006} 06-21 19:48:28.021: D/Zygote(118): Process 28508 terminated by signal (11) 06-21 19:48:28.053: D/dalvikvm(193): GC_CONCURRENT freed 1276K, 23% free 25071K/32327K, paused 4ms+7ms 06-21 19:48:28.123: I/ActivityThread(28590): Pub org.mozilla.firefox_beta.db.browser: org.mozilla.firefox_beta.db.BrowserProvider 06-21 19:48:28.123: I/ActivityThread(28590): Pub org.mozilla.firefox_beta.db.formhistory: org.mozilla.firefox_beta.db.FormHistoryProvider 06-21 19:48:28.123: I/ActivityThread(28590): Pub org.mozilla.firefox_beta.db.tabs: org.mozilla.firefox_beta.db.TabsProvider 06-21 19:48:28.131: D/GeckoProfile(28590): Found profile dir: /data/data/org.mozilla.firefox_beta/files/mozilla/0f49o1k4.default 06-21 19:48:28.146: D/dalvikvm(28590): Trying to load lib /data/data/org.mozilla.firefox_beta/lib/libmozglue.so 0x41686630 06-21 19:48:28.146: D/dalvikvm(28590): Added shared lib /data/data/org.mozilla.firefox_beta/lib/libmozglue.so 0x41686630 06-21 19:48:28.146: D/dalvikvm(28590): No JNI_OnLoad found in /data/data/org.mozilla.firefox_beta/lib/libmozglue.so 0x41686630, skipping init 06-21 19:48:28.146: W/GeckoApp(28590): zerdatime 41007537 - onCreate 06-21 19:48:28.217: D/dalvikvm(28590): GC_CONCURRENT freed 183K, 3% free 12863K/13127K, paused 6ms+3ms 06-21 19:48:28.287: I/GeckoViewsFactory(28590): Creating custom Gecko view: FormAssistPopup 06-21 19:48:28.287: I/GeckoViewsFactory(28590): Creating custom Gecko view: AboutHomeContent 06-21 19:48:28.342: D/dalvikvm(28590): GC_CONCURRENT freed 60K, 2% free 13307K/13447K, paused 1ms+5ms 06-21 19:48:28.365: W/GeckoApp(28590): zerdatime 41007752 - onStart 06-21 19:48:28.365: I/GeckoApp(28590): start 06-21 19:48:28.388: I/GeckoApp(28590): resume 06-21 19:48:28.428: D/libEGL(28590): loaded /system/lib/egl/libGLES_android.so 06-21 19:48:28.443: D/libEGL(28590): loaded /vendor/lib/egl/libEGL_POWERVR_SGX540_120.so 06-21 19:48:28.451: D/libEGL(28590): loaded /vendor/lib/egl/libGLESv1_CM_POWERVR_SGX540_120.so 06-21 19:48:28.459: D/libEGL(28590): loaded /vendor/lib/egl/libGLESv2_POWERVR_SGX540_120.so 06-21 19:48:28.568: D/OpenGLRenderer(28590): Enabling debug mode 0 06-21 19:48:28.568: I/GeckoToolbar(28590): zerdatime 41007956 - Throbber start 06-21 19:48:28.568: I/GeckoApp(28590): Checking profile migration in: /data/data/org.mozilla.firefox_beta/files/mozilla/0f49o1k4.default 06-21 19:48:28.568: D/GeckoFavicons(28590): Creating Favicons instance 06-21 19:48:28.568: D/GeckoFavicons(28590): Creating DatabaseHelper 06-21 19:48:28.568: W/GeckoApp(28590): zerdatime 41007959 - start of getPluginDirectories 06-21 19:48:28.568: W/GeckoApp(28590): Loading plugin: com.adobe.flashplayer 06-21 19:48:28.584: I/GeckoAxis(28590): Prefs: 0.85,0.97,10.0,0.012,0.04,0.3,0.5 06-21 19:48:28.592: W/GeckoApp(28590): zerdatime 41007979 - end of getPluginDirectories 06-21 19:48:28.592: I/GeckoAppShell(28590): dir: /data/data/com.adobe.flashplayer/lib 06-21 19:48:28.592: I/GeckoAppShell(28590): env0: null 06-21 19:48:28.592: D/dalvikvm(28590): Trying to load lib /data/data/org.mozilla.firefox_beta/lib/libmozglue.so 0x41686630 06-21 19:48:28.592: D/dalvikvm(28590): Shared lib '/data/data/org.mozilla.firefox_beta/lib/libmozglue.so' already loaded in same CL 0x41686630 06-21 19:48:28.599: E/GeckoLibLoad(28590): Load sqlite start 06-21 19:48:28.607: W/GeckoApp(28590): zerdatime 41007996 - UI almost up 06-21 19:48:28.623: E/GeckoLinker(28590): /data/app/org.mozilla.firefox_beta-1.apk!/libmozsqlite3.so: Warning: relocation to NULL @0x00052db4 06-21 19:48:28.623: E/GeckoLinker(28590): /data/app/org.mozilla.firefox_beta-1.apk!/libmozsqlite3.so: Warning: relocation to NULL @0x00052cb0 for symbol "__cxa_begin_cleanup" 06-21 19:48:28.623: E/GeckoLinker(28590): /data/app/org.mozilla.firefox_beta-1.apk!/libmozsqlite3.so: Warning: relocation to NULL @0x00052d1c for symbol "__cxa_type_match" 06-21 19:48:28.623: E/GeckoLibLoad(28590): Load sqlite done 06-21 19:48:28.623: D/dalvikvm(28590): Trying to load lib /data/data/org.mozilla.firefox_beta/lib/libmozglue.so 0x41686630 06-21 19:48:28.623: D/dalvikvm(28590): Shared lib '/data/data/org.mozilla.firefox_beta/lib/libmozglue.so' already loaded in same CL 0x41686630 06-21 19:48:28.623: E/GeckoLibLoad(28590): Load nss start 06-21 19:48:28.631: W/InputManagerService(193): Got RemoteException sending setActive(false) notification to pid 28508 uid 10072 06-21 19:48:28.662: W/SurfaceTexture(117): [org.mozilla.firefox_beta/org.mozilla.firefox_beta.App] cancelBuffer: SurfaceTexture has been abandoned! 06-21 19:48:28.685: W/GeckoApp(28590): zerdatime 41008071 - pre checkLaunchState 06-21 19:48:28.701: E/GeckoLinker(28590): /data/app/org.mozilla.firefox_beta-1.apk!/libnspr4.so: Warning: relocation to NULL @0x00020de0 06-21 19:48:28.701: E/GeckoLinker(28590): /data/app/org.mozilla.firefox_beta-1.apk!/libnspr4.so: Warning: relocation to NULL @0x00020b98 for symbol "__cxa_begin_cleanup" 06-21 19:48:28.701: E/GeckoLinker(28590): /data/app/org.mozilla.firefox_beta-1.apk!/libnspr4.so: Warning: relocation to NULL @0x00020cb0 for symbol "__cxa_type_match" 06-21 19:48:28.724: E/GeckoLibLoad(28590): Load nss done 06-21 19:48:28.865: I/ActivityManager(193): Displayed org.mozilla.firefox_beta/.App: +882ms 06-21 19:48:29.357: E/GeckoLinker(28590): /data/app/org.mozilla.firefox_beta-1.apk!/libmozalloc.so: Warning: relocation to NULL @0x00003e2c 06-21 19:48:29.357: E/GeckoLinker(28590): /data/app/org.mozilla.firefox_beta-1.apk!/libmozalloc.so: Warning: relocation to NULL @0x00003db8 for symbol "__cxa_begin_cleanup" 06-21 19:48:29.357: E/GeckoLinker(28590): /data/app/org.mozilla.firefox_beta-1.apk!/libmozalloc.so: Warning: relocation to NULL @0x00003de0 for symbol "__cxa_type_match" 06-21 19:48:29.388: E/GeckoLibLoad(28590): Loaded libs in 661ms total, 359ms user, 234ms system, 2 faults 06-21 19:48:29.388: W/GeckoThread(28590): zerdatime 41008775 - runGecko 06-21 19:48:29.388: I/GeckoThread(28590): RunGecko - URI = null 06-21 19:48:29.388: I/GeckoAppShell(28590): post native init 06-21 19:48:29.388: I/GeckoAppShell(28590): setLayerClient called 06-21 19:48:29.474: E/GeckoConsole(28590): Could not read chrome manifest 'file:///data/data/org.mozilla.firefox_beta/chrome.manifest'. 06-21 19:48:29.818: W/ResourceType(28590): Too many attribute references, stopped at: 0x01010099 06-21 19:48:30.037: E/GeckoConsole(28590): zerdatime 1340333310047 - browser chrome startup finished. 06-21 19:48:30.045: I/GeckoApp(28590): Got message: CharEncoding:State 06-21 19:48:30.084: I/GeckoApp(28590): Got message: Menu:Add 06-21 19:48:30.084: I/GeckoTabs(28590): Got message: Session:RestoreBegin 06-21 19:48:30.092: I/GeckoApp(28590): Got message: Gecko:Ready 06-21 19:48:30.115: D/GeckoLayerClient(28590): Screen-size changed to (720,1184)
Sorry, i pasted the wrong section. Logcat: 06-21 19:48:24.185: E/SQLiteOpenHelper(28508): Couldn't open /data/data/org.mozilla.firefox_beta/files/mozilla/0f49o1k4.default/browser.db for writing (will try read-only): 06-21 19:48:24.185: E/SQLiteOpenHelper(28508): android.database.sqlite.SQLiteDatabaseLockedException: error code 5: database is locked 06-21 19:48:24.185: E/SQLiteOpenHelper(28508): at android.database.sqlite.SQLiteStatement.native_1x1_string(Native Method) 06-21 19:48:24.185: E/SQLiteOpenHelper(28508): at android.database.sqlite.SQLiteStatement.simpleQueryForString(SQLiteStatement.java:161) 06-21 19:48:24.185: E/SQLiteOpenHelper(28508): at android.database.DatabaseUtils.stringForQuery(DatabaseUtils.java:813) 06-21 19:48:24.185: E/SQLiteOpenHelper(28508): at android.database.DatabaseUtils.stringForQuery(DatabaseUtils.java:801) 06-21 19:48:24.185: E/SQLiteOpenHelper(28508): at android.database.sqlite.SQLiteDatabase.setJournalMode(SQLiteDatabase.java:1060) 06-21 19:48:24.185: E/SQLiteOpenHelper(28508): at android.database.sqlite.SQLiteDatabase.openDatabase(SQLiteDatabase.java:996) 06-21 19:48:24.185: E/SQLiteOpenHelper(28508): at android.database.sqlite.SQLiteDatabase.openOrCreateDatabase(SQLiteDatabase.java:1051) 06-21 19:48:24.185: E/SQLiteOpenHelper(28508): at android.app.ContextImpl.openOrCreateDatabase(ContextImpl.java:770) 06-21 19:48:24.185: E/SQLiteOpenHelper(28508): at android.content.ContextWrapper.openOrCreateDatabase(ContextWrapper.java:221) 06-21 19:48:24.185: E/SQLiteOpenHelper(28508): at android.database.sqlite.SQLiteOpenHelper.getWritableDatabase(SQLiteOpenHelper.java:157) 06-21 19:48:24.185: E/SQLiteOpenHelper(28508): at android.database.sqlite.SQLiteOpenHelper.getReadableDatabase(SQLiteOpenHelper.java:231) 06-21 19:48:24.185: E/SQLiteOpenHelper(28508): at org.mozilla.firefox_beta.db.BrowserProvider.getReadableDatabase(BrowserProvider.java:1017) 06-21 19:48:24.185: E/SQLiteOpenHelper(28508): at org.mozilla.firefox_beta.db.BrowserProvider.query(BrowserProvider.java:1538) 06-21 19:48:24.185: E/SQLiteOpenHelper(28508): at android.content.ContentProvider$Transport.query(ContentProvider.java:178) 06-21 19:48:24.185: E/SQLiteOpenHelper(28508): at android.content.ContentResolver.query(ContentResolver.java:311) 06-21 19:48:24.185: E/SQLiteOpenHelper(28508): at org.mozilla.gecko.db.LocalBrowserDB.filterAllSites(LocalBrowserDB.java:180) 06-21 19:48:24.185: E/SQLiteOpenHelper(28508): at org.mozilla.gecko.db.LocalBrowserDB.filter(LocalBrowserDB.java:190) 06-21 19:48:24.185: E/SQLiteOpenHelper(28508): at org.mozilla.gecko.db.BrowserDB.filter(BrowserDB.java:115) 06-21 19:48:24.185: E/SQLiteOpenHelper(28508): at org.mozilla.gecko.AwesomeBarTabs$2.runQuery(AwesomeBarTabs.java:811) 06-21 19:48:24.185: E/SQLiteOpenHelper(28508): at android.widget.CursorAdapter.runQueryOnBackgroundThread(CursorAdapter.java:391) 06-21 19:48:24.185: E/SQLiteOpenHelper(28508): at android.widget.CursorFilter.performFiltering(CursorFilter.java:49) 06-21 19:48:24.185: E/SQLiteOpenHelper(28508): at android.widget.Filter$RequestHandler.handleMessage(Filter.java:234) 06-21 19:48:24.185: E/SQLiteOpenHelper(28508): at android.os.Handler.dispatchMessage(Handler.java:99) 06-21 19:48:24.185: E/SQLiteOpenHelper(28508): at android.os.Looper.loop(Looper.java:137) 06-21 19:48:24.185: E/SQLiteOpenHelper(28508): at android.os.HandlerThread.run(HandlerThread.java:60) 06-21 19:48:24.279: I/ActivityManager(193): Displayed org.mozilla.firefox_beta/org.mozilla.gecko.AwesomeBar: +471ms 06-21 19:48:24.279: W/SQLiteOpenHelper(28508): Opened /data/data/org.mozilla.firefox_beta/files/mozilla/0f49o1k4.default/browser.db in read-only mode 06-21 19:48:24.287: D/OpenGLRenderer(28508): Flushing caches (mode 0) 06-21 19:48:24.388: E/GeckoConsole(28508): zerdatime 1340333304399 - browser chrome startup finished. 06-21 19:48:24.396: I/GeckoApp(28508): Got message: CharEncoding:State 06-21 19:48:24.490: I/GeckoApp(28508): Got message: Menu:Add 06-21 19:48:24.490: I/Gecko(28508): Detected osrelease `3.0.8-gda6252b' 06-21 19:48:24.498: I/Gecko(28508): JITs are not broken 06-21 19:48:24.592: I/GeckoTabs(28508): Got message: Tab:Added 06-21 19:48:24.592: I/GeckoTabs(28508): Received message from Gecko: 41003977 - Tab:Added 06-21 19:48:24.592: I/GeckoTabs(28508): Added a tab with id: 1 06-21 19:48:24.599: I/GeckoApp(28508): Got message: Content:StateChange 06-21 19:48:24.599: I/GeckoApp(28508): State - 983041 06-21 19:48:24.599: I/GeckoApp(28508): Got a document start 06-21 19:48:24.607: I/GeckoToolbar(28508): zerdatime 41003994 - Throbber stop 06-21 19:48:24.607: I/GeckoDoorHangerPopup(28508): Showing all doorhangers for tab: 1 06-21 19:48:24.607: I/GeckoApp(28508): Got message: Gecko:Ready 06-21 19:48:24.623: D/GeckoLayerClient(28508): Screen-size changed to (720,1184) 06-21 19:48:24.623: D/GeckoLayerClient(28508): Window-size changed to (720,1038) 06-21 19:48:24.623: E/SQLiteDatabase(28508): close() was never explicitly called on database '/data/data/org.mozilla.firefox_beta/files/mozilla/0f49o1k4.default/browser.db' 06-21 19:48:24.623: E/SQLiteDatabase(28508): android.database.sqlite.DatabaseObjectNotClosedException: Application did not close the cursor or database object that was opened here 06-21 19:48:24.623: E/SQLiteDatabase(28508): at android.database.sqlite.SQLiteDatabase.<init>(SQLiteDatabase.java:1943) 06-21 19:48:24.623: E/SQLiteDatabase(28508): at android.database.sqlite.SQLiteDatabase.openDatabase(SQLiteDatabase.java:1007) 06-21 19:48:24.623: E/SQLiteDatabase(28508): at android.database.sqlite.SQLiteDatabase.openDatabase(SQLiteDatabase.java:986) 06-21 19:48:24.623: E/SQLiteDatabase(28508): at android.database.sqlite.SQLiteDatabase.openOrCreateDatabase(SQLiteDatabase.java:1051) 06-21 19:48:24.623: E/SQLiteDatabase(28508): at android.app.ContextImpl.openOrCreateDatabase(ContextImpl.java:770) 06-21 19:48:24.623: E/SQLiteDatabase(28508): at android.content.ContextWrapper.openOrCreateDatabase(ContextWrapper.java:221) 06-21 19:48:24.623: E/SQLiteDatabase(28508): at android.database.sqlite.SQLiteOpenHelper.getWritableDatabase(SQLiteOpenHelper.java:157) 06-21 19:48:24.623: E/SQLiteDatabase(28508): at org.mozilla.gecko.db.DBUtils.ensureDatabaseIsNotLocked(DBUtils.java:84) 06-21 19:48:24.623: E/SQLiteDatabase(28508): at org.mozilla.firefox_beta.db.BrowserProvider.getDatabaseHelperForProfile(BrowserProvider.java:978) 06-21 19:48:24.623: E/SQLiteDatabase(28508): at org.mozilla.firefox_beta.db.BrowserProvider.getReadableDatabase(BrowserProvider.java:1017) 06-21 19:48:24.623: E/SQLiteDatabase(28508): at org.mozilla.firefox_beta.db.BrowserProvider.query(BrowserProvider.java:1538) 06-21 19:48:24.623: E/SQLiteDatabase(28508): at android.content.ContentProvider$Transport.query(ContentProvider.java:178) 06-21 19:48:24.623: E/SQLiteDatabase(28508): at android.content.ContentResolver.query(ContentResolver.java:311) 06-21 19:48:24.623: E/SQLiteDatabase(28508): at org.mozilla.gecko.db.LocalBrowserDB.filterAllSites(LocalBrowserDB.java:180) 06-21 19:48:24.623: E/SQLiteDatabase(28508): at org.mozilla.gecko.db.LocalBrowserDB.getTopSites(LocalBrowserDB.java:201) 06-21 19:48:24.623: E/SQLiteDatabase(28508): at org.mozilla.gecko.db.BrowserDB.getTopSites(BrowserDB.java:119) 06-21 19:48:24.623: E/SQLiteDatabase(28508): at org.mozilla.gecko.AboutHomeContent.loadTopSites(AboutHomeContent.java:339) 06-21 19:48:24.623: E/SQLiteDatabase(28508): at org.mozilla.gecko.AboutHomeContent.access$300(AboutHomeContent.java:94) 06-21 19:48:24.623: E/SQLiteDatabase(28508): at org.mozilla.gecko.AboutHomeContent$9.run(AboutHomeContent.java:370) 06-21 19:48:24.623: E/SQLiteDatabase(28508): at android.os.Handler.handleCallback(Handler.java:605) 06-21 19:48:24.623: E/SQLiteDatabase(28508): at android.os.Handler.dispatchMessage(Handler.java:92) 06-21 19:48:24.623: E/SQLiteDatabase(28508): at android.os.Looper.loop(Looper.java:137) 06-21 19:48:24.623: E/SQLiteDatabase(28508): at org.mozilla.gecko.GeckoBackgroundThread.run(GeckoBackgroundThread.java:31) 06-21 19:48:24.623: I/GeckoLayerClient(28508): Showing checks: true 06-21 19:48:24.623: E/SQLiteDatabase(28508): close() was never explicitly called on database '/data/data/org.mozilla.firefox_beta/files/mozilla/0f49o1k4.default/browser.db' 06-21 19:48:24.623: E/SQLiteDatabase(28508): android.database.sqlite.DatabaseObjectNotClosedException: Application did not close the cursor or database object that was opened here 06-21 19:48:24.623: E/SQLiteDatabase(28508): at android.database.sqlite.SQLiteDatabase.<init>(SQLiteDatabase.java:1943) 06-21 19:48:24.623: E/SQLiteDatabase(28508): at android.database.sqlite.SQLiteDatabase.openDatabase(SQLiteDatabase.java:1007) 06-21 19:48:24.623: E/SQLiteDatabase(28508): at android.database.sqlite.SQLiteDatabase.openDatabase(SQLiteDatabase.java:986) 06-21 19:48:24.623: E/SQLiteDatabase(28508): at android.database.sqlite.SQLiteDatabase.openOrCreateDatabase(SQLiteDatabase.java:1051) 06-21 19:48:24.623: E/SQLiteDatabase(28508): at android.app.ContextImpl.openOrCreateDatabase(ContextImpl.java:770) 06-21 19:48:24.623: E/SQLiteDatabase(28508): at android.content.ContextWrapper.openOrCreateDatabase(ContextWrapper.java:221) 06-21 19:48:24.623: E/SQLiteDatabase(28508): at android.database.sqlite.SQLiteOpenHelper.getWritableDatabase(SQLiteOpenHelper.java:157) 06-21 19:48:24.623: E/SQLiteDatabase(28508): at android.database.sqlite.SQLiteOpenHelper.getReadableDatabase(SQLiteOpenHelper.java:231) 06-21 19:48:24.623: E/SQLiteDatabase(28508): at org.mozilla.firefox_beta.db.BrowserProvider.getReadableDatabase(BrowserProvider.java:1017) 06-21 19:48:24.623: E/SQLiteDatabase(28508): at org.mozilla.firefox_beta.db.BrowserProvider.query(BrowserProvider.java:1538) 06-21 19:48:24.623: E/SQLiteDatabase(28508): at android.content.ContentProvider$Transport.query(ContentProvider.java:178) 06-21 19:48:24.623: E/SQLiteDatabase(28508): at android.content.ContentResolver.query(ContentResolver.java:311) 06-21 19:48:24.623: E/SQLiteDatabase(28508): at org.mozilla.gecko.db.LocalBrowserDB.filterAllSites(LocalBrowserDB.java:180) 06-21 19:48:24.623: E/SQLiteDatabase(28508): at org.mozilla.gecko.db.LocalBrowserDB.filter(LocalBrowserDB.java:190) 06-21 19:48:24.623: E/SQLiteDatabase(28508): at org.mozilla.gecko.db.BrowserDB.filter(BrowserDB.java:115) 06-21 19:48:24.623: E/SQLiteDatabase(28508): at org.mozilla.gecko.AwesomeBarTabs$2.runQuery(AwesomeBarTabs.java:811) 06-21 19:48:24.623: E/SQLiteDatabase(28508): at android.widget.CursorAdapter.runQueryOnBackgroundThread(CursorAdapter.java:391) 06-21 19:48:24.623: E/SQLiteDatabase(28508): at android.widget.CursorFilter.performFiltering(CursorFilter.java:49) 06-21 19:48:24.623: E/SQLiteDatabase(28508): at android.widget.Filter$RequestHandler.handleMessage(Filter.java:234) 06-21 19:48:24.623: E/SQLiteDatabase(28508): at android.os.Handler.dispatchMessage(Handler.java:99) 06-21 19:48:24.623: E/SQLiteDatabase(28508): at android.os.Looper.loop(Looper.java:137) 06-21 19:48:24.623: E/SQLiteDatabase(28508): at android.os.HandlerThread.run(HandlerThread.java:60)
cc'ing rnewman and gcp if they know more.
Previously, this error required a hard phone reboot to be able to launch Fennec. Is that the case for you Tony?
(In reply to Mark Finkle (:mfinkle) from comment #4) > Previously, this error required a hard phone reboot to be able to launch > Fennec. Is that the case for you Tony? negative, no rebooting at all. i launched beta, sync'ed some crazy large profile, and then was just tapping around awesomebar, playing with history and top sites. i was then just backscrolling my adb logcat and saw this. the crash (WIN DEATH) occurred but no crash reporter was fired.
Crash Signature: [@ android.database.sqlite.SQLiteDatabaseLockedException: error code 5: database is locked: at android.database.sqlite.SQLiteStatement.native_1x1_string(Native Method)] → [@ android.database.sqlite.SQLiteDatabaseLockedException: error code 5: database is locked at android.database.sqlite.SQLiteStatement.native_1x1_string(Native Method)]
Version: Firefox 15 → Firefox 16
Blocks: 975024
Opening a DB connection involves doing a write, believe it or not. Doing that write in a thread after a read has occurred involves upgrading a read to a write when the current DB state has changed, which will cause SQLITE_BUSY to be raised. That's my diagnosis for Bug 876589. That seems suspiciously close to this bug report.
I can reproduce this bug using Asus Transformer Tab (Android 4.0.3); Steps to reproduce: 1. Go to mozilla.org; 2. Tap on bookmark star and tap on 'Add to reading list' button; 3. Tap on the Reader mode button in the url bar;
I got this crash after visiting a page, tapping the reader mode icon and adding it to reading list. Device:ZTE x86 (Android 4.0.4) Build: Firefox for Android Aurora 30.0a2
Looking at this some more: crashes are occurring on API13 ARM devices and API15 x86 devices, pretty much the same subset of devices. Current reports: https://crash-stats.mozilla.com/report/list?signature=android.database.sqlite.SQLiteDatabaseLockedException%3A+error+code+5%3A+database+is+locked+at+android.database.sqlite.SQLiteStatement.native_1x1_string%28Native+Method%29&product=FennecAndroid&query_type=contains&range_unit=weeks&process_type=any&version=FennecAndroid%3A31.0a1&version=FennecAndroid%3A30.0a2&version=FennecAndroid%3A29.0b1&hang_type=any&date=2014-03-20+16%3A00%3A00&range_value=3#tab-reports Example stack: android.database.sqlite.SQLiteDatabaseLockedException: error code 5: database is locked at android.database.sqlite.SQLiteStatement.native_1x1_string(Native Method) at android.database.sqlite.SQLiteStatement.simpleQueryForString(SQLiteStatement.java:161) at android.database.DatabaseUtils.stringForQuery(DatabaseUtils.java:813) at android.database.DatabaseUtils.stringForQuery(DatabaseUtils.java:801) at android.database.sqlite.SQLiteDatabase.setJournalMode(SQLiteDatabase.java:1063) at android.database.sqlite.SQLiteDatabase.openDatabase(SQLiteDatabase.java:999) at android.database.sqlite.SQLiteDatabase.openOrCreateDatabase(SQLiteDatabase.java:1054) at android.app.ContextImpl.openOrCreateDatabase(ContextImpl.java:770) at android.content.ContextWrapper.openOrCreateDatabase(ContextWrapper.java:221) at android.database.sqlite.SQLiteOpenHelper.getWritableDatabase(SQLiteOpenHelper.java:157) at org.mozilla.gecko.db.TransactionalProvider.getWritableDatabase(TransactionalProvider.java:116) at org.mozilla.gecko.db.TransactionalProvider.update(TransactionalProvider.java:392) at android.content.ContentProvider$Transport.update(ContentProvider.java:219) at android.content.ContentResolver.update(ContentResolver.java:856) at org.mozilla.gecko.db.LocalBrowserDB.addReadingListItem(LocalBrowserDB.java:719) at org.mozilla.gecko.db.BrowserDB.addReadingListItem(BrowserDB.java:276) at org.mozilla.gecko.BrowserApp$5.run(BrowserApp.java:404) at android.os.Handler.handleCallback(Handler.java:605) at android.os.Handler.dispatchMessage(Handler.java:92) at android.os.Looper.loop(Looper.java:137) at org.mozilla.gecko.util.GeckoBackgroundThread.run(GeckoBackgroundThread.java:32) This is interesting, because it indicates that the Android sqlite layer is failing *during open*, as it tries to set the journal mode: https://android.googlesource.com/platform/frameworks/base.git/+/android-4.0.3_r1.1/core/java/android/database/sqlite/SQLiteDatabase.java line 1060 Not only is our own PerProfileDatabases code supposed to be synchronized at this point, but SQLiteDatabase itself is holding its own lock, and the enclosing SQLiteOpenHelper remains synchronized until onOpen has been called. There should be no other opener trying to open that DB. The only conclusion I can draw is that some other thread within Fennec already has an open connection to browser.db, probably executing a write, but that connection did *not* come via our SQLiteOpenHelper classes. Alternatively, there's a persistent flag that's causing the DB to report SQLITE_BUSY even after use. Teodora, Flaviu: could you run adb shell setprop log.tag.SQLiteDatabase VERBOSE adb shell setprop log.tag.SQLiteStatement VERBOSE adb shell setprop log.tag.Databases VERBOSE adb shell setprop log.tag.GeckoBrowserDBHelper VERBOSE kill and relaunch Fennec, repro, and upload a logcat?
Flags: needinfo?(flaviu.cos)
Incidentally, it seems that if the lock is a result of a process crashing during a write, the only means of recovery is to move-then-copy the DB file itself.
I might have just found another cause of this. Both ReadingListProvider and BrowserProvider are backed by the same DB. But they don't use the same PerProfileDatabases instance: each of them implements createDatabaseHelper, which creates a new BrowserDatabaseHelper, and each Provider instance has its own mDatabases. BrowserProvider and ReadingListProvider need to share their PerProfileDatabases.
Blocks: 986114
Filed RL bit as Bug 986114.
Component: General → Data Providers
Hardware: ARM → All
Attached file log.txt (deleted) —
(In reply to Richard Newman [:rnewman] from comment #10) > Flaviu: could you run > > adb shell setprop log.tag.SQLiteDatabase VERBOSE > adb shell setprop log.tag.SQLiteStatement VERBOSE > adb shell setprop log.tag.Databases VERBOSE > adb shell setprop log.tag.GeckoBrowserDBHelper VERBOSE > > kill and relaunch Fennec, repro, and upload a logcat? I attached the logs from logcat.
Flags: needinfo?(flaviu.cos)
Ugh, our zombie killer is horrible. D/GeckoDBUtils( 2517): Database is locked, trying to kill any zombie processes: /data/data/org.mozilla.fennec/files/mozilla/mlep0rqz.default/browser.db I/ActivityManager( 170): Process org.mozilla.fennec.UpdateService (pid 2611) has died. I/ActivityManager( 170): Process org.mozilla.fennec_aurora (pid 2505) has died. Thanks. This log confirms my hypothesis in Bug 986114: we're successfully doing BrowserDB stuff, then ReadingListProvider comes along and tries to hit the same DB, hitting the lock, triggering the zombie killer to kill other processes, then failing, leaving the DB unclosed. Oops.
Crash Signature: [@ android.database.sqlite.SQLiteDatabaseLockedException: error code 5: database is locked at android.database.sqlite.SQLiteStatement.native_1x1_string(Native Method)] → [@ android.database.sqlite.SQLiteDatabaseLockedException: error code 5: database is locked at android.database.sqlite.SQLiteStatement.native_1x1_string(Native Method)] [@ android.database.sqlite.SQLiteDatabaseLockedException: error code 5: database is lo…
Closing because no crashes reported for 12 weeks.
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → WONTFIX
Closing because no crashes reported for 12 weeks.
Product: Firefox for Android → Firefox for Android Graveyard
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: