1392263 - Regression in PLACES_AUTOCOMPLETE_1ST_RESULTS_TIME_MS on July 15th

Status: VERIFIED FIXED

(Toolkit :: Places, defect, P1)

Description

[Panos Astithas (he/him) [:past] (please ni?)]

There is a regression in PLACES_AUTOCOMPLETE_1ST_RESULTS_TIME_MS occurring on 7/15:

https://mzl.la/2vX5elO

PLACES_AUTOCOMPLETE_6_FIRST_RESULTS_TIME_MS seems unaffected however:

https://mzl.la/2w0BzdG

We need to understand why this happened.

Comment 1

[Marco Bonardo [:mak]]

range: https://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=67cd1ee26f2661fa5efe3d952485ab3c89af4271&tochange=bd1b6a4e5d8e1184a89ae60a74fd86d3d4a9e95c

Just by looking at it, Bug 1359899 is a potential suspect.
We must confirm that though.

Comment 2

[Simon Lindholm]

I stared at the patch for bug 1359899 for a while, and came up with the following possible explanation:

In the previous code, when the heuristic match was a search, _addMatch was called with that search, incrementing _localMatchesCount, and thus _onResultRow never detected |_localMatchesCount == 0|, and the stopwatch was later cancelled.  Instead all cases where |_localMatchesCount == 0| occurs happen from _matchKnownUrl, which is generally quite quick.

In the new world, the condition for recording TELEMETRY_1ST_RESULT is that |_counts[MATCHTYPE.GENERAL] == 0|, which doesn't take into account heuristic matches.  Thus when the heuristic result is a search we *do* manage to record the timing for the first non-heuristic awesomebar match.  (In fact, when _matchKnownUrl calls _onResultRow with a heuristic match, this causes |_counts[MATCHTYPE.GENERAL] == 0| to be true twice, causing a "TelemetryStopwatch: requesting elapsed time for nonexisting stopwatch" error to appear in the console.  It would be great to fix this at the same time as deciding what TELEMETRY_1ST_RESULT really should count.)

Comment 3

[Marco Bonardo [:mak]]

(In reply to Simon Lindholm from comment #2)
> at the same
> time as deciding what TELEMETRY_1ST_RESULT really should count.)

You have a good point, the original intent was to measure "responsiveness", so how much time elapsed before we pushed out the first result. I think that has still value and it's what we should aim at.

an alternative would be to measure the first result from the db, but that's sort of covered by the "6 first results" probe.

Would you have time to fix the probe to actually measure the time to push out the first result, whatever it is?

Comment 4

[Simon Lindholm]

Attachment: Make TELEMETRY_1ST_RESULT count results of all types

If we want to include heuristic results, it should be as simple as this (untested, though).  I'd expect most measurements to fall below the 50ms minimum (like with the old telemetry data), but mean and 95th percentile would indeed still be useful to measure.

Comment 5

[Marco Bonardo [:mak]]

Comment on attachment 8907835 [details] [diff] [review]
Make TELEMETRY_1ST_RESULT count results of all types

Review of attachment 8907835 [details] [diff] [review]:
-----------------------------------------------------------------

Yeah, at this point let's just rebase the measurement.

Comment 6

[Simon Lindholm]

Should I test this somehow, e.g. with a try push? Doesn't seem like TELEMETRY_1ST_RESULT appears in any tests, though, and the patch is very straightforward.

Comment 7

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/968822d2cc5d
Make TELEMETRY_1ST_RESULT count results of all types. r=mak

Comment 8

[Marco Bonardo [:mak]]

I just pushed it :)

For the future, I may suggest using the mozreview workflow, that simplifies pushing to the tree.
Though, we are also in the middle of an further review evolution (not sure when exactly, but soon) so it may be not worth learning something that could disappear shortly.

Still thank you a lot for your help, it's very useful and appreciated by all the team.

Comment 9

[Wes Kocher (:KWierso) (Not reading bugmail; email directly if needed)]

https://hg.mozilla.org/mozilla-central/rev/968822d2cc5d

Comment 10

[Ryan VanderMeulen [:RyanVM]]

This needs a mozilla-release approval ASAP if the desire is for this to ship in Fx56. We're building the RC on Monday.

Comment 11

[Marco Bonardo [:mak]]

I don't think it's critical, we are fixing the measurement, not addressing a real regression. It shouldn't cause us any troubles.

Comment 12

[Marco Bonardo [:mak]]

I also verified telemetry is back measuring the expected thing.