1423395 - Sync will duplicate history visits.

Status: RESOLVED FIXED

(Firefox :: Sync, enhancement, P1)

Description

[Thom Chiovoloni [:tcsc] (ex-moco)]

We truncate the microsecond part of the `date` field before inserting (insertMany requires a Date object, which doesn't allow us to provide microseconds), but we consider it when deduping. This will lead to us roughly doubling the number of history visits D:

Patch incoming.

Comment 1

[Thom Chiovoloni [:tcsc] (ex-moco)]

Attachment: Bug 1423395 - Clamp and truncate microseconds from incoming history visit dates when deduping

Review commit: https://reviewboard.mozilla.org/r/205648/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/205648/

Comment 2

[Mark Hammond [:markh] [:mhammond]]

Comment on attachment 8934760 [details]
Bug 1423395 - Clamp and truncate microseconds from incoming history visit dates when deduping

https://reviewboard.mozilla.org/r/205648/#review211232

This looks good, but the test seems unclear to me. While I'm sure it's just me not understanding it, it would be great if it could be commented better (and ideally not use time2, unless I *completely* misunderstand it :)

::: services/sync/modules/engines/history.js:298
(Diff revision 1)
>        this._log.error("Error while fetching visits for URL ${record.histUri}", record.histUri);
>      }
>  
>      let i, k;
>      for (i = 0; i < curVisitsAsArray.length; i++) {
> -      curVisits.add(curVisitsAsArray[i].date + "," + curVisitsAsArray[i].type);
> +      // Same logic as used in the loop to generate the key.

This might be clearer as `// Same logic as used in the loop below to generate visitKey.` (It wasn't immediately clear what loop was being referred to given we are in a loop here)

::: services/sync/tests/unit/test_history_engine.js:156
(Diff revision 1)
> +  let {count} = await rawAddVisit(id, "https://www.example.com", time,
> +                                  PlacesUtils.history.TRANSITIONS.TYPED);
> +  equal(count, 1);
> +
> +  let visits = await PlacesSyncUtils.history.fetchVisitsForURL("https://www.example.com");
> +  equal(visits.length, 1);

ISTM we might as well assert that the visitDate here is exactly what we added.

::: services/sync/tests/unit/test_history_engine.js:166
(Diff revision 1)
> +
> +  let wbo = collection.wbo(id);
> +  let data = JSON.parse(JSON.parse(wbo.payload).ciphertext);
> +  equal(data.visits[0].date, time);
> +
> +  let time2 = (Date.now() - oneHourMS / 2) * 1000 + 444;

A comment here would be good to indicate how time2 relates to time - in general, I think this test needs more comments to explain its intent.

(Actually, I'm not sure why time2 is relevant here - IIUC, we should really only need time, as that is the timestamp that ends up duplicated?)

Comment 3

[Marco Bonardo [:mak]]

Fwiw, from quite some time we started rounding times in Places. It's possible some code doesn't do that yet, and I'm happy to get bugs filed where we don't.

Comment 4

[Thom Chiovoloni [:tcsc] (ex-moco)]

Comment on attachment 8934760 [details]
Bug 1423395 - Clamp and truncate microseconds from incoming history visit dates when deduping

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/205648/diff/1-2/

Comment 5

[Thom Chiovoloni [:tcsc] (ex-moco)]

Comment on attachment 8934760 [details]
Bug 1423395 - Clamp and truncate microseconds from incoming history visit dates when deduping

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/205648/diff/2-3/

Comment 6

[Thom Chiovoloni [:tcsc] (ex-moco)]

Comment on attachment 8934760 [details]
Bug 1423395 - Clamp and truncate microseconds from incoming history visit dates when deduping

https://reviewboard.mozilla.org/r/205648/#review211232

> A comment here would be good to indicate how time2 relates to time - in general, I think this test needs more comments to explain its intent.
> 
> (Actually, I'm not sure why time2 is relevant here - IIUC, we should really only need time, as that is the timestamp that ends up duplicated?)

Without it we fail this check: https://searchfox.org/mozilla-central/source/services/sync/modules/engines.js#1566

(unrelated: the trace statements around that line in reconcile are examples of logs that aren't output without bug 1425544)

Comment 7

[Mark Hammond [:markh] [:mhammond]]

Comment on attachment 8934760 [details]
Bug 1423395 - Clamp and truncate microseconds from incoming history visit dates when deduping

https://reviewboard.mozilla.org/r/205648/#review214040

I don't think the test is exercising the new code - it passes even without the changes to the history engine!

::: services/sync/tests/unit/test_history_engine.js:138
(Diff revision 3)
>  
>    deepEqual(engine.toFetch, []);
> +  await PlacesTestUtils.clearHistory();
> +});
> +
> +add_task(async function test_history_visit_roundtrip() {

I don't see where this test is arranging to process a visit with a timestamp that only differs by microseconds and is thus ignored?

Comment 8

[Thom Chiovoloni [:tcsc] (ex-moco)]

Comment on attachment 8934760 [details]
Bug 1423395 - Clamp and truncate microseconds from incoming history visit dates when deduping

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/205648/diff/3-4/

Comment 9

[Mark Hammond [:markh] [:mhammond]]

Comment on attachment 8934760 [details]
Bug 1423395 - Clamp and truncate microseconds from incoming history visit dates when deduping

https://reviewboard.mozilla.org/r/205648/#review214056

Thanks, and sorry for the misunderstanding!

Comment 10

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/9723654fda39
Clamp and truncate microseconds from incoming history visit dates when deduping r=markh

Comment 11

[Bogdan Tara[:bogdan_tara | bogdant]]

https://hg.mozilla.org/mozilla-central/rev/9723654fda39