Closed Bug 531005 Opened 15 years ago Closed 15 years ago

Sync is not working after update IWeaveCrypto.unwrapSymmetricKey NS_ERROR_FAILURE

Categories

(Firefox :: Sync, defect)

Product:
Firefox
Component:
Sync
Type:
defect
Priority:
Not set
Severity:
major

Tracking

()

Status:
RESOLVED FIXED
Milestone:
1.0 beta3

People

(Reporter: 1k4rus, Assigned: Mardak)

References

Details

Attachments

(1 file)

a sad activity log :(
8.12 KB, text/html
Details 
User-Agent:       Mozilla/5.0 (Windows; U; Windows NT 6.1; de; rv:1.9.1.5) Gecko/20091102 Firefox/3.5.5 (.NET CLR 3.5.30729)
Build Identifier: Mozilla/5.0 (Windows; U; Windows NT 6.1; de; rv:1.9.1.5) Gecko/20091102 Firefox/3.5.5 (.NET CLR 3.5.30729)

Every time it tries to sync I get the blue ! sign telling me "Error While Syncing. Weave encountered an error while syncing: Unknown error. Weave will automatically retry this action"
I've updated weave on each machine I'm using but still facing the same error on each machine.

Reproducible: Always

Steps to Reproduce:
1.Open Firefox
2.Tell weave to sync
3.


Expected Results:  
Every time it tries to sync I get the blue ! sign telling me "Error While Syncing. Weave encountered an error while syncing: Unknown error. Weave will automatically retry this action"

2009-11-25 08:52:51	Service.Main         INFO	Loading Weave 1.0b2 in 5 sec.
2009-11-25 08:52:52	Chrome.Window        INFO	Initializing Firefox Weave embedding
2009-11-25 08:52:56	Engine.Bookmarks     DEBUG	Engine initialized
2009-11-25 08:52:56	Engine.Forms         DEBUG	Engine initialized
2009-11-25 08:52:56	Engine.History       DEBUG	Engine initialized
2009-11-25 08:52:56	Engine.Passwords     DEBUG	Engine initialized
2009-11-25 08:52:56	Engine.Prefs         DEBUG	Engine initialized
2009-11-25 08:52:56	Engine.Tabs          DEBUG	Engine initialized
2009-11-25 08:52:56	Service.Main         INFO	Mozilla/5.0 (Windows; U; Windows NT 6.1; de; rv:1.9.1.5) Gecko/20091102 Firefox/3.5.5 (.NET CLR 3.5.30729)
2009-11-25 08:52:56	Service.Main         DEBUG	Caching URLs under storage user base: https://sj-weave01.services.mozilla.com/1.0/fidschi86/
2009-11-25 08:52:56	Service.Main         DEBUG	Event: weave:service:login:start
2009-11-25 08:52:56	Service.Main         INFO	Logging in user fidschi86
2009-11-25 08:52:56	Service.Main         DEBUG	Event: weave:service:verify-login:start
2009-11-25 08:52:57	Net.Resource         DEBUG	GET request for https://sj-weave01.services.mozilla.com/1.0/fidschi86/info/collections
2009-11-25 08:52:57	Net.Resource         DEBUG	GET success: 200
2009-11-25 08:52:57	Service.Main         DEBUG	Event: weave:service:verify-passphrase:start
2009-11-25 08:52:57	PubKeyManager        TRACE	Importing record: https://sj-weave01.services.mozilla.com/1.0/fidschi86/storage/keys/pubkey
2009-11-25 08:52:58	Net.Resource         DEBUG	GET request for https://sj-weave01.services.mozilla.com/1.0/fidschi86/storage/keys/pubkey
2009-11-25 08:52:58	Net.Resource         DEBUG	GET success: 200
2009-11-25 08:52:58	PrivKeyManager       TRACE	Importing record: https://sj-weave01.services.mozilla.com/1.0/fidschi86/storage/keys/privkey
2009-11-25 08:52:58	Net.Resource         DEBUG	GET request for https://sj-weave01.services.mozilla.com/1.0/fidschi86/storage/keys/privkey
2009-11-25 08:52:58	Net.Resource         DEBUG	GET success: 200
2009-11-25 08:52:58	Service.Main         DEBUG	Event: weave:service:verify-passphrase:finish
2009-11-25 08:52:58	Service.Main         DEBUG	Event: weave:service:verify-login:finish
2009-11-25 08:52:58	Service.Main         DEBUG	Next sync in 3341 sec.
2009-11-25 08:52:58	Service.Main         DEBUG	Event: weave:service:login:finish
2009-11-25 08:59:16	Service.Main         DEBUG	Event: weave:service:sync:start
2009-11-25 08:59:16	RecordMgr            TRACE	Importing record: https://sj-weave01.services.mozilla.com/1.0/fidschi86/storage/meta/global
2009-11-25 08:59:17	Net.Resource         DEBUG	GET request for https://sj-weave01.services.mozilla.com/1.0/fidschi86/storage/meta/global
2009-11-25 08:59:17	Net.Resource         DEBUG	GET success: 200
2009-11-25 08:59:17	Service.Main         DEBUG	Weave Version: 1.0b2 Compatible: 1.0b2pre1 Remote: 1.0b2
2009-11-25 08:59:18	Net.Resource         DEBUG	GET request for https://sj-weave01.services.mozilla.com/1.0/fidschi86/info/collections
2009-11-25 08:59:18	Net.Resource         DEBUG	GET success: 200
2009-11-25 08:59:18	Store.Clients.Store  DEBUG	Setting client c963ccbe-422e-4c95-8dec-39a4ab94ce49: {"name":"Fidschi's Firefox on Fidschi-PC","type":"desktop"}
2009-11-25 08:59:18	Engine.Clients       DEBUG	Event: weave:engine:sync:start
2009-11-25 08:59:18	Engine.Clients       DEBUG	Ensuring server crypto records are there
2009-11-25 08:59:18	RecordMgr            TRACE	Importing record: https://sj-weave01.services.mozilla.com/1.0/fidschi86/storage/crypto/clients
2009-11-25 08:59:19	Net.Resource         DEBUG	GET request for https://sj-weave01.services.mozilla.com/1.0/fidschi86/storage/crypto/clients
2009-11-25 08:59:19	Net.Resource         DEBUG	GET success: 200
2009-11-25 08:59:19	Engine.Clients       INFO	0 outgoing items pre-reconciliation
2009-11-25 08:59:19	Engine.Clients       DEBUG	Downloading & applying server changes
2009-11-25 08:59:19	Engine.Clients       INFO	Records: 0 applied, 0 reconciled, 0 left to fetch
2009-11-25 08:59:19	Engine.Clients       DEBUG	Event: weave:engine:sync:finish
2009-11-25 08:59:19	Engine.Clients       INFO	Total (ms): sync 635, processIncoming 0, uploadOutgoing 1, syncStartup 634, syncFinish 0, updateLocalInfo 0
2009-11-25 08:59:19	Engine.Bookmarks     DEBUG	Event: weave:engine:sync:start
2009-11-25 08:59:19	Engine.Bookmarks     DEBUG	Ensuring server crypto records are there
2009-11-25 08:59:19	RecordMgr            TRACE	Importing record: https://sj-weave01.services.mozilla.com/1.0/fidschi86/storage/crypto/bookmarks
2009-11-25 08:59:19	Net.Resource         DEBUG	GET request for https://sj-weave01.services.mozilla.com/1.0/fidschi86/storage/crypto/bookmarks
2009-11-25 08:59:19	Net.Resource         DEBUG	GET success: 200
2009-11-25 08:59:19	Engine.Bookmarks     INFO	First sync, uploading all items
2009-11-25 08:59:19	Engine.Bookmarks     INFO	364 outgoing items pre-reconciliation
2009-11-25 08:59:19	Engine.Bookmarks     DEBUG	Downloading & applying server changes
2009-11-25 08:59:19	Engine.Bookmarks     INFO	Records: 0 applied, 0 reconciled, 0 left to fetch
2009-11-25 08:59:19	Engine.Bookmarks     DEBUG	Preparing 364 outgoing records
2009-11-25 08:59:19	Engine.Bookmarks     WARN	Sync failed
2009-11-25 08:59:19	Engine.Bookmarks     DEBUG	Event: weave:engine:sync:error
2009-11-25 08:59:19	Engine.Bookmarks     INFO	Total (ms): sync 872, processIncoming 1, uploadOutgoing 24, syncStartup 841, createRecord 3
2009-11-25 08:59:19	Service.Main         DEBUG	Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [IWeaveCrypto.unwrapSymmetricKey] Stack trace: CryptoMeta_getKey()@crypto.js:154 < CryptoWrapper_encrypt()@crypto.js:80 < SyncEngine__uploadOutgoing()@engines.js:630 < anonymous()@engines.js:206 < SyncEngine__sync()@engines.js:684 < wrappedSync()@util.js:136 < <file:unknown> < batchedSync()@util.js:142 < anonymous()@engines.js:206 < WrappedNotify()@util.js:115 < Engine_sync()@engines.js:216 < WeaveSvc__syncEngine()@service.js:1203 < anonymous()@service.js:1142 < WrappedNotify()@util.js:115 < WrappedLock()@util.js:87 < WrappedCatch()@util.js:66 < sync()@service.js:1066 < WeaveWin_doSync()@sync.js:270 < oncommand()@browser.xul:1
2009-11-25 08:59:19	Engine.Forms         DEBUG	Event: weave:engine:sync:start
2009-11-25 08:59:19	Engine.Forms         DEBUG	Ensuring server crypto records are there
2009-11-25 08:59:19	RecordMgr            TRACE	Importing record: https://sj-weave01.services.mozilla.com/1.0/fidschi86/storage/crypto/forms
2009-11-25 08:59:20	Net.Resource         DEBUG	GET request for https://sj-weave01.services.mozilla.com/1.0/fidschi86/storage/crypto/forms
2009-11-25 08:59:20	Net.Resource         DEBUG	GET success: 200
2009-11-25 08:59:20	Engine.Forms         INFO	First sync, uploading all items
2009-11-25 08:59:20	Engine.Forms         INFO	0 outgoing items pre-reconciliation
2009-11-25 08:59:20	Engine.Forms         DEBUG	Downloading & applying server changes
2009-11-25 08:59:20	Engine.Forms         INFO	Records: 0 applied, 0 reconciled, 0 left to fetch
2009-11-25 08:59:20	Engine.Forms         DEBUG	Event: weave:engine:sync:finish
2009-11-25 08:59:20	Engine.Forms         INFO	Total (ms): sync 821, processIncoming 0, uploadOutgoing 1, syncStartup 820, syncFinish 0
2009-11-25 08:59:20	Engine.History       DEBUG	Event: weave:engine:sync:start
2009-11-25 08:59:20	Engine.History       DEBUG	Ensuring server crypto records are there
2009-11-25 08:59:20	RecordMgr            TRACE	Importing record: https://sj-weave01.services.mozilla.com/1.0/fidschi86/storage/crypto/history
2009-11-25 08:59:21	Net.Resource         DEBUG	GET request for https://sj-weave01.services.mozilla.com/1.0/fidschi86/storage/crypto/history
2009-11-25 08:59:21	Net.Resource         DEBUG	GET success: 200
2009-11-25 08:59:21	Engine.History       INFO	First sync, uploading all items
2009-11-25 08:59:21	Engine.History       INFO	0 outgoing items pre-reconciliation
2009-11-25 08:59:21	Engine.History       DEBUG	Downloading & applying server changes
2009-11-25 08:59:21	Engine.History       INFO	Records: 0 applied, 0 reconciled, 0 left to fetch
2009-11-25 08:59:21	Engine.History       DEBUG	Event: weave:engine:sync:finish
2009-11-25 08:59:21	Engine.History       INFO	Total (ms): sync 641, processIncoming 1, uploadOutgoing 0, syncStartup 640, syncFinish 0
2009-11-25 08:59:21	Engine.Passwords     DEBUG	Event: weave:engine:sync:start
2009-11-25 08:59:21	Engine.Passwords     DEBUG	Ensuring server crypto records are there
2009-11-25 08:59:21	RecordMgr            TRACE	Importing record: https://sj-weave01.services.mozilla.com/1.0/fidschi86/storage/crypto/passwords
2009-11-25 08:59:22	Net.Resource         DEBUG	GET request for https://sj-weave01.services.mozilla.com/1.0/fidschi86/storage/crypto/passwords
2009-11-25 08:59:22	Net.Resource         DEBUG	GET success: 200
2009-11-25 08:59:22	Engine.Passwords     INFO	First sync, uploading all items
2009-11-25 08:59:22	Engine.Passwords     INFO	43 outgoing items pre-reconciliation
2009-11-25 08:59:22	Engine.Passwords     DEBUG	Downloading & applying server changes
2009-11-25 08:59:22	Engine.Passwords     INFO	Records: 0 applied, 0 reconciled, 0 left to fetch
2009-11-25 08:59:22	Engine.Passwords     DEBUG	Preparing 43 outgoing records
2009-11-25 08:59:22	Engine.Passwords     WARN	Sync failed
2009-11-25 08:59:22	Engine.Passwords     DEBUG	Event: weave:engine:sync:error
2009-11-25 08:59:22	Engine.Passwords     INFO	Total (ms): sync 900, processIncoming 0, uploadOutgoing 22, syncStartup 878, createRecord 1
2009-11-25 08:59:22	Service.Main         DEBUG	Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [IWeaveCrypto.unwrapSymmetricKey] Stack trace: CryptoMeta_getKey()@crypto.js:154 < CryptoWrapper_encrypt()@crypto.js:80 < SyncEngine__uploadOutgoing()@engines.js:630 < anonymous()@engines.js:206 < SyncEngine__sync()@engines.js:684 < anonymous()@engines.js:206 < WrappedNotify()@util.js:115 < Engine_sync()@engines.js:216 < WeaveSvc__syncEngine()@service.js:1203 < anonymous()@service.js:1142 < WrappedNotify()@util.js:115 < WrappedLock()@util.js:87 < WrappedCatch()@util.js:66 < sync()@service.js:1066 < WeaveWin_doSync()@sync.js:270 < oncommand()@browser.xul:1
2009-11-25 08:59:22	Engine.Prefs         DEBUG	Event: weave:engine:sync:start
2009-11-25 08:59:22	Engine.Prefs         DEBUG	Ensuring server crypto records are there
2009-11-25 08:59:22	RecordMgr            TRACE	Importing record: https://sj-weave01.services.mozilla.com/1.0/fidschi86/storage/crypto/prefs
2009-11-25 08:59:23	Net.Resource         DEBUG	GET request for https://sj-weave01.services.mozilla.com/1.0/fidschi86/storage/crypto/prefs
2009-11-25 08:59:23	Net.Resource         DEBUG	GET success: 200
2009-11-25 08:59:23	Engine.Prefs         INFO	First sync, uploading all items
2009-11-25 08:59:23	Engine.Prefs         INFO	1 outgoing items pre-reconciliation
2009-11-25 08:59:23	Engine.Prefs         DEBUG	Downloading & applying server changes
2009-11-25 08:59:23	Engine.Prefs         INFO	Records: 0 applied, 0 reconciled, 0 left to fetch
2009-11-25 08:59:23	Engine.Prefs         DEBUG	Preparing 1 outgoing records
2009-11-25 08:59:23	Engine.Prefs         WARN	Sync failed
2009-11-25 08:59:23	Engine.Prefs         DEBUG	Event: weave:engine:sync:error
2009-11-25 08:59:23	Engine.Prefs         INFO	Total (ms): sync 861, processIncoming 0, uploadOutgoing 21, syncStartup 840, createRecord 1
2009-11-25 08:59:23	Service.Main         DEBUG	Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [IWeaveCrypto.unwrapSymmetricKey] Stack trace: CryptoMeta_getKey()@crypto.js:154 < CryptoWrapper_encrypt()@crypto.js:80 < SyncEngine__uploadOutgoing()@engines.js:630 < anonymous()@engines.js:206 < SyncEngine__sync()@engines.js:684 < anonymous()@engines.js:206 < WrappedNotify()@util.js:115 < Engine_sync()@engines.js:216 < WeaveSvc__syncEngine()@service.js:1203 < anonymous()@service.js:1142 < WrappedNotify()@util.js:115 < WrappedLock()@util.js:87 < WrappedCatch()@util.js:66 < sync()@service.js:1066 < WeaveWin_doSync()@sync.js:270 < oncommand()@browser.xul:1
2009-11-25 08:59:23	Engine.Tabs          DEBUG	Event: weave:engine:sync:start
2009-11-25 08:59:23	Engine.Tabs          DEBUG	Ensuring server crypto records are there
2009-11-25 08:59:23	RecordMgr            TRACE	Importing record: https://sj-weave01.services.mozilla.com/1.0/fidschi86/storage/crypto/tabs
2009-11-25 08:59:24	Net.Resource         DEBUG	GET request for https://sj-weave01.services.mozilla.com/1.0/fidschi86/storage/crypto/tabs
2009-11-25 08:59:24	Net.Resource         DEBUG	GET success: 200
2009-11-25 08:59:24	Engine.Tabs          INFO	First sync, uploading all items
2009-11-25 08:59:24	Engine.Tabs          INFO	5 outgoing items pre-reconciliation
2009-11-25 08:59:24	Engine.Tabs          DEBUG	Downloading & applying server changes
2009-11-25 08:59:24	Engine.Tabs          INFO	Records: 0 applied, 0 reconciled, 0 left to fetch
2009-11-25 08:59:24	Engine.Tabs          DEBUG	Preparing 5 outgoing records
2009-11-25 08:59:24	Store.Tabs.Store     DEBUG	Wrapping a tab with title Enter A Bug
2009-11-25 08:59:24	Engine.Tabs          WARN	Sync failed
2009-11-25 08:59:24	Engine.Tabs          DEBUG	Event: weave:engine:sync:error
2009-11-25 08:59:24	Engine.Tabs          INFO	Total (ms): sync 862, processIncoming 1, uploadOutgoing 21, syncStartup 839, createRecord 1
2009-11-25 08:59:24	Service.Main         DEBUG	Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [IWeaveCrypto.unwrapSymmetricKey] Stack trace: CryptoMeta_getKey()@crypto.js:154 < CryptoWrapper_encrypt()@crypto.js:80 < SyncEngine__uploadOutgoing()@engines.js:630 < anonymous()@engines.js:206 < SyncEngine__sync()@engines.js:684 < anonymous()@engines.js:206 < WrappedNotify()@util.js:115 < Engine_sync()@engines.js:216 < WeaveSvc__syncEngine()@service.js:1203 < anonymous()@service.js:1142 < WrappedNotify()@util.js:115 < WrappedLock()@util.js:87 < WrappedCatch()@util.js:66 < sync()@service.js:1066 < WeaveWin_doSync()@sync.js:270 < oncommand()@browser.xul:1
2009-11-25 08:59:24	Service.Main         DEBUG	Event: weave:service:sync:error
2009-11-25 08:59:24	Service.Main         DEBUG	Next sync in 3600 sec.
2009-11-25 08:59:24	Service.Main         DEBUG	Exception: Some engines did not sync correctly No traceback available
I confirmed this on Mozilla/5.0 (Macintosh; U; Intel Mac OS X 10.5; en-US; rv:1.9.2b5pre) Gecko/20091201 Namoroka/3.6b5pre.   

My repro was installing weave 1.0b3pre1 over 1.0b2.  My sync was successful prior to the pave over install, and then after restarting with the new xpi, forcing sync threw a similar exception:
  
2009-12-01 16:29:57	Engine.Forms         WARN	Sync failed
2009-12-01 16:29:57	Engine.Forms         DEBUG	Event: weave:engine:sync:error
2009-12-01 16:29:57	Engine.Forms         INFO	Total (ms): sync 199, processIncoming 1, uploadOutgoing 20, syncStartup 178, createRecord 0
2009-12-01 16:29:57	Service.Main         DEBUG	Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [IWeaveCrypto.unwrapSymmetricKey] Stack trace: CryptoMeta_getKey()@crypto.js:152 < CryptoWrapper_encrypt()@crypto.js:78 < SyncEngine__uploadOutgoing()@engines.js:630 < anonymous()@engines.js:206 < SyncEngine__sync()@engines.js:684 < anonymous()@engines.js:206 < WrappedNotify()@util.js:114 < Engine_sync()@engines.js:216 < WeaveSvc__syncEngine()@service.js:1198 < anonymous()@service.js:1136 < WrappedNotify()@util.js:114 < WrappedLock()@util.js:86 < WrappedCatch()@util.js:65 < sync()@service.js:1060 < anonymous()@sync.js:284
2009-12-01 16:29:57	Engine.History       DEBUG	Event: weave:engine:sync:start
2009-12-01 16:29:57	Engine.History       DEBUG	Ensuring server crypto records are there
2009-12-01 16:29:57	RecordMgr            TRACE	Importing record: https://sj-weave03.services.mozilla.com/1.0/dknite/storage/crypto/history
2009-12-01 16:29:58	Net.Resource         DEBUG	GET request for https://sj-weave03.services.mozilla.com/1.0/dknite/storage/crypto/history
2009-12-01 16:29:58	Net.Resource         DEBUG	GET success: 200
2009-12-01 16:29:58	Engine.History       INFO	1890 outgoing items pre-reconciliation
2009-12-01 16:29:58	Engine.History       DEBUG	Downloading & applying server changes
2009-12-01 16:29:58	Engine.History       INFO	Records: 0 applied, 0 reconciled, 0 left to fetch
2009-12-01 16:29:58	Engine.History       DEBUG	Preparing 1890 outgoing records
2009-12-01 16:29:58	Engine.History       WARN	Sync failed
2009-12-01 16:29:58	Engine.History       DEBUG	Event: weave:engine:sync:error
2009-12-01 16:29:58	Engine.History       INFO	Total (ms): sync 394, processIncoming 1, uploadOutgoing 63, syncStartup 330, createRecord 2
2009-12-01 16:29:58	Service.Main         DEBUG	Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [IWeaveCrypto.unwrapSymmetricKey] Stack trace: CryptoMeta_getKey()@crypto.js:152 < CryptoWrapper_encrypt()@crypto.js:78 < SyncEngine__uploadOutgoing()@engines.js:630 < anonymous()@engines.js:206 < SyncEngine__sync()@engines.js:684 < wrappedSync()@util.js:135 < <file:unknown> < batchedSync()@util.js:141 < anonymous()@engines.js:206 < WrappedNotify()@util.js:114 < Engine_sync()@engines.js:216 < WeaveSvc__syncEngine()@service.js:1198 < anonymous()@service.js:1136 < WrappedNotify()@util.js:114 < WrappedLock()@util.js:86 < WrappedCatch()@util.js:65 < sync()@service.js:1060 < anonymous()@sync.js:284
2009-12-01 16:29:58	Engine.Passwords     DEBUG	Event: weave:engine:sync:start
2009-12-01 16:29:58	Engine.Passwords     DEBUG	Ensuring server crypto records are there
2009-12-01 16:29:58	RecordMgr            TRACE	Importing record: https://sj-weave03.services.mozilla.com/1.0/dknite/storage/crypto/passwords
2009-12-01 16:29:58	Net.Resource         DEBUG	GET request for https://sj-weave03.services.mozilla.com/1.0/dknite/storage/crypto/passwords
2009-12-01 16:29:58	Net.Resource         DEBUG	GET success: 200
2009-12-01 16:29:58	Engine.Passwords     INFO	First sync, uploading all items
2009-12-01 16:29:58	Engine.Passwords     INFO	117 outgoing items pre-reconciliation
2009-12-01 16:29:58	Engine.Passwords     DEBUG	Downloading & applying server changes
2009-12-01 16:29:58	Engine.Passwords     INFO	Records: 0 applied, 0 reconciled, 0 left to fetch
2009-12-01 16:29:58	Engine.Passwords     DEBUG	Preparing 117 outgoing records
2009-12-01 16:29:58	Engine.Passwords     WARN	Sync failed
2009-12-01 16:29:58	Engine.Passwords     DEBUG	Event: weave:engine:sync:error
2009-12-01 16:29:58	Engine.Passwords     INFO	Total (ms): sync 306, processIncoming 1, uploadOutgoing 57, syncStartup 248, createRecord 2
2009-12-01 16:29:58	Service.Main         DEBUG	Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [IWeaveCrypto.unwrapSymmetricKey] Stack trace: CryptoMeta_getKey()@crypto.js:152 < CryptoWrapper_encrypt()@crypto.js:78 < SyncEngine__uploadOutgoing()@engines.js:630 < anonymous()@engines.js:206 < SyncEngine__sync()@engines.js:684 < anonymous()@engines.js:206 < WrappedNotify()@util.js:114 < Engine_sync()@engines.js:216 < WeaveSvc__syncEngine()@service.js:1198 < anonymous()@service.js:1136 < WrappedNotify()@util.js:114 < WrappedLock()@util.js:86 < WrappedCatch()@util.js:65 < sync()@service.js:1060 < anonymous()@sync.js:284
2009-12-01 16:29:58	Engine.Prefs         DEBUG	Event: weave:engine:sync:start
2009-12-01 16:29:58	Engine.Prefs         DEBUG	Ensuring server crypto records are there
2009-12-01 16:29:58	RecordMgr            TRACE	Importing record: https://sj-weave03.services.mozilla.com/1.0/dknite/storage/crypto/prefs
2009-12-01 16:29:58	Net.Resource         DEBUG	GET request for https://sj-weave03.services.mozilla.com/1.0/dknite/storage/crypto/prefs
2009-12-01 16:29:58	Net.Resource         DEBUG	GET success: 200
2009-12-01 16:29:58	Engine.Prefs         INFO	First sync, uploading all items
2009-12-01 16:29:58	Engine.Prefs         INFO	1 outgoing items pre-reconciliation
2009-12-01 16:29:58	Engine.Prefs         DEBUG	Downloading & applying server changes
2009-12-01 16:29:58	Engine.Prefs         INFO	Records: 0 applied, 0 reconciled, 0 left to fetch
2009-12-01 16:29:58	Engine.Prefs         DEBUG	Preparing 1 outgoing records
2009-12-01 16:29:58	Engine.Prefs         WARN	Sync failed
2009-12-01 16:29:58	Engine.Prefs         DEBUG	Event: weave:engine:sync:error
2009-12-01 16:29:58	Engine.Prefs         INFO	Total (ms): sync 101, processIncoming 1, uploadOutgoing 27, syncStartup 73, createRecord 3
2009-12-01 16:29:58	Service.Main         DEBUG	Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [IWeaveCrypto.unwrapSymmetricKey] Stack trace: CryptoMeta_getKey()@crypto.js:152 < CryptoWrapper_encrypt()@crypto.js:78 < SyncEngine__uploadOutgoing()@engines.js:630 < anonymous()@engines.js:206 < SyncEngine__sync()@engines.js:684 < anonymous()@engines.js:206 < WrappedNotify()@util.js:114 < Engine_sync()@engines.js:216 < WeaveSvc__syncEngine()@service.js:1198 < anonymous()@service.js:1136 < WrappedNotify()@util.js:114 < WrappedLock()@util.js:86 < WrappedCatch()@util.js:65 < sync()@service.js:1060 < anonymous()@sync.js:284
2009-12-01 16:29:58	Service.Main         DEBUG	Event: weave:service:sync:error
2009-12-01 16:29:58	Service.Main         DEBUG	Next sync in 86400 sec.
2009-12-01 16:29:58	Service.Main         DEBUG	Exception: Some engines did not sync correctly No traceback available
Status: UNCONFIRMED → NEW
Ever confirmed: true
I built a debug version of WeaveCrypto and used the same failing unwrapSymmetricKey inputs and found that it was failing at step 4:

http://hg.mozilla.org/labs/weave/file/df8536fd7d1b/crypto/src/WeaveCrypto.cpp#l960

So this means it was able to process the inputs and unwrap the private key but failed to PK11_PubUnwrapSymKey.

I double checked the modified dates of the various keys, and they're all created from the same session, so the inputs into unwrapSymmetricKey should all be the same.
And as a sanity check, Tony tried syncing with 1.0b2 (the version he was using before upgrading to 1.0b3pre1 and ran into this problem) and IWeaveCrypto.unwrapSymmetricKey was still failing.

So.. still no idea what could be wrong. The server data is theoretically the same (unchanged modified time), crypto is unchanged, passphrase is unchanged..
Component: General → Sync
QA Contact: general → sync
Summary: Sync is not working after update to Weave 1.0b2 → Sync is not working after update IWeaveCrypto.unwrapSymmetricKey NS_ERROR_FAILURE
Assignee: nobody → edilee
Flags: blocking-weave1.0+
OS: Windows 7 → All
Hardware: x86_64 → All
I double checked with the crypto library used on the weave web interface, and it also fails when trying to unwrap the symmetric key. The 256-byte decrypted value doesn't match the expected PKCS#1 type 2 format.
Attached file a sad activity log :( — 
Seems like two syncs started at the same time because Minefield and Namoroka were open on the same machine and idle triggered syncing.

1. Both Namoroka and Minefield grab the pub/priv keypair at the start of sync
2. Somehow Namoroka decided to start deleting data
3. Namoroka generates a new keypair (slow)
4. Minefield generates new crypto/symkeys because the server was empty (fast)
5. Namoroka finally uploads keypair and sees symkeys existing and stops
Oh, I should note that the above log is from Nov 21st. I'm assuming Namoroka got a weave update and needed to wipe the server. During the Namoroka wipe process, meta/global wasn't updated by the time Minefield ran remoteSetup, so it continued.
http://hg.mozilla.org/labs/weave/rev/8f9308938f3f
Check that the cryptometa is unwrappable when syncing; if not purge the key and data and make a new crypto record. 

This is the recovery step of the bug.
Target Milestone: --- → 1.0 beta3
http://hg.mozilla.org/labs/weave/rev/44ceecdd5b86
Avoid concurrent key generation by updating meta/global immediately after resetting the client and have wipeServer not delete the meta collection. Also on detecting a syncid mismatch, sleep to allow remote keypair to be uploaded, and don't force a mismatch on upgrade.
Status: NEW → RESOLVED
Closed: 15 years ago
Resolution: --- → FIXED
Component: Firefox Sync: Backend → Sync
Product: Cloud Services → Firefox
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: