search

mozilla-services / syncstorage-rs

Sync Storage server in Rust
Mozilla Public License 2.0
973 stars 49 forks source link

Self-hosted: 401 unauthorized #1504

Closed alucryd closed 10 months ago

alucryd commented 10 months ago

I'm trying to set up a self-hosted sync server. Installation of the latest release went fine, I also populated the service and node tables according to instructions found here: https://aur.archlinux.org/packages/firefox-syncstorage-git

However when I try to use my sync server via Firefox, I get a 401 error. Log below (redacted my domain name):

1701861067321   Sync.LogManager DEBUG   Flushing file log
1701861067328   FirefoxAccounts TRACE   finished write of json user data - took: 9
1701861067328   FirefoxAccounts DEBUG   writing secure storage: ["scopedKeys"]
1701861067328   FirefoxAccounts TRACE   starting write of user data to the login manager
1701861067330   FirefoxAccounts TRACE   finished write of user data to the login manager
1701861067337   Sync.LogManager DEBUG   Log cleanup threshold time: 1700997067337
1701861067337   Sync.LogManager DEBUG   Done deleting files.
1701861067528   Services.Common.RESTRequest DEBUG   POST https://api.accounts.firefox.com/v1/oauth/destroy 200
1701861067529   Hawk    DEBUG   (Response) /oauth/destroy: code: 200 - Status text: 
1701861067529   Hawk    DEBUG   Clock offset vs https://api.accounts.firefox.com/v1: -529
1701861069216   Sync.Engine.Tabs.Tracker    DEBUG   Detected a tab change, but conditions aren't met for a quick write or a score bump
1701861069356   FirefoxAccounts TRACE   not checking freshness of profile as it remains recent
1701861069356   FirefoxAccounts TRACE   not checking freshness of profile as it remains recent
1701861072088   Sync.RemoteTabs INFO    Doing a tab sync.
1701861072088   Sync.Service    DEBUG   User-Agent: Firefox/120.0.1 (Linux x86_64) FxSync/1.122.0.20231130105227.desktop
1701861072088   Sync.Service    INFO    Starting sync at 2023-12-06 12:11:12 in browser session cwvFxVrcBklr
1701861072088   Sync.SyncScheduler  DEBUG   Clearing sync triggers and the global score.
1701861072090   Sync.Status INFO    Resetting Status.
1701861072090   Sync.Status DEBUG   Status.service: error.sync.failed => success.status_ok
1701861072090   Sync.RemoteTabs INFO    Generating tab list with filter
1701861072097   FirefoxAccounts TRACE   not checking freshness of profile as it remains recent
1701861072098   Sync.SyncAuthManager    INFO    Getting sync key
1701861072098   Sync.SyncAuthManager    INFO    Getting a sync token from: https://domain.tld/1.0/sync/1.5
1701861072098   Sync.SyncAuthManager    DEBUG   Getting a token using OAuth
1701861072098   FirefoxAccounts DEBUG   getOAuthToken enter
1701861072100   Sync.RemoteTabs INFO    Final tab list has 0 clients with 0 tabs.
1701861072102   Services.Common.RESTRequest DEBUG   POST request to https://api.accounts.firefox.com/v1/oauth/token
1701861072102   Services.Common.RESTRequest DEBUG   POST Length: 127
1701861072336   Services.Common.RESTRequest DEBUG   POST https://api.accounts.firefox.com/v1/oauth/token 200
1701861072336   Hawk    DEBUG   (Response) /oauth/token: code: 200 - Status text: 
1701861072336   Hawk    DEBUG   Clock offset vs https://api.accounts.firefox.com/v1: -336
1701861072336   FirefoxAccounts DEBUG   _updateAccountData with items: ["oauthTokens"]
1701861072336   FirefoxAccounts DEBUG   writing plain storage: ["email","sessionToken","uid","verified","device","oauthTokens","encryptedSendTabKeys","profileCache"]
1701861072336   FirefoxAccounts TRACE   starting write of json user data: ["email","sessionToken","uid","verified","device","oauthTokens","encryptedSendTabKeys","profileCache"]
1701861072336   Services.Common.TokenServerClient   DEBUG   Beginning OAuth token exchange: https://domain.tld/1.0/sync/1.5
1701861072336   Services.Common.RESTRequest DEBUG   GET request to https://domain.tld/1.0/sync/1.5
1701861072337   FirefoxAccounts TRACE   finished write of json user data - took: 1
1701861072337   FirefoxAccounts DEBUG   writing secure storage: ["scopedKeys"]
1701861072337   FirefoxAccounts TRACE   starting write of user data to the login manager
1701861072339   FirefoxAccounts TRACE   finished write of user data to the login manager
1701861072540   Services.Common.RESTRequest DEBUG   GET https://domain.tld/1.0/sync/1.5 401
1701861072540   Services.Common.TokenServerClient   DEBUG   Got token response: 401
1701861072540   Services.Common.TokenServerClient   INFO    Server-reported error: {"location":"body","name":"","description":"Unauthorized"}
1701861072541   Services.Common.RESTRequest DEBUG   POST request to https://api.accounts.firefox.com/v1/oauth/destroy
1701861072541   Services.Common.RESTRequest DEBUG   POST Length: 969
1701861072542   FirefoxAccounts DEBUG   _updateAccountData with items: ["oauthTokens"]
1701861072542   FirefoxAccounts DEBUG   writing plain storage: ["email","sessionToken","uid","verified","device","oauthTokens","encryptedSendTabKeys","profileCache"]
1701861072542   FirefoxAccounts TRACE   starting write of json user data: ["email","sessionToken","uid","verified","device","oauthTokens","encryptedSendTabKeys","profileCache"]
1701861072542   Sync.SyncAuthManager    WARN    Token server returned 401, retrying token fetch with fresh credentials
1701861072542   Sync.SyncAuthManager    INFO    Getting a sync token from: https://domain.tld/1.0/sync/1.5
1701861072542   Sync.SyncAuthManager    DEBUG   Getting a token using OAuth
1701861072542   FirefoxAccounts DEBUG   getOAuthToken enter
1701861072543   FirefoxAccounts TRACE   finished write of json user data - took: 1
1701861072543   FirefoxAccounts DEBUG   writing secure storage: ["scopedKeys"]
1701861072544   FirefoxAccounts TRACE   starting write of user data to the login manager
1701861072546   FirefoxAccounts TRACE   finished write of user data to the login manager
1701861072546   Services.Common.RESTRequest DEBUG   POST request to https://api.accounts.firefox.com/v1/oauth/token
1701861072547   Services.Common.RESTRequest DEBUG   POST Length: 127
1701861072739   Services.Common.RESTRequest DEBUG   POST https://api.accounts.firefox.com/v1/oauth/destroy 200
1701861072739   Hawk    DEBUG   (Response) /oauth/destroy: code: 200 - Status text: 
1701861072739   Hawk    DEBUG   Clock offset vs https://api.accounts.firefox.com/v1: -739
1701861072759   Services.Common.RESTRequest DEBUG   POST https://api.accounts.firefox.com/v1/oauth/token 200
1701861072759   Hawk    DEBUG   (Response) /oauth/token: code: 200 - Status text: 
1701861072759   Hawk    DEBUG   Clock offset vs https://api.accounts.firefox.com/v1: -759
1701861072759   FirefoxAccounts DEBUG   _updateAccountData with items: ["oauthTokens"]
1701861072759   FirefoxAccounts DEBUG   writing plain storage: ["email","sessionToken","uid","verified","device","oauthTokens","encryptedSendTabKeys","profileCache"]
1701861072759   FirefoxAccounts TRACE   starting write of json user data: ["email","sessionToken","uid","verified","device","oauthTokens","encryptedSendTabKeys","profileCache"]
1701861072760   Services.Common.TokenServerClient   DEBUG   Beginning OAuth token exchange: https://domain.tld/1.0/sync/1.5
1701861072760   Services.Common.RESTRequest DEBUG   GET request to https://domain.tld/1.0/sync/1.5
1701861072761   FirefoxAccounts TRACE   finished write of json user data - took: 2
1701861072761   FirefoxAccounts DEBUG   writing secure storage: ["scopedKeys"]
1701861072761   FirefoxAccounts TRACE   starting write of user data to the login manager
1701861072763   FirefoxAccounts TRACE   finished write of user data to the login manager
1701861072950   Services.Common.RESTRequest DEBUG   GET https://domain.tld/1.0/sync/1.5 401
1701861072950   Services.Common.TokenServerClient   DEBUG   Got token response: 401
1701861072950   Services.Common.TokenServerClient   INFO    Server-reported error: {"location":"body","name":"","description":"Unauthorized"}
1701861072951   Services.Common.RESTRequest DEBUG   POST request to https://api.accounts.firefox.com/v1/oauth/destroy
1701861072951   Services.Common.RESTRequest DEBUG   POST Length: 969
1701861072951   FirefoxAccounts DEBUG   _updateAccountData with items: ["oauthTokens"]
1701861072951   FirefoxAccounts DEBUG   writing plain storage: ["email","sessionToken","uid","verified","device","oauthTokens","encryptedSendTabKeys","profileCache"]
1701861072951   FirefoxAccounts TRACE   starting write of json user data: ["email","sessionToken","uid","verified","device","oauthTokens","encryptedSendTabKeys","profileCache"]
1701861072951   Sync.SyncAuthManager    ERROR   Authentication error in _fetchTokenForUser: {"details":{"now":"2023-12-06T11:11:12.950Z","message":"Authentication failed.","cause":"invalid-credentials","response_body":"{\"status\":\"invalid-credentials\",\"errors\":[{\"location\":\"body\",\"name\":\"\",\"description\":\"Unauthorized\"}]}","response_headers":{"content-type":"application/json","date":"Wed, 06 Dec 2023 11:11:12 GMT","strict-transport-security":"max-age=63072000","vary":"Accept-Encoding","x-weave-timestamp":"1701861072.76","content-length":"102","x-firefox-spdy":"h2"},"response_status":401,"name":"TokenServerClientServerError"},"source":"tokenserver"}
1701861072952   Sync.Status DEBUG   Status.login: success.login => error.login.reason.account
1701861072952   Sync.Status DEBUG   Status.service: success.status_ok => error.login.failed
1701861072952   Sync.SyncAuthManager    INFO    Failed to fetch the cluster URL: {"details":{"now":"2023-12-06T11:11:12.950Z","message":"Authentication failed.","cause":"invalid-credentials","response_body":"{\"status\":\"invalid-credentials\",\"errors\":[{\"location\":\"body\",\"name\":\"\",\"description\":\"Unauthorized\"}]}","response_headers":{"content-type":"application/json","date":"Wed, 06 Dec 2023 11:11:12 GMT","strict-transport-security":"max-age=63072000","vary":"Accept-Encoding","x-weave-timestamp":"1701861072.76","content-length":"102","x-firefox-spdy":"h2"},"response_status":401,"name":"TokenServerClientServerError"},"source":"tokenserver"}
1701861072952   Sync.SyncAuthManager    DEBUG   Cluster value = null
1701861072952   Sync.Status DEBUG   Status.sync: success.sync => error.sync.reason.no_node_found
1701861072952   Sync.Status DEBUG   Status.service: error.login.failed => error.sync.failed
1701861072952   Sync.Synchronizer   INFO    No cluster URL found. Cannot sync.
1701861072952   Sync.SyncScheduler  DEBUG   Next sync in 600000 ms. (why=schedule)
1701861072953   FirefoxAccounts TRACE   not checking freshness of profile as it remains recent

Any idea?

┆Issue is synchronized with this Jira Task

alucryd commented 10 months ago

Nevermind, my fxa configuration was wrong.