Open Bug 721713 Opened 12 years ago Updated 2 years ago

Sync fail with: Failed to reconcile incoming record with exception "guidMap is undefined JS Stack trace"

Categories

(Firefox :: Sync, defect)

Product:
Firefox
Component:
Sync
Platform:
x86
macOS
Type:
defect

Tracking

()

People

(Reporter: bugzilla, Unassigned)

Details

Attachments

(2 files)

error log
88.27 KB, text/plain
Details
error log with Nightly 2012-01-29 (console appender=Debug)
2.33 MB, text/plain
Details
Attached file error log — 
Firefox cannot sync these days.
There are many warning log like:
# I attach full log file

1327657741250	Sync.Engine.Bookmarks	WARN	Failed to reconcile incoming record 38b0HTFgHO4r
1327657741250	Sync.Engine.Bookmarks	WARN	Encountered exception: guidMap is undefined JS Stack trace: _mapDupe([object Object])@bookmarks.js:358 < _createRecord("38b0HTFgHO4r")@bookmarks.js:438 < SyncEngine__isEqual([object Object])@engines.js:1017 < SyncEngine__reconcile([object Object])@engines.js:1082 < ([object Object])@engines.js:884 < ()@record.js:828 < Channel_onDataAvail([object XPCWrappedNative_NoHelper],null,[object XPCWrappedNative_NoHelper],3883,383814)@resource.js:579
I haven't heard of this one before! We just landed rewritten record reconciling in bug 710448. But, this doesn't appear to be related because it appears you are running Firefox 10.

How many times have you seen this error? Was it a one-time thing? Intermittent? Or, is it continuous and preventing you from syncing at all?

If you can reproduce it, I'd be very interested in seeing if it occurs on Firefox 11. However, you may have to wait until Firefox 11 is promoted to Firefox Beta, as I don't think the changes from bug 710448 have made it into a released Aurora yet.
This duck quacks a lot like bug 670069. Same stack trace and all.

Tomoya: if you can reproduce the issue, please follow the steps at https://bugzilla.mozilla.org/show_bug.cgi?id=670069#c3 and let us know what you get.
(In reply to Gregory Szorc [:gps] from comment #1)
> How many times have you seen this error? Was it a one-time thing?
> Intermittent? Or, is it continuous and preventing you from syncing at all?

Reproduced continuously and I cannot sync more than a week.

> If you can reproduce it, I'd be very interested in seeing if it occurs on
> Firefox 11. However, you may have to wait until Firefox 11 is promoted to
> Firefox Beta, as I don't think the changes from bug 710448 have made it into
> a released Aurora yet.

I can test with Aurora/Nightly if you need.
Should I test with Nightly and the same profile?

(In reply to Gregory Szorc [:gps] from comment #3)
> Tomoya: if you can reproduce the issue, please follow the steps at
> https://bugzilla.mozilla.org/show_bug.cgi?id=670069#c3 and let us know what
> you get.

When I executed "Components.utils.import ... ._buildGUIDMap()" on latest Firefox Beta 10.0 and wait a few minutes, I've got huge number of INFO message like:
1327902098942	Sync.Engine.Bookmarks	INFO	XXX: 146769 (O4oUf9dgooiu).
  ... and finally I got:
1327902333547	Sync.Engine.Bookmarks	INFO	XXX: 144673 (tSe-McmOkP65).
1327902333557	Sync.Engine.Bookmarks	INFO	XXX: 144679 (y4mH32DaUSqo).
1327902333559	Sync.Engine.Bookmarks	INFO	XXX: 144681 (zonijhjYFj_L).

Is this enough info for you?
(In reply to dynamis (Tomoya ASAI) from comment #4)
> I can test with Aurora/Nightly if you need.
> Should I test with Nightly and the same profile?

I'll attach log file with Nightly too.

> (In reply to Gregory Szorc [:gps] from comment #3)
> > Tomoya: if you can reproduce the issue, please follow the steps at
> > https://bugzilla.mozilla.org/show_bug.cgi?id=670069#c3 and let us know what
> > you get.
> 
> When I executed "Components.utils.import ... ._buildGUIDMap()" on latest
> Firefox Beta 10.0 and wait a few minutes, I've got huge number of INFO
> message like:
> 1327902098942	Sync.Engine.Bookmarks	INFO	XXX: 146769 (O4oUf9dgooiu).
>   ... and finally I got:
> 1327902333547	Sync.Engine.Bookmarks	INFO	XXX: 144673 (tSe-McmOkP65).
> 1327902333557	Sync.Engine.Bookmarks	INFO	XXX: 144679 (y4mH32DaUSqo).
> 1327902333559	Sync.Engine.Bookmarks	INFO	XXX: 144681 (zonijhjYFj_L).

Also done with 12.0a1 (2012-01-29) Nightly build and same result:
  ... many many INFO for each IDs and finally:
1327903165870	Sync.Engine.Bookmarks	INFO	XXX: 144673 (tSe-McmOkP65).
1327903165872	Sync.Engine.Bookmarks	INFO	XXX: 144679 (y4mH32DaUSqo).
1327903165874	Sync.Engine.Bookmarks	INFO	XXX: 144681 (zonijhjYFj_L).
You wouldn't happen to have one hundred and forty thousand bookmarks, would you?
And I'd be really interested to see what happens if you give this a try:

  https://addons.mozilla.org/en-US/firefox/addon/places-maintenance/
I count 34563 bookmarks in that log. That is a TON! Do you really have that many bookmarks? Do you have an extension creating bookmarks automatically?

The "wait a few minutes" is really concerning. If it takes Sync that long just to obtain the set of bookmarks, the bookmarks database is being really slow. And, when Sync runs, this slowness is possibly causing the timeout errors you see.

Please try out the Places Maintenance extension Richard linked to in comment #7 and run the "All" preset. Please also copy the output from that extension into this bug so we know what we're dealing with.
(In reply to Richard Newman [:rnewman] from comment #6)
> You wouldn't happen to have one hundred and forty thousand bookmarks, would
> you?

I don't have 140k bookmarks, I have 15k unsorted bookmarks and 3k other bookmarks and 3k kind of tags.
The number 140k is including history isn't it?

(In reply to Richard Newman [:rnewman] from comment #7)
> And I'd be really interested to see what happens if you give this a try:
> 
>   https://addons.mozilla.org/en-US/firefox/addon/places-maintenance/

I've already installed the extension (since the release of the extension) and here is the result:

> Integrity check
+ The database is sane
> Reindex
+ The database has been reindexed
> Orphans expiration
+ Database cleaned up
> Coherence check
+ The database is coherent
> Vacuum
Initial database size is 40960 KiB
+ The database has been vacuumed
Final database size is 40960 KiB
> Statistics
Database size is 40960 KiB
user_version is 17
page_size is 32768
cache_size is 128
journal_mode is wal
synchronous is 1
History can store a maximum of 100664 unique pages
Table moz_bookmarks has 31726 records
Table moz_bookmarks_roots has 5 records
Table moz_keywords has 46 records
Table sqlite_sequence has 1 records
Table moz_favicons has 4638 records
Table moz_annos has 6300 records
Table moz_anno_attributes has 13 records
Table moz_items_annos has 15907 records
Table moz_places has 50356 records
Table moz_historyvisits has 80989 records
Table moz_inputhistory has 2600 records
Table sqlite_stat1 has 15 records
Table moz_hosts has 6430 records
Index sqlite_autoindex_moz_bookmarks_roots_1
Index sqlite_autoindex_moz_keywords_1
Index sqlite_autoindex_moz_favicons_1
Index sqlite_autoindex_moz_anno_attributes_1
Index sqlite_autoindex_moz_inputhistory_1
Index moz_bookmarks_itemindex
Index moz_bookmarks_parentindex
Index moz_bookmarks_itemlastmodifiedindex
Index moz_places_faviconindex
Index moz_places_hostindex
Index moz_places_visitcount
Index moz_places_frecencyindex
Index moz_places_lastvisitdateindex
Index moz_historyvisits_placedateindex
Index moz_historyvisits_fromindex
Index moz_historyvisits_dateindex
Index moz_annos_placeattributeindex
Index moz_items_annos_itemattributeindex
Index moz_places_url_uniqueindex
Index moz_bookmarks_guid_uniqueindex
Index moz_places_guid_uniqueindex
Index moz_favicons_guid_uniqueindex
Index sqlite_autoindex_moz_hosts_1
Index moz_hosts_frecencyhostindex
(In reply to Gregory Szorc [:gps] from comment #9)
> I count 34563 bookmarks in that log. That is a TON! Do you really have that
> many bookmarks? Do you have an extension creating bookmarks automatically?

No extension creating any bookmarks automatically.
I manually bookmark maybe about 30 pages a day (mainly workday).
It's not surprising to have about 20~30k bookmarks
# (30 items/day * 20 days/month * 12 month = 7200 items/year) * few years

I haven't check the code but I heard that Places have separate item for tagged bookmark. I use many tags to make awesome-bar really awesome and the number of item become larger.

> The "wait a few minutes" is really concerning. If it takes Sync that long
> just to obtain the set of bookmarks, the bookmarks database is being really
> slow. And, when Sync runs, this slowness is possibly causing the timeout
> errors you see.

Your code write console.log for every items and took long time doesn't it?
When sync service started, Firefox freezed every time and cannot use it but performance and async-ness improvement make it work for this profile too.
I don't see any timeout error these days.

The message I see these days is:
  Sync has not been able to complete during the last 7 days. Please check your
  network sttings.
# this message start showing maybe since about a week ago, no problem last month

> Please try out the Places Maintenance extension Richard linked to in comment
> #7 and run the "All" preset. Please also copy the output from that extension
> into this bug so we know what we're dealing with.

Previous comment is OK?
(In reply to dynamis (Tomoya ASAI) from comment #11)
> I manually bookmark maybe about 30 pages a day (mainly workday).
> It's not surprising to have about 20~30k bookmarks
> # (30 items/day * 20 days/month * 12 month = 7200 items/year) * few years

That's a lot of bookmarks!
 
> The message I see these days is:
>   Sync has not been able to complete during the last 7 days. Please check
> your
>   network sttings.
> # this message start showing maybe since about a week ago, no problem last
> month

We recently changed Sync so the error bar you are seeing only shows up if Sync hasn't worked for over a week. In other words, if Sync starts breaking, you won't know for a week. Can you think of anything you did that might have triggered breakage about 2 weeks ago (since you started seeing the error about a week ago)?

Also, the logs you posted indicate that Sync is partially working: it is just bookmarks that are failing.
 
> > Please try out the Places Maintenance extension Richard linked to in comment
> > #7 and run the "All" preset. Please also copy the output from that extension
> > into this bug so we know what we're dealing with.
> 
> Previous comment is OK?

Yes.
Component: Firefox Sync: Backend → Sync
Product: Cloud Services → Firefox
Severity: normal → S3
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: