Closed Bug 1773397 Opened 2 years ago Closed 2 years ago

Intermittent [tier 2] TV-fis TEST-UNEXPECTED-TIMEOUT | devtools/client/inspector/rules/test/browser_rules_update_mask_image_cors.js | application timed out after 370 seconds with no output

Categories

(DevTools :: Inspector: Rules, defect, P5)

Product:
DevTools
Component:
Inspector: Rules
Type:
defect

Tracking

(firefox-esr91 unaffected, firefox-esr102 unaffected, firefox101 unaffected, firefox102 unaffected, firefox103 wontfix, firefox104 wontfix)

Status:
RESOLVED INCOMPLETE
Tracking Flags:
Tracking Status
firefox-esr91 --- unaffected
firefox-esr102 --- unaffected
firefox101 --- unaffected
firefox102 --- unaffected
firefox103 --- wontfix
firefox104 --- wontfix

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Regression)

Details

(Keywords: intermittent-failure, regression)

Attachments

(1 file)

image.png
397.62 KB, image/png
Details

Filed by: mlaza [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=380691750&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/ZNTMKHcDRHe_KXuSfqvigQ/runs/0/artifacts/public/logs/live_backing.log
Reftest URL: https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/ZNTMKHcDRHe_KXuSfqvigQ/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1

[task 2022-06-08T22:04:05.851Z] 22:04:05     INFO - TEST-START | devtools/client/inspector/rules/test/browser_rules_update_mask_image_cors.js
[task 2022-06-08T22:04:06.356Z] 22:04:06     INFO - GECKO(2257) | 2022-06-08 22:04:06.355 firefox[2257:32468] Persistent UI failed to open file file:///Users/cltbld/Library/Saved%20Application%20State/org.mozilla.nightly.savedState/window_1.data: No such file or directory (2)
[task 2022-06-08T22:04:19.921Z] 22:04:19     INFO - GECKO(2257) | console.log: "[DISPATCH] action type:" "CLEAR_FLEXBOX"
[task 2022-06-08T22:04:19.950Z] 22:04:19     INFO - GECKO(2257) | console.log: "[DISPATCH] action type:" "UPDATE_GRIDS"
[task 2022-06-08T22:04:20.301Z] 22:04:20     INFO - GECKO(2257) | console.log: "[DISPATCH] action type:" "UPDATE_OFFSET_PARENT"
[task 2022-06-08T22:04:20.303Z] 22:04:20     INFO - GECKO(2257) | console.log: "[DISPATCH] action type:" "UPDATE_LAYOUT"
[task 2022-06-08T22:04:24.055Z] 22:04:24     INFO - GECKO(2257) | console.log: "[DISPATCH] action type:" "CLEAR_FLEXBOX"
[task 2022-06-08T22:04:24.308Z] 22:04:24     INFO - GECKO(2257) | console.log: "[DISPATCH] action type:" "UPDATE_OFFSET_PARENT"
[task 2022-06-08T22:04:24.312Z] 22:04:24     INFO - GECKO(2257) | console.log: "[DISPATCH] action type:" "UPDATE_LAYOUT"
[task 2022-06-08T22:10:34.437Z] 22:10:34     INFO - Buffered messages logged at 22:04:05
[task 2022-06-08T22:10:34.437Z] 22:10:34     INFO - Entering test bound 
[task 2022-06-08T22:10:34.438Z] 22:10:34     INFO - Adding a new tab with URL: https://example.org/document-builder.sjs?html=<div style='mask-image: url("https://example.com/browser/devtools/client/inspector/rules/test/square_svg.sjs"); width:10px; height: 10px; background: red;'>
[task 2022-06-08T22:10:34.438Z] 22:10:34     INFO - Buffered messages logged at 22:04:08
[task 2022-06-08T22:10:34.439Z] 22:10:34     INFO - Console message: [JavaScript Warning: "This page is in Quirks Mode. Page layout may be impacted. For Standards Mode use “<!DOCTYPE html>”." {file: "https://example.org/document-builder.sjs?html=%3Cdiv%20style=%27mask-image:%20url(%22https://example.com/browser/devtools/client/inspector/rules/test/square_svg.sjs%22);%20width:10px;%20height:%2010px;%20background:%20red;%27%3E" line: 0}]
[task 2022-06-08T22:10:34.439Z] 22:10:34     INFO - Buffered messages logged at 22:04:10
[task 2022-06-08T22:10:34.439Z] 22:10:34     INFO - Tab added and finished loading
[task 2022-06-08T22:10:34.440Z] 22:10:34     INFO - Opening the inspector
[task 2022-06-08T22:10:34.440Z] 22:10:34     INFO - Opening the toolbox
[task 2022-06-08T22:10:34.441Z] 22:10:34     INFO - Console message: [JavaScript Error: "Unknown Collection "main/partitioning-exempt-urls"" {file: "resource://services-settings/RemoteSettingsClient.jsm" line: 147}]
[task 2022-06-08T22:10:34.441Z] 22:10:34     INFO - UnknownCollectionError@resource://services-settings/RemoteSettingsClient.jsm:147:5
[task 2022-06-08T22:10:34.441Z] 22:10:34     INFO - sync@resource://services-settings/RemoteSettingsClient.jsm:511:13
[task 2022-06-08T22:10:34.441Z] 22:10:34     INFO - async*get/this._importingPromise<@resource://services-settings/RemoteSettingsClient.jsm:369:26
[task 2022-06-08T22:10:34.441Z] 22:10:34     INFO - async*get@resource://services-settings/RemoteSettingsClient.jsm:375:13
[task 2022-06-08T22:10:34.441Z] 22:10:34     INFO - async*lazyInit@resource://gre/modules/PartitioningExceptionListService.jsm:113:26
[task 2022-06-08T22:10:34.441Z] 22:10:34     INFO - registerAndRunExceptionListObserver@resource://gre/modules/PartitioningExceptionListService.jsm:137:10
[task 2022-06-08T22:10:34.441Z] 22:10:34     INFO - 
[task 2022-06-08T22:10:34.441Z] 22:10:34     INFO - Buffered messages logged at 22:04:13
[task 2022-06-08T22:10:34.442Z] 22:10:34     INFO - Console message: [JavaScript Error: "Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”)." {file: "chrome" line: 511}]
[task 2022-06-08T22:10:34.442Z] 22:10:34     INFO - Console message: [JavaScript Error: "Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”)." {file: "chrome" line: 511}]
[task 2022-06-08T22:10:34.442Z] 22:10:34     INFO - Console message: [JavaScript Error: "Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”)." {file: "chrome" line: 62}]
[task 2022-06-08T22:10:34.443Z] 22:10:34     INFO - Buffered messages logged at 22:04:18
[task 2022-06-08T22:10:34.443Z] 22:10:34     INFO - Console message: [JavaScript Error: "Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”)." {file: "chrome" line: 511}]
[task 2022-06-08T22:10:34.443Z] 22:10:34     INFO - Console message: [JavaScript Error: "Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”)." {file: "chrome" line: 511}]
[task 2022-06-08T22:10:34.444Z] 22:10:34     INFO - Console message: [JavaScript Error: "Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”)." {file: "chrome" line: 62}]
[task 2022-06-08T22:10:34.444Z] 22:10:34     INFO - Console message: [JavaScript Error: "Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”)." {file: "chrome" line: 511}]
[task 2022-06-08T22:10:34.444Z] 22:10:34     INFO - Console message: [JavaScript Error: "Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”)." {file: "chrome" line: 511}]
[task 2022-06-08T22:10:34.445Z] 22:10:34     INFO - Console message: [JavaScript Error: "Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”)." {file: "chrome" line: 62}]
[task 2022-06-08T22:10:34.445Z] 22:10:34     INFO - Console message: [JavaScript Error: "Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”)." {file: "chrome" line: 511}]
[task 2022-06-08T22:10:34.445Z] 22:10:34     INFO - Console message: [JavaScript Error: "Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”)." {file: "chrome" line: 511}]
[task 2022-06-08T22:10:34.446Z] 22:10:34     INFO - Console message: [JavaScript Error: "Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”)." {file: "chrome" line: 62}]
[task 2022-06-08T22:10:34.446Z] 22:10:34     INFO - Buffered messages logged at 22:04:19
[task 2022-06-08T22:10:34.446Z] 22:10:34     INFO - Toolbox opened and focused
[task 2022-06-08T22:10:34.447Z] 22:10:34     INFO - Open the splitconsole to check for CORS messages
[task 2022-06-08T22:10:34.447Z] 22:10:34     INFO - Buffered messages logged at 22:04:22
[task 2022-06-08T22:10:34.447Z] 22:10:34     INFO - Console message: [JavaScript Error: "Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”)." {file: "chrome" line: 511}]
[task 2022-06-08T22:10:34.448Z] 22:10:34     INFO - Console message: [JavaScript Error: "Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”)." {file: "chrome" line: 511}]
[task 2022-06-08T22:10:34.448Z] 22:10:34     INFO - Console message: [JavaScript Error: "Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”)." {file: "chrome" line: 62}]
[task 2022-06-08T22:10:34.448Z] 22:10:34     INFO - Buffered messages logged at 22:04:23
[task 2022-06-08T22:10:34.449Z] 22:10:34     INFO - Selecting the node for 'div'[task 2022-06-08T22:10:34.449Z] 22:10:34     INFO - Console message: [JavaScript Warning: "Use of nsIFile in content process is deprecated." {file: "resource://gre/modules/NetUtil.jsm" line: 253}]
[task 2022-06-08T22:10:34.449Z] 22:10:34     INFO - Take a node screenshot, mask is applied, should be red
[task 2022-06-08T22:10:34.450Z] 22:10:34     INFO - Call screenshotNode() and wait until the screenshot is found in the Downloads
[task 2022-06-08T22:10:34.450Z] 22:10:34     INFO - Buffered messages logged at 22:04:24
[task 2022-06-08T22:10:34.451Z] 22:10:34     INFO - Console message: [JavaScript Error: "Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”)." {file: "chrome" line: 511}]
[task 2022-06-08T22:10:34.451Z] 22:10:34     INFO - Console message: [JavaScript Error: "Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”)." {file: "chrome" line: 511}]
[task 2022-06-08T22:10:34.452Z] 22:10:34     INFO - Console message: [JavaScript Error: "Content Security Policy: The page’s settings blocked the loading of a resource at inline (“default-src”)." {file: "chrome" line: 62}]
[task 2022-06-08T22:10:34.452Z] 22:10:34     INFO - Buffered messages finished
[task 2022-06-08T22:10:34.452Z] 22:10:34    ERROR - TEST-UNEXPECTED-TIMEOUT | devtools/client/inspector/rules/test/browser_rules_update_mask_image_cors.js | application timed out after 370 seconds with no output
[task 2022-06-08T22:10:34.453Z] 22:10:34    ERROR - Force-terminating active process(es).
[task 2022-06-08T22:10:34.453Z] 22:10:34     INFO - Determining child pids from psutil...
[task 2022-06-08T22:10:34.453Z] 22:10:34     INFO - [2264, 2265, 2270, 2271, 2284]
[task 2022-06-08T22:10:34.454Z] 22:10:34     INFO - ==> process 2257 launched child process 2264
[task 2022-06-08T22:10:34.454Z] 22:10:34     INFO - ==> process 2257 launched child process 2265
[task 2022-06-08T22:10:34.455Z] 22:10:34     INFO - ==> process 2257 launched child process 2270
[task 2022-06-08T22:10:34.455Z] 22:10:34     INFO - ==> process 2257 launched child process 2271
[task 2022-06-08T22:10:34.455Z] 22:10:34     INFO - ==> process 2257 launched child process 2272
[task 2022-06-08T22:10:34.456Z] 22:10:34     INFO - ==> process 2257 launched child process 2283
[task 2022-06-08T22:10:34.456Z] 22:10:34     INFO - ==> process 2257 launched child process 2284
[task 2022-06-08T22:10:34.456Z] 22:10:34     INFO - Found child pids: {2272, 2283, 2284, 2264, 2265, 2270, 2271}
[task 2022-06-08T22:10:34.457Z] 22:10:34     INFO - Failed to get child procs
[task 2022-06-08T22:10:34.457Z] 22:10:34     INFO - Killing process: 2272
[task 2022-06-08T22:10:34.457Z] 22:10:34     INFO - TEST-INFO | started process screencapture
[task 2022-06-08T22:10:34.561Z] 22:10:34     INFO - TEST-INFO | screencapture: exit 0

Set release status flags based on info from the regressing bug 1604562

status-firefox101: --- → unaffected
status-firefox102: --- → unaffected
status-firefox103: --- → affected
status-firefox-esr91: --- → unaffected

:emilio, since you are the author of the regressor, bug 1604562, could you take a look?
For more information, please visit auto_nag documentation.

Flags: needinfo?(emilio)

This is about the test, so moving the ni to myself.

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

I did some retriggers and it looks like this is permafail with --verify on macos on try.
It seems to fail at the chaos mode step, rather consistently, but I can't reproduce that locally.

Flags: needinfo?(jdescottes)
Attached image image.png —

As you can see on the screenshot, the download seems to fail. It doesn't have a correct size.
Maybe I could log the screenshot as base 64 before we initiate the download just to make sure the issue is with the download and not with the screenshot capture.

It seems we really hang in the save step. The screenshot is correctly generated, but somehow saving fails.
I doubt this has anything to do with the implementation change from Bug 1604562,a nd I think this affects other tests for screenshots in DevTools, eg https://bugzilla.mozilla.org/show_bug.cgi?id=1772443

Has Regression Range: --- → yes

Set release status flags based on info from the regressing bug 1604562

status-firefox104: --- → affected
status-firefox-esr102: --- → unaffected

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

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

Attachment

General

Creator:
Created:
Updated:
Size: