1228633 - No internet connection causes FxA to transition to Separated

Status: RESOLVED FIXED

(Firefox for iOS :: Firefox Accounts, defect)

Description

[Richard Newman [:rnewman]]

… which means you need to re-enter your password. Not good.

---
Unknown error: <FxAClientError.Local Error Domain=NSURLErrorDomain Code=-1009 "The Internet connection appears to be offline.">.  Transitioning to Separated.
---

---
2015-11-25 11:29:41.167 [Debug] [Profile.swift:817] syncOnTimer() > Running timed logins sync.
2015-11-25 11:29:41.217 [Info] > XCGLogger writing to log to: file:///Users/rnewman/Library/Developer/CoreSimulator/Devices/522A062C-9D9F-4011-BC6C-972FA475A849/data/Containers/Data/Application/FBAEBC48-46BC-477E-8CA7-CE50CAB358F4/Library/Caches/Logs/keychain.log
2015-11-25 11:29:41.217 [Info] [KeychainCache.swift:34] fromBranch(_:withLabel:withDefault:factory:) > Read account.state from Keychain with label account.state.LR44z6-9zw2_.
2015-11-25 11:29:41.219 [Info] [KeychainCache.swift:52] checkpoint() > Storing account.state in Keychain with label account.state.LR44z6-9zw2_.
2015-11-25 11:29:41.368 [Info] [KeychainCache.swift:34] fromBranch(_:withLabel:withDefault:factory:) > Read account.syncAuthState from Keychain with label account.syncAuthState.LR44z6-9zw2_.
2015-11-25 11:29:41.368 [Info] [Profile.swift:755] withSyncInputs(_:function:) > Syncing logins.
2015-11-25 11:29:41.375 [Debug] [SyncAuthState.swift:113] token(_:canBeExpired:) > Advancing Account state.
2015-11-25 11:29:41.378 [Info] [FxALoginStateMachine.swift:57] advanceOneState(_:now:) > Advancing from state: married
2015-11-25 11:29:41.378 [Debug] [FxALoginStateMachine.swift:61] advanceOneState(_:now:) > Checking key pair freshness.
2015-11-25 11:29:41.378 [Debug] [FxALoginStateMachine.swift:66] advanceOneState(_:now:) > Checking certificate freshness.
2015-11-25 11:29:41.379 [Info] [FxALoginStateMachine.swift:68] advanceOneState(_:now:) > Certificate has expired; transitioning to CohabitingAfterKeyPair.
2015-11-25 11:29:41.379 [Info] [FxALoginStateMachine.swift:57] advanceOneState(_:now:) > Advancing from state: cohabitingAfterKeyPair
2015-11-25 11:29:41.813 [Debug] [FxALoginStateMachine.swift:92] advanceOneState(_:now:) > Signing public key.
2015-11-25 11:29:41.826 [Debug] [FirefoxAccount.swift:182] advance() > no advance() in progress; setting and returning new shared deferred.
2015-11-25 11:29:42.121 [Error] [FxALoginStateMachine.swift:122] advanceOneState(_:now:) > Unknown error: <FxAClientError.Local Error Domain=NSURLErrorDomain Code=-1009 "The Internet connection appears to be offline.">.  Transitioning to Separated.
2015-11-25 11:29:42.122 [Info] [FxALoginStateMachine.swift:57] advanceOneState(_:now:) > Advancing from state: separated
2015-11-25 11:29:42.123 [Warning] [FxALoginStateMachine.swift:173] advanceOneState(_:now:) > User interaction required; not transitioning.
2015-11-25 11:29:42.123 [Info] [KeychainCache.swift:52] checkpoint() > Storing account.state in Keychain with label account.state.LR44z6-9zw2_.
2015-11-25 11:29:42.133 [Debug] [FirefoxAccount.swift:191] advance() > advance() completed and shared deferred is existing deferred; clearing shared deferred.
2015-11-25 11:29:42.133 [Debug] [Profile.swift:828] syncOnTimer() > Timed logins sync failed. Reason: Not married..
2015-11-25 11:29:42.133 [Debug] [Profile.swift:831] syncOnTimer() > Running timed history sync.
2015-11-25 11:29:42.133 [Info] [Profile.swift:755] withSyncInputs(_:function:) > Syncing history.
2015-11-25 11:29:42.198 [Debug] [SyncAuthState.swift:113] token(_:canBeExpired:) > Advancing Account state.
2015-11-25 11:29:42.198 [Info] [FxALoginStateMachine.swift:57] advanceOneState(_:now:) > Advancing from state: separated
2015-11-25 11:29:42.198 [Warning] [FxALoginStateMachine.swift:173] advanceOneState(_:now:) > User interaction required; not transitioning.
2015-11-25 11:29:42.198 [Debug] [FirefoxAccount.swift:182] advance() > no advance() in progress; setting and returning new shared deferred.
2015-11-25 11:29:42.199 [Info] [KeychainCache.swift:52] checkpoint() > Storing account.state in Keychain with label account.state.LR44z6-9zw2_.
2015-11-25 11:29:42.209 [Debug] [FirefoxAccount.swift:191] advance() > advance() completed and shared deferred is existing deferred; clearing shared deferred.
2015-11-25 11:29:42.209 [Debug] [Profile.swift:837] syncOnTimer() > Timed history sync failed. Reason: Not married..
2015-11-25 11:44:40.743 [Debug] [Profile.swift:817] syncOnTimer() > Running timed logins sync.
2015-11-25 11:44:40.745 [Info] [Profile.swift:755] withSyncInputs(_:function:) > Syncing logins.
2015-11-25 11:44:40.745 [Debug] [SyncAuthState.swift:113] token(_:canBeExpired:) > Advancing Account state.
2015-11-25 11:44:40.745 [Info] [FxALoginStateMachine.swift:57] advanceOneState(_:now:) > Advancing from state: separated
2015-11-25 11:44:40.745 [Warning] [FxALoginStateMachine.swift:173] advanceOneState(_:now:) > User interaction required; not transitioning.
2015-11-25 11:44:40.746 [Debug] [FirefoxAccount.swift:182] advance() > no advance() in progress; setting and returning new shared deferred.
2015-11-25 11:44:40.746 [Info] [KeychainCache.swift:52] checkpoint() > Storing account.state in Keychain with label account.state.LR44z6-9zw2_.
2015-11-25 11:44:40.754 [Debug] [FirefoxAccount.swift:191] advance() > advance() completed and shared deferred is existing deferred; clearing shared deferred.
2015-11-25 11:44:40.754 [Debug] [Profile.swift:828] syncOnTimer() > Timed logins sync failed. Reason: Not married..
2015-11-25 11:44:40.755 [Debug] [Profile.swift:831] syncOnTimer() > Running timed history sync.
2015-11-25 11:44:40.755 [Info] [Profile.swift:755] withSyncInputs(_:function:) > Syncing history.
2015-11-25 11:44:40.755 [Debug] [SyncAuthState.swift:113] token(_:canBeExpired:) > Advancing Account state.
2015-11-25 11:44:40.756 [Info] [FxALoginStateMachine.swift:57] advanceOneState(_:now:) > Advancing from state: separated
2015-11-25 11:44:40.756 [Warning] [FxALoginStateMachine.swift:173] advanceOneState(_:now:) > User interaction required; not transitioning.
2015-11-25 11:44:40.756 [Debug] [FirefoxAccount.swift:182] advance() > no advance() in progress; setting and returning new shared deferred.
2015-11-25 11:44:40.756 [Info] [KeychainCache.swift:52] checkpoint() > Storing account.state in Keychain with label account.state.LR44z6-9zw2_.
2015-11-25 11:44:40.762 [Debug] [FirefoxAccount.swift:191] advance() > advance() completed and shared deferred is existing deferred; clearing shared deferred.
2015-11-25 11:44:40.762 [Debug] [Profile.swift:837] syncOnTimer() > Timed history sync failed. Reason: Not married..
2015-11-25 11:44:41.273 [Debug] [SwiftData.swift:147] transaction(synchronous:transactionClosure:) > Op in transaction failed. Rolling back.

Comment 1

[Nick Alexander :nalexander [he/him]]

(In reply to Richard Newman [:rnewman] from comment #0)
> … which means you need to re-enter your password. Not good.

I thought we counted this case as a transient failure.  This is critical.

Comment 2

[Richard Newman [:rnewman]]

I just hit this on my personal profile on a real device, so this definitely happens in the wild. It's not a recoverable state if you don't remember your password.

(Sometimes my wifi is flaky in the morning and I have wifi off and on, but I triggered a sync before I figured it out.)

Comment 3

[Stephan Leroux [:sleroux]]

We will take this for 1.3 but the code freeze is on Thursday so I've tracked it for 1.4 in case.

Comment 4

[Richard Newman [:rnewman]]

Nick, I know you're in Orlando, but do you have an update on this?

And while I'm writing: we should look at the other error codes we might get here and make sure we fix all of the transient cases, not just this one.

Comment 5

[Nick Alexander :nalexander [he/him]]

(In reply to Richard Newman [:rnewman] from comment #4)
> Nick, I know you're in Orlando, but do you have an update on this?

No update, but it's in my queue.

> And while I'm writing: we should look at the other error codes we might get
> here and make sure we fix all of the transient cases, not just this one.

Roger that.  I'm a little concerned that the `Deferred<State>` choice we made is no longer the right choice around... actually, I'm just going to look at this now.

Comment 6

[Nick Alexander :nalexander [he/him]]

Attachment: Link to Github pull-request: https://github.com/mozilla/firefox-ios/pull/1344

You'll be pleased to know that the two tests fail if you revert the two relevant hunks \o/

Comment 7

[Richard Newman [:rnewman]]

Research during reviewing:

https://developer.apple.com/library/mac/#documentation/Networking/Reference/CFNetworkErrors/Reference/reference.html

In particular:

  kCFURLErrorUnknown   = -998,
  kCFURLErrorCancelled = -999,
  kCFURLErrorBadURL    = -1000,
  kCFURLErrorTimedOut  = -1001,
  kCFURLErrorUnsupportedURL = -1002,
  kCFURLErrorCannotFindHost = -1003,
  kCFURLErrorCannotConnectToHost    = -1004,
  kCFURLErrorNetworkConnectionLost  = -1005,
  kCFURLErrorDNSLookupFailed        = -1006,
  kCFURLErrorHTTPTooManyRedirects   = -1007,
  kCFURLErrorResourceUnavailable    = -1008,
  kCFURLErrorNotConnectedToInternet = -1009,
  kCFURLErrorRedirectToNonExistentLocation = -1010,
  kCFURLErrorBadServerResponse             = -1011,
  kCFURLErrorUserCancelledAuthentication   = -1012,
  kCFURLErrorUserAuthenticationRequired    = -1013,
  kCFURLErrorZeroByteResource        = -1014,
  kCFURLErrorCannotDecodeRawData     = -1015,
  kCFURLErrorCannotDecodeContentData = -1016,
  kCFURLErrorCannotParseResponse     = -1017,
  kCFURLErrorInternationalRoamingOff = -1018,
  kCFURLErrorCallIsActive               = -1019,
  kCFURLErrorDataNotAllowed             = -1020,
  kCFURLErrorRequestBodyStreamExhausted = -1021,
  kCFURLErrorFileDoesNotExist           = -1100,
  kCFURLErrorFileIsDirectory            = -1101,
  kCFURLErrorNoPermissionsToReadFile    = -1102,
  kCFURLErrorDataLengthExceedsMaximum   = -1103,


There are some really fascinating error codes in there; surprised nobody has hit this while roaming yet.

Comment 8

[Richard Newman [:rnewman]]

Comment on attachment 8696760 [details] [review]
Link to Github pull-request: https://github.com/mozilla/firefox-ios/pull/1344

Two comments on the PR.

Comment 9

[Richard Newman [:rnewman]]

Reminder: when this lands on master, target-milestone=2.0. When uplifted to `v1.x`, clear [needsuplift] and set target-milestone=1.4.

Comment 10

[Nick Alexander :nalexander [he/him]]

(In reply to Richard Newman [:rnewman] from comment #9)
> Reminder: when this lands on master, target-milestone=2.0. When uplifted to
> `v1.x`, clear [needsuplift] and set target-milestone=1.4.

rnewman: I responded on the PR.  Can you make any test changes you want, and then land?  Otherwise, I should get to this by the end of the week.  Thanks!

Comment 11

[Richard Newman [:rnewman]]

v1.x: 42e35c7
master: a9fe225