Just to be clear, this is about regular tab syncing. Not Send Tab via notifications?

This is about the synced tabs on desktop. Attaching screenshot.

With similar STR, I'm unable to reproduce the problem, using master for iOS and release (55.0.3) for Desktop. STR differences: I a previously logged in account on both desktop and iOS. I do have to sync the iOS client first, then desktop. Also (missing but implied) I did have to verify the account via email before anything started working. However, when using a new install with an existing account, I am able to reproduce.

Tabs synchronizing thinks it has worked. Tap record uploaded: { "id" : "237bMkHgJKpz", "clientName" : "Fennec (jhugman) on Rhinestone 7+", "tabs" : [ { "icon" : null, "title" : "This 'tree' has the environmental benefits of a forest - CNN", "lastUsed" : "1504873816.12", "urlHistory" : [ "http:\/\/edition.cnn.com\/style\/article\/citytree-urban-pollution\/index.html" ] }, { "icon" : null, "title" : "Most Forbidden Places in the World - Page 20 of 39 - the Brofessional", "lastUsed" : "1504877641.69", "urlHistory" : [ "http:\/\/www.thebrofessional.net\/forbidden-places-world\/20\/?v=p&src=taboola&utm_source=taboola&utm_medium=CRAIG_TheBrofessional.net-Desktop-UK-NoGo-C2&utm_term=slashdot&utm_campaign=Even+The+US+President+Can%27t+Visit+These+39+Forbidden+Places", "http:\/\/www.thebrofessional.net\/forbidden-places-world\/20\/?v=p&src=taboola&utm_source=taboola&utm_medium=CRAIG_TheBrofessional.net-Desktop-UK-NoGo-C2&utm_term=slashdot&utm_campaign=Even+The+US+President+Can%27t+Visit+These+39+Forbidden+Places" ] } ] } Client as seen by desktop: commands: Array[0] protocols: Array[1] 0: "1.5" name: "Fennec (jhugman) on Rhinestone 7+" appPackage: "org.mozilla.ios.Fennec" id: "237bMkHgJKpz" os: "iOS" application: "Fennec (jhugman)" fxaDeviceId: "966628c0526e8c9dc61537a2cc937e89" version: "8.0" formfactor: "phone" type: "mobile" device: "iPhone" Vijay, could I get some of your eyes on this please?

I think I may have the same problem with tab push notifications. I installed the last 9.0 beta (clean install) and then logged in to FxA. But I am unable to receive notifications. Would be good to get a confirmation on this from a second person and find out if this is related.

Can confirm comment 5. This may be related to Bug 1382561.

Not sure about comment 5. I cleanly installed 8.3 and 9.0 beta and they both work as expected against my existing account and also against a new account. I was able to see tabs from both sides and push notifications work great. Temporary glitch in the matrix? Let's re-test this.

I'm seeing some off behaviour here: 2017-09-11 10:06:56.410 [Debug] [Profile.swift:1091] syncWith(synchronizers:account:statsSession:why:) > Syncing clients… 2017-09-11 10:06:56.411 [Debug] [Profile.swift:942] syncClientsWithDelegate(_:prefs:ready:why:) > Syncing clients to storage. 2017-09-11 10:06:56.411 [Info] [Synchronizer.swift:194] init(scratchpad:delegate:basePrefs:why:collection:) > Synchronizer configured with prefs 'profile.sync.synchronizer.clients...' 2017-09-11 10:06:56.411 [Debug] [ClientsSynchronizer.swift:389] synchronizeLocalClients(_:withServer:info:) > Synchronizing clients. 2017-09-11 10:06:56.411 [Debug] [StorageClient.swift:787] getSince(_:sort:limit:offset:) > Issuing GET with newer = 0, offset = nil, sort = nil. 2017-09-11 10:06:56.797 [Debug] [StorageClient.swift:381] failFromResponse > Status code: 200. 2017-09-11 10:06:56.800 [Debug] [ClientsSynchronizer.swift:330] applyStorageResponse(_:toLocalClients:withServer:) > Applying clients response. 2017-09-11 10:06:56.800 [Debug] [ClientsSynchronizer.swift:337] applyStorageResponse(_:toLocalClients:withServer:) > Got 10 client records. 2017-09-11 10:06:56.800 [Debug] [ClientsSynchronizer.swift:351] applyStorageResponse(_:toLocalClients:withServer:) > Skipping our own unmodified record. 2017-09-11 10:06:56.803 [Debug] [ClientsSynchronizer.swift:222] processCommandsFromRecord(_:withServer:) > Processing commands from downloaded record. 2017-09-11 10:06:56.804 [Debug] [ClientsSynchronizer.swift:306] maybeUploadOurRecord(_:ifUnmodifiedSince:toServer:) > Should we upload our client record? Caller = false, expired = false. 2017-09-11 10:06:56.804 [Debug] [SQLiteRemoteClientsAndTabs.swift:420] getCommands() > Found 0 client sync commands in the DB. 2017-09-11 10:06:56.804 [Debug] [ClientsSynchronizer.swift:378] applyStorageResponse(_:toLocalClients:withServer:) > Running 0 commands. 2017-09-11 10:06:56.804 [Debug] [Profile.swift:951] syncClientsWithDelegate(_:prefs:ready:why:) > Updating FxA devices list. 2017-09-11 10:06:57.250 [Debug] [Profile.swift:1091] syncWith(synchronizers:account:statsSession:why:) > Syncing tabs… 2017-09-11 10:06:57.250 [Info] [Synchronizer.swift:194] init(scratchpad:delegate:basePrefs:why:collection:) > Synchronizer configured with prefs 'profile.sync.synchronizer.tabs...' 2017-09-11 10:06:57.251 [Debug] [SQLiteRemoteClientsAndTabs.swift:266] getTabsForClientWithGUID > Looking for tabs for client with guid: nil 2017-09-11 10:06:57.251 [Debug] [Profile.swift:1091] syncWith(synchronizers:account:statsSession:why:) > Syncing logins… 2017-09-11 10:06:57.251 [Debug] [Profile.swift:971] syncLoginsWithDelegate(_:prefs:ready:why:) > Syncing logins to storage. 2017-09-11 10:06:57.251 [Info] [Synchronizer.swift:194] init(scratchpad:delegate:basePrefs:why:collection:) > Synchronizer configured with prefs 'profile.sync.synchronizer.passwords...' 2017-09-11 10:06:57.251 [Debug] [SQLiteRemoteClientsAndTabs.swift:269] getTabsForClientWithGUID > Found 3 tabs for client with guid: nil 2017-09-11 10:06:57.251 [Debug] [LoginsSynchronizer.swift:169] synchronizeLocalLogins(_:withServer:info:) > Synchronizing passwords. Last fetched: 1504193011320. 2017-09-11 10:06:57.251 [Debug] [StorageClient.swift:787] getSince(_:sort:limit:offset:) > Issuing GET with newer = 1504193011320, offset = nil, sort = nil. 2017-09-11 10:06:57.251 [Debug] [TabsSynchronizer.swift:68] uploadOurTabs(_:toServer:) > Uploading our tabs: 3. 2017-09-11 10:06:57.347 [Debug] [StorageClient.swift:381] failFromResponse > Status code: 200. 2017-09-11 10:06:57.348 [Debug] [LoginsSynchronizer.swift:174] synchronizeLocalLogins(_:withServer:info:) > Applying incoming password records from response timestamped 1505138881660, last modified 1504193011320. 2017-09-11 10:06:57.348 [Debug] [LoginsSynchronizer.swift:175] synchronizeLocalLogins(_:withServer:info:) > Records header hint: 0 First, it looks like tabs and logins are synced at the same time? Then there is: - Looking for tabs for client with guid: nil - Found 3 tabs for client with guid: nil But also: 2017-09-11 10:06:57.251 [Debug] [TabsSynchronizer.swift:68] uploadOurTabs(_:toServer:) > Uploading our tabs: 3. 2017-09-11 10:06:57.347 [Debug] [StorageClient.swift:381] failFromResponse > Status code: 200.

Asking rnewman to take a peek too to this.

Catalin confirmed that he got my tabs. But also that he was able to reproduce this issue again.

Full log of my testing session

Still reproducing this issue with a different account but only on that specific device with latest master ffdce75bae212.

Chasing down the nil guid in the log. It seems this is explicity coded for, and used: https://github.com/mozilla-mobile/firefox-ios/blob/15407ccab90713793e7a3c83d4a4950922699285/Sync/Synchronizers/TabsSynchronizer.swift#L58 :rnewman Does this look right?

(In reply to James Hugman [:jhugman] [@jhugman] from comment #13) > :rnewman Does this look right? SQL `NULL` (and Swift `nil` in the interface) is used for our own client, because its GUID can change over time. That code is correct. (In reply to Stefan Arentz [:st3fan] from comment #8) > First, it looks like tabs and logins are synced at the same time? This looks totally sequential to me. > Then there is: > > - Looking for tabs for client with guid: nil > - Found 3 tabs for client with guid: nil This is when we upload our own tabs. It seems to me that this is due to desktop excluding records without a corresponding FxA device ID; in order for desktop to see tabs for a device (if I understand the current state correctly), it must: - Have registered with FxA and got a device ID - Have uploaded its tabs under its client GUID - Have uploaded its client record under that GUID, including its FxA device ID

I thought that this was a problem with not having the fxaDeviceId available in time for the client record to be uploaded. This seems to be happening when I've stepped through with a debugger. However, cutting and pasting from about:sync, I'm not seeing an tabs with the given ids. Clients: commands: Array[0] application: "Fennec (jhugman)" device: "iPhone" name: "Fennec (jhugman) on jhugman-10147" os: "iOS" appPackage: "org.mozilla.ios.Fennec" fxaDeviceId: "20b823c593ed6bf6f043e5050204674e" protocols: Array[1] id: "1yUr_XF2ESo5" version: "8.0" type: "mobile" formfactor: "phone" Tabs: clientName: "Fennec (jhugman) on jhugman-10147" tabs: Array[0] id: "1yUr_XF2ESo5" From Comment 4, I can see the tabs leaving the device, with a client GUID attached. AFAIU comment 14, the tabs don't need an fxaDeviceId, only a client GUID, so as shown by about:sync, this seems to have happened. Attaching log from the simulator that is currently exhibiting this bug.

This simulator log exhibits the bug. Fresh install, logged into an existing account. Needed to confirm the login via email.

The device that I added to this account (Fennec (sarentz) on Risa) did not have this problem. Maybe we can see a difference between my and James' device?

Sync logs from corresponding desktop.

From the desktop sync logs: 1505159106569 Sync.Doctor INFO Skipping check of tabs - disabled via preferences ?

I was able to reproduce briefly. Pages I opened in order: - The "What new with Firefox" default page did now show up when I hit Sync on iOS and Sync on desktop. - I opened accounts.firefox.com. (hit sync on ios + sync on desktop) It did not show up. - Opened some random page in the history AND changed sync engine preferences to not Sync passwords (because I'm paranoid to sync passwords with test accounts). The random page as well as the 2 others showed up on Desktop.

Since the first comment was deleted, here is that comment without the PII: >Build: 9.0(5607) >Device: iPhone 7 >iOS: 10.3.3 >Steps to reproduce: >1. Create a new FxA >2. Log in to Dektop and iOS >3. Open a few tabs and load a few pages on iOS >4. Sync on both desktop and iOS >5. On desktop, go to Sync Tabs list >Actual results: >- The Sync Tabs list is empty on desktop. I am seeing the device in the list but no open tabs. >Note >- Tested with Clean profile on desktop >- Send tabs from desktop to iOS work and vice-versa >- On iOS, I am seeing the opened tabs from desktop >- Tested on several devices and found that the same account is showing the synced tabs on some devices and on two (iPhone 7 and iPad Air 2) does not work

Late to the game, but I was also not able to reproduce https://bugzilla.mozilla.org/show_bug.cgi?id=1395547#c0 or https://bugzilla.mozilla.org/show_bug.cgi?id=1395547#c5. I tested this with FxiOS 9 (TestFlight latest) and production FxA environment. This was with a new account, an existing account and having to confirm login. In each scenario, I was able to see tab list, receive and send push notifications to a desktop client. Sometimes there was a delay in receiving the notification, maybe a minute, but nothing that seemed out of the ordinary.

In slack, :st3fan hypothesizes that this may be caused by non-ascii characters in the iOS device name.

I've been able to reproduce this problem without emoji involvement. (see Simulator logs and about:sync logs).

(In reply to James Hugman [:jhugman] [@jhugman] from comment #15) > Tabs: > clientName: "Fennec (jhugman) on jhugman-10147" > tabs: Array[0] > id: "1yUr_XF2ESo5" I hope I'm not stating the obvious, but the above is the root of the problem - the server simply has no tabs from the client. > From Comment 4, I can see the tabs leaving the device, with a client GUID > attached. > AFAIU comment 14, the tabs don't need an fxaDeviceId, only a client GUID, so > as shown by about:sync, this seems to have happened. > > Attaching log from the simulator that is currently exhibiting this bug. I'm not really sure how to read those logs, but this sticks out: > 2017-09-11 20:44:48.787 [Debug] [SQLiteRemoteClientsAndTabs.swift:340] getClientsAndTabs() > Found 27 raw tabs in the DB. I assume that's saying there are 27 tabs in the local store. ... > 2017-09-11 20:44:48.811 [Debug] [Telemetry.swift:54] send(ping:docType:) > Ping payload: {"events":[],"why":"schedule","uid":"4654f1c09505b1cde62f90b96011d053","deviceID":"55d82162c54e3210fb5cfd665d0305e2707a073492611bd3c5c4359f4f1d504c","version":1,"syncs":[{"didLogin":false,"why":"user","devices":[{"version":"55.0.3","id":"6aa48ff0f4fa4fe8fd6c6137e06f7f986c253ba03f6ab2bb6812430be72bdfde","os":"Darwin"}],"engines":[{"took":625,"name":"clients","incoming":{"newFailed":0,"reconciled":0,"failed":0,"applied":9,"succeeded":9}},{"name":"tabs","took":17081}],"when":1505159070393,"took":18392}]} That seems to imply that the tab sync saw no incoming records nor sent any records (but apparently took 17 seconds to do nothing?) > 2017-09-11 20:44:48.812 [Debug] [SQLiteRemoteClientsAndTabs.swift:340] getClientsAndTabs() > Found 27 raw tabs in the DB. But still 27 in the local store. I can't see any other evidence of tabs being uploaded. Is it possible that for some reason the tab sync thinks it has nothing to do? (eg, maybe because the last-modified on the server is somehow later than the current time on the device, or something else as equally obscure?)

While on the same simulator/desktop/session I didn't collect tabs upload, I did see evidence of a tabs record being uploaded – this is Comment 4. I'll get a full set of a) client log b) desktop log c) tabs record JSON exhibiting the problem.

Working on a theory: FxALoginHelper tries to verify the account. After the first time it account.advance(), it stores the fxaDeviceId in the scratchpad for sync to be ready to upload our client record. At the same time, there is a scheduled sync happening, which needs the fxaDeviceId to upload a client record. If a scheduled sync[2] or onAdded sync[3] happens before the fxaDeviceId has been stored in the scratchpad (currently in [1]) we would get a client record uploaded with the no fxaDeviceId. Pretty much all syncEverything() calls seem to be guarded by profile.hasSyncableAccount(). I don't quite understand the implementation of hasSyncableAccount() (stateCache.value especially) well enough to know if I'm on the right track. Perhaps :rnewman might have a perspective on this. [1]: https://github.com/mozilla-mobile/firefox-ios/blob/master/Client/Helpers/FxALoginHelper.swift#L294 [2]: https://github.com/mozilla-mobile/firefox-ios/blob/master/Providers/Profile.swift#L1173 [3]: https://github.com/mozilla-mobile/firefox-ios/blob/master/Providers/Profile.swift#L849

Theory was that the fxaDeviceId was not being set before the first syncEverything. I found that the Refresh button selector was being called before the first advance was being called. Fixing this incidentally fixes Bug 1382561. However, this doesn't fix this problem. Next, making the fxaDeviceId set properly in the SyncStateMachine. Also: when the fxaDeviceId changes, reset the client collection, to upload our client record again. This is definitely paying down technical debt, but doesn't fix the problem.

> we would get a client record uploaded with the no fxaDeviceId Are there circumstances where we might *want* to upload a client record without an fxaDeviceId, or should we error out in this case? ISTM that refusing to upload such a record would either fix this bug, or eliminate that as a cause of this bug.

> Are there circumstances where we might *want* to upload a client record without an fxaDeviceId, or should we error out in this case? My feeling is that there are no circumstances when not having an fxaDeviceId is beneficial. Defer to :rnewman to be authoritative on this.

This is the work in progress PR against v9.x.

With 5 tabs open: 2017-09-19 14:24:37.093 [Debug] [SQLiteRemoteClientsAndTabs.swift:266] getTabsForClientWithGUID > Looking for tabs for client with guid: nil 2017-09-19 14:24:41.668 [Debug] [SQLiteRemoteClientsAndTabs.swift:269] getTabsForClientWithGUID > Found 0 tabs for client with guid: nil 2017-09-19 14:25:00.538 [Debug] [TabsSynchronizer.swift:68] uploadOurTabs(_:toServer:) > Uploading our tabs: 0. I'm still suspicious of getTabsForClientWithGUID(nil).

Looking at the database, I see no tabs in the tabs table with the client_guid IS NULL or with the client_guid as the client id the device thinks it is. The tabs table doesn't even have the tabs that the device has open. Then, syncing again, 30 minutes later: 2017-09-19 14:55:54.925 [Debug] [SQLiteRemoteClientsAndTabs.swift:269] getTabsForClientWithGUID > Found 5 tabs for client with guid: nil 2017-09-19 14:56:26.731 [Debug] [TabsSynchronizer.swift:68] uploadOurTabs(_:toServer:) > Uploading our tabs: 5. Need infoing :justindarc. How are tabs not in the database?

Discussed on Slack, but re-iterating here for preservation. I would start off by setting a breakpoint here: https://github.com/mozilla-mobile/firefox-ios/blob/master/Storage/SQL/SQLiteRemoteClientsAndTabs.swift#L112-L117

(In reply to James Hugman [:jhugman] [@jhugman] from comment #32) > My feeling is that there are no circumstances when not having an fxaDeviceId > is beneficial. > > Defer to :rnewman to be authoritative on this. Two perspectives: - I'm not sure if self-hosted users will have device IDs. If we know they will -- that every FxA registration under the sun allocates a device ID -- then ignore this. - From a Sync-centric perspective, it's better for a client that exists and is writing to have a client record than not, especially if a missing field will later be filled in. If we know that every FxA registration pass will yield a device ID, then let's start making those fields non-optional.

(In reply to James Hugman [:jhugman] [@jhugman] from comment #35) > Looking at the database, I see no tabs in the tabs table with the > client_guid IS NULL or with the client_guid as the client id the device > thinks it is. N.B., we should never see our own client_guid in that table. > The tabs table doesn't even have the tabs that the device has open. Which means they weren't flushed to the DB, or they were deleted after they were flushed. Justin's pointer is the right starting point. N.B., we flush delayed: func tabManagerWillStoreTabs(_ tabs: [Tab]) { // It is possible that not all tabs have loaded yet, so we filter out tabs with a nil URL. let storedTabs: [RemoteTab] = tabs.flatMap( Tab.toTab ) // Don't insert into the DB immediately. We tend to contend with more important // work like querying for top sites. let queue = DispatchQueue.global(qos: DispatchQoS.background.qosClass) queue.asyncAfter(deadline: DispatchTime.now() + Double(Int64(ProfileRemoteTabsSyncDelay * Double(NSEC_PER_MSEC))) / Double(NSEC_PER_SEC)) { self.profile?.storeTabs(storedTabs) } } ProfileRemoteTabsSyncDelay = 0.1. It's possible that's too short -- we flush before we've finished restoring tabs. Or it's possible there's an arithmetic error in that code, where we convert between seconds, nanoseconds, milliseconds, integers, and doubles.

Merged into master.

Uplifted to v9.x as 741b4a63a.

Verifying as fix on 9.1(6241). Tested with new accounts and with accounts that previous failed to display synced tabs from iOS to desktop and everything works as expected.