search

mozilla-services / syncstorage-rs

Sync Storage server in Rust
Mozilla Public License 2.0
863 stars 46 forks source link

Syncserver not working with error .../1.5/1/info/collections failed with status 401 in sync-log #1564

Open thomaslitk opened 2 months ago

thomaslitk commented 2 months ago

Hi,

I want to setup syncserver-rs on a raspberry pi 5. So I used mainly the documentation from here https://artemis.sh/2023/03/27/firefox-syncstorage-rs.html and some inspirations from https://www.synology-forum.de/threads/neuer-firefox-syncserver-rust-in-docker-mit-mariadb-datenbank.123662/ https://sarwiki.informatik.hu-berlin.de/Eigener_Sync-Server_f%C3%BCr_Firefox_(Rust) https://aur.archlinux.org/packages/firefox-syncstorage-git

Before, I had firefox syncserver with python 2.7 on a raspberry pi 4, which was working great.

Now, I think I have got almost everything running for syncserver-rs on the raspberry pi 5. It was not easy (some code not working), but now it seems to work mostly. I fail in the end at the sync with firefox.

Some information in advanced: I use ProxyPass for redirection in apache:

ProxyPass /syncserver/ http://localhost:8000/
ProxyPassReverse /syncserver/ http://localhost:8000/

The config.toml looks like

master_secret = "SECRETKEY1"

human_logs = 1

host = "localhost" # default
port = 8000 # default

syncstorage.database_url = "mysql://syncstorage:PASSWORD@localhost/syncstorage_rs"
syncstorage.enable_quota = 0
syncstorage.enabled = true
syncstorage.limits.max_total_records = 1666 # See issues #298/#333

tokenserver.database_url = "mysql://syncstorage:PASSWORD@localhost/tokenserver_rs"
tokenserver.enabled = true
tokenserver.fxa_email_domain = "api.accounts.firefox.com"
tokenserver.fxa_metrics_hash_secret = "SECRETKEY2"
tokenserver.fxa_oauth_server_url = "https://oauth.accounts.firefox.com"
tokenserver.fxa_browserid_audience = "https://token.services.mozilla.com"
tokenserver.fxa_browserid_issuer = "https://api.accounts.firefox.com"
tokenserver.fxa_browserid_server_url = "https://verifier.accounts.firefox.com/v2"

The about:sync-log in firefox gives

1717100169701   Sync.LogManager DEBUG   Flushing file log
1717100169704   Sync.LogManager DEBUG   Log cleanup threshold time: 1716236169704
1717100169705   Sync.LogManager DEBUG   Done deleting files.
1717100172595   Sync.Engine.Tabs.Tracker    DEBUG   Detected a tab change, but conditions aren't met for a quick write or a score bump
1717100688762   Sync.Engine.Tabs.Tracker    DEBUG   Detected a tab change, but conditions aren't met for a quick write or a score bump
1717100691304   Sync.RemoteTabs INFO    Doing a tab sync.
1717100691304   Sync.Service    DEBUG   User-Agent: Firefox/126.0.1 (Windows NT 10.0; Win64; x64) FxSync/1.128.0.2xxx.desktop
1717100691305   Sync.Service    INFO    Starting sync at 2024-05-30 22:24:51 in browser session XXXXXXXXXXXX
1717100691305   Sync.Service    DEBUG   In sync: should login.
1717100691305   Sync.Service    INFO    User logged in successfully - verifying login.
1717100691305   Sync.RemoteTabs INFO    Generating tab list with filter
1717100691305   FirefoxAccounts DEBUG   FxAccountsProfileClient: Requested profile
1717100691305   FirefoxAccounts DEBUG   getOAuthToken enter
1717100691305   FirefoxAccounts TRACE   getCachedToken returning cached token
1717100691306   FirefoxAccounts DEBUG   getOAuthToken returning a cached token
1717100691306   Sync.SyncAuthManager    DEBUG   unlockAndVerifyAuthState already has (or can fetch) sync keys
1717100691306   Services.Common.RESTRequest DEBUG   GET request to https://profile.accounts.firefox.com/v1/profile
1717100691306   Sync.Status DEBUG   Status.login: error.login.reason.network => success.status_ok
1717100691306   Sync.Status DEBUG   Status.service: error.login.failed => error.login.failed
1717100691306   Sync.Service    DEBUG   Fetching unlocked auth state returned success.status_ok
1717100691311   Sync.RemoteTabs INFO    Final tab list has 0 clients with 0 tabs.
1717100691710   Services.Common.RESTRequest DEBUG   GET https://profile.accounts.firefox.com/v1/profile 304
1717100692726   FirefoxAccounts INFO    Polling device commands.
1717100692727   Sync.Service    DEBUG   User-Agent: Firefox/126.0.1 (Windows NT 10.0; Win64; x64) FxSync/1.128.0.20240526221752.desktop
1717100692727   Sync.Service    INFO    Starting sync at 2024-05-30 22:24:52 in browser session XXXXXXXXXXXX
1717100692727   Sync.Service    DEBUG   In sync: should login.
1717100692727   Sync.Service    DEBUG   Exception calling WrappedLock: LockException: Could not acquire lock. Label: "service.js: login".(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
WrappedCatch@util.sys.mjs:112:27
login@service.sys.mjs:1052:66
sync/<@service.sys.mjs:1330:26
WrappedCatch@util.sys.mjs:112:27
sync@service.sys.mjs:1338:7
1717100692727   Sync.Service    INFO    Cannot start sync: already syncing?
1717100692727   Sync.Service    DEBUG   Not syncing: login returned false.
1717100692731   Services.Common.RESTRequest DEBUG   GET request to https://api.accounts.firefox.com/v1/account/device/commands?index=0
1717100692741   Sync.Resource   DEBUG   GET fail 401 https://mydomain.tld/syncserver/1.5/1/info/collections
1717100692741   Sync.Resource   WARN    GET request to https://mydomain.tld/syncserver/1.5/1/info/collections failed with status 401
1717100692741   Sync.Service    WARN    401: login failed.
1717100692741   Sync.SyncAuthManager    DEBUG   _findCluster has a pre-existing clusterURL, so fetching a new token token
1717100692742   FirefoxAccounts TRACE   not checking freshness of profile as it remains recent
1717100692742   Sync.SyncAuthManager    INFO    Getting sync key
1717100692742   FirefoxAccounts DEBUG   getOAuthToken enter
1717100692742   FirefoxAccounts TRACE   getCachedToken returning cached token
1717100692742   FirefoxAccounts DEBUG   getOAuthToken returning a cached token
1717100692743   Sync.SyncAuthManager    INFO    Getting a sync token from: https://mydomain.tld/syncserver/1.0/sync/1.5
1717100692743   Sync.SyncAuthManager    DEBUG   Getting a token using OAuth
1717100692743   Services.Common.TokenServerClient   DEBUG   Beginning OAuth token exchange: https://mydomain.tld/syncserver/1.0/sync/1.5
1717100692743   Services.Common.RESTRequest DEBUG   GET request to https://mydomain.tld/syncserver/1.0/sync/1.5
1717100692952   Services.Common.RESTRequest DEBUG   GET https://api.accounts.firefox.com/v1/account/device/commands?index=0 200
1717100692953   Hawk    DEBUG   (Response) /account/device/commands?index=0: code: 200 - Status text: 
1717100692953   Hawk    DEBUG   Clock offset vs https://api.accounts.firefox.com/v1: -953
1717100693093   Services.Common.RESTRequest DEBUG   GET https://mydomain.tld/syncserver/1.0/sync/1.5 200
1717100693093   Services.Common.TokenServerClient   DEBUG   Got token response: 200
1717100693094   Services.Common.TokenServerClient   DEBUG   Successful token response
1717100693094   Sync.Status DEBUG   Status.login: success.status_ok => success.login
1717100693094   Sync.Status DEBUG   Status.service: error.login.failed => success.status_ok
1717100693094   Sync.SyncAuthManager    DEBUG   _findCluster returning https://mydomain.tld/syncserver/1.5/1/
1717100693094   Sync.SyncAuthManager    DEBUG   Cluster value = https://mydomain.tld/syncserver/1.5/1/
1717100693094   Sync.Status DEBUG   Status.login: success.login => error.login.reason.network
1717100693094   Sync.Status DEBUG   Status.service: success.status_ok => error.login.failed
1717100693094   Sync.ErrorHandler   ERROR   Sync encountered a login error
1717100693094   Sync.SyncScheduler  DEBUG   Clearing sync triggers and the global score.
1717100693094   Sync.SyncScheduler  DEBUG   Next sync in 3600000 ms. (why=schedule)
1717100693095   FirefoxAccounts TRACE   not checking freshness of profile as it remains recent
1717100693095   Sync.Service    DEBUG   Exception calling WrappedLock: Error: Login failed: error.login.reason.network(resource://services-sync/service.sys.mjs:1041:15) JS Stack trace: onNotify@service.sys.mjs:1041:15
1717100693095   Sync.Service    DEBUG   Not syncing: login returned false.
1717100693095   FirefoxAccounts TRACE   not checking freshness of profile as it remains recent

Some things do not seem to work, but I think the problem lies here:

1717100692741   Sync.Resource   DEBUG   GET fail 401 https://mydomain.tld/syncserver/1.5/1/info/collections
1717100692741   Sync.Resource   WARN    GET request to https://mydomain.tld/syncserver/1.5/1/info/collections failed with status 401

Other problems are Exception calling WrappedLock: LockException: Could not acquire lock. Label: "service.js: login" Exception calling WrappedLock: Error: Login failed

The database can be written in principle. A new user is created in database tokenserver_rs:users. But no BSOs are created. Maybe there is a problem with the table collections (failed with status 401). It is predefined with some values about categories (1: clients, 2: crypto, ...)

I tried different solution approaches, but nothing works: Disconnect account and reconnect

Different settings in the config.toml see here:

and others.

Now I don't know what to do next. Have anyone an additional approach for get the syncserver-rs to work?

Thanks and best regards Thomas

┆Issue is synchronized with this Jira Task