Closed Bug 1356758 Opened 4 years ago Closed 4 years ago

Intermittent browser/modules/test/browser/browser_UsageTelemetry_urlbar.js | Test timed out -

Categories

(Firefox :: General, defect, P1)

Product:
Firefox
Component:
General
Type:
defect

Tracking

()

Status:
RESOLVED FIXED
Milestone:
Firefox 58
Tracking Flags:
Tracking Status
firefox56 --- wontfix
firefox57 --- fixed
firefox58 --- fixed

People

(Reporter: intermittent-bug-filer, Assigned: mak)

References

Details

(Keywords: intermittent-failure, Whiteboard: [stockwell fixed][fxsearch])

Attachments

(2 files)

temporarily disable linxu32/debug
1.04 KB, patch
adw
: review+
Details | Diff | Splinter Review
Bug 1356758 - Intermittent timeouts in browser_UsageTelemetry_urlbar.js.
59 bytes, text/x-review-board-request
adw
: review+
Details 
this test is failing very frequently, mostly linux32 debug.

here is the test:
https://dxr.mozilla.org/mozilla-central/source/browser/modules/test/browser/browser_UsageTelemetry_urlbar.js?q=path%3Abrowser_UsageTelemetry_urlbar.js&redirect_type=single

I noticed this was filed 5 days ago and 5 days ago a change from bug 1334615 was landed:
https://hg.mozilla.org/mozilla-central/rev/dd703291b11a

Most likely the changes are related to the failure.

:adw, can you take a look at this?  With 29 failures yesterday, I would be inclined to disable this test (linux32/debug) in the short term or set this as a higher priority to reduce the pain.
Flags: needinfo?(adw)
Whiteboard: [stockwell needswork]
I probably won't be able to look at this very soon.
Assignee: nobody → adw
Status: NEW → ASSIGNED
Flags: needinfo?(adw)
thanks :adw! I don't mind disabling for linxu32/debug for now and leave it on everywhere else until you have more cycles to hack on this.  Here is a patch if you want to go this route, just r+ and I can land :)
Attachment #8860097 - Flags: review+
Pushed by jmaher@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/5a76bb21c37d
Intermittent browser/modules/test/browser/browser_UsageTelemetry_urlbar.js. temporarily disable linux32/debug. r=adw
Keywords: leave-open
Whiteboard: [stockwell needswork] → [stockwell disabled]
Whiteboard: [stockwell disabled] → [stockwell disabled][fxsearch]
Assignee: adw → nobody
Status: ASSIGNED → NEW
Priority: -- → P2
Flags: needinfo?(past)
This is failing because for some reason the search suggestions are coming from the wrong search engine, or are at least being annotated that way.
The label of the suggestion is supposed to be

queryfoo browser_UsageTelemetry usageTelemetrySearchSuggestions.xml Search

which is `${suggestion} ${engineName} Search` but for some reason it is getting the name of the first engine added in the test, MozSearch:

queryfoo MozSearch Search

since the test is trying to select an entry to click based on the label, and then waiting on the load that would cause, it just sits there, then times out.
https://treeherder.mozilla.org/logviewer.html#?job_id=134477711&repo=try&lineNumber=3635

However browser_UsageTelemetry usageTelemetrySearchSuggestions.xml is the currentEngine, which is why the test fails are showing the expected engine being used for the first bare "Search with ${engineName}" entry.
https://public-artifacts.taskcluster.net/Jj2x_aP3S3KA9m9NW1hDoA/0/public/test_info//mozilla-test-fail-screenshot_4zqucx.png

Is there some way for suggestions to come from an engine other than the default?  Or could the suggestion code be caching the currentEngine and not updating it fast enough in debug builds?
(In reply to Ian Moody [:Kwan] from comment #42)
> This is failing because for some reason the search suggestions are coming
> from the wrong search engine, or are at least being annotated that way.

I suspect the suggestions are not "coming from the wrong search engine", but just not updated yet. One way to verify would be to change the "query" query at http://searchfox.org/mozilla-central/rev/a4702203522745baff21e519035b6c946b7d710d/browser/modules/test/browser/browser_UsageTelemetry_urlbar.js#380 to use a unique string instead.

If my guess is correct, the increased frequency in the failures here would be caused by bug 1391293 which landed 14 days ago.
Assignee: nobody → mak77
Status: NEW → ASSIGNED
Priority: P2 → P1
if the test doesn't wait for the item to be updated, it's likely to do the wrong thing. Unfortunately waiting for the query to be complete is not enough.
Flags: needinfo?(past)
(In reply to Florian Quèze [:florian] [:flo] from comment #44)
> I suspect the suggestions are not "coming from the wrong search engine", but
> just not updated yet.

So, this is not the problem. I changed the test to poll for 5 seconds, and the result is constantly using MozSearch.
From some first logging, looks like we properly create a SearchSuggestionController for the expected engine, and we properly set currentEngine.
Still trying to understand what's up.
I think I'm starting seeing the light at the end of the tunnel. My suspect is currently overrideSearchEngineName, a previous test indeed selects a search suggestion usageTelemetrySearchSuggestions.xml, but then selects a one-off button (MozSearch!).

That overrides the name of the engine in the "url" attribute, so later when we go through the items for a suggestion from usageTelemetrySearchSuggestions.xml we find an identical one and we decide to reuse it. But this suggestion's "url" attribute in reality has been manipulated. There seems to be a bug in the code that detects whether we can completely reuse a result.
Ah, and this is intermittent because sometimes the search in between these 2 tests may complete and remove the "reusable" entry, other times it may not.
Comment on attachment 8915699 [details]
Bug 1356758 - Intermittent timeouts in browser_UsageTelemetry_urlbar.js.

https://reviewboard.mozilla.org/r/186910/#review192048

Make sense, thanks.

::: browser/modules/test/browser/browser_UsageTelemetry_urlbar.js:35
(Diff revision 1)
>    await new Promise(r => waitForFocus(r, win));
>    // Write the search query in the urlbar.
>    win.gURLBar.focus();
>    win.gURLBar.value = inputText;
> +
> +  // This is necessary to clear oneoff buttons status.

Is this really necessary now that you're nulling the selectedButton in onSearchBegin?

::: browser/modules/test/browser/browser_UsageTelemetry_urlbar.js:60
(Diff revision 1)
>    // The entry in the suggestion list should follow the format:
>    // "<search term> <engine name> Search"
>    const expectedSuggestionName = entryName + " " + SUGGESTION_ENGINE_NAME + " Search";
> +  return BrowserTestUtils.waitForCondition(() => {
> -  for (let child of gURLBar.popup.richlistbox.children) {
> +    for (let child of gURLBar.popup.richlistbox.children) {
> +      dump(child.label + "\n")

Did you mean to leave this here?  Maybe change it to an info() if so?

::: toolkit/content/widgets/autocomplete.xml:2136
(Diff revision 1)
>  
>  
>        <method name="_adjustAcItem">
>          <body>
>            <![CDATA[
> -          this.setAttribute("url", this.getAttribute("ac-value"));
> +          let originalUrl = this.getAttribute("ac-value");

Just so I understand, it looks like these changes don't actually change any behavior, right?
Attachment #8915699 - Flags: review?(adw) → review+
Comment on attachment 8915699 [details]
Bug 1356758 - Intermittent timeouts in browser_UsageTelemetry_urlbar.js.

https://reviewboard.mozilla.org/r/186910/#review192048

> Is this really necessary now that you're nulling the selectedButton in onSearchBegin?

No, it's not strictly necessary with the fix, but it doesn't hurt and may point out people to something interesting about oneoffs behavior.

> Did you mean to leave this here?  Maybe change it to an info() if so?

ah, no I will remove that.

> Just so I understand, it looks like these changes don't actually change any behavior, right?

No, it's a micro-optimization to avoid getAttribute a just set attribute.
Pushed by mak77@bonardo.net:
https://hg.mozilla.org/integration/autoland/rev/d115a2114809
Intermittent timeouts in browser_UsageTelemetry_urlbar.js. r=adw
Status: ASSIGNED → RESOLVED
Closed: 4 years ago
status-firefox56: --- → wontfix
status-firefox57: --- → affected
status-firefox58: --- → fixed
Keywords: leave-open
Resolution: --- → FIXED
Target Milestone: --- → Firefox 58
Please request Beta approval on this when you get a chance. And thanks for fixing this massive PITA orange!
Flags: needinfo?(mak77)
(In reply to Ryan VanderMeulen [:RyanVM] from comment #62)
> Please request Beta approval on this when you get a chance. And thanks for
> fixing this massive PITA orange!

This bug is unlikely to be hit by a normal user, indeed it's more likely to cause intermittent failures than real issues. On the other side, while the changes are trivial, they are not risk free. As such I'm not sure whether it's a good uplift candidate.

On the other side, you could just uplift the changes to browser_UsageTelemetry_urlbar.js, those should be enough to resolve the intermittent. I'd suggest to do a Try run first, just in case. And you don't need an approval for test changes.
Flags: needinfo?(mak77) → needinfo?(ryanvm)
If just the changes to browser_UsageTelemetry_urlbar.js will suffice, then I can indeed take it from here :)
Flags: needinfo?(ryanvm)
Looks good, thanks!

https://hg.mozilla.org/releases/mozilla-beta/rev/98c8f403b3acf2734a8ef0794d28c1c9fcd98ef0
status-firefox57: affected → fixed
Whiteboard: [stockwell disabled][fxsearch] → [stockwell fixed][fxsearch]
Depends on: 1407060
You need to log in before you can comment on or make changes to this bug.