Closed Bug 1578648 Opened 5 years ago Closed 5 years ago

Debian 10 - browser/components/search/test/browser/ | multiple failures | browser_private_search_perwindowpb.js, browser_contextmenu.js, browser_webapi.js | Test timed out -

Categories

(Firefox :: Search, defect, P2)

Product:
Firefox
Component:
Search
Type:
defect

Tracking

()

Status:
RESOLVED INVALID

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

Filed by: egao [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=264871681&repo=try
Full log: https://queue.taskcluster.net/v1/task/BXSXdWJcSZafqhrKThP3Qg/runs/0/artifacts/public/logs/live_backing.log

Platform: debian 10
Suite: browser-chrome
Chunk: 4

Context:
browser_private_search_perwindowpb.js
[task 2019-09-04T02:31:50.293Z] 02:31:50 INFO - TEST-START | browser/components/search/test/browser/browser_private_search_perwindowpb.js
[task 2019-09-04T02:32:35.296Z] 02:32:35 INFO - Not taking screenshot here: see the one that was previously logged
[task 2019-09-04T02:32:35.297Z] 02:32:35 INFO - Buffered messages logged at 02:31:50
[task 2019-09-04T02:32:35.297Z] 02:32:35 INFO - Entering test bound test_setup
[task 2019-09-04T02:32:35.297Z] 02:32:35 INFO - Leaving test bound test_setup
[task 2019-09-04T02:32:35.298Z] 02:32:35 INFO - Entering test bound
[task 2019-09-04T02:32:35.299Z] 02:32:35 INFO - Waiting for engine to be added: 426329.xml
[task 2019-09-04T02:32:35.300Z] 02:32:35 INFO - Search engine added: 426329.xml
[task 2019-09-04T02:32:35.300Z] 02:32:35 INFO - Buffered messages finished
[task 2019-09-04T02:32:35.302Z] 02:32:35 INFO - TEST-UNEXPECTED-FAIL | browser/components/search/test/browser/browser_private_search_perwindowpb.js | Test timed out -
[task 2019-09-04T02:32:35.318Z] 02:32:35 INFO - Search engine removed: 426329.xml
[task 2019-09-04T02:32:35.341Z] 02:32:35 INFO - GECKO(4576) | JavaScript error: resource://testing-common/PromiseTestUtils.jsm, line 112: uncaught exception: Object
[task 2019-09-04T02:32:35.341Z] 02:32:35 INFO - Console message: [JavaScript Error: "uncaught exception: Object" {file: "resource://testing-common/PromiseTestUtils.jsm" line: 112}]
[task 2019-09-04T02:32:35.348Z] 02:32:35 INFO - GECKO(4576) | MEMORY STAT | vsize 2827MB | residentFast 320MB | heapAllocated 117MB
[task 2019-09-04T02:32:35.349Z] 02:32:35 INFO - TEST-OK | browser/components/search/test/browser/browser_private_search_perwindowpb.js | took 45056ms
[task 2019-09-04T02:32:35.386Z] 02:32:35 INFO - checking window state
[task 2019-09-04T02:32:35.387Z] 02:32:35 INFO - Not taking screenshot here: see the one that was previously logged
[task 2019-09-04T02:32:35.388Z] 02:32:35 INFO - TEST-UNEXPECTED-FAIL | browser/components/search/test/browser/browser_private_search_perwindowpb.js | Found a browser window after previous test timed out -

browser_contextmenu.js
[task 2019-09-04T02:31:47.343Z] 02:31:47 INFO - TEST-PASS | browser/components/search/test/browser/browser_contextmenu.js | Checking context menu search URL - "https://example.com/browser/browser/components/search/test/browser/?test=test+search&ie=utf-8&channel=contextsearch" == "https://example.com/browser/browser/components/search/test/browser/?test=test+search&ie=utf-8&channel=contextsearch" -
[task 2019-09-04T02:31:47.343Z] 02:31:47 INFO - Leaving test bound test_normalWindow
[task 2019-09-04T02:31:47.343Z] 02:31:47 INFO - Entering test bound test_privateWindow
[task 2019-09-04T02:31:47.343Z] 02:31:47 INFO - Console message: [JavaScript Error: "Security Error: Content at about:privatebrowsing may not load or link to moz-extension://5c809163-5470-4ecf-9620-56aaa02388ca/favicon.ico."]
[task 2019-09-04T02:31:47.343Z] 02:31:47 INFO - Console message: [JavaScript Error: "Security Error: Content at about:privatebrowsing may not load or link to moz-extension://5c809163-5470-4ecf-9620-56aaa02388ca/favicon.ico."]
[task 2019-09-04T02:31:47.344Z] 02:31:47 INFO - Console message: [JavaScript Error: "Security Error: Content at chrome://browser/skin/privatebrowsing/aboutPrivateBrowsing.css may not load or link to moz-extension://5c809163-5470-4ecf-9620-56aaa02388ca/favicon.ico."]
[task 2019-09-04T02:31:47.345Z] 02:31:47 INFO - Console message: [JavaScript Error: "Security Error: Content at about:privatebrowsing may not load or link to moz-extension://5c809163-5470-4ecf-9620-56aaa02388ca/favicon.ico."]
[task 2019-09-04T02:31:47.346Z] 02:31:47 INFO - Console message: [JavaScript Error: "Security Error: Content at about:privatebrowsing may not load or link to moz-extension://5c809163-5470-4ecf-9620-56aaa02388ca/favicon.ico."]
[task 2019-09-04T02:31:47.346Z] 02:31:47 INFO - Console message: [JavaScript Error: "Security Error: Content at chrome://browser/skin/privatebrowsing/aboutPrivateBrowsing.css may not load or link to moz-extension://5c809163-5470-4ecf-9620-56aaa02388ca/favicon.ico."]
[task 2019-09-04T02:31:47.347Z] 02:31:47 INFO - Buffered messages finished
[task 2019-09-04T02:31:47.347Z] 02:31:47 INFO - TEST-UNEXPECTED-FAIL | browser/components/search/test/browser/browser_contextmenu.js | Test timed out -
[task 2019-09-04T02:31:47.361Z] 02:31:47 INFO - GECKO(4576) | JavaScript error: resource://gre/modules/SearchService.jsm, line 714: Error: Something tried to use the search service before it's been properly intialized. Please examine the stack trace to figure out what and where to fix it:
[task 2019-09-04T02:31:47.361Z] 02:31:47 INFO - GECKO(4576) | _ensureInitialized@resource://gre/modules/SearchService.jsm:714:15
[task 2019-09-04T02:31:47.362Z] 02:31:47 INFO - GECKO(4576) | _getEngineDefault@resource://gre/modules/SearchService.jsm:2618:10
[task 2019-09-04T02:31:47.362Z] 02:31:47 INFO - GECKO(4576) | get defaultEngine@resource://gre/modules/SearchService.jsm:2761:17
[task 2019-09-04T02:31:47.362Z] 02:31:47 INFO - GECKO(4576) | _currentEngineObj@resource:///modules/ContentSearch.jsm:549:18
[task 2019-09-04T02:31:47.362Z] 02:31:47 INFO - GECKO(4576) | currentStateObj@resource:///modules/ContentSearch.jsm:369:33
[task 2019-09-04T02:31:47.362Z] 02:31:47 INFO - GECKO(4576) | _onObserve@resource:///modules/ContentSearch.jsm:507:30
[task 2019-09-04T02:31:47.362Z] 02:31:47 INFO - GECKO(4576) | _processEventQueue/this._currentEventPromise<@resource:///modules/ContentSearch.jsm:397:39
[task 2019-09-04T02:31:47.362Z] 02:31:47 INFO - GECKO(4576) | _processEventQueue@resource:///modules/ContentSearch.jsm:404:7
[task 2019-09-04T02:31:47.362Z] 02:31:47 INFO - GECKO(4576) | _processEventQueue/this._currentEventPromise<@resource:///modules/ContentSearch.jsm:402:14
[task 2019-09-04T02:31:47.362Z] 02:31:47 INFO - GECKO(4576) | async*_processEventQueue@resource:///modules/ContentSearch.jsm:404:7
[task 2019-09-04T02:31:47.362Z] 02:31:47 INFO - GECKO(4576) | observe@resource:///modules/ContentSearch.jsm:218:14
[task 2019-09-04T02:31:47.364Z] 02:31:47 INFO - GECKO(4576) | notifyAction@resource://gre/modules/SearchUtils.jsm:80:20
[task 2019-09-04T02:31:47.364Z] 02:31:47 INFO - GECKO(4576) | _setEngineDefault@resource://gre/modules/SearchService.jsm:2754:17
[task 2019-09-04T02:31:47.364Z] 02:31:47 INFO - GECKO(4576) | set defaultPrivateEngine@resource://gre/modules/SearchService.jsm:2773:10
[task 2019-09-04T02:31:47.365Z] 02:31:47 INFO - GECKO(4576) | setDefaultPrivate@resource://gre/modules/SearchService.jsm:2793:5
[task 2019-09-04T02:31:47.365Z] 02:31:47 INFO - GECKO(4576) | asyncsetup/<@chrome://mochitests/content/browser/browser/components/search/test/browser/browser_contextmenu.js:54:27
[task 2019-09-04T02:31:47.365Z] 02:31:47 INFO - GECKO(4576) | asyncnextTest@chrome://mochikit/content/browser-test.js:860:35
[task 2019-09-04T02:31:47.369Z] 02:31:47 INFO - GECKO(4576) | timeoutFn@chrome://mochikit/content/browser-test.js:1471:18
[task 2019-09-04T02:31:47.369Z] 02:31:47 INFO - GECKO(4576) | setTimeout handler*Tester_execTest@chrome://mochikit/content/browser-test.js:1418:80
[task 2019-09-04T02:31:47.369Z] 02:31:47 INFO - GECKO(4576) | nextTest/<@chrome://mochikit/content/browser-test.js:1213:14
[task 2019-09-04T02:31:47.369Z] 02:31:47 INFO - GECKO(4576) | SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<@chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:805:67
[task 2019-09-04T02:31:47.369Z] 02:31:47 INFO - GECKO(4576) | JavaScript error: resource://gre/modules/SearchService.jsm, line 714: Error: Something tried to use the search service before it's been properly intialized. Please examine the stack trace to figure out what and where to fix it:

browser_webapi.js
[task 2019-09-04T02:32:41.468Z] 02:32:41 INFO - TEST-START | browser/components/search/test/browser/browser_webapi.js
[task 2019-09-04T02:32:41.585Z] 02:32:41 INFO - GECKO(4576) | JavaScript error: resource://specialpowers/SpecialPowersParent.jsm, line 605: TypeError: this.manager.rootFrameLoader is null
[task 2019-09-04T02:32:41.585Z] 02:32:41 INFO - GECKO(4576) | JavaScript error: resource://gre/modules/Prompter.jsm, line 452: NS_ERROR_UNEXPECTED:
[task 2019-09-04T02:42:03.888Z] 02:42:03 INFO - Buffered messages logged at 02:32:41
[task 2019-09-04T02:42:03.889Z] 02:42:03 INFO - Entering test bound test_working
[task 2019-09-04T02:42:03.889Z] 02:42:03 INFO - Console message: [JavaScript Error: "The character encoding of the HTML document was not declared. The document will render with garbled text in some browser configurations if the document contains characters from outside the US-ASCII range. The character encoding of the page must be declared in the document or in the transfer protocol." {file: "http://example.com/browser/browser/components/search/test/browser/webapi.html?%5B%22http%3A%2F%2Fexample.com%2Fbrowser%2Fbrowser%2Fcomponents%2Fsearch%2Ftest%2Fbrowser%2FtestEngine.xml%22%5D" line: 0}]
[task 2019-09-04T02:42:03.890Z] 02:42:03 INFO - Console message: [JavaScript Warning: "AddSearchProvider is deprecated." {file: "http://example.com/browser/browser/components/search/test/browser/webapi.html?%5B%22http%3A%2F%2Fexample.com%2Fbrowser%2Fbrowser%2Fcomponents%2Fsearch%2Ftest%2Fbrowser%2FtestEngine.xml%22%5D" line: 10}]
[task 2019-09-04T02:42:03.891Z] 02:42:03 INFO - must wait for load
[task 2019-09-04T02:42:03.892Z] 02:42:03 INFO - must wait for focus
[task 2019-09-04T02:42:03.893Z] 02:42:03 INFO - Console message: [JavaScript Error: "TypeError: this.manager.rootFrameLoader is null" {file: "resource://specialpowers/SpecialPowersParent.jsm" line: 605}]
[task 2019-09-04T02:42:03.894Z] 02:42:03 INFO - Console message: [JavaScript Error: "NS_ERROR_UNEXPECTED: " {file: "resource://gre/modules/Prompter.jsm" line: 452}]
[task 2019-09-04T02:42:03.896Z] 02:42:03 INFO - Buffered messages logged at 02:35:53
[task 2019-09-04T02:42:03.897Z] 02:42:03 INFO - Console message: [JavaScript Error: "getScreenshot(http://mochi.test:8888/browser/browser/components/search/test/browser/test.html?test=test) failed: TypeError: NetworkError when attempting to fetch resource." {file: "resource://activity-stream/lib/Screenshots.jsm" line: 59}]
[task 2019-09-04T02:42:03.898Z] 02:42:03 INFO - getScreenshotForURL@resource://activity-stream/lib/Screenshots.jsm:59:10
[task 2019-09-04T02:42:03.905Z] 02:42:03 INFO - asyncmaybeCacheScreenshot@resource://activity-stream/lib/Screenshots.jsm:112:37
[task 2019-09-04T02:42:03.906Z] 02:42:03 INFO - _fetchScreenshot@resource://activity-stream/lib/TopSitesFeed.jsm:527:23
[task 2019-09-04T02:42:03.907Z] 02:42:03 INFO - _fetchIcon@resource://activity-stream/lib/TopSitesFeed.jsm:515:16
[task 2019-09-04T02:42:03.908Z] 02:42:03 INFO - getLinksWithDefaults@resource://activity-stream/lib/TopSitesFeed.jsm:408:16
[task 2019-09-04T02:42:03.909Z] 02:42:03 INFO - asyncrefresh@resource://activity-stream/lib/TopSitesFeed.jsm:431:30
[task 2019-09-04T02:42:03.910Z] 02:42:03 INFO - onAction@resource://activity-stream/lib/TopSitesFeed.jsm:771:14
[task 2019-09-04T02:42:03.910Z] 02:42:03 INFO - _middleware/</<@resource://activity-stream/lib/Store.jsm:63:17
[task 2019-09-04T02:42:03.911Z] 02:42:03 INFO - Store/this[method]@resource://activity-stream/lib/Store.jsm:39:54
[task 2019-09-04T02:42:03.912Z] 02:42:03 INFO - init/this.intervalId<@resource://activity-stream/lib/SystemTickFeed.jsm:27:24
[task 2019-09-04T02:42:03.913Z] 02:42:03 INFO - notify@resource://gre/modules/Timer.jsm:62:17
[task 2019-09-04T02:42:03.913Z] 02:42:03 INFO - openModalWindow@resource://gre/modules/Prompter.jsm:452:15
[task 2019-09-04T02:42:03.914Z] 02:42:03 INFO - openPrompt@resource://gre/modules/Prompter.jsm:688:20
[task 2019-09-04T02:42:03.915Z] 02:42:03 INFO - confirmEx@resource://gre/modules/Prompter.jsm:845:10
[task 2019-09-04T02:42:03.916Z] 02:42:03 INFO - confirmEx@resource://gre/modules/Prompter.jsm:90:14
[task 2019-09-04T02:42:03.917Z] 02:42:03 INFO - _confirmAddEngine@resource://gre/modules/SearchEngine.jsm:968:23
[task 2019-09-04T02:42:03.918Z] 02:42:03 INFO - _onLoad@resource://gre/modules/SearchEngine.jsm:1101:35
[task 2019-09-04T02:42:03.918Z] 02:42:03 INFO - onStopRequest@resource://gre/modules/SearchEngine.jsm:167:10
[task 2019-09-04T02:42:03.919Z] 02:42:03 INFO -
[task 2019-09-04T02:42:03.920Z] 02:42:03 INFO - Buffered messages finished
[task 2019-09-04T02:42:03.921Z] 02:42:03 ERROR - TEST-UNEXPECTED-TIMEOUT | browser/components/search/test/browser/browser_webapi.js | application timed out after 370 seconds with no output

:daleharvey - there are three tests from manifest browser/components/search/test/browser/browser.ini is failing on experimental debian 10 platform:

  • browser_private_search_perwindowpb.js
  • browser_webapi.js
  • browser_contextmenu.js

Could you redirect the ni to someone who may be able to take a look? To enable debian 10 on mozilla-central, please change the line at https://searchfox.org/mozilla-central/source/taskcluster/taskgraph/transforms/tests.py#578 to read debian10-test and push to try.

I am also able to split this into three separate bugs in case the root causes are not related.

Flags: needinfo?(dharvey)
Keywords: regression
Summary: Intermittent browser/components/search/test/browser/ | multiple failures | browser_private_search_perwindowpb.js, browser_contextmenu.js, browser_webapi.js | Test timed out - → Debian 10 - browser/components/search/test/browser/ | multiple failures | browser_private_search_perwindowpb.js, browser_contextmenu.js, browser_webapi.js | Test timed out -

Edwin, I notice there's no screenshot artifacts being uploaded... that would be highly useful here.

Has the screen resolution been checked as well? Typically that's an issue with these new setups.

Flags: needinfo?(egao)

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

Edwin, I notice there's no screenshot artifacts being uploaded... that would be highly useful here.

Has the screen resolution been checked as well? Typically that's an issue with these new setups.

The lack of screenshot is likely due to the fact the container is timing out for multiple chunks of mochitest-browser-chrome on debian 10. The logs indicate that a whole bunch of tests request longer timeouts which cause what is normally a ~20 min chunk to exceed 60 minutes.

The screen resolution has been checked (using browser-screenshots, please let me know if this is an incorrect method) and the screenshots show up the same size as the ones from Ubuntu 16.04. The screen resolution should be set to 1600x1200.

Flags: needinfo?(egao)

Sorry been trying to take a look at this but my debian vbox isnt reproducing and away on paternity leave now, Mark however commented and knows this code though so can hopefully get to the bottom

Flags: needinfo?(dharvey)

I just tried a browser/components/search only test here: https://treeherder.mozilla.org/#/jobs?repo=try&selectedJob=267991795&revision=fa43e22ab6119fe774c6c6939b534539b03a9e51

I think the context menu notices about the search service are something else. I'll try and look for it tomorrow.

Realistically, I'm not going to be able to get to this for a couple of weeks... this is going to take some investigating to sort out. Putting in the priority list though.

Priority: P5 → P2

Closing this bug as debian10 work has been halted and focus redirected to ubuntu1804, and that platform does not observe this failure.

Status: NEW → RESOLVED
Closed: 5 years ago
Resolution: --- → INVALID
You need to log in before you can comment on or make changes to this bug.