1811991 - Perma [tier 2] Btime raptor-browsertime Critical: Could not find window recording directory in C:\<path>\browsertime-results\welcome | or Critical: TypeError: Cannot read properties of undefined (reading 'substr')

Status: RESOLVED FIXED

(Core :: Security: Process Sandboxing, defect, P5)

Description

[Treeherder Bug Filer]

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

---

[task 2023-01-24T02:22:12.811Z] 02:22:12     INFO -  raptor-browsertime Info: Navigating to url about:welcome iteration 1
[task 2023-01-24T02:22:20.856Z] 02:22:20     INFO -  raptor-browsertime Info: Stop firefox window recorder.
[task 2023-01-24T02:22:20.909Z] 02:22:20    ERROR -  raptor-browsertime Error: Browsertime failed to run
[task 2023-01-24T02:22:20.971Z] 02:22:20 CRITICAL -  raptor-browsertime Critical: Could not find window recording directory in C:\Users\task_1674524863\build\blobber_upload_dir\browsertime-results\welcome
[task 2023-01-24T02:22:20.972Z] 02:22:20     INFO -  raptor-mitmproxy Info: MitmproxyDesktop stop!!
[task 2023-01-24T02:22:20.972Z] 02:22:20     INFO -  raptor-mitmproxy Info: Mitmproxy stop!!
[task 2023-01-24T02:22:20.972Z] 02:22:20     INFO -  raptor-mitmproxy Info: Stopping mitmproxy playback, killing process 8844
[task 2023-01-24T02:22:20.973Z] 02:22:20     INFO -  raptor-mitmproxy Info: Sending CTRL_BREAK_EVENT to mitmproxy
[task 2023-01-24T02:22:22.972Z] 02:22:22     INFO -  raptor-mitmproxy Info: Successfully killed the mitmproxy playback process with exit code 3221225786
[task 2023-01-24T02:22:22.972Z] 02:22:22     INFO -  raptor-mitmproxy Info: Turning off the browser proxy
[task 2023-01-24T02:22:22.973Z] 02:22:22     INFO -  raptor-mitmproxy Info: writing: C:\Users\task_1674524863\build\application\firefox\distribution\policies.json
[task 2023-01-24T02:22:22.973Z] 02:22:22     INFO -  raptor-perftest Info: Removing temporary directory: C:\Users\task_1674524863\AppData\Local\Temp\tmppv7aw_b1
[task 2023-01-24T02:22:23.012Z] 02:22:23    ERROR -  Traceback (most recent call last):
[task 2023-01-24T02:22:23.012Z] 02:22:23     INFO -    File "C:\Users\task_1674524863\build\tests\raptor\raptor\raptor.py", line 204, in <module>
[task 2023-01-24T02:22:23.013Z] 02:22:23     INFO -      main()
[task 2023-01-24T02:22:23.013Z] 02:22:23     INFO -    File "C:\Users\task_1674524863\build\tests\raptor\raptor\raptor.py", line 150, in main
[task 2023-01-24T02:22:23.013Z] 02:22:23     INFO -      success = raptor.run_tests(raptor_test_list, raptor_test_names)
[task 2023-01-24T02:22:23.014Z] 02:22:23     INFO -    File "C:\Users\task_1674524863\build\tests\raptor\raptor\perftest.py", line 469, in run_tests
[task 2023-01-24T02:22:23.014Z] 02:22:23     INFO -      self.run_test(test, timeout=int(test.get("page_timeout")))
[task 2023-01-24T02:22:23.014Z] 02:22:23     INFO -    File "C:\Users\task_1674524863\build\tests\raptor\raptor\browsertime\base.py", line 811, in run_test
[task 2023-01-24T02:22:23.015Z] 02:22:23     INFO -      raise Exception(self.browsertime_failure)
[task 2023-01-24T02:22:23.015Z] 02:22:23     INFO -  Exception: Could not find window recording directory in C:\Users\task_1674524863\build\blobber_upload_dir\browsertime-results\welcome
[task 2023-01-24T02:22:23.072Z] 02:22:23    ERROR - Return code: 1
[task 2023-01-24T02:22:23.072Z] 02:22:23  WARNING - setting return code to 1
[task 2023-01-24T02:22:23.072Z] 02:22:23     INFO - Copying Raptor results to upload dir:
[task 2023-01-24T02:22:23.072Z] 02:22:23     INFO - C:\Users\task_1674524863\build\blobber_upload_dir\perfherder-data.json
[task 2023-01-24T02:22:23.072Z] 02:22:23     INFO - Copying raptor results from C:\Users\task_1674524863\build\raptor.json to C:\Users\task_1674524863\build\blobber_upload_dir\perfherder-data.json
[task 2023-01-24T02:22:23.073Z] 02:22:23 CRITICAL - Error copying results C:\Users\task_1674524863\build\raptor.json to upload dir C:\Users\task_1674524863\build\blobber_upload_dir\perfherder-data.json
[task 2023-01-24T02:22:23.073Z] 02:22:23     INFO - [Errno 2] No such file or directory: 'C:\\Users\\task_1674524863\\build\\raptor.json'
[task 2023-01-24T02:22:23.073Z] 02:22:23     INFO - Running post-action listener: _package_coverage_data

Comment 1

[Iulian Moraru]

backfill and retriggers

Hi Chris! Can you please take a look at this? It seems that Bug 1799470 caused this perma failure.
Thank you!

Comment 2

[Iulian Moraru]

This fails with raptor-browsertime Critical: Could not find window recording directory in C:\Users\task_1674526439\build\blobber_upload_dir\browsertime-results\welcome or with raptor-browsertime Critical: TypeError: Cannot read properties of undefined (reading 'substr')

Log snippet for the TypeError failure line:

[task 2023-01-24T02:36:30.799Z] 02:36:30     INFO -  raptor-browsertime Info: Start firefox window recorder.
[task 2023-01-24T02:36:32.660Z] 02:36:32     INFO -  raptor-browsertime Info: Navigating to url about:welcome iteration 1
[task 2023-01-24T02:36:40.706Z] 02:36:40     INFO -  raptor-browsertime Info: Stop firefox window recorder.
[task 2023-01-24T02:36:40.750Z] 02:36:40    ERROR -  raptor-browsertime Error: Browsertime failed to run
[task 2023-01-24T02:36:40.816Z] 02:36:40    ERROR -  raptor-browsertime Error: Browsertime failed to run
[task 2023-01-24T02:36:40.816Z] 02:36:40     INFO -  raptor-browsertime Info:     at findRecordingStartTime (C:\Users\task_1674525821\fetches\browsertime\node_modules\browsertime\lib\video\screenRecording\firefox\firefoxWindowRecorder.js:63:23)
[task 2023-01-24T02:36:40.817Z] 02:36:40     INFO -  raptor-browsertime Info:     at FirefoxWindowRecorder.stop (C:\Users\task_1674525821\fetches\browsertime\node_modules\browsertime\lib\video\screenRecording\firefox\firefoxWindowRecorder.js:196:31)
[task 2023-01-24T02:36:40.818Z] 02:36:40     INFO -  raptor-browsertime Info:     at async Measure._stopVideo (C:\Users\task_1674525821\fetches\browsertime\node_modules\browsertime\lib\core\engine\command\measure.js:101:7)
[task 2023-01-24T02:36:40.818Z] 02:36:40     INFO -  raptor-browsertime Info:     at async Measure.stop (C:\Users\task_1674525821\fetches\browsertime\node_modules\browsertime\lib\core\engine\command\measure.js:296:5)
[task 2023-01-24T02:36:40.818Z] 02:36:40     INFO -  raptor-browsertime Info:     at async module.exports (C:\Users\task_1674525821\build\tests\raptor\browsertime\welcome.js:23:5)
[task 2023-01-24T02:36:40.819Z] 02:36:40     INFO -  raptor-browsertime Info:     at async C:\Users\task_1674525821\fetches\browsertime\node_modules\browsertime\lib\core\engine\run.js:7:9
[task 2023-01-24T02:36:40.819Z] 02:36:40     INFO -  raptor-browsertime Info:     at async Iteration.run (C:\Users\task_1674525821\fetches\browsertime\node_modules\browsertime\lib\core\engine\iteration.js:227:9)
[task 2023-01-24T02:36:40.820Z] 02:36:40     INFO -  raptor-browsertime Info:     at async Engine.runByScript (C:\Users\task_1674525821\fetches\browsertime\node_modules\browsertime\lib\core\engine\index.js:274:20)
[task 2023-01-24T02:36:40.820Z] 02:36:40     INFO -  raptor-browsertime Info:     at async run (C:\Users\task_1674525821\fetches\browsertime\node_modules\browsertime\bin\browsertime.js:104:22)
[task 2023-01-24T02:36:40.821Z] 02:36:40    ERROR -  raptor-browsertime Critical: TypeError: Cannot read properties of undefined (reading 'substr')
[task 2023-01-24T02:36:40.821Z] 02:36:40     INFO -  raptor-mitmproxy Info: MitmproxyDesktop stop!!
[task 2023-01-24T02:36:40.821Z] 02:36:40     INFO -  raptor-mitmproxy Info: Mitmproxy stop!!
[task 2023-01-24T02:36:40.822Z] 02:36:40     INFO -  raptor-mitmproxy Info: Stopping mitmproxy playback, killing process 2956
[task 2023-01-24T02:36:40.822Z] 02:36:40     INFO -  raptor-mitmproxy Info: Sending CTRL_BREAK_EVENT to mitmproxy
[task 2023-01-24T02:36:42.816Z] 02:36:42     INFO -  raptor-mitmproxy Info: Successfully killed the mitmproxy playback process with exit code 3221225786
[task 2023-01-24T02:36:42.817Z] 02:36:42     INFO -  raptor-mitmproxy Info: Turning off the browser proxy
[task 2023-01-24T02:36:42.817Z] 02:36:42     INFO -  raptor-mitmproxy Info: writing: C:\Users\task_1674525821\build\application\firefox\distribution\policies.json
[task 2023-01-24T02:36:42.818Z] 02:36:42     INFO -  raptor-perftest Info: Removing temporary directory: C:\Users\task_1674525821\AppData\Local\Temp\tmp9_ls31cd
[task 2023-01-24T02:36:42.857Z] 02:36:42    ERROR -  Traceback (most recent call last):
[task 2023-01-24T02:36:42.857Z] 02:36:42     INFO -    File "C:\Users\task_1674525821\build\tests\raptor\raptor\raptor.py", line 204, in <module>
[task 2023-01-24T02:36:42.857Z] 02:36:42     INFO -      main()
[task 2023-01-24T02:36:42.858Z] 02:36:42     INFO -    File "C:\Users\task_1674525821\build\tests\raptor\raptor\raptor.py", line 150, in main
[task 2023-01-24T02:36:42.858Z] 02:36:42     INFO -      success = raptor.run_tests(raptor_test_list, raptor_test_names)
[task 2023-01-24T02:36:42.859Z] 02:36:42     INFO -    File "C:\Users\task_1674525821\build\tests\raptor\raptor\perftest.py", line 469, in run_tests
[task 2023-01-24T02:36:42.859Z] 02:36:42     INFO -      self.run_test(test, timeout=int(test.get("page_timeout")))
[task 2023-01-24T02:36:42.859Z] 02:36:42     INFO -    File "C:\Users\task_1674525821\build\tests\raptor\raptor\browsertime\base.py", line 811, in run_test
[task 2023-01-24T02:36:42.860Z] 02:36:42     INFO -      raise Exception(self.browsertime_failure)
[task 2023-01-24T02:36:42.860Z] 02:36:42    ERROR -  Exception: TypeError: Cannot read properties of undefined (reading 'substr')
[task 2023-01-24T02:36:42.921Z] 02:36:42    ERROR - Return code: 1
[task 2023-01-24T02:36:42.921Z] 02:36:42  WARNING - setting return code to 1

Comment 3

[Chris Martin [:cmartin]]

Hmm -- It looks like the root cause here is that the feature I enabled (GPU Process Sandbox) is doing exactly what it's supposed to do - Blocking access to the filesystem from the GPU Process.

That likely means we're going to have to try and find a way to either fix this test, or-else somehow add an exception to the sandbox for the directories that need to be accessed here (or possibly turn the sandbox off for these tests).

I'll see what I can figure out.

Comment 4

[Iulian Moraru]

Removing "welcome test" from the bug summary because this is also perma failing on other jobs, at least on this process-switch job.

• Failure log with TypeError: Cannot read properties of undefined (reading 'substr')
• Failure log with Could not find window recording directory in C:\Users\task_1674703336\build\blobber_upload_dir\browsertime-results\process-switch

Comment 5

[Greg Mierzwinski [:sparky]]

:cmartin, let me know if you need any help with this. This issue is happening when we're trying to handle the recording directory here: https://github.com/sitespeedio/browsertime/blob/bad11af757eafa3da7e5f5e951c6f661d9a82f3c/lib/video/screenRecording/firefox/firefoxWindowRecorder.js#L63

This recording directory stores recordings from the Firefox Window Recorder.

Comment 6

[Intermittent Failures Robot]

70 failures in 3914 pushes (0.018 failures/push) were associated with this bug in the last 7 days.

This is the #11 most frequent failure this week.

** This failure happened more than 30 times this week! Resolving this bug is a high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 2 weeks, the affected test(s) may be disabled. **

Repository breakdown:

• autoland: 43
• mozilla-central: 27

Platform and build breakdown:

• windows10-64-shippable-qr: 70
  • opt: 70

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1811991&startday=2023-01-23&endday=2023-01-29&tree=all

Comment 7

[Chris Martin [:cmartin]]

Attachment: Bug 1811991 - Backout GPU Sandbox filesystem blocking

The filesystem blocking breaks Raptor tests and other programs that rely on
screen recording.

Will have to remote the screen recording and then re-enable filesystem blocking

Comment 8

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/cfd0bbedf4e6
Backout GPU Sandbox filesystem blocking r=handyman

Comment 9

[Norisz Fay [:noriszfay]]

https://hg.mozilla.org/mozilla-central/rev/cfd0bbedf4e6

Comment 10

[Intermittent Failures Robot]

24 failures in 3606 pushes (0.007 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 9
• mozilla-central: 15

Platform and build breakdown:

• windows10-64-shippable-qr: 24
  • opt: 24

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1811991&startday=2023-01-30&endday=2023-02-05&tree=all