401 unauthorized error

[witchent]

Hi everyone,

I set up this project and try to get it to work. But after logging in my firefox tells me that it is disconnected. Server logs are of no use (not even with level debug, which does not seem to do anything), and in firefox I am getting the attached sync-log.
I think the only important part is the 401 error, but I cannot figure out why it happens. Anyone got any idea?

1744638118609	Sync.LogManager	DEBUG	Flushing file log
1744638118615	FirefoxAccounts	TRACE	finished write of json user data - took: 9
1744638118615	FirefoxAccounts	DEBUG	writing secure storage: ["scopedKeys"]
1744638118615	FirefoxAccounts	TRACE	starting write of user data to the login manager
1744638118617	FirefoxAccounts	TRACE	finished write of user data to the login manager
1744638118622	Sync.LogManager	DEBUG	Log cleanup threshold time: 1743774118622
1744638118623	Sync.LogManager	DEBUG	Done deleting files.
1744638118790	Services.Common.RESTRequest	DEBUG	POST https://api.accounts.firefox.com/v1/oauth/destroy 200
1744638118790	Hawk	DEBUG	(Response) /oauth/destroy: code: 200 - Status text: 
1744638118790	Hawk	DEBUG	Clock offset vs https://api.accounts.firefox.com/v1: -790
1744638119347	Sync.Engine.Tabs.Tracker	DEBUG	Detected a tab change, but conditions aren't met for a quick write - bumping score
1744638119357	Sync.Engine.Tabs.Tracker	DEBUG	Detected a tab change, but conditions aren't met for a quick write or a score bump
1744638119427	Sync.Engine.Tabs.Tracker	DEBUG	Detected a tab change, but conditions aren't met for a quick write or a score bump
1744638119518	Sync.Engine.Tabs.Tracker	DEBUG	Detected a tab change, but conditions aren't met for a quick write or a score bump
1744638119520	Sync.Engine.Tabs.Tracker	DEBUG	Detected a tab change, but conditions aren't met for a quick write or a score bump
1744638119533	FirefoxAccounts	TRACE	not checking freshness of profile as it remains recent
1744638119533	FirefoxAccounts	TRACE	not checking freshness of profile as it remains recent
1744638119533	FirefoxAccounts	TRACE	not checking freshness of profile as it remains recent
1744638119533	FirefoxAccounts	TRACE	not checking freshness of profile as it remains recent
1744638121374	FirefoxAccounts	TRACE	not checking freshness of profile as it remains recent
1744638121689	Sync.Engine.Tabs.Tracker	DEBUG	Detected a tab change, but conditions aren't met for a quick write or a score bump
1744638122282	FirefoxAccounts	DEBUG	FxAccountsWebChannel message received: fxaccounts:fxa_status
1744638122282	FirefoxAccounts	TRACE	_receiveMessage for command fxaccounts:fxa_status
1744638122282	FirefoxAccounts	DEBUG	fxa_status received
1744638122282	FirefoxAccounts	DEBUG	fxa status ok=true - private=false, service=sync, context=oauth_webchannel_v1, pairing=false
1744638122588	Sync.Engine.Tabs.Tracker	DEBUG	Detected a tab change, but conditions aren't met for a quick write or a score bump
1744638122604	Sync.Engine.Tabs.Tracker	DEBUG	Detected a tab change, but conditions aren't met for a quick write or a score bump
1744638122911	Sync.Engine.Tabs.Tracker	DEBUG	Detected a tab change, but conditions aren't met for a quick write or a score bump
1744638124410	FirefoxAccounts	DEBUG	FxAccountsWebChannel message received: fxaccounts:fxa_status
1744638124410	FirefoxAccounts	TRACE	_receiveMessage for command fxaccounts:fxa_status
1744638124410	FirefoxAccounts	DEBUG	fxa_status received
1744638124410	FirefoxAccounts	DEBUG	fxa status ok=true - private=false, service=sync, context=oauth_webchannel_v1, pairing=false
1744638125946	FirefoxAccounts	DEBUG	FxAccountsWebChannel message received: fxaccounts:can_link_account
1744638125946	FirefoxAccounts	TRACE	_receiveMessage for command fxaccounts:can_link_account
1744638127198	FirefoxAccounts	DEBUG	FxAccountsWebChannel message received: fxaccounts:login
1744638127198	FirefoxAccounts	TRACE	_receiveMessage for command fxaccounts:login
1744638127198	FirefoxAccounts	TRACE	not checking freshness of profile as it remains recent
1744638127199	FirefoxAccounts	DEBUG	Webchannel is updating the info for an already logged in user.
1744638127199	FirefoxAccounts	DEBUG	storing info for services sync
1744638127201	FirefoxAccounts	DEBUG	setSignedInUser - aborting any existing flows
1744638127201	Sync.Engine.Clients.Tracker	DEBUG	client.name preference changed
1744638127201	FirefoxAccounts	DEBUG	Unsubscribing from FxA push.
1744638127201	FirefoxAccounts	TRACE	FxAccountsPushService unsubscribe
1744638127294	Sync.Engine.Tabs.Tracker	DEBUG	Detected a tab change, but conditions aren't met for a quick write or a score bump
1744638127389	FirefoxAccounts	DEBUG	FxAccountsPushService unsubscribed
1744638127389	FirefoxAccounts	DEBUG	Destroying session and device.
1744638127390	Services.Common.RESTRequest	DEBUG	POST request to https://api.accounts.firefox.com/v1/session/destroy?service=sync
1744638127391	Services.Common.RESTRequest	DEBUG	POST Length: 2
1744638127594	Services.Common.RESTRequest	DEBUG	POST https://api.accounts.firefox.com/v1/session/destroy?service=sync 200
1744638127594	Hawk	DEBUG	(Response) /session/destroy?service=sync: code: 200 - Status text: 
1744638127594	Hawk	DEBUG	Clock offset vs https://api.accounts.firefox.com/v1: -594
1744638127594	FirefoxAccounts	DEBUG	Destroying all OAuth tokens.
1744638127595	Services.Common.RESTRequest	DEBUG	POST request to https://api.accounts.firefox.com/v1/oauth/destroy
1744638127595	Services.Common.RESTRequest	DEBUG	POST Length: 900
1744638127766	Services.Common.RESTRequest	DEBUG	POST https://api.accounts.firefox.com/v1/oauth/destroy 200
1744638127766	Hawk	DEBUG	(Response) /oauth/destroy: code: 200 - Status text: 
1744638127766	Hawk	DEBUG	Clock offset vs https://api.accounts.firefox.com/v1: -766
1744638127767	FirefoxAccounts	DEBUG	removing account data
1744638127767	FirefoxAccounts	TRACE	starting write of json user data: null
1744638127768	FirefoxAccounts	TRACE	finished write of json user data - took: 1
1744638127772	FirefoxAccounts	TRACE	storage set finished clearing account data
1744638127772	FirefoxAccounts	DEBUG	account data reset
1744638127772	FirefoxAccounts	TRACE	StorageManager finalizing
1744638127772	FirefoxAccounts	TRACE	StorageManager finalized
1744638127772	FirefoxAccounts	TRACE	initializing new storage manager
1744638127772	FirefoxAccounts	DEBUG	writing plain storage: ["email","sessionToken","uid","verified","requestedServices"]
1744638127772	FirefoxAccounts	TRACE	starting write of json user data: ["email","sessionToken","uid","verified","requestedServices"]
1744638127773	FirefoxAccounts	TRACE	finished write of json user data - took: 1
1744638127773	FirefoxAccounts	DEBUG	writing secure storage: []
1744638127773	FirefoxAccounts	TRACE	starting write of user data to the login manager
1744638127777	FirefoxAccounts	TRACE	finished write of user data to the login manager
1744638127777	FirefoxAccounts	TRACE	initializing of new storage manager done
1744638127777	FirefoxAccounts	DEBUG	Notifying observers of fxaccounts:onlogin
1744638127777	Sync.SyncAuthManager	DEBUG	observed fxaccounts:onlogin
1744638127777	Sync.SyncAuthManager	INFO	Sync has been connected to a logged in user
1744638127778	FirefoxAccounts	DEBUG	FxAccountsProfileClient: Initialized
1744638127778	FirefoxAccounts	TRACE	FxAccountsPush registerPushEndpoint
1744638127778	FirefoxAccounts	DEBUG	FxAccountsProfileClient: Requested profile
1744638127778	FirefoxAccounts	DEBUG	getOAuthToken enter
1744638127778	Sync.SyncAuthManager	INFO	The user is not verified
1744638127784	Services.Common.RESTRequest	DEBUG	POST request to https://api.accounts.firefox.com/v1/oauth/token
1744638127784	Services.Common.RESTRequest	DEBUG	POST Length: 81
1744638127955	FirefoxAccounts	DEBUG	FxAccountsPush got subscription
1744638127957	FirefoxAccounts	TRACE	Command queue observer created
1744638127957	FirefoxAccounts	TRACE	Getting command keys: https://identity.mozilla.com/cmd/open-uri
1744638127957	Sync.Engine.Clients.Tracker	DEBUG	client.name preference changed
1744638127957	FirefoxAccounts	INFO	Generating and persisting encrypted key (false, false)
1744638127957	FirefoxAccounts	INFO	Can't get keys; no key material or tokens available
1744638127957	FirefoxAccounts	INFO	Can't fetch keys, so unable to determine command keys
1744638127957	FirefoxAccounts	TRACE	Getting command keys: https://identity.mozilla.com/cmd/close-uri/v1
1744638127957	FirefoxAccounts	INFO	Generating and persisting encrypted key (false, false)
1744638127958	FirefoxAccounts	INFO	Can't get keys; no key material or tokens available
1744638127958	FirefoxAccounts	INFO	Can't fetch keys, so unable to determine command keys
1744638127958	FirefoxAccounts	INFO	registering with available commands: []
1744638127958	FirefoxAccounts	DEBUG	registering new device details
1744638127960	Services.Common.RESTRequest	DEBUG	POST request to https://api.accounts.firefox.com/v1/account/device
1744638127960	Services.Common.RESTRequest	DEBUG	POST Length: 437
1744638128031	Services.Common.RESTRequest	DEBUG	POST https://api.accounts.firefox.com/v1/oauth/token 200
1744638128032	Hawk	DEBUG	(Response) /oauth/token: code: 200 - Status text: 
1744638128032	Hawk	DEBUG	Clock offset vs https://api.accounts.firefox.com/v1: -1032
1744638128032	FirefoxAccounts	DEBUG	_updateAccountData with items: ["oauthTokens"]
1744638128032	FirefoxAccounts	DEBUG	writing plain storage: ["email","sessionToken","uid","verified","requestedServices","oauthTokens"]
1744638128032	FirefoxAccounts	TRACE	starting write of json user data: ["email","sessionToken","uid","verified","requestedServices","oauthTokens"]
1744638128033	Services.Common.RESTRequest	DEBUG	GET request to https://profile.accounts.firefox.com/v1/profile
1744638128034	FirefoxAccounts	TRACE	finished write of json user data - took: 2
1744638128034	FirefoxAccounts	DEBUG	writing secure storage: []
1744638128034	FirefoxAccounts	TRACE	starting write of user data to the login manager
1744638128040	FirefoxAccounts	TRACE	finished write of user data to the login manager
1744638128178	Services.Common.RESTRequest	DEBUG	POST https://api.accounts.firefox.com/v1/account/device 200
1744638128178	Hawk	DEBUG	(Response) /account/device: code: 200 - Status text: 
1744638128178	Hawk	DEBUG	Clock offset vs https://api.accounts.firefox.com/v1: -178
1744638128178	FirefoxAccounts	DEBUG	_updateAccountData with items: ["device"]
1744638128178	FirefoxAccounts	DEBUG	writing plain storage: ["email","sessionToken","uid","verified","requestedServices","oauthTokens","device"]
1744638128178	FirefoxAccounts	TRACE	starting write of json user data: ["email","sessionToken","uid","verified","requestedServices","oauthTokens","device"]
1744638128179	FirefoxAccounts	DEBUG	Webchannel finished logging a user in.
1744638128180	FirefoxAccounts	TRACE	finished write of json user data - took: 2
1744638128180	FirefoxAccounts	DEBUG	writing secure storage: []
1744638128180	FirefoxAccounts	TRACE	starting write of user data to the login manager
1744638128184	FirefoxAccounts	TRACE	finished write of user data to the login manager
1744638128243	Services.Common.RESTRequest	DEBUG	GET https://profile.accounts.firefox.com/v1/profile 200
1744638128243	FirefoxAccounts	DEBUG	_updateAccountData with items: ["profileCache"]
1744638128244	FirefoxAccounts	DEBUG	writing plain storage: ["email","sessionToken","uid","verified","requestedServices","oauthTokens","device","profileCache"]
1744638128244	FirefoxAccounts	TRACE	starting write of json user data: ["email","sessionToken","uid","verified","requestedServices","oauthTokens","device","profileCache"]
1744638128244	FirefoxAccounts	DEBUG	notifying profile changed for user 95425aca94a8465fa883249e675a7130
1744638128244	FirefoxAccounts	TRACE	not checking freshness of profile as it remains recent
1744638128267	Sync.Engine.Tabs.Tracker	DEBUG	Detected a tab change, but conditions aren't met for a quick write or a score bump
1744638128286	FirefoxAccounts	TRACE	finished write of json user data - took: 42
1744638128286	FirefoxAccounts	DEBUG	writing secure storage: []
1744638128286	FirefoxAccounts	TRACE	starting write of user data to the login manager
1744638128288	FirefoxAccounts	TRACE	finished write of user data to the login manager
1744638129037	FirefoxAccounts	DEBUG	FxAccountsWebChannel message received: fxaccounts:oauth_login
1744638129037	FirefoxAccounts	TRACE	_receiveMessage for command fxaccounts:oauth_login
1744638129037	FirefoxAccounts	DEBUG	Webchannel is completing the oauth flow
1744638129054	Services.Common.RESTRequest	DEBUG	POST request to https://api.accounts.firefox.com/v1/oauth/token
1744638129055	Services.Common.RESTRequest	DEBUG	POST Length: 202
1744638129303	Services.Common.RESTRequest	DEBUG	POST https://api.accounts.firefox.com/v1/oauth/token 200
1744638129303	Hawk	DEBUG	(Response) /oauth/token: code: 200 - Status text: 
1744638129303	Hawk	DEBUG	Clock offset vs https://api.accounts.firefox.com/v1: -303
1744638129310	Services.Common.RESTRequest	DEBUG	POST request to https://api.accounts.firefox.com/v1/oauth/destroy
1744638129310	Services.Common.RESTRequest	DEBUG	POST Length: 107
1744638129540	Services.Common.RESTRequest	DEBUG	POST https://api.accounts.firefox.com/v1/oauth/destroy 200
1744638129540	Hawk	DEBUG	(Response) /oauth/destroy: code: 200 - Status text: 
1744638129540	Hawk	DEBUG	Clock offset vs https://api.accounts.firefox.com/v1: -540
1744638129541	FirefoxAccounts	DEBUG	_updateAccountData with items: ["scopedKeys"]
1744638129541	FirefoxAccounts	DEBUG	writing plain storage: ["email","sessionToken","uid","verified","requestedServices","oauthTokens","device","profileCache"]
1744638129541	FirefoxAccounts	TRACE	starting write of json user data: ["email","sessionToken","uid","verified","requestedServices","oauthTokens","device","profileCache"]
1744638129541	FirefoxAccounts	DEBUG	services requested are sync
1744638129541	FirefoxAccounts	DEBUG	Did not receive any engine selection information
1744638129541	FirefoxAccounts	DEBUG	Webchannel is enabling sync
1744638129541	FirefoxAccounts	TRACE	not checking freshness of profile as it remains recent
1744638129541	Sync.Service	INFO	Configuring sync with current FxA user
1744638129541	Sync.SyncAuthManager	DEBUG	observed weave:connected
1744638129542	Sync.SyncAuthManager	INFO	Sync has been connected to a logged in user
1744638129542	FirefoxAccounts	DEBUG	updateUserAccountData called with fields: ["uid","requestedServices"]
1744638129542	FirefoxAccounts	DEBUG	_updateAccountData with items: ["requestedServices"]
1744638129542	FirefoxAccounts	TRACE	not checking freshness of profile as it remains recent
1744638129542	FirefoxAccounts	TRACE	not checking freshness of profile as it remains recent
1744638129542	Sync.SyncAuthManager	INFO	The user became verified
1744638129542	Sync.Status	DEBUG	Status.login: error.login.reason.account => success.login
1744638129542	Sync.Status	DEBUG	Status.service: error.sync.failed => success.status_ok
1744638129542	Sync.SyncAuthManager	INFO	Doing initial sync actions
1744638129543	Sync.Service	DEBUG	User-Agent: Firefox/136.0.4 (Linux x86_64) FxSync/1.138.0.20250326231000.desktop
1744638129543	Sync.Service	INFO	Starting sync at 2025-04-14 15:42:09 in browser session KYRbYndpZBBi
1744638129543	Sync.SyncScheduler	DEBUG	Clearing sync triggers and the global score.
1744638129545	Sync.Status	INFO	Resetting Status.
1744638129545	Sync.Status	DEBUG	Status.service: success.status_ok => success.status_ok
1744638129546	FirefoxAccounts	DEBUG	Notifying observers of fxaccounts:onverified
1744638129572	Sync.SyncAuthManager	DEBUG	observed fxaccounts:onverified
1744638129572	Sync.SyncAuthManager	INFO	The user became verified
1744638129572	Sync.Status	DEBUG	Status.login: success.login => success.login
1744638129572	Sync.Status	DEBUG	Status.service: success.status_ok => success.status_ok
1744638129572	Sync.Service	DEBUG	User-Agent: Firefox/136.0.4 (Linux x86_64) FxSync/1.138.0.20250326231000.desktop
1744638129573	Sync.Service	INFO	Starting sync at 2025-04-14 15:42:09 in browser session KYRbYndpZBBi
1744638129573	FirefoxAccounts	DEBUG	Webchannel completed oauth flows
1744638129573	FirefoxAccounts	TRACE	Getting command keys: https://identity.mozilla.com/cmd/open-uri
1744638129574	FirefoxAccounts	INFO	fetching updated device list
1744638129575	Sync.Service	DEBUG	Exception calling anonymous function: LockException: Could not acquire lock. Label: "service.js: sync".(resource://services-sync/util.sys.mjs:43:5) JS Stack trace: LockException@util.sys.mjs:43:5
throwLockException@util.sys.mjs:127:11
WrappedLock@util.sys.mjs:141:15
_lockedSync@service.sys.mjs:1368:6
sync/<@service.sys.mjs:1337:18
WrappedCatch@util.sys.mjs:112:27
sync@service.sys.mjs:1338:7
1744638129575	Sync.Service	INFO	Cannot start sync: already syncing?
1744638129575	FirefoxAccounts	TRACE	not checking freshness of profile as it remains recent
1744638129575	FirefoxAccounts	TRACE	not checking freshness of profile as it remains recent
1744638129575	FirefoxAccounts	INFO	Generating and persisting encrypted key (false, false)
1744638129575	Sync.SyncAuthManager	INFO	Getting sync key
1744638129576	FirefoxAccounts	INFO	Already fetching device list, return existing promise
1744638129576	FirefoxAccounts	INFO	Could not find command keys, generating them
1744638129576	FirefoxAccounts	DEBUG	getOAuthToken enter
1744638129598	FirefoxAccounts	TRACE	finished write of json user data - took: 57
1744638129598	FirefoxAccounts	DEBUG	writing secure storage: ["scopedKeys"]
1744638129598	FirefoxAccounts	TRACE	starting write of user data to the login manager
1744638129601	FirefoxAccounts	TRACE	finished write of user data to the login manager
1744638129601	FirefoxAccounts	DEBUG	writing plain storage: ["email","sessionToken","uid","verified","oauthTokens","device","profileCache"]
1744638129601	FirefoxAccounts	TRACE	starting write of json user data: ["email","sessionToken","uid","verified","oauthTokens","device","profileCache"]
1744638129604	Services.Common.RESTRequest	DEBUG	GET request to https://api.accounts.firefox.com/v1/account/devices?filterIdleDevicesTimestamp=1742823729575
1744638129608	FirefoxAccounts	TRACE	writing to sendTabKeys for command https://identity.mozilla.com/cmd/open-uri
1744638129608	FirefoxAccounts	DEBUG	_updateAccountData with items: ["device"]
1744638129609	Sync.BulkKeyBundle	INFO	BulkKeyBundle being created for undefined
1744638129611	Services.Common.RESTRequest	DEBUG	POST request to https://api.accounts.firefox.com/v1/oauth/token
1744638129611	Services.Common.RESTRequest	DEBUG	POST Length: 127
1744638129612	FirefoxAccounts	TRACE	finished write of json user data - took: 11
1744638129612	FirefoxAccounts	DEBUG	writing secure storage: ["scopedKeys"]
1744638129612	FirefoxAccounts	TRACE	starting write of user data to the login manager
1744638129614	FirefoxAccounts	TRACE	finished write of user data to the login manager
1744638129614	FirefoxAccounts	DEBUG	writing plain storage: ["email","sessionToken","uid","verified","oauthTokens","device","profileCache"]
1744638129614	FirefoxAccounts	TRACE	starting write of json user data: ["email","sessionToken","uid","verified","oauthTokens","device","profileCache"]
1744638129615	FirefoxAccounts	DEBUG	_updateAccountData with items: ["encryptedSendTabKeys"]
1744638129615	FirefoxAccounts	TRACE	Getting command keys: https://identity.mozilla.com/cmd/close-uri/v1
1744638129615	FirefoxAccounts	INFO	Generating and persisting encrypted key (false, false)
1744638129615	FirefoxAccounts	INFO	Could not find command keys, generating them
1744638129616	FirefoxAccounts	TRACE	finished write of json user data - took: 2
1744638129616	FirefoxAccounts	DEBUG	writing secure storage: ["scopedKeys"]
1744638129616	FirefoxAccounts	TRACE	starting write of user data to the login manager
1744638129618	FirefoxAccounts	TRACE	finished write of user data to the login manager
1744638129618	FirefoxAccounts	DEBUG	writing plain storage: ["email","sessionToken","uid","verified","oauthTokens","device","profileCache","encryptedSendTabKeys"]
1744638129618	FirefoxAccounts	TRACE	starting write of json user data: ["email","sessionToken","uid","verified","oauthTokens","device","profileCache","encryptedSendTabKeys"]
1744638129619	FirefoxAccounts	TRACE	writing to closeTabKeys for command https://identity.mozilla.com/cmd/close-uri/v1
1744638129619	FirefoxAccounts	DEBUG	_updateAccountData with items: ["device"]
1744638129619	Sync.BulkKeyBundle	INFO	BulkKeyBundle being created for undefined
1744638129620	FirefoxAccounts	TRACE	finished write of json user data - took: 2
1744638129620	FirefoxAccounts	DEBUG	writing secure storage: ["scopedKeys"]
1744638129620	FirefoxAccounts	TRACE	starting write of user data to the login manager
1744638129623	FirefoxAccounts	TRACE	finished write of user data to the login manager
1744638129623	FirefoxAccounts	DEBUG	writing plain storage: ["email","sessionToken","uid","verified","oauthTokens","device","profileCache","encryptedSendTabKeys"]
1744638129623	FirefoxAccounts	TRACE	starting write of json user data: ["email","sessionToken","uid","verified","oauthTokens","device","profileCache","encryptedSendTabKeys"]
1744638129624	FirefoxAccounts	DEBUG	_updateAccountData with items: ["encryptedCloseTabKeys"]
1744638129624	FirefoxAccounts	TRACE	FxAccountsPush registerPushEndpoint
1744638129624	FirefoxAccounts	TRACE	finished write of json user data - took: 1
1744638129624	FirefoxAccounts	DEBUG	writing secure storage: ["scopedKeys"]
1744638129624	FirefoxAccounts	TRACE	starting write of user data to the login manager
1744638129627	FirefoxAccounts	TRACE	finished write of user data to the login manager
1744638129627	FirefoxAccounts	DEBUG	writing plain storage: ["email","sessionToken","uid","verified","oauthTokens","device","profileCache","encryptedSendTabKeys","encryptedCloseTabKeys"]
1744638129627	FirefoxAccounts	TRACE	starting write of json user data: ["email","sessionToken","uid","verified","oauthTokens","device","profileCache","encryptedSendTabKeys","encryptedCloseTabKeys"]
1744638129627	FirefoxAccounts	TRACE	finished write of json user data - took: 0
1744638129627	FirefoxAccounts	DEBUG	writing secure storage: ["scopedKeys"]
1744638129627	FirefoxAccounts	TRACE	starting write of user data to the login manager
1744638129629	FirefoxAccounts	TRACE	finished write of user data to the login manager
1744638129629	FirefoxAccounts	DEBUG	FxAccountsPush got subscription
1744638129629	FirefoxAccounts	TRACE	Getting command keys: https://identity.mozilla.com/cmd/open-uri
1744638129630	FirefoxAccounts	TRACE	Getting command keys: https://identity.mozilla.com/cmd/close-uri/v1
1744638129630	FirefoxAccounts	INFO	registering with available commands: ["https://identity.mozilla.com/cmd/close-uri/v1","https://identity.mozilla.com/cmd/open-uri"]
1744638129630	FirefoxAccounts	DEBUG	updating existing device details
1744638129631	Services.Common.RESTRequest	DEBUG	POST request to https://api.accounts.firefox.com/v1/account/device
1744638129631	Services.Common.RESTRequest	DEBUG	POST Length: 1301
1744638129778	Services.Common.RESTRequest	DEBUG	GET https://api.accounts.firefox.com/v1/account/devices?filterIdleDevicesTimestamp=1742823729575 200
1744638129778	Hawk	DEBUG	(Response) /account/devices?filterIdleDevicesTimestamp=1742823729575: code: 200 - Status text: 
1744638129778	Hawk	DEBUG	Clock offset vs https://api.accounts.firefox.com/v1: -778
1744638129779	FirefoxAccounts	INFO	Got new device list: bc791d3b64ca31b835d38bdb02bd53ed
1744638129780	FirefoxAccounts	TRACE	Getting command keys: https://identity.mozilla.com/cmd/open-uri
1744638129781	FirefoxAccounts	TRACE	Getting command keys: https://identity.mozilla.com/cmd/close-uri/v1
1744638129781	FirefoxAccounts	WARN	Our commands need to be updated on the server
1744638129781	FirefoxAccounts	TRACE	FxAccountsPush registerPushEndpoint
1744638129782	FirefoxAccounts	DEBUG	FxAccountsPush got subscription
1744638129782	FirefoxAccounts	TRACE	Getting command keys: https://identity.mozilla.com/cmd/open-uri
1744638129782	FirefoxAccounts	TRACE	Getting command keys: https://identity.mozilla.com/cmd/close-uri/v1
1744638129782	FirefoxAccounts	INFO	registering with available commands: ["https://identity.mozilla.com/cmd/close-uri/v1","https://identity.mozilla.com/cmd/open-uri"]
1744638129782	FirefoxAccounts	DEBUG	updating existing device details
1744638129784	Services.Common.RESTRequest	DEBUG	POST request to https://api.accounts.firefox.com/v1/account/device
1744638129784	Services.Common.RESTRequest	DEBUG	POST Length: 1301
1744638129811	Services.Common.RESTRequest	DEBUG	POST https://api.accounts.firefox.com/v1/account/device 200
1744638129811	Hawk	DEBUG	(Response) /account/device: code: 200 - Status text: 
1744638129811	Hawk	DEBUG	Clock offset vs https://api.accounts.firefox.com/v1: -811
1744638129811	FirefoxAccounts	DEBUG	_updateAccountData with items: ["device"]
1744638129811	FirefoxAccounts	DEBUG	writing plain storage: ["email","sessionToken","uid","verified","oauthTokens","device","profileCache","encryptedSendTabKeys","encryptedCloseTabKeys"]
1744638129811	FirefoxAccounts	TRACE	starting write of json user data: ["email","sessionToken","uid","verified","oauthTokens","device","profileCache","encryptedSendTabKeys","encryptedCloseTabKeys"]
1744638129812	Services.Common.RESTRequest	DEBUG	POST https://api.accounts.firefox.com/v1/oauth/token 200
1744638129812	Hawk	DEBUG	(Response) /oauth/token: code: 200 - Status text: 
1744638129812	Hawk	DEBUG	Clock offset vs https://api.accounts.firefox.com/v1: -812
1744638129812	FirefoxAccounts	DEBUG	_updateAccountData with items: ["oauthTokens"]
1744638129812	Sync.SyncAuthManager	INFO	Getting a sync token from: https://mydomain.tld/1.0/sync/1.5
1744638129812	Sync.SyncAuthManager	DEBUG	Getting a token using OAuth
1744638129812	Services.Common.TokenServerClient	DEBUG	Beginning OAuth token exchange: https://mydomain.tld/1.0/sync/1.5
1744638129813	Services.Common.RESTRequest	DEBUG	GET request to https://mydomain.tld/1.0/sync/1.5
1744638129817	FirefoxAccounts	TRACE	finished write of json user data - took: 6
1744638129817	FirefoxAccounts	DEBUG	writing secure storage: ["scopedKeys"]
1744638129817	FirefoxAccounts	TRACE	starting write of user data to the login manager
1744638129819	FirefoxAccounts	TRACE	finished write of user data to the login manager
1744638129819	FirefoxAccounts	DEBUG	writing plain storage: ["email","sessionToken","uid","verified","oauthTokens","device","profileCache","encryptedSendTabKeys","encryptedCloseTabKeys"]
1744638129819	FirefoxAccounts	TRACE	starting write of json user data: ["email","sessionToken","uid","verified","oauthTokens","device","profileCache","encryptedSendTabKeys","encryptedCloseTabKeys"]
1744638129820	FirefoxAccounts	TRACE	finished write of json user data - took: 1
1744638129820	FirefoxAccounts	DEBUG	writing secure storage: ["scopedKeys"]
1744638129820	FirefoxAccounts	TRACE	starting write of user data to the login manager
1744638129822	FirefoxAccounts	TRACE	finished write of user data to the login manager
1744638130054	Services.Common.RESTRequest	DEBUG	POST https://api.accounts.firefox.com/v1/account/device 200
1744638130054	Hawk	DEBUG	(Response) /account/device: code: 200 - Status text: 
1744638130054	Hawk	DEBUG	Clock offset vs https://api.accounts.firefox.com/v1: -1054
1744638130054	FirefoxAccounts	DEBUG	_updateAccountData with items: ["device"]
1744638130054	FirefoxAccounts	DEBUG	writing plain storage: ["email","sessionToken","uid","verified","oauthTokens","device","profileCache","encryptedSendTabKeys","encryptedCloseTabKeys"]
1744638130055	FirefoxAccounts	TRACE	starting write of json user data: ["email","sessionToken","uid","verified","oauthTokens","device","profileCache","encryptedSendTabKeys","encryptedCloseTabKeys"]
1744638130055	FirefoxAccounts	INFO	updating the cache
1744638130056	Services.Common.RESTRequest	DEBUG	GET https://mydomain.tld/1.0/sync/1.5 401
1744638130056	Services.Common.TokenServerClient	DEBUG	Got token response: 401
1744638130056	Services.Common.TokenServerClient	INFO	Server-reported error: {"location":"body","name":"","description":"Unauthorized"}
1744638130057	Services.Common.RESTRequest	DEBUG	POST request to https://api.accounts.firefox.com/v1/oauth/destroy
1744638130057	Services.Common.RESTRequest	DEBUG	POST Length: 969
1744638130058	FirefoxAccounts	DEBUG	_updateAccountData with items: ["oauthTokens"]
1744638130058	Sync.SyncAuthManager	WARN	Token server returned 401, retrying token fetch with fresh credentials
1744638130058	FirefoxAccounts	DEBUG	getOAuthToken enter
1744638130063	FirefoxAccounts	TRACE	finished write of json user data - took: 8
1744638130063	FirefoxAccounts	DEBUG	writing secure storage: ["scopedKeys"]
1744638130063	FirefoxAccounts	TRACE	starting write of user data to the login manager
1744638130067	FirefoxAccounts	TRACE	finished write of user data to the login manager
1744638130068	FirefoxAccounts	DEBUG	writing plain storage: ["email","sessionToken","uid","verified","oauthTokens","device","profileCache","encryptedSendTabKeys","encryptedCloseTabKeys"]
1744638130068	FirefoxAccounts	TRACE	starting write of json user data: ["email","sessionToken","uid","verified","oauthTokens","device","profileCache","encryptedSendTabKeys","encryptedCloseTabKeys"]
1744638130069	Services.Common.RESTRequest	DEBUG	POST request to https://api.accounts.firefox.com/v1/oauth/token
1744638130069	Services.Common.RESTRequest	DEBUG	POST Length: 127
1744638130070	FirefoxAccounts	TRACE	finished write of json user data - took: 2
1744638130070	FirefoxAccounts	DEBUG	writing secure storage: ["scopedKeys"]
1744638130070	FirefoxAccounts	TRACE	starting write of user data to the login manager
1744638130074	FirefoxAccounts	TRACE	finished write of user data to the login manager
1744638130230	Services.Common.RESTRequest	DEBUG	POST https://api.accounts.firefox.com/v1/oauth/destroy 200
1744638130230	Hawk	DEBUG	(Response) /oauth/destroy: code: 200 - Status text: 
1744638130230	Hawk	DEBUG	Clock offset vs https://api.accounts.firefox.com/v1: -230
1744638130271	Services.Common.RESTRequest	DEBUG	POST https://api.accounts.firefox.com/v1/oauth/token 200
1744638130271	Hawk	DEBUG	(Response) /oauth/token: code: 200 - Status text: 
1744638130271	Hawk	DEBUG	Clock offset vs https://api.accounts.firefox.com/v1: -271
1744638130272	FirefoxAccounts	DEBUG	_updateAccountData with items: ["oauthTokens"]
1744638130272	FirefoxAccounts	DEBUG	writing plain storage: ["email","sessionToken","uid","verified","oauthTokens","device","profileCache","encryptedSendTabKeys","encryptedCloseTabKeys"]
1744638130272	FirefoxAccounts	TRACE	starting write of json user data: ["email","sessionToken","uid","verified","oauthTokens","device","profileCache","encryptedSendTabKeys","encryptedCloseTabKeys"]
1744638130272	Sync.SyncAuthManager	INFO	Getting a sync token from: https://mydomain.tld/1.0/sync/1.5
1744638130272	Sync.SyncAuthManager	DEBUG	Getting a token using OAuth
1744638130272	Services.Common.TokenServerClient	DEBUG	Beginning OAuth token exchange: https://mydomain.tld/1.0/sync/1.5
1744638130272	Services.Common.RESTRequest	DEBUG	GET request to https://mydomain.tld/1.0/sync/1.5
1744638130283	FirefoxAccounts	TRACE	finished write of json user data - took: 11
1744638130283	FirefoxAccounts	DEBUG	writing secure storage: ["scopedKeys"]
1744638130283	FirefoxAccounts	TRACE	starting write of user data to the login manager
1744638130287	FirefoxAccounts	TRACE	finished write of user data to the login manager
1744638130454	Services.Common.RESTRequest	DEBUG	GET https://mydomain.tld/1.0/sync/1.5 401
1744638130454	Services.Common.TokenServerClient	DEBUG	Got token response: 401
1744638130455	Services.Common.TokenServerClient	INFO	Server-reported error: {"location":"body","name":"","description":"Unauthorized"}
1744638130455	Services.Common.RESTRequest	DEBUG	POST request to https://api.accounts.firefox.com/v1/oauth/destroy
1744638130455	Services.Common.RESTRequest	DEBUG	POST Length: 969
1744638130456	FirefoxAccounts	DEBUG	_updateAccountData with items: ["oauthTokens"]
1744638130457	FirefoxAccounts	DEBUG	writing plain storage: ["email","sessionToken","uid","verified","oauthTokens","device","profileCache","encryptedSendTabKeys","encryptedCloseTabKeys"]
1744638130457	FirefoxAccounts	TRACE	starting write of json user data: ["email","sessionToken","uid","verified","oauthTokens","device","profileCache","encryptedSendTabKeys","encryptedCloseTabKeys"]
1744638130457	Sync.SyncAuthManager	ERROR	Authentication error in _fetchTokenForUser: {"details":{"now":"2025-04-14T13:42:10.455Z","message":"Authentication failed.","cause":"invalid-credentials","response_body":"{\"status\":\"invalid-credentials\",\"errors\":[{\"location\":\"body\",\"name\":\"\",\"description\":\"Unauthorized\"}]}","response_headers":{"server":"nginx/1.27.4","date":"Mon, 14 Apr 2025 13:41:29 GMT","content-type":"application/json","content-length":"102","vary":"Origin, Access-Control-Request-Method, Access-Control-Request-Headers","x-weave-timestamp":"1744638089.70","x-firefox-spdy":"h2"},"response_status":401,"name":"TokenServerClientServerError"},"source":"tokenserver"}
1744638130457	Sync.Status	DEBUG	Status.login: success.login => error.login.reason.account
1744638130457	Sync.Status	DEBUG	Status.service: success.status_ok => error.login.failed
1744638130458	Sync.SyncAuthManager	INFO	Failed to fetch the cluster URL: {"details":{"now":"2025-04-14T13:42:10.455Z","message":"Authentication failed.","cause":"invalid-credentials","response_body":"{\"status\":\"invalid-credentials\",\"errors\":[{\"location\":\"body\",\"name\":\"\",\"description\":\"Unauthorized\"}]}","response_headers":{"server":"nginx/1.27.4","date":"Mon, 14 Apr 2025 13:41:29 GMT","content-type":"application/json","content-length":"102","vary":"Origin, Access-Control-Request-Method, Access-Control-Request-Headers","x-weave-timestamp":"1744638089.70","x-firefox-spdy":"h2"},"response_status":401,"name":"TokenServerClientServerError"},"source":"tokenserver"}
1744638130458	Sync.SyncAuthManager	DEBUG	Cluster value = null
1744638130458	Sync.Status	DEBUG	Status.sync: success.sync => error.sync.reason.no_node_found
1744638130458	Sync.Status	DEBUG	Status.service: error.login.failed => error.sync.failed
1744638130458	Sync.Synchronizer	INFO	No cluster URL found. Cannot sync.
1744638130460	Sync.SyncScheduler	DEBUG	Next sync in 600000 ms. (why=schedule)
1744638130462	FirefoxAccounts	TRACE	not checking freshness of profile as it remains recent

[urigg]

Getting the same error with a server I've tried to set up today. Also tried with a blank firefox profile, same. Account login works, but token server instantly replies 401 unauthorized.

[porelli]

This usually happens when you reach the MAX_USERS quota set in the .env file, the default value is 1. This means that unless the parameter is changed, you will be able to use firefox-sync with only one Firefox account (but unlimited devices).

Can you share the log for the containers?

[witchent]

I did not change this file, started every time with a clean database, so I don't think that this was the problem.
Anyway, I moved to build the container myself and have it working there, so I cannot reproduce this. If @urigg cannot do this either we might have to close this issue. Thank you very much anyway for your help :)

[urigg]

I suspected the user limit too, so I tried with cleaned database, made sure it says 0 of 1 users at first start, but was still the same.
I will try again, but not sure when I'll have the time.

[porelli]

I just tried a brand new installation and I couldn't face any error with the most recent build. Are you using any special configuration like cloudfare/authentik/keycloak/authelia/etc or other custom rules in the nginx definition?

[urigg]

Tried with limit increased to 10 users, no change.

Differences to vanilla install:

• Using apache instead of nginx for proxying
• Server url has an attached /path/
• Server is not publically accessible, but haven't seen any contact attempts from outside
• Due to debian stable, its docker-compose, not docker compose.

Here's a log from a fresh instance and a fresh firefox profile logging in:

firefox-sync_syncstorage_db_1 is up-to-date
firefox-sync_tokenserver_db_1 is up-to-date
Creating firefox-sync_syncstorage_1 ... done
Creating firefox-sync_tokenserver_db_init_1 ... done
Attaching to firefox-sync_syncstorage_db_1, firefox-sync_tokenserver_db_1, firefox-sync_syncstorage_1, firefox-sync_tokenserver_db_init_1
syncstorage_1          | Apr 27 15:38:58.776 INFO starting 2 workers
syncstorage_1          | Apr 27 15:38:58.787 INFO Server running on http://0.0.0.0:8000 (mysql) (available_parallelism: Ok(2) num_cpus: 2 num_cpus (phys): 2) No quota
syncstorage_1          | Apr 27 15:38:58.787 INFO Actix runtime found; starting in Actix runtime
syncstorage_1          | Apr 27 15:39:20.199 INFO {"ua.os.family":"Other","uri.path":"/__heartbeat__","ua":"curl","uri.method":"GET","ua.browser.ver":"curl","ua.browser.family":"Other","ua.name":"HTTP Library","ua.os.ver":"UNKNOWN"}
syncstorage_db_1       | 2025-04-27 15:37:16+00:00 [Note] [Entrypoint]: Entrypoint script for MariaDB Server 1:11.4.5+maria~ubu2404 started.
syncstorage_db_1       | 2025-04-27 15:37:21+00:00 [Warn] [Entrypoint]: /sys/fs/cgroup///memory.pressure not writable, functionality unavailable to MariaDB
syncstorage_db_1       | 2025-04-27 15:37:21+00:00 [Note] [Entrypoint]: Switching to dedicated user 'mysql'
syncstorage_db_1       | 2025-04-27 15:37:21+00:00 [Note] [Entrypoint]: Entrypoint script for MariaDB Server 1:11.4.5+maria~ubu2404 started.
syncstorage_db_1       | 2025-04-27 15:37:26+00:00 [Note] [Entrypoint]: Initializing database files
syncstorage_db_1       | 2025-04-27 15:37:34+00:00 [Note] [Entrypoint]: Database files initialized
syncstorage_db_1       | 2025-04-27 15:37:34+00:00 [Note] [Entrypoint]: Starting temporary server
syncstorage_db_1       | 2025-04-27 15:37:34+00:00 [Note] [Entrypoint]: Waiting for server startup
syncstorage_db_1       | 2025-04-27 15:37:35 0 [Note] Starting MariaDB 11.4.5-MariaDB-ubu2404 source revision 0771110266ff5c04216af4bf1243c65f8c67ccf4 server_uid 2KQvNCDvu6PQATgLu/GVimw4hjM= as process 108
syncstorage_db_1       | 2025-04-27 15:37:36 0 [Note] InnoDB: Compressed tables use zlib 1.3
syncstorage_db_1       | 2025-04-27 15:37:36 0 [Note] InnoDB: Number of transaction pools: 1
syncstorage_db_1       | 2025-04-27 15:37:36 0 [Note] InnoDB: Using generic crc32 instructions
syncstorage_db_1       | 2025-04-27 15:37:36 0 [Note] mariadbd: O_TMPFILE is not supported on /tmp (disabling future attempts)
syncstorage_db_1       | 2025-04-27 15:37:36 0 [Note] InnoDB: Using liburing
syncstorage_db_1       | 2025-04-27 15:37:36 0 [Note] InnoDB: Initializing buffer pool, total size = 128.000MiB, chunk size = 2.000MiB
syncstorage_db_1       | 2025-04-27 15:37:36 0 [Note] InnoDB: Completed initialization of buffer pool
syncstorage_db_1       | 2025-04-27 15:37:36 0 [Note] InnoDB: File system buffers for log disabled (block size=512 bytes)
syncstorage_db_1       | 2025-04-27 15:37:36 0 [Note] InnoDB: End of log at LSN=47661
syncstorage_db_1       | 2025-04-27 15:37:36 0 [Note] InnoDB: Opened 3 undo tablespaces
syncstorage_db_1       | 2025-04-27 15:37:36 0 [Note] InnoDB: 128 rollback segments in 3 undo tablespaces are active.
syncstorage_db_1       | 2025-04-27 15:37:36 0 [Note] InnoDB: Setting file './ibtmp1' size to 12.000MiB. Physically writing the file full; Please wait ...
syncstorage_db_1       | 2025-04-27 15:37:36 0 [Note] InnoDB: File './ibtmp1' size is now 12.000MiB.
syncstorage_db_1       | 2025-04-27 15:37:36 0 [Note] InnoDB: log sequence number 47661; transaction id 14
syncstorage_db_1       | 2025-04-27 15:37:36 0 [Note] Plugin 'FEEDBACK' is disabled.
syncstorage_db_1       | 2025-04-27 15:37:36 0 [Note] Plugin 'wsrep-provider' is disabled.
syncstorage_db_1       | 2025-04-27 15:37:58 0 [Note] mariadbd: Event Scheduler: Loaded 0 events
syncstorage_db_1       | 2025-04-27 15:37:58 0 [Note] mariadbd: ready for connections.
syncstorage_db_1       | Version: '11.4.5-MariaDB-ubu2404'  socket: '/run/mysqld/mysqld.sock'  port: 0  mariadb.org binary distribution
syncstorage_db_1       | 2025-04-27 15:38:00+00:00 [Note] [Entrypoint]: Temporary server started.
syncstorage_db_1       | 2025-04-27 15:38:11+00:00 [Note] [Entrypoint]: GENERATED ROOT PASSWORD: "sfu7m6LI0bdQx}"T<5GP-Jato`-Z~^Q
syncstorage_db_1       | 2025-04-27 15:38:11+00:00 [Note] [Entrypoint]: Creating database syncstorage
syncstorage_db_1       | 2025-04-27 15:38:11+00:00 [Note] [Entrypoint]: Creating user syncstorage
syncstorage_db_1       | 2025-04-27 15:38:11+00:00 [Note] [Entrypoint]: Giving user syncstorage access to schema syncstorage
syncstorage_db_1       | 2025-04-27 15:38:11+00:00 [Note] [Entrypoint]: Securing system users (equivalent to running mysql_secure_installation)
syncstorage_db_1       | 
syncstorage_db_1       | 2025-04-27 15:38:14+00:00 [Note] [Entrypoint]: Stopping temporary server
syncstorage_db_1       | 2025-04-27 15:38:14 0 [Note] mariadbd (initiated by: unknown): Normal shutdown
syncstorage_db_1       | 2025-04-27 15:38:14 0 [Note] InnoDB: FTS optimize thread exiting.
syncstorage_db_1       | 2025-04-27 15:38:14 0 [Note] InnoDB: Starting shutdown...
syncstorage_db_1       | 2025-04-27 15:38:14 0 [Note] InnoDB: Dumping buffer pool(s) to /var/lib/mysql/ib_buffer_pool
syncstorage_db_1       | 2025-04-27 15:38:14 0 [Note] InnoDB: Buffer pool(s) dump completed at 250427 15:38:14
syncstorage_db_1       | 2025-04-27 15:38:14 0 [Note] InnoDB: Removed temporary tablespace data file: "./ibtmp1"
syncstorage_db_1       | 2025-04-27 15:38:14 0 [Note] InnoDB: Shutdown completed; log sequence number 47661; transaction id 15
syncstorage_db_1       | 2025-04-27 15:38:14 0 [Note] mariadbd: Shutdown complete
syncstorage_db_1       | 2025-04-27 15:38:14+00:00 [Note] [Entrypoint]: Temporary server stopped
syncstorage_db_1       | 
tokenserver_db_1       | 2025-04-27 15:37:16+00:00 [Note] [Entrypoint]: Entrypoint script for MariaDB Server 1:11.4.5+maria~ubu2404 started.
tokenserver_db_1       | 2025-04-27 15:37:21+00:00 [Warn] [Entrypoint]: /sys/fs/cgroup///memory.pressure not writable, functionality unavailable to MariaDB
tokenserver_db_1       | 2025-04-27 15:37:21+00:00 [Note] [Entrypoint]: Switching to dedicated user 'mysql'
tokenserver_db_1       | 2025-04-27 15:37:22+00:00 [Note] [Entrypoint]: Entrypoint script for MariaDB Server 1:11.4.5+maria~ubu2404 started.
tokenserver_db_1       | 2025-04-27 15:37:25+00:00 [Note] [Entrypoint]: Initializing database files
tokenserver_db_1       | 2025-04-27 15:37:34+00:00 [Note] [Entrypoint]: Database files initialized
tokenserver_db_1       | 2025-04-27 15:37:34+00:00 [Note] [Entrypoint]: Starting temporary server
tokenserver_db_1       | 2025-04-27 15:37:34+00:00 [Note] [Entrypoint]: Waiting for server startup
tokenserver_db_1       | 2025-04-27 15:37:35 0 [Note] Starting MariaDB 11.4.5-MariaDB-ubu2404 source revision 0771110266ff5c04216af4bf1243c65f8c67ccf4 server_uid RjhoQPKnFbzyL1r5RfWZQkD3BSI= as process 105
tokenserver_db_1       | 2025-04-27 15:37:36 0 [Note] InnoDB: Compressed tables use zlib 1.3
tokenserver_db_1       | 2025-04-27 15:37:36 0 [Note] InnoDB: Number of transaction pools: 1
tokenserver_db_1       | 2025-04-27 15:37:36 0 [Note] InnoDB: Using generic crc32 instructions
syncstorage_db_1       | 2025-04-27 15:38:15+00:00 [Note] [Entrypoint]: MariaDB init process done. Ready for start up.
syncstorage_db_1       | 
syncstorage_db_1       | 2025-04-27 15:38:16 0 [Note] Starting MariaDB 11.4.5-MariaDB-ubu2404 source revision 0771110266ff5c04216af4bf1243c65f8c67ccf4 server_uid 2KQvNCDvu6PQATgLu/GVimw4hjM= as process 1
syncstorage_db_1       | 2025-04-27 15:38:17 0 [Note] InnoDB: Compressed tables use zlib 1.3
syncstorage_db_1       | 2025-04-27 15:38:17 0 [Note] InnoDB: Number of transaction pools: 1
syncstorage_db_1       | 2025-04-27 15:38:17 0 [Note] InnoDB: Using generic crc32 instructions
syncstorage_db_1       | 2025-04-27 15:38:17 0 [Note] mariadbd: O_TMPFILE is not supported on /tmp (disabling future attempts)
syncstorage_db_1       | 2025-04-27 15:38:17 0 [Note] InnoDB: Using liburing
syncstorage_db_1       | 2025-04-27 15:38:17 0 [Note] InnoDB: Initializing buffer pool, total size = 128.000MiB, chunk size = 2.000MiB
syncstorage_db_1       | 2025-04-27 15:38:17 0 [Note] InnoDB: Completed initialization of buffer pool
syncstorage_db_1       | 2025-04-27 15:38:17 0 [Note] InnoDB: File system buffers for log disabled (block size=512 bytes)
syncstorage_db_1       | 2025-04-27 15:38:17 0 [Note] InnoDB: End of log at LSN=47661
syncstorage_db_1       | 2025-04-27 15:38:17 0 [Note] InnoDB: Opened 3 undo tablespaces
syncstorage_db_1       | 2025-04-27 15:38:17 0 [Note] InnoDB: 128 rollback segments in 3 undo tablespaces are active.
syncstorage_db_1       | 2025-04-27 15:38:17 0 [Note] InnoDB: Setting file './ibtmp1' size to 12.000MiB. Physically writing the file full; Please wait ...
syncstorage_db_1       | 2025-04-27 15:38:17 0 [Note] InnoDB: File './ibtmp1' size is now 12.000MiB.
syncstorage_db_1       | 2025-04-27 15:38:17 0 [Note] InnoDB: log sequence number 47661; transaction id 14
syncstorage_db_1       | 2025-04-27 15:38:17 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
syncstorage_db_1       | 2025-04-27 15:38:17 0 [Note] Plugin 'FEEDBACK' is disabled.
syncstorage_db_1       | 2025-04-27 15:38:17 0 [Note] InnoDB: Buffer pool(s) load completed at 250427 15:38:17
syncstorage_db_1       | 2025-04-27 15:38:17 0 [Note] Plugin 'wsrep-provider' is disabled.
syncstorage_db_1       | 2025-04-27 15:38:29 0 [Note] Server socket created on IP: '0.0.0.0'.
syncstorage_db_1       | 2025-04-27 15:38:29 0 [Note] Server socket created on IP: '::'.
syncstorage_db_1       | 2025-04-27 15:38:30 0 [Note] mariadbd: Event Scheduler: Loaded 0 events
tokenserver_db_1       | 2025-04-27 15:37:36 0 [Note] mariadbd: O_TMPFILE is not supported on /tmp (disabling future attempts)
tokenserver_db_1       | 2025-04-27 15:37:36 0 [Note] InnoDB: Using liburing
tokenserver_db_1       | 2025-04-27 15:37:36 0 [Note] InnoDB: Initializing buffer pool, total size = 128.000MiB, chunk size = 2.000MiB
tokenserver_db_1       | 2025-04-27 15:37:36 0 [Note] InnoDB: Completed initialization of buffer pool
tokenserver_db_1       | 2025-04-27 15:37:36 0 [Note] InnoDB: File system buffers for log disabled (block size=512 bytes)
tokenserver_db_1       | 2025-04-27 15:37:36 0 [Note] InnoDB: End of log at LSN=47645
tokenserver_db_1       | 2025-04-27 15:37:36 0 [Note] InnoDB: Opened 3 undo tablespaces
tokenserver_db_1       | 2025-04-27 15:37:36 0 [Note] InnoDB: 128 rollback segments in 3 undo tablespaces are active.
tokenserver_db_1       | 2025-04-27 15:37:36 0 [Note] InnoDB: Setting file './ibtmp1' size to 12.000MiB. Physically writing the file full; Please wait ...
syncstorage_db_1       | 2025-04-27 15:38:30 0 [Note] mariadbd: ready for connections.
syncstorage_db_1       | Version: '11.4.5-MariaDB-ubu2404'  socket: '/run/mysqld/mysqld.sock'  port: 3306  mariadb.org binary distribution
tokenserver_db_1       | 2025-04-27 15:37:36 0 [Note] InnoDB: File './ibtmp1' size is now 12.000MiB.
tokenserver_db_1       | 2025-04-27 15:37:36 0 [Note] InnoDB: log sequence number 47645; transaction id 14
tokenserver_db_1       | 2025-04-27 15:37:36 0 [Note] Plugin 'FEEDBACK' is disabled.
tokenserver_db_1       | 2025-04-27 15:37:36 0 [Note] Plugin 'wsrep-provider' is disabled.
tokenserver_db_1       | 2025-04-27 15:37:54 0 [Note] mariadbd: Event Scheduler: Loaded 0 events
tokenserver_db_1       | 2025-04-27 15:37:54 0 [Note] mariadbd: ready for connections.
tokenserver_db_1       | Version: '11.4.5-MariaDB-ubu2404'  socket: '/run/mysqld/mysqld.sock'  port: 0  mariadb.org binary distribution
tokenserver_db_1       | 2025-04-27 15:37:56+00:00 [Note] [Entrypoint]: Temporary server started.
tokenserver_db_1       | 2025-04-27 15:38:07+00:00 [Note] [Entrypoint]: GENERATED ROOT PASSWORD: ~|X&,@g6sl_~;}Y>fwKU{[ybN-~^S*2q
tokenserver_db_1       | 2025-04-27 15:38:07+00:00 [Note] [Entrypoint]: Creating database tokenserver
tokenserver_db_1       | 2025-04-27 15:38:07+00:00 [Note] [Entrypoint]: Creating user tokenserver
tokenserver_db_1       | 2025-04-27 15:38:07+00:00 [Note] [Entrypoint]: Giving user tokenserver access to schema tokenserver
tokenserver_db_1       | 2025-04-27 15:38:07+00:00 [Note] [Entrypoint]: Securing system users (equivalent to running mysql_secure_installation)
tokenserver_db_1       | 
tokenserver_db_1       | 2025-04-27 15:38:09+00:00 [Note] [Entrypoint]: Stopping temporary server
tokenserver_db_1       | 2025-04-27 15:38:09 0 [Note] mariadbd (initiated by: unknown): Normal shutdown
tokenserver_db_1       | 2025-04-27 15:38:09 0 [Note] InnoDB: FTS optimize thread exiting.
tokenserver_db_1       | 2025-04-27 15:38:09 0 [Note] InnoDB: Starting shutdown...
tokenserver_db_1       | 2025-04-27 15:38:09 0 [Note] InnoDB: Dumping buffer pool(s) to /var/lib/mysql/ib_buffer_pool
tokenserver_db_1       | 2025-04-27 15:38:09 0 [Note] InnoDB: Buffer pool(s) dump completed at 250427 15:38:09
tokenserver_db_1       | 2025-04-27 15:38:09 0 [Note] InnoDB: Removed temporary tablespace data file: "./ibtmp1"
tokenserver_db_1       | 2025-04-27 15:38:09 0 [Note] InnoDB: Shutdown completed; log sequence number 47645; transaction id 15
tokenserver_db_1       | 2025-04-27 15:38:09 0 [Note] mariadbd: Shutdown complete
tokenserver_db_1       | 2025-04-27 15:38:09+00:00 [Note] [Entrypoint]: Temporary server stopped
tokenserver_db_1       | 
tokenserver_db_1       | 2025-04-27 15:38:09+00:00 [Note] [Entrypoint]: MariaDB init process done. Ready for start up.
tokenserver_db_1       | 
tokenserver_db_1       | 2025-04-27 15:38:10 0 [Note] Starting MariaDB 11.4.5-MariaDB-ubu2404 source revision 0771110266ff5c04216af4bf1243c65f8c67ccf4 server_uid RjhoQPKnFbzyL1r5RfWZQkD3BSI= as process 1
tokenserver_db_1       | 2025-04-27 15:38:10 0 [Note] InnoDB: Compressed tables use zlib 1.3
tokenserver_db_1       | 2025-04-27 15:38:10 0 [Note] InnoDB: Number of transaction pools: 1
tokenserver_db_1       | 2025-04-27 15:38:10 0 [Note] InnoDB: Using generic crc32 instructions
tokenserver_db_1       | 2025-04-27 15:38:10 0 [Note] mariadbd: O_TMPFILE is not supported on /tmp (disabling future attempts)
tokenserver_db_1       | 2025-04-27 15:38:10 0 [Note] InnoDB: Using liburing
tokenserver_db_1       | 2025-04-27 15:38:10 0 [Note] InnoDB: Initializing buffer pool, total size = 128.000MiB, chunk size = 2.000MiB
tokenserver_db_1       | 2025-04-27 15:38:10 0 [Note] InnoDB: Completed initialization of buffer pool
tokenserver_db_1       | 2025-04-27 15:38:10 0 [Note] InnoDB: File system buffers for log disabled (block size=512 bytes)
tokenserver_db_1       | 2025-04-27 15:38:10 0 [Note] InnoDB: End of log at LSN=47645
tokenserver_db_1       | 2025-04-27 15:38:10 0 [Note] InnoDB: Opened 3 undo tablespaces
tokenserver_db_1       | 2025-04-27 15:38:10 0 [Note] InnoDB: 128 rollback segments in 3 undo tablespaces are active.
tokenserver_db_1       | 2025-04-27 15:38:10 0 [Note] InnoDB: Setting file './ibtmp1' size to 12.000MiB. Physically writing the file full; Please wait ...
tokenserver_db_1       | 2025-04-27 15:38:10 0 [Note] InnoDB: File './ibtmp1' size is now 12.000MiB.
tokenserver_db_1       | 2025-04-27 15:38:10 0 [Note] InnoDB: log sequence number 47645; transaction id 14
tokenserver_db_1       | 2025-04-27 15:38:10 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
tokenserver_db_1       | 2025-04-27 15:38:10 0 [Note] Plugin 'FEEDBACK' is disabled.
tokenserver_db_1       | 2025-04-27 15:38:10 0 [Note] Plugin 'wsrep-provider' is disabled.
tokenserver_db_1       | 2025-04-27 15:38:10 0 [Note] InnoDB: Buffer pool(s) load completed at 250427 15:38:10
tokenserver_db_1       | 2025-04-27 15:38:35 0 [Note] Server socket created on IP: '0.0.0.0'.
tokenserver_db_1       | 2025-04-27 15:38:35 0 [Note] Server socket created on IP: '::'.
tokenserver_db_1       | 2025-04-27 15:38:35 0 [Note] mariadbd: Event Scheduler: Loaded 0 events
tokenserver_db_1       | 2025-04-27 15:38:35 0 [Note] mariadbd: ready for connections.
tokenserver_db_1       | Version: '11.4.5-MariaDB-ubu2404'  socket: '/run/mysqld/mysqld.sock'  port: 3306  mariadb.org binary distribution
tokenserver_db_init_1  | Database is correctly initialized!
tokenserver_db_init_1  | -----
tokenserver_db_init_1  | Current users: 0
tokenserver_db_init_1  | Max users: 1
tokenserver_db_init_1  | -----
firefox-sync_tokenserver_db_init_1 exited with code 0
syncstorage_1          | Apr 27 15:39:50.955 INFO {"uri.path":"/__heartbeat__","ua.browser.family":"Other","ua":"curl","ua.name":"HTTP Library","ua.browser.ver":"curl","uri.method":"GET","ua.os.family":"Other","ua.os.ver":"UNKNOWN"}
syncstorage_1          | Apr 27 15:40:22.641 INFO {"ua.name":"HTTP Library","uri.method":"GET","uri.path":"/__heartbeat__","ua":"curl","ua.browser.family":"Other","ua.os.ver":"UNKNOWN","ua.browser.ver":"curl","ua.os.family":"Other"}
syncstorage_1          | Apr 27 15:40:53.229 INFO {"uri.method":"GET","ua.browser.ver":"curl","uri.path":"/__heartbeat__","ua.name":"HTTP Library","ua.os.family":"Other","ua":"curl","ua.os.ver":"UNKNOWN","ua.browser.family":"Other"}
syncstorage_1          | Apr 27 15:41:24.937 INFO {"ua.os.ver":"UNKNOWN","ua.os.family":"Other","ua.name":"HTTP Library","uri.path":"/__heartbeat__","uri.method":"GET","ua.browser.family":"Other","ua.browser.ver":"curl","ua":"curl"}
syncstorage_1          | Apr 27 15:41:55.582 INFO {"ua.os.family":"Other","uri.method":"GET","uri.path":"/__heartbeat__","ua.name":"HTTP Library","ua":"curl","ua.os.ver":"UNKNOWN","ua.browser.family":"Other","ua.browser.ver":"curl"}
syncstorage_1          | Apr 27 15:42:27.254 INFO {"ua.os.ver":"UNKNOWN","ua":"curl","ua.os.family":"Other","ua.name":"HTTP Library","uri.method":"GET","ua.browser.family":"Other","uri.path":"/__heartbeat__","ua.browser.ver":"curl"}
syncstorage_1          | Apr 27 15:42:57.879 INFO {"ua.os.ver":"UNKNOWN","uri.path":"/__heartbeat__","ua.os.family":"Other","ua":"curl","ua.browser.family":"Other","ua.name":"HTTP Library","ua.browser.ver":"curl","uri.method":"GET"}
syncstorage_1          | Apr 27 15:43:22.267 INFO {"ua":"137.0","token_type":"OAuth","ua.browser.family":"Firefox","ua.name":"Firefox","uri.path":"/1.0/sync/1.5","uri.method":"GET","ua.os.ver":"UNKNOWN","ua.browser.ver":"137.0","ua.os.family":"Linux"}
syncstorage_1          | Apr 27 15:43:22.672 INFO {"ua.browser.ver":"137.0","ua.os.family":"Linux","uri.method":"GET","ua.name":"Firefox","ua":"137.0","ua.os.ver":"UNKNOWN","uri.path":"/1.0/sync/1.5","ua.browser.family":"Firefox","token_type":"OAuth"}
syncstorage_1          | Apr 27 15:43:23.035 INFO {"ua":"137.0","ua.name":"Firefox","token_type":"OAuth","ua.os.ver":"UNKNOWN","ua.browser.ver":"137.0","ua.os.family":"Linux","uri.method":"GET","ua.browser.family":"Firefox","uri.path":"/1.0/sync/1.5"}
syncstorage_1          | Apr 27 15:43:23.452 INFO {"token_type":"OAuth","ua.name":"Firefox","uri.method":"GET","ua.browser.family":"Firefox","ua":"137.0","ua.os.ver":"UNKNOWN","ua.os.family":"Linux","ua.browser.ver":"137.0","uri.path":"/1.0/sync/1.5"}
syncstorage_1          | Apr 27 15:43:28.867 INFO {"ua":"curl","ua.os.family":"Other","uri.method":"GET","uri.path":"/__heartbeat__","ua.browser.family":"Other","ua.os.ver":"UNKNOWN","ua.name":"HTTP Library","ua.browser.ver":"curl"}
syncstorage_1          | Apr 27 15:43:45.199 INFO {"uri.path":"/1.0/sync/1.5","ua.os.ver":"UNKNOWN","ua.browser.ver":"137.0","ua.name":"Firefox","ua.browser.family":"Firefox","uri.method":"GET","token_type":"OAuth","ua":"137.0","ua.os.family":"Linux"}
syncstorage_1          | Apr 27 15:43:45.552 INFO {"ua.browser.family":"Firefox","ua.browser.ver":"137.0","ua":"137.0","uri.path":"/1.0/sync/1.5","token_type":"OAuth","ua.name":"Firefox","ua.os.ver":"UNKNOWN","ua.os.family":"Linux","uri.method":"GET"}

error-sync-1745768616778.txt:

1745768203109	FirefoxAccounts	TRACE	starting fetch of json user data
1745768203151	FirefoxAccounts	TRACE	initializing of new storage manager done
1745768203543	FirefoxAccounts	DEBUG	FxAccountsWebChannel registered: account_updates with origin https://accounts.firefox.com
1745768526114	Sync.RemoteTabs	DEBUG	Sync isn't yet ready; assuming tab engine is enabled
1745768526128	Sync.Status	INFO	Resetting Status.
1745768526128	Sync.Status	DEBUG	Status.service: undefined => success.status_ok
1745768526129	Sync.SyncScheduler	TRACE	Setting SyncScheduler policy values to defaults.
1745768526129	Sync.SyncScheduler	DEBUG	Clearing sync triggers and the global score.
1745768526129	Sync.Status	DEBUG	Status.login: success.login => error.login.reason.no_username
1745768526129	Sync.Status	DEBUG	Status.service: success.status_ok => service.client_not_configured
1745768526129	Sync.Status	DEBUG	Status.service: service.client_not_configured => service.client_not_configured
1745768526130	Sync.Service	INFO	Loading Weave 1.139.0
1745768526130	Sync.Engine.Clients	DEBUG	Engine constructed
1745768526130	Sync.Engine.Clients	DEBUG	Resetting clients last sync time
1745768526130	Sync.Status	DEBUG	Status.login: error.login.reason.no_username => error.login.reason.no_username
1745768526130	Sync.Status	DEBUG	Status.service: service.client_not_configured => service.client_not_configured
1745768526130	Sync.Status	DEBUG	Status.service: service.client_not_configured => service.client_not_configured
1745768526130	Sync.RemoteTabs	INFO	Sync client is not configured, so not attempting a tab sync
1745768526131	Sync.RemoteTabs	INFO	Generating tab list with filter
1745768526131	Sync.RemoteTabs	DEBUG	Sync isn't yet ready, so returning an empty tab list
1745768526133	Sync.Engine.Addons	DEBUG	Engine constructed
1745768526153	Sync.Engine.Addons	DEBUG	SyncEngine initialized: addons
1745768526155	Sync.AddonsReconciler	DEBUG	No data seen in loaded file: addonsreconciler
1745768526156	Sync.Engine.Passwords	DEBUG	Engine constructed
1745768526156	Sync.Engine.Passwords	DEBUG	SyncEngine initialized: passwords
1745768526157	Sync.Engine.Prefs	DEBUG	Engine constructed
1745768526157	Sync.Engine.Prefs	DEBUG	SyncEngine initialized: prefs
1745768526158	Sync.Engine.Bookmarks	DEBUG	Engine constructed
1745768526159	Sync.Engine.Bookmarks	DEBUG	SyncEngine initialized: bookmarks
1745768526159	Sync.Engine.Forms	DEBUG	Engine constructed
1745768526160	Sync.Engine.Forms	DEBUG	SyncEngine initialized: forms
1745768526161	Sync.Engine.History	DEBUG	Engine constructed
1745768526161	Sync.Engine.History	DEBUG	SyncEngine initialized: history
1745768526163	Sync.Engine.Tabs	DEBUG	Engine constructed
1745768526163	Sync.Engine.Tabs	DEBUG	SyncEngine initialized: tabs
1745768526192	Sync.Engine.Tabs	INFO	Got a bridged engine!
1745768526193	Sync.Engine.Addresses	DEBUG	Engine constructed
1745768526195	Sync.Engine.Addresses	DEBUG	SyncEngine initialized: addresses
1745768526195	Sync.Engine.CreditCards	DEBUG	Engine constructed
1745768526195	Sync.Engine.CreditCards	DEBUG	SyncEngine initialized: creditcards
1745768526197	Sync.Engine.Extension-Storage	DEBUG	Engine constructed
1745768526197	Sync.Engine.Extension-Storage	DEBUG	SyncEngine initialized: extension-storage
1745768526201	Sync.Engine.Extension-Storage	INFO	Got a bridged engine!
1745768526202	Sync.Service	INFO	Mozilla/5.0 (X11; Linux x86_64; rv:137.0) Gecko/20100101 Firefox/137.0
1745768526202	Sync.Status	DEBUG	Status.login: error.login.reason.no_username => error.login.reason.no_username
1745768526202	Sync.Status	DEBUG	Status.service: service.client_not_configured => service.client_not_configured
1745768526202	Sync.Status	DEBUG	Status.service: service.client_not_configured => service.client_not_configured
1745768529627	FirefoxAccounts	DEBUG	FxAccountsWebChannel message received: fxaccounts:fxa_status
1745768529628	FirefoxAccounts	TRACE	_receiveMessage for command fxaccounts:fxa_status
1745768529628	FirefoxAccounts	DEBUG	fxa_status received
1745768529628	FirefoxAccounts	DEBUG	fxa status ok=true - private=false, service=sync, context=oauth_webchannel_v1, pairing=false
1745768530687	FirefoxAccounts	DEBUG	FxAccountsWebChannel message received: fxaccounts:fxa_status
1745768530687	FirefoxAccounts	TRACE	_receiveMessage for command fxaccounts:fxa_status
1745768530687	FirefoxAccounts	DEBUG	fxa_status received
1745768530687	FirefoxAccounts	DEBUG	fxa status ok=true - private=false, service=sync, context=oauth_webchannel_v1, pairing=false
1745768545406	FirefoxAccounts	DEBUG	FxAccountsWebChannel message received: fxaccounts:can_link_account
1745768545406	FirefoxAccounts	TRACE	_receiveMessage for command fxaccounts:can_link_account
1745768586620	FirefoxAccounts	DEBUG	FxAccountsWebChannel message received: fxaccounts:login
1745768586620	FirefoxAccounts	TRACE	_receiveMessage for command fxaccounts:login
1745768586620	FirefoxAccounts	DEBUG	Webchannel is logging new a user in.
1745768586621	FirefoxAccounts	DEBUG	storing info for services sync
1745768586622	FirefoxAccounts	DEBUG	setSignedInUser - aborting any existing flows
1745768586622	FirefoxAccounts	DEBUG	removing account data
1745768586622	FirefoxAccounts	TRACE	starting write of json user data: null
1745768586628	FirefoxAccounts	TRACE	finished write of json user data - took: 6
1745768586628	FirefoxAccounts	TRACE	storage set finished clearing account data
1745768586629	FirefoxAccounts	DEBUG	account data reset
1745768586629	FirefoxAccounts	TRACE	StorageManager finalizing
1745768586629	FirefoxAccounts	TRACE	StorageManager finalized
1745768586629	FirefoxAccounts	TRACE	initializing new storage manager
1745768586629	FirefoxAccounts	DEBUG	writing plain storage: ["email","sessionToken","uid","verified","requestedServices"]
1745768586629	FirefoxAccounts	TRACE	starting write of json user data: ["email","sessionToken","uid","verified","requestedServices"]
1745768586631	FirefoxAccounts	TRACE	finished write of json user data - took: 2
1745768586631	FirefoxAccounts	DEBUG	writing secure storage: []
1745768586631	FirefoxAccounts	TRACE	starting write of user data to the login manager
1745768586633	FirefoxAccounts	TRACE	finished write of user data to the login manager
1745768586633	FirefoxAccounts	TRACE	initializing of new storage manager done
1745768586633	FirefoxAccounts	DEBUG	Notifying observers of fxaccounts:onlogin
1745768586633	Sync.SyncAuthManager	DEBUG	observed fxaccounts:onlogin
1745768586633	Sync.SyncAuthManager	INFO	Sync is not configured, so ignoring the notification
1745768586637	FirefoxAccounts	DEBUG	FxAccountsProfileClient: Initialized
1745768586638	FirefoxAccounts	DEBUG	FxAccountsPush loading service
1745768586638	FirefoxAccounts	DEBUG	FxAccountsPush initialized
1745768586638	FirefoxAccounts	TRACE	FxAccountsPush registerPushEndpoint
1745768586638	FirefoxAccounts	DEBUG	FxAccountsProfileClient: Requested profile
1745768586638	FirefoxAccounts	DEBUG	getOAuthToken enter
1745768586638	FirefoxAccounts	ERROR	FxA rejecting with error UNVERIFIED_ACCOUNT, details: undefined
1745768586638	FirefoxAccounts	ERROR	Background refresh of initial profile failed: Error: UNVERIFIED_ACCOUNT(resource://gre/modules/FxAccounts.sys.mjs:1655:18) JS Stack trace: _error@FxAccounts.sys.mjs:1655:18
withSessionToken@FxAccounts.sys.mjs:874:18
1745768586640	FirefoxAccounts	DEBUG	FxAccountsProfileClient: Requested profile
1745768586640	FirefoxAccounts	DEBUG	getOAuthToken enter
1745768586640	FirefoxAccounts	ERROR	FxA rejecting with error UNVERIFIED_ACCOUNT, details: undefined
1745768586640	FirefoxAccounts	ERROR	Background refresh of initial profile failed: Error: UNVERIFIED_ACCOUNT(resource://gre/modules/FxAccounts.sys.mjs:1655:18) JS Stack trace: _error@FxAccounts.sys.mjs:1655:18
withSessionToken@FxAccounts.sys.mjs:874:18
1745768586804	FirefoxAccounts	DEBUG	FxAccountsPush got subscription
1745768586808	FirefoxAccounts	TRACE	Command queue observer created
1745768586808	FirefoxAccounts	TRACE	Getting command keys: https://identity.mozilla.com/cmd/open-uri
1745768586808	FirefoxAccounts	INFO	Generating and persisting encrypted key (false, false)
1745768586808	FirefoxAccounts	INFO	Can't get keys; user is not verified
1745768586808	FirefoxAccounts	INFO	Can't fetch keys, so unable to determine command keys
1745768586808	FirefoxAccounts	TRACE	Getting command keys: https://identity.mozilla.com/cmd/close-uri/v1
1745768586808	FirefoxAccounts	INFO	Generating and persisting encrypted key (false, false)
1745768586808	FirefoxAccounts	INFO	Can't get keys; user is not verified
1745768586808	FirefoxAccounts	INFO	Can't fetch keys, so unable to determine command keys
1745768586808	FirefoxAccounts	INFO	registering with available commands: []
1745768586808	FirefoxAccounts	DEBUG	registering new device details
1745768586811	Services.Common.RESTRequest	DEBUG	POST request to https://api.accounts.firefox.com/v1/account/device
1745768586811	Services.Common.RESTRequest	DEBUG	POST Length: 424
1745768587017	Services.Common.RESTRequest	DEBUG	POST https://api.accounts.firefox.com/v1/account/device 200
1745768587017	Hawk	DEBUG	(Response) /account/device: code: 200 - Status text: 
1745768587017	Hawk	DEBUG	Clock offset vs https://api.accounts.firefox.com/v1: -1017
1745768587017	FirefoxAccounts	DEBUG	_updateAccountData with items: ["device"]
1745768587017	FirefoxAccounts	DEBUG	writing plain storage: ["email","sessionToken","uid","verified","requestedServices","device"]
1745768587017	FirefoxAccounts	TRACE	starting write of json user data: ["email","sessionToken","uid","verified","requestedServices","device"]
1745768587017	FirefoxAccounts	DEBUG	Webchannel finished logging a user in.
1745768587018	FirefoxAccounts	TRACE	finished write of json user data - took: 1
1745768587018	FirefoxAccounts	DEBUG	writing secure storage: []
1745768587018	FirefoxAccounts	TRACE	starting write of user data to the login manager
1745768587022	FirefoxAccounts	TRACE	finished write of user data to the login manager
1745768612873	FirefoxAccounts	TRACE	observed topic=push-message, data=chrome://fxa-device-update, subject=[xpconnect wrapped nsISupports]
1745768612873	FirefoxAccounts	TRACE	FxAccountsPushService _onPushMessage
1745768612873	FirefoxAccounts	DEBUG	empty push message - checking account status
1745768612873	FirefoxAccounts	TRACE	checkVerificationStatus
1745768612873	FirefoxAccounts	TRACE	checkVerificationStatus - forcing verification status check
1745768612873	FirefoxAccounts	DEBUG	entering startPollEmailStatus: push
1745768612873	FirefoxAccounts	DEBUG	entering pollEmailStatus: push
1745768612873	FirefoxAccounts	DEBUG	not polling for verification because oauth is enabled
1745768614024	FirefoxAccounts	DEBUG	FxAccountsWebChannel message received: fxaccounts:oauth_login
1745768614024	FirefoxAccounts	TRACE	_receiveMessage for command fxaccounts:oauth_login
1745768614024	FirefoxAccounts	DEBUG	Webchannel is completing the oauth flow
1745768614031	Services.Common.RESTRequest	DEBUG	POST request to https://api.accounts.firefox.com/v1/oauth/token
1745768614031	Services.Common.RESTRequest	DEBUG	POST Length: 202
1745768614299	Services.Common.RESTRequest	DEBUG	POST https://api.accounts.firefox.com/v1/oauth/token 200
1745768614299	Hawk	DEBUG	(Response) /oauth/token: code: 200 - Status text: 
1745768614299	Hawk	DEBUG	Clock offset vs https://api.accounts.firefox.com/v1: -299
1745768614302	Services.Common.RESTRequest	DEBUG	POST request to https://api.accounts.firefox.com/v1/oauth/destroy
1745768614302	Services.Common.RESTRequest	DEBUG	POST Length: 107
1745768614468	Services.Common.RESTRequest	DEBUG	POST https://api.accounts.firefox.com/v1/oauth/destroy 200
1745768614468	Hawk	DEBUG	(Response) /oauth/destroy: code: 200 - Status text: 
1745768614468	Hawk	DEBUG	Clock offset vs https://api.accounts.firefox.com/v1: -468
1745768614469	FirefoxAccounts	DEBUG	_updateAccountData with items: ["scopedKeys"]
1745768614469	FirefoxAccounts	DEBUG	writing plain storage: ["email","sessionToken","uid","verified","requestedServices","device"]
1745768614469	FirefoxAccounts	TRACE	starting write of json user data: ["email","sessionToken","uid","verified","requestedServices","device"]
1745768614469	FirefoxAccounts	DEBUG	services requested are sync
1745768614469	FirefoxAccounts	DEBUG	Did not receive any engine selection information
1745768614469	FirefoxAccounts	DEBUG	Webchannel is enabling sync
1745768614469	Sync.Service	INFO	Configuring sync with current FxA user
1745768614471	FirefoxAccounts	DEBUG	FxAccountsProfileClient: Requested profile
1745768614471	FirefoxAccounts	DEBUG	getOAuthToken enter
1745768614472	Sync.SyncAuthManager	DEBUG	observed weave:connected
1745768614472	Sync.SyncAuthManager	INFO	Sync has been connected to a logged in user
1745768614472	FirefoxAccounts	DEBUG	updateUserAccountData called with fields: ["uid","requestedServices"]
1745768614472	FirefoxAccounts	ERROR	FxA rejecting with error UNVERIFIED_ACCOUNT, details: undefined
1745768614473	FirefoxAccounts	DEBUG	_updateAccountData with items: ["requestedServices"]
1745768614473	FirefoxAccounts	ERROR	Background refresh of initial profile failed: Error: UNVERIFIED_ACCOUNT(resource://gre/modules/FxAccounts.sys.mjs:1655:18) JS Stack trace: _error@FxAccounts.sys.mjs:1655:18
withSessionToken@FxAccounts.sys.mjs:874:18
1745768614473	FirefoxAccounts	DEBUG	FxAccountsProfileClient: Requested profile
1745768614473	FirefoxAccounts	DEBUG	getOAuthToken enter
1745768614473	Sync.SyncAuthManager	INFO	The user is not verified
1745768614474	FirefoxAccounts	DEBUG	_updateAccountData with items: ["verified"]
1745768614474	FirefoxAccounts	ERROR	FxA rejecting with error UNVERIFIED_ACCOUNT, details: undefined
1745768614474	FirefoxAccounts	DEBUG	Notifying observers of fxaccounts:onverified
1745768614526	FirefoxAccounts	ERROR	Background refresh of initial profile failed: Error: UNVERIFIED_ACCOUNT(resource://gre/modules/FxAccounts.sys.mjs:1655:18) JS Stack trace: _error@FxAccounts.sys.mjs:1655:18
withSessionToken@FxAccounts.sys.mjs:874:18
1745768614526	FirefoxAccounts	ERROR	Background refresh of initial profile failed: Error: UNVERIFIED_ACCOUNT(resource://gre/modules/FxAccounts.sys.mjs:1655:18) JS Stack trace: _error@FxAccounts.sys.mjs:1655:18
withSessionToken@FxAccounts.sys.mjs:874:18
1745768614526	Sync.SyncAuthManager	DEBUG	observed fxaccounts:onverified
1745768614526	Sync.SyncAuthManager	INFO	The user became verified
1745768614526	Sync.Status	DEBUG	Status.login: error.login.reason.no_username => success.login
1745768614526	Sync.Status	DEBUG	Status.service: service.client_not_configured => success.status_ok
1745768614526	Sync.SyncAuthManager	INFO	Doing initial sync actions
1745768614527	Sync.AddonsReconciler	INFO	Registering as Add-on Manager listener.
1745768614527	Sync.AddonsReconciler	DEBUG	Adding change listener.
1745768614527	Sync.Engine.History.Tracker	INFO	Adding Places observer.
1745768614529	Sync.Service	DEBUG	User-Agent: Firefox/137.0.2 (Linux x86_64) FxSync/1.139.0.20250414091429.desktop
1745768614529	Sync.Service	INFO	Starting sync at 2025-04-27 17:43:34 in browser session KhrT8KSSX3eD
1745768614529	Sync.Service	DEBUG	In sync: should login.
1745768614529	Sync.Service	INFO	User logged in successfully - verifying login.
1745768614530	FirefoxAccounts	DEBUG	Webchannel completed oauth flows
1745768614530	FirefoxAccounts	TRACE	Getting command keys: https://identity.mozilla.com/cmd/open-uri
1745768614530	FirefoxAccounts	INFO	Generating and persisting encrypted key (false, false)
1745768614530	FirefoxAccounts	DEBUG	FxAccountsProfileClient: Requested profile
1745768614530	FirefoxAccounts	DEBUG	getOAuthToken enter
1745768614532	Sync.SyncAuthManager	DEBUG	unlockAndVerifyAuthState already has (or can fetch) sync keys
1745768614533	FirefoxAccounts	INFO	fetching updated device list
1745768614534	Sync.Status	DEBUG	Status.login: success.login => success.status_ok
1745768614534	Sync.Status	DEBUG	Status.service: success.status_ok => error.login.failed
1745768614534	Sync.Service	DEBUG	Fetching unlocked auth state returned success.status_ok
1745768614534	FirefoxAccounts	INFO	Could not find command keys, generating them
1745768614535	Sync.SyncAuthManager	INFO	Getting sync key
1745768614536	FirefoxAccounts	DEBUG	getOAuthToken enter
1745768614574	FirefoxAccounts	TRACE	finished write of json user data - took: 105
1745768614574	FirefoxAccounts	DEBUG	writing secure storage: ["scopedKeys"]
1745768614574	FirefoxAccounts	TRACE	starting write of user data to the login manager
1745768614576	FirefoxAccounts	TRACE	finished write of user data to the login manager
1745768614576	FirefoxAccounts	DEBUG	writing plain storage: ["email","sessionToken","uid","verified","device"]
1745768614576	FirefoxAccounts	TRACE	starting write of json user data: ["email","sessionToken","uid","verified","device"]
1745768614576	Services.Common.RESTRequest	DEBUG	GET request to https://api.accounts.firefox.com/v1/account/attached_clients
1745768614576	FirefoxAccounts	TRACE	writing to sendTabKeys for command https://identity.mozilla.com/cmd/open-uri
1745768614576	FirefoxAccounts	DEBUG	_updateAccountData with items: ["device"]
1745768614577	Sync.BulkKeyBundle	INFO	BulkKeyBundle being created for undefined
1745768614577	Services.Common.RESTRequest	DEBUG	GET request to https://api.accounts.firefox.com/v1/account/devices?filterIdleDevicesTimestamp=1743954214535
1745768614577	Services.Common.RESTRequest	DEBUG	POST request to https://api.accounts.firefox.com/v1/oauth/token
1745768614577	Services.Common.RESTRequest	DEBUG	POST Length: 81
1745768614578	Services.Common.RESTRequest	DEBUG	POST request to https://api.accounts.firefox.com/v1/oauth/token
1745768614578	Services.Common.RESTRequest	DEBUG	POST Length: 127
1745768614578	FirefoxAccounts	TRACE	finished write of json user data - took: 2
1745768614578	FirefoxAccounts	DEBUG	writing secure storage: ["scopedKeys"]
1745768614578	FirefoxAccounts	TRACE	starting write of user data to the login manager
1745768614580	FirefoxAccounts	TRACE	finished write of user data to the login manager
1745768614580	FirefoxAccounts	DEBUG	writing plain storage: ["email","sessionToken","uid","verified","device"]
1745768614580	FirefoxAccounts	TRACE	starting write of json user data: ["email","sessionToken","uid","verified","device"]
1745768614580	FirefoxAccounts	DEBUG	_updateAccountData with items: ["encryptedSendTabKeys"]
1745768614580	FirefoxAccounts	TRACE	Getting command keys: https://identity.mozilla.com/cmd/close-uri/v1
1745768614580	FirefoxAccounts	INFO	Generating and persisting encrypted key (false, false)
1745768614580	FirefoxAccounts	INFO	Could not find command keys, generating them
1745768614580	FirefoxAccounts	TRACE	finished write of json user data - took: 0
1745768614580	FirefoxAccounts	DEBUG	writing secure storage: ["scopedKeys"]
1745768614580	FirefoxAccounts	TRACE	starting write of user data to the login manager
1745768614584	FirefoxAccounts	TRACE	finished write of user data to the login manager
1745768614584	FirefoxAccounts	DEBUG	writing plain storage: ["email","sessionToken","uid","verified","device","encryptedSendTabKeys"]
1745768614584	FirefoxAccounts	TRACE	starting write of json user data: ["email","sessionToken","uid","verified","device","encryptedSendTabKeys"]
1745768614584	FirefoxAccounts	TRACE	writing to closeTabKeys for command https://identity.mozilla.com/cmd/close-uri/v1
1745768614585	FirefoxAccounts	DEBUG	_updateAccountData with items: ["device"]
1745768614585	Sync.BulkKeyBundle	INFO	BulkKeyBundle being created for undefined
1745768614585	FirefoxAccounts	TRACE	finished write of json user data - took: 1
1745768614585	FirefoxAccounts	DEBUG	writing secure storage: ["scopedKeys"]
1745768614585	FirefoxAccounts	TRACE	starting write of user data to the login manager
1745768614587	FirefoxAccounts	TRACE	finished write of user data to the login manager
1745768614587	FirefoxAccounts	DEBUG	writing plain storage: ["email","sessionToken","uid","verified","device","encryptedSendTabKeys"]
1745768614587	FirefoxAccounts	TRACE	starting write of json user data: ["email","sessionToken","uid","verified","device","encryptedSendTabKeys"]
1745768614587	FirefoxAccounts	DEBUG	_updateAccountData with items: ["encryptedCloseTabKeys"]
1745768614588	FirefoxAccounts	TRACE	FxAccountsPush registerPushEndpoint
1745768614588	FirefoxAccounts	TRACE	finished write of json user data - took: 1
1745768614588	FirefoxAccounts	DEBUG	writing secure storage: ["scopedKeys"]
1745768614588	FirefoxAccounts	TRACE	starting write of user data to the login manager
1745768614590	FirefoxAccounts	TRACE	finished write of user data to the login manager
1745768614590	FirefoxAccounts	DEBUG	writing plain storage: ["email","sessionToken","uid","verified","device","encryptedSendTabKeys","encryptedCloseTabKeys"]
1745768614590	FirefoxAccounts	TRACE	starting write of json user data: ["email","sessionToken","uid","verified","device","encryptedSendTabKeys","encryptedCloseTabKeys"]
1745768614590	FirefoxAccounts	TRACE	finished write of json user data - took: 0
1745768614590	FirefoxAccounts	DEBUG	writing secure storage: ["scopedKeys"]
1745768614590	FirefoxAccounts	TRACE	starting write of user data to the login manager
1745768614592	FirefoxAccounts	TRACE	finished write of user data to the login manager
1745768614592	FirefoxAccounts	DEBUG	writing plain storage: ["email","sessionToken","uid","verified","device","encryptedSendTabKeys","encryptedCloseTabKeys"]
1745768614592	FirefoxAccounts	TRACE	starting write of json user data: ["email","sessionToken","uid","verified","device","encryptedSendTabKeys","encryptedCloseTabKeys"]
1745768614592	FirefoxAccounts	DEBUG	FxAccountsPush got subscription
1745768614592	FirefoxAccounts	TRACE	Getting command keys: https://identity.mozilla.com/cmd/open-uri
1745768614592	FirefoxAccounts	TRACE	Getting command keys: https://identity.mozilla.com/cmd/close-uri/v1
1745768614592	FirefoxAccounts	INFO	registering with available commands: ["https://identity.mozilla.com/cmd/close-uri/v1","https://identity.mozilla.com/cmd/open-uri"]
1745768614592	FirefoxAccounts	DEBUG	updating existing device details
1745768614592	FirefoxAccounts	TRACE	finished write of json user data - took: 0
1745768614592	FirefoxAccounts	DEBUG	writing secure storage: ["scopedKeys"]
1745768614593	FirefoxAccounts	TRACE	starting write of user data to the login manager
1745768614594	FirefoxAccounts	TRACE	finished write of user data to the login manager
1745768614594	Services.Common.RESTRequest	DEBUG	POST request to https://api.accounts.firefox.com/v1/account/device
1745768614595	Services.Common.RESTRequest	DEBUG	POST Length: 1288
1745768614752	Services.Common.RESTRequest	DEBUG	GET https://api.accounts.firefox.com/v1/account/devices?filterIdleDevicesTimestamp=1743954214535 200
1745768614752	Hawk	DEBUG	(Response) /account/devices?filterIdleDevicesTimestamp=1743954214535: code: 200 - Status text: 
1745768614752	Hawk	DEBUG	Clock offset vs https://api.accounts.firefox.com/v1: -752
1745768614752	FirefoxAccounts	INFO	Got new device list: 082a1fe81d5f13cb4dc82ee5f8bc3403, 15490bd7543d3ea5f6cdcc7665489b92, 62ffa57302f7a0b65972b4e1fca62915, 6de8d6a220125232ee92a7669f20eb9d, 903bcb136999ed68797148cd6c718df7, 9ba76a2e0e25699240f0c1e9b397e59c, a5ccf3040f31d7e11294fc6f01c3575f, e53578f100ead96442d09691bd5fccd9
1745768614753	FirefoxAccounts	TRACE	Getting command keys: https://identity.mozilla.com/cmd/open-uri
1745768614753	FirefoxAccounts	TRACE	Getting command keys: https://identity.mozilla.com/cmd/close-uri/v1
1745768614753	FirefoxAccounts	WARN	Our commands need to be updated on the server
1745768614753	FirefoxAccounts	TRACE	FxAccountsPush registerPushEndpoint
1745768614753	FirefoxAccounts	DEBUG	FxAccountsPush got subscription
1745768614754	FirefoxAccounts	TRACE	Getting command keys: https://identity.mozilla.com/cmd/open-uri
1745768614754	FirefoxAccounts	TRACE	Getting command keys: https://identity.mozilla.com/cmd/close-uri/v1
1745768614754	FirefoxAccounts	INFO	registering with available commands: ["https://identity.mozilla.com/cmd/close-uri/v1","https://identity.mozilla.com/cmd/open-uri"]
1745768614754	FirefoxAccounts	DEBUG	updating existing device details
1745768614754	Services.Common.RESTRequest	DEBUG	POST request to https://api.accounts.firefox.com/v1/account/device
1745768614754	Services.Common.RESTRequest	DEBUG	POST Length: 1288
1745768614763	Services.Common.RESTRequest	DEBUG	GET https://api.accounts.firefox.com/v1/account/attached_clients 200
1745768614763	Hawk	DEBUG	(Response) /account/attached_clients: code: 200 - Status text: 
1745768614763	Hawk	DEBUG	Clock offset vs https://api.accounts.firefox.com/v1: -763
1745768614765	Services.Common.RESTRequest	DEBUG	POST https://api.accounts.firefox.com/v1/account/device 200
1745768614765	Hawk	DEBUG	(Response) /account/device: code: 200 - Status text: 
1745768614765	Hawk	DEBUG	Clock offset vs https://api.accounts.firefox.com/v1: -765
1745768614765	FirefoxAccounts	DEBUG	_updateAccountData with items: ["device"]
1745768614765	FirefoxAccounts	DEBUG	writing plain storage: ["email","sessionToken","uid","verified","device","encryptedSendTabKeys","encryptedCloseTabKeys"]
1745768614765	FirefoxAccounts	TRACE	starting write of json user data: ["email","sessionToken","uid","verified","device","encryptedSendTabKeys","encryptedCloseTabKeys"]
1745768614766	FirefoxAccounts	TRACE	finished write of json user data - took: 1
1745768614766	FirefoxAccounts	DEBUG	writing secure storage: ["scopedKeys"]
1745768614766	FirefoxAccounts	TRACE	starting write of user data to the login manager
1745768614769	FirefoxAccounts	TRACE	finished write of user data to the login manager
1745768614773	Services.Common.RESTRequest	DEBUG	POST https://api.accounts.firefox.com/v1/oauth/token 200
1745768614773	Hawk	DEBUG	(Response) /oauth/token: code: 200 - Status text: 
1745768614773	Hawk	DEBUG	Clock offset vs https://api.accounts.firefox.com/v1: -773
1745768614773	FirefoxAccounts	DEBUG	_updateAccountData with items: ["oauthTokens"]
1745768614774	FirefoxAccounts	DEBUG	writing plain storage: ["email","sessionToken","uid","verified","device","encryptedSendTabKeys","encryptedCloseTabKeys","oauthTokens"]
1745768614774	FirefoxAccounts	TRACE	starting write of json user data: ["email","sessionToken","uid","verified","device","encryptedSendTabKeys","encryptedCloseTabKeys","oauthTokens"]
1745768614774	Sync.SyncAuthManager	INFO	Getting a sync token from: https://XXXXXXXXXXXXXXXXXXXX/ffsync/1.0/sync/1.5
1745768614774	Sync.SyncAuthManager	DEBUG	Getting a token using OAuth
1745768614774	Services.Common.TokenServerClient	DEBUG	Beginning OAuth token exchange: https://XXXXXXXXXXXXXXXXXXXX/ffsync/1.0/sync/1.5
1745768614774	Services.Common.RESTRequest	DEBUG	GET request to https://XXXXXXXXXXXXXXXXXXXX/ffsync/1.0/sync/1.5
1745768614775	FirefoxAccounts	TRACE	finished write of json user data - took: 1
1745768614775	FirefoxAccounts	DEBUG	writing secure storage: ["scopedKeys"]
1745768614775	FirefoxAccounts	TRACE	starting write of user data to the login manager
1745768614777	FirefoxAccounts	TRACE	finished write of user data to the login manager
1745768614820	Services.Common.RESTRequest	DEBUG	POST https://api.accounts.firefox.com/v1/oauth/token 200
1745768614820	Hawk	DEBUG	(Response) /oauth/token: code: 200 - Status text: 
1745768614820	Hawk	DEBUG	Clock offset vs https://api.accounts.firefox.com/v1: -820
1745768614820	FirefoxAccounts	DEBUG	_updateAccountData with items: ["oauthTokens"]
1745768614820	FirefoxAccounts	DEBUG	writing plain storage: ["email","sessionToken","uid","verified","device","encryptedSendTabKeys","encryptedCloseTabKeys","oauthTokens"]
1745768614820	FirefoxAccounts	TRACE	starting write of json user data: ["email","sessionToken","uid","verified","device","encryptedSendTabKeys","encryptedCloseTabKeys","oauthTokens"]
1745768614820	Services.Common.RESTRequest	DEBUG	GET request to https://profile.accounts.firefox.com/v1/profile
1745768614821	FirefoxAccounts	TRACE	finished write of json user data - took: 1
1745768614821	FirefoxAccounts	DEBUG	writing secure storage: ["scopedKeys"]
1745768614821	FirefoxAccounts	TRACE	starting write of user data to the login manager
1745768614824	FirefoxAccounts	TRACE	finished write of user data to the login manager
1745768614950	Services.Common.RESTRequest	DEBUG	POST https://api.accounts.firefox.com/v1/account/device 200
1745768614950	Hawk	DEBUG	(Response) /account/device: code: 200 - Status text: 
1745768614950	Hawk	DEBUG	Clock offset vs https://api.accounts.firefox.com/v1: -950
1745768614950	FirefoxAccounts	DEBUG	_updateAccountData with items: ["device"]
1745768614950	FirefoxAccounts	DEBUG	writing plain storage: ["email","sessionToken","uid","verified","device","encryptedSendTabKeys","encryptedCloseTabKeys","oauthTokens"]
1745768614950	FirefoxAccounts	TRACE	starting write of json user data: ["email","sessionToken","uid","verified","device","encryptedSendTabKeys","encryptedCloseTabKeys","oauthTokens"]
1745768614951	FirefoxAccounts	INFO	updating the cache
1745768614951	FirefoxAccounts	TRACE	finished write of json user data - took: 1
1745768614951	FirefoxAccounts	DEBUG	writing secure storage: ["scopedKeys"]
1745768614951	FirefoxAccounts	TRACE	starting write of user data to the login manager
1745768614953	FirefoxAccounts	TRACE	finished write of user data to the login manager
1745768615015	Services.Common.RESTRequest	DEBUG	GET https://profile.accounts.firefox.com/v1/profile 200
1745768615015	FirefoxAccounts	DEBUG	_updateAccountData with items: ["profileCache"]
1745768615015	FirefoxAccounts	DEBUG	writing plain storage: ["email","sessionToken","uid","verified","device","encryptedSendTabKeys","encryptedCloseTabKeys","oauthTokens","profileCache"]
1745768615016	FirefoxAccounts	TRACE	starting write of json user data: ["email","sessionToken","uid","verified","device","encryptedSendTabKeys","encryptedCloseTabKeys","oauthTokens","profileCache"]
1745768615016	FirefoxAccounts	DEBUG	notifying profile changed for user XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX
1745768615016	FirefoxAccounts	TRACE	not checking freshness of profile as it remains recent
1745768615018	FirefoxAccounts	TRACE	finished write of json user data - took: 2
1745768615018	FirefoxAccounts	DEBUG	writing secure storage: ["scopedKeys"]
1745768615018	FirefoxAccounts	TRACE	starting write of user data to the login manager
1745768615021	FirefoxAccounts	TRACE	finished write of user data to the login manager
1745768615587	Services.Common.RESTRequest	DEBUG	GET https://XXXXXXXXXXXXXXXXXXXX/ffsync/1.0/sync/1.5 401
1745768615587	Services.Common.TokenServerClient	DEBUG	Got token response: 401
1745768615587	Services.Common.TokenServerClient	INFO	Server-reported error: {"location":"body","name":"","description":"Unauthorized"}
1745768615588	Services.Common.RESTRequest	DEBUG	POST request to https://api.accounts.firefox.com/v1/oauth/destroy
1745768615588	Services.Common.RESTRequest	DEBUG	POST Length: 969
1745768615588	FirefoxAccounts	DEBUG	_updateAccountData with items: ["oauthTokens"]
1745768615588	FirefoxAccounts	DEBUG	writing plain storage: ["email","sessionToken","uid","verified","device","encryptedSendTabKeys","encryptedCloseTabKeys","oauthTokens","profileCache"]
1745768615588	FirefoxAccounts	TRACE	starting write of json user data: ["email","sessionToken","uid","verified","device","encryptedSendTabKeys","encryptedCloseTabKeys","oauthTokens","profileCache"]
1745768615588	Sync.SyncAuthManager	WARN	Token server returned 401, retrying token fetch with fresh credentials
1745768615588	FirefoxAccounts	DEBUG	getOAuthToken enter
1745768615589	FirefoxAccounts	TRACE	finished write of json user data - took: 1
1745768615589	FirefoxAccounts	DEBUG	writing secure storage: ["scopedKeys"]
1745768615589	FirefoxAccounts	TRACE	starting write of user data to the login manager
1745768615591	FirefoxAccounts	TRACE	finished write of user data to the login manager
1745768615591	Services.Common.RESTRequest	DEBUG	POST request to https://api.accounts.firefox.com/v1/oauth/token
1745768615591	Services.Common.RESTRequest	DEBUG	POST Length: 127
1745768615765	Services.Common.RESTRequest	DEBUG	POST https://api.accounts.firefox.com/v1/oauth/destroy 200
1745768615765	Hawk	DEBUG	(Response) /oauth/destroy: code: 200 - Status text: 
1745768615765	Hawk	DEBUG	Clock offset vs https://api.accounts.firefox.com/v1: -765
1745768615816	Services.Common.RESTRequest	DEBUG	POST https://api.accounts.firefox.com/v1/oauth/token 200
1745768615816	Hawk	DEBUG	(Response) /oauth/token: code: 200 - Status text: 
1745768615816	Hawk	DEBUG	Clock offset vs https://api.accounts.firefox.com/v1: -816
1745768615816	FirefoxAccounts	DEBUG	_updateAccountData with items: ["oauthTokens"]
1745768615817	FirefoxAccounts	DEBUG	writing plain storage: ["email","sessionToken","uid","verified","device","encryptedSendTabKeys","encryptedCloseTabKeys","oauthTokens","profileCache"]
1745768615817	FirefoxAccounts	TRACE	starting write of json user data: ["email","sessionToken","uid","verified","device","encryptedSendTabKeys","encryptedCloseTabKeys","oauthTokens","profileCache"]
1745768615817	Sync.SyncAuthManager	INFO	Getting a sync token from: https://XXXXXXXXXXXXXXXXXXXX/ffsync/1.0/sync/1.5
1745768615817	Sync.SyncAuthManager	DEBUG	Getting a token using OAuth
1745768615817	Services.Common.TokenServerClient	DEBUG	Beginning OAuth token exchange: https://XXXXXXXXXXXXXXXXXXXX/ffsync/1.0/sync/1.5
1745768615817	Services.Common.RESTRequest	DEBUG	GET request to https://XXXXXXXXXXXXXXXXXXXX/ffsync/1.0/sync/1.5
1745768615817	FirefoxAccounts	TRACE	finished write of json user data - took: 0
1745768615817	FirefoxAccounts	DEBUG	writing secure storage: ["scopedKeys"]
1745768615817	FirefoxAccounts	TRACE	starting write of user data to the login manager
1745768615820	FirefoxAccounts	TRACE	finished write of user data to the login manager
1745768615993	Services.Common.RESTRequest	DEBUG	GET https://XXXXXXXXXXXXXXXXXXXX/ffsync/1.0/sync/1.5 401
1745768615993	Services.Common.TokenServerClient	DEBUG	Got token response: 401
1745768615993	Services.Common.TokenServerClient	INFO	Server-reported error: {"location":"body","name":"","description":"Unauthorized"}
1745768615994	Services.Common.RESTRequest	DEBUG	POST request to https://api.accounts.firefox.com/v1/oauth/destroy
1745768615994	Services.Common.RESTRequest	DEBUG	POST Length: 969
1745768615994	FirefoxAccounts	DEBUG	_updateAccountData with items: ["oauthTokens"]
1745768615994	FirefoxAccounts	DEBUG	writing plain storage: ["email","sessionToken","uid","verified","device","encryptedSendTabKeys","encryptedCloseTabKeys","oauthTokens","profileCache"]
1745768615994	FirefoxAccounts	TRACE	starting write of json user data: ["email","sessionToken","uid","verified","device","encryptedSendTabKeys","encryptedCloseTabKeys","oauthTokens","profileCache"]
1745768615994	Sync.SyncAuthManager	ERROR	Authentication error in _fetchTokenForUser: {"details":{"now":"2025-04-27T15:43:35.993Z","message":"Authentication failed.","cause":"invalid-credentials","response_body":"{\"status\":\"invalid-credentials\",\"errors\":[{\"location\":\"body\",\"name\":\"\",\"description\":\"Unauthorized\"}]}","response_headers":{"date":"Sun, 27 Apr 2025 15:43:22 GMT","server":"Apache/2.4.62 (Debian)","strict-transport-security":"max-age=15552000; $","content-length":"102","content-type":"application/json","vary":"Origin,Access-Control-Request-Method,Access-Control-Request-Headers","x-weave-timestamp":"1745768602.50","keep-alive":"timeout=5, max=99","connection":"Keep-Alive"},"response_status":401,"name":"TokenServerClientServerError"},"source":"tokenserver"}
1745768615994	Sync.Status	DEBUG	Status.login: success.status_ok => error.login.reason.account
1745768615994	Sync.Status	DEBUG	Status.service: error.login.failed => error.login.failed
1745768615995	Sync.SyncAuthManager	INFO	Failed to fetch the cluster URL: {"details":{"now":"2025-04-27T15:43:35.993Z","message":"Authentication failed.","cause":"invalid-credentials","response_body":"{\"status\":\"invalid-credentials\",\"errors\":[{\"location\":\"body\",\"name\":\"\",\"description\":\"Unauthorized\"}]}","response_headers":{"date":"Sun, 27 Apr 2025 15:43:22 GMT","server":"Apache/2.4.62 (Debian)","strict-transport-security":"max-age=15552000; $","content-length":"102","content-type":"application/json","vary":"Origin,Access-Control-Request-Method,Access-Control-Request-Headers","x-weave-timestamp":"1745768602.50","keep-alive":"timeout=5, max=99","connection":"Keep-Alive"},"response_status":401,"name":"TokenServerClientServerError"},"source":"tokenserver"}
1745768615995	Sync.SyncAuthManager	DEBUG	Cluster value = null
1745768615995	Sync.Status	DEBUG	Status.sync: success.sync => error.sync.reason.no_node_found
1745768615995	Sync.Status	DEBUG	Status.service: error.login.failed => error.sync.failed
1745768615995	FirefoxAccounts	TRACE	not checking freshness of profile as it remains recent
1745768615995	Sync.SyncScheduler	DEBUG	Clearing sync triggers and the global score.
1745768615996	Sync.Status	INFO	Resetting Status.
1745768615996	Sync.Status	DEBUG	Status.service: error.sync.failed => success.status_ok
1745768615996	FirefoxAccounts	TRACE	not checking freshness of profile as it remains recent
1745768615997	Sync.SyncAuthManager	INFO	Getting sync key
1745768615997	FirefoxAccounts	DEBUG	getOAuthToken enter
1745768615998	FirefoxAccounts	TRACE	finished write of json user data - took: 4
1745768615998	FirefoxAccounts	DEBUG	writing secure storage: ["scopedKeys"]
1745768615998	FirefoxAccounts	TRACE	starting write of user data to the login manager
1745768616001	FirefoxAccounts	TRACE	finished write of user data to the login manager
1745768616002	Services.Common.RESTRequest	DEBUG	POST request to https://api.accounts.firefox.com/v1/oauth/token
1745768616002	Services.Common.RESTRequest	DEBUG	POST Length: 127
1745768616159	Services.Common.RESTRequest	DEBUG	POST https://api.accounts.firefox.com/v1/oauth/destroy 200
1745768616159	Hawk	DEBUG	(Response) /oauth/destroy: code: 200 - Status text: 
1745768616159	Hawk	DEBUG	Clock offset vs https://api.accounts.firefox.com/v1: -159
1745768616180	Services.Common.RESTRequest	DEBUG	POST https://api.accounts.firefox.com/v1/oauth/token 200
1745768616180	Hawk	DEBUG	(Response) /oauth/token: code: 200 - Status text: 
1745768616180	Hawk	DEBUG	Clock offset vs https://api.accounts.firefox.com/v1: -180
1745768616180	FirefoxAccounts	DEBUG	_updateAccountData with items: ["oauthTokens"]
1745768616180	FirefoxAccounts	DEBUG	writing plain storage: ["email","sessionToken","uid","verified","device","encryptedSendTabKeys","encryptedCloseTabKeys","oauthTokens","profileCache"]
1745768616180	FirefoxAccounts	TRACE	starting write of json user data: ["email","sessionToken","uid","verified","device","encryptedSendTabKeys","encryptedCloseTabKeys","oauthTokens","profileCache"]
1745768616180	Sync.SyncAuthManager	INFO	Getting a sync token from: https://XXXXXXXXXXXXXXXXXXXX/ffsync/1.0/sync/1.5
1745768616180	Sync.SyncAuthManager	DEBUG	Getting a token using OAuth
1745768616180	Services.Common.TokenServerClient	DEBUG	Beginning OAuth token exchange: https://XXXXXXXXXXXXXXXXXXXX/ffsync/1.0/sync/1.5
1745768616180	Services.Common.RESTRequest	DEBUG	GET request to https://XXXXXXXXXXXXXXXXXXXX/ffsync/1.0/sync/1.5
1745768616181	FirefoxAccounts	TRACE	finished write of json user data - took: 1
1745768616181	FirefoxAccounts	DEBUG	writing secure storage: ["scopedKeys"]
1745768616181	FirefoxAccounts	TRACE	starting write of user data to the login manager
1745768616184	FirefoxAccounts	TRACE	finished write of user data to the login manager
1745768616357	Services.Common.RESTRequest	DEBUG	GET https://XXXXXXXXXXXXXXXXXXXX/ffsync/1.0/sync/1.5 401
1745768616357	Services.Common.TokenServerClient	DEBUG	Got token response: 401
1745768616357	Services.Common.TokenServerClient	INFO	Server-reported error: {"location":"body","name":"","description":"Unauthorized"}
1745768616358	Services.Common.RESTRequest	DEBUG	POST request to https://api.accounts.firefox.com/v1/oauth/destroy
1745768616358	Services.Common.RESTRequest	DEBUG	POST Length: 969
1745768616358	FirefoxAccounts	DEBUG	_updateAccountData with items: ["oauthTokens"]
1745768616358	FirefoxAccounts	DEBUG	writing plain storage: ["email","sessionToken","uid","verified","device","encryptedSendTabKeys","encryptedCloseTabKeys","oauthTokens","profileCache"]
1745768616358	FirefoxAccounts	TRACE	starting write of json user data: ["email","sessionToken","uid","verified","device","encryptedSendTabKeys","encryptedCloseTabKeys","oauthTokens","profileCache"]
1745768616358	Sync.SyncAuthManager	WARN	Token server returned 401, retrying token fetch with fresh credentials
1745768616359	FirefoxAccounts	DEBUG	getOAuthToken enter
1745768616359	FirefoxAccounts	TRACE	finished write of json user data - took: 1
1745768616360	FirefoxAccounts	DEBUG	writing secure storage: ["scopedKeys"]
1745768616360	FirefoxAccounts	TRACE	starting write of user data to the login manager
1745768616363	FirefoxAccounts	TRACE	finished write of user data to the login manager
1745768616363	Services.Common.RESTRequest	DEBUG	POST request to https://api.accounts.firefox.com/v1/oauth/token
1745768616363	Services.Common.RESTRequest	DEBUG	POST Length: 127
1745768616529	Services.Common.RESTRequest	DEBUG	POST https://api.accounts.firefox.com/v1/oauth/destroy 200
1745768616529	Hawk	DEBUG	(Response) /oauth/destroy: code: 200 - Status text: 
1745768616529	Hawk	DEBUG	Clock offset vs https://api.accounts.firefox.com/v1: -529
1745768616590	Services.Common.RESTRequest	DEBUG	POST https://api.accounts.firefox.com/v1/oauth/token 200
1745768616590	Hawk	DEBUG	(Response) /oauth/token: code: 200 - Status text: 
1745768616590	Hawk	DEBUG	Clock offset vs https://api.accounts.firefox.com/v1: -590
1745768616590	FirefoxAccounts	DEBUG	_updateAccountData with items: ["oauthTokens"]
1745768616590	FirefoxAccounts	DEBUG	writing plain storage: ["email","sessionToken","uid","verified","device","encryptedSendTabKeys","encryptedCloseTabKeys","oauthTokens","profileCache"]
1745768616590	FirefoxAccounts	TRACE	starting write of json user data: ["email","sessionToken","uid","verified","device","encryptedSendTabKeys","encryptedCloseTabKeys","oauthTokens","profileCache"]
1745768616590	Sync.SyncAuthManager	INFO	Getting a sync token from: https://XXXXXXXXXXXXXXXXXXXX/ffsync/1.0/sync/1.5
1745768616590	Sync.SyncAuthManager	DEBUG	Getting a token using OAuth
1745768616590	Services.Common.TokenServerClient	DEBUG	Beginning OAuth token exchange: https://XXXXXXXXXXXXXXXXXXXX/ffsync/1.0/sync/1.5
1745768616590	Services.Common.RESTRequest	DEBUG	GET request to https://XXXXXXXXXXXXXXXXXXXX/ffsync/1.0/sync/1.5
1745768616591	FirefoxAccounts	TRACE	finished write of json user data - took: 1
1745768616591	FirefoxAccounts	DEBUG	writing secure storage: ["scopedKeys"]
1745768616591	FirefoxAccounts	TRACE	starting write of user data to the login manager
1745768616593	FirefoxAccounts	TRACE	finished write of user data to the login manager
1745768616773	Services.Common.RESTRequest	DEBUG	GET https://XXXXXXXXXXXXXXXXXXXX/ffsync/1.0/sync/1.5 401
1745768616773	Services.Common.TokenServerClient	DEBUG	Got token response: 401
1745768616773	Services.Common.TokenServerClient	INFO	Server-reported error: {"location":"body","name":"","description":"Unauthorized"}
1745768616774	Services.Common.RESTRequest	DEBUG	POST request to https://api.accounts.firefox.com/v1/oauth/destroy
1745768616774	Services.Common.RESTRequest	DEBUG	POST Length: 969
1745768616774	FirefoxAccounts	DEBUG	_updateAccountData with items: ["oauthTokens"]
1745768616774	FirefoxAccounts	DEBUG	writing plain storage: ["email","sessionToken","uid","verified","device","encryptedSendTabKeys","encryptedCloseTabKeys","oauthTokens","profileCache"]
1745768616774	FirefoxAccounts	TRACE	starting write of json user data: ["email","sessionToken","uid","verified","device","encryptedSendTabKeys","encryptedCloseTabKeys","oauthTokens","profileCache"]
1745768616774	Sync.SyncAuthManager	ERROR	Authentication error in _fetchTokenForUser: {"details":{"now":"2025-04-27T15:43:36.773Z","message":"Authentication failed.","cause":"invalid-credentials","response_body":"{\"status\":\"invalid-credentials\",\"errors\":[{\"location\":\"body\",\"name\":\"\",\"description\":\"Unauthorized\"}]}","response_headers":{"date":"Sun, 27 Apr 2025 15:43:23 GMT","server":"Apache/2.4.62 (Debian)","strict-transport-security":"max-age=15552000; $","content-length":"102","content-type":"application/json","vary":"Origin,Access-Control-Request-Method,Access-Control-Request-Headers","x-weave-timestamp":"1745768603.27","keep-alive":"timeout=5, max=97","connection":"Keep-Alive"},"response_status":401,"name":"TokenServerClientServerError"},"source":"tokenserver"}
1745768616774	Sync.Status	DEBUG	Status.login: success.login => error.login.reason.account
1745768616774	Sync.Status	DEBUG	Status.service: success.status_ok => error.login.failed
1745768616775	Sync.SyncAuthManager	INFO	Failed to fetch the cluster URL: {"details":{"now":"2025-04-27T15:43:36.773Z","message":"Authentication failed.","cause":"invalid-credentials","response_body":"{\"status\":\"invalid-credentials\",\"errors\":[{\"location\":\"body\",\"name\":\"\",\"description\":\"Unauthorized\"}]}","response_headers":{"date":"Sun, 27 Apr 2025 15:43:23 GMT","server":"Apache/2.4.62 (Debian)","strict-transport-security":"max-age=15552000; $","content-length":"102","content-type":"application/json","vary":"Origin,Access-Control-Request-Method,Access-Control-Request-Headers","x-weave-timestamp":"1745768603.27","keep-alive":"timeout=5, max=97","connection":"Keep-Alive"},"response_status":401,"name":"TokenServerClientServerError"},"source":"tokenserver"}
1745768616775	Sync.SyncAuthManager	DEBUG	Cluster value = null
1745768616775	Sync.Status	DEBUG	Status.sync: success.sync => error.sync.reason.no_node_found
1745768616775	Sync.Status	DEBUG	Status.service: error.login.failed => error.sync.failed
1745768616775	Sync.Synchronizer	INFO	No cluster URL found. Cannot sync.
1745768616775	Sync.SyncScheduler	DEBUG	Next sync in 600000 ms. (why=schedule)
1745768616777	FirefoxAccounts	TRACE	not checking freshness of profile as it remains recent

error-sync-1745768638877.txt:

1745768616783	FirefoxAccounts	TRACE	finished write of json user data - took: 9
1745768616783	FirefoxAccounts	DEBUG	writing secure storage: ["scopedKeys"]
1745768616783	FirefoxAccounts	TRACE	starting write of user data to the login manager
1745768616785	FirefoxAccounts	TRACE	finished write of user data to the login manager
1745768616789	Sync.LogManager	DEBUG	Log cleanup threshold time: 1744904616789
1745768616789	Sync.LogManager	DEBUG	Done deleting files.
1745768616944	Services.Common.RESTRequest	DEBUG	POST https://api.accounts.firefox.com/v1/oauth/destroy 200
1745768616944	Hawk	DEBUG	(Response) /oauth/destroy: code: 200 - Status text: 
1745768616944	Hawk	DEBUG	Clock offset vs https://api.accounts.firefox.com/v1: -944
1745768637804	Sync.RemoteTabs	INFO	Doing a tab sync.
1745768637804	Sync.Service	DEBUG	User-Agent: Firefox/137.0.2 (Linux x86_64) FxSync/1.139.0.20250414091429.desktop
1745768637804	Sync.Service	INFO	Starting sync at 2025-04-27 17:43:57 in browser session KhrT8KSSX3eD
1745768637805	Sync.SyncScheduler	DEBUG	Clearing sync triggers and the global score.
1745768637806	Sync.Status	INFO	Resetting Status.
1745768637806	Sync.Status	DEBUG	Status.service: error.sync.failed => success.status_ok
1745768637806	Sync.RemoteTabs	INFO	Generating tab list with filter
1745768637812	FirefoxAccounts	TRACE	not checking freshness of profile as it remains recent
1745768637812	Sync.SyncAuthManager	INFO	Getting sync key
1745768637812	FirefoxAccounts	DEBUG	getOAuthToken enter
1745768637820	Sync.RemoteTabs	INFO	Final tab list has 0 clients with 0 tabs.
1745768637821	Services.Common.RESTRequest	DEBUG	POST request to https://api.accounts.firefox.com/v1/oauth/token
1745768637821	Services.Common.RESTRequest	DEBUG	POST Length: 127
1745768638044	Services.Common.RESTRequest	DEBUG	POST https://api.accounts.firefox.com/v1/oauth/token 200
1745768638044	Hawk	DEBUG	(Response) /oauth/token: code: 200 - Status text: 
1745768638044	Hawk	DEBUG	Clock offset vs https://api.accounts.firefox.com/v1: -1044
1745768638045	FirefoxAccounts	DEBUG	_updateAccountData with items: ["oauthTokens"]
1745768638045	FirefoxAccounts	DEBUG	writing plain storage: ["email","sessionToken","uid","verified","device","encryptedSendTabKeys","encryptedCloseTabKeys","oauthTokens","profileCache"]
1745768638045	FirefoxAccounts	TRACE	starting write of json user data: ["email","sessionToken","uid","verified","device","encryptedSendTabKeys","encryptedCloseTabKeys","oauthTokens","profileCache"]
1745768638045	Sync.SyncAuthManager	INFO	Getting a sync token from: https://XXXXXXXXXXXXXXXXXXXX/ffsync/1.0/sync/1.5
1745768638045	Sync.SyncAuthManager	DEBUG	Getting a token using OAuth
1745768638045	Services.Common.TokenServerClient	DEBUG	Beginning OAuth token exchange: https://XXXXXXXXXXXXXXXXXXXX/ffsync/1.0/sync/1.5
1745768638045	Services.Common.RESTRequest	DEBUG	GET request to https://XXXXXXXXXXXXXXXXXXXX/ffsync/1.0/sync/1.5
1745768638045	FirefoxAccounts	TRACE	finished write of json user data - took: 0
1745768638046	FirefoxAccounts	DEBUG	writing secure storage: ["scopedKeys"]
1745768638046	FirefoxAccounts	TRACE	starting write of user data to the login manager
1745768638048	FirefoxAccounts	TRACE	finished write of user data to the login manager
1745768638519	Services.Common.RESTRequest	DEBUG	GET https://XXXXXXXXXXXXXXXXXXXX/ffsync/1.0/sync/1.5 401
1745768638519	Services.Common.TokenServerClient	DEBUG	Got token response: 401
1745768638519	Services.Common.TokenServerClient	INFO	Server-reported error: {"location":"body","name":"","description":"Unauthorized"}
1745768638520	Services.Common.RESTRequest	DEBUG	POST request to https://api.accounts.firefox.com/v1/oauth/destroy
1745768638520	Services.Common.RESTRequest	DEBUG	POST Length: 969
1745768638520	FirefoxAccounts	DEBUG	_updateAccountData with items: ["oauthTokens"]
1745768638520	FirefoxAccounts	DEBUG	writing plain storage: ["email","sessionToken","uid","verified","device","encryptedSendTabKeys","encryptedCloseTabKeys","oauthTokens","profileCache"]
1745768638520	FirefoxAccounts	TRACE	starting write of json user data: ["email","sessionToken","uid","verified","device","encryptedSendTabKeys","encryptedCloseTabKeys","oauthTokens","profileCache"]
1745768638520	Sync.SyncAuthManager	WARN	Token server returned 401, retrying token fetch with fresh credentials
1745768638520	FirefoxAccounts	DEBUG	getOAuthToken enter
1745768638521	FirefoxAccounts	TRACE	finished write of json user data - took: 1
1745768638521	FirefoxAccounts	DEBUG	writing secure storage: ["scopedKeys"]
1745768638521	FirefoxAccounts	TRACE	starting write of user data to the login manager
1745768638524	FirefoxAccounts	TRACE	finished write of user data to the login manager
1745768638524	Services.Common.RESTRequest	DEBUG	POST request to https://api.accounts.firefox.com/v1/oauth/token
1745768638524	Services.Common.RESTRequest	DEBUG	POST Length: 127
1745768638679	Services.Common.RESTRequest	DEBUG	POST https://api.accounts.firefox.com/v1/oauth/destroy 200
1745768638679	Hawk	DEBUG	(Response) /oauth/destroy: code: 200 - Status text: 
1745768638679	Hawk	DEBUG	Clock offset vs https://api.accounts.firefox.com/v1: -679
1745768638697	Services.Common.RESTRequest	DEBUG	POST https://api.accounts.firefox.com/v1/oauth/token 200
1745768638697	Hawk	DEBUG	(Response) /oauth/token: code: 200 - Status text: 
1745768638697	Hawk	DEBUG	Clock offset vs https://api.accounts.firefox.com/v1: -697
1745768638697	FirefoxAccounts	DEBUG	_updateAccountData with items: ["oauthTokens"]
1745768638697	FirefoxAccounts	DEBUG	writing plain storage: ["email","sessionToken","uid","verified","device","encryptedSendTabKeys","encryptedCloseTabKeys","oauthTokens","profileCache"]
1745768638697	FirefoxAccounts	TRACE	starting write of json user data: ["email","sessionToken","uid","verified","device","encryptedSendTabKeys","encryptedCloseTabKeys","oauthTokens","profileCache"]
1745768638697	Sync.SyncAuthManager	INFO	Getting a sync token from: https://XXXXXXXXXXXXXXXXXXXX/ffsync/1.0/sync/1.5
1745768638697	Sync.SyncAuthManager	DEBUG	Getting a token using OAuth
1745768638697	Services.Common.TokenServerClient	DEBUG	Beginning OAuth token exchange: https://XXXXXXXXXXXXXXXXXXXX/ffsync/1.0/sync/1.5
1745768638697	Services.Common.RESTRequest	DEBUG	GET request to https://XXXXXXXXXXXXXXXXXXXX/ffsync/1.0/sync/1.5
1745768638698	FirefoxAccounts	TRACE	finished write of json user data - took: 1
1745768638698	FirefoxAccounts	DEBUG	writing secure storage: ["scopedKeys"]
1745768638698	FirefoxAccounts	TRACE	starting write of user data to the login manager
1745768638700	FirefoxAccounts	TRACE	finished write of user data to the login manager
1745768638874	Services.Common.RESTRequest	DEBUG	GET https://XXXXXXXXXXXXXXXXXXXX/ffsync/1.0/sync/1.5 401
1745768638874	Services.Common.TokenServerClient	DEBUG	Got token response: 401
1745768638874	Services.Common.TokenServerClient	INFO	Server-reported error: {"location":"body","name":"","description":"Unauthorized"}
1745768638874	Services.Common.RESTRequest	DEBUG	POST request to https://api.accounts.firefox.com/v1/oauth/destroy
1745768638874	Services.Common.RESTRequest	DEBUG	POST Length: 969
1745768638875	FirefoxAccounts	DEBUG	_updateAccountData with items: ["oauthTokens"]
1745768638875	FirefoxAccounts	DEBUG	writing plain storage: ["email","sessionToken","uid","verified","device","encryptedSendTabKeys","encryptedCloseTabKeys","oauthTokens","profileCache"]
1745768638875	FirefoxAccounts	TRACE	starting write of json user data: ["email","sessionToken","uid","verified","device","encryptedSendTabKeys","encryptedCloseTabKeys","oauthTokens","profileCache"]
1745768638875	Sync.SyncAuthManager	ERROR	Authentication error in _fetchTokenForUser: {"details":{"now":"2025-04-27T15:43:58.874Z","message":"Authentication failed.","cause":"invalid-credentials","response_body":"{\"status\":\"invalid-credentials\",\"errors\":[{\"location\":\"body\",\"name\":\"\",\"description\":\"Unauthorized\"}]}","response_headers":{"date":"Sun, 27 Apr 2025 15:43:45 GMT","server":"Apache/2.4.62 (Debian)","strict-transport-security":"max-age=15552000; $","content-length":"102","content-type":"application/json","vary":"Origin,Access-Control-Request-Method,Access-Control-Request-Headers","x-weave-timestamp":"1745768625.38","keep-alive":"timeout=5, max=99","connection":"Keep-Alive"},"response_status":401,"name":"TokenServerClientServerError"},"source":"tokenserver"}
1745768638875	Sync.Status	DEBUG	Status.login: success.login => error.login.reason.account
1745768638875	Sync.Status	DEBUG	Status.service: success.status_ok => error.login.failed
1745768638875	Sync.SyncAuthManager	INFO	Failed to fetch the cluster URL: {"details":{"now":"2025-04-27T15:43:58.874Z","message":"Authentication failed.","cause":"invalid-credentials","response_body":"{\"status\":\"invalid-credentials\",\"errors\":[{\"location\":\"body\",\"name\":\"\",\"description\":\"Unauthorized\"}]}","response_headers":{"date":"Sun, 27 Apr 2025 15:43:45 GMT","server":"Apache/2.4.62 (Debian)","strict-transport-security":"max-age=15552000; $","content-length":"102","content-type":"application/json","vary":"Origin,Access-Control-Request-Method,Access-Control-Request-Headers","x-weave-timestamp":"1745768625.38","keep-alive":"timeout=5, max=99","connection":"Keep-Alive"},"response_status":401,"name":"TokenServerClientServerError"},"source":"tokenserver"}
1745768638875	Sync.SyncAuthManager	DEBUG	Cluster value = null
1745768638875	Sync.Status	DEBUG	Status.sync: success.sync => error.sync.reason.no_node_found
1745768638875	Sync.Status	DEBUG	Status.service: error.login.failed => error.sync.failed
1745768638875	Sync.Synchronizer	INFO	No cluster URL found. Cannot sync.
1745768638876	Sync.SyncScheduler	DEBUG	Next sync in 600000 ms. (why=schedule)
1745768638877	FirefoxAccounts	TRACE	not checking freshness of profile as it remains recent

[porelli]

@urigg, in your case I think the problem is this line. Syncstorage does not expect the folder or the domain to be different from what you initially specified. You will also have to update it in your Firefox configuration.
As a quick workaround to check if it works, you can append here your subfolder -before- initializing the database; it should look like DOMAIN: ${SYNCSTORAGE_DOMAIN}/your/sub/folder

@witchent I would be very curios to understand what's happening with your setup. I'm not aware of anyone else outside this thread having the issue, I assume there might be some peculiarity like the subfolder above.

[witchent]

My setup was podman + Quadlets, but I converted all my docker-compose scripts to Quadlets and they all worked, so I don't think that was the problem (also it all started and firefox was able to connect to the service, so probably no problem there).
I have my own subdomain for the service (firefox.mydomain.tld) and I used nginx, first with my own config, then with the one provided in this repo. No subpath or anything else like this.

I just noticed I still have my quadlet files so if you have an idea how to debug this I can spin it up again and try stuff, but the container logs didn't show anything back then (just like in uriggs case) and the firefox log is above, so I am quite at a loss how to debug this.
And if it's just me I'm fine with just closing this because I'm fine with building the syncstorage image myself :)

[urigg]

Just to clarify: I've already added my sub-folder to SYNCSTORAGE_DOMAIN, so in case this is the problem, its rather where does it need to be removed.