Sync broken after syncstorage-rs-mysql-0.18.3-20250526T064429

[simpz]

Hi

Every build after 0.18.3-20250526T064429 (i.e. this is the last working one) doesn't sync properly. The symptoms are slightly hard to fathom, some devices will just stop syncing other will lose history. The main consistent failure mode (and how I first noticed it) was new devices (or profile) seem to just stay unsync'd no history or bookmarks (but they do weirdly seem to sync synced tabs).

I even started with a blank syncserver DBs (both DBs) today and the latest build syncstorage-rs-mysql-0.18.3-20250623T064642, existing browsers seems to mostly sync up except one, and I setup a new profile on that. As ever that just failed to sync bookmarks and history. On this new profile I stepped back through syncstorage builds and restarted my container with this, and just hit "synchronize now" in the broken browser (no restart or anything of the Firefox). Nothing happened until I hit 0.18.3-20250526T064429, then it sprang instantly back into life and sync'd everything up.

I'm amazed no one else has seen this.

The log doesn't say much on the broken sync

Jun 23 22:12:21 syncsrv syncstorage-rs[660989]: {"Type":"glean-server-event","Fields":{"document_namespace":"syncstorage","document_type":"events","document_version":
"1","document_id":"81234cd8-cd7d-406f-af6f-6e87b12355aa","user_agent":"Firefox/128.11.0 (Linux x86_64) FxSync/1.130.0.20250519114620.desktop","ip_address":"","payload
":"{\"client_info\":{\"telemetry_sdk_build\":\"glean_parser v15.0.2.dev17+g81fec69a\",\"first_run_date\":\"Unknown\",\"os\":\"Unknown\",\"os_version\":\"Unknown\",\"a
rchitecture\":\"Unknown\",\"app_build\":\"Unknown\",\"app_display_version\":\"0.18.3\",\"app_channel\":\"dev\"},\"ping_info\":{\"seq\":0,\"start_time\":\"2025-06-23T2
1:12:21.663208722+00:00\",\"end_time\":\"2025-06-23T21:12:21.663208722+00:00\"},\"metrics\":{\"string\":{\"syncstorage.hashed_fxa_uid\":\"aaab13742ddefb46fc3536f45c92
aaaa\",\"syncstorage.hashed_device_id\":\"1123c923ed2f2f0bf494742a43aaab54\",\"syncstorage.device_family\":\"desktop\",\"syncstorage.platform\":\"firefoxdesktop\"}},\
"events\":[{\"category\":\"syncstorage\",\"name\":\"get_collections\",\"timestamp\":1750713141663,\"extra\":{}}]}"}}
Jun 23 22:12:21 syncsrv syncstorage-rs[660989]: Jun 23 21:12:21.663 INFO {"ua.os.ver":"UNKNOWN","ua.os.family":"Linux","uri.method":"GET","ua.name":"Firefox","ua.brow
ser.ver":"128.11.0","ua":"128.11.0","uri.path":"/1.5/4/info/collections","ua.browser.family":"Firefox"}
Jun 23 22:12:21 syncsrv syncstorage-rs[660989]: Jun 23 21:12:21.666 INFO {"uri.method":"GET","ua.browser.family":"Firefox","ua.name":"Firefox","ua.os.ver":"UNKNOWN","
ua.browser.ver":"128.11.0","ua":"128.11.0","uri.path":"/1.5/4/info/configuration","ua.os.family":"Linux"}
Jun 23 22:12:21 syncsrv syncstorage-rs[660989]: Jun 23 21:12:21.671 INFO {"uri.path":"/1.5/4/storage/clients?full=1&limit=1000","ua.os.family":"Linux","ua.browser.ver
":"128.11.0","ua.name":"Firefox","ua":"128.11.0","ua.os.ver":"UNKNOWN","uri.method":"GET","ua.browser.family":"Firefox"}
Jun 23 22:12:21 syncsrv syncstorage-rs[660989]: Jun 23 21:12:21.686 INFO {"ua.browser.family":"Firefox","ua.browser.ver":"128.11.0","ua.name":"Firefox","ua.os.ver":"U
NKNOWN","uri.method":"GET","uri.path":"/1.5/4/storage/passwords?full=1&limit=1000","ua.os.family":"Linux","ua":"128.11.0"}

My setup is pretty bog standard with using Mozilla for authentication.
MAX_USERS=1200
Any thoughts or what changed after 0.18.3-20250526T064429 , that might explain this.

[simpz]

Retested with latest:
"syncstorage-rs-mysql-0.18.3-20250721T064828"
, still broken as above.

Reverting to "syncstorage-rs-mysql-0.18.3-20250526T064429" , works as ever.

As before, using a new profile in Firefox won't sync with these new version.

Reverting back to "syncstorage-rs-mysql-0.18.3-20250526T064429" with no changes to firefox at all, suddenly starts to sync with no changes to the browser.

[tslpre]

I just tried to pull the new version after I skipped a few and realized that I'm experiencing the same issue. Moving back to the tag suggested by @simpz makes sync work again.

My log from a few days ago when I was using the latest tag:

1756816615482 Sync.LogManager DEBUG Flushing file log 1756816615490 Sync.LogManager DEBUG Log cleanup threshold time: 1755952615490 1756816615497 Sync.LogManager DEBUG Done deleting files. 1756816617606 FirefoxAccounts INFO Polling device commands. 1756816617607 Sync.Service DEBUG User-Agent: Firefox/142.0 (Linux x86_64) FxSync/1.144.0.20250811145442.desktop 1756816617607 Sync.Service INFO Starting sync at 2025-09-02 14:36:57 in browser session -2SUk9mYRpEG 1756816617607 Sync.Service DEBUG In sync: should login. 1756816617607 Sync.Service INFO User logged in successfully - verifying login. 1756816617608 FirefoxAccounts TRACE not checking freshness of profile as it remains recent 1756816617608 Sync.SyncAuthManager DEBUG unlockAndVerifyAuthState already has (or can fetch) sync keys 1756816617608 Sync.Status DEBUG Status.login: success.status_ok => success.status_ok 1756816617608 Sync.Status DEBUG Status.service: error.login.failed => error.login.failed 1756816617608 Sync.Service DEBUG Fetching unlocked auth state returned success.status_ok 1756816617608 FirefoxAccounts TRACE not checking freshness of profile as it remains recent 1756816617612 Services.Common.RESTRequest DEBUG GET request to https://api.accounts.firefox.com/v1/account/device/commands?index=168432271 1756816617643 Sync.Resource DEBUG GET success 200 https://xxx.xxx.xxx/1.5/4/info/collections 1756816617643 Sync.Service DEBUG Fetching server configuration: https://xxx.xxx.xxx/1.5/4/info/configuration 1756816617643 FirefoxAccounts TRACE not checking freshness of profile as it remains recent 1756816617658 Sync.Resource DEBUG GET success 200 https://xxx.xxx.xxx/1.5/4/info/configuration 1756816617658 Sync.Service DEBUG Fetching global metadata record 1756816617658 FirefoxAccounts TRACE not checking freshness of profile as it remains recent 1756816617676 Sync.Resource DEBUG GET fail 500 https://xxx.xxx.xxx/1.5/4/storage/meta/global 1756816617676 Sync.Resource WARN GET request to https://xxx.xxx.xxx/1.5/4/storage/meta/global failed with status 500 1756816617676 Sync.Service DEBUG Clearing cached meta record. metaModified is undefined, setting to 1742728686.74 1756816617677 FirefoxAccounts TRACE not checking freshness of profile as it remains recent 1756816617699 Sync.Resource DEBUG GET fail 500 https://xxx.xxx.xxx/1.5/4/storage/meta/global 1756816617699 Sync.Resource WARN GET request to https://xxx.xxx.xxx/1.5/4/storage/meta/global failed with status 500 1756816617699 Sync.Service WARN Unable to get meta/global. Failing remote setup. 1756816617699 Sync.Service WARN Remote setup failed. 1756816617699 Sync.ErrorHandler ERROR Sync encountered a login error 1756816617699 Sync.SyncScheduler DEBUG Clearing sync triggers and the global score. 1756816617700 Sync.SyncScheduler DEBUG Next sync in 3600000 ms. (why=schedule) 1756816617701 Sync.Service DEBUG Exception calling WrappedLock: Error: Login failed: success.status_ok(resource://services-sync/service.sys.mjs:1051:15) JS Stack trace: onNotify@service.sys.mjs:1051:15 1756816617701 Sync.Service DEBUG Not syncing: login returned false. 1756816617701 FirefoxAccounts TRACE not checking freshness of profile as it remains recent

[simpz]

Glad someone else sees this, I thought I must be doing something weird. I have regularly tried newer versions (and just the other days) and still all broken.

[simpz]

Just to keep note, tested a new version "syncstorage-rs-mysql-0.21.1-20251013T064439" and this issue is still present.

[XueSheng-GIT]

This could be related to mozilla-services/syncstorage-rs#1804

[simpz]

I'm occasional testing new versions. Just tried "syncstorage-rs-mysql-0.21.1-20260105T065549".
This issue is still present so this is still totally broken, still very surprised more people aren't seeing this...