1693826891583 Sync.LogManager DEBUG Flushing file log 1693826891592 Sync.LogManager DEBUG Log cleanup threshold time: 1692962891592 1693826891594 Sync.LogManager DEBUG Done deleting files. 1693826892739 Sync.RemoteTabs INFO Sync client is not configured, so not attempting a tab sync 1693826892740 Sync.RemoteTabs INFO Generating tab list with filter 1693826892771 Sync.RemoteTabs INFO Final tab list has 0 clients with 0 tabs. 1693826896256 Sync.Engine.Tabs.Tracker DEBUG Detected a tab change: scheduling a quick-write in 5000ms 1693826896373 Sync.Engine.Tabs.Tracker DEBUG Detected a tab change, but a quick-write is already scheduled 1693826896374 Sync.Engine.Tabs.Tracker DEBUG Detected a tab change, but a quick-write is already scheduled 1693826899543 Sync.Engine.Tabs.Tracker DEBUG Detected a tab change, but a quick-write is already scheduled 1693826899857 FirefoxAccounts DEBUG FxAccountsWebChannel message received: fxaccounts:fxa_status 1693826899857 FirefoxAccounts DEBUG fxa_status received 1693826899857 FirefoxAccounts DEBUG service: sync 1693826899857 FirefoxAccounts DEBUG is private browsing: false 1693826899868 Sync.Engine.Tabs.Tracker DEBUG Detected a tab change, but a quick-write is already scheduled 1693826899878 Sync.Engine.Tabs.Tracker DEBUG Detected a tab change, but a quick-write is already scheduled 1693826901015 FirefoxAccounts DEBUG FxAccountsWebChannel message received: fxaccounts:loaded 1693826901015 FirefoxAccounts WARN Unrecognized FxAccountsWebChannel command: fxaccounts:loaded 1693826901342 Sync.Engine.Tabs INFO Can't do a quick-sync due to the service status: 1693826909591 FirefoxAccounts DEBUG FxAccountsWebChannel message received: fxaccounts:can_link_account 1693826909592 FirefoxAccounts DEBUG FxAccountsWebChannel response: {"command":"fxaccounts:can_link_account","messageId":"16938269095882","data":{"ok":true}} 1693826910943 Sync.Engine.Tabs.Tracker DEBUG Detected a tab change: scheduling a quick-write in 5000ms 1693826910961 FirefoxAccounts DEBUG FxAccountsWebChannel message received: fxaccounts:login 1693826910961 FirefoxAccounts DEBUG Webchannel is logging a user in. 1693826910962 FirefoxAccounts DEBUG setSignedInUser - aborting any existing flows 1693826910962 Sync.Engine.Clients.Tracker DEBUG client.name preference changed 1693826910962 FirefoxAccounts DEBUG removing account data 1693826910962 FirefoxAccounts TRACE starting write of json user data: null 1693826910963 FirefoxAccounts TRACE finished write of json user data - took: 1 1693826910968 FirefoxAccounts TRACE storage set finished clearing account data 1693826910968 FirefoxAccounts DEBUG account data reset 1693826910968 FirefoxAccounts TRACE StorageManager finalizing 1693826910968 FirefoxAccounts TRACE StorageManager finalized 1693826910968 FirefoxAccounts TRACE initializing new storage manager 1693826910969 FirefoxAccounts DEBUG writing plain storage: ["email","sessionToken","uid","verified"] 1693826910969 FirefoxAccounts TRACE starting write of json user data: ["email","sessionToken","uid","verified"] 1693826910974 FirefoxAccounts TRACE finished write of json user data - took: 4 1693826910974 FirefoxAccounts DEBUG writing secure storage: ["keyFetchToken","unwrapBKey"] 1693826910974 FirefoxAccounts TRACE starting write of user data to the login manager 1693826910980 FirefoxAccounts TRACE finished write of user data to the login manager 1693826910980 FirefoxAccounts TRACE initializing of new storage manager done 1693826910980 FirefoxAccounts DEBUG startVerifiedCheck: false 1693826910980 FirefoxAccounts DEBUG whenVerified promise starts polling for verified email 1693826910980 FirefoxAccounts DEBUG entering startPollEmailStatus: start 1693826910980 FirefoxAccounts DEBUG entering pollEmailStatus: start 1693826910982 FirefoxAccounts DEBUG Notifying observers of fxaccounts:onlogin 1693826910982 Sync.SyncAuthManager DEBUG observed fxaccounts:onlogin 1693826910982 Sync.SyncAuthManager INFO Sync has been connected to a logged in user 1693826910983 FirefoxAccounts DEBUG startVerifiedCheck: false 1693826910984 FirefoxAccounts DEBUG FxAccountsProfileClient: Initialized 1693826910984 FirefoxAccounts DEBUG startVerifiedCheck: false 1693826910985 FirefoxAccounts DEBUG FxAccountsPush loading service 1693826910985 FirefoxAccounts DEBUG FxAccountsPush initialized 1693826910985 FirefoxAccounts TRACE FxAccountsPush registerPushEndpoint 1693826910985 FirefoxAccounts DEBUG FxAccountsProfileClient: Requested profile 1693826910985 FirefoxAccounts DEBUG getOAuthToken enter 1693826910985 Sync.SyncAuthManager INFO The user is not verified 1693826910985 FirefoxAccounts ERROR FxA rejecting with error UNVERIFIED_ACCOUNT, details: undefined 1693826910986 FirefoxAccounts ERROR Background refresh of initial profile failed: Error: UNVERIFIED_ACCOUNT(resource://gre/modules/FxAccounts.sys.mjs:1522:18) JS Stack trace: _error@FxAccounts.sys.mjs:1522:18 withSessionToken@FxAccounts.sys.mjs:777:18 1693826910986 FirefoxAccounts ERROR Background refresh of initial profile failed: Error: UNVERIFIED_ACCOUNT(resource://gre/modules/FxAccounts.sys.mjs:1522:18) JS Stack trace: _error@FxAccounts.sys.mjs:1522:18 withSessionToken@FxAccounts.sys.mjs:777:18 1693826910996 Services.Common.RESTRequest DEBUG GET request to https://api.accounts.firefox.com/v1/recovery_email/status?reason=start 1693826911000 FirefoxAccounts DEBUG FxAccountsPush got subscription 1693826911002 Sync.Engine.Clients.Tracker DEBUG client.name preference changed 1693826911002 FirefoxAccounts INFO Generating and persisting encrypted sendtab keys 1693826911002 FirefoxAccounts INFO Could not find sendtab keys, generating them 1693826911006 FirefoxAccounts DEBUG _updateAccountData with items: ["device"] 1693826911006 FirefoxAccounts DEBUG writing plain storage: ["email","sessionToken","uid","verified","device"] 1693826911006 FirefoxAccounts TRACE starting write of json user data: ["email","sessionToken","uid","verified","device"] 1693826911006 FirefoxAccounts INFO Can't get keys; user is not verified 1693826911006 FirefoxAccounts INFO Can't fetch keys, so unable to determine sendtab keys 1693826911006 FirefoxAccounts INFO registering with available commands: [] 1693826911006 FirefoxAccounts DEBUG registering new device details 1693826911008 FirefoxAccounts TRACE finished write of json user data - took: 2 1693826911008 FirefoxAccounts DEBUG writing secure storage: ["keyFetchToken","unwrapBKey"] 1693826911008 FirefoxAccounts TRACE starting write of user data to the login manager 1693826911017 FirefoxAccounts TRACE finished write of user data to the login manager 1693826911017 Services.Common.RESTRequest DEBUG POST request to https://api.accounts.firefox.com/v1/account/device 1693826911017 Services.Common.RESTRequest DEBUG POST Length: 429 1693826911843 Services.Common.RESTRequest DEBUG GET https://api.accounts.firefox.com/v1/recovery_email/status?reason=start 200 1693826911843 Hawk DEBUG (Response) /recovery_email/status?reason=start: code: 200 - Status text: OK 1693826911844 Hawk DEBUG Clock offset vs https://api.accounts.firefox.com/v1: -2844 1693826911844 FirefoxAccounts DEBUG checkEmailStatus -> {"email":"anonymous@XXXX.de","verified":false,"sessionVerified":false,"emailVerified":true} 1693826911844 FirefoxAccounts DEBUG polling with timeout = 60000 1693826911869 Services.Common.RESTRequest DEBUG POST https://api.accounts.firefox.com/v1/account/device 200 1693826911869 Hawk DEBUG (Response) /account/device: code: 200 - Status text: OK 1693826911870 Hawk DEBUG Clock offset vs https://api.accounts.firefox.com/v1: -2870 1693826911870 FirefoxAccounts DEBUG _updateAccountData with items: ["device"] 1693826911870 FirefoxAccounts DEBUG writing plain storage: ["email","sessionToken","uid","verified","device"] 1693826911870 FirefoxAccounts TRACE starting write of json user data: ["email","sessionToken","uid","verified","device"] 1693826911871 FirefoxAccounts DEBUG Webchannel is enabling sync 1693826911871 FirefoxAccounts DEBUG startVerifiedCheck: false 1693826911871 FirefoxAccounts INFO Generating and persisting encrypted sendtab keys 1693826911871 Sync.Service INFO Configuring sync with current FxA user 1693826911872 FirefoxAccounts DEBUG FxAccountsProfileClient: Requested profile 1693826911872 FirefoxAccounts DEBUG getOAuthToken enter 1693826911872 Sync.SyncAuthManager DEBUG observed weave:connected 1693826911872 Sync.SyncAuthManager INFO Sync has been connected to a logged in user 1693826911872 FirefoxAccounts INFO Can't get keys; user is not verified 1693826911872 FirefoxAccounts DEBUG startVerifiedCheck: false 1693826911872 FirefoxAccounts DEBUG startVerifiedCheck: false 1693826911872 FirefoxAccounts INFO Can't fetch keys, so unable to determine sendtab keys 1693826911872 FirefoxAccounts ERROR FxA rejecting with error UNVERIFIED_ACCOUNT, details: undefined 1693826911873 FirefoxAccounts ERROR Background refresh of initial profile failed: Error: UNVERIFIED_ACCOUNT(resource://gre/modules/FxAccounts.sys.mjs:1522:18) JS Stack trace: _error@FxAccounts.sys.mjs:1522:18 withSessionToken@FxAccounts.sys.mjs:777:18 1693826911873 FirefoxAccounts DEBUG FxAccountsProfileClient: Requested profile 1693826911873 FirefoxAccounts DEBUG getOAuthToken enter 1693826911873 Sync.SyncAuthManager INFO The user is not verified 1693826911873 FirefoxAccounts ERROR FxA rejecting with error UNVERIFIED_ACCOUNT, details: undefined 1693826911874 FirefoxAccounts ERROR Background refresh of initial profile failed: Error: UNVERIFIED_ACCOUNT(resource://gre/modules/FxAccounts.sys.mjs:1522:18) JS Stack trace: _error@FxAccounts.sys.mjs:1522:18 withSessionToken@FxAccounts.sys.mjs:777:18 1693826911875 FirefoxAccounts ERROR Background refresh of initial profile failed: Error: UNVERIFIED_ACCOUNT(resource://gre/modules/FxAccounts.sys.mjs:1522:18) JS Stack trace: _error@FxAccounts.sys.mjs:1522:18 withSessionToken@FxAccounts.sys.mjs:777:18 1693826911878 FirefoxAccounts TRACE finished write of json user data - took: 8 1693826911879 FirefoxAccounts DEBUG writing secure storage: ["keyFetchToken","unwrapBKey"] 1693826911879 FirefoxAccounts TRACE starting write of user data to the login manager 1693826911889 FirefoxAccounts TRACE finished write of user data to the login manager 1693826915969 Sync.Engine.Tabs INFO Can't do a quick-sync due to the service status: 1693826953825 FirefoxAccounts TRACE observed topic=push-message, data=chrome://fxa-device-update, subject=[xpconnect wrapped nsISupports] 1693826953825 FirefoxAccounts TRACE FxAccountsPushService _onPushMessage 1693826953826 FirefoxAccounts DEBUG empty push message - checking account status 1693826953826 FirefoxAccounts TRACE checkVerificationStatus 1693826953826 FirefoxAccounts TRACE checkVerificationStatus - forcing verification status check 1693826953826 FirefoxAccounts DEBUG entering startPollEmailStatus: push 1693826953826 FirefoxAccounts DEBUG startPollEmailStatus starting while existing timer is running 1693826953826 FirefoxAccounts DEBUG entering pollEmailStatus: push 1693826953829 Services.Common.RESTRequest DEBUG GET request to https://api.accounts.firefox.com/v1/recovery_email/status?reason=push 1693826954030 Services.Common.RESTRequest DEBUG GET https://api.accounts.firefox.com/v1/recovery_email/status?reason=push 200 1693826954030 Hawk DEBUG (Response) /recovery_email/status?reason=push: code: 200 - Status text: OK 1693826954031 Hawk DEBUG Clock offset vs https://api.accounts.firefox.com/v1: -3031 1693826954031 FirefoxAccounts DEBUG checkEmailStatus -> {"email":"anonymous@XXXX.de","verified":true,"sessionVerified":true,"emailVerified":true} 1693826954031 FirefoxAccounts DEBUG _updateAccountData with items: ["verified"] 1693826954031 FirefoxAccounts DEBUG writing plain storage: ["email","sessionToken","uid","verified","device"] 1693826954031 FirefoxAccounts TRACE starting write of json user data: ["email","sessionToken","uid","verified","device"] 1693826954032 FirefoxAccounts INFO the user became verified 1693826954032 FirefoxAccounts DEBUG Notifying observers of fxaccounts:onverified 1693826954096 Sync.SyncAuthManager DEBUG observed fxaccounts:onverified 1693826954096 Sync.SyncAuthManager INFO The user became verified 1693826954096 Sync.Status DEBUG Status.login: error.login.reason.no_username => success.login 1693826954096 Sync.Status DEBUG Status.service: service.client_not_configured => success.status_ok 1693826954097 Sync.Service DEBUG User-Agent: Firefox/117.0 (Windows NT 10.0; Win64; x64) FxSync/1.119.0.20230824132758.desktop 1693826954097 Sync.Service INFO Starting sync at 2023-09-04 13:29:14 in browser session 6d_AQMlbMO6f 1693826954097 Sync.Service DEBUG In sync: should login. 1693826954097 Sync.Service INFO User logged in successfully - verifying login. 1693826954097 FirefoxAccounts INFO Generating and persisting encrypted sendtab keys 1693826954097 FirefoxAccounts DEBUG FxAccountsProfileClient: Requested profile 1693826954097 FirefoxAccounts DEBUG getOAuthToken enter 1693826954098 Sync.SyncAuthManager DEBUG unlockAndVerifyAuthState already has (or can fetch) sync keys 1693826954100 FirefoxAccounts INFO fetching updated device list 1693826954101 Sync.Status DEBUG Status.login: success.login => success.status_ok 1693826954101 Sync.Status DEBUG Status.service: success.status_ok => error.login.failed 1693826954101 Sync.Service DEBUG Fetching unlocked auth state returned success.status_ok 1693826954102 Sync.SyncAuthManager INFO Getting sync key 1693826954107 FirefoxAccounts TRACE finished write of json user data - took: 76 1693826954107 FirefoxAccounts DEBUG writing secure storage: ["keyFetchToken","unwrapBKey"] 1693826954107 FirefoxAccounts TRACE starting write of user data to the login manager 1693826954120 FirefoxAccounts TRACE finished write of user data to the login manager 1693826954121 Services.Common.RESTRequest DEBUG GET request to https://api.accounts.firefox.com/v1/account/devices?filterIdleDevicesTimestamp=1692012554102 1693826954122 Services.Common.RESTRequest DEBUG POST request to https://api.accounts.firefox.com/v1/oauth/token 1693826954122 Services.Common.RESTRequest DEBUG POST Length: 81 1693826954123 Services.Common.RESTRequest DEBUG POST request to https://api.accounts.firefox.com/v1/account/scoped-key-data 1693826954123 Services.Common.RESTRequest DEBUG POST Length: 84 1693826954331 Services.Common.RESTRequest DEBUG GET https://api.accounts.firefox.com/v1/account/devices?filterIdleDevicesTimestamp=1692012554102 200 1693826954331 Hawk DEBUG (Response) /account/devices?filterIdleDevicesTimestamp=1692012554102: code: 200 - Status text: OK 1693826954331 Hawk DEBUG Clock offset vs https://api.accounts.firefox.com/v1: -3331 1693826954332 FirefoxAccounts INFO Got new device list: 2f112f9964c129a31af697e7b87e1f38, 5588c73f5efb3571a982455bc68613f8, 905680977f74379a44a67d293a36645e, a32c298cf7a82a7accf2c7791ad4b577, bd9c40c5e6df79f39a9399076a658b25, cb352dca5b33c5feafda3a180af1240e, d6a83f54cb9b51c139ad39aace01b75c, da02661413122041fc8b5bd49375e5b7, e6b126323ef76e55646b86881bbe64a1, fd9d1b4b8f747c8411dedcf326cfdaba 1693826954335 FirefoxAccounts INFO Generating and persisting encrypted sendtab keys 1693826954435 Services.Common.RESTRequest DEBUG POST https://api.accounts.firefox.com/v1/oauth/token 200 1693826954436 Hawk DEBUG (Response) /oauth/token: code: 200 - Status text: OK 1693826954436 Hawk DEBUG Clock offset vs https://api.accounts.firefox.com/v1: -3436 1693826954436 FirefoxAccounts DEBUG _updateAccountData with items: ["oauthTokens"] 1693826954437 FirefoxAccounts DEBUG writing plain storage: ["email","sessionToken","uid","verified","device","oauthTokens"] 1693826954437 FirefoxAccounts TRACE starting write of json user data: ["email","sessionToken","uid","verified","device","oauthTokens"] 1693826954437 Services.Common.RESTRequest DEBUG GET request to https://profile.accounts.firefox.com/v1/profile 1693826954441 FirefoxAccounts TRACE finished write of json user data - took: 3 1693826954441 FirefoxAccounts DEBUG writing secure storage: ["keyFetchToken","unwrapBKey"] 1693826954441 FirefoxAccounts TRACE starting write of user data to the login manager 1693826954459 FirefoxAccounts TRACE finished write of user data to the login manager 1693826954921 Services.Common.RESTRequest DEBUG POST https://api.accounts.firefox.com/v1/account/scoped-key-data 200 1693826954921 Hawk DEBUG (Response) /account/scoped-key-data: code: 200 - Status text: OK 1693826954921 Hawk DEBUG Clock offset vs https://api.accounts.firefox.com/v1: -2921 1693826954921 FirefoxAccounts DEBUG Fetching keys with token true from https://api.accounts.firefox.com/v1 1693826954922 Services.Common.RESTRequest DEBUG GET request to https://api.accounts.firefox.com/v1/account/keys 1693826955129 Services.Common.RESTRequest DEBUG GET https://api.accounts.firefox.com/v1/account/keys 200 1693826955129 Hawk DEBUG (Response) /account/keys: code: 200 - Status text: OK 1693826955129 Hawk DEBUG Clock offset vs https://api.accounts.firefox.com/v1: -3129 1693826955130 FirefoxAccounts DEBUG Keys Obtained: https://identity.mozilla.com/apps/oldsync 1693826955130 FirefoxAccounts DEBUG _updateAccountData with items: ["scopedKeys","keyFetchToken","unwrapBKey"] 1693826955130 FirefoxAccounts DEBUG writing plain storage: ["email","sessionToken","uid","verified","device","oauthTokens"] 1693826955130 FirefoxAccounts TRACE starting write of json user data: ["email","sessionToken","uid","verified","device","oauthTokens"] 1693826955130 Sync.BulkKeyBundle INFO BulkKeyBundle being created for undefined 1693826955131 Sync.SyncAuthManager INFO Getting a sync token from: https://token.services.mozilla.com/1.0/sync/1.5 1693826955131 Sync.SyncAuthManager DEBUG Getting a token using OAuth 1693826955131 FirefoxAccounts DEBUG getOAuthToken enter 1693826955131 Sync.BulkKeyBundle INFO BulkKeyBundle being created for undefined 1693826955132 FirefoxAccounts DEBUG _updateAccountData with items: ["encryptedSendTabKeys"] 1693826955132 FirefoxAccounts TRACE FxAccountsPush registerPushEndpoint 1693826955132 FirefoxAccounts DEBUG _updateAccountData with items: ["encryptedSendTabKeys"] 1693826955132 FirefoxAccounts WARN Our commands need to be updated on the server 1693826955132 FirefoxAccounts TRACE FxAccountsPush registerPushEndpoint 1693826955133 FirefoxAccounts TRACE finished write of json user data - took: 3 1693826955133 FirefoxAccounts DEBUG writing secure storage: ["scopedKeys"] 1693826955133 FirefoxAccounts TRACE starting write of user data to the login manager 1693826955141 FirefoxAccounts TRACE finished write of user data to the login manager 1693826955141 FirefoxAccounts DEBUG writing plain storage: ["email","sessionToken","uid","verified","device","oauthTokens","encryptedSendTabKeys"] 1693826955141 FirefoxAccounts TRACE starting write of json user data: ["email","sessionToken","uid","verified","device","oauthTokens","encryptedSendTabKeys"] 1693826955142 Services.Common.RESTRequest DEBUG POST request to https://api.accounts.firefox.com/v1/oauth/token 1693826955142 Services.Common.RESTRequest DEBUG POST Length: 127 1693826955143 FirefoxAccounts DEBUG FxAccountsPush got subscription 1693826955143 FirefoxAccounts INFO registering with available commands: ["https://identity.mozilla.com/cmd/open-uri"] 1693826955143 FirefoxAccounts DEBUG updating existing device details 1693826955143 FirefoxAccounts DEBUG FxAccountsPush got subscription 1693826955143 FirefoxAccounts INFO registering with available commands: ["https://identity.mozilla.com/cmd/open-uri"] 1693826955143 FirefoxAccounts DEBUG updating existing device details 1693826955143 FirefoxAccounts TRACE finished write of json user data - took: 2 1693826955143 FirefoxAccounts DEBUG writing secure storage: ["scopedKeys"] 1693826955143 FirefoxAccounts TRACE starting write of user data to the login manager 1693826955150 FirefoxAccounts TRACE finished write of user data to the login manager 1693826955150 FirefoxAccounts DEBUG writing plain storage: ["email","sessionToken","uid","verified","device","oauthTokens","encryptedSendTabKeys"] 1693826955150 FirefoxAccounts TRACE starting write of json user data: ["email","sessionToken","uid","verified","device","oauthTokens","encryptedSendTabKeys"] 1693826955153 Services.Common.RESTRequest DEBUG POST request to https://api.accounts.firefox.com/v1/account/device 1693826955153 Services.Common.RESTRequest DEBUG POST Length: 870 1693826955154 Services.Common.RESTRequest DEBUG POST request to https://api.accounts.firefox.com/v1/account/device 1693826955154 Services.Common.RESTRequest DEBUG POST Length: 870 1693826955154 FirefoxAccounts TRACE finished write of json user data - took: 4 1693826955154 FirefoxAccounts DEBUG writing secure storage: ["scopedKeys"] 1693826955154 FirefoxAccounts TRACE starting write of user data to the login manager 1693826955162 FirefoxAccounts TRACE finished write of user data to the login manager 1693826955283 Services.Common.RESTRequest DEBUG GET https://profile.accounts.firefox.com/v1/profile 200 1693826955283 FirefoxAccounts DEBUG _updateAccountData with items: ["profileCache"] 1693826955283 FirefoxAccounts DEBUG writing plain storage: ["email","sessionToken","uid","verified","device","oauthTokens","encryptedSendTabKeys","profileCache"] 1693826955283 FirefoxAccounts TRACE starting write of json user data: ["email","sessionToken","uid","verified","device","oauthTokens","encryptedSendTabKeys","profileCache"] 1693826955283 FirefoxAccounts DEBUG notifying profile changed for user fd068c64a37a4677a8c451c955db6920 1693826955284 FirefoxAccounts TRACE not checking freshness of profile as it remains recent 1693826955285 FirefoxAccounts INFO Already fetching device list, return existing promise 1693826955287 FirefoxAccounts TRACE finished write of json user data - took: 4 1693826955287 FirefoxAccounts DEBUG writing secure storage: ["scopedKeys"] 1693826955287 FirefoxAccounts TRACE starting write of user data to the login manager 1693826955294 FirefoxAccounts TRACE finished write of user data to the login manager 1693826955372 Services.Common.RESTRequest DEBUG POST https://api.accounts.firefox.com/v1/oauth/token 200 1693826955372 Hawk DEBUG (Response) /oauth/token: code: 200 - Status text: OK 1693826955372 Hawk DEBUG Clock offset vs https://api.accounts.firefox.com/v1: -3372 1693826955372 FirefoxAccounts DEBUG _updateAccountData with items: ["oauthTokens"] 1693826955372 FirefoxAccounts DEBUG writing plain storage: ["email","sessionToken","uid","verified","device","oauthTokens","encryptedSendTabKeys","profileCache"] 1693826955372 FirefoxAccounts TRACE starting write of json user data: ["email","sessionToken","uid","verified","device","oauthTokens","encryptedSendTabKeys","profileCache"] 1693826955373 Services.Common.TokenServerClient DEBUG Beginning OAuth token exchange: https://token.services.mozilla.com/1.0/sync/1.5 1693826955373 Services.Common.RESTRequest DEBUG GET request to https://token.services.mozilla.com/1.0/sync/1.5 1693826955374 FirefoxAccounts TRACE finished write of json user data - took: 2 1693826955374 FirefoxAccounts DEBUG writing secure storage: ["scopedKeys"] 1693826955374 FirefoxAccounts TRACE starting write of user data to the login manager 1693826955381 FirefoxAccounts TRACE finished write of user data to the login manager 1693826955385 Services.Common.RESTRequest DEBUG POST https://api.accounts.firefox.com/v1/account/device 200 1693826955385 Hawk DEBUG (Response) /account/device: code: 200 - Status text: OK 1693826955385 Hawk DEBUG Clock offset vs https://api.accounts.firefox.com/v1: -3385 1693826955385 FirefoxAccounts DEBUG _updateAccountData with items: ["device"] 1693826955385 FirefoxAccounts DEBUG writing plain storage: ["email","sessionToken","uid","verified","device","oauthTokens","encryptedSendTabKeys","profileCache"] 1693826955385 FirefoxAccounts TRACE starting write of json user data: ["email","sessionToken","uid","verified","device","oauthTokens","encryptedSendTabKeys","profileCache"] 1693826955386 FirefoxAccounts TRACE finished write of json user data - took: 1 1693826955387 FirefoxAccounts DEBUG writing secure storage: ["scopedKeys"] 1693826955387 FirefoxAccounts TRACE starting write of user data to the login manager 1693826955394 FirefoxAccounts TRACE finished write of user data to the login manager 1693826955427 Services.Common.RESTRequest DEBUG POST https://api.accounts.firefox.com/v1/account/device 200 1693826955427 Hawk DEBUG (Response) /account/device: code: 200 - Status text: OK 1693826955427 Hawk DEBUG Clock offset vs https://api.accounts.firefox.com/v1: -3427 1693826955427 FirefoxAccounts DEBUG _updateAccountData with items: ["device"] 1693826955427 FirefoxAccounts DEBUG writing plain storage: ["email","sessionToken","uid","verified","device","oauthTokens","encryptedSendTabKeys","profileCache"] 1693826955427 FirefoxAccounts TRACE starting write of json user data: ["email","sessionToken","uid","verified","device","oauthTokens","encryptedSendTabKeys","profileCache"] 1693826955427 FirefoxAccounts INFO updating the cache 1693826955428 FirefoxAccounts TRACE finished write of json user data - took: 1 1693826955428 FirefoxAccounts DEBUG writing secure storage: ["scopedKeys"] 1693826955428 FirefoxAccounts TRACE starting write of user data to the login manager 1693826955435 FirefoxAccounts TRACE finished write of user data to the login manager 1693826955722 FirefoxAccounts TRACE observed topic=push-message, data=chrome://fxa-device-update, subject=[xpconnect wrapped nsISupports] 1693826955722 FirefoxAccounts TRACE FxAccountsPushService _onPushMessage 1693826955722 FirefoxAccounts DEBUG empty push message - checking account status 1693826955722 FirefoxAccounts TRACE checkVerificationStatus 1693826955722 FirefoxAccounts TRACE checkVerificationStatus - forcing verification status check 1693826955722 FirefoxAccounts DEBUG entering startPollEmailStatus: push 1693826955722 FirefoxAccounts DEBUG entering pollEmailStatus: push 1693826955724 Services.Common.RESTRequest DEBUG GET request to https://api.accounts.firefox.com/v1/recovery_email/status?reason=push 1693826955744 Sync.Engine.Tabs.Tracker DEBUG Detected a tab change: scheduling a quick-write in 5000ms 1693826955752 Services.Common.RESTRequest DEBUG GET https://token.services.mozilla.com/1.0/sync/1.5 200 1693826955752 Services.Common.TokenServerClient DEBUG Got token response: 200 1693826955752 Services.Common.TokenServerClient DEBUG Successful token response 1693826955752 Sync.BulkKeyBundle INFO BulkKeyBundle being created for undefined 1693826955753 Sync.Status DEBUG Status.login: success.status_ok => success.login 1693826955753 Sync.Status DEBUG Status.service: error.login.failed => success.status_ok 1693826955753 Sync.SyncAuthManager DEBUG _findCluster returning https://sync-1-us-west1-g.sync.services.mozilla.com/1.5/205628552/ 1693826955753 Sync.SyncAuthManager DEBUG Cluster value = https://sync-1-us-west1-g.sync.services.mozilla.com/1.5/205628552/ 1693826955753 Sync.SyncAuthManager DEBUG Setting cluster to https://sync-1-us-west1-g.sync.services.mozilla.com/1.5/205628552/ 1693826955753 Sync.Service DEBUG Caching URLs under storage user base: https://sync-1-us-west1-g.sync.services.mozilla.com/1.5/205628552/ 1693826955754 FirefoxAccounts TRACE not checking freshness of profile as it remains recent 1693826955754 FirefoxAccounts TRACE not checking freshness of profile as it remains recent 1693826955873 Sync.SyncScheduler DEBUG Global Score threshold hit, triggering sync. 1693826955874 Sync.Service DEBUG User-Agent: Firefox/117.0 (Windows NT 10.0; Win64; x64) FxSync/1.119.0.20230824132758.desktop 1693826955874 Sync.Service INFO Starting sync at 2023-09-04 13:29:15 in browser session 6d_AQMlbMO6f 1693826955874 Sync.Service DEBUG In sync: should login. 1693826955874 Sync.Service DEBUG Exception calling WrappedLock: LockException: Could not acquire lock. Label: "service.js: login".(resource://services-sync/util.sys.mjs:45:5) JS Stack trace: LockException@util.sys.mjs:45:5 throwLockException@util.sys.mjs:129:11 WrappedLock@util.sys.mjs:143:15 WrappedCatch@util.sys.mjs:114:27 login@service.sys.mjs:1049:66 sync/<@service.sys.mjs:1327:26 WrappedCatch@util.sys.mjs:114:27 sync@service.sys.mjs:1335:7 1693826955875 Sync.Service INFO Cannot start sync: already syncing? 1693826955875 Sync.Service DEBUG Not syncing: login returned false. 1693826955920 Services.Common.RESTRequest DEBUG GET https://api.accounts.firefox.com/v1/recovery_email/status?reason=push 200 1693826955920 Hawk DEBUG (Response) /recovery_email/status?reason=push: code: 200 - Status text: OK 1693826955920 Hawk DEBUG Clock offset vs https://api.accounts.firefox.com/v1: -2920 1693826955920 FirefoxAccounts DEBUG checkEmailStatus -> {"email":"anonymous@XXXX.de","verified":true,"sessionVerified":true,"emailVerified":true} 1693826955921 FirefoxAccounts DEBUG _updateAccountData with items: ["verified"] 1693826955921 FirefoxAccounts DEBUG writing plain storage: ["email","sessionToken","uid","verified","device","oauthTokens","encryptedSendTabKeys","profileCache"] 1693826955921 FirefoxAccounts TRACE starting write of json user data: ["email","sessionToken","uid","verified","device","oauthTokens","encryptedSendTabKeys","profileCache"] 1693826955921 FirefoxAccounts INFO the user became verified 1693826955921 FirefoxAccounts DEBUG Notifying observers of fxaccounts:onverified 1693826955947 Sync.SyncAuthManager DEBUG observed fxaccounts:onverified 1693826955947 Sync.SyncAuthManager INFO The user became verified 1693826955947 Sync.Status DEBUG Status.login: success.login => success.login 1693826955947 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1693826955947 Sync.Service DEBUG User-Agent: Firefox/117.0 (Windows NT 10.0; Win64; x64) FxSync/1.119.0.20230824132758.desktop 1693826955947 Sync.Service INFO Starting sync at 2023-09-04 13:29:15 in browser session 6d_AQMlbMO6f 1693826955947 Sync.Service DEBUG In sync: should login. 1693826955947 Sync.Service DEBUG Exception calling WrappedLock: LockException: Could not acquire lock. Label: "service.js: login".(resource://services-sync/util.sys.mjs:45:5) JS Stack trace: LockException@util.sys.mjs:45:5 throwLockException@util.sys.mjs:129:11 WrappedLock@util.sys.mjs:143:15 WrappedCatch@util.sys.mjs:114:27 login@service.sys.mjs:1049:66 sync/<@service.sys.mjs:1327:26 WrappedCatch@util.sys.mjs:114:27 sync@service.sys.mjs:1335:7 1693826955947 Sync.Service INFO Cannot start sync: already syncing? 1693826955947 Sync.Service DEBUG Not syncing: login returned false. 1693826955947 FirefoxAccounts TRACE not checking freshness of profile as it remains recent 1693826955951 FirefoxAccounts TRACE finished write of json user data - took: 30 1693826955951 FirefoxAccounts DEBUG writing secure storage: ["scopedKeys"] 1693826955951 FirefoxAccounts TRACE starting write of user data to the login manager 1693826955959 FirefoxAccounts TRACE finished write of user data to the login manager 1693826956164 Sync.Resource DEBUG GET success 200 https://sync-1-us-west1-g.sync.services.mozilla.com/1.5/205628552/info/collections 1693826956165 Sync.Service DEBUG Fetching server configuration: https://sync-1-us-west1-g.sync.services.mozilla.com/1.5/205628552/info/configuration 1693826956165 FirefoxAccounts TRACE not checking freshness of profile as it remains recent 1693826956356 Sync.Resource DEBUG GET success 200 https://sync-1-us-west1-g.sync.services.mozilla.com/1.5/205628552/info/configuration 1693826956356 Sync.Service DEBUG Fetching global metadata record 1693826956357 FirefoxAccounts TRACE not checking freshness of profile as it remains recent 1693826956594 Sync.Resource DEBUG GET success 200 https://sync-1-us-west1-g.sync.services.mozilla.com/1.5/205628552/storage/meta/global 1693826956594 Sync.Service DEBUG Clearing cached meta record. metaModified is undefined, setting to 1684229669.46 1693826956595 FirefoxAccounts TRACE not checking freshness of profile as it remains recent 1693826956805 Sync.Resource DEBUG GET success 200 https://sync-1-us-west1-g.sync.services.mozilla.com/1.5/205628552/storage/meta/global 1693826956806 Sync.Service DEBUG Weave Version: 1.119.0 Local Storage: 5 Remote Storage: 5 1693826956806 Sync.Service DEBUG Fetching and verifying -- or generating -- symmetric keys. 1693826956806 Sync.Service INFO Testing info/collections: {"tabs":1693826862.67,"clients":1693826745.23,"passwords":1692951351.77,"meta":1684229669.46,"bookmarks":1692951353.2,"history":1693826746.02,"forms":1692962612.68,"prefs":1693826453.86,"crypto":1684229651.82} 1693826956806 Sync.CollectionKeyManager INFO Testing for updateNeeded. Last modified: 0 1693826956806 Sync.Service INFO collection keys reports that a key update is needed. 1693826956806 FirefoxAccounts TRACE not checking freshness of profile as it remains recent 1693826957021 Sync.Resource DEBUG GET success 200 https://sync-1-us-west1-g.sync.services.mozilla.com/1.5/205628552/storage/crypto/keys 1693826957021 Sync.CollectionKeyManager INFO Updating collection keys... 1693826957022 Sync.CollectionKeyManager INFO Setting collection keys contents. Our last modified: 0, input modified: 1684229651.82. 1693826957022 Sync.BulkKeyBundle INFO BulkKeyBundle being created for [default] 1693826957023 Sync.CollectionKeyManager INFO Processing downloaded per-collection keys. 1693826957023 Sync.CollectionKeyManager INFO Clearing collection keys... 1693826957023 Sync.CollectionKeyManager INFO Saving downloaded keys. 1693826957023 Sync.CollectionKeyManager INFO Bumping last modified to 1684229651.82 1693826957023 Sync.CollectionKeyManager INFO Collection keys updated. 1693826957023 Sync.Status DEBUG Status.login: success.login => success.login 1693826957023 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1693826957023 Sync.Service DEBUG Caching URLs under storage user base: https://sync-1-us-west1-g.sync.services.mozilla.com/1.5/205628552/ 1693826957023 Sync.SyncScheduler DEBUG Clearing sync triggers and the global score. 1693826957026 Sync.Status INFO Resetting Status. 1693826957026 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1693826957026 FirefoxAccounts TRACE not checking freshness of profile as it remains recent 1693826957241 Sync.Resource DEBUG GET success 200 https://sync-1-us-west1-g.sync.services.mozilla.com/1.5/205628552/info/collections 1693826957242 Sync.Service DEBUG Fetching server configuration: https://sync-1-us-west1-g.sync.services.mozilla.com/1.5/205628552/info/configuration 1693826957242 FirefoxAccounts TRACE not checking freshness of profile as it remains recent 1693826957437 Sync.Resource DEBUG GET success 200 https://sync-1-us-west1-g.sync.services.mozilla.com/1.5/205628552/info/configuration 1693826957437 Sync.Service DEBUG Fetching global metadata record 1693826957437 Sync.Service DEBUG Weave Version: 1.119.0 Local Storage: 5 Remote Storage: 5 1693826957437 Sync.Service DEBUG Fetching and verifying -- or generating -- symmetric keys. 1693826957437 Sync.Service INFO Testing info/collections: {"history":1693826746.02,"tabs":1693826862.67,"forms":1692962612.68,"prefs":1693826453.86,"passwords":1692951351.77,"meta":1684229669.46,"clients":1693826745.23,"bookmarks":1692951353.2,"crypto":1684229651.82} 1693826957437 Sync.CollectionKeyManager INFO Testing for updateNeeded. Last modified: 1684229651.82 1693826957438 Sync.Synchronizer DEBUG Refreshing client list. 1693826957438 Sync.Engine.Clients DEBUG First sync, uploading all items 1693826957439 Sync.Engine.Clients DEBUG Resetting clients last sync time 1693826957440 FirefoxAccounts TRACE not checking freshness of profile as it remains recent 1693826957698 Sync.Collection DEBUG GET success 200 https://sync-1-us-west1-g.sync.services.mozilla.com/1.5/205628552/storage/clients?full=1&limit=1000 1693826957716 Sync.Engine.Clients INFO Records: 27 applied, 27 successfully, 0 failed to apply, 0 newly failed to apply, 1 reconciled. 1693826957717 FirefoxAccounts INFO Device list cache is fresh, re-using it 1693826957717 Sync.Engine.Clients DEBUG Refreshing the known stale clients list 1693826957717 Sync.Engine.Clients INFO Hiding stale client ckqisTRzaP78 with age 880554.6800000668 1693826957717 Sync.Engine.Clients INFO Hiding stale client vHdzU2NSORVl with age 968916.2100000381 1693826957717 Sync.Engine.Clients INFO Hiding stale client tsmscxb1AoRP with age 1139848.7200000286 1693826957717 Sync.Engine.Clients INFO Hiding stale client pu16FBk4arnA with age 1225107.8399999142 1693826957717 Sync.Engine.Clients INFO Hiding stale client wTPczI1KkG_2 with age 1658183.0499999523 1693826957717 Sync.Engine.Clients INFO Hiding stale client 0wkRAmVrYobX with age 1744768.2599999905 1693826957717 Sync.Engine.Clients INFO Hiding stale client chEY30Uh2A4F with age 1747414.1100001335 1693826957717 Sync.Engine.Clients INFO Hiding stale client p0sa0n1wS_wP - in known stale clients list 1693826957717 Sync.Engine.Clients INFO Hiding stale client p0sa0n1wS_wP with age 1829384.3399999142 1693826957717 Sync.Engine.Clients INFO Hiding stale client H_C8HnXDLjC9 - in known stale clients list 1693826957717 Sync.Engine.Clients INFO Hiding stale client H_C8HnXDLjC9 with age 2091214.2599999905 1693826957717 Sync.Engine.Clients INFO Hiding stale client zEZOBD6faXo- - in known stale clients list 1693826957717 Sync.Engine.Clients INFO Hiding stale client zEZOBD6faXo- with age 2177510.440000057 1693826957717 Sync.Engine.Clients INFO Hiding stale client YeloDrE6-asP - in known stale clients list 1693826957717 Sync.Engine.Clients INFO Hiding stale client YeloDrE6-asP with age 2263726.0299999714 1693826957717 Sync.Engine.Clients INFO Hiding stale client rRRDf0Hkjx4K - in known stale clients list 1693826957717 Sync.Engine.Clients INFO Hiding stale client rRRDf0Hkjx4K with age 2694975.0799999237 1693826957717 Sync.Engine.Clients INFO Hiding stale client QQjR1jtkwez3 - in known stale clients list 1693826957717 Sync.Engine.Clients INFO Hiding stale client QQjR1jtkwez3 with age 2780456.25 1693826957717 Sync.Engine.Clients INFO Hiding stale client 7b_HYEFgzLkn - in known stale clients list 1693826957717 Sync.Engine.Clients INFO Hiding stale client 7b_HYEFgzLkn with age 2848150.0099999905 1693826957717 Sync.Engine.Clients INFO Hiding stale client 8oiNLePbG951 - in known stale clients list 1693826957717 Sync.Engine.Clients INFO Hiding stale client 8oiNLePbG951 with age 2848150.0099999905 1693826957717 Sync.Engine.Clients INFO Hiding stale client CxdcINZmahVu - in known stale clients list 1693826957717 Sync.Engine.Clients INFO Hiding stale client CxdcINZmahVu with age 2848150.0099999905 1693826957717 Sync.Engine.Clients INFO Hiding stale client DlHU8T_lleV7 - in known stale clients list 1693826957717 Sync.Engine.Clients INFO Hiding stale client DlHU8T_lleV7 with age 2848150.0099999905 1693826957717 Sync.Engine.Clients INFO Hiding stale client avIksd47v8Xq - in known stale clients list 1693826957717 Sync.Engine.Clients INFO Hiding stale client avIksd47v8Xq with age 2848150.0099999905 1693826957717 Sync.Engine.Clients INFO Hiding stale client eJZiki63xWeU - in known stale clients list 1693826957717 Sync.Engine.Clients INFO Hiding stale client eJZiki63xWeU with age 2848150.0099999905 1693826957717 Sync.Engine.Clients INFO Hiding stale client hkEl4-TRyZbx - in known stale clients list 1693826957717 Sync.Engine.Clients INFO Hiding stale client hkEl4-TRyZbx with age 2848150.0099999905 1693826957717 Sync.Engine.Clients INFO Hiding stale client iufPvZL-Oe9W - in known stale clients list 1693826957717 Sync.Engine.Clients INFO Hiding stale client iufPvZL-Oe9W with age 2848150.0099999905 1693826957717 Sync.Engine.Clients INFO Hiding stale client m1WDXRbssb6o - in known stale clients list 1693826957717 Sync.Engine.Clients INFO Hiding stale client m1WDXRbssb6o with age 2848150.0099999905 1693826957717 Sync.Engine.Clients INFO Hiding stale client qxRho8TPLMai - in known stale clients list 1693826957717 Sync.Engine.Clients INFO Hiding stale client qxRho8TPLMai with age 2848150.0099999905 1693826957717 Sync.Engine.Clients INFO Hiding stale client tvp7mH0CVBGc - in known stale clients list 1693826957717 Sync.Engine.Clients INFO Hiding stale client tvp7mH0CVBGc with age 2848150.0099999905 1693826957717 Sync.Engine.Clients INFO Hiding stale client uV_JFMzMGrk1 - in known stale clients list 1693826957717 Sync.Engine.Clients INFO Hiding stale client uV_JFMzMGrk1 with age 2848150.0099999905 1693826957717 Sync.Engine.Clients INFO Hiding stale client zHZoytljEWqH - in known stale clients list 1693826957717 Sync.Engine.Clients INFO Hiding stale client zHZoytljEWqH with age 2848150.0099999905 1693826957718 Sync.Engine.Clients INFO Uploading 1 outgoing records 1693826957719 Sync.Engine.Clients INFO Posting 1 records of 530 bytes with batch=true 1693826957719 FirefoxAccounts TRACE not checking freshness of profile as it remains recent 1693826957720 Sync.Collection DEBUG POST Length: 530 1693826957958 Sync.Collection DEBUG POST success 200 https://sync-1-us-west1-g.sync.services.mozilla.com/1.5/205628552/storage/clients?batch=true&commit=true 1693826957962 Sync.SyncScheduler DEBUG Client count: 0 -> 2 1693826957963 Sync.Synchronizer INFO Updating enabled engines: 2 clients. 1693826957964 Sync.Synchronizer INFO Syncing all enabled engines. 1693826957965 Sync.Engine.Prefs INFO Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled. 1693826957965 Sync.Engine.Prefs INFO Uploading 0 outgoing records 1693826958118 Sync.Engine.Passwords INFO Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled. 1693826958118 Sync.Engine.Passwords INFO Uploading 0 outgoing records 1693826958126 Sync.Engine.Tabs INFO Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled. 1693826958126 Sync.Engine.Tabs INFO Uploading 1 outgoing records 1693826958127 Sync.Engine.Tabs INFO Posting 1 records of 663 bytes with batch=true 1693826958127 FirefoxAccounts TRACE not checking freshness of profile as it remains recent 1693826958127 Sync.Collection DEBUG POST Length: 663 1693826958370 Sync.Collection DEBUG POST success 200 https://sync-1-us-west1-g.sync.services.mozilla.com/1.5/205628552/storage/tabs?batch=true&commit=true 1693826958385 Sync.Engine.Bookmarks DEBUG Checking if server sync ID n5ec7PFRKOJF matches existing 1693826958405 Sync.Engine.Bookmarks.Mirror INFO Sync ID changed from to n5ec7PFRKOJF; resetting mirror 1693826958416 Sync.Engine.Bookmarks DEBUG Bookmarks backup starting 1693826958430 Sync.Engine.Bookmarks DEBUG Bookmarks backup done 1693826958431 FirefoxAccounts TRACE not checking freshness of profile as it remains recent 1693826958733 Sync.Collection DEBUG GET success 200 https://sync-1-us-west1-g.sync.services.mozilla.com/1.5/205628552/storage/bookmarks?full=1&sort=oldest&limit=1000 1693826958871 Sync.Engine.Bookmarks INFO Records: 139 applied, 139 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled. 1693826958872 Sync.Engine.Bookmarks.Mirror DEBUG Merging bookmarks in Rust 1693826958873 Sync.Engine.Bookmarks.Mirror DEBUG Building local tree 1693826958875 Sync.Engine.Bookmarks.Mirror DEBUG Building remote tree 1693826958876 Sync.Engine.Bookmarks.Mirror DEBUG Building merged tree 1693826958876 Sync.Engine.Bookmarks.Mirror DEBUG Applying merged tree 1693826958876 Sync.Engine.Bookmarks.Mirror DEBUG Updating local items in Places 1693826958876 Sync.Engine.Bookmarks.Mirror DEBUG Cleaning up observer notifications left from last sync 1693826958876 Sync.Engine.Bookmarks.Mirror DEBUG Inserting Places for new items 1693826958877 Sync.Engine.Bookmarks.Mirror DEBUG Updating origins for new URLs 1693826958877 Sync.Engine.Bookmarks.Mirror DEBUG Staging apply remote item ops 1693826958879 Sync.Engine.Bookmarks.Mirror DEBUG Staging change GUID ops 1693826958879 Sync.Engine.Bookmarks.Mirror DEBUG Staging apply new local structure ops 1693826958879 Sync.Engine.Bookmarks.Mirror DEBUG Removing tombstones for revived items 1693826958879 Sync.Engine.Bookmarks.Mirror DEBUG Inserting new tombstones for non-syncable and invalid items 1693826958879 Sync.Engine.Bookmarks.Mirror DEBUG Removing local items 1693826958879 Sync.Engine.Bookmarks.Mirror DEBUG Changing GUIDs 1693826958879 Sync.Engine.Bookmarks.Mirror DEBUG Applying remote items 1693826958879 Sync.Engine.Bookmarks.Mirror DEBUG Recording item added notifications for new items 1693826958879 Sync.Engine.Bookmarks.Mirror DEBUG Recording item changed notifications for existing items 1693826958879 Sync.Engine.Bookmarks.Mirror DEBUG Removing old keywords 1693826958880 Sync.Engine.Bookmarks.Mirror DEBUG Removing old tags 1693826958881 Sync.Engine.Bookmarks.Mirror DEBUG Upserting new items 1693826958882 Sync.Engine.Bookmarks.Mirror DEBUG Flagging frecencies for recalculation 1693826958882 Sync.Engine.Bookmarks.Mirror DEBUG Inserting new keywords for new URLs 1693826958882 Sync.Engine.Bookmarks.Mirror DEBUG Inserting new tags for new URLs 1693826958884 Sync.Engine.Bookmarks.Mirror DEBUG Updating origins for changed URLs 1693826958884 Sync.Engine.Bookmarks.Mirror DEBUG Applying new local structure 1693826958884 Sync.Engine.Bookmarks.Mirror DEBUG Resetting change counters for items that shouldn't be uploaded 1693826958884 Sync.Engine.Bookmarks.Mirror DEBUG Bumping change counters for items that should be uploaded 1693826958884 Sync.Engine.Bookmarks.Mirror DEBUG Flagging applied remote items as merged 1693826958885 Sync.Engine.Bookmarks.Mirror DEBUG Staging items to upload 1693826958885 Sync.Engine.Bookmarks.Mirror DEBUG Cleaning up staged items left from last sync 1693826958885 Sync.Engine.Bookmarks.Mirror DEBUG Staging items with older local dates added 1693826958885 Sync.Engine.Bookmarks.Mirror DEBUG Staging remaining locally changed items for upload 1693826958885 Sync.Engine.Bookmarks.Mirror DEBUG Staging structure to upload 1693826958885 Sync.Engine.Bookmarks.Mirror DEBUG Staging tags to upload 1693826958885 Sync.Engine.Bookmarks.Mirror DEBUG Staging tombstones to upload 1693826958891 Sync.Engine.Bookmarks.Mirror DEBUG Merging bookmarks in Rust took 19.569ms 1693826958891 Sync.Engine.Bookmarks.Mirror DEBUG Notifying Places observers 1693826958898 Sync.Engine.Bookmarks.Mirror DEBUG Notifying Places observers took 6.607ms 1693826958898 Sync.Engine.Bookmarks.Mirror DEBUG Fetching records for local items to upload 1693826958899 Sync.Engine.Bookmarks.Mirror DEBUG Fetching records for local items to upload took 0.506ms 1693826958899 Sync.Engine.Bookmarks INFO Uploading 0 outgoing records 1693826958899 Sync.Engine.Bookmarks.BookmarkSyncUtils DEBUG pushChanges: Processed change records: {"weak":0,"skipped":0,"updated":0} 1693826958899 Sync.Engine.Addons DEBUG Refreshing reconciler state 1693826958899 Sync.AddonsReconciler INFO Refreshing global state from AddonManager. 1693826958900 Sync.AddonsReconciler DEBUG Rectifying state for addon Form Autofill (version=1.0.1, id=formautofill@mozilla.org) 1693826958900 Sync.AddonsReconciler DEBUG Adding change because add-on not present locally: formautofill@mozilla.org 1693826958900 Sync.AddonsReconciler INFO Change recorded for formautofill@mozilla.org 1693826958900 Sync.Engine.Addons.Tracker DEBUG changeListener invoked: 1 formautofill@mozilla.org 1693826958900 Sync.Engine.Addons.Store DEBUG formautofill@mozilla.org not syncable: vetoed by the addon manager. 1693826958900 Sync.Engine.Addons.Tracker DEBUG Ignoring change because add-on isn't syncable: formautofill@mozilla.org 1693826958900 Sync.AddonsReconciler DEBUG Rectifying state for addon Picture-In-Picture (version=1.0.0, id=pictureinpicture@mozilla.org) 1693826958900 Sync.AddonsReconciler DEBUG Adding change because add-on not present locally: pictureinpicture@mozilla.org 1693826958900 Sync.AddonsReconciler INFO Change recorded for pictureinpicture@mozilla.org 1693826958900 Sync.Engine.Addons.Tracker DEBUG changeListener invoked: 1 pictureinpicture@mozilla.org 1693826958900 Sync.Engine.Addons.Store DEBUG pictureinpicture@mozilla.org not syncable: vetoed by the addon manager. 1693826958900 Sync.Engine.Addons.Tracker DEBUG Ignoring change because add-on isn't syncable: pictureinpicture@mozilla.org 1693826958900 Sync.AddonsReconciler DEBUG Rectifying state for addon Firefox Screenshots (version=39.0.1, id=screenshots@mozilla.org) 1693826958900 Sync.AddonsReconciler DEBUG Adding change because add-on not present locally: screenshots@mozilla.org 1693826958900 Sync.AddonsReconciler INFO Change recorded for screenshots@mozilla.org 1693826958900 Sync.Engine.Addons.Tracker DEBUG changeListener invoked: 1 screenshots@mozilla.org 1693826958900 Sync.Engine.Addons.Store DEBUG screenshots@mozilla.org not syncable: vetoed by the addon manager. 1693826958900 Sync.Engine.Addons.Tracker DEBUG Ignoring change because add-on isn't syncable: screenshots@mozilla.org 1693826958900 Sync.AddonsReconciler DEBUG Rectifying state for addon WebCompat Reporter (version=1.5.1, id=webcompat-reporter@mozilla.org) 1693826958900 Sync.AddonsReconciler DEBUG Adding change because add-on not present locally: webcompat-reporter@mozilla.org 1693826958900 Sync.AddonsReconciler INFO Change recorded for webcompat-reporter@mozilla.org 1693826958900 Sync.Engine.Addons.Tracker DEBUG changeListener invoked: 1 webcompat-reporter@mozilla.org 1693826958900 Sync.Engine.Addons.Store DEBUG webcompat-reporter@mozilla.org not syncable: vetoed by the addon manager. 1693826958900 Sync.Engine.Addons.Tracker DEBUG Ignoring change because add-on isn't syncable: webcompat-reporter@mozilla.org 1693826958900 Sync.AddonsReconciler DEBUG Rectifying state for addon Web Compatibility Interventions (version=117.0.0, id=webcompat@mozilla.org) 1693826958900 Sync.AddonsReconciler DEBUG Adding change because add-on not present locally: webcompat@mozilla.org 1693826958900 Sync.AddonsReconciler INFO Change recorded for webcompat@mozilla.org 1693826958900 Sync.Engine.Addons.Tracker DEBUG changeListener invoked: 1 webcompat@mozilla.org 1693826958900 Sync.Engine.Addons.Store DEBUG webcompat@mozilla.org not syncable: vetoed by the addon manager. 1693826958900 Sync.Engine.Addons.Tracker DEBUG Ignoring change because add-on isn't syncable: webcompat@mozilla.org 1693826958901 Sync.AddonsReconciler DEBUG Rectifying state for addon System-Theme – automatisch (version=1.3, id=default-theme@mozilla.org) 1693826958901 Sync.AddonsReconciler DEBUG Adding change because add-on not present locally: default-theme@mozilla.org 1693826958901 Sync.AddonsReconciler INFO Change recorded for default-theme@mozilla.org 1693826958901 Sync.Engine.Addons.Tracker DEBUG changeListener invoked: 1 default-theme@mozilla.org 1693826958901 Sync.Engine.Addons.Store DEBUG default-theme@mozilla.org not syncable: not installed in profile. 1693826958901 Sync.Engine.Addons.Tracker DEBUG Ignoring change because add-on isn't syncable: default-theme@mozilla.org 1693826958901 Sync.AddonsReconciler DEBUG Rectifying state for addon Add-ons Search Detection (version=2.0.0, id=addons-search-detection@mozilla.com) 1693826958901 Sync.AddonsReconciler DEBUG Adding change because add-on not present locally: addons-search-detection@mozilla.com 1693826958901 Sync.AddonsReconciler INFO Change recorded for addons-search-detection@mozilla.com 1693826958901 Sync.Engine.Addons.Tracker DEBUG changeListener invoked: 1 addons-search-detection@mozilla.com 1693826958901 Sync.Engine.Addons.Store DEBUG addons-search-detection@mozilla.com not syncable: not installed in profile. 1693826958901 Sync.Engine.Addons.Tracker DEBUG Ignoring change because add-on isn't syncable: addons-search-detection@mozilla.com 1693826958901 Sync.AddonsReconciler DEBUG Rectifying state for addon Google (version=1.4, id=google@search.mozilla.org) 1693826958901 Sync.AddonsReconciler DEBUG Adding change because add-on not present locally: google@search.mozilla.org 1693826958901 Sync.AddonsReconciler INFO Change recorded for google@search.mozilla.org 1693826958901 Sync.Engine.Addons.Tracker DEBUG changeListener invoked: 1 google@search.mozilla.org 1693826958901 Sync.Engine.Addons.Store DEBUG google@search.mozilla.org not syncable: not installed in profile. 1693826958901 Sync.Engine.Addons.Tracker DEBUG Ignoring change because add-on isn't syncable: google@search.mozilla.org 1693826958901 Sync.AddonsReconciler DEBUG Rectifying state for addon LEO Eng-Deu (version=1.1, id=leo_ende_de@search.mozilla.org) 1693826958901 Sync.AddonsReconciler DEBUG Adding change because add-on not present locally: leo_ende_de@search.mozilla.org 1693826958901 Sync.AddonsReconciler INFO Change recorded for leo_ende_de@search.mozilla.org 1693826958901 Sync.Engine.Addons.Tracker DEBUG changeListener invoked: 1 leo_ende_de@search.mozilla.org 1693826958901 Sync.Engine.Addons.Store DEBUG leo_ende_de@search.mozilla.org not syncable: not installed in profile. 1693826958901 Sync.Engine.Addons.Tracker DEBUG Ignoring change because add-on isn't syncable: leo_ende_de@search.mozilla.org 1693826958901 Sync.AddonsReconciler DEBUG Rectifying state for addon Ecosia (version=1.2, id=ecosia@search.mozilla.org) 1693826958901 Sync.AddonsReconciler DEBUG Adding change because add-on not present locally: ecosia@search.mozilla.org 1693826958901 Sync.AddonsReconciler INFO Change recorded for ecosia@search.mozilla.org 1693826958901 Sync.Engine.Addons.Tracker DEBUG changeListener invoked: 1 ecosia@search.mozilla.org 1693826958901 Sync.Engine.Addons.Store DEBUG ecosia@search.mozilla.org not syncable: not installed in profile. 1693826958901 Sync.Engine.Addons.Tracker DEBUG Ignoring change because add-on isn't syncable: ecosia@search.mozilla.org 1693826958901 Sync.AddonsReconciler DEBUG Rectifying state for addon Wikipedia (de) (version=1.3, id=wikipedia@search.mozilla.org) 1693826958901 Sync.AddonsReconciler DEBUG Adding change because add-on not present locally: wikipedia@search.mozilla.org 1693826958901 Sync.AddonsReconciler INFO Change recorded for wikipedia@search.mozilla.org 1693826958901 Sync.Engine.Addons.Tracker DEBUG changeListener invoked: 1 wikipedia@search.mozilla.org 1693826958901 Sync.Engine.Addons.Store DEBUG wikipedia@search.mozilla.org not syncable: not installed in profile. 1693826958901 Sync.Engine.Addons.Tracker DEBUG Ignoring change because add-on isn't syncable: wikipedia@search.mozilla.org 1693826958901 Sync.AddonsReconciler DEBUG Rectifying state for addon Bing (version=1.6, id=bing@search.mozilla.org) 1693826958901 Sync.AddonsReconciler DEBUG Adding change because add-on not present locally: bing@search.mozilla.org 1693826958901 Sync.AddonsReconciler INFO Change recorded for bing@search.mozilla.org 1693826958901 Sync.Engine.Addons.Tracker DEBUG changeListener invoked: 1 bing@search.mozilla.org 1693826958901 Sync.Engine.Addons.Store DEBUG bing@search.mozilla.org not syncable: not installed in profile. 1693826958901 Sync.Engine.Addons.Tracker DEBUG Ignoring change because add-on isn't syncable: bing@search.mozilla.org 1693826958901 Sync.AddonsReconciler DEBUG Rectifying state for addon DuckDuckGo (version=1.4, id=ddg@search.mozilla.org) 1693826958901 Sync.AddonsReconciler DEBUG Adding change because add-on not present locally: ddg@search.mozilla.org 1693826958901 Sync.AddonsReconciler INFO Change recorded for ddg@search.mozilla.org 1693826958901 Sync.Engine.Addons.Tracker DEBUG changeListener invoked: 1 ddg@search.mozilla.org 1693826958901 Sync.Engine.Addons.Store DEBUG ddg@search.mozilla.org not syncable: not installed in profile. 1693826958901 Sync.Engine.Addons.Tracker DEBUG Ignoring change because add-on isn't syncable: ddg@search.mozilla.org 1693826958901 Sync.AddonsReconciler DEBUG Rectifying state for addon eBay (version=1.4, id=ebay@search.mozilla.org) 1693826958901 Sync.AddonsReconciler DEBUG Adding change because add-on not present locally: ebay@search.mozilla.org 1693826958901 Sync.AddonsReconciler INFO Change recorded for ebay@search.mozilla.org 1693826958901 Sync.Engine.Addons.Tracker DEBUG changeListener invoked: 1 ebay@search.mozilla.org 1693826958901 Sync.Engine.Addons.Store DEBUG ebay@search.mozilla.org not syncable: not installed in profile. 1693826958901 Sync.Engine.Addons.Tracker DEBUG Ignoring change because add-on isn't syncable: ebay@search.mozilla.org 1693826958901 Sync.AddonsReconciler DEBUG Rectifying state for addon Hell (version=1.2, id=firefox-compact-light@mozilla.org) 1693826958901 Sync.AddonsReconciler DEBUG Adding change because add-on not present locally: firefox-compact-light@mozilla.org 1693826958901 Sync.AddonsReconciler INFO Change recorded for firefox-compact-light@mozilla.org 1693826958901 Sync.Engine.Addons.Tracker DEBUG changeListener invoked: 1 firefox-compact-light@mozilla.org 1693826958901 Sync.Engine.Addons.Store DEBUG firefox-compact-light@mozilla.org not syncable: not installed in profile. 1693826958901 Sync.Engine.Addons.Tracker DEBUG Ignoring change because add-on isn't syncable: firefox-compact-light@mozilla.org 1693826958901 Sync.AddonsReconciler DEBUG Rectifying state for addon Dunkel (version=1.2, id=firefox-compact-dark@mozilla.org) 1693826958901 Sync.AddonsReconciler DEBUG Adding change because add-on not present locally: firefox-compact-dark@mozilla.org 1693826958901 Sync.AddonsReconciler INFO Change recorded for firefox-compact-dark@mozilla.org 1693826958901 Sync.Engine.Addons.Tracker DEBUG changeListener invoked: 1 firefox-compact-dark@mozilla.org 1693826958901 Sync.Engine.Addons.Store DEBUG firefox-compact-dark@mozilla.org not syncable: not installed in profile. 1693826958901 Sync.Engine.Addons.Tracker DEBUG Ignoring change because add-on isn't syncable: firefox-compact-dark@mozilla.org 1693826958901 Sync.AddonsReconciler DEBUG Rectifying state for addon Firefox Alpenglow (version=1.4, id=firefox-alpenglow@mozilla.org) 1693826958902 Sync.AddonsReconciler DEBUG Adding change because add-on not present locally: firefox-alpenglow@mozilla.org 1693826958902 Sync.AddonsReconciler INFO Change recorded for firefox-alpenglow@mozilla.org 1693826958902 Sync.Engine.Addons.Tracker DEBUG changeListener invoked: 1 firefox-alpenglow@mozilla.org 1693826958902 Sync.Engine.Addons.Store DEBUG firefox-alpenglow@mozilla.org not syncable: not installed in profile. 1693826958902 Sync.Engine.Addons.Tracker DEBUG Ignoring change because add-on isn't syncable: firefox-alpenglow@mozilla.org 1693826958902 Sync.AddonsReconciler DEBUG Rectifying state for addon Amazon.de (version=1.12, id=amazon@search.mozilla.org) 1693826958902 Sync.AddonsReconciler DEBUG Adding change because add-on not present locally: amazon@search.mozilla.org 1693826958902 Sync.AddonsReconciler INFO Change recorded for amazon@search.mozilla.org 1693826958902 Sync.Engine.Addons.Tracker DEBUG changeListener invoked: 1 amazon@search.mozilla.org 1693826958902 Sync.Engine.Addons.Store DEBUG amazon@search.mozilla.org not syncable: not installed in profile. 1693826958902 Sync.Engine.Addons.Tracker DEBUG Ignoring change because add-on isn't syncable: amazon@search.mozilla.org 1693826958902 Sync.AddonsReconciler DEBUG Rectifying state for addon OpenH264-Videocodec zur Verfügung gestellt von Cisco Systems, Inc. (version=2.3.2, id=gmp-gmpopenh264) 1693826958902 Sync.AddonsReconciler DEBUG Adding change because add-on not present locally: gmp-gmpopenh264 1693826958902 Sync.AddonsReconciler INFO Change recorded for gmp-gmpopenh264 1693826958902 Sync.Engine.Addons.Tracker DEBUG changeListener invoked: 1 gmp-gmpopenh264 1693826958902 Sync.Engine.Addons.Store DEBUG gmp-gmpopenh264 not syncable: type not in allowed list: plugin 1693826958902 Sync.Engine.Addons.Tracker DEBUG Ignoring change because add-on isn't syncable: gmp-gmpopenh264 1693826958902 Sync.AddonsReconciler DEBUG Rectifying state for addon Widevine Content Decryption Module zur Verfügung gestellt von Google Inc. (version=4.10.2557.0, id=gmp-widevinecdm) 1693826958902 Sync.AddonsReconciler DEBUG Adding change because add-on not present locally: gmp-widevinecdm 1693826958902 Sync.AddonsReconciler INFO Change recorded for gmp-widevinecdm 1693826958902 Sync.Engine.Addons.Tracker DEBUG changeListener invoked: 1 gmp-widevinecdm 1693826958902 Sync.Engine.Addons.Store DEBUG gmp-widevinecdm not syncable: type not in allowed list: plugin 1693826958902 Sync.Engine.Addons.Tracker DEBUG Ignoring change because add-on isn't syncable: gmp-widevinecdm 1693826958902 Sync.AddonsReconciler INFO Saving reconciler state to file: addonsreconciler 1693826958903 Sync.Engine.Addons DEBUG First sync, uploading all items 1693826958903 Sync.Engine.Addons.Store DEBUG formautofill@mozilla.org not syncable: vetoed by the addon manager. 1693826958903 Sync.Engine.Addons.Store DEBUG pictureinpicture@mozilla.org not syncable: vetoed by the addon manager. 1693826958903 Sync.Engine.Addons.Store DEBUG screenshots@mozilla.org not syncable: vetoed by the addon manager. 1693826958903 Sync.Engine.Addons.Store DEBUG webcompat-reporter@mozilla.org not syncable: vetoed by the addon manager. 1693826958903 Sync.Engine.Addons.Store DEBUG webcompat@mozilla.org not syncable: vetoed by the addon manager. 1693826958903 Sync.Engine.Addons.Store DEBUG default-theme@mozilla.org not syncable: not installed in profile. 1693826958903 Sync.Engine.Addons.Store DEBUG addons-search-detection@mozilla.com not syncable: not installed in profile. 1693826958903 Sync.Engine.Addons.Store DEBUG google@search.mozilla.org not syncable: not installed in profile. 1693826958903 Sync.Engine.Addons.Store DEBUG leo_ende_de@search.mozilla.org not syncable: not installed in profile. 1693826958903 Sync.Engine.Addons.Store DEBUG ecosia@search.mozilla.org not syncable: not installed in profile. 1693826958903 Sync.Engine.Addons.Store DEBUG wikipedia@search.mozilla.org not syncable: not installed in profile. 1693826958903 Sync.Engine.Addons.Store DEBUG bing@search.mozilla.org not syncable: not installed in profile. 1693826958903 Sync.Engine.Addons.Store DEBUG ddg@search.mozilla.org not syncable: not installed in profile. 1693826958903 Sync.Engine.Addons.Store DEBUG ebay@search.mozilla.org not syncable: not installed in profile. 1693826958903 Sync.Engine.Addons.Store DEBUG firefox-compact-light@mozilla.org not syncable: not installed in profile. 1693826958903 Sync.Engine.Addons.Store DEBUG firefox-compact-dark@mozilla.org not syncable: not installed in profile. 1693826958903 Sync.Engine.Addons.Store DEBUG firefox-alpenglow@mozilla.org not syncable: not installed in profile. 1693826958903 Sync.Engine.Addons.Store DEBUG amazon@search.mozilla.org not syncable: not installed in profile. 1693826958903 Sync.Engine.Addons.Store DEBUG gmp-gmpopenh264 not syncable: type not in allowed list: plugin 1693826958903 Sync.Engine.Addons.Store DEBUG gmp-widevinecdm not syncable: type not in allowed list: plugin 1693826958903 Sync.Engine.Addons INFO Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled. 1693826958904 Sync.Engine.Addons INFO Uploading 0 outgoing records 1693826958904 Sync.Engine.CreditCards DEBUG First sync, uploading all items 1693826958904 Sync.Engine.CreditCards INFO Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled. 1693826958904 Sync.Engine.CreditCards INFO Uploading 0 outgoing records 1693826958905 Sync.Engine.Forms INFO Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled. 1693826958905 Sync.Engine.Forms INFO Uploading 0 outgoing records 1693826958905 Sync.Engine.History DEBUG Checking if server sync ID ZQnkzDQzc_5H matches existing 1693826958907 Sync.Engine.History INFO Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled. 1693826958907 Sync.Engine.History INFO Uploading 4 outgoing records 1693826958911 Sync.Engine.History INFO Posting 4 records of 2233 bytes with batch=true 1693826958911 FirefoxAccounts TRACE not checking freshness of profile as it remains recent 1693826958912 Sync.Collection DEBUG POST Length: 2233 1693826959162 Sync.Collection DEBUG POST success 200 https://sync-1-us-west1-g.sync.services.mozilla.com/1.5/205628552/storage/history?batch=true&commit=true 1693826959176 Sync.Engine.Extension-Storage INFO Records: 0 applied, 0 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled. 1693826959176 Sync.Engine.Extension-Storage INFO Uploading 0 outgoing records 1693826959177 Sync.Doctor INFO Skipping check of prefs - disabled via preferences 1693826959177 Sync.Doctor INFO Skipping check of passwords - disabled via preferences 1693826959177 Sync.Doctor INFO Skipping check of tabs - disabled via preferences 1693826959177 Sync.Doctor INFO Skipping check of bookmarks - disabled via preferences 1693826959177 Sync.Doctor INFO Skipping check of addons - disabled via preferences 1693826959177 Sync.Doctor INFO Skipping check of creditcards - disabled via preferences 1693826959177 Sync.Doctor INFO Skipping check of forms - disabled via preferences 1693826959177 Sync.Doctor INFO Skipping check of history - disabled via preferences 1693826959177 Sync.Doctor INFO Skipping check of extension-storage - disabled via preferences 1693826959177 Sync.Doctor INFO Skipping validation: no engines qualify 1693826959178 Sync.Status DEBUG Status.sync: success.sync => success.sync 1693826959178 Sync.Status DEBUG Status.service: success.status_ok => success.status_ok 1693826959178 Sync.Synchronizer INFO Sync completed at 2023-09-04 13:29:19 after 2.15 secs. 1693826959178 Sync.Declined DEBUG Handling remote declined: [] 1693826959178 Sync.Declined DEBUG Handling local declined: [] 1693826959178 Sync.Declined DEBUG Declined changed? false 1693826959178 Sync.Service INFO No change to declined engines. Not reuploading meta/global. 1693826959178 Sync.SyncScheduler DEBUG Next sync in 90000 ms. (why=schedule)