Closed
Bug 1801769
Opened 3 years ago
Closed 3 years ago
Intermittent security/sandbox/test/browser_content_sandbox_syscalls.js | single tracking bug
Categories
(Core :: Security: Process Sandboxing, defect, P5)
Core
Security: Process Sandboxing
Tracking
()
RESOLVED
INCOMPLETE
People
(Reporter: intermittent-bug-filer, Unassigned)
Details
(Keywords: intermittent-failure, intermittent-testcase)
Filed by: ctuns [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=397279415&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/ShUZ4L9oQ_uAOnDHP1VsJQ/runs/0/artifacts/public/logs/live_backing.log
[task 2022-11-22T01:08:45.887Z] 01:08:45 INFO - TEST-PASS | security/sandbox/test/browser_content_sandbox_syscalls.js | opening a file for writing in content temp is not permitted -
[task 2022-11-22T01:08:45.887Z] 01:08:45 INFO - Buffered messages finished
[task 2022-11-22T01:08:45.888Z] 01:08:45 INFO - TEST-UNEXPECTED-FAIL | security/sandbox/test/browser_content_sandbox_syscalls.js | Test timed out -
[task 2022-11-22T01:08:55.842Z] 01:08:55 INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-11-22T01:08:55.843Z] 01:08:55 INFO - TEST-UNEXPECTED-FAIL | security/sandbox/test/browser_content_sandbox_syscalls.js | waiting for vsync to be disabled - timed out after 50 tries. - false == true - JS frame :: chrome://mochikit/content/browser-test.js :: ensureVsyncDisabled :: line 594
[task 2022-11-22T01:08:55.843Z] 01:08:55 INFO - Stack trace:
[task 2022-11-22T01:08:55.843Z] 01:08:55 INFO - chrome://mochikit/content/browser-test.js:ensureVsyncDisabled:594
[task 2022-11-22T01:08:55.844Z] 01:08:55 INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-11-22T01:08:55.844Z] 01:08:55 INFO - TEST-UNEXPECTED-FAIL | security/sandbox/test/browser_content_sandbox_syscalls.js | vsync remained enabled at the end of the test. Is there an animation still running? Consider talking to the performance team for tips to solve this. - false == true - JS frame :: chrome://mochikit/content/browser-test.js :: ensureVsyncDisabled :: line 595
[task 2022-11-22T01:08:55.844Z] 01:08:55 INFO - Stack trace:
[task 2022-11-22T01:08:55.844Z] 01:08:55 INFO - chrome://mochikit/content/browser-test.js:ensureVsyncDisabled:595
[task 2022-11-22T01:08:55.845Z] 01:08:55 INFO - GECKO(3057) | MEMORY STAT | vsize 8686MB | residentFast 298MB | heapAllocated 125MB
[task 2022-11-22T01:08:55.845Z] 01:08:55 INFO - TEST-OK | security/sandbox/test/browser_content_sandbox_syscalls.js | took 55229ms
[task 2022-11-22T01:08:55.854Z] 01:08:55 INFO - checking window state
[task 2022-11-22T01:08:55.863Z] 01:08:55 INFO - GECKO(3057) | Completed ShutdownLeaks collections in process 3057
[task 2022-11-22T01:08:55.864Z] 01:08:55 INFO - TEST-START | Shutdown
[task 2022-11-22T01:08:55.865Z] 01:08:55 INFO - Browser Chrome Test Summary
[task 2022-11-22T01:08:55.866Z] 01:08:55 INFO - Passed: 83
[task 2022-11-22T01:08:55.866Z] 01:08:55 INFO - Failed: 3
[task 2022-11-22T01:08:55.867Z] 01:08:55 INFO - Todo: 0
[task 2022-11-22T01:08:55.867Z] 01:08:55 INFO - Mode: e10s
[task 2022-11-22T01:08:55.868Z] 01:08:55 INFO - *** End BrowserChrome Test Results ***
[task 2022-11-22T01:08:55.882Z] 01:08:55 INFO - GECKO(3057) | Exiting due to channel error.
[task 2022-11-22T01:08:55.884Z] 01:08:55 INFO - GECKO(3057) | Exiting due to channel error.
[task 2022-11-22T01:08:55.884Z] 01:08:55 INFO - GECKO(3057) | Exiting due to channel error.
[task 2022-11-22T01:08:55.884Z] 01:08:55 INFO - GECKO(3057) | Exiting due to channel error.
[task 2022-11-22T01:08:55.885Z] 01:08:55 INFO - GECKO(3057) | Exiting due to channel error.
[task 2022-11-22T01:08:55.885Z] 01:08:55 INFO - GECKO(3057) | Exiting due to channel error.
[task 2022-11-22T01:15:05.923Z] 01:15:05 INFO - Buffered messages finished
[task 2022-11-22T01:15:05.923Z] 01:15:05 ERROR - TEST-UNEXPECTED-TIMEOUT | Last test finished | application timed out after 370 seconds with no output
[task 2022-11-22T01:15:05.923Z] 01:15:05 ERROR - Force-terminating active process(es).
[task 2022-11-22T01:15:05.924Z] 01:15:05 INFO - Determining child pids from psutil...
[task 2022-11-22T01:15:05.925Z] 01:15:05 INFO - []
[task 2022-11-22T01:15:05.926Z] 01:15:05 INFO - ==> process 3057 launched child process 3062
[task 2022-11-22T01:15:05.926Z] 01:15:05 INFO - ==> process 3057 launched child process 3063
[task 2022-11-22T01:15:05.926Z] 01:15:05 INFO - ==> process 3057 launched child process 3064
[task 2022-11-22T01:15:05.927Z] 01:15:05 INFO - ==> process 3057 launched child process 3065
[task 2022-11-22T01:15:05.927Z] 01:15:05 INFO - ==> process 3057 launched child process 3066
[task 2022-11-22T01:15:05.927Z] 01:15:05 INFO - ==> process 3057 launched child process 3067
[task 2022-11-22T01:15:05.928Z] 01:15:05 INFO - ==> process 3057 launched child process 3070
[task 2022-11-22T01:15:05.928Z] 01:15:05 INFO - ==> process 3057 launched child process 3071
[task 2022-11-22T01:15:05.928Z] 01:15:05 INFO - ==> process 3057 launched child process 3074
[task 2022-11-22T01:15:05.929Z] 01:15:05 INFO - ==> process 3057 launched child process 3078
[task 2022-11-22T01:15:05.929Z] 01:15:05 INFO - Found child pids: {3074, 3078, 3062, 3063, 3064, 3065, 3066, 3067, 3070, 3071}
[task 2022-11-22T01:15:05.929Z] 01:15:05 INFO - Failed to get child procs
[task 2022-11-22T01:15:05.930Z] 01:15:05 INFO - Killing process: 3074
[task 2022-11-22T01:15:05.930Z] 01:15:05 INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-11-22T01:15:05.930Z] 01:15:05 INFO - Can't trigger Breakpad, process no longer exists
[task 2022-11-22T01:15:05.931Z] 01:15:05 INFO - Killing process: 3078
[task 2022-11-22T01:15:05.931Z] 01:15:05 INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-11-22T01:15:05.931Z] 01:15:05 INFO - Can't trigger Breakpad, process no longer exists
[task 2022-11-22T01:15:05.932Z] 01:15:05 INFO - Killing process: 3062
[task 2022-11-22T01:15:05.932Z] 01:15:05 INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-11-22T01:15:05.932Z] 01:15:05 INFO - Can't trigger Breakpad, process no longer exists
[task 2022-11-22T01:15:05.932Z] 01:15:05 INFO - Killing process: 3063
[task 2022-11-22T01:15:05.933Z] 01:15:05 INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-11-22T01:15:05.933Z] 01:15:05 INFO - Can't trigger Breakpad, process no longer exists
[task 2022-11-22T01:15:05.933Z] 01:15:05 INFO - Killing process: 3064
[task 2022-11-22T01:15:05.934Z] 01:15:05 INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-11-22T01:15:05.934Z] 01:15:05 INFO - Can't trigger Breakpad, process no longer exists
[task 2022-11-22T01:15:05.934Z] 01:15:05 INFO - Killing process: 3065
[task 2022-11-22T01:15:05.935Z] 01:15:05 INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-11-22T01:15:05.935Z] 01:15:05 INFO - Killing process: 3066
[task 2022-11-22T01:15:05.936Z] 01:15:05 INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-11-22T01:15:05.936Z] 01:15:05 INFO - Can't trigger Breakpad, process no longer exists
[task 2022-11-22T01:15:05.936Z] 01:15:05 INFO - Killing process: 3067
[task 2022-11-22T01:15:05.936Z] 01:15:05 INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-11-22T01:15:05.937Z] 01:15:05 INFO - Can't trigger Breakpad, process no longer exists
[task 2022-11-22T01:15:05.937Z] 01:15:05 INFO - Killing process: 3070
[task 2022-11-22T01:15:05.938Z] 01:15:05 INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-11-22T01:15:05.938Z] 01:15:05 INFO - Can't trigger Breakpad, process no longer exists
[task 2022-11-22T01:15:05.938Z] 01:15:05 INFO - Killing process: 3071
[task 2022-11-22T01:15:05.939Z] 01:15:05 INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-11-22T01:15:05.939Z] 01:15:05 INFO - Can't trigger Breakpad, process no longer exists
[task 2022-11-22T01:15:05.939Z] 01:15:05 INFO - Killing process: 3057
[task 2022-11-22T01:15:05.940Z] 01:15:05 INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-11-22T01:15:05.940Z] 01:15:05 INFO - psutil found pid 3057 dead
[task 2022-11-22T01:31:45.994Z] 01:31:45 INFO - Automation Error: mozprocess timed out after 1000 seconds running ['/opt/worker/tasks/task_166907826884843/build/venv/bin/python', '-u', '/opt/worker/tasks/task_166907826884843/build/tests/mochitest/runtests.py', 'browser/base/content/test/general/browser.ini', 'browser/base/content/test/outOfProcess/browser.ini', 'browser/base/content/test/pageActions/browser.ini', 'browser/base/content/test/pageStyle/browser.ini', 'browser/base/content/test/static/browser.ini', 'browser/base/content/test/zoom/browser.ini', 'browser/components/enterprisepolicies/tests/browser/homepage_button/browser.ini', 'browser/components/ion/test/browser/browser.ini', 'browser/components/places/tests/browser/browser.ini', 'browser/components/pocket/test/unit/browser.ini', 'browser/components/privatebrowsing/test/browser/browser.ini', 'browser/components/protections/test/browser/browser.ini', 'browser/components/syncedtabs/test/browser/browser.ini', 'browser/extensions/formautofill/test/browser/browser.ini', 'browser/extensions/webcompat/tests/browser/browser.ini', 'dom/base/test/browser.ini', 'dom/broadcastchannel/tests/browser.ini', 'dom/cache/test/browser/browser.ini', 'dom/events/test/browser.ini', 'dom/html/test/browser.ini', 'dom/ipc/tests/JSProcessActor/browser.ini', 'dom/manifest/test/browser.ini', 'dom/media/mediacontrol/tests/browser/browser.ini', 'dom/serviceworkers/test/browser-dFPI.ini', 'dom/u2f/tests/browser/browser.ini', 'dom/url/tests/browser.ini', 'gfx/tests/browser/browser.ini', 'netwerk/cookie/test/browser/browser.ini', 'security/sandbox/test/browser.ini', 'toolkit/components/aboutthirdparty/tests/browser/browser.ini', 'toolkit/components/antitracking/test/browser/browser.ini', 'toolkit/components/nimbus/test/browser/browser.ini', 'toolkit/components/startup/tests/browser/browser.ini', 'toolkit/components/viewsource/test/browser/browser.ini', '--setpref=network.process.enabled=true', '--setpref=network.http.network_access_on_socket_process.enabled=true', '--setpref=layers.d3d11.enable-blacklist=false', '--appname=/opt/worker/tasks/task_166907826884843/build/application/Firefox Nightly.app/Contents/MacOS/firefox', '--utility-path=tests/bin', '--extra-profile-file=tests/bin/plugins', '--symbols-path=https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/ZHHEYJ4aRz-0JrFt2zdQpg/artifacts/public/build/target.crashreporter-symbols.zip', '--certificate-path=tests/certs', '--quiet', '--log-raw=/opt/worker/tasks/task_166907826884843/build/blobber_upload_dir/mochitest-browser-chrome_raw.log', '--log-errorsummary=/opt/worker/tasks/task_166907826884843/build/blobber_upload_dir/mochitest-browser-chrome_errorsummary.log', '--screenshot-on-fail', '--cleanup-crashes', '--marionette-startup-timeout=180', '--sandbox-read-whitelist=/opt/worker/tasks/task_166907826884843/build', '--log-raw=-', '--flavor=browser', '--chunk-by-runtime']
[task 2022-11-22T01:31:45.994Z] 01:31:45 ERROR - timed out after 1000 seconds of no output
[task 2022-11-22T01:31:45.994Z] 01:31:45 ERROR - Return code: -15
[task 2022-11-22T01:31:45.994Z] 01:31:45 ERROR - Got 3 unexpected statuses
[task 2022-11-22T01:31:45.994Z] 01:31:45 ERROR - No suite end message was emitted by this harness.
[task 2022-11-22T01:31:45.994Z] 01:31:45 INFO - TinderboxPrint: mochitest-mochitest-browser-chrome<br/>473/<em class="testfail">3</em>/0
[task 2022-11-22T01:31:45.995Z] 01:31:45 ERROR - # TBPL FAILURE #
[task 2022-11-22T01:31:45.995Z] 01:31:45 WARNING - setting return code to 2
[task 2022-11-22T01:31:45.995Z] 01:31:45 ERROR - The mochitest suite: mochitest-browser-chrome ran with return status: FAILURE
[task 2022-11-22T01:31:45.995Z] 01:31:45 INFO - Running post-action listener: _package_coverage_data
[task 2022-11-22T01:31:45.995Z] 01:31:45 INFO - Running post-action listener: _resource_record_post_action
[task 2022-11-22T01:31:45.995Z] 01:31:45 INFO - Running post-action listener: process_java_coverage_data
[task 2022-11-22T01:31:45.995Z] 01:31:45 INFO - [mozharness: 2022-11-22 01:31:45.995633Z] Finished run-tests step (success)
[task 2022-11-22T01:31:45.995Z] 01:31:45 INFO - Running post-run listener: _resource_record_post_run
[task 2022-11-22T01:31:46.193Z] 01:31:46 INFO - instance_metadata.json not found; unable to determine instance type
[task 2022-11-22T01:31:46.202Z] 01:31:46 INFO - Validating Perfherder data against /opt/worker/tasks/task_166907826884843/mozharness/external_tools/performance-artifact-schema.json
[task 2022-11-22T01:31:46.205Z] 01:31:46 INFO - PERFHERDER_DATA: {"framework": {"name": "job_resource_usage"}, "suites": [{"name": "mochitest.mochitest-browser-chrome.overall", "extraOptions": ["e10s", "buildbot-unknown"], "subtests": [{"name": "cpu_percent", "value": 4.738023168908834}, {"name": "io_write_bytes", "value": 2361999360}, {"name": "io.read_bytes", "value": 445411328}, {"name": "io_write_time", "value": 11550}, {"name": "io_read_time", "value": 7576}]}, {"name": "mochitest.mochitest-browser-chrome.start-pulseaudio", "subtests": [{"name": "time", "value": 0.0004417896270751953}, {"name": "cpu_percent", "value": 0}]}, {"name": "mochitest.mochitest-browser-chrome.install", "subtests": [{"name": "time", "value": 19.58192801475525}, {"name": "cpu_percent", "value": 14.016666666666666}]}, {"name": "mochitest.mochitest-browser-chrome.stage-files", "subtests": [{"name": "time", "value": 0.0002849102020263672}, {"name": "cpu_percent", "value": 0}]}, {"name": "mochitest.mochitest-browser-chrome.run-tests", "subtests": [{"name": "time", "value": 2305.3745951652527}, {"name": "cpu_percent", "value": 4.652345399698349}]}]}
[task 2022-11-22T01:31:46.205Z] 01:31:46 INFO - Total resource usage - Wall time: 2324s; CPU: 5%; Read bytes: 445411328; Write bytes: 2361999360; Read time: 7576; Write time: 11550
[task 2022-11-22T01:31:46.205Z] 01:31:46 INFO - TinderboxPrint: CPU usage<br/>4.7%
[task 2022-11-22T01:31:46.205Z] 01:31:46 INFO - TinderboxPrint: I/O read bytes / time<br/>445,411,328 / 7,576
[task 2022-11-22T01:31:46.205Z] 01:31:46 INFO - TinderboxPrint: I/O write bytes / time<br/>2,361,999,360 / 11,550
[task 2022-11-22T01:31:46.205Z] 01:31:46 INFO - TinderboxPrint: CPU idle<br/>25,875.6 (92.8%)
[task 2022-11-22T01:31:46.205Z] 01:31:46 INFO - TinderboxPrint: CPU system<br/>573.0 (2.1%)
[task 2022-11-22T01:31:46.205Z] 01:31:46 INFO - TinderboxPrint: CPU user<br/>1,441.5 (5.2%)
[task 2022-11-22T01:31:46.205Z] 01:31:46 INFO - TinderboxPrint: Swap in / out<br/>782,200,832 / 0
[task 2022-11-22T01:31:46.206Z] 01:31:46 INFO - start-pulseaudio - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2022-11-22T01:31:46.208Z] 01:31:46 INFO - install - Wall time: 20s; CPU: 14%; Read bytes: 323642880; Write bytes: 258961408; Read time: 17872; Write time: 409
[task 2022-11-22T01:31:46.208Z] 01:31:46 INFO - stage-files - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2022-11-22T01:31:46.238Z] 01:31:46 INFO - run-tests - Wall time: 2305s; CPU: 5%; Read bytes: 380354560; Write bytes: 2102906880; Read time: 7048; Write time: 11139
[task 2022-11-22T01:31:46.769Z] 01:31:46 WARNING - returning nonzero exit status 2
[taskcluster 2022-11-22T01:31:46.812Z] Exit Code: 2
[taskcluster 2022-11-22T01:31:46.812Z] User Time: 15m35.701172s
[taskcluster 2022-11-22T01:31:46.812Z] Kernel Time: 2m26.728883s
[taskcluster 2022-11-22T01:31:46.812Z] Wall Time: 40m31.619683s
[taskcluster 2022-11-22T01:31:46.812Z] Result: FAILED
[taskcluster 2022-11-22T01:31:46.812Z] === Task Finished ===
[taskcluster 2022-11-22T01:31:46.812Z] Task Duration: 40m31.624724s
[taskcluster 2022-11-22T01:31:46.917Z] Uploading artifact public/logs/localconfig.json from file logs/localconfig.json with content encoding "gzip", mime type "application/json" and expiry 2023-11-22T00:01:29.709Z
[taskcluster 2022-11-22T01:31:47.150Z] Uploading artifact public/test_info/manifests.list from file build/blobber_upload_dir/manifests.list with content encoding "gzip", mime type "text/plain; charset=utf-8" and expiry 2023-11-22T00:01:29.709Z
[taskcluster 2022-11-22T01:31:47.244Z] Uploading artifact public/test_info/mochitest-browser-chrome_errorsummary.log from file build/blobber_upload_dir/mochitest-browser-chrome_errorsummary.log with content encoding "gzip", mime type "text/plain" and expiry 2023-11-22T00:01:29.709Z
[taskcluster 2022-11-22T01:31:47.360Z] Uploading artifact public/test_info/mochitest-browser-chrome_raw.log from file build/blobber_upload_dir/mochitest-browser-chrome_raw.log with content encoding "gzip", mime type "text/plain" and expiry 2023-11-22T00:01:29.709Z
[taskcluster 2022-11-22T01:31:48.166Z] Uploading artifact public/test_info/mozilla-test-fail-screenshot_vcv92gnp.png from file build/blobber_upload_dir/mozilla-test-fail-screenshot_vcv92gnp.png with content encoding "identity", mime type "image/png" and expiry 2023-11-22T00:01:29.709Z
[taskcluster 2022-11-22T01:31:48.482Z] Uploading artifact public/test_info/resource-usage.json from file build/blobber_upload_dir/resource-usage.json with content encoding "gzip", mime type "application/json" and expiry 2023-11-22T00:01:29.709Z
[taskcluster 2022-11-22T01:31:48.743Z] Uploading artifact public/test_info/system-info.log from file build/blobber_upload_dir/system-info.log with content encoding "gzip", mime type "text/plain" and expiry 2023-11-22T00:01:29.709Z
[taskcluster 2022-11-22T01:31:48.854Z] Uploading redirect artifact public/logs/live.log to URL https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/ShUZ4L9oQ_uAOnDHP1VsJQ/runs/0/artifacts/public%2Flogs%2Flive_backing.log with mime type "text/plain; charset=utf-8" and expiry 2023-11-22T00:01:29.709Z
[taskcluster:error] exit status 2
| Comment hidden (Intermittent Failures Robot) |
|
||
Comment 2•3 years ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.
Status: NEW → RESOLVED
Closed: 3 years ago
Resolution: --- → INCOMPLETE
You need to log in
before you can comment on or make changes to this bug.
Description
•