Intermittent raptor-browsertime Critical: Couldn't execute async script named toggle composition recorder error:ScriptTimeoutError: Timed out after 60000 / 120000 / 144000 ms
Categories
(Testing :: Raptor, defect, P5)
Tracking
(firefox-esr91 unaffected, firefox100 unaffected, firefox101 unaffected, firefox102 wontfix)
Tracking | Status | |
---|---|---|
firefox-esr91 | --- | unaffected |
firefox100 | --- | unaffected |
firefox101 | --- | unaffected |
firefox102 | --- | wontfix |
People
(Reporter: intermittent-bug-filer, Unassigned)
References
(Regression)
Details
(Keywords: intermittent-failure, regression)
Filed by: ncsoregi [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=377679337&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/JrVgL6FHQMSnuxtA5S3S1Q/runs/0/artifacts/public/logs/live_backing.log
[task 2022-05-11T13:23:06.493Z] 13:23:06 INFO - raptor-browsertime Info: Start firefox window recorder.
[task 2022-05-11T13:24:29.721Z] 13:24:29 INFO - raptor-browsertime Info: Stop firefox window recorder.
[task 2022-05-11T13:26:53.763Z] 13:26:53 ERROR - raptor-browsertime Error: Browsertime failed to run
[task 2022-05-11T13:26:53.785Z] 13:26:53 CRITICAL - raptor-browsertime Critical: Couldn't execute async script named toggle composition recorder error:ScriptTimeoutError: Timed out after 144000 ms
[task 2022-05-11T13:26:53.786Z] 13:26:53 INFO - raptor-perftest Info: Removing temporary directory: /var/folders/6_/2fr28cdd7y77jbw9wg779c0r000014/T/tmpmhlf7qmh
[task 2022-05-11T13:26:53.802Z] 13:26:53 ERROR - Traceback (most recent call last):
[task 2022-05-11T13:26:53.802Z] 13:26:53 INFO - File "/opt/worker/tasks/task_165227504541766/build/tests/raptor/raptor/raptor.py", line 215, in <module>
[task 2022-05-11T13:26:53.802Z] 13:26:53 INFO - main()
[task 2022-05-11T13:26:53.803Z] 13:26:53 INFO - File "/opt/worker/tasks/task_165227504541766/build/tests/raptor/raptor/raptor.py", line 161, in main
[task 2022-05-11T13:26:53.803Z] 13:26:53 INFO - success = raptor.run_tests(raptor_test_list, raptor_test_names)
[task 2022-05-11T13:26:53.803Z] 13:26:53 INFO - File "/opt/worker/tasks/task_165227504541766/build/tests/raptor/raptor/perftest.py", line 457, in run_tests
[task 2022-05-11T13:26:53.803Z] 13:26:53 INFO - self.run_test(test, timeout=int(test.get("page_timeout")))
[task 2022-05-11T13:26:53.804Z] 13:26:53 INFO - File "/opt/worker/tasks/task_165227504541766/build/tests/raptor/raptor/browsertime/base.py", line 601, in run_test
[task 2022-05-11T13:26:53.804Z] 13:26:53 INFO - raise Exception(self.browsertime_failure)
[task 2022-05-11T13:26:53.804Z] 13:26:53 INFO - Exception: Couldn't execute async script named toggle composition recorder error:ScriptTimeoutError: Timed out after 144000 ms
[task 2022-05-11T13:26:54.014Z] 13:26:54 ERROR - Return code: 1
[task 2022-05-11T13:26:54.014Z] 13:26:54 WARNING - setting return code to 1
[task 2022-05-11T13:26:54.015Z] 13:26:54 INFO - Copying Raptor results to upload dir:
[task 2022-05-11T13:26:54.015Z] 13:26:54 INFO - /opt/worker/tasks/task_165227504541766/build/blobber_upload_dir/perfherder-data.json
[task 2022-05-11T13:26:54.015Z] 13:26:54 INFO - Copying raptor results from /opt/worker/tasks/task_165227504541766/build/raptor.json to /opt/worker/tasks/task_165227504541766/build/blobber_upload_dir/perfherder-data.json
[task 2022-05-11T13:26:54.016Z] 13:26:54 CRITICAL - Error copying results /opt/worker/tasks/task_165227504541766/build/raptor.json to upload dir /opt/worker/tasks/task_165227504541766/build/blobber_upload_dir/perfherder-data.json
[task 2022-05-11T13:26:54.016Z] 13:26:54 INFO - [Errno 2] No such file or directory: '/opt/worker/tasks/task_165227504541766/build/raptor.json'
Comment 1•3 years ago
|
||
The raptor failure started with https://treeherder.mozilla.org/jobs?repo=mozilla-central&searchStr=os%2Cx%2C10.15%2Cwebrender%2Cshippable%2Copt%2Cbrowsertime%2Cperformance%2Ctests%2Con%2Cfirefox%2Ctest-macosx1015-64-shippable-qr%2Fopt-browsertime-tp6-live-sheriffed-firefox-cnn-e10s%2Ccnn&fromchange=b6dca56b56ccf7002c5a222a109898a3c32c82a8&group_state=expanded&selectedTaskRun=JrVgL6FHQMSnuxtA5S3S1Q.0 - most probably caused by Bug 1767797?
Greg, is there any chance you could take a look over this?
Thank you.
Updated•3 years ago
|
Comment 2•3 years ago
|
||
Set release status flags based on info from the regressing bug 1767797
Comment 3•3 years ago
|
||
:barret, it looks like the Window Recorder is having a lot of issues stopping on this test on the mac platform. Would you be able to look into it? If not, could you redirect the needinfo?
Comment 4•3 years ago
|
||
In the worst case, I can try using ffmpeg for recording but it's preferred to continue using the firefox window recorder.
Comment 5•3 years ago
•
|
||
I don't know why this is failing. I tried disabling/enabling the composition recorder directly on the latest macOS nightly (ie running windowUtils.setCompositionRecording(true|false)
from the browser console) directly and the recorder itself seems to be working.
This is the script that is running in browserTime. Maybe you could add logging here to see whats up, e.g.
const cb = arguments[arguments.length-1];
Promise.resolve(
windowUtils.setCompositionRecording(${enable})
)
.catch(e => console.log("*** e = " + e)
.then(() => cb());
Comment 6•3 years ago
|
||
Thanks :barret, I've made a try run with those changes to see what we find: https://treeherder.mozilla.org/#/jobs?repo=try&revision=ecdb4d391f8958208272af97600666380bf77f2e
Comment 7•3 years ago
•
|
||
Something else that is interesting is that this is only happening on non-fission tests.
Comment hidden (Intermittent Failures Robot) |
Updated•3 years ago
|
Comment 9•3 years ago
|
||
:barret, would you have any thoughts on what else we could try? The try run from yesterday didn't produce an error message: https://treeherder.mozilla.org/jobs?repo=try&tier=1%2C2%2C3&revision=ecdb4d391f8958208272af97600666380bf77f2e&selectedTaskRun=ReFcdudGQUWfgqYEm4Aqnw.0
It's timing out while it's trying to stop the recorder without an error being thrown. I could increase the timeout but 2.5 minutes already feels quite high.
Updated•3 years ago
|
Comment 10•3 years ago
|
||
I just tried enabling & disabling the composition recorder on the latest nightly with fission disabled and it worked, so I don't have any concrete ideas as to what is going on. Next steps would be to add some logging into Firefox to see whats going on.
The call path is as follows:
WindowUtils::StopCompositionRecording()
- This is the main entry point. Since we are calling
setCompositionRecording(false)
, we will enter this branch. This callsSendEndRecordingToDisk()
, which is received by theCompositorBridgeParent
:
- This is the main entry point. Since we are calling
CompositorBridgeParent::RecvStopRecordingToDIsk()
WebRenderBridgeParent::WriteCollectedFrames()
WebRenderAPI::WriteCollectedFrames()
- This sets up a runnable
WriteCollectedFramesEvent
to run on the render thread.
- This sets up a runnable
WriteCollectedFramesEvent::Run
- This is the entry point on the render thread where we request the RenderThread to write its collected frames.
RenderThread::WriteCollectedFramesForWindow()
RendererOGL::WriteCollectedFrames()
CompositionRecorder::WriteCollectedFrames()
- This is where we actually write the frames to disk. It's possible we are just taking too long to write our frames here if there are too many captured.
Comment 11•3 years ago
|
||
Ok, I wonder if there's any value in keeping this test running with fission disabled. :davehunt, what do you think?
Updated•3 years ago
|
Comment hidden (Intermittent Failures Robot) |
Comment 14•3 years ago
|
||
(In reply to Greg Mierzwinski [:sparky] from comment #11)
Ok, I wonder if there's any value in keeping this test running with fission disabled. :davehunt, what do you think?
If it's only failing in non-Fission then I don't see a good reason to keep it running. If we're still running other tests with Fission disabled then perhaps those should be disabled too? :jmaher do you see a reason to keep non-Fission tests around?
Comment 15•3 years ago
|
||
we only ship fission by default; users can hack their prefs to disable fission, but for all desktop fission is and has been the default config. Android is different, fission still has a roadmap to walk down- but we run all our unit/perf tests on android in no-fission.
I vote for turning off the no-fission version of the tests on desktop.
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Updated•3 years ago
|
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 25•2 years ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.
Reporter | ||
Comment 26•2 years ago
|
||
treeherder |
New failure instance: https://treeherder.mozilla.org/logviewer?job_id=390676282&repo=autoland
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 31•2 years ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.
Reporter | ||
Comment 32•2 years ago
|
||
treeherder |
New failure instance: https://treeherder.mozilla.org/logviewer?job_id=397315823&repo=mozilla-central
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 38•2 years ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.
Reporter | ||
Comment 39•2 years ago
|
||
treeherder |
New failure instance: https://treeherder.mozilla.org/logviewer?job_id=408037720&repo=mozilla-central
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 43•2 years ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit BugBot documentation.
Reporter | ||
Comment 44•2 years ago
|
||
treeherder |
New failure instance: https://treeherder.mozilla.org/logviewer?job_id=416106426&repo=mozilla-central
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 48•2 years ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit BugBot documentation.
Reporter | ||
Comment 49•2 years ago
|
||
treeherder |
New failure instance: https://treeherder.mozilla.org/logviewer?job_id=423551446&repo=mozilla-central
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 55•1 year ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit BugBot documentation.
Reporter | ||
Comment 56•1 year ago
|
||
treeherder |
New failure instance: https://treeherder.mozilla.org/logviewer?job_id=436628327&repo=autoland
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 64•1 year ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit BugBot documentation.
Reporter | ||
Comment 65•11 months ago
|
||
treeherder |
New failure instance: https://treeherder.mozilla.org/logviewer?job_id=453531499&repo=autoland
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 76•7 months ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit BugBot documentation.
Reporter | ||
Comment 77•5 months ago
|
||
treeherder |
New failure instance: https://treeherder.mozilla.org/logviewer?job_id=474524517&repo=mozilla-central
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 82•4 months ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit BugBot documentation.
Reporter | ||
Comment 83•3 months ago
|
||
treeherder |
New failure instance: https://treeherder.mozilla.org/logviewer?job_id=484308506&repo=mozilla-central
Comment hidden (Intermittent Failures Robot) |
Comment hidden (Intermittent Failures Robot) |
Comment 86•2 months ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit BugBot documentation.
Description
•