771278 - Selecting site via another device's top sites removes it from Awesomebar dropdown

Status: RESOLVED FIXED

(Firefox :: Sync, defect, P1)

Description

[Paul [pwd]]

User Agent: Mozilla/5.0 (Windows NT 6.1; rv:16.0) Gecko/16.0 Firefox/16.0
Build ID: 20120705030540

Steps to reproduce:

If I select a site via my top sites on Fennec. If I then later check my awesomebar, the site's been removed.

Comment 1

[Richard Newman [:rnewman]]

Can you elaborate?

Did you try searching by URL or by title?

Can you provide a desktop sync log for the first sync after reproducing? You'll need to repro on mobile, sync mobile, sync desktop.

Setting history and bookmarks to Trace logging would help:

https://philikon.wordpress.com/2011/06/13/how-to-file-a-good-sync-bug/

Comment 2

[Paul [pwd]]

To elaborate:

If I click the awesomebar on desktop, I have my top sites

I have a similar list on fennec as I visit a bunch of the same sites on both devices.

If I click one of those sites on Fennec, I'll find that once I've gone back to desktop the site is missing from my awesomebar top sites.

If I type in the tag/site name/url the site will come up. It just doesn't appear in the top sites list.

Once again clicking the site on the desktop awesomebar after finding it via a search will re-add it to the awesomebar top sites list.

It's almost like the site can't exist on both at the same time.

Comment 3

[Richard Newman [:rnewman]]

(In reply to Paul [sabret00the] from comment #2)

> Once again clicking the site on the desktop awesomebar after finding it via
> a search will re-add it to the awesomebar top sites list.
> 
> It's almost like the site can't exist on both at the same time.

I have no idea what the "awesomebar top sites" list would be on desktop. The only way I can make my Aurora awesomebar give suggestions is to start to type something. Can you provide a screenshot? 

about:newtab shows suggestions. Are you seeing the same list there?

Visiting a site on Fennec will cause a history entry to be synced up, and that will affect Places on desktop. A Trace-level history log from desktop will help.

Comment 4

[Paul [pwd]]

(In reply to Richard Newman [:rnewman] from comment #3)
> I have no idea what the "awesomebar top sites" list would be on desktop. The
> only way I can make my Aurora awesomebar give suggestions is to start to
> type something. Can you provide a screenshot? 

On any tab click the down arrow on the awesomebar and you have a list of your twelve most visited sites.

(In reply to Richard Newman [:rnewman] from comment #1)
> Can you provide a desktop sync log for the first sync after reproducing?
> You'll need to repro on mobile, sync mobile, sync desktop.

Ah, how I lust after the sync now option in Fennec. Anyway, sorting this now.

Comment 5

[Richard Newman [:rnewman]]

(In reply to Paul [sabret00the] from comment #4)
> On any tab click the down arrow on the awesomebar and you have a list of
> your twelve most visited sites.

Ah. Yay discoverability!

> Ah, how I lust after the sync now option in Fennec. Anyway, sorting this now.

Settings > pick your Sync account > press the menu button > Sync Now.

Comment 6

[Paul [pwd]]

Attachment: Sync Logs

Log showing a site has been removed.

Comment 7

[Richard Newman [:rnewman]]

(In reply to Paul [sabret00the] from comment #6)

> Log showing a site has been removed.

That log doesn't indicate that any history or bookmark records were downloaded/applied, and desktop uploaded a single record. No smoking gun here. This is essentially an empty log file.

Are you sure you got the right log?

And can you grab a mobile log?

Comment 8

[Paul [pwd]]

Attachment: There was this other log

Second desktop log. How do I grab a mobile log? In the same way?

Comment 9

[Richard Newman [:rnewman]]

http://160.twinql.com/how-to-file-a-good-android-sync-bug

Comment 10

[Richard Newman [:rnewman]]

(In reply to Paul [sabret00the] from comment #8)
> Created attachment 640736 [details]
> There was this other log

As suggested in Comment 1, we'd need Trace logging to see what's happening here. See philikon's post for how to change that.

Comment 11

[Paul [pwd]]

I thought I turned that on when I enabled services.sync.log.appender.file.logOnSuccess?

Comment 12

[Richard Newman [:rnewman]]

(In reply to Paul [sabret00the] from comment #11)
> I thought I turned that on when I enabled
> services.sync.log.appender.file.logOnSuccess?

You need to set a pref to Trace (caps matters), and restart Firefox.

Comment 13

[Paul [pwd]]

Right, I've reconfirmed that this is happening. Though it's not happening in as timely a fashion as it should be. However, I'm in need of knowing how to clear the sync logs so as that I can try and find the necessary log to facilitate this issue being fixed.

Comment 14

[Naoki Hirata :nhirata (please use needinfo instead of cc)]

tracy, could you possibly look into this please?

Comment 15

[Tracy Walker [:tracy]]

Is tricky to reproduce.  I think what triggered it for me was having the page just visited on both desktop and mobile. Then sync mobile, sync desktop.  

this is a snippet of log on desktop when it the item disappeared from the top 12 list:
1348253323828	Sync.Engine.History	TRACE	Event: weave:engine:sync:start
1348253323828	Sync.Tracker.History	TRACE	Clearing changed ID list
1348253323828	Sync.Engine.History	INFO	1 outgoing items pre-reconciliation
1348253323828	Sync.Engine.History	TRACE	Downloading & applying server changes
1348253323829	Sync.Engine.Bookmarks	TRACE	Saving json to disk: weave/failed/bookmarks.json
1348253323955	Sync.Engine.History	TRACE	Incoming: { id: UTn_GWmYtVan  index: 0  modified: 1348253278.16  ttl: 5184000  payload: {"id":"UTn_GWmYtVan","visits":[{"date":1344878808588990,"type":1},{"type":1,"date":1348253111013000},{"type":1,"date":1348253111012000},{"type":1,"date":1348253111011000},{"type":1,"date":1348253111014000}],"title":"Professional Disc Golf Association","histUri":"http://www.pdga.com/"}  collection: history }
1348253323956	Sync.Engine.History	TRACE	Reconciling UTn_GWmYtVan. exists=true; modified=true; local age=95.95600008964539; incoming age=45.72000002861023
1348253323957	Sync.Engine.History	WARN	DATA LOSS: Both local and remote changes to record: UTn_GWmYtVan
1348253323957	Sync.Collection	DEBUG	mesg: GET success 200 https://phx-sync470.services.mozilla.com/1.1/u4nhdnma3korempmidqxpplkfhnto6ov/storage/history?newer=1348253203.51&full=1
1348253323957	Sync.Collection	DEBUG	GET success 200 https://phx-sync470.services.mozilla.com/1.1/u4nhdnma3korempmidqxpplkfhnto6ov/storage/history?newer=1348253203.51&full=1
1348253323963	Sync.Engine.History	INFO	Records: 1 applied, 1 successfully, 0 failed to apply, 0 newly failed to apply, 0 reconciled.
1348253323963	Sync.Engine.History	TRACE	Uploading local changes to server.
1348253323963	Sync.Engine.History	TRACE	Preparing 1 outgoing records
1348253323966	Sync.Engine.History	TRACE	Outgoing: { id: UTn_GWmYtVan  index: 3003  modified: undefined  ttl: 5184000  payload: {"id":"UTn_GWmYtVan","histUri":"http://www.pdga.com/","title":"Professional Disc Golf Association","visits":[{"date":1348253228555353,"type":2},{"date":1348253111014000,"type":1},{"date":1348253111013000,"type":1},{"date":1348253111012000,"type":1},{"date":1348253111011000,"type":1},{"date":1346346427950000,"type":1},{"date":1346346427949000,"type":1},{"date":1344878808588990,"type":1}]}  collection: history }
1348253323967	Sync.Engine.History	INFO	Uploading all of 1 records

Could what was reported in bug 783920 be related to this as well?

Comment 16

[Paul [pwd]]

Does creation date effect the Awesome Bar? Selecting one of the disappeared sites via a text search in Awesome Bar will restore it to it's rightful position.

Comment 17

[Paul [pwd]]

Now that the route cause has been found, any idea on how to prevent this? It's quite an annoying bug.

Comment 18

[Richard Newman [:rnewman]]

Paul: what do you think the root cause is?

Comment 19

[Paul [pwd]]

I'm pretty sure that the rankings just aren't merging correctly. Without knowing the database structure, it's as if whichever table the awesomebar reads from is having the ranking column cleared and once a user selects the site manually, it's being rewritten into the awesomebar table with the correct value.

Comment 20

[Richard Newman [:rnewman]]

Thanks for your input.

Comment 21

[Richard Newman [:rnewman]]

(In reply to Tracy Walker [:tracy] from comment #15)
> Is tricky to reproduce.  I think what triggered it for me was having the
> page just visited on both desktop and mobile. Then sync mobile, sync
> desktop.  

Could not reproduce with these steps in Aurora.

> this is a snippet of log on desktop when it the item disappeared from the
> top 12 list:

Doesn't look suspicious, alas.

> Could what was reported in bug 783920 be related to this as well?

Seems less likely than a history issue, but maybe.

Comment 22

[Richard Newman [:rnewman]]

Managed to reproduce. _Don't_ visit on desktop.

Picked a top site. Visited on mobile. Synced. No longer top on desktop.

If I then visit by picking it from bookmarks, it is _still_ not a top site.

If I type part of the title or URL, it becomes a top site again.


 id          visit_count  hidden      typed       frecency    last_visit_date 
 ----------  -----------  ----------  ----------  ----------  ----------------
*80174       125          0           1           82398       1348011035211016
 80174       127          0           0           58776       1349505808245000
 80174       128          0           0           53184       1349505858697401
*80174       129          0           1           72344       1349505883183277


It's quite possible that the frecency calculation is simply stale, and touching the record updates it and causes it to drop out.

It's also possible that there's something else is going on.

I would have thought that truncation of visits was a likely culprit, but my DB says otherwise.

Comment 23

[Paul [pwd]]

Can I add that I'm also able to lose pages between other devices and not just Fennec to Desktop

Comment 24

[Richard Newman [:rnewman]]

(In reply to Paul [pwd] from comment #23)
> Can I add that I'm also able to lose pages between other devices and not
> just Fennec to Desktop

Not unexpected. The issue is likely in the application of records, rather than who generates them.

Comment 25

[Ed Lee :Mardak]

The dropdown from clicking the down arrow in the awesomebar only shows typed entries, so assuming the unstarred lines from comment 22 are the missing entries, it matches up with not being "typed"

The dropdown is doing an "" empty string search that has special behaviors:
http://mxr.mozilla.org/mozilla-central/source/toolkit/components/places/nsPlacesAutoComplete.js#891

Comment 26

[Paul [pwd]]

(In reply to Ed Lee :Mardak from comment #25)
> The dropdown from clicking the down arrow in the awesomebar only shows typed
> entries, so assuming the unstarred lines from comment 22 are the missing
> entries, it matches up with not being "typed"
> 
> The dropdown is doing an "" empty string search that has special behaviors:
> http://mxr.mozilla.org/mozilla-central/source/toolkit/components/places/
> nsPlacesAutoComplete.js#891

So how can we mitigate the issue? I'm finding myself not visiting sites on certain devices through fear of them going missing on my main desktop.

Would fixing bug 725694 help? Based on the information from comment 25 couldn't we fake typing and submit that to the database with a click of thumbnails on both desktop and mobile?

Comment 27

[Paul [pwd]]

Also it should be noted, that by opening up a site repeatedly (with just the mouse) you can change rank. e.g. moving the eighth site up to first.

Comment 28

[Richard Newman [:rnewman]]

I think we can summarize this bug as:


Visiting a page through anything other than typing it in the Awesomebar results in an updated Sync history record. When applied, this record causes Places to discard the typed=1 attribute, and thus excludes that history entry from the drop-down menu, even though it has previously been typed.


I'm probably misunderstanding something, but it looks like Places' schema and its docs disagree a tiny bit here:

The design doc:

---
Every visit is identified by its visit date, and a visit type (also known as transition type) that represents how we have come to that page (typed, click, redirect, bookmark, etc.).
---

The schema:

---
CREATE TABLE moz_historyvisits (id INTEGER PRIMARY KEY, from_visit INTEGER, place_id INTEGER, visit_date INTEGER, visit_type INTEGER, session INTEGER);
CREATE TABLE moz_places (id INTEGER PRIMARY KEY, url LONGVARCHAR, title LONGVARCHAR, rev_host LONGVARCHAR, visit_count INTEGER DEFAULT 0, hidden INTEGER DEFAULT 0 NOT NULL, typed INTEGER DEFAULT 0 NOT NULL, favicon_id INTEGER, frecency INTEGER DEFAULT -1 NOT NULL, last_visit_date INTEGER, guid TEXT, foreign_count INTEGER DEFAULT 0 NOT NULL);
---

That is: yes, visits have a type, but 'typed' is a property of the *place*, not the *visit*. When we apply the record, we don't specify 'typed' at all.


Sync just calls mozIAsyncHistory::updatePlaces with a sequence of objects, with no value set for 'typed' (or a bunch of other fields).

Those mozIPlaceInfo objects are created by _recordToPlaceInfo:

http://mxr.mozilla.org/mozilla-central/source/services/sync/modules/engines/history.js#241

ISTM that updatePlaces should perhaps not discard existing column values if the provided PlaceInfo records don't specify a replacement.

We can fix this bug in one of two ways:

* Change updatePlaces to do exactly that.
* Change Sync to -- prior to applying every history record -- first fetch the current DB contents and do a merge to preserve fields.

mak, any thoughts?

Comment 29

[Marco Bonardo [:mak]]

(In reply to Richard Newman [:rnewman] from comment #28)
> ISTM that updatePlaces should perhaps not discard existing column values if
> the provided PlaceInfo records don't specify a replacement.
> 
> We can fix this bug in one of two ways:
> 
> * Change updatePlaces to do exactly that.
> * Change Sync to -- prior to applying every history record -- first fetch
> the current DB contents and do a merge to preserve fields.

updatePlaces should not overwrite an existing typed annotation, unless the old value was false and the new value is true. The only case (and I think we are not even supporting that yet) would be all typed visits removal. So basically typed is immutable once set to true, for the docshell.
I think the problem is that updatePlaces takes a slightly different code path compared to a straight visit in the browser itself, the latter has more information and could do better choices.
I'm looking into the code and will shortly report what I find, but off-hand looks like a code bug in History.cpp.

Comment 30

[Marco Bonardo [:mak]]

while I didn't complete the investigation yet, by inspection I found something fishy. I filed Bug 1117072 in Toolkit/Places and will continue there.

Comment 31

[Marco Bonardo [:mak]]

Should have been resolved by the dependency bug 1117072, please verify.

We are going to uplift the fix.

Comment 32

[Paul [pwd]]

(In reply to Marco Bonardo [::mak] (needinfo? me) from comment #31)
> Should have been resolved by the dependency bug 1117072, please verify.
> 
> We are going to uplift the fix.

I can verify that it's fixed. Thank you.

Comment 33

[[SV Manager] Florin Mezei, QA (:FlorinMezei)]

(In reply to Paul [pwd] from comment #32)
> I can verify that it's fixed. Thank you.

Marking as Verified for 38.

Comment 34

[Rares Doghi, Desktop QA]

This bug was Verified on FF 38, I have removed the QeVerify+ flag.