1393104 - Sync operations crashing in my new profile on Firefox Nightly for Android

Status: RESOLVED DUPLICATE of bug 1392716

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

Description

[Daniel Holbert [:dholbert]]

I just got a new Samsung Galaxy Tab S2 (running Android 7.0 Nougat), and I installed Firefox Nightly on it and configured it with Sync, but the browser seemed to crash partway through the Sync operation, on every single Sync operation.

Crash reports:
bp-365efcf8-20d1-4f88-938a-00c4b0170823
bp-4376cf17-b436-4722-a289-9f49a0170823
bp-bf3fee13-fa2b-4c57-9332-e370a0170823
bp-22108730-68e0-4f22-b6e3-f03d60170823
bp-eef73631-a5e2-4649-b23e-70f910170823
bp-e12e78b3-b78d-4c16-8b57-d25fd0170823


I seem to have made the problem go away after disabling and then reenabling every sync sub-category, so I can't reproduce anymore. :-/  But I did capture "adb logcat" from when the problem happened, and I'll attach that.

Comment 1

[Daniel Holbert [:dholbert]]

My Nightly version is 2017-08-23, BTW.

And I just crashed again, so it turns out I can still reproduce! "Hooray". :)

Comment 2

[Lina Butler [:lina]]

Thanks! This looks like bug 1392716; Grisha has a patch up in bug 1388884.

Comment 3

[Daniel Holbert [:dholbert]]

Oh great! in case it helps, here's the adb logcat output leading up to when the crash happens:
> 08-23 09:03:46.566 23716 23919 I FxAccounts: fennec_aurora :: GlobalSession :: Running next stage syncRecentHistory (org.mozilla.gecko.sync.stage.RecentHistoryServerSyncStage@c856e41)...
> 08-23 09:03:46.567 23716 23919 I FxAccounts: fennec_aurora :: ServerSyncStage :: Skipping stage history.
> 08-23 09:03:46.567 23716 23919 I FxAccounts: fennec_aurora :: GlobalSession :: Running next stage syncBookmarks (org.mozilla.gecko.sync.stage.BookmarksServerSyncStage@2592472)...
> 08-23 09:03:48.663 23716 23923 I FxAccounts: fennec_aurora :: SessionHelper :: BEGIN: creating record -> GUID map.
> 08-23 09:03:49.314 23716 23923 I FxAccounts: fennec_aurora :: SessionHelper :: END: creating record -> GUID map.
> 08-23 09:03:49.315 23716 23923 I FxAccounts: fennec_aurora :: SessionHelper :: Stored after reconcile attempt #1
> 08-23 09:03:49.320 23716 23923 I FxAccounts: fennec_aurora :: SessionHelper :: Stored after reconcile attempt #1
> 08-23 09:03:49.326 23716 23923 I FxAccounts: fennec_aurora :: SessionHelper :: Stored after reconcile attempt #1
> 08-23 09:03:49.332 23716 23923 I FxAccounts: fennec_aurora :: SessionHelper :: Stored after reconcile attempt #1
> 08-23 09:03:49.338 23716 23923 I FxAccounts: fennec_aurora :: SessionHelper :: Stored after reconcile attempt #1
[SNIP -- there are 1262 consecutive copies of this "Stored after reconcile attempt line" here...]
> 08-23 09:04:00.335 23716 23923 I FxAccounts: fennec_aurora :: SessionHelper :: Stored after reconcile attempt #1
> 08-23 09:04:00.342 23716 23923 I FxAccounts: fennec_aurora :: SessionHelper :: Stored after reconcile attempt #1
> 08-23 09:04:00.360 23716 23716 D GeckoToolbar: onTabChanged: MENU_UPDATED
> 08-23 09:04:00.360 23716 23716 D GeckoBrowserApp: BrowserApp.onTabChanged: 0: MENU_UPDATED
> 08-23 09:04:00.365 23716 23716 D SwitchBoard: top-addons-menu = true
> 08-23 09:04:00.377 23716 23716 D GeckoToolbar: onTabChanged: MENU_UPDATED
> 08-23 09:04:00.377 23716 23716 D GeckoBrowserApp: BrowserApp.onTabChanged: 0: MENU_UPDATED
> 08-23 09:04:00.380 23716 23716 D SwitchBoard: top-addons-menu = true
> 08-23 09:04:00.399 23716 23716 D GeckoToolbar: onTabChanged: MENU_UPDATED
> 08-23 09:04:00.399 23716 23716 D GeckoBrowserApp: BrowserApp.onTabChanged: 0: MENU_UPDATED
> 08-23 09:04:00.403 23716 23716 D SwitchBoard: top-addons-menu = true
> 08-23 09:04:00.446 23716 23716 D GeckoToolbar: onTabChanged: MENU_UPDATED
> 08-23 09:04:00.446 23716 23716 D GeckoBrowserApp: BrowserApp.onTabChanged: 0: MENU_UPDATED
> 08-23 09:04:00.449 23716 23716 D SwitchBoard: top-addons-menu = true
> 08-23 09:04:00.463 23716 23716 D GeckoToolbar: onTabChanged: MENU_UPDATED
> 08-23 09:04:00.463 23716 23716 D GeckoBrowserApp: BrowserApp.onTabChanged: 0: MENU_UPDATED
> 08-23 09:04:00.467 23716 23716 D SwitchBoard: top-addons-menu = true
> 08-23 09:04:00.477 23716 23716 D GeckoToolbar: onTabChanged: MENU_UPDATED
> 08-23 09:04:00.477 23716 23716 D GeckoBrowserApp: BrowserApp.onTabChanged: 0: MENU_UPDATED
> 08-23 09:04:00.481 23716 23716 D SwitchBoard: top-addons-menu = true
> 08-23 09:04:00.489 23716 23716 D GeckoToolbar: onTabChanged: MENU_UPDATED
> 08-23 09:04:00.489 23716 23716 D GeckoBrowserApp: BrowserApp.onTabChanged: 0: MENU_UPDATED
> 08-23 09:04:00.493 23716 23716 D SwitchBoard: top-addons-menu = true
> 08-23 09:04:00.525 23716 23716 D GeckoToolbar: onTabChanged: MENU_UPDATED
> 08-23 09:04:00.525 23716 23716 D GeckoBrowserApp: BrowserApp.onTabChanged: 0: MENU_UPDATED
> 08-23 09:04:00.529 23716 23716 D SwitchBoard: top-addons-menu = true
> 08-23 09:04:00.614 23716 23716 D GeckoToolbar: onTabChanged: MENU_UPDATED
> 08-23 09:04:00.614 23716 23716 D GeckoBrowserApp: BrowserApp.onTabChanged: 0: MENU_UPDATED
> 08-23 09:04:00.618 23716 23716 D SwitchBoard: top-addons-menu = true
> 08-23 09:04:00.693 23716 23716 D GeckoToolbar: onTabChanged: MENU_UPDATED
> 08-23 09:04:00.693 23716 23716 D GeckoBrowserApp: BrowserApp.onTabChanged: 0: MENU_UPDATED
> 08-23 09:04:00.698 23716 23716 D SwitchBoard: top-addons-menu = true
> 08-23 09:04:00.707 23716 23716 D GeckoToolbar: onTabChanged: MENU_UPDATED
> 08-23 09:04:00.708 23716 23716 D GeckoBrowserApp: BrowserApp.onTabChanged: 0: MENU_UPDATED
> 08-23 09:04:00.713 23716 23716 D SwitchBoard: top-addons-menu = true
> 08-23 09:04:00.822 23716 23716 D GeckoToolbar: onTabChanged: MENU_UPDATED
> 08-23 09:04:00.822 23716 23716 D GeckoBrowserApp: BrowserApp.onTabChanged: 0: MENU_UPDATED
> 08-23 09:04:00.826 23716 23716 D SwitchBoard: top-addons-menu = true
> 08-23 09:04:01.113 23716 23929 E GeckoCrashHandler: >>> REPORTING UNCAUGHT EXCEPTION FROM THREAD 328 ("pool-26-thread-1")
> 08-23 09:04:01.113 23716 23929 E GeckoCrashHandler: java.lang.IllegalStateException: Expected to modify syncVersion for a guid, but did not
> 08-23 09:04:01.113 23716 23929 E GeckoCrashHandler:     at org.mozilla.gecko.db.BrowserProvider.bulkUpdateSyncVersions(BrowserProvider.java:2782)
> 08-23 09:04:01.113 23716 23929 E GeckoCrashHandler:     at org.mozilla.gecko.db.BrowserProvider.call(BrowserProvider.java:2555)
> 08-23 09:04:01.113 23716 23929 E GeckoCrashHandler:     at android.content.ContentProvider$Transport.call(ContentProvider.java:404)
> 08-23 09:04:01.113 23716 23929 E GeckoCrashHandler:     at android.content.ContentResolver.call(ContentResolver.java:1449)
> 08-23 09:04:01.113 23716 23929 E GeckoCrashHandler:     at org.mozilla.gecko.sync.repositories.VersioningDelegateHelper.persistSyncVersions(VersioningDelegateHelper.java:100)
> 08-23 09:04:01.113 23716 23929 E GeckoCrashHandler:     at org.mozilla.gecko.sync.repositories.android.BookmarksRepositorySession.performCleanup(BookmarksRepositorySession.java:214)
> 08-23 09:04:01.113 23716 23929 E GeckoCrashHandler:     at org.mozilla.gecko.sync.middleware.BufferingMiddlewareRepositorySession.performCleanup(BufferingMiddlewareRepositorySession.java:66)
> 08-23 09:04:01.113 23716 23929 E GeckoCrashHandler:     at org.mozilla.gecko.sync.synchronizer.RecordsChannel.onStoreCompleted(RecordsChannel.java:305)
> 08-23 09:04:01.113 23716 23929 E GeckoCrashHandler:     at org.mozilla.gecko.sync.repositories.delegates.DeferredRepositorySessionStoreDelegate$3.run(DeferredRepositorySessionStoreDelegate.java:53)
> 08-23 09:04:01.113 23716 23929 E GeckoCrashHandler:     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1133)
> 08-23 09:04:01.113 23716 23929 E GeckoCrashHandler:     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:607)
> 08-23 09:04:01.113 23716 23929 E GeckoCrashHandler:     at java.lang.Thread.run(Thread.java:762)
> 08-23 09:04:01.113 23716 23929 E GeckoCrashHandler: Main thread (1) stack:
> 08-23 09:04:01.119 23716 23929 E GeckoCrashHandler:     android.os.MessageQueue.nativePollOnce(Native Method)
> 08-23 09:04:01.119 23716 23929 E GeckoCrashHandler:     android.os.MessageQueue.next(MessageQueue.java:323)
> 08-23 09:04:01.119 23716 23929 E GeckoCrashHandler:     android.os.Looper.loop(Looper.java:136)
> 08-23 09:04:01.119 23716 23929 E GeckoCrashHandler:     android.app.ActivityThread.main(ActivityThread.java:6780)
> 08-23 09:04:01.119 23716 23929 E GeckoCrashHandler:     java.lang.reflect.Method.invoke(Native Method)
> 08-23 09:04:01.119 23716 23929 E GeckoCrashHandler:     com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:1496)
> 08-23 09:04:01.119 23716 23929 E GeckoCrashHandler:     com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1386)
> 08-23 09:04:01.155 23716 23929 W google-breakpad: ExceptionHandler::GenerateDump cloned child 
> 08-23 09:04:01.155 23716 23929 W google-breakpad: 23931
> 08-23 09:04:01.155 23716 23929 W google-breakpad:

Comment 4

[:Grisha Kruglov]

Where you doing anything with bookmarks in the meantime? Perhaps modifying them in the UI..?

Comment 5

[Daniel Holbert [:dholbert]]

Nope. Browser was just sitting there doing nothing. The most complex thing I did was open a new tab or visit about:logins or about:crashes.

Comment 6

[Daniel Holbert [:dholbert]]

(My tapping/typing in URL bar may have queried the bookmarks DB, I suppose, but I wasn't modifying them.)

Comment 7

[Daniel Holbert [:dholbert]]

I've now hit this on a second device (my cell phone, OnePlus One, with yesterday's Nightly 2017-08-22).

Crash report: bp-d7caa73e-7c20-4464-905a-25cb10170823

I didn't do anything special (that I know of) to trigger it on that device, either -- I just got a random crash. And then after I restarted, I got another sync crash (again, without any meaningful user interaction that I know of), this time with a different signature: bp-eac3d403-e0bf-4877-a271-cba270170823
===
Signature: java.lang.NullPointerException: Attempt to invoke interface method ''java.lang.Object java.util.Map.get(java.lang.Object)'' on a null object reference at org.mozilla.gecko.sync.GlobalSession.getSyncStageByName(GlobalSession.java)
===

Not sure if that's related or not.

Comment 8

[Richard Newman [:rnewman]]

(In reply to Daniel Holbert [:dholbert] from comment #7)
> I've now hit this on a second device (my cell phone, OnePlus One, with
> yesterday's Nightly 2017-08-22).

That helps a lot; I think we'll need to repro to figure this one out, so if your Sync account repros, I think Grisha might want to throw a build at you!


> ===
> Signature: java.lang.NullPointerException: Attempt to invoke interface
> method ''java.lang.Object java.util.Map.get(java.lang.Object)'' on a null
> object reference at
> org.mozilla.gecko.sync.GlobalSession.getSyncStageByName(GlobalSession.java)
> ===
> 
> Not sure if that's related or not.

That one's Bug 1373254. Also a P1 :D