1599136455580 FirefoxAccounts DEBUG removing account data
1599136455581 FirefoxAccounts TRACE starting write of json user data: null
1599136455581 FirefoxAccounts TRACE not checking freshness of profile as it remains recent
1599136455582 FirefoxAccounts INFO An accountState promise was resolved, but was actually rejected due to a different user being signed in. Originally resolved with: {"email":"nico@nisp.ch","uid":"702dff69c5d84dc08052a9e5c584ad17","verified":true,"avatar":"https://firefoxusercontent.com/00000000000000000000000000000000","avatarDefault":true}
1599136455584 FirefoxAccounts INFO An accountState promise was rejected, but we are ignoring that reason and rejecting it due to a different user being signed in. Originally rejected with: Error: Another user has signed in(resource://gre/modules/FxAccounts.jsm:210:29) JS Stack trace: getUserAccountData@FxAccounts.jsm:210:29
getSignedInUser/<@FxAccounts.jsm:637:39
withCurrentAccountState@FxAccounts.jsm:851:22
_withCurrentAccountState@FxAccounts.jsm:437:27
getSignedInUser@FxAccounts.jsm:636:17
_getFxaSignedInUser@TelemetryEnvironment.jsm:1750:23
_updateServicesInfo@TelemetryEnvironment.jsm:1765:31
observe@TelemetryEnvironment.jsm:1415:14
notifyStateUpdated@UIState.jsm:140:18
refreshState@UIState.jsm:127:10
1599136455699 FirefoxAccounts TRACE finished write of json user data - took: 118
1599136455702 FirefoxAccounts TRACE storage set finished clearing account data
1599136455702 FirefoxAccounts DEBUG account data reset
1599136455702 FirefoxAccounts TRACE StorageManager finalizing
1599136455702 FirefoxAccounts TRACE StorageManager finalized
1599136455702 FirefoxAccounts TRACE initializing new storage manager
1599136455702 FirefoxAccounts TRACE starting fetch of json user data
1599136455709 FirefoxAccounts TRACE finished fetch of json user data - took: 7
1599136455709 FirefoxAccounts TRACE initializing of new storage manager done
1599136455709 FirefoxAccounts DEBUG Notifying observers of fxaccounts:onlogout
1599136455710 Sync.BrowserIDManager DEBUG observed fxaccounts:onlogout
1599136455710 Sync.BrowserIDManager INFO Sync is not configured, so ignoring the notification
1599136455710 FirefoxAccounts TRACE observed topic=fxaccounts:onlogout, data=null, subject=null
1599136455710 FirefoxAccounts TRACE FxAccountsPushService unsubscribe
1599136455712 FirefoxAccounts DEBUG Unsubscribing from FxA push.
1599136455712 FirefoxAccounts TRACE FxAccountsPushService unsubscribe
1599136455717 Sync.LogManager DEBUG Done deleting files.
1599136455880 FirefoxAccounts DEBUG FxAccountsPushService unsubscribed
1599136455880 FirefoxAccounts DEBUG FxAccountsPushService unsubscribed
1599136455880 FirefoxAccounts DEBUG Destroying session and device.
1599136455882 Services.Common.RESTRequest DEBUG POST request to https://api.accounts.firefox.com/v1/session/destroy?service=sync
1599136455882 Services.Common.RESTRequest DEBUG POST Length: 2
1599136456164 Services.Common.RESTRequest DEBUG POST https://api.accounts.firefox.com/v1/session/destroy?service=sync 200
1599136456164 Hawk DEBUG (Response) /session/destroy?service=sync: code: 200 - Status text: OK
1599136456164 Hawk DEBUG Clock offset vs https://api.accounts.firefox.com/v1: -164
1599136456164 FirefoxAccounts DEBUG Destroying all OAuth tokens.
1599136456164 Services.Common.RESTRequest DEBUG POST request to https://api.accounts.firefox.com/v1/oauth/destroy
1599136456164 Services.Common.RESTRequest DEBUG POST Length: 900
1599136456331 Services.Common.RESTRequest DEBUG POST https://api.accounts.firefox.com/v1/oauth/destroy 200
1599136456331 Hawk DEBUG (Response) /oauth/destroy: code: 200 - Status text: OK
1599136456332 Hawk DEBUG Clock offset vs https://api.accounts.firefox.com/v1: -332
1599136456332 FirefoxAccounts DEBUG Notifying observers of testhelper-fxa-signout-complete
1599136457045 FirefoxAccounts DEBUG FxAccountsWebChannel message received: fxaccounts:fxa_status
1599136457045 FirefoxAccounts DEBUG fxa_status received
1599136457045 FirefoxAccounts DEBUG service: sync
1599136457045 FirefoxAccounts DEBUG is private browsing: false
1599136457131 FirefoxAccounts DEBUG FxAccountsWebChannel message received: fxaccounts:loaded
1599136457131 FirefoxAccounts WARN Unrecognized FxAccountsWebChannel command: fxaccounts:loaded
1599136463028 FirefoxAccounts DEBUG FxAccountsWebChannel message received: fxaccounts:can_link_account
1599136464677 FirefoxAccounts DEBUG FxAccountsWebChannel response: {"command":"fxaccounts:can_link_account","messageId":"15991364630272","data":{"ok":true}}
1599136470506 FirefoxAccounts DEBUG FxAccountsWebChannel message received: fxaccounts:login
1599136470507 FirefoxAccounts DEBUG Webchannel is logging a user in.
1599136470508 FirefoxAccounts DEBUG setSignedInUser - aborting any existing flows
1599136470508 FirefoxAccounts DEBUG removing account data
1599136470508 FirefoxAccounts TRACE starting write of json user data: null
1599136470547 FirefoxAccounts TRACE finished write of json user data - took: 39
1599136470548 FirefoxAccounts TRACE storage set finished clearing account data
1599136470548 FirefoxAccounts DEBUG account data reset
1599136470548 FirefoxAccounts TRACE StorageManager finalizing
1599136470548 FirefoxAccounts TRACE StorageManager finalized
1599136470548 FirefoxAccounts TRACE initializing new storage manager
1599136470549 FirefoxAccounts DEBUG writing plain storage: ["email","sessionToken","uid","verified"]
1599136470549 FirefoxAccounts TRACE starting write of json user data: ["email","sessionToken","uid","verified"]
1599136470554 FirefoxAccounts TRACE finished write of json user data - took: 4
1599136470554 FirefoxAccounts DEBUG writing secure storage: ["keyFetchToken","unwrapBKey"]
1599136470554 FirefoxAccounts TRACE starting write of user data to the login manager
1599136470556 FirefoxAccounts TRACE finished write of user data to the login manager
1599136470556 FirefoxAccounts TRACE initializing of new storage manager done
1599136470556 FirefoxAccounts DEBUG Notifying observers of fxaccounts:onlogin
1599136470556 Sync.BrowserIDManager DEBUG observed fxaccounts:onlogin
1599136470556 Sync.BrowserIDManager INFO Sync is not configured, so ignoring the notification
1599136470556 FirefoxAccounts DEBUG FxAccountsProfileClient: Initialized
1599136470556 FirefoxAccounts TRACE FxAccountsPush registerPushEndpoint
1599136470557 FirefoxAccounts DEBUG FxAccountsProfileClient: Requested profile
1599136470557 FirefoxAccounts DEBUG getOAuthToken enter
1599136470558 FirefoxAccounts INFO fetching updated device list
1599136470581 Services.Common.RESTRequest DEBUG GET request to https://api.accounts.firefox.com/v1/account/devices
1599136470582 Services.Common.RESTRequest DEBUG POST request to https://api.accounts.firefox.com/v1/oauth/token
1599136470582 Services.Common.RESTRequest DEBUG POST Length: 81
1599136470821 Services.Common.RESTRequest DEBUG GET https://api.accounts.firefox.com/v1/account/devices 200
1599136470822 Hawk DEBUG (Response) /account/devices: code: 200 - Status text: OK
1599136470822 Hawk DEBUG Clock offset vs https://api.accounts.firefox.com/v1: -822
1599136470822 FirefoxAccounts INFO Got new device list:
1599136470822 FirefoxAccounts INFO updating the cache
1599136470831 FirefoxAccounts DEBUG FxAccountsPush got subscription
1599136470834 FirefoxAccounts DEBUG _updateAccountData with items: ["device"]
1599136470834 FirefoxAccounts DEBUG writing plain storage: ["email","sessionToken","uid","verified","device"]
1599136470834 FirefoxAccounts TRACE starting write of json user data: ["email","sessionToken","uid","verified","device"]
1599136470835 FirefoxAccounts DEBUG Fetching keys with token true from https://api.accounts.firefox.com/v1
1599136470837 Services.Common.RESTRequest DEBUG GET request to https://api.accounts.firefox.com/v1/account/keys
1599136470838 FirefoxAccounts TRACE finished write of json user data - took: 3
1599136470838 FirefoxAccounts DEBUG writing secure storage: ["keyFetchToken","unwrapBKey"]
1599136470838 FirefoxAccounts TRACE starting write of user data to the login manager
1599136470840 FirefoxAccounts TRACE finished write of user data to the login manager
1599136471019 Services.Common.RESTRequest DEBUG GET https://api.accounts.firefox.com/v1/account/keys 200
1599136471019 Hawk DEBUG (Response) /account/keys: code: 200 - Status text: OK
1599136471019 Hawk DEBUG Clock offset vs https://api.accounts.firefox.com/v1: -1019
1599136471021 FirefoxAccounts DEBUG Keys Obtained:kSync=true, kXCS=true, kExtSync=true, kExtKbHash=true
1599136471021 FirefoxAccounts DEBUG _updateAccountData with items: ["kSync","kXCS","kExtSync","kExtKbHash","keyFetchToken","unwrapBKey"]
1599136471021 FirefoxAccounts DEBUG writing plain storage: ["email","sessionToken","uid","verified","device"]
1599136471021 FirefoxAccounts TRACE starting write of json user data: ["email","sessionToken","uid","verified","device"]
1599136471022 Sync.BulkKeyBundle INFO BulkKeyBundle being created for undefined
1599136471023 FirefoxAccounts INFO registering with available commands: ["https://identity.mozilla.com/cmd/open-uri"]
1599136471023 FirefoxAccounts DEBUG registering new device details
1599136471023 FirefoxAccounts TRACE finished write of json user data - took: 2
1599136471023 FirefoxAccounts DEBUG writing secure storage: ["kSync","kXCS","kExtSync","kExtKbHash"]
1599136471024 FirefoxAccounts TRACE starting write of user data to the login manager
1599136471026 FirefoxAccounts TRACE finished write of user data to the login manager
1599136471028 Services.Common.RESTRequest DEBUG POST request to https://api.accounts.firefox.com/v1/account/device
1599136471029 Services.Common.RESTRequest DEBUG POST Length: 856
1599136471309 Services.Common.RESTRequest DEBUG POST https://api.accounts.firefox.com/v1/account/device 200
1599136471309 Hawk DEBUG (Response) /account/device: code: 200 - Status text: OK
1599136471309 Hawk DEBUG Clock offset vs https://api.accounts.firefox.com/v1: -309
1599136471309 FirefoxAccounts DEBUG _updateAccountData with items: ["device"]
1599136471309 FirefoxAccounts DEBUG writing plain storage: ["email","sessionToken","uid","verified","device"]
1599136471309 FirefoxAccounts TRACE starting write of json user data: ["email","sessionToken","uid","verified","device"]
1599136471310 FirefoxAccounts DEBUG Webchannel is enabling sync
1599136471310 Sync.Service INFO Configuring sync with current FxA user
1599136471313 Sync.BrowserIDManager DEBUG observed weave:connected
1599136471313 Sync.BrowserIDManager INFO Sync has been connected to a logged in user
1599136471314 Sync.BrowserIDManager INFO The user became verified
1599136471314 Sync.Status DEBUG Status.login: error.login.reason.no_username => success.login
1599136471314 Sync.Status DEBUG Status.service: service.client_not_configured => success.status_ok
1599136471314 Sync.BrowserIDManager INFO Doing initial sync actions
1599136471314 Sync.AddonsReconciler INFO Registering as Add-on Manager listener.
1599136471315 Sync.AddonsReconciler DEBUG Adding change listener.
1599136471315 Sync.Engine.History.Tracker INFO Adding Places observer.
1599136471316 Sync.Service DEBUG User-Agent: Firefox/80.0.1 (Intel Mac OS X 10.13) FxSync/1.82.0.20200831163820.desktop
1599136471316 Sync.Service INFO Starting sync at 2020-09-03 14:34:31 in browser session 6W6te0EeS-aR
1599136471316 Sync.Service DEBUG In sync: should login.
1599136471316 Sync.Service INFO User logged in successfully - verifying login.
1599136471318 Sync.BrowserIDManager DEBUG unlockAndVerifyAuthState already has (or can fetch) sync keys
1599136471318 Sync.Status DEBUG Status.login: success.login => success.status_ok
1599136471318 Sync.Status DEBUG Status.service: success.status_ok => error.login.failed
1599136471318 Sync.Service DEBUG Fetching unlocked auth state returned success.status_ok
1599136471319 Sync.BrowserIDManager INFO Getting keys
1599136471320 Sync.BrowserIDManager INFO Getting an assertion from: https://my.domain.org:PORT/token/1.0/sync/1.5
1599136471320 Sync.BrowserIDManager DEBUG Getting a token using OAuth
1599136471320 FirefoxAccounts DEBUG getAccessToken enter
1599136471320 FirefoxAccounts DEBUG getOAuthToken enter
1599136471413 Services.Common.RESTRequest DEBUG POST https://api.accounts.firefox.com/v1/oauth/token 200
1599136471413 Hawk DEBUG (Response) /oauth/token: code: 200 - Status text: OK
1599136471414 Hawk DEBUG Clock offset vs https://api.accounts.firefox.com/v1: -414
1599136471414 FirefoxAccounts DEBUG _updateAccountData with items: ["oauthTokens"]
1599136471414 Services.Common.RESTRequest DEBUG GET request to https://profile.accounts.firefox.com/v1/profile
1599136471416 FirefoxAccounts TRACE finished write of json user data - took: 107
1599136471416 FirefoxAccounts DEBUG writing secure storage: ["kSync","kXCS","kExtSync","kExtKbHash"]
1599136471417 FirefoxAccounts TRACE starting write of user data to the login manager
1599136471419 FirefoxAccounts TRACE finished write of user data to the login manager
1599136471419 FirefoxAccounts DEBUG writing plain storage: ["email","sessionToken","uid","verified","device","oauthTokens"]
1599136471419 FirefoxAccounts TRACE starting write of json user data: ["email","sessionToken","uid","verified","device","oauthTokens"]
1599136471420 Services.Common.RESTRequest DEBUG POST request to https://api.accounts.firefox.com/v1/oauth/token
1599136471420 Services.Common.RESTRequest DEBUG POST Length: 127
1599136471422 FirefoxAccounts TRACE finished write of json user data - took: 3
1599136471422 FirefoxAccounts DEBUG writing secure storage: ["kSync","kXCS","kExtSync","kExtKbHash"]
1599136471422 FirefoxAccounts TRACE starting write of user data to the login manager
1599136471424 FirefoxAccounts TRACE finished write of user data to the login manager
1599136471607 Services.Common.RESTRequest DEBUG POST https://api.accounts.firefox.com/v1/oauth/token 200
1599136471607 Hawk DEBUG (Response) /oauth/token: code: 200 - Status text: OK
1599136471607 Hawk DEBUG Clock offset vs https://api.accounts.firefox.com/v1: -607
1599136471607 FirefoxAccounts DEBUG _updateAccountData with items: ["oauthTokens"]
1599136471607 FirefoxAccounts DEBUG writing plain storage: ["email","sessionToken","uid","verified","device","oauthTokens"]
1599136471607 FirefoxAccounts TRACE starting write of json user data: ["email","sessionToken","uid","verified","device","oauthTokens"]
1599136471608 FirefoxAccounts DEBUG Fetching scopedKeys data for https://identity.mozilla.com/apps/oldsync
1599136471610 FirefoxAccounts TRACE finished write of json user data - took: 3
1599136471610 FirefoxAccounts DEBUG writing secure storage: ["kSync","kXCS","kExtSync","kExtKbHash"]
1599136471610 FirefoxAccounts TRACE starting write of user data to the login manager
1599136471613 FirefoxAccounts TRACE finished write of user data to the login manager
1599136471614 Services.Common.RESTRequest DEBUG POST request to https://api.accounts.firefox.com/v1/account/scoped-key-data
1599136471614 Services.Common.RESTRequest DEBUG POST Length: 84
1599136471874 Services.Common.RESTRequest DEBUG POST https://api.accounts.firefox.com/v1/account/scoped-key-data 200
1599136471874 Hawk DEBUG (Response) /account/scoped-key-data: code: 200 - Status text: OK
1599136471874 Hawk DEBUG Clock offset vs https://api.accounts.firefox.com/v1: -874
1599136471874 FirefoxAccounts DEBUG _updateAccountData with items: ["scopedKeys"]
1599136471874 FirefoxAccounts DEBUG writing plain storage: ["email","sessionToken","uid","verified","device","oauthTokens"]
1599136471874 FirefoxAccounts TRACE starting write of json user data: ["email","sessionToken","uid","verified","device","oauthTokens"]
1599136471875 Services.Common.TokenServerClient DEBUG Beginning OAuth token exchange: https://my.domain.org:PORT/token/1.0/sync/1.5
1599136471875 Services.Common.RESTRequest DEBUG GET request to https://my.domain.org:PORT/token/1.0/sync/1.5
1599136471877 FirefoxAccounts TRACE finished write of json user data - took: 3
1599136471877 FirefoxAccounts DEBUG writing secure storage: ["kSync","kXCS","kExtSync","kExtKbHash","scopedKeys"]
1599136471877 FirefoxAccounts TRACE starting write of user data to the login manager
1599136471881 FirefoxAccounts TRACE finished write of user data to the login manager
1599136471908 Services.Common.RESTRequest DEBUG GET https://profile.accounts.firefox.com/v1/profile 200
1599136471908 FirefoxAccounts DEBUG _updateAccountData with items: ["profileCache"]
1599136471908 FirefoxAccounts DEBUG writing plain storage: ["email","sessionToken","uid","verified","device","oauthTokens","profileCache"]
1599136471908 FirefoxAccounts TRACE starting write of json user data: ["email","sessionToken","uid","verified","device","oauthTokens","profileCache"]
1599136471908 FirefoxAccounts DEBUG notifying profile changed for user c9da759b69e94e1d9c080ad64d8f329a
1599136471909 FirefoxAccounts TRACE not checking freshness of profile as it remains recent
1599136471912 FirefoxAccounts TRACE finished write of json user data - took: 4
1599136471912 FirefoxAccounts DEBUG writing secure storage: ["kSync","kXCS","kExtSync","kExtKbHash","scopedKeys"]
1599136471912 FirefoxAccounts TRACE starting write of user data to the login manager
1599136471916 FirefoxAccounts TRACE finished write of user data to the login manager
1599136472820 Services.Common.RESTRequest DEBUG GET https://my.domain.org:PORT/token/1.0/sync/1.5 401
1599136472820 Services.Common.TokenServerClient DEBUG Got token response: 401
1599136472820 Services.Common.TokenServerClient INFO Server-reported error: {"location":"body","name":"","description":"Unauthorized"}
1599136472821 Services.Common.RESTRequest DEBUG POST request to https://api.accounts.firefox.com/v1/oauth/destroy
1599136472821 Services.Common.RESTRequest DEBUG POST Length: 969
1599136472821 FirefoxAccounts DEBUG _updateAccountData with items: ["oauthTokens"]
1599136472822 FirefoxAccounts DEBUG writing plain storage: ["email","sessionToken","uid","verified","device","oauthTokens","profileCache"]
1599136472822 FirefoxAccounts TRACE starting write of json user data: ["email","sessionToken","uid","verified","device","oauthTokens","profileCache"]
1599136472822 Sync.BrowserIDManager WARN Token server returned 401, refreshing certificate and retrying token fetch
1599136472822 FirefoxAccounts DEBUG _updateAccountData with items: ["cert"]
1599136472822 Sync.BrowserIDManager INFO Getting an assertion from: https://my.domain.org:PORT/token/1.0/sync/1.5
1599136472822 Sync.BrowserIDManager DEBUG Getting a token using OAuth
1599136472822 FirefoxAccounts DEBUG getAccessToken enter
1599136472822 FirefoxAccounts DEBUG getOAuthToken enter
1599136472824 Services.Common.RESTRequest DEBUG POST request to https://api.accounts.firefox.com/v1/oauth/token
1599136472825 Services.Common.RESTRequest DEBUG POST Length: 127
1599136472825 FirefoxAccounts TRACE finished write of json user data - took: 3
1599136472825 FirefoxAccounts DEBUG writing secure storage: ["kSync","kXCS","kExtSync","kExtKbHash","scopedKeys"]
1599136472825 FirefoxAccounts TRACE starting write of user data to the login manager
1599136472829 FirefoxAccounts TRACE finished write of user data to the login manager
1599136472830 FirefoxAccounts DEBUG writing plain storage: ["email","sessionToken","uid","verified","device","oauthTokens","profileCache"]
1599136472830 FirefoxAccounts TRACE starting write of json user data: ["email","sessionToken","uid","verified","device","oauthTokens","profileCache"]
1599136472832 FirefoxAccounts TRACE finished write of json user data - took: 2
1599136472832 FirefoxAccounts DEBUG writing secure storage: ["kSync","kXCS","kExtSync","kExtKbHash","scopedKeys"]
1599136472832 FirefoxAccounts TRACE starting write of user data to the login manager
1599136472835 FirefoxAccounts TRACE finished write of user data to the login manager
1599136473026 Services.Common.RESTRequest DEBUG POST https://api.accounts.firefox.com/v1/oauth/destroy 200
1599136473026 Hawk DEBUG (Response) /oauth/destroy: code: 200 - Status text: OK
1599136473026 Hawk DEBUG Clock offset vs https://api.accounts.firefox.com/v1: -1026
1599136473027 Services.Common.RESTRequest DEBUG POST https://api.accounts.firefox.com/v1/oauth/token 200
1599136473027 Hawk DEBUG (Response) /oauth/token: code: 200 - Status text: OK
1599136473028 Hawk DEBUG Clock offset vs https://api.accounts.firefox.com/v1: -1028
1599136473028 FirefoxAccounts DEBUG _updateAccountData with items: ["oauthTokens"]
1599136473028 FirefoxAccounts DEBUG writing plain storage: ["email","sessionToken","uid","verified","device","oauthTokens","profileCache"]
1599136473028 FirefoxAccounts TRACE starting write of json user data: ["email","sessionToken","uid","verified","device","oauthTokens","profileCache"]
1599136473029 FirefoxAccounts DEBUG Using cached scopedKeys data for https://identity.mozilla.com/apps/oldsync
1599136473029 Services.Common.TokenServerClient DEBUG Beginning OAuth token exchange: https://my.domain.org:PORT/token/1.0/sync/1.5
1599136473029 Services.Common.RESTRequest DEBUG GET request to https://my.domain.org:PORT/token/1.0/sync/1.5
1599136473032 FirefoxAccounts TRACE finished write of json user data - took: 4
1599136473032 FirefoxAccounts DEBUG writing secure storage: ["kSync","kXCS","kExtSync","kExtKbHash","scopedKeys"]
1599136473032 FirefoxAccounts TRACE starting write of user data to the login manager
1599136473035 FirefoxAccounts TRACE finished write of user data to the login manager
1599136473436 Services.Common.RESTRequest DEBUG GET https://my.domain.org:PORT/token/1.0/sync/1.5 401
1599136473436 Services.Common.TokenServerClient DEBUG Got token response: 401
1599136473436 Services.Common.TokenServerClient INFO Server-reported error: {"location":"body","name":"","description":"Unauthorized"}
1599136473437 Services.Common.RESTRequest DEBUG POST request to https://api.accounts.firefox.com/v1/oauth/destroy
1599136473437 Services.Common.RESTRequest DEBUG POST Length: 969
1599136473438 FirefoxAccounts DEBUG _updateAccountData with items: ["oauthTokens"]
1599136473438 FirefoxAccounts DEBUG writing plain storage: ["email","sessionToken","uid","verified","device","oauthTokens","profileCache"]
1599136473438 FirefoxAccounts TRACE starting write of json user data: ["email","sessionToken","uid","verified","device","oauthTokens","profileCache"]
1599136473438 Sync.BrowserIDManager ERROR Authentication error in _fetchTokenForUser: {"details":{"now":"2020-09-03T12:34:33.436Z","message":"Authentication failed.","cause":"invalid-credentials","response_body":"{\"status\": \"invalid-credentials\", \"errors\": [{\"location\": \"body\", \"name\": \"\", \"description\": \"Unauthorized\"}]}","response_headers":{"server":"nginx","date":"Thu, 03 Sep 2020 12:34:33 GMT","content-type":"application/json; charset=UTF-8","content-length":"110","x-weave-timestamp":"1599136473.24","x-timestamp":"1599136473","strict-transport-security":"max-age=15768000; includeSubdomains; preload","x-firefox-spdy":"h2"},"response_status":401,"name":"TokenServerClientServerError"},"source":"tokenserver"}
1599136473438 Sync.Status DEBUG Status.login: success.status_ok => error.login.reason.account
1599136473438 Sync.Status DEBUG Status.service: error.login.failed => error.login.failed
1599136473439 Sync.BrowserIDManager INFO Failed to fetch the cluster URL: {"details":{"now":"2020-09-03T12:34:33.436Z","message":"Authentication failed.","cause":"invalid-credentials","response_body":"{\"status\": \"invalid-credentials\", \"errors\": [{\"location\": \"body\", \"name\": \"\", \"description\": \"Unauthorized\"}]}","response_headers":{"server":"nginx","date":"Thu, 03 Sep 2020 12:34:33 GMT","content-type":"application/json; charset=UTF-8","content-length":"110","x-weave-timestamp":"1599136473.24","x-timestamp":"1599136473","strict-transport-security":"max-age=15768000; includeSubdomains; preload","x-firefox-spdy":"h2"},"response_status":401,"name":"TokenServerClientServerError"},"source":"tokenserver"}
1599136473439 Sync.BrowserIDManager DEBUG Cluster value = null
1599136473439 Sync.Status DEBUG Status.sync: success.sync => error.sync.reason.no_node_found
1599136473439 Sync.Status DEBUG Status.service: error.login.failed => error.sync.failed
1599136473439 FirefoxAccounts TRACE not checking freshness of profile as it remains recent
1599136473439 Sync.SyncScheduler DEBUG Clearing sync triggers and the global score.
1599136473441 Sync.Status INFO Resetting Status.
1599136473441 Sync.Status DEBUG Status.service: error.sync.failed => success.status_ok
1599136473441 FirefoxAccounts TRACE not checking freshness of profile as it remains recent
1599136473442 Sync.BrowserIDManager INFO Getting keys
1599136473442 Sync.BrowserIDManager INFO Getting an assertion from: https://my.domain.org:PORT/token/1.0/sync/1.5
1599136473442 Sync.BrowserIDManager DEBUG Getting a token using OAuth
1599136473442 FirefoxAccounts DEBUG getAccessToken enter
1599136473442 FirefoxAccounts DEBUG getOAuthToken enter
1599136473445 FirefoxAccounts TRACE finished write of json user data - took: 7
1599136473445 FirefoxAccounts DEBUG writing secure storage: ["kSync","kXCS","kExtSync","kExtKbHash","scopedKeys"]
1599136473445 FirefoxAccounts TRACE starting write of user data to the login manager
1599136473448 FirefoxAccounts TRACE finished write of user data to the login manager
1599136473448 Services.Common.RESTRequest DEBUG POST request to https://api.accounts.firefox.com/v1/oauth/token
1599136473449 Services.Common.RESTRequest DEBUG POST Length: 127
1599136473608 Services.Common.RESTRequest DEBUG POST https://api.accounts.firefox.com/v1/oauth/destroy 200
1599136473608 Hawk DEBUG (Response) /oauth/destroy: code: 200 - Status text: OK
1599136473608 Hawk DEBUG Clock offset vs https://api.accounts.firefox.com/v1: -608
1599136473638 Services.Common.RESTRequest DEBUG POST https://api.accounts.firefox.com/v1/oauth/token 200
1599136473638 Hawk DEBUG (Response) /oauth/token: code: 200 - Status text: OK
1599136473638 Hawk DEBUG Clock offset vs https://api.accounts.firefox.com/v1: -638
1599136473639 FirefoxAccounts DEBUG _updateAccountData with items: ["oauthTokens"]
1599136473639 FirefoxAccounts DEBUG writing plain storage: ["email","sessionToken","uid","verified","device","oauthTokens","profileCache"]
1599136473639 FirefoxAccounts TRACE starting write of json user data: ["email","sessionToken","uid","verified","device","oauthTokens","profileCache"]
1599136473639 FirefoxAccounts DEBUG Using cached scopedKeys data for https://identity.mozilla.com/apps/oldsync
1599136473639 Services.Common.TokenServerClient DEBUG Beginning OAuth token exchange: https://my.domain.org:PORT/token/1.0/sync/1.5
1599136473639 Services.Common.RESTRequest DEBUG GET request to https://my.domain.org:PORT/token/1.0/sync/1.5
1599136473641 FirefoxAccounts TRACE finished write of json user data - took: 2
1599136473641 FirefoxAccounts DEBUG writing secure storage: ["kSync","kXCS","kExtSync","kExtKbHash","scopedKeys"]
1599136473641 FirefoxAccounts TRACE starting write of user data to the login manager
1599136473645 FirefoxAccounts TRACE finished write of user data to the login manager
1599136473868 Services.Common.RESTRequest DEBUG GET https://my.domain.org:PORT/token/1.0/sync/1.5 401
1599136473869 Services.Common.TokenServerClient DEBUG Got token response: 401
1599136473869 Services.Common.TokenServerClient INFO Server-reported error: {"location":"body","name":"","description":"Unauthorized"}
1599136473869 Services.Common.RESTRequest DEBUG POST request to https://api.accounts.firefox.com/v1/oauth/destroy
1599136473869 Services.Common.RESTRequest DEBUG POST Length: 969
1599136473870 FirefoxAccounts DEBUG _updateAccountData with items: ["oauthTokens"]
1599136473870 FirefoxAccounts DEBUG writing plain storage: ["email","sessionToken","uid","verified","device","oauthTokens","profileCache"]
1599136473870 FirefoxAccounts TRACE starting write of json user data: ["email","sessionToken","uid","verified","device","oauthTokens","profileCache"]
1599136473871 Sync.BrowserIDManager WARN Token server returned 401, refreshing certificate and retrying token fetch
1599136473871 FirefoxAccounts DEBUG _updateAccountData with items: ["cert"]
1599136473871 Sync.BrowserIDManager INFO Getting an assertion from: https://my.domain.org:PORT/token/1.0/sync/1.5
1599136473871 Sync.BrowserIDManager DEBUG Getting a token using OAuth
1599136473871 FirefoxAccounts DEBUG getAccessToken enter
1599136473871 FirefoxAccounts DEBUG getOAuthToken enter
1599136473873 Services.Common.RESTRequest DEBUG POST request to https://api.accounts.firefox.com/v1/oauth/token
1599136473873 Services.Common.RESTRequest DEBUG POST Length: 127
1599136473874 FirefoxAccounts TRACE finished write of json user data - took: 4
1599136473874 FirefoxAccounts DEBUG writing secure storage: ["kSync","kXCS","kExtSync","kExtKbHash","scopedKeys"]
1599136473874 FirefoxAccounts TRACE starting write of user data to the login manager
1599136473880 FirefoxAccounts TRACE finished write of user data to the login manager
1599136473880 FirefoxAccounts DEBUG writing plain storage: ["email","sessionToken","uid","verified","device","oauthTokens","profileCache"]
1599136473880 FirefoxAccounts TRACE starting write of json user data: ["email","sessionToken","uid","verified","device","oauthTokens","profileCache"]
1599136473889 FirefoxAccounts TRACE finished write of json user data - took: 9
1599136473889 FirefoxAccounts DEBUG writing secure storage: ["kSync","kXCS","kExtSync","kExtKbHash","scopedKeys"]
1599136473889 FirefoxAccounts TRACE starting write of user data to the login manager
1599136473893 FirefoxAccounts TRACE finished write of user data to the login manager
1599136474036 Services.Common.RESTRequest DEBUG POST https://api.accounts.firefox.com/v1/oauth/destroy 200
1599136474036 Hawk DEBUG (Response) /oauth/destroy: code: 200 - Status text: OK
1599136474036 Hawk DEBUG Clock offset vs https://api.accounts.firefox.com/v1: -1036
1599136474052 Services.Common.RESTRequest DEBUG POST https://api.accounts.firefox.com/v1/oauth/token 200
1599136474052 Hawk DEBUG (Response) /oauth/token: code: 200 - Status text: OK
1599136474052 Hawk DEBUG Clock offset vs https://api.accounts.firefox.com/v1: -1052
1599136474053 FirefoxAccounts DEBUG _updateAccountData with items: ["oauthTokens"]
1599136474053 FirefoxAccounts DEBUG writing plain storage: ["email","sessionToken","uid","verified","device","oauthTokens","profileCache"]
1599136474053 FirefoxAccounts TRACE starting write of json user data: ["email","sessionToken","uid","verified","device","oauthTokens","profileCache"]
1599136474053 FirefoxAccounts DEBUG Using cached scopedKeys data for https://identity.mozilla.com/apps/oldsync
1599136474053 Services.Common.TokenServerClient DEBUG Beginning OAuth token exchange: https://my.domain.org:PORT/token/1.0/sync/1.5
1599136474053 Services.Common.RESTRequest DEBUG GET request to https://my.domain.org:PORT/token/1.0/sync/1.5
1599136474056 FirefoxAccounts TRACE finished write of json user data - took: 3
1599136474056 FirefoxAccounts DEBUG writing secure storage: ["kSync","kXCS","kExtSync","kExtKbHash","scopedKeys"]
1599136474056 FirefoxAccounts TRACE starting write of user data to the login manager
1599136474059 FirefoxAccounts TRACE finished write of user data to the login manager
1599136474453 Services.Common.RESTRequest DEBUG GET https://my.domain.org:PORT/token/1.0/sync/1.5 401
1599136474453 Services.Common.TokenServerClient DEBUG Got token response: 401
1599136474453 Services.Common.TokenServerClient INFO Server-reported error: {"location":"body","name":"","description":"Unauthorized"}
1599136474454 Services.Common.RESTRequest DEBUG POST request to https://api.accounts.firefox.com/v1/oauth/destroy
1599136474454 Services.Common.RESTRequest DEBUG POST Length: 969
1599136474454 FirefoxAccounts DEBUG _updateAccountData with items: ["oauthTokens"]
1599136474454 FirefoxAccounts DEBUG writing plain storage: ["email","sessionToken","uid","verified","device","oauthTokens","profileCache"]
1599136474454 FirefoxAccounts TRACE starting write of json user data: ["email","sessionToken","uid","verified","device","oauthTokens","profileCache"]
1599136474455 Sync.BrowserIDManager ERROR Authentication error in _fetchTokenForUser: {"details":{"now":"2020-09-03T12:34:34.453Z","message":"Authentication failed.","cause":"invalid-credentials","response_body":"{\"status\": \"invalid-credentials\", \"errors\": [{\"location\": \"body\", \"name\": \"\", \"description\": \"Unauthorized\"}]}","response_headers":{"server":"nginx","date":"Thu, 03 Sep 2020 12:34:34 GMT","content-type":"application/json; charset=UTF-8","content-length":"110","x-weave-timestamp":"1599136474.28","x-timestamp":"1599136474","strict-transport-security":"max-age=15768000; includeSubdomains; preload","x-firefox-spdy":"h2"},"response_status":401,"name":"TokenServerClientServerError"},"source":"tokenserver"}
1599136474455 Sync.Status DEBUG Status.login: success.login => error.login.reason.account
1599136474455 Sync.Status DEBUG Status.service: success.status_ok => error.login.failed
1599136474455 Sync.BrowserIDManager INFO Failed to fetch the cluster URL: {"details":{"now":"2020-09-03T12:34:34.453Z","message":"Authentication failed.","cause":"invalid-credentials","response_body":"{\"status\": \"invalid-credentials\", \"errors\": [{\"location\": \"body\", \"name\": \"\", \"description\": \"Unauthorized\"}]}","response_headers":{"server":"nginx","date":"Thu, 03 Sep 2020 12:34:34 GMT","content-type":"application/json; charset=UTF-8","content-length":"110","x-weave-timestamp":"1599136474.28","x-timestamp":"1599136474","strict-transport-security":"max-age=15768000; includeSubdomains; preload","x-firefox-spdy":"h2"},"response_status":401,"name":"TokenServerClientServerError"},"source":"tokenserver"}
1599136474455 Sync.BrowserIDManager DEBUG Cluster value = null
1599136474455 Sync.Status DEBUG Status.sync: success.sync => error.sync.reason.no_node_found
1599136474455 Sync.Status DEBUG Status.service: error.login.failed => error.sync.failed
1599136474455 Sync.Synchronizer INFO No cluster URL found. Cannot sync.
1599136474457 Sync.SyncScheduler DEBUG Next sync in 600000 ms. (why=schedule)
1599136474458 Sync.Telemetry INFO Early submission of sync telemetry due to changed IDs/NodeType
1599136474460 FirefoxAccounts TRACE not checking freshness of profile as it remains recent