Closed Bug 1572881 Opened 5 years ago Closed 5 years ago

Sync: null cursor exception in PasswordsRepoSession.store

Categories

(Firefox for Android Graveyard :: Android Sync, defect)

Product:
Firefox for Android Graveyard
Component:
Android Sync
Version:
Firefox 68
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

(Not tracked)

Status:
RESOLVED WORKSFORME

People

(Reporter: a.mux, Unassigned, NeedInfo)

Details

User Agent: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:68.0) Gecko/20100101 Firefox/68.0

Steps to reproduce:

Tapped "Settings | Firefox Account | Sync now".
Bookmarks and passwords do not sync. Details follow.

Environment:

Actual results:

Bookmarks and password did not sync, logcat points to some problem in the android sqlite database.

Relevant logcat output is 4000 rows, full of redundance.

The slimmest log version I could produce is the following (edited manually & with https://stackoverflow.com/a/37034957/5438566).

==========================================
[ nothing strange here ]

I FxAccounts: firefox :: FirefoxAccounts :: Requesting sync.
I FxAccounts: firefox :: FirefoxAccounts :: Sync options -- scheduling now: true
I FxAccounts: firefox :: FxAccountStatusFragment :: Got sync started message; refreshing.
I FxAccounts: firefox :: FxAccountSyncAdapter :: Syncing FxAccount account named like X.XXX@XXXXXX.XX for authority org.mozilla.firefox.db.browser with instance org.mozilla.gecko.fxa.sync.FxAccountSyncAdapter@89e6b98.
I FxAccounts: firefox :: FxAccountSyncAdapter :: Account last synced at: 1565386946491
I FxAccounts: firefox :: FirefoxAccounts :: Sync options -- scheduling now: true
I FxAccounts: firefox :: FxAccountSyncAdapter :: Forced sync (rate): overruling remaining backoff of 21378ms.
I FxAccounts: firefox :: LoginStateMachineDelegate :: handleFinal: in Married
I FxAccounts: firefox :: AndroidFxAccount :: Moving account named like X.XXX@XXXXXX.XX to state Married
I FxAccounts: firefox :: FxAccountNotificationManager :: State Married needs no action; cancelling any existing notification.
I FxAccounts: firefox :: LoginStateMachineDelegate :: handleMarried: in Married
I FxADeviceListUpdater: Beginning FxA device list update.
I GeckoBrowserProvider: Deleted 4 remote devices.
I FxADeviceListUpdater: FxA Device list update done.
I FxAccounts: firefox :: LoginStateMachineDelegate :: Fetching profile avatar information.
I GeckoLogger: firefox :: AndroidFxAccount :: Intent service launched to fetch profile.
I FxAccounts: firefox :: GlobalSession :: Running next stage checkPreconditions (org.mozilla.gecko.sync.stage.CheckPreconditionsStage@30917a1)...
I FxAccounts: firefox :: GlobalSession :: Running next stage fetchInfoCollections (org.mozilla.gecko.sync.stage.FetchInfoCollectionsStage@7984dc6)...
I GeckoLogger: firefox :: AndroidFxAccount :: Profile JSON fetch succeeded!
I FxAccounts: firefox :: GlobalSession :: Running next stage fetchInfoConfiguration (org.mozilla.gecko.sync.stage.FetchInfoConfigurationStage@7e1674d)...
I FxAccounts: firefox :: FxAccountStatusFragment :: Profile avatar cache update action broadcast received.
I FxAccounts: firefox :: GlobalSession :: Running next stage fetchMetaGlobal (org.mozilla.gecko.sync.stage.FetchMetaGlobalStage@9dadc4e)...
I FxAccounts: firefox :: FetchMetaGlobalStage :: Trying to use persisted meta/global for this session.
I FxAccounts: firefox :: FetchMetaGlobalStage :: Using persisted meta/global for this session.
I FxAccounts: firefox :: GlobalSession :: Running next stage ensureKeysStage (org.mozilla.gecko.sync.stage.EnsureCrypto5KeysStage@3a3c16f)...
I FxAccounts: firefox :: GlobalSession :: Running next stage syncClientsEngine (org.mozilla.gecko.sync.stage.SyncClientsEngineStage@c835e7c)...
I FxAccounts: firefox :: SyncClientsEngineStage :: Local client GUID exists on server and was downloaded.
I FxAccounts: firefox :: GlobalSession :: Running next stage syncTabs (org.mozilla.gecko.sync.stage.FennecTabsServerSyncStage@bd5058b)...
I FxAccounts: firefox :: RecordsChannel :: No data available: short-circuiting flow from source org.mozilla.gecko.sync.middleware.Crypto5MiddlewareRepositorySession@da7bdbd
I FxAccounts: firefox :: RecordsChannel :: onFetchCompleted. Fetched 0 records. Storing...
I FxAccounts: firefox :: RecordsChannel :: Performing source cleanup.
I FxAccounts: firefox :: RecordsChannel :: onStoreCompleted. Attempted to store 0 records; Store accepted 0, reconciled 0, failed 0
I FxAccounts: firefox :: ServerSyncStage :: Stage tabs received 0; stored 0, reconciling 0 and failed to store 0. Sent 0; server accepted 0 and rejected 0. Duration: 0.02 seconds.
I FxAccounts: firefox :: ServerSyncStage :: Advancing session.

[... problems seem to start here ...]

I FxAccounts: firefox :: GlobalSession :: Running next stage syncPasswords (org.mozilla.gecko.sync.stage.PasswordsServerSyncStage@12de45f)...
I MSM-irqbalance: Decided to move IRQ166 from CPU3 to CPU1
I FxAccounts: firefox :: RecordsChannel :: onFetchCompleted. Fetched 241 records. Storing...
E FxAccounts: firefox :: PasswordsRepoSession :: Got null cursor exception in PasswordsRepoSession.store
W FxAccounts: firefox :: SynchronizerSession :: First RecordsChannel onFlowStoreFailed. Logging local store error.
W FxAccounts: org.mozilla.gecko.sync.repositories.NullCursorException
W FxAccounts: at org.mozilla.gecko.sync.repositories.android.RepoUtils$QueryHelper.checkNullCursor(RepoUtils.java:91)
W FxAccounts: at org.mozilla.gecko.sync.repositories.android.RepoUtils$QueryHelper.checkAndLogCursor(RepoUtils.java:85)
W FxAccounts: at org.mozilla.gecko.sync.repositories.android.RepoUtils$QueryHelper.safeQuery(RepoUtils.java:64)
W FxAccounts: at org.mozilla.gecko.sync.repositories.android.PasswordsRepositorySession.retrieveByGUID(PasswordsRepositorySession.java:526)
W FxAccounts: at org.mozilla.gecko.sync.repositories.android.PasswordsRepositorySession.access$1000(PasswordsRepositorySession.java:34)
W FxAccounts: at org.mozilla.gecko.sync.repositories.android.PasswordsRepositorySession$4.run(PasswordsRepositorySession.java:217)
W FxAccounts: at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
W FxAccounts: at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
W FxAccounts: at java.lang.Thread.run(Thread.java:761)
E SQLiteBridge: Bridge finalized without closing the database
E GeckoLibLoad: Throw
E SQLiteBridge: Bridge finalized without closing the database
E GeckoPasswordsProvider: Error getting version
E GeckoPasswordsProvider: org.mozilla.gecko.sqlite.SQLiteBridgeException: Can't prepare statement: database is locked
E GeckoPasswordsProvider: at org.mozilla.gecko.sqlite.SQLiteBridge.sqliteCallWithDb(Native Method)
E GeckoPasswordsProvider: at org.mozilla.gecko.sqlite.SQLiteBridge.internalQuery(SQLiteBridge.java:244)
E GeckoPasswordsProvider: at org.mozilla.gecko.sqlite.SQLiteBridge.prepareWAL(SQLiteBridge.java:346)
E GeckoPasswordsProvider: at org.mozilla.gecko.sqlite.SQLiteBridge.openDatabase(SQLiteBridge.java:272)
E GeckoPasswordsProvider: at org.mozilla.gecko.db.SQLiteBridgeContentProvider.getDB(SQLiteBridgeContentProvider.java:125)
E GeckoPasswordsProvider: at org.mozilla.gecko.db.SQLiteBridgeContentProvider.getDatabaseForProfile(SQLiteBridgeContentProvider.java:205)
E GeckoPasswordsProvider: at org.mozilla.gecko.db.SQLiteBridgeContentProvider.getDatabase(SQLiteBridgeContentProvider.java:269)
E GeckoPasswordsProvider: at org.mozilla.gecko.db.SQLiteBridgeContentProvider.query(SQLiteBridgeContentProvider.java:412)
E GeckoPasswordsProvider: at android.content.ContentProvider.query(ContentProvider.java:1020)
E GeckoPasswordsProvider: at android.content.ContentProvider$Transport.query(ContentProvider.java:239)
E GeckoPasswordsProvider: at android.content.ContentProviderNative.onTransact(ContentProviderNative.java:112)
E GeckoPasswordsProvider: at android.os.Binder.execTransact(Binder.java:565)
E GeckoPasswordsProvider: Can not set up database. Gecko is not running
E SQLiteBridge: Bridge finalized without closing the database
E FxAccounts: firefox :: PasswordsRepoSession :: Got null cursor exception in PasswordsRepoSession.store
W FxAccounts: firefox :: SynchronizerSession :: First RecordsChannel onFlowStoreFailed. Logging local store error.
W FxAccounts: org.mozilla.gecko.sync.repositories.NullCursorException
W FxAccounts: at org.mozilla.gecko.sync.repositories.android.RepoUtils$QueryHelper.checkNullCursor(RepoUtils.java:91)
W FxAccounts: at org.mozilla.gecko.sync.repositories.android.RepoUtils$QueryHelper.checkAndLogCursor(RepoUtils.java:85)
W FxAccounts: at org.mozilla.gecko.sync.repositories.android.RepoUtils$QueryHelper.safeQuery(RepoUtils.java:64)
W FxAccounts: at org.mozilla.gecko.sync.repositories.android.PasswordsRepositorySession.retrieveByGUID(PasswordsRepositorySession.java:526)
W FxAccounts: at org.mozilla.gecko.sync.repositories.android.PasswordsRepositorySession.access$1000(PasswordsRepositorySession.java:34)
W FxAccounts: at org.mozilla.gecko.sync.repositories.android.PasswordsRepositorySession$4.run(PasswordsRepositorySession.java:217)
W FxAccounts: at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
W FxAccounts: at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
W FxAccounts: at java.lang.Thread.run(Thread.java:761)
E SQLiteBridge: Bridge finalized without closing the database
E GeckoLibLoad: Throw
E GeckoPasswordsProvider: Error getting version
E GeckoPasswordsProvider: org.mozilla.gecko.sqlite.SQLiteBridgeException: Can't prepare statement: database is locked
E GeckoPasswordsProvider: at org.mozilla.gecko.sqlite.SQLiteBridge.sqliteCallWithDb(Native Method)
E GeckoPasswordsProvider: at org.mozilla.gecko.sqlite.SQLiteBridge.internalQuery(SQLiteBridge.java:244)
E GeckoPasswordsProvider: at org.mozilla.gecko.sqlite.SQLiteBridge.prepareWAL(SQLiteBridge.java:346)
E GeckoPasswordsProvider: at org.mozilla.gecko.sqlite.SQLiteBridge.openDatabase(SQLiteBridge.java:272)
E GeckoPasswordsProvider: at org.mozilla.gecko.db.SQLiteBridgeContentProvider.getDB(SQLiteBridgeContentProvider.java:125)
E GeckoPasswordsProvider: at org.mozilla.gecko.db.SQLiteBridgeContentProvider.getDatabaseForProfile(SQLiteBridgeContentProvider.java:205)
E GeckoPasswordsProvider: at org.mozilla.gecko.db.SQLiteBridgeContentProvider.getDatabase(SQLiteBridgeContentProvider.java:269)
E GeckoPasswordsProvider: at org.mozilla.gecko.db.SQLiteBridgeContentProvider.query(SQLiteBridgeContentProvider.java:412)
E GeckoPasswordsProvider: at android.content.ContentProvider.query(ContentProvider.java:1020)
E GeckoPasswordsProvider: at android.content.ContentProvider$Transport.query(ContentProvider.java:239)
E GeckoPasswordsProvider: at android.content.ContentProviderNative.onTransact(ContentProviderNative.java:112)
E GeckoPasswordsProvider: at android.os.Binder.execTransact(Binder.java:565)
E GeckoPasswordsProvider: Can not set up database. Gecko is not running
E FxAccounts: firefox :: PasswordsRepoSession :: Got null cursor exception in PasswordsRepoSession.store
E SQLiteBridge: Bridge finalized without closing the database
W FxAccounts: firefox :: SynchronizerSession :: First RecordsChannel onFlowStoreFailed. Logging local store error.
W FxAccounts: org.mozilla.gecko.sync.repositories.NullCursorException
W FxAccounts: at org.mozilla.gecko.sync.repositories.android.RepoUtils$QueryHelper.checkNullCursor(RepoUtils.java:91)
W FxAccounts: at org.mozilla.gecko.sync.repositories.android.RepoUtils$QueryHelper.checkAndLogCursor(RepoUtils.java:85)
W FxAccounts: at org.mozilla.gecko.sync.repositories.android.RepoUtils$QueryHelper.safeQuery(RepoUtils.java:64)
W FxAccounts: at org.mozilla.gecko.sync.repositories.android.PasswordsRepositorySession.retrieveByGUID(PasswordsRepositorySession.java:526)
W FxAccounts: at org.mozilla.gecko.sync.repositories.android.PasswordsRepositorySession.access$1000(PasswordsRepositorySession.java:34)
W FxAccounts: at org.mozilla.gecko.sync.repositories.android.PasswordsRepositorySession$4.run(PasswordsRepositorySession.java:217)
W FxAccounts: at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
W FxAccounts: at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
W FxAccounts: at java.lang.Thread.run(Thread.java:761)
E SQLiteBridge: Bridge finalized without closing the database
E FxAccounts: firefox :: PasswordsRepoSession :: Got null cursor exception in PasswordsRepoSession.store
W FxAccounts: firefox :: SynchronizerSession :: First RecordsChannel onFlowStoreFailed. Logging local store error.
W FxAccounts: org.mozilla.gecko.sync.repositories.NullCursorException
W FxAccounts: at org.mozilla.gecko.sync.repositories.android.RepoUtils$QueryHelper.checkNullCursor(RepoUtils.java:91)
W FxAccounts: at org.mozilla.gecko.sync.repositories.android.RepoUtils$QueryHelper.checkAndLogCursor(RepoUtils.java:85)
W FxAccounts: at org.mozilla.gecko.sync.repositories.android.RepoUtils$QueryHelper.safeQuery(RepoUtils.java:64)
W FxAccounts: at org.mozilla.gecko.sync.repositories.android.PasswordsRepositorySession.retrieveByGUID(PasswordsRepositorySession.java:526)
W FxAccounts: at org.mozilla.gecko.sync.repositories.android.PasswordsRepositorySession.access$1000(PasswordsRepositorySession.java:34)
W FxAccounts: at org.mozilla.gecko.sync.repositories.android.PasswordsRepositorySession$4.run(PasswordsRepositorySession.java:217)
W FxAccounts: at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
W FxAccounts: at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
W FxAccounts: at java.lang.Thread.run(Thread.java:761)
I FxAccounts: firefox :: RecordsChannel :: Performing source cleanup.
I FxAccounts: firefox :: RecordsChannel :: onStoreCompleted. Attempted to store 241 records; Store accepted 0, reconciled 0, failed 241
W FxAccounts: firefox :: SynchronizerSession :: Got 241 failures storing local records! Ignoring local store failures and continuing synchronizer session.

E FxAccounts: firefox :: PasswordsRepoSession :: Got null cursor exception in PasswordsRepoSession.fetchModified
E FxAccounts: firefox :: PasswordsRepoSession :: Exception in fetch.
W FxAccounts: firefox :: RecordsChannel :: onFetchFailed. Calling for immediate stop.
W FxAccounts: org.mozilla.gecko.sync.repositories.NullCursorException
W FxAccounts: at org.mozilla.gecko.sync.repositories.android.RepoUtils$QueryHelper.checkNullCursor(RepoUtils.java:91)
W FxAccounts: at org.mozilla.gecko.sync.repositories.android.RepoUtils$QueryHelper.checkAndLogCursor(RepoUtils.java:85)
W FxAccounts: at org.mozilla.gecko.sync.repositories.android.RepoUtils$QueryHelper.safeQuery(RepoUtils.java:64)
W FxAccounts: at org.mozilla.gecko.sync.repositories.android.PasswordsRepositorySession$1.run(PasswordsRepositorySession.java:80)
W FxAccounts: at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
W FxAccounts: at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
W FxAccounts: at java.lang.Thread.run(Thread.java:761)
W FxAccounts: firefox :: SynchronizerSession :: Second RecordsChannel onFlowFetchFailed. Logging local fetch error.
W FxAccounts: org.mozilla.gecko.sync.repositories.NullCursorException
W FxAccounts: at org.mozilla.gecko.sync.repositories.android.RepoUtils$QueryHelper.checkNullCursor(RepoUtils.java:91)
W FxAccounts: at org.mozilla.gecko.sync.repositories.android.RepoUtils$QueryHelper.checkAndLogCursor(RepoUtils.java:85)
W FxAccounts: at org.mozilla.gecko.sync.repositories.android.RepoUtils$QueryHelper.safeQuery(RepoUtils.java:64)
W FxAccounts: at org.mozilla.gecko.sync.repositories.android.PasswordsRepositorySession$1.run(PasswordsRepositorySession.java:80)
W FxAccounts: at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
W FxAccounts: at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
W FxAccounts: at java.lang.Thread.run(Thread.java:761)

W FxAccounts: firefox :: SynchronizerSession :: Saw failures fetching local records! Aborting session.
W FxAccounts: firefox :: ServerSyncStage :: Synchronize failed: Saw failures fetching local records!

W FxAccounts: org.mozilla.gecko.sync.repositories.FetchFailedException
W FxAccounts: at org.mozilla.gecko.sync.synchronizer.SynchronizerSession.onSecondFlowCompleted(SynchronizerSession.java:383)
W FxAccounts: at org.mozilla.gecko.sync.synchronizer.SynchronizerSession.onFlowCompleted(SynchronizerSession.java:419)
W FxAccounts: at org.mozilla.gecko.sync.synchronizer.RecordsChannel.onFetchFailed(RecordsChannel.java:198)
W FxAccounts: at org.mozilla.gecko.sync.repositories.android.PasswordsRepositorySession$1.run(PasswordsRepositorySession.java:108)
W FxAccounts: at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
W FxAccounts: at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
W FxAccounts: at java.lang.Thread.run(Thread.java:761)

I FxAccounts: firefox :: ServerSyncStage :: Advancing session even though stage failed (took 3.38 seconds). Timestamps not persisted.
I FxAccounts: firefox :: GlobalSession :: Running next stage syncRecentHistory (org.mozilla.gecko.sync.stage.RecentHistoryServerSyncStage@aaaf35f)...
I FxAccounts: firefox :: ServerSyncStage :: Skipping stage history.
I FxAccounts: firefox :: GlobalSession :: Running next stage syncBookmarks (org.mozilla.gecko.sync.stage.BookmarksServerSyncStage@1fefe0a)...
I FxAccounts: firefox :: RecordsChannel :: No data available: short-circuiting flow from source org.mozilla.gecko.sync.middleware.Crypto5MiddlewareRepositorySession@a119a44
I FxAccounts: firefox :: RecordsChannel :: onFetchCompleted. Fetched 0 records. Storing...
I FxAccounts: firefox :: RecordsChannel :: Performing source cleanup.
I FxAccounts: firefox :: RecordsChannel :: onStoreCompleted. Attempted to store 0 records; Store accepted 0, reconciled 0, failed 0
I FxAccounts: firefox :: ServerSyncStage :: Stage bookmarks received 0; stored 0, reconciling 0 and failed to store 0. Sent 0; server accepted 0 and rejected 0. Duration: 0.02 seconds.
I FxAccounts: firefox :: ServerSyncStage :: Advancing session.
I FxAccounts: firefox :: GlobalSession :: Running next stage syncFullHistory (org.mozilla.gecko.sync.stage.HistoryServerSyncStage@71b44ae)...
I FxAccounts: firefox :: ServerSyncStage :: Skipping stage history.
I FxAccounts: firefox :: GlobalSession :: Running next stage syncFormHistory (org.mozilla.gecko.sync.stage.FormHistoryServerSyncStage@cb17ee5)...
I FxAccounts: firefox :: ServerSyncStage :: Skipping stage forms.
I FxAccounts: firefox :: GlobalSession :: Running next stage validateBookmarks (org.mozilla.gecko.sync.stage.ValidateBookmarksSyncStage@f840bc8)...
I FxAccounts: firefox :: ServerSyncStage :: Skipping stage bookmarks.
I FxAccounts: firefox :: GlobalSession :: Running next stage uploadMetaGlobal (org.mozilla.gecko.sync.stage.UploadMetaGlobalStage@8af5c47)...
I FxAccounts: firefox :: GlobalSession :: Not uploading updated meta/global record since there are no engines requesting upload.
I FxAccounts: firefox :: GlobalSession :: Running next stage completed (org.mozilla.gecko.sync.stage.CompletedStage@6b21c74)...
I FxAccounts: firefox :: FxAccountSyncAdapter :: Global session succeeded.
I FxAccounts: firefox :: FxAccountSchedulePolicy :: Scheduling periodic sync for 43200.
I FxAccounts: firefox :: FxAccountSyncAdapter :: Sync succeeded.
I TelemetryBgReceiver: Handling background telemetry broadcast
I TelemetryBgReceiver: Telemetry is disabled via preferences, dropping background telemetry.
I FxAccounts: firefox :: FxAccountSyncAdapter :: Syncing done.
I FxAccounts: firefox :: FxAccountStatusFragment :: Got sync finished message; refreshing.

Expected results:

Bookmarks & Password should have synced.

Conversedly, sending tabs across devices works as expected.

The priority flag is not set for this bug.
:Grisha, could you have a look please?

For more information, please visit auto_nag documentation.

Flags: needinfo?(gkruglov)

This bug is currently not actionable. If more reports come in then we may investigate.

Status: UNCONFIRMED → RESOLVED
Closed: 5 years ago
Resolution: --- → WORKSFORME
Product: Firefox for Android → Firefox for Android Graveyard
You need to log in before you can comment on or make changes to this bug.