1722136 - Intermittent devtools/client/framework/test/browser_enable_devtools_popup_new_user.js | Test timed out -

Reporter

Description

•

4 years ago

treeherder

Filed by: malexandru [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=346215375&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/Vzh9dAtxTXCbwbChTQk__Q/runs/1/artifacts/public/logs/live_backing.log

[task 2021-07-24T03:10:50.523Z] 03:10:50     INFO - TEST-START | devtools/client/framework/test/browser_enable_devtools_popup_new_user.js
[task 2021-07-24T03:11:35.685Z] 03:11:35     INFO - TEST-INFO | started process screentopng
[task 2021-07-24T03:11:35.974Z] 03:11:35     INFO - TEST-INFO | screentopng: exit 0
[task 2021-07-24T03:11:35.976Z] 03:11:35     INFO - Buffered messages logged at 03:10:50
[task 2021-07-24T03:11:35.977Z] 03:11:35     INFO - Entering test bound 
[task 2021-07-24T03:11:35.980Z] 03:11:35     INFO - Adding a new tab with URL: data:text/html,<html><head><title>Test Disable F12 experiment</title></head><body><h1>Disable F12 experiment</h1></body></html>
[task 2021-07-24T03:11:35.980Z] 03:11:35     INFO - Tab added and finished loading
[task 2021-07-24T03:11:35.981Z] 03:11:35     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: "data:text/html,<html><head><title>Test Disable F12 experiment</title></head><body><h1>Disable F12 experiment</h1></body></html>" line: 0}]
[task 2021-07-24T03:11:35.983Z] 03:11:35     INFO - Unwrapping enable devtools popup
[task 2021-07-24T03:11:35.986Z] 03:11:35     INFO - TEST-PASS | devtools/client/framework/test/browser_enable_devtools_popup_new_user.js | The enable devtools popup is initially hidden - 
[task 2021-07-24T03:11:35.987Z] 03:11:35     INFO - Press F12 and wait for the enable devtools popup to be displayed
[task 2021-07-24T03:11:35.987Z] 03:11:35     INFO - Console message: [JavaScript Warning: "Key event not available on some keyboard layouts: key=“r” modifiers=“accel,alt” id=“key_toggleReaderMode”" {file: "chrome://mochikit/content/tests/SimpleTest/EventUtils.js" line: 1361}]
[task 2021-07-24T03:11:35.988Z] 03:11:35     INFO - Console message: [JavaScript Warning: "Key event not available on some keyboard layouts: key=“i” modifiers=“accel,alt,shift” id=“key_browserToolbox”" {file: "chrome://mochikit/content/tests/SimpleTest/EventUtils.js" line: 1361}]
[task 2021-07-24T03:11:35.988Z] 03:11:35     INFO - Buffered messages finished
[task 2021-07-24T03:11:35.989Z] 03:11:35     INFO - TEST-UNEXPECTED-FAIL | devtools/client/framework/test/browser_enable_devtools_popup_new_user.js | Test timed out - 
[task 2021-07-24T03:11:35.989Z] 03:11:35     INFO - Removing tab.
[task 2021-07-24T03:11:35.989Z] 03:11:35     INFO - Waiting for event: 'TabClose' on [object XULElement].
[task 2021-07-24T03:11:35.990Z] 03:11:35     INFO - Got event: 'TabClose' on [object XULElement].
[task 2021-07-24T03:11:35.991Z] 03:11:35     INFO - Tab removed and finished closing
[task 2021-07-24T03:11:35.991Z] 03:11:35     INFO - TEST-PASS | devtools/client/framework/test/browser_enable_devtools_popup_new_user.js | The main process DevToolsServer has no pending connection when the test ends - 
[task 2021-07-24T03:11:35.991Z] 03:11:35     INFO - GECKO(7621) | MEMORY STAT vsizeMaxContiguous not supported in this build configuration.
[task 2021-07-24T03:11:35.992Z] 03:11:35     INFO - GECKO(7621) | MEMORY STAT | vsize 3159MB | residentFast 410MB | heapAllocated 185MB
[task 2021-07-24T03:11:35.992Z] 03:11:35     INFO - TEST-OK | devtools/client/framework/test/browser_enable_devtools_popup_new_user.js | took 45236ms
[task 2021-07-24T03:11:35.993Z] 03:11:35     INFO - checking window state
[task 2021-07-24T03:11:35.993Z] 03:11:35     INFO - GECKO(7621) | Completed ShutdownLeaks collections in process 7621
[task 2021-07-24T03:11:35.994Z] 03:11:35     INFO - TEST-START | Shutdown
[task 2021-07-24T03:11:35.995Z] 03:11:35     INFO - Browser Chrome Test Summary
[task 2021-07-24T03:11:35.995Z] 03:11:35     INFO - Passed:  2
[task 2021-07-24T03:11:35.995Z] 03:11:35     INFO - Failed:  1
[task 2021-07-24T03:11:35.995Z] 03:11:35     INFO - Todo:    0
[task 2021-07-24T03:11:35.995Z] 03:11:35     INFO - Mode:    e10s
[task 2021-07-24T03:11:35.996Z] 03:11:35     INFO - *** End BrowserChrome Test Results ***
[task 2021-07-24T03:11:35.996Z] 03:11:35     INFO - GECKO(7621) | Exiting due to channel error.
[task 2021-07-24T03:11:35.997Z] 03:11:35     INFO - GECKO(7621) | Exiting due to channel error.
[task 2021-07-24T03:11:35.997Z] 03:11:35     INFO - GECKO(7621) | Exiting due to channel error.
[task 2021-07-24T03:11:35.998Z] 03:11:35     INFO - GECKO(7621) | Exiting due to channel error.
[task 2021-07-24T03:11:35.998Z] 03:11:35     INFO - GECKO(7621) | Exiting due to channel error.
[task 2021-07-24T03:11:35.999Z] 03:11:35     INFO - TEST-INFO | Main app process: exit 0
[task 2021-07-24T03:11:35.999Z] 03:11:35     INFO - runtests.py | Application ran for: 0:00:51.717468
[task 2021-07-24T03:11:36.000Z] 03:11:36     INFO - zombiecheck | Reading PID log: /tmp/tmpi50x5y63pidlog
[task 2021-07-24T03:11:36.000Z] 03:11:36     INFO - ==> process 7621 launched child process 7641
[task 2021-07-24T03:11:36.001Z] 03:11:36     INFO - ==> process 7621 launched child process 7697
[task 2021-07-24T03:11:36.001Z] 03:11:36     INFO - ==> process 7621 launched child process 7720
[task 2021-07-24T03:11:36.002Z] 03:11:36     INFO - ==> process 7621 launched child process 7789
[task 2021-07-24T03:11:36.003Z] 03:11:36     INFO - ==> process 7621 launched child process 7820
[task 2021-07-24T03:11:36.003Z] 03:11:36     INFO - ==> process 7621 launched child process 7823
[task 2021-07-24T03:11:36.005Z] 03:11:36     INFO - zombiecheck | Checking for orphan process with PID: 7720
[task 2021-07-24T03:11:36.005Z] 03:11:36     INFO - zombiecheck | Checking for orphan process with PID: 7820
[task 2021-07-24T03:11:36.005Z] 03:11:36     INFO - zombiecheck | Checking for orphan process with PID: 7789
[task 2021-07-24T03:11:36.005Z] 03:11:36     INFO - zombiecheck | Checking for orphan process with PID: 7823
[task 2021-07-24T03:11:36.005Z] 03:11:36     INFO - zombiecheck | Checking for orphan process with PID: 7697
[task 2021-07-24T03:11:36.005Z] 03:11:36     INFO - zombiecheck | Checking for orphan process with PID: 7641
[task 2021-07-24T03:11:36.005Z] 03:11:36     INFO - Stopping web server
[task 2021-07-24T03:11:36.005Z] 03:11:36     INFO - Server shut down.
[task 2021-07-24T03:11:36.006Z] 03:11:36     INFO - Web server killed.
[task 2021-07-24T03:11:36.007Z] 03:11:36     INFO - Stopping web socket server
[task 2021-07-24T03:11:36.024Z] 03:11:36     INFO - Stopping ssltunnel
[task 2021-07-24T03:11:36.045Z] 03:11:36  WARNING - leakcheck | refcount logging is off, so leaks can't be detected!
[task 2021-07-24T03:11:36.045Z] 03:11:36     INFO - runtests.py | Running tests: end.
[task 2021-07-24T03:11:36.064Z] 03:11:36     INFO - Buffered messages finished
[task 2021-07-24T03:11:36.065Z] 03:11:36     INFO - Running manifest: devtools/client/framework/test/browser-telemetry-startup.ini
[task 2021-07-24T03:11:36.088Z] 03:11:36     INFO -  Setting pipeline to PAUSED ...
[task 2021-07-24T03:11:36.088Z] 03:11:36     INFO -  Pipeline is PREROLLING ...
[task 2021-07-24T03:11:36.088Z] 03:11:36     INFO -  Pipeline is PREROLLED ...
[task 2021-07-24T03:11:36.088Z] 03:11:36     INFO -  Setting pipeline to PLAYING ...
[task 2021-07-24T03:11:36.088Z] 03:11:36     INFO -  New clock: GstSystemClock
[task 2021-07-24T03:11:36.121Z] 03:11:36     INFO -  Got EOS from element "pipeline0".
[task 2021-07-24T03:11:36.122Z] 03:11:36     INFO -  Execution ended after 0:00:00.033403603
[task 2021-07-24T03:11:36.123Z] 03:11:36     INFO -  Setting pipeline to PAUSED ...
[task 2021-07-24T03:11:36.124Z] 03:11:36     INFO -  Setting pipeline to READY ...
[task 2021-07-24T03:11:36.125Z] 03:11:36     INFO -  (gst-launch-1.0:7889): GStreamer-CRITICAL **: 03:11:36.120: gst_object_unref: assertion '((GObject *) object)->ref_count > 0' failed
[task 2021-07-24T03:11:36.127Z] 03:11:36     INFO -  Setting pipeline to NULL ...
[task 2021-07-24T03:11:36.128Z] 03:11:36     INFO -  Freeing pipeline ...
[task 2021-07-24T03:11:36.324Z] 03:11:36     INFO - PID 7899 | pk12util: PKCS12 IMPORT SUCCESSFUL
[task 2021-07-24T03:11:36.435Z] 03:11:36     INFO - MochitestServer : launching ['/builds/worker/workspace/build/tests/bin/xpcshell', '-g', '/builds/worker/workspace/build/application/firefox', '-f', '/builds/worker/workspace/build/tests/bin/components/httpd.js', '-e', "const _PROFILE_PATH = '/tmp/tmpuw2gxqdl.mozrunner'; const _SERVER_PORT = '8888'; const _SERVER_ADDR = '127.0.0.1'; const _TEST_PREFIX = undefined; const _DISPLAY_RESULTS = false;", '-f', '/builds/worker/workspace/build/tests/mochitest/server.js']
[task 2021-07-24T03:11:36.435Z] 03:11:36     INFO - runtests.py | Server pid: 7908
[task 2021-07-24T03:11:36.456Z] 03:11:36     INFO - runtests.py | Websocket server pid: 7911
[task 2021-07-24T03:11:36.483Z] 03:11:36     INFO - runtests.py | SSL tunnel pid: 7916
[task 2021-07-24T03:11:36.536Z] 03:11:36     INFO - runtests.py | Running with scheme: http
[task 2021-07-24T03:11:36.536Z] 03:11:36     INFO - runtests.py | Running with e10s: True
[task 2021-07-24T03:11:36.536Z] 03:11:36     INFO - runtests.py | Running with fission: True
[task 2021-07-24T03:11:36.536Z] 03:11:36     INFO - runtests.py | Running with cross-origin iframes: False
[task 2021-07-24T03:11:36.536Z] 03:11:36     INFO - runtests.py | Running with serviceworker_e10s: True
[task 2021-07-24T03:11:36.536Z] 03:11:36     INFO - runtests.py | Running with socketprocess_e10s: False
[task 2021-07-24T03:11:36.536Z] 03:11:36     INFO - runtests.py | Running tests: start.
[task 2021-07-24T03:11:36.536Z] 03:11:36     INFO - 
[task 2021-07-24T03:11:36.560Z] 03:11:36     INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox -marionette -foreground -profile /tmp/tmpuw2gxqdl.mozrunner
[task 2021-07-24T03:11:36.572Z] 03:11:36     INFO - runtests.py | Application pid: 7933
[task 2021-07-24T03:11:36.572Z] 03:11:36     INFO - TEST-INFO | started process GECKO(7933)
[task 2021-07-24T03:11:37.162Z] 03:11:37     INFO - GECKO(7933) | 1627096297161	Marionette	INFO	Marionette enabled
[task 2021-07-24T03:11:37.202Z] 03:11:37     INFO - GECKO(7933) | 1627096297200	RemoteAgent	DEBUG	WebDriver BiDi enabled
[task 2021-07-24T03:11:37.206Z] 03:11:37     INFO - GECKO(7933) | 1627096297201	RemoteAgent	DEBUG	CDP enabled
[task 2021-07-24T03:11:37.218Z] 03:11:37     INFO - GECKO(7933) | 1627096297217	Marionette	TRACE	Received observer notification toplevel-window-ready
[task 2021-07-24T03:11:40.757Z] 03:11:40     INFO - GECKO(7933) | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at /tmp/tmpuw2gxqdl.mozrunner/search.json.mozlz4", (void 0)))
[task 2021-07-24T03:11:41.329Z] 03:11:41     INFO - GECKO(7933) | 1627096301327	Marionette	TRACE	Received observer notification marionette-startup-requested
[task 2021-07-24T03:11:41.329Z] 03:11:41     INFO - GECKO(7933) | 1627096301327	Marionette	TRACE	Waiting until startup recorder finished recording startup scripts...
[task 2021-07-24T03:11:41.341Z] 03:11:41     INFO - GECKO(7933) | 1627096301340	Marionette	TRACE	All scripts recorded.
[task 2021-07-24T03:11:41.343Z] 03:11:41     INFO - GECKO(7933) | 1627096301342	Marionette	INFO	Listening on port 2828
[task 2021-07-24T03:11:41.344Z] 03:11:41     INFO - GECKO(7933) | 1627096301342	Marionette	DEBUG	Marionette is listening
[task 2021-07-24T03:11:41.399Z] 03:11:41     INFO - GECKO(7933) | 1627096301398	Marionette	DEBUG	Accepted connection 0 from 127.0.0.1:56412
[task 2021-07-24T03:11:41.404Z] 03:11:41     INFO - GECKO(7933) | 1627096301403	Marionette	DEBUG	Closed connection 0
[task 2021-07-24T03:11:41.405Z] 03:11:41     INFO - GECKO(7933) | 1627096301405	Marionette	DEBUG	Accepted connection 1 from 127.0.0.1:56414
[task 2021-07-24T03:11:41.412Z] 03:11:41     INFO - GECKO(7933) | 1627096301412	Marionette	DEBUG	1 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2021-07-24T03:11:41.427Z] 03:11:41     INFO - GECKO(7933) | 1627096301426	Marionette	DEBUG	1 <- [1,1,null,{"sessionId":"de916b52-0e39-4fd1-8617-1e2df253dc2a","capabilities":{"browserName":"firefox","browserVersion":"92.0a ... l.mozrunner","moz:shutdownTimeout":60000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true,"proxy":{}}}]
[task 2021-07-24T03:11:41.456Z] 03:11:41     INFO - GECKO(7933) | 1627096301455	Marionette	DEBUG	1 -> [0,2,"Addon:Install",{"path":"/tmp/tmpezv06wab.zip","temporary":false}]
[task 2021-07-24T03:11:41.486Z] 03:11:41     INFO - GECKO(7933) | 1627096301484	Marionette	TRACE	[39] MarionetteEvents actor created for window id 22
[task 2021-07-24T03:11:41.551Z] 03:11:41     INFO - GECKO(7933) | 1627096301550	Marionette	DEBUG	1 <- [1,2,null,{"value":"special-powers@mozilla.org"}]
[task 2021-07-24T03:11:41.601Z] 03:11:41     INFO - GECKO(7933) | 1627096301599	Marionette	DEBUG	1 -> [0,3,"Addon:Install",{"path":"/tmp/tmp7wjuhy6f.zip","temporary":false}]
[task 2021-07-24T03:11:41.629Z] 03:11:41     INFO - GECKO(7933) | 1627096301628	Marionette	DEBUG	1 <- [1,3,null,{"value":"mochikit@mozilla.org"}]
[task 2021-07-24T03:11:41.631Z] 03:11:41     INFO - GECKO(7933) | 1627096301630	Marionette	DEBUG	1 -> [0,4,"Marionette:GetContext",{}]
[task 2021-07-24T03:11:41.633Z] 03:11:41     INFO - GECKO(7933) | 1627096301632	Marionette	DEBUG	1 <- [1,4,null,{"value":"content"}]
[task 2021-07-24T03:11:41.635Z] 03:11:41     INFO - GECKO(7933) | 1627096301634	Marionette	DEBUG	1 -> [0,5,"Marionette:SetContext",{"value":"chrome"}]
[task 2021-07-24T03:11:41.636Z] 03:11:41     INFO - GECKO(7933) | 1627096301635	Marionette	DEBUG	1 <- [1,5,null,{"value":null}]
[task 2021-07-24T03:11:41.638Z] 03:11:41     INFO - GECKO(7933) | 1627096301637	Marionette	DEBUG	1 -> [0,6,"WebDriver:ExecuteScript",{"script":"/* This Source Code Form is subject to the terms of the Mozilla Public\n * License, ... hrome","testUrl":"about:blank"}],"newSandbox":true,"sandbox":"default","line":1934,"filename":"tests/mochitest/runtests.py"}]
[task 2021-07-24T03:11:41.643Z] 03:11:41     INFO - GECKO(7933) | 1627096301642	Marionette	TRACE	[7] MarionetteCommands actor created for window id 2
[task 2021-07-24T03:11:41.648Z] 03:11:41     INFO - GECKO(7933) | 1627096301647	Marionette	TRACE	[19] MarionetteEvents actor created for window id 2147483649
[task 2021-07-24T03:11:41.693Z] 03:11:41     INFO - GECKO(7933) | 1627096301692	Marionette	TRACE	Received observer notification toplevel-window-ready
[task 2021-07-24T03:11:41.703Z] 03:11:41     INFO - GECKO(7933) | 1627096301702	Marionette	DEBUG	1 <- [1,6,null,{"value":null}]
[task 2021-07-24T03:11:41.723Z] 03:11:41     INFO - GECKO(7933) | 1627096301721	Marionette	TRACE	Remoteness change detected. Set new top-level browsing context to 46
[task 2021-07-24T03:11:41.732Z] 03:11:41     INFO - GECKO(7933) | 1627096301731	Marionette	DEBUG	1 -> [0,7,"Marionette:SetContext",{"value":"content"}]
[task 2021-07-24T03:11:41.732Z] 03:11:41     INFO - GECKO(7933) | 1627096301731	Marionette	DEBUG	1 <- [1,7,null,{"value":null}]
[task 2021-07-24T03:11:41.737Z] 03:11:41     INFO - GECKO(7933) | 1627096301736	Marionette	TRACE	[46] MarionetteEvents actor created for window id 26
[task 2021-07-24T03:11:41.770Z] 03:11:41     INFO - GECKO(7933) | 1627096301769	Marionette	TRACE	[46] MarionetteEvents actor created for window id 8589934593
[task 2021-07-24T03:11:41.776Z] 03:11:41     INFO - GECKO(7933) | 1627096301775	Marionette	DEBUG	1 -> [0,8,"WebDriver:DeleteSession",{}]
[task 2021-07-24T03:11:41.778Z] 03:11:41     INFO - GECKO(7933) | 1627096301776	Marionette	DEBUG	1 <- [1,8,null,{"value":null}]
[task 2021-07-24T03:11:41.784Z] 03:11:41     INFO - GECKO(7933) | JavaScript error: , line 0: NotFoundError: No such JSWindowActor 'MarionetteEvents'
[task 2021-07-24T03:11:41.819Z] 03:11:41     INFO - GECKO(7933) | JavaScript error: , line 0: NotFoundError: No such JSWindowActor 'MarionetteEvents'
[task 2021-07-24T03:11:41.822Z] 03:11:41     INFO - runtests.py | Waiting for browser...
[task 2021-07-24T03:11:41.825Z] 03:11:41     INFO - GECKO(7933) | JavaScript error: , line 0: NotFoundError: No such JSWindowActor 'MarionetteEvents'
[task 2021-07-24T03:11:41.842Z] 03:11:41     INFO - GECKO(7933) | 1627096301841	Marionette	DEBUG	Closed connection 1
[task 2021-07-24T03:11:42.644Z] 03:11:42     INFO - *** Start BrowserChrome Test Results ***
[task 2021-07-24T03:11:42.723Z] 03:11:42     INFO - checking window state
[task 2021-07-24T03:11:42.793Z] 03:11:42     INFO - TEST-START | devtools/client/framework/test/browser_toolbox_telemetry_open_event.js

Comment hidden (Intermittent Failures Robot)

Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)

Comment 3

•

4 years ago

The Linux 18.04 x64 WebRender Shippable dt3 devtools chunk fails permanently with different devtools popup tests - what's the path to get these passing again?

Flags: needinfo?(odvarko)

Jan Honza Odvarko [:Honza] (always need-info? me)

Comment 4

•

4 years ago

Julian, looks the test is infinitely waiting for the popup (on Linux):
https://searchfox.org/mozilla-central/rev/4f05a46731c1f7f111ec7a41ce38a34594aa0d37/devtools/client/framework/test/helper_enable_devtools_popup.js#63

Interestingly when I run the test locally on Win10 with --repeat 2 I am seeing:
0:16.19 FAIL The devtools toolbox should not open

Could you please check this?

Honza

Flags: needinfo?(odvarko) → needinfo?(jdescottes)

Julian Descottes [:jdescottes]

Assignee

Comment 5

•

4 years ago

•

Edited

This test is not designed to be used with --repeat. It needs to be used in isolation only, that's why it has its own test suite: https://searchfox.org/mozilla-central/source/devtools/client/framework/test/browser-enable-popup-new-user.ini#17

Edit: So if anyone wants to try and investigate locally, use for instance devtools/client/shared/test/browser_html_tooltip_resize.js rather than this test

Flags: needinfo?(jdescottes)

Julian Descottes [:jdescottes]

Assignee

Comment 6

•

4 years ago

•

Edited

The question here is probably not about this particular test, but rather about a whole class of tooltip/popup related intermittents:

browser_enable_devtools_popup_new_user.js
browser_html_tooltip_screen_edge.js
browser_autocomplete_popup_consecutive-show.js
...

They all seem to timeout while waiting for a popup to open. Some of them rely on a devtools wrapper (HTMLTooltip), but others such as the one used in browser_enable_devtools_popup_new_user.js are just regular popups without any devtools custom code.
Also there has been no DevTools change in this area recently.

To me it sounds like a platform or harness change suddenly made a whole class of DevTools tests racy.

Aryx: is there a regression-window to help us identify which change could be responsible here?

Flags: needinfo?(aryx.bugmail)

Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)

Comment 7

•

4 years ago

Based on this query:

day	autoland failure lines for devtools tasks and which mention 'popup'
2021-07-07	7
2021-07-08	2
2021-07-10	3
2021-07-14	6
2021-07-16	6
2021-07-19	6
2021-07-20	7
2021-07-21	6
2021-07-22	11
2021-07-23	53
2021-07-24	6
2021-07-25	4
2021-07-26	1
2021-07-27	13
2021-07-28	12
2021-07-29	13
2021-07-30	30
2021-07-31	11
2021-08-01	25
2021-08-02	17
2021-08-03	9

Failures have likely been started by the move of Linux devtools test to WebRender in bug 1717627.

Flags: needinfo?(aryx.bugmail)

Julian Descottes [:jdescottes]

Assignee

Comment 8

•

4 years ago

Thanks for the info!

So Linux + webrender makes DevTools popup-related tests very intermittent.
It seems to repro on try easily https://treeherder.mozilla.org/jobs?repo=try&revision=51eb6c9afeaa94ab6c2200bfa12a4c97f8ae78ba&selectedTaskRun=VAgTpIPURl-lv1dBVNCZtQ.0

I will add some delays in the test to try to understand where we might be hitting a race here.

Julian Descottes [:jdescottes]

Assignee

Comment 9

•

4 years ago

The tests are not as intermittent as I hoped, and I seem to get a failure rate of ~10% for a suite containing a single test. I suppose that for a full suite containing several popup-related tests, we end up with a near 100% failure rate.

In any case, it seems that whatever race we are hitting goes away if we simply wait before starting the test, before doing anything in the test.
I see that almost all the popup tests which fail in dt3 are relying on the createHost test helper. https://searchfox.org/mozilla-central/rev/064a1e6a2a6f6aa30be8bf4edea2f8408f779d4d/devtools/client/shared/test/head.js#112

I don't know if there is a relevant event we could wait for to know that the document is ready to be modified & used for popups, but I will try to wait a bit in the helper to see if it helps. If it does we might just go ahead with this to reduce the amount of intermittents

Julian Descottes [:jdescottes]

Assignee

Comment 10

•

4 years ago

Waiting for the host document readyState to be "complete" and waiting for an additional tick doesn't seem to help:
https://treeherder.mozilla.org/jobs?repo=try&revision=4d9c3765c051b9433b839a1a7748b65d4fb6d26c

However waiting plainly for 100ms makes dt3 almost green:
https://treeherder.mozilla.org/jobs?repo=try&revision=4e20f1827f472eee5ab257d6d5132bc6c2bd0b9e

Without any error, it's difficult to know what those tests might be missing. There is one test however which fails with a slightly more interesting error: browser_html_tooltip_hover.js, tracked in https://bugzilla.mozilla.org/show_bug.cgi?id=1676048 . This is also a tooltip test, but which starts by simulating a mouse event.

Here we get an error when trying to use nsIDOMWindowUtils.sendMouseEvent: "Component returned failure code: 0x80004005 (NS_ERROR_FAILURE)".

It might be from the following: https://searchfox.org/mozilla-central/rev/064a1e6a2a6f6aa30be8bf4edea2f8408f779d4d/dom/base/nsContentUtils.cpp#8175 . So it might be about presShell being ready or not? I'll try to dig more in this direction. Worst case scenario we can just go with the small delay in createHosts to silence the frequent intermittents.

Julian Descottes [:jdescottes]

Assignee

Comment 11

•

4 years ago

Attached file Bug 1722136 - [devtools] Wait for a valid presShell in devtools/client/shared tests — Details

Phabricator Automation

Updated

•

4 years ago

Assignee: nobody → jdescottes

Status: NEW → ASSIGNED

Pulsebot

Comment 12

•

4 years ago

Pushed by jdescottes@mozilla.com: https://hg.mozilla.org/integration/autoland/rev/178e3b55cdae [devtools] Wait for a valid presShell in devtools/client/shared tests r=nchevobbe

Julian Descottes [:jdescottes]

Assignee

Updated

•

4 years ago

Updated

•

4 years ago

Regressions: 1724207

Dorel Luca [:dluca]

Comment 13

•

4 years ago

bugherder

https://hg.mozilla.org/mozilla-central/rev/178e3b55cdae

Status: ASSIGNED → RESOLVED

Closed: 4 years ago

status-firefox92: --- → fixed

Resolution: --- → FIXED

Target Milestone: --- → 92 Branch

Julian Descottes [:jdescottes]

Assignee

Comment 14

•

4 years ago

Checked a few tooltip intermittents this morning, they seem to be quieter since the patch landed, will keep monitoring.

Comment hidden (Intermittent Failures Robot)

Julian Descottes [:jdescottes]

Assignee

Updated

•

4 years ago

Updated

•

4 years ago

No longer regressions: 1724207

Comment hidden (Intermittent Failures Robot)

Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)

Updated

•

4 years ago

Whiteboard: [checkin-needed-esr91]

Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)

Comment 22

•

4 years ago

bugherder uplift

https://hg.mozilla.org/releases/mozilla-esr91/rev/ba100ac145a0

status-firefox-esr91: --- → fixed

Whiteboard: [checkin-needed-esr91]

Julian Descottes [:jdescottes]

Assignee

Updated

•

4 years ago