Closed Bug 1775793 Opened 3 years ago Closed 5 months ago

Intermittent browser/components/search/test/browser/browser_contentSearch.js | single tracking bug

Categories

(Firefox :: Search, defect, P5)

Product:
Firefox
Component:
Search
Type:
defect

Tracking

()

Status:
RESOLVED FIXED
Milestone:
131 Branch
Tracking Flags:
Tracking Status
firefox-esr128 --- fixed
firefox131 --- fixed

People

(Reporter: jmaher, Assigned: scunnane)

References

Details

(Keywords: intermittent-failure, intermittent-testcase, Whiteboard: [sng][stockwell disable-recommended])

Attachments

(2 files)

Bug 1775793 - Fix intermittent failure in browser/components/search/test/browser/browser_contentSearch.js. r?Standard8!
48 bytes, text/x-phabricator-request
Details | Review
Bug 1775793 - Fix intermittent failure in browser/components/search/test/browser/browser_contentSearch.js. r?Standard8!
48 bytes, text/x-phabricator-request
phab-bot
: approval-mozilla-esr128+
Details | Review
No description provided.

Additional information about this bug failures and frequency patterns can be found by running: ./mach test-info failure-report --bug 1775793

Severity: -- → S4
Priority: P3 → P5

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Status: NEW → RESOLVED
Closed: 3 years ago
Resolution: --- → INCOMPLETE

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=384891217&repo=autoland

Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Status: REOPENED → RESOLVED
Closed: 3 years ago → 2 years ago
Resolution: --- → INCOMPLETE

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=394897671&repo=autoland

Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Status: REOPENED → RESOLVED
Closed: 2 years ago → 2 years ago
Resolution: --- → INCOMPLETE

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=401067350&repo=autoland

Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Status: REOPENED → RESOLVED
Closed: 2 years ago → 2 years ago
Resolution: --- → INCOMPLETE

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=412430701&repo=mozilla-esr102

Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit BugBot documentation.

Status: REOPENED → RESOLVED
Closed: 2 years ago → 2 years ago
Resolution: --- → INCOMPLETE

New failure instance: https://treeherder.mozilla.org/logviewer?job_id=427769053&repo=autoland

Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---

Update

There have been 31 total failures within the last 7 days:

[task 2023-11-02T14:55:06.929Z] 14:55:06     INFO - TEST-PASS | browser/modules/test/browser/browser_ContentSearch.js | Correct search page loaded - "http://mochi.test:8888/browser/browser/components/search/test/browser/?search&test=ContentSearchTest" == "http://mochi.test:8888/browser/browser/components/search/test/browser/?search&test=ContentSearchTest" - 
[task 2023-11-02T14:55:06.930Z] 14:55:06     INFO - Leaving test bound searchInBackgroundTab
[task 2023-11-02T14:55:06.930Z] 14:55:06     INFO - Entering test bound badImage
[task 2023-11-02T14:55:06.932Z] 14:55:06     INFO - Buffered messages finished
[task 2023-11-02T14:55:06.933Z] 14:55:06     INFO - TEST-UNEXPECTED-FAIL | browser/modules/test/browser/browser_ContentSearch.js | Test timed out - 
[task 2023-11-02T14:55:07.084Z] 14:55:07     INFO - Waiting for engine to be added: contentSearchBadImage.xml
[task 2023-11-02T14:55:07.521Z] 14:55:07     INFO - TEST-PASS | browser/modules/test/browser/browser_ContentSearch.js | Sanity check: engine should be in expected state - 
[task 2023-11-02T14:55:07.522Z] 14:55:07     INFO - TEST-PASS | browser/modules/test/browser/browser_ContentSearch.js | Sanity check: icon of engine in expected state should be the placeholder: chrome://browser/skin/search-engine-placeholder.png - 
[task 2023-11-02T14:55:07.540Z] 14:55:07     INFO - TEST-PASS | browser/modules/test/browser/browser_ContentSearch.js | Checking message - 
[task 2023-11-02T14:55:07.621Z] 14:55:07     INFO - GECKO(3285) | MEMORY STAT | vsize 20983578MB | residentFast 1392MB
[task 2023-11-02T14:55:07.623Z] 14:55:07     INFO - TEST-OK | browser/modules/test/browser/browser_ContentSearch.js | took 91000ms
[task 2023-11-02T14:55:07.631Z] 14:55:07     INFO - Not taking screenshot here: see the one that was previously logged
[task 2023-11-02T14:55:07.633Z] 14:55:07     INFO - TEST-UNEXPECTED-FAIL | browser/modules/test/browser/browser_ContentSearch.js | Found a tab after previous test timed out: about:newtab -

Mark, can you assign this to someone?
Thank you.

Flags: needinfo?(standard8)
Whiteboard: [stockwell needswork:owner]

I think Stephanie is going to take a look a this.

Assignee: nobody → scunnane
Flags: needinfo?(standard8)
Summary: Intermittent browser/modules/test/browser/browser_ContentSearch.js | single tracking bug → Intermittent browser/components/search/test/browser/browser_contentSearch.js | single tracking bug
Duplicate of this bug: 1875959

Update

There have been 35 total failures within the last 7 days:

  • 10 failures on Windows 11 x64 22H2 asan WebRender opt
  • 25 failures on Linux 18.04 x64 WebRender debug

Recent log: https://treeherder.mozilla.org/logviewer?job_id=449273492&repo=autoland&lineNumber=41700

[task 2024-03-03T02:54:34.916Z] 02:54:34     INFO - TEST-PASS | browser/components/search/test/browser/browser_contentSearch.js | Correct search page loaded - "http://mochi.test:8888/browser/browser/components/search/test/browser/?search&test=ContentSearchTest" == "http://mochi.test:8888/browser/browser/components/search/test/browser/?search&test=ContentSearchTest" - 
[task 2024-03-03T02:54:34.917Z] 02:54:34     INFO - Leaving test bound searchInBackgroundTab
[task 2024-03-03T02:54:34.918Z] 02:54:34     INFO - Entering test bound badImage
[task 2024-03-03T02:54:34.919Z] 02:54:34     INFO - Buffered messages finished
[task 2024-03-03T02:54:34.920Z] 02:54:34     INFO - TEST-UNEXPECTED-FAIL | browser/components/search/test/browser/browser_contentSearch.js | Test timed out - 
[task 2024-03-03T02:54:34.921Z] 02:54:34     INFO - GECKO(18415) | Completed ShutdownLeaks collections in process 18415

Stephanie, any chance you could take a look at this?
Thank you!

Flags: needinfo?(scunnane)
Whiteboard: [stockwell unknown] → [stockwell needswork:owner]

Update

There have been 30 total failures within the last 7 days:

  • 23 failures on Linux 18.04 x64 WebRender debug
  • 1 failure on Linux 18.04 x64 WebRender tsan opt
  • 6 failures on Windows 11 x64 22H2 asan WebRender opt

Recent log: https://treeherder.mozilla.org/logviewer?job_id=452011729&repo=autoland&lineNumber=11970

Update:

There have been 30 total failures in the last 7 days.
There are:

  • 4 failures on linux1804-64-asan-qr opt
  • 18 failures on linux1804-64-qr debug
  • 7 failures on windows11-64-2009-asan-qr opt
  • 1 failure on linux1804-64-tsan-qr opt

Recent failure log.

I'm investigating this intermittent and will post a patch later this week.

Flags: needinfo?(scunnane)

I haven't been able to repro locally, but I have repro'd this on try and gotten failures on both Linux and Windows. From the logging I added, we're never getting past this line in the task that tests bad image URLs.

(In reply to Stephanie Cunnane [:scunnane] from comment #64)

we're never getting past this line in the task that tests bad image URLs.

It seems strange that addTab() can fail, though I must notice it's basically a worse reimplementation of BrowserTestUtils.withNewTab, where apparently all tabs are removed at the end of the whole test, instead of being removed at end of each sub test. Is that necessary for the test?
The other strange thing, in the screenshot I can't see the browser window, but maybe it's just a bogus (delayed) screenshot, as I can't see a place where we could end up closing the window.
One thing I'd try is to use waitForLoad:false, waitForStateStop: true options in openNewForegroundTab and see if you can still reproduce the failure. about pages sometimes have different load behaviors.
Regardless, this addTab() method could be replaced with BrowserTestUtils.withNewTab (note its options argument is passed-through to openNewForegroundTab if it's an object, so it wouldn't be a problem to pass options to it)

Whiteboard: [stockwell needswork:owner] → [stockwell needswork:owner][sng]
Attachment #9417757 - Attachment description: WIP: Bug 1775793 - Fix intermittent failure in browser/components/search/test/browser/browser_contentSearch.js. r?mak! → WIP: Bug 1775793 - Fix intermittent failure in browser/components/search/test/browser/browser_contentSearch.js

Marco, to address your comments above:

  • the addTab helper is actually necessary. Mark added it ~7 yrs ago to fix a different intermittent in this same test
  • looking at the screenshots taken by the test harness, they don't seem too helpful, as sometimes the browser under test is there, sometimes not
  • adding waitForLoad:false, waitForStateStop: true to the options obj didn't seem to affect things

Some other observations:

  • windows11-64-2009-asan-qr & linux1804-64-qr are the builds this test most often fails on, WebRender jobs specifically
  • only 2 Mac failures across the 782 times this test has failed
  • this intermittent only occurs on test-verify runs
  • if I skip the badImage task, the next and final task (GetSuggestions_AddFormHistoryEntry_RemoveFormHistoryEntry) times out instead. If I skip both badImage and GetSuggestions_AddFormHistoryEntry_RemoveFormHistoryEntry, the test passes just fine
  • adding a lot of logging, I see that we're never calling the callback to BrowserTestUtils.withNewTab. I suspect this is the crux of this intermittent.
  • I tried adding various timeouts inside tasks and adding SimpleTest.requestLongerTimeout at the end of the test file -> no dice
  • I looked for missing awaits but didn't find anything
  • Something happened between 9-4-23 & 9-10-23 - failures went from 1-2 to ~40
  • Here's my most recent try push for the current WIP patch

Marco (and Mark, since you worked on a prev intermittent in this same test), do you have any other ideas I could try?

Flags: needinfo?(standard8)
Flags: needinfo?(mak)

Does it help if you set browser.newtab.preload to false for this test?

Flags: needinfo?(mak)

(In reply to Marco Bonardo [:mak] from comment #87)

Does it help if you set browser.newtab.preload to false for this test?

Preload is already false: https://searchfox.org/mozilla-central/rev/261005fcc4d6f8b64189946958211259fb45e9e1/browser/components/search/test/browser/browser_contentSearch.js#34

I'm currently wondering if there's something up with the end of the previous test. It all looks fine, but that would potentially explain why running either of the next two fail. I've been pushing to try for something else, so I've also just tried pushing a change which closes the newly added tab after the search completes. That's a big guess though.

Flags: needinfo?(standard8)

(In reply to Mark Banner (:standard8) from comment #89)

I'm currently wondering if there's something up with the end of the previous test. It all looks fine, but that would potentially explain why running either of the next two fail. I've been pushing to try for something else, so I've also just tried pushing a change which closes the newly added tab after the search completes. That's a big guess though.

Huh, somehow that may have fixed or improved it...

Attachment #9417757 - Attachment description: WIP: Bug 1775793 - Fix intermittent failure in browser/components/search/test/browser/browser_contentSearch.js → Bug 1775793 - Fix intermittent failure in browser/components/search/test/browser/browser_contentSearch.js. r?Standard8!

Ah nice, thank you Mark. Removing the tab at the end of searchInBackgroundTab rather than in the cleanup for the entire test file does seem to have fixed the problem. I did a larger try push, which looks good.

(In reply to Stephanie Cunnane [:scunnane] from comment #91)

Ah nice, thank you Mark. Removing the tab at the end of searchInBackgroundTab rather than in the cleanup for the entire test file does seem to have fixed the problem. I did a larger try push, which looks good.

TBH I'm not sure why it does fix it. I'm suspecting some sort of weird timing issue or maybe something to do with the about:blank. In any case, I think we're safe to go with the fix.

Pushed by scunnane@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/9e75dd657ea5 Fix intermittent failure in browser/components/search/test/browser/browser_contentSearch.js. r=Standard8

https://hg.mozilla.org/mozilla-central/rev/9e75dd657ea5

Status: REOPENED → RESOLVED
Closed: 2 years ago → 5 months ago
status-firefox131: --- → fixed
Resolution: --- → FIXED
Target Milestone: --- → 131 Branch
Attachment #9423932 - Flags: approval-mozilla-esr128?

esr128 Uplift Approval Request

  • User impact if declined: None
  • Code covered by automated testing: yes
  • Fix verified in Nightly: yes
  • Needs manual QE test: no
  • Steps to reproduce for manual QE testing: n/a
  • Risk associated with taking this patch: Very low
  • Explanation of risk level: Only affects one test
  • String changes made/needed: n/a
  • Is Android affected?: no
Attachment #9423932 - Flags: approval-mozilla-esr128? → approval-mozilla-esr128+
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: