Closed Bug 621594 Opened 12 years ago Closed 12 years ago

History sync: failure when title is null

Categories

(Firefox :: Sync, defect)

defect
Not set
normal

Tracking

()

VERIFIED FIXED
Tracking Status
blocking2.0 --- betaN+

People

(Reporter: philikon, Assigned: philikon)

References

Details

(Whiteboard: [has patch][needs review mconnor])

Attachments

(1 file)

Syncing one of my accounts that I haven't synced in a while, I got this:

2010-12-27 14:35:00	Service.Main         DEBUG	history failed: NS_ERROR_NOT_AVAILABLE JS Stack trace: Res_get()@resource.js:376 < SyncEngine__processIncoming()@engines.js:511 < ()@engines.js:203 < SyncEngine__sync()@engines.js:768 < wrappedSync(null)@util.js:168 < batchedSync()@util.js:174 < ()@engines.js:203 < WrappedNotify()@util.js:147 < Engine_sync()@engines.js:213 < WeaveSvc__syncEngine([object Object])@service.js:1738 < ()@service.js:1624 < WrappedNotify()@util.js:147 < WrappedLock()@util.js:119 < WrappedCatch()@util.js:97 < sync()@service.js:1529 < (0)@browser.js:5208

I could reproduce this reliably (using the Mozilla ethernet, so no flaky network connection or anything) and it always occurred in the history engine, so I turned on Trace logging for history. Many records synced fine, e.g.:

2010-12-27 14:35:00	Engine.History       TRACE	Local record: { id: NoU-i-NviRAx
  index: 140
  modified: undefined
  payload: {"id":"NoU-i-NviRAx","histUri":"https://bugzilla.mozilla.org/attachment.cgi?id=497962","title":null,"visits":[{"date":1292884239566435,"type":1},{"date":1292461654931954,"type":1}]}
  collection: history }
2010-12-27 14:35:00	Engine.History       TRACE	Local record is the same
2010-12-27 14:35:00	Engine.History       TRACE	Skipping reconciled incoming item NoU-i-NviRAx

But then it failed on this record:

2010-12-27 14:35:00	Engine.History       TRACE	Incoming: { id: Np5C8k8z4cQY
  index: 2600
  modified: 1293049998.56
  payload: {"id":"Np5C8k8z4cQY","histUri":"resource://gre/components/nsPlacesDBFlush.js","title":null,"visits":[{"date":1291409637910610,"type":2},{"date":1291333682796411,"type":2}]}
  collection: history }
2010-12-27 14:35:00	Engine.History       TRACE	Reconcile step 1: Check for conflicts
2010-12-27 14:35:00	Engine.History       TRACE	Reconcile step 2: Check for updates
2010-12-27 14:35:00	Engine.History       TRACE	Reconcile step 2.5: Don't dupe deletes
2010-12-27 14:35:00	Engine.History       TRACE	Reconcile step 3: Find dupes
2010-12-27 14:35:00	Store.History        TRACE	  -> processing history entry: resource://gre/components/nsPlacesDBFlush.js
2010-12-27 14:35:00	Engine.History       TRACE	Event: weave:engine:sync:error
2010-12-27 14:35:00	Engine.History       DEBUG	Total (ms): sync 6108, processIncoming 5661, syncStartup 446, findDupe 0, createRecord 1109, isEqual 1953, reconcile 2951, syncCleanup 1
2010-12-27 14:35:00	Service.Main         DEBUG	history failed: NS_ERROR_NOT_AVAILABLE JS Stack trace: Res_get()@resource.js:376 < SyncEngine__processIncoming()@engines.js:511 < ()@engines.js:203 < SyncEngine__sync()@engines.js:768 < wrappedSync(null)@util.js:168 < batchedSync()@util.js:174 < ()@engines.js:203 < WrappedNotify()@util.js:147 < Engine_sync()@engines.js:213 < WeaveSvc__syncEngine([object Object])@service.js:1738 < ()@service.js:1624 < WrappedNotify()@util.js:147 < WrappedLock()@util.js:119 < WrappedCatch()@util.js:97 < sync()@service.js:1529 < (0)@browser.js:5208

Notice "title":null in the payload. I bet the history API isn't liking this, so it's throwing NS_ERROR_NOT_AVAILABLE.

So why is Res_get() on top of the stack? Pretty simple: we process incoming records as we fetch them in ChannelListener._onProgress (see the recordHandler thing in collection.js which engines.js sets). So the async handler in resource.js hasn't completed yet, so to the outside caller it looks like the failure is coming from Resource.get (Res_get) whereas it's really occurring within the async _onProgress handler.

Needless to say this would all be better if our code was more async to begin with (and as a result had better error reporting from async calls).
Assignee: nobody → philipp
blocking2.0: --- → ?
Attached patch v1Splinter Review
Attachment #499984 - Flags: review?(mconnor)
blocking2.0: ? → beta9+
Whiteboard: [has patch][needs review mconnor]
Attachment #499984 - Flags: review?(mconnor) → review+
1.6.x: https://hg.mozilla.org/services/fx-sync/rev/8634f4201f44
default: https://hg.mozilla.org/services/fx-sync/rev/e7ac71ac0d90
Status: NEW → RESOLVED
Closed: 12 years ago
Resolution: --- → FIXED
Blocks: 621194
As per today's meeting, beta 9 will be a time-based release. Marking these all betaN+. Please move it back to beta9+ if  you believe it MUST be in the next beta (ie: trunk is in an unshippable state without this)
blocking2.0: beta9+ → betaN+
I can verify that this patch did fix my sync error problems.
Blocks: 623788
Trying to verify this for 1.6.2. Is there a way to create a null title of a history item?
(In reply to comment #5)
> Trying to verify this for 1.6.2. Is there a way to create a null title of a
> history item?

You should be able to do that by visiting a URL like resource://gre/components/nsPlacesDBFlush.js on 3.6.
verified with 1.6.2 on 3.6.13
Status: RESOLVED → VERIFIED
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.