1722710 - Intermittent TEST-UNEXPECTED-TIMEOUT | devtools/client/performance/test/browser_perf-docload.js | application timed out after 370 seconds with no output

Status: RESOLVED INCOMPLETE

(DevTools :: Performance Tools (Profiler/Timeline), defect, P5)

Description

[Treeherder Bug Filer]

Filed by: smolnar [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=346597450&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/en1GCMGUT2eve2TxxXQ5sw/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/en1GCMGUT2eve2TxxXQ5sw/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1

---

INFO - TEST-START | devtools/client/performance/test/browser_perf-docload.js
[task 2021-07-28T12:19:13.420Z] 12:19:13     INFO - GECKO(1397) | Adding tab with url: http://example.com/browser/devtools/client/performance/test/doc_simple-test.html#1842603086838523.
[task 2021-07-28T12:19:14.320Z] 12:19:14     INFO - GECKO(1397) | Initializing a performance panel.
[task 2021-07-28T12:19:17.825Z] 12:19:17     INFO - GECKO(1397) | JavaScript warning: resource://devtools/client/shared/demangle.js, line 0: Successfully compiled asm.js code (total compilation time 53ms)
[task 2021-07-28T12:19:18.551Z] 12:19:18     INFO - GECKO(1397) | Waiting for event: 'Performance:BackendReadyRecordingStart' on [object PerformanceController] for 1 time(s).
[task 2021-07-28T12:19:18.552Z] 12:19:18     INFO - GECKO(1397) | Waiting for event: 'Performance:RecordingStateChange' on [object PerformanceController] for 1 time(s) with arguments: ["recording-started"].
[task 2021-07-28T12:19:18.552Z] 12:19:18     INFO - GECKO(1397) | Waiting for event: 'Performance:UI:StateChanged' on [object PerformanceView] for 1 time(s) with arguments: [{}].
[task 2021-07-28T12:19:18.553Z] 12:19:18     INFO - GECKO(1397) | Waiting for event: 'Performance:UI:OverviewRendered' on [object OverviewView] for 1 time(s) with arguments: [100].
[task 2021-07-28T12:19:18.697Z] 12:19:18     INFO - GECKO(1397) | Event: 'Performance:UI:StateChanged' on [object PerformanceView] received.
[task 2021-07-28T12:19:18.740Z] 12:19:18     INFO - GECKO(1397) | Event: 'Performance:RecordingStateChange' on [object PerformanceController] received.
[task 2021-07-28T12:19:18.776Z] 12:19:18     INFO - GECKO(1397) | Event: 'Performance:BackendReadyRecordingStart' on [object PerformanceController] received.
[task 2021-07-28T12:19:27.905Z] 12:19:27     INFO - GECKO(1397) | 2021-07-28 12:19:27.904 firefox[1397:18388] 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 2021-07-28T12:26:16.038Z] 12:26:16     INFO - Buffered messages logged at 12:19:13
[task 2021-07-28T12:26:16.039Z] 12:26:16     INFO - Entering test bound 
[task 2021-07-28T12:26:16.039Z] 12:26:16     INFO - Buffered messages logged at 12:19:16
[task 2021-07-28T12:26:16.040Z] 12:26:16     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 2021-07-28T12:26:16.040Z] 12:26:16     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 2021-07-28T12:26:16.041Z] 12:26:16     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: 75}]
[task 2021-07-28T12:26:16.041Z] 12:26:16     INFO - Buffered messages logged at 12:19:17
[task 2021-07-28T12:26:16.042Z] 12:26:16     INFO - Console message: [JavaScript Warning: "Successfully compiled asm.js code (total compilation time 53ms)" {file: "resource://devtools/client/shared/demangle.js" line: 0}]
[task 2021-07-28T12:26:16.042Z] 12:26:16     INFO - Buffered messages logged at 12:20:06
[task 2021-07-28T12:26:16.042Z] 12:26:16     INFO - Longer timeout required, waiting longer...  Remaining timeouts: 2
[task 2021-07-28T12:26:16.043Z] 12:26:16     INFO - Buffered messages finished
[task 2021-07-28T12:26:16.043Z] 12:26:16    ERROR - TEST-UNEXPECTED-TIMEOUT | devtools/client/performance/test/browser_perf-docload.js | application timed out after 370 seconds with no output
[task 2021-07-28T12:26:16.044Z] 12:26:16    ERROR - Force-terminating active process(es).
[task 2021-07-28T12:26:16.044Z] 12:26:16     INFO - Determining child pids from psutil...
[task 2021-07-28T12:26:16.044Z] 12:26:16     INFO - [1408, 1409, 1414, 1415, 1416]
[task 2021-07-28T12:26:16.045Z] 12:26:16     INFO - ==> process 1397 launched child process 1408
[task 2021-07-28T12:26:16.045Z] 12:26:16     INFO - ==> process 1397 launched child process 1409
[task 2021-07-28T12:26:16.045Z] 12:26:16     INFO - ==> process 1397 launched child process 1414
[task 2021-07-28T12:26:16.046Z] 12:26:16     INFO - ==> process 1397 launched child process 1415
[task 2021-07-28T12:26:16.046Z] 12:26:16     INFO - ==> process 1397 launched child process 1416
[task 2021-07-28T12:26:16.046Z] 12:26:16     INFO - Found child pids: {1408, 1409, 1414, 1415, 1416}
[task 2021-07-28T12:26:16.047Z] 12:26:16     INFO - Killing process: 1408
[task 2021-07-28T12:26:16.047Z] 12:26:16     INFO - TEST-INFO | started process screencapture
[task 2021-07-28T12:26:16.148Z] 12:26:16     INFO - TEST-INFO | screencapture: exit 0

Comment 1

[BugBot [:suhaib / :marco/ :calixte]]

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

Comment 2

[Intermittent Failures Robot]

4 failures in 3131 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 4

Platform and build breakdown:

• macosx1015-64-qr: 4
  • debug: 2
  • opt: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1722710&startday=2021-07-26&endday=2021-08-01&tree=all

Comment 3

[BugBot [:suhaib / :marco/ :calixte]]

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